Re: Odd maximum elapsed event times in raw 10046 trace

Niall,

>
> I assume you are talking about this snippet from the trace file with a
> circa 28 minute wait on sqlnet?

Correct.

>
> Now it looks like you have a between call event (as described on p103)
> here. (the STAT lines get written (in my understanding) only when the
> previous dbcall is finished.

I agree with you - a between call event. However, my understanding is that the STAT records don't get written until the session closes (from experience, but not proven)

> From the extract you posted your other sqlnet message from client
> events are in the sub 500 microsecond range. Then suddenly we wait for
> 28 minutes. I'd *love* to know what the app/user was doing at this
> point.

More on what the application is doing later in this post...

> In other words - yes you should forward attribute - I was wrong
> - but is it actually reasonable to associate a 28 minute wait for the
> next dbcall to be issued with that dbcall, or have you in fact merely
> determined that 28 minutes of your response time is not attributable
> in any meaningful sense to the db at all (that would be my guess).

I that the application on machine APP calls the database on machine DB and retrieves the data. It then formats some of the data as an sql loader file and loads this data back into the database. Effectively the 28 mins is accounted for (I believe) by the network transfer, formatting the data and persisting this on disk before sending is back to the DB via sqlldr. Strange I know.

It doesn't really explain the trace though.

> It also seems to me that I was misled by the term 'associated with' as
> meaning 'caused by'.

Apologies for for my use of language - caused by is the correct interpretation.

>
> I'd rewrite my 'explanation' as
>
> in db
> ======
> wait --- on dbfile.... #1
> dbcall --- select 1 million rows. #1
> wait --- on sqlnet (and any others) #2
> dbcall --- select value from lookup that tells me to update,delete or
> whatever #2
> in app
> ======
> find that I have to process the 1m rows. take ages.
> in db
> =====
> wait --- <this is the cause of the 28 minutes> sqlnet message #3
> dbcall --- now issue another statement #3

The explaination makes sense standalone. When I apply it to the trace in question "wait --- <this is the cause of the 28 minutes> sqlnet message #3"
should refer to cursor #2.

I think I need to go back to the problem and re-run the test and trace and compare results.

Cheers.

Mat. Received on Tue Aug 10 2004 - 00:45:05 CDT