Re: sql trace - forward attribution
Btw, reading through a 10046/12 trace from instance startup & database opening can reveal really lots of interesting information :) Tanel. - Original Message - To: "Multiple recipients of list ORACLE-L" <[EMAIL PROTECTED]> Sent: Tuesday, January 06, 2004 8:24 PM > Thanks, Raj, but I don't think so. The whole reason > behind enabling a db-wide trace was to capture > everything sql trace is instrumented to capture. As > you know sql_trace is a static parameter, so I got > everything "from the begining", including: > > PARSING IN CURSOR #1 > ALTER DATABASE MOUNT > .. > PARSING IN CURSOR #1 > ALTER DATABASE OPEN > > PARSING IN CURSOR #2 > create table bootstrap$ ( line# > > PARSING IN CURSOR #2 > CREATE ROLLBACK SEGMENT SYSTEM > > .. but not the cursor #0 > > (Interestingly "alter database mount" went to one > trace file, while "alter database open" and the rest > to another - so to mount a DB Oracle spawns a > different process on your behalf and than passes > control back to your foreground to open it?) > > > --- "Jamadagni, Rajendra" > <[EMAIL PROTECTED]> wrote: > you may not be > seeing parse etc entries for cursor > > #0 merely because maybe by design, cursor#0 gets > > invoked before trace gets activated. This way, you > > will never get cursor #0 info. > > > > You can tell, I am guessing but to get similar > > experience, start trace in an already active session > > and you'll see. > > Raj > > > -- -- > > Rajendra dot Jamadagni at nospamespn dot com > > All Views expressed in this email are strictly > > personal. > > QOTD: Any clod can have facts, having an opinion is > > an art ! > > > > > > -Original Message- > > Sent: Tuesday, January 06, 2004 12:00 PM > > To: Multiple recipients of list ORACLE-L > > > > > > Thanks to Anjo, Cary, Tanel, and everybody who > > provided feedback back channel. > > > > Just to rule out the possibility of a collection > > error > > (somebody suggested that cursor #0 is simply not > > captured) I bounced the DB today, enabled a DB-wide > > trace ... and as expected > > > > grep -i "cursor #0" * > > > > returned nothing, while "wait #0" gives plenty. So > > it > > is not a trace activation/termination error. > > > > -- > > Please see the official ORACLE-L FAQ: > > http://www.orafaq.net > > -- > > Author: Jamadagni, Rajendra > > INET: [EMAIL PROTECTED] > > > > Fat City Network Services-- 858-538-5051 > > http://www.fatcity.com > > San Diego, California-- Mailing list and web > > hosting services > > > - > > To REMOVE yourself from this mailing list, send an > > E-Mail message > > to: [EMAIL PROTECTED] (note EXACT spelling of > > 'ListGuru') and in > > the message BODY, include a line containing: UNSUB > > ORACLE-L > > (or the name of mailing list you want to be removed > > from). You may > > also send the HELP command for other information > > (like subscribing). > > __ > Post your free ad now! http://personals.yahoo.ca > -- > Please see the official ORACLE-L FAQ: http://www.orafaq.net > -- > Author: Boris Dali > INET: [EMAIL PROTECTED] > > Fat City Network Services-- 858-538-5051 http://www.fatcity.com > San Diego, California-- Mailing list and web hosting services > - > To REMOVE yourself from this mailing list, send an E-Mail message > to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in > the message BODY, include a line containing: UNSUB ORACLE-L > (or the name of mailing list you want to be removed from). You may > also send the HELP command for other information (like subscribing). > -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Tanel Poder INET: [EMAIL PROTECTED] Fat City Network Services-- 858-538-5051 http://www.fatcity.com San Diego, California-- Mailing list and web hosting services - To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).
Re: sql trace - forward attribution
I had the same discussion with Jeff Holt (one of Cary's partners in crime) and
he described #0 attributions as actions not associated with a cursor (i.e.
statement). For example, I worked on a web server which would maintain a
persistent connection. Every 90 minutes, it would execute a series of statements
to load up the web cache. At the end of the series, it closed all the cursors
and issued a "rollback" . As all cursors were closed, the wait time
until the next 'awakening' was attributed to cursor #0.
The non-association of #0 also explains why you should not see #0 parses,
executes, fetches or stats.
Daniel Fink
Boris Dali wrote:
> Thanks to Anjo, Cary, Tanel, and everybody who
> provided feedback back channel.
>
> Just to rule out the possibility of a collection error
> (somebody suggested that cursor #0 is simply not
> captured) I bounced the DB today, enabled a DB-wide
> trace ... and as expected
>
> grep -i "cursor #0" *
>
> returned nothing, while "wait #0" gives plenty. So it
> is not a trace activation/termination error.
>
> ---
>
> I think what we deal with here is a "variant" of what
> Anjo described, but not exactly that as I don't see
>
> *** SESSION ID:(sid.serial#) lines in the middle of
> any trace file, only in the header, but I think it
> still might be "session switching" of a kind.
>
> What we use here is an n-tier proxy authentication and
> I suspect these waits is the price we pay for it. Not
> sure, but maybe if proxy attributes are "switched" sql
> trace doesn't capture this properly, "forgeting" to
> emit new session info? I would be interested to know
> how to
>
> 1) confirm or refute this
> 2) since waits #0 appear only before the calls to a
> stored code - I don't know if they deliberatly "switch
> sessions" in the code that runs on the app server and
> run the stored code as the schema owner (similar to
> switching current schema as an alternative to using
> synonyms) or it is a feature of Oracle's proxy
> authentication implementation
> 3) how to check "proxy identity" of the user - i.e.
> how to run something like sys_context('userenv',
> 'proxy_user') for sessions other than my own.
>
> Thanks,
> Boris Dali.
>
> --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > They write
> all to the same trace file. So there
> > should be different
> > sid.serial# combinations.
>
> __
> Post your free ad now! http://personals.yahoo.ca
> --
> Please see the official ORACLE-L FAQ: http://www.orafaq.net
> --
> Author: Boris Dali
> INET: [EMAIL PROTECTED]
>
> Fat City Network Services-- 858-538-5051 http://www.fatcity.com
> San Diego, California-- Mailing list and web hosting services
> -
> To REMOVE yourself from this mailing list, send an E-Mail message
> to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in
> the message BODY, include a line containing: UNSUB ORACLE-L
> (or the name of mailing list you want to be removed from). You may
> also send the HELP command for other information (like subscribing).
--
Please see the official ORACLE-L FAQ: http://www.orafaq.net
--
Author: Daniel W. Fink
INET: [EMAIL PROTECTED]
Fat City Network Services-- 858-538-5051 http://www.fatcity.com
San Diego, California-- Mailing list and web hosting services
-
To REMOVE yourself from this mailing list, send an E-Mail message
to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from). You may
also send the HELP command for other information (like subscribing).
RE: sql trace - forward attribution
Thanks, Raj, but I don't think so. The whole reason behind enabling a db-wide trace was to capture everything sql trace is instrumented to capture. As you know sql_trace is a static parameter, so I got everything "from the begining", including: PARSING IN CURSOR #1 ALTER DATABASE MOUNT .. PARSING IN CURSOR #1 ALTER DATABASE OPEN PARSING IN CURSOR #2 create table bootstrap$ ( line# PARSING IN CURSOR #2 CREATE ROLLBACK SEGMENT SYSTEM .. but not the cursor #0 (Interestingly "alter database mount" went to one trace file, while "alter database open" and the rest to another - so to mount a DB Oracle spawns a different process on your behalf and than passes control back to your foreground to open it?) --- "Jamadagni, Rajendra" <[EMAIL PROTECTED]> wrote: > you may not be seeing parse etc entries for cursor > #0 merely because maybe by design, cursor#0 gets > invoked before trace gets activated. This way, you > will never get cursor #0 info. > > You can tell, I am guessing but to get similar > experience, start trace in an already active session > and you'll see. > Raj > > Rajendra dot Jamadagni at nospamespn dot com > All Views expressed in this email are strictly > personal. > QOTD: Any clod can have facts, having an opinion is > an art ! > > > -Original Message- > Sent: Tuesday, January 06, 2004 12:00 PM > To: Multiple recipients of list ORACLE-L > > > Thanks to Anjo, Cary, Tanel, and everybody who > provided feedback back channel. > > Just to rule out the possibility of a collection > error > (somebody suggested that cursor #0 is simply not > captured) I bounced the DB today, enabled a DB-wide > trace ... and as expected > > grep -i "cursor #0" * > > returned nothing, while "wait #0" gives plenty. So > it > is not a trace activation/termination error. > > -- > Please see the official ORACLE-L FAQ: > http://www.orafaq.net > -- > Author: Jamadagni, Rajendra > INET: [EMAIL PROTECTED] > > Fat City Network Services-- 858-538-5051 > http://www.fatcity.com > San Diego, California-- Mailing list and web > hosting services > - > To REMOVE yourself from this mailing list, send an > E-Mail message > to: [EMAIL PROTECTED] (note EXACT spelling of > 'ListGuru') and in > the message BODY, include a line containing: UNSUB > ORACLE-L > (or the name of mailing list you want to be removed > from). You may > also send the HELP command for other information > (like subscribing). __ Post your free ad now! http://personals.yahoo.ca -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Boris Dali INET: [EMAIL PROTECTED] Fat City Network Services-- 858-538-5051 http://www.fatcity.com San Diego, California-- Mailing list and web hosting services - To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).
Re: sql trace - forward attribution
Thanks, Tanel. I did checked v$session_connect info, but it doesn't tell me much, except authentication_type='PROXY' which is less than useful as it doesn't tell to whom. v$session.client_identifier is empty. Thanks, Boris Dali. > Check V$SESSION_CONNECT_INFO view. > CLIENT_IDENTIFIER in V$SESSION might show something > as well, if mid-tier is > configured to pass client id to server. > > Tanel. __ Post your free ad now! http://personals.yahoo.ca -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Boris Dali INET: [EMAIL PROTECTED] Fat City Network Services-- 858-538-5051 http://www.fatcity.com San Diego, California-- Mailing list and web hosting services - To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).
Re: sql trace - forward attribution
> 2) since waits #0 appear only before the calls to a
> stored code - I don't know if they deliberatly "switch
> sessions" in the code that runs on the app server and
> run the stored code as the schema owner (similar to
> switching current schema as an alternative to using
> synonyms) or it is a feature of Oracle's proxy
> authentication implementation
If this overhead happens only with stored code executions, could there be
some dependency tracking like with forms & dblinks (this
remote_dependencies_mode parameter etc..).
This proxy authentication is quite new and probably quite low level
functionality, it wouldn't be a surprise if Oracle had some special shortcut
there (internal cursor #0 which isn't ever parsed or similar?)
> 3) how to check "proxy identity" of the user - i.e.
> how to run something like sys_context('userenv',
> 'proxy_user') for sessions other than my own.
Check V$SESSION_CONNECT_INFO view.
CLIENT_IDENTIFIER in V$SESSION might show something as well, if mid-tier is
configured to pass client id to server.
Tanel.
--
Please see the official ORACLE-L FAQ: http://www.orafaq.net
--
Author: Tanel Poder
INET: [EMAIL PROTECTED]
Fat City Network Services-- 858-538-5051 http://www.fatcity.com
San Diego, California-- Mailing list and web hosting services
-
To REMOVE yourself from this mailing list, send an E-Mail message
to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from). You may
also send the HELP command for other information (like subscribing).
RE: sql trace - forward attribution
you may not be seeing parse etc entries for cursor #0 merely because maybe by design, cursor#0 gets invoked before trace gets activated. This way, you will never get cursor #0 info. You can tell, I am guessing but to get similar experience, start trace in an already active session and you'll see. Raj Rajendra dot Jamadagni at nospamespn dot com All Views expressed in this email are strictly personal. QOTD: Any clod can have facts, having an opinion is an art ! -Original Message- Sent: Tuesday, January 06, 2004 12:00 PM To: Multiple recipients of list ORACLE-L Thanks to Anjo, Cary, Tanel, and everybody who provided feedback back channel. Just to rule out the possibility of a collection error (somebody suggested that cursor #0 is simply not captured) I bounced the DB today, enabled a DB-wide trace ... and as expected grep -i "cursor #0" * returned nothing, while "wait #0" gives plenty. So it is not a trace activation/termination error. -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Jamadagni, Rajendra INET: [EMAIL PROTECTED] Fat City Network Services-- 858-538-5051 http://www.fatcity.com San Diego, California-- Mailing list and web hosting services - To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).
RE: sql trace - forward attribution
Thanks to Anjo, Cary, Tanel, and everybody who
provided feedback back channel.
Just to rule out the possibility of a collection error
(somebody suggested that cursor #0 is simply not
captured) I bounced the DB today, enabled a DB-wide
trace ... and as expected
grep -i "cursor #0" *
returned nothing, while "wait #0" gives plenty. So it
is not a trace activation/termination error.
---
I think what we deal with here is a "variant" of what
Anjo described, but not exactly that as I don't see
*** SESSION ID:(sid.serial#) lines in the middle of
any trace file, only in the header, but I think it
still might be "session switching" of a kind.
What we use here is an n-tier proxy authentication and
I suspect these waits is the price we pay for it. Not
sure, but maybe if proxy attributes are "switched" sql
trace doesn't capture this properly, "forgeting" to
emit new session info? I would be interested to know
how to
1) confirm or refute this
2) since waits #0 appear only before the calls to a
stored code - I don't know if they deliberatly "switch
sessions" in the code that runs on the app server and
run the stored code as the schema owner (similar to
switching current schema as an alternative to using
synonyms) or it is a feature of Oracle's proxy
authentication implementation
3) how to check "proxy identity" of the user - i.e.
how to run something like sys_context('userenv',
'proxy_user') for sessions other than my own.
Thanks,
Boris Dali.
--- Anjo Kolk <[EMAIL PROTECTED]> wrote: > They write
all to the same trace file. So there
> should be different
> sid.serial# combinations.
__
Post your free ad now! http://personals.yahoo.ca
--
Please see the official ORACLE-L FAQ: http://www.orafaq.net
--
Author: Boris Dali
INET: [EMAIL PROTECTED]
Fat City Network Services-- 858-538-5051 http://www.fatcity.com
San Diego, California-- Mailing list and web hosting services
-
To REMOVE yourself from this mailing list, send an E-Mail message
to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from). You may
also send the HELP command for other information (like subscribing).
RE: sql trace - forward attribution
They write all to the same trace file. So there should be different sid.serial# combinations. -Original Message- Boris Dali Sent: Monday, January 05, 2004 9:49 PM To: Multiple recipients of list ORACLE-L Right, but the new session (that inherits the sql trace attribute) - wouldn't it produce a **separate** trace file? In my case there's only one trace file with sid.serial# clearly stated at the begining of the trace file and WAIT #0 scattered all over the trace. ..Or am I missing something? --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > No, > > Each session will have its own sid and serail#, but > they all run in the > same process. Basically the client side tells > oracle, that it wants to > switch from session to session and oracle will keep > the state of the > switched out session. So you don't have to commit or > rollback on every > switch that you perform. SQL trace is inherited by > the process it you > set in a session, so other sessions that run in the > same process will > produce also trace output. > > Anjo. > > -Original Message- > Boris Dali > Sent: Monday, January 05, 2004 7:34 PM > To: Multiple recipients of list ORACLE-L > > > Thanks, Anjo. > > When session switching occurs does the new session > get > the same sid and serial#? And what happens with the > session being "switched/replaced" - does the > transaction it was performing get > commited/rollbacked? > I don't see XCTEND markers before those pesky WAIT > #0 > in the trace file. > Also if session gets switched, wouldn't this > terminate > sql trace for the session (in my case it doesn't)? > > Thanks, > Boris Dali. > > --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > > > > > Cursor 0 also happens in oracle due to session > > switching (multiple > > sessions in the same process), oracle apps uses > that > > but it also could > > happen with certain other application servers > > (haven't investigated it). > > > > Anjo. > > > > > > -Original Message- > > Boris Dali > > Sent: Monday, January 05, 2004 3:59 PM > > To: Multiple recipients of list ORACLE-L > > > > > > Thanks, Cary. > > > > Could you elaborate what do you mean by "wait > events associated with > > COMMIT processing"? Why does Oracle need this > "exchange of messages" > > with the client (well, with the app server really > in my case of a > > 3-tier deployment) to perform a commit? > > > > > > In any event, as I described earlier in my case I > > think Cursor #0 doesn't fall in neither of the two > > uses you mentioned. > > > > Bug 2425312 is RPC related as I understand. I > don't > > work distributed (single DB) and app server (and > > clients - thin) don't have their own SQL engine, > so > > all SQL processing is happening strictly on the DB > > server. So this doesn't seem to apply to me. > > > > And I see Cursor #0 used with no commits/rollbacks > > as > > part of one Oracle transaction. > > > > > > I see these WAIT #0 flying back and forth between > DB > > and the app server sometimes 20 times just before > > stored procs are called and I can't figure out > why. > > Another bug? > > > > Thank you, > > Boris Dali. > > > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > Boris, > > > > > > Cursor #0 seems reserved for two special uses: > (1) > > > wait events > > > associated with COMMIT processing (also, of > > course, > > > ROLLBACK and > > > SAVEPOINT), and (2) wait events associated with > > > dbcalls not instrumented > > > because of bug 2425312. > > > > > > > > > Cary Millsap > > > Hotsos Enterprises, Ltd. > > > http://www.hotsos.com > > > > > > Upcoming events: > > > - Performance Diagnosis 101: 1/27 Atlanta > > > - SQL Optimization 101: 2/16 Dallas > > > - Hotsos Symposium 2004: March 7-10 Dallas > > > - Visit www.hotsos.com for schedule details... > > > > > > > > > -Original Message- > > > Boris Dali > > > Sent: Thursday, January 01, 2004 10:29 AM > > > To: Multiple recipients of list ORACLE-L > > > > > > Thanks a lot for your reply, Cary. > > > > > > One follow-up question. What would motivate "a > > chat" > > > of sometimes 5, sometimes 10-20 'SQL*Net message > > > to/from client' consecutive wait lines emitted > to > > > the > > > trace file in the following manner: > > > > > > WAIT #0: nam='SQL*Net message to client' ela= 2 > p1=1413697536 p2=1 > > > p3=0 WAIT #0: nam='SQL*Net message from client' > ela= > > 678 p1=1413697536 p2=1 > > > > > p3=0 WAIT #0: nam='SQL*Net message to client' > ela= > > 1 > > > p1=1413697536 p2=1 p3=0 > > > WAIT #0: nam='SQL*Net message from client' ela= > > 3463 > > > p1=1413697536 p2=1 p3=0 > > > WAIT #0: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 > > > p3=0 WAIT #0: nam='SQL*Net message from client' ela= > > 3322 > > > p1=1413697536 p2=1 p3=0 > > > > > > > > > I see this pattern of "message exchanges" before > > > calling a stored code from the app server (OCI), > > so > > > using forward attribution it is a call to a > stored > > > code that it t
Re: sql trace - forward attribution
Tanel, What I see in the trace file header is something like the following: ... *** SESSION ID:(22.9304) 2003-12-29 15:04:45.743 ... Which is sid.serial# isn't it? If "session switching" occurs, handled by the same shadow process and the new session with a different sid.serial# continues to write to the **same** trace file... wouldn't you expect to see line similar to the above, but with a new sid.serial# in it? --- Tanel Poder <[EMAIL PROTECTED]> wrote: > Trace file has server process number in it's name, > not session number, thus > as long as the sessions are served by the same > server process, the contents > will be written into one single file. > > Tanel. > > - Original Message - > To: "Multiple recipients of list ORACLE-L" > <[EMAIL PROTECTED]> > Sent: Monday, January 05, 2004 10:49 PM > > > > Right, but the new session (that inherits the sql > > trace attribute) - wouldn't it produce a > **separate** > > trace file? In my case there's only one trace file > > with sid.serial# clearly stated at the begining of > the > > trace file and WAIT #0 scattered all over the t > race === message truncated === __ Post your free ad now! http://personals.yahoo.ca -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Boris Dali INET: [EMAIL PROTECTED] Fat City Network Services-- 858-538-5051 http://www.fatcity.com San Diego, California-- Mailing list and web hosting services - To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).
Re: sql trace - forward attribution
Trace file has server process number in it's name, not session number, thus as long as the sessions are served by the same server process, the contents will be written into one single file. Tanel. - Original Message - To: "Multiple recipients of list ORACLE-L" <[EMAIL PROTECTED]> Sent: Monday, January 05, 2004 10:49 PM > Right, but the new session (that inherits the sql > trace attribute) - wouldn't it produce a **separate** > trace file? In my case there's only one trace file > with sid.serial# clearly stated at the begining of the > trace file and WAIT #0 scattered all over the t [EMAIL PROTECTED],Eachsessionw illhaveitsownsidandserail#,buttheyallruninthesameprocess.Basicallytheclients idetellsoracle,thatitwantstoswitchfromsessiontosession and oracle will keep > > the state of the > > switched out session. So you don't have to commit or > > rollback on every > > switch that you perform. SQL trace is inherited by > > the process it you > > set in a session, so other sessions that run in the > > same process will > > produce also trace output. > > > > Anjo. > > > > -Original Message- > > Boris Dali > > Sent: Monday, January 05, 2004 7:34 PM > > To: Multiple recipients of list ORACLE-L > > > > > > Thanks, Anjo. > > > > When session switching occurs does the new session > > get > > the same sid and serial#? And what happens with the > > session being "switched/replaced" - does the > > transaction it was performing get > > commited/rollbacked? > > I don't see XCTEND markers before those pesky WAIT > > #0 > > in the trace file. > > Also if session gets switched, wouldn't this > > terminate > > sql trace for the session (in my case it doesn't)? > > > > Thanks, > > Boris Dali. > > > > --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > > > > > > > Cursor 0 also happens in oracle due to session > > > switching (multiple > > > sessions in the same process), oracle apps uses > > that > > > but it also could > > > happen with certain other application servers > > > (haven't investigated it). > > > > > > Anjo. > > > > > > > > > -Original Message- > > > Boris Dali > > > Sent: Monday, January 05, 2004 3:59 PM > > > To: Multiple recipients of list ORACLE-L > > > > > > > > > Thanks, Cary. > > > > > > Could you elaborate what do you mean by "wait > > events associated with > > > COMMIT processing"? Why does Oracle need this > > "exchange of messages" > > > with the client (well, with the app server really > > in my case of a > > > 3-tier deployment) to perform a commit? > > > > > > > > > In any event, as I described earlier in my case I > > > think Cursor #0 doesn't fall in neither of the two > > > uses you mentioned. > > > > > > Bug 2425312 is RPC related as I understand. I > > don't > > > work distributed (single DB) and app server (and > > > clients - thin) don't have their own SQL engine, > > so > > > all SQL processing is happening strictly on the DB > > > server. So this doesn't seem to apply to me. > > > > > > And I see Cursor #0 used with no commits/rollbacks > > > as > > > part of one Oracle transaction. > > > > > > > > > I see these WAIT #0 flying back and forth between > > DB > > > and the app server sometimes 20 times just before > > > stored procs are called and I can't figure out > > why. > > > Another bug? > > > > > > Thank you, > > > Boris Dali. > > > > > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > > Boris, > > > > > > > > Cursor #0 seems reserved for two special uses: > > (1) > > > > wait events > > > > associated with COMMIT processing (also, of > > > course, > > > > ROLLBACK and > > > > SAVEPOINT), and (2) wait events associated with > > > > dbcalls not instrumented > > > > because of bug 2425312. > > > > > > > > > > > > Cary Millsap > > > > Hotsos Enterprises, Ltd. > > > > http://www.hotsos.com > > > > > > > > Upcoming events: > > > > - Performance Diagnosis 101: 1/27 Atlanta > > > > - SQL Optimization 101: 2/16 Dallas > > > > - Hotsos Symposium 2004: March 7-10 Dallas > > > > - Visit www.hotsos.com for schedule details... > > > > > > > > > > > > -Original Message- > > > > Boris Dali > > > > Sent: Thursday, January 01, 2004 10:29 AM > > > > To: Multiple recipients of list ORACLE-L > > > > > > > > Thanks a lot for your reply, Cary. > > > > > > > > One follow-up question. What would motivate "a > > > chat" > > > > of sometimes 5, sometimes 10-20 'SQL*Net message > > > > to/from client' consecutive wait lines emitted > > to > > > > the > > > > trace file in the following manner: > > > > > > > > WAIT #0: nam='SQL*Net message to client' ela= 2 > > p1=1413697536 p2=1 > > > > p3=0 WAIT #0: nam='SQL*Net message from client' > > ela= > > > 678 p1=1413697536 p2=1 > > > > > > > p3=0 WAIT #0: nam='SQL*Net message to client' > > ela= > > > 1 > > > > p1=1413697536 p2=1 p3=0 > > > > WAIT #0: nam='SQL*Net message from client' ela= > > > 3463 > > > > p1=1413697536 p2=1 p3=0 > > > > WAIT #0: nam='SQL*Net message to client' ela= 1 > > > > p1=1413697536 p2=1 p3=0 > > > > WAIT #0:
RE: sql trace - forward attribution
Right, but the new session (that inherits the sql trace attribute) - wouldn't it produce a **separate** trace file? In my case there's only one trace file with sid.serial# clearly stated at the begining of the trace file and WAIT #0 scattered all over the trace. ..Or am I missing something? --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > No, > > Each session will have its own sid and serail#, but > they all run in the > same process. Basically the client side tells > oracle, that it wants to > switch from session to session and oracle will keep > the state of the > switched out session. So you don't have to commit or > rollback on every > switch that you perform. SQL trace is inherited by > the process it you > set in a session, so other sessions that run in the > same process will > produce also trace output. > > Anjo. > > -Original Message- > Boris Dali > Sent: Monday, January 05, 2004 7:34 PM > To: Multiple recipients of list ORACLE-L > > > Thanks, Anjo. > > When session switching occurs does the new session > get > the same sid and serial#? And what happens with the > session being "switched/replaced" - does the > transaction it was performing get > commited/rollbacked? > I don't see XCTEND markers before those pesky WAIT > #0 > in the trace file. > Also if session gets switched, wouldn't this > terminate > sql trace for the session (in my case it doesn't)? > > Thanks, > Boris Dali. > > --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > > > > > Cursor 0 also happens in oracle due to session > > switching (multiple > > sessions in the same process), oracle apps uses > that > > but it also could > > happen with certain other application servers > > (haven't investigated it). > > > > Anjo. > > > > > > -Original Message- > > Boris Dali > > Sent: Monday, January 05, 2004 3:59 PM > > To: Multiple recipients of list ORACLE-L > > > > > > Thanks, Cary. > > > > Could you elaborate what do you mean by "wait > events associated with > > COMMIT processing"? Why does Oracle need this > "exchange of messages" > > with the client (well, with the app server really > in my case of a > > 3-tier deployment) to perform a commit? > > > > > > In any event, as I described earlier in my case I > > think Cursor #0 doesn't fall in neither of the two > > uses you mentioned. > > > > Bug 2425312 is RPC related as I understand. I > don't > > work distributed (single DB) and app server (and > > clients - thin) don't have their own SQL engine, > so > > all SQL processing is happening strictly on the DB > > server. So this doesn't seem to apply to me. > > > > And I see Cursor #0 used with no commits/rollbacks > > as > > part of one Oracle transaction. > > > > > > I see these WAIT #0 flying back and forth between > DB > > and the app server sometimes 20 times just before > > stored procs are called and I can't figure out > why. > > Another bug? > > > > Thank you, > > Boris Dali. > > > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > Boris, > > > > > > Cursor #0 seems reserved for two special uses: > (1) > > > wait events > > > associated with COMMIT processing (also, of > > course, > > > ROLLBACK and > > > SAVEPOINT), and (2) wait events associated with > > > dbcalls not instrumented > > > because of bug 2425312. > > > > > > > > > Cary Millsap > > > Hotsos Enterprises, Ltd. > > > http://www.hotsos.com > > > > > > Upcoming events: > > > - Performance Diagnosis 101: 1/27 Atlanta > > > - SQL Optimization 101: 2/16 Dallas > > > - Hotsos Symposium 2004: March 7-10 Dallas > > > - Visit www.hotsos.com for schedule details... > > > > > > > > > -Original Message- > > > Boris Dali > > > Sent: Thursday, January 01, 2004 10:29 AM > > > To: Multiple recipients of list ORACLE-L > > > > > > Thanks a lot for your reply, Cary. > > > > > > One follow-up question. What would motivate "a > > chat" > > > of sometimes 5, sometimes 10-20 'SQL*Net message > > > to/from client' consecutive wait lines emitted > to > > > the > > > trace file in the following manner: > > > > > > WAIT #0: nam='SQL*Net message to client' ela= 2 > p1=1413697536 p2=1 > > > p3=0 WAIT #0: nam='SQL*Net message from client' > ela= > > 678 p1=1413697536 p2=1 > > > > > p3=0 WAIT #0: nam='SQL*Net message to client' > ela= > > 1 > > > p1=1413697536 p2=1 p3=0 > > > WAIT #0: nam='SQL*Net message from client' ela= > > 3463 > > > p1=1413697536 p2=1 p3=0 > > > WAIT #0: nam='SQL*Net message to client' ela= 1 > > > p1=1413697536 p2=1 p3=0 > > > WAIT #0: nam='SQL*Net message from client' ela= > > 3322 > > > p1=1413697536 p2=1 p3=0 > > > > > > > > > I see this pattern of "message exchanges" before > > > calling a stored code from the app server (OCI), > > so > > > using forward attribution it is a call to a > stored > > > code that it to blame correct? > > > I can't of course eliminate a call to a stored > > code > > > but is there something that can be done to > > minimize > > > amount of these 'SQL*Net message...' lines? > While > > > t
RE: sql trace - forward attribution
Anjo, I suppose your test-case involved more than just use of sqlplus. Probably some middle tier with connection/session pooling of some sort? --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > I actually build a testcase for this and it still > failed on 9.2 without > any patches. It is supposed to be fixed in some > later patch. I don't > have the patches > > -Original Message- > Anjo Kolk > Sent: Monday, January 05, 2004 6:49 PM > To: Multiple recipients of list ORACLE-L > > > > > Cursor 0 also happens in oracle due to session > switching (multiple > sessions in the same process), oracle apps uses that > but it also could > happen with certain other application servers > (haven't investigated it). > > Anjo. > > > -Original Message- > Boris Dali > Sent: Monday, January 05, 2004 3:59 PM > To: Multiple recipients of list ORACLE-L > > > Thanks, Cary. > > Could you elaborate what do you mean by "wait events > associated with COMMIT processing"? Why does Oracle > need this "exchange of messages" with the client > (well, with the app server really in my case of a > 3-tier deployment) to perform a commit? > > > In any event, as I described earlier in my case I > think Cursor #0 doesn't fall in neither of the two > uses you mentioned. > > Bug 2425312 is RPC related as I understand. I don't > work distributed (single DB) and app server (and > clients - thin) don't have their own SQL engine, so > all SQL processing is happening strictly on the DB > server. So this doesn't seem to apply to me. > > And I see Cursor #0 used with no commits/rollbacks > as > part of one Oracle transaction. > > > I see these WAIT #0 flying back and forth between DB > and the app server sometimes 20 times just before > stored procs are called and I can't figure out why. > Another bug? > > Thank you, > Boris Dali. > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > Boris, > > > > Cursor #0 seems reserved for two special uses: (1) > > wait events > > associated with COMMIT processing (also, of > course, > > ROLLBACK and > > SAVEPOINT), and (2) wait events associated with > > dbcalls not instrumented > > because of bug 2425312. > > > > > > Cary Millsap > > Hotsos Enterprises, Ltd. > > http://www.hotsos.com > > > > Upcoming events: > > - Performance Diagnosis 101: 1/27 Atlanta > > - SQL Optimization 101: 2/16 Dallas > > - Hotsos Symposium 2004: March 7-10 Dallas > > - Visit www.hotsos.com for schedule details... > > > > > > -Original Message- > > Boris Dali > > Sent: Thursday, January 01, 2004 10:29 AM > > To: Multiple recipients of list ORACLE-L > > > > Thanks a lot for your reply, Cary. > > > > One follow-up question. What would motivate "a > chat" > > of sometimes 5, sometimes 10-20 'SQL*Net message > > to/from client' consecutive wait lines emitted to > > the > > trace file in the following manner: > > > > WAIT #0: nam='SQL*Net message to client' ela= 2 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= > 678 p1=1413697536 p2=1 > > > p3=0 WAIT #0: nam='SQL*Net message to client' ela= > 1 p1=1413697536 > > p2=1 p3=0 WAIT #0: nam='SQL*Net message from > client' ela= 3463 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= > 3322 > > p1=1413697536 p2=1 p3=0 > > > > > > I see this pattern of "message exchanges" before > > calling a stored code from the app server (OCI), > so > > using forward attribution it is a call to a stored > > code that it to blame correct? > > I can't of course eliminate a call to a stored > code > > but is there something that can be done to > minimize > > amount of these 'SQL*Net message...' lines? While > > the > > latency of these waits is low, these 3-5 > > milliseconds > > get accumulated slowly, but surely. > > > > Also does cursor #0 has some special meaning in > > traces? I can't seem to create a test-case where I > > get > > cursor #0 emitted for me and yet tracing real > > applications I see it all over (like in the > excerpt > > above) > > > > > > I guess I have more than one follow-up question > :-( > > > > Thanks, > > Boris Dali. > > > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > > > > >WAIT #31: nam='SQL*Net message to client' ela= > 1 > > > p1=1413697536 p2=1 p3=0 > > > >WAIT #31: nam='SQL*Net message from client' > ela= > > > 692 p1=1413697536 p2=1 > > > p3=0 > > > >WAIT #31: nam='SQL*Net message to client' ela= > 1 > > > p1=1413697536 p2=1 > > > p3=0 >FETCH > > > > > > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > > > >WAIT #31: nam='SQL*Net message from client' > ela= > > > 2295 p1=1413697536 > > > p2=1 p3=0 > > > > > > > > > > Boris, "SQL*Net message..." events are > > > "between-call" events. Their > > > times are not included in the following dbcall's > > > elapsed time. But it > > > *is* appropriate to "blame" the dbcall that > > follows > > > for the time >
RE: sql trace - forward attribution
I actually build a testcase for this and it still failed on 9.2 without any patches. It is supposed to be fixed in some later patch. I don't have the patches -Original Message- Anjo Kolk Sent: Monday, January 05, 2004 6:49 PM To: Multiple recipients of list ORACLE-L Cursor 0 also happens in oracle due to session switching (multiple sessions in the same process), oracle apps uses that but it also could happen with certain other application servers (haven't investigated it). Anjo. -Original Message- Boris Dali Sent: Monday, January 05, 2004 3:59 PM To: Multiple recipients of list ORACLE-L Thanks, Cary. Could you elaborate what do you mean by "wait events associated with COMMIT processing"? Why does Oracle need this "exchange of messages" with the client (well, with the app server really in my case of a 3-tier deployment) to perform a commit? In any event, as I described earlier in my case I think Cursor #0 doesn't fall in neither of the two uses you mentioned. Bug 2425312 is RPC related as I understand. I don't work distributed (single DB) and app server (and clients - thin) don't have their own SQL engine, so all SQL processing is happening strictly on the DB server. So this doesn't seem to apply to me. And I see Cursor #0 used with no commits/rollbacks as part of one Oracle transaction. I see these WAIT #0 flying back and forth between DB and the app server sometimes 20 times just before stored procs are called and I can't figure out why. Another bug? Thank you, Boris Dali. --- Cary Millsap <[EMAIL PROTECTED]> wrote: > Boris, > > Cursor #0 seems reserved for two special uses: (1) > wait events > associated with COMMIT processing (also, of course, > ROLLBACK and > SAVEPOINT), and (2) wait events associated with > dbcalls not instrumented > because of bug 2425312. > > > Cary Millsap > Hotsos Enterprises, Ltd. > http://www.hotsos.com > > Upcoming events: > - Performance Diagnosis 101: 1/27 Atlanta > - SQL Optimization 101: 2/16 Dallas > - Hotsos Symposium 2004: March 7-10 Dallas > - Visit www.hotsos.com for schedule details... > > > -Original Message- > Boris Dali > Sent: Thursday, January 01, 2004 10:29 AM > To: Multiple recipients of list ORACLE-L > > Thanks a lot for your reply, Cary. > > One follow-up question. What would motivate "a chat" > of sometimes 5, sometimes 10-20 'SQL*Net message > to/from client' consecutive wait lines emitted to > the > trace file in the following manner: > > WAIT #0: nam='SQL*Net message to client' ela= 2 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 678 p1=1413697536 p2=1 > p3=0 WAIT #0: nam='SQL*Net message to client' ela= 1 p1=1413697536 > p2=1 p3=0 WAIT #0: nam='SQL*Net message from client' ela= 3463 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 3322 > p1=1413697536 p2=1 p3=0 > > > I see this pattern of "message exchanges" before > calling a stored code from the app server (OCI), so > using forward attribution it is a call to a stored > code that it to blame correct? > I can't of course eliminate a call to a stored code > but is there something that can be done to minimize > amount of these 'SQL*Net message...' lines? While > the > latency of these waits is low, these 3-5 > milliseconds > get accumulated slowly, but surely. > > Also does cursor #0 has some special meaning in > traces? I can't seem to create a test-case where I > get > cursor #0 emitted for me and yet tracing real > applications I see it all over (like in the excerpt > above) > > > I guess I have more than one follow-up question :-( > > Thanks, > Boris Dali. > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > >WAIT #31: nam='SQL*Net message from client' ela= > > 692 p1=1413697536 p2=1 > > p3=0 > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 > > p3=0 >FETCH > > > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > > >WAIT #31: nam='SQL*Net message from client' ela= > > 2295 p1=1413697536 > > p2=1 p3=0 > > > > > > > Boris, "SQL*Net message..." events are > > "between-call" events. Their > > times are not included in the following dbcall's > > elapsed time. But it > > *is* appropriate to "blame" the dbcall that > follows > > for the time > > consumed by the event. That is, if you can > eliminate > > the dbcall that > > follows, then you can eliminate the between-call > > event (and its elapsed > > time). The "assignment of blame" is what "forward attribution" is > > about. > > > > > > Cary Millsap > > Hotsos Enterprises, Ltd. > > http://www.hotsos.com > > > > Upcoming events: > > - Performance Diagnosis 101: 1/27 Atlanta > > - SQL Optimization 101: 2/16 Dallas > > - Hotsos Symposium 2004: March 7-10 Dallas > > - Visit www.hotsos.com for schedule details... > > > >
RE: sql trace - forward attribution
No, Each session will have its own sid and serail#, but they all run in the same process. Basically the client side tells oracle, that it wants to switch from session to session and oracle will keep the state of the switched out session. So you don't have to commit or rollback on every switch that you perform. SQL trace is inherited by the process it you set in a session, so other sessions that run in the same process will produce also trace output. Anjo. -Original Message- Boris Dali Sent: Monday, January 05, 2004 7:34 PM To: Multiple recipients of list ORACLE-L Thanks, Anjo. When session switching occurs does the new session get the same sid and serial#? And what happens with the session being "switched/replaced" - does the transaction it was performing get commited/rollbacked? I don't see XCTEND markers before those pesky WAIT #0 in the trace file. Also if session gets switched, wouldn't this terminate sql trace for the session (in my case it doesn't)? Thanks, Boris Dali. --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > > > Cursor 0 also happens in oracle due to session > switching (multiple > sessions in the same process), oracle apps uses that > but it also could > happen with certain other application servers > (haven't investigated it). > > Anjo. > > > -Original Message- > Boris Dali > Sent: Monday, January 05, 2004 3:59 PM > To: Multiple recipients of list ORACLE-L > > > Thanks, Cary. > > Could you elaborate what do you mean by "wait events associated with > COMMIT processing"? Why does Oracle need this "exchange of messages" > with the client (well, with the app server really in my case of a > 3-tier deployment) to perform a commit? > > > In any event, as I described earlier in my case I > think Cursor #0 doesn't fall in neither of the two > uses you mentioned. > > Bug 2425312 is RPC related as I understand. I don't > work distributed (single DB) and app server (and > clients - thin) don't have their own SQL engine, so > all SQL processing is happening strictly on the DB > server. So this doesn't seem to apply to me. > > And I see Cursor #0 used with no commits/rollbacks > as > part of one Oracle transaction. > > > I see these WAIT #0 flying back and forth between DB > and the app server sometimes 20 times just before > stored procs are called and I can't figure out why. > Another bug? > > Thank you, > Boris Dali. > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > Boris, > > > > Cursor #0 seems reserved for two special uses: (1) > > wait events > > associated with COMMIT processing (also, of > course, > > ROLLBACK and > > SAVEPOINT), and (2) wait events associated with > > dbcalls not instrumented > > because of bug 2425312. > > > > > > Cary Millsap > > Hotsos Enterprises, Ltd. > > http://www.hotsos.com > > > > Upcoming events: > > - Performance Diagnosis 101: 1/27 Atlanta > > - SQL Optimization 101: 2/16 Dallas > > - Hotsos Symposium 2004: March 7-10 Dallas > > - Visit www.hotsos.com for schedule details... > > > > > > -Original Message- > > Boris Dali > > Sent: Thursday, January 01, 2004 10:29 AM > > To: Multiple recipients of list ORACLE-L > > > > Thanks a lot for your reply, Cary. > > > > One follow-up question. What would motivate "a > chat" > > of sometimes 5, sometimes 10-20 'SQL*Net message > > to/from client' consecutive wait lines emitted to > > the > > trace file in the following manner: > > > > WAIT #0: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 > > p3=0 WAIT #0: nam='SQL*Net message from client' ela= > 678 p1=1413697536 p2=1 > > > p3=0 WAIT #0: nam='SQL*Net message to client' ela= > 1 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= > 3463 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= > 3322 > > p1=1413697536 p2=1 p3=0 > > > > > > I see this pattern of "message exchanges" before > > calling a stored code from the app server (OCI), > so > > using forward attribution it is a call to a stored > > code that it to blame correct? > > I can't of course eliminate a call to a stored > code > > but is there something that can be done to > minimize > > amount of these 'SQL*Net message...' lines? While > > the > > latency of these waits is low, these 3-5 > > milliseconds > > get accumulated slowly, but surely. > > > > Also does cursor #0 has some special meaning in > > traces? I can't seem to create a test-case where I > > get > > cursor #0 emitted for me and yet tracing real > > applications I see it all over (like in the > excerpt > > above) > > > > > > I guess I have more than one follow-up question > :-( > > > > Thanks, > > Boris Dali. > > > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > > > > >WAIT #31: nam='SQL*Net message to client' ela= > 1 > > > p1=1413697536 p2=1 p3=0 > > > >WAIT #31: nam='SQL*Net message from client' > ela= > > > 692 p1=1413697536
RE: sql trace - forward attribution
Thanks, Anjo. When session switching occurs does the new session get the same sid and serial#? And what happens with the session being "switched/replaced" - does the transaction it was performing get commited/rollbacked? I don't see XCTEND markers before those pesky WAIT #0 in the trace file. Also if session gets switched, wouldn't this terminate sql trace for the session (in my case it doesn't)? Thanks, Boris Dali. --- Anjo Kolk <[EMAIL PROTECTED]> wrote: > > > Cursor 0 also happens in oracle due to session > switching (multiple > sessions in the same process), oracle apps uses that > but it also could > happen with certain other application servers > (haven't investigated it). > > Anjo. > > > -Original Message- > Boris Dali > Sent: Monday, January 05, 2004 3:59 PM > To: Multiple recipients of list ORACLE-L > > > Thanks, Cary. > > Could you elaborate what do you mean by "wait events > associated with COMMIT processing"? Why does Oracle > need this "exchange of messages" with the client > (well, with the app server really in my case of a > 3-tier deployment) to perform a commit? > > > In any event, as I described earlier in my case I > think Cursor #0 doesn't fall in neither of the two > uses you mentioned. > > Bug 2425312 is RPC related as I understand. I don't > work distributed (single DB) and app server (and > clients - thin) don't have their own SQL engine, so > all SQL processing is happening strictly on the DB > server. So this doesn't seem to apply to me. > > And I see Cursor #0 used with no commits/rollbacks > as > part of one Oracle transaction. > > > I see these WAIT #0 flying back and forth between DB > and the app server sometimes 20 times just before > stored procs are called and I can't figure out why. > Another bug? > > Thank you, > Boris Dali. > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > Boris, > > > > Cursor #0 seems reserved for two special uses: (1) > > wait events > > associated with COMMIT processing (also, of > course, > > ROLLBACK and > > SAVEPOINT), and (2) wait events associated with > > dbcalls not instrumented > > because of bug 2425312. > > > > > > Cary Millsap > > Hotsos Enterprises, Ltd. > > http://www.hotsos.com > > > > Upcoming events: > > - Performance Diagnosis 101: 1/27 Atlanta > > - SQL Optimization 101: 2/16 Dallas > > - Hotsos Symposium 2004: March 7-10 Dallas > > - Visit www.hotsos.com for schedule details... > > > > > > -Original Message- > > Boris Dali > > Sent: Thursday, January 01, 2004 10:29 AM > > To: Multiple recipients of list ORACLE-L > > > > Thanks a lot for your reply, Cary. > > > > One follow-up question. What would motivate "a > chat" > > of sometimes 5, sometimes 10-20 'SQL*Net message > > to/from client' consecutive wait lines emitted to > > the > > trace file in the following manner: > > > > WAIT #0: nam='SQL*Net message to client' ela= 2 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= > 678 p1=1413697536 p2=1 > > > p3=0 WAIT #0: nam='SQL*Net message to client' ela= > 1 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= > 3463 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= > 3322 > > p1=1413697536 p2=1 p3=0 > > > > > > I see this pattern of "message exchanges" before > > calling a stored code from the app server (OCI), > so > > using forward attribution it is a call to a stored > > code that it to blame correct? > > I can't of course eliminate a call to a stored > code > > but is there something that can be done to > minimize > > amount of these 'SQL*Net message...' lines? While > > the > > latency of these waits is low, these 3-5 > > milliseconds > > get accumulated slowly, but surely. > > > > Also does cursor #0 has some special meaning in > > traces? I can't seem to create a test-case where I > > get > > cursor #0 emitted for me and yet tracing real > > applications I see it all over (like in the > excerpt > > above) > > > > > > I guess I have more than one follow-up question > :-( > > > > Thanks, > > Boris Dali. > > > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > > > > >WAIT #31: nam='SQL*Net message to client' ela= > 1 > > > p1=1413697536 p2=1 p3=0 > > > >WAIT #31: nam='SQL*Net message from client' > ela= > > > 692 p1=1413697536 p2=1 > > > p3=0 > > > >WAIT #31: nam='SQL*Net message to client' ela= > 1 > > > p1=1413697536 p2=1 > > > p3=0 >FETCH > > > > > > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > > > >WAIT #31: nam='SQL*Net message from client' > ela= > > > 2295 p1=1413697536 > > > p2=1 p3=0 > > > > > > > > > > Boris, "SQL*Net message..." events are > > > "between-call" events. Their > > > times are not included in the following dbcall's > > > elapsed time. But it > > > *is* appropriate to "blame" the dbcall that > > follows > > > for the time > > > consumed by the
Re: sql trace - forward attribution
Oracle Portal uses session switching as well (and Apps 11i uses Portal...) Tanel. - Original Message - To: "Multiple recipients of list ORACLE-L" <[EMAIL PROTECTED]> Sent: Monday, January 05, 2004 7:49 PM > > > Cursor 0 also happens in oracle due to session switching (multiple > sessions in the same process), oracle apps uses that but it also could > happen with certain other application servers (haven't investigated it). > > Anjo. > > > -Original Message- > Boris Dali > Sent: Monday, January 05, 2004 3:59 PM > To: Multiple recipients of list ORACLE-L > > > Thanks, Cary. > > Could you elaborate what do you mean by "wait events > associated with COMMIT processing"? Why does Oracle > need this "exchange of messages" with the client > (well, with the app server really in my case of a > 3-tier deployment) to perform a commit? > > > In any event, as I described earlier in my case I > think Cursor #0 doesn't fall in neither of the two > uses you mentioned. > > Bug 2425312 is RPC related as I understand. I don't > work distributed (single DB) and app server (and > clients - thin) don't have their own SQL engine, so > all SQL processing is happening strictly on the DB > server. So this doesn't seem to apply to me. > > And I see Cursor #0 used with no commits/rollbacks as > part of one Oracle transaction. > > > I see these WAIT #0 flying back and forth between DB > and the app server sometimes 20 times just before > stored procs are called and I can't figure out why. > Another bug? > > Thank you, > Boris Dali. > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > Boris, > > > > Cursor #0 seems reserved for two special uses: (1) > > wait events > > associated with COMMIT processing (also, of course, > > ROLLBACK and > > SAVEPOINT), and (2) wait events associated with > > dbcalls not instrumented > > because of bug 2425312. > > > > > > Cary Millsap > > Hotsos Enterprises, Ltd. > > http://www.hotsos.com > > > > Upcoming events: > > - Performance Diagnosis 101: 1/27 Atlanta > > - SQL Optimization 101: 2/16 Dallas > > - Hotsos Symposium 2004: March 7-10 Dallas > > - Visit www.hotsos.com for schedule details... > > > > > > -Original Message- > > Boris Dali > > Sent: Thursday, January 01, 2004 10:29 AM > > To: Multiple recipients of list ORACLE-L > > > > Thanks a lot for your reply, Cary. > > > > One follow-up question. What would motivate "a chat" > > of sometimes 5, sometimes 10-20 'SQL*Net message > > to/from client' consecutive wait lines emitted to > > the > > trace file in the following manner: > > > > WAIT #0: nam='SQL*Net message to client' ela= 2 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= 678 p1=1413697536 p2=1 > > > p3=0 WAIT #0: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= 3463 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > WAIT #0: nam='SQL*Net message from client' ela= 3322 > > p1=1413697536 p2=1 p3=0 > > > > > > I see this pattern of "message exchanges" before > > calling a stored code from the app server (OCI), so > > using forward attribution it is a call to a stored > > code that it to blame correct? > > I can't of course eliminate a call to a stored code > > but is there something that can be done to minimize > > amount of these 'SQL*Net message...' lines? While > > the > > latency of these waits is low, these 3-5 > > milliseconds > > get accumulated slowly, but surely. > > > > Also does cursor #0 has some special meaning in > > traces? I can't seem to create a test-case where I > > get > > cursor #0 emitted for me and yet tracing real > > applications I see it all over (like in the excerpt > > above) > > > > > > I guess I have more than one follow-up question :-( > > > > Thanks, > > Boris Dali. > > > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > > p1=1413697536 p2=1 p3=0 > > > >WAIT #31: nam='SQL*Net message from client' ela= > > > 692 p1=1413697536 p2=1 > > > p3=0 > > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > > p1=1413697536 p2=1 > > > p3=0 >FETCH > > > > > > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > > > >WAIT #31: nam='SQL*Net message from client' ela= > > > 2295 p1=1413697536 > > > p2=1 p3=0 > > > > > > > > > > Boris, "SQL*Net message..." events are > > > "between-call" events. Their > > > times are not included in the following dbcall's > > > elapsed time. But it > > > *is* appropriate to "blame" the dbcall that > > follows > > > for the time > > > consumed by the event. That is, if you can > > eliminate > > > the dbcall that > > > follows, then you can eliminate the between-call > > > event (and its elapsed > > > time). The "assignment of blame" is what "forward attribution" is > > > about. > > > > > > > > > Cary Millsap > > > Hotsos Enterpri
RE: sql trace - forward attribution
Cursor 0 also happens in oracle due to session switching (multiple sessions in the same process), oracle apps uses that but it also could happen with certain other application servers (haven't investigated it). Anjo. -Original Message- Boris Dali Sent: Monday, January 05, 2004 3:59 PM To: Multiple recipients of list ORACLE-L Thanks, Cary. Could you elaborate what do you mean by "wait events associated with COMMIT processing"? Why does Oracle need this "exchange of messages" with the client (well, with the app server really in my case of a 3-tier deployment) to perform a commit? In any event, as I described earlier in my case I think Cursor #0 doesn't fall in neither of the two uses you mentioned. Bug 2425312 is RPC related as I understand. I don't work distributed (single DB) and app server (and clients - thin) don't have their own SQL engine, so all SQL processing is happening strictly on the DB server. So this doesn't seem to apply to me. And I see Cursor #0 used with no commits/rollbacks as part of one Oracle transaction. I see these WAIT #0 flying back and forth between DB and the app server sometimes 20 times just before stored procs are called and I can't figure out why. Another bug? Thank you, Boris Dali. --- Cary Millsap <[EMAIL PROTECTED]> wrote: > Boris, > > Cursor #0 seems reserved for two special uses: (1) > wait events > associated with COMMIT processing (also, of course, > ROLLBACK and > SAVEPOINT), and (2) wait events associated with > dbcalls not instrumented > because of bug 2425312. > > > Cary Millsap > Hotsos Enterprises, Ltd. > http://www.hotsos.com > > Upcoming events: > - Performance Diagnosis 101: 1/27 Atlanta > - SQL Optimization 101: 2/16 Dallas > - Hotsos Symposium 2004: March 7-10 Dallas > - Visit www.hotsos.com for schedule details... > > > -Original Message- > Boris Dali > Sent: Thursday, January 01, 2004 10:29 AM > To: Multiple recipients of list ORACLE-L > > Thanks a lot for your reply, Cary. > > One follow-up question. What would motivate "a chat" > of sometimes 5, sometimes 10-20 'SQL*Net message > to/from client' consecutive wait lines emitted to > the > trace file in the following manner: > > WAIT #0: nam='SQL*Net message to client' ela= 2 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 678 p1=1413697536 p2=1 > p3=0 WAIT #0: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 3463 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 3322 > p1=1413697536 p2=1 p3=0 > > > I see this pattern of "message exchanges" before > calling a stored code from the app server (OCI), so > using forward attribution it is a call to a stored > code that it to blame correct? > I can't of course eliminate a call to a stored code > but is there something that can be done to minimize > amount of these 'SQL*Net message...' lines? While > the > latency of these waits is low, these 3-5 > milliseconds > get accumulated slowly, but surely. > > Also does cursor #0 has some special meaning in > traces? I can't seem to create a test-case where I > get > cursor #0 emitted for me and yet tracing real > applications I see it all over (like in the excerpt > above) > > > I guess I have more than one follow-up question :-( > > Thanks, > Boris Dali. > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > >WAIT #31: nam='SQL*Net message from client' ela= > > 692 p1=1413697536 p2=1 > > p3=0 > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 > > p3=0 >FETCH > > > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > > >WAIT #31: nam='SQL*Net message from client' ela= > > 2295 p1=1413697536 > > p2=1 p3=0 > > > > > > > Boris, "SQL*Net message..." events are > > "between-call" events. Their > > times are not included in the following dbcall's > > elapsed time. But it > > *is* appropriate to "blame" the dbcall that > follows > > for the time > > consumed by the event. That is, if you can > eliminate > > the dbcall that > > follows, then you can eliminate the between-call > > event (and its elapsed > > time). The "assignment of blame" is what "forward attribution" is > > about. > > > > > > Cary Millsap > > Hotsos Enterprises, Ltd. > > http://www.hotsos.com > > > > Upcoming events: > > - Performance Diagnosis 101: 1/27 Atlanta > > - SQL Optimization 101: 2/16 Dallas > > - Hotsos Symposium 2004: March 7-10 Dallas > > - Visit www.hotsos.com for schedule details... > > > > > > -Original Message- > > Boris Dali > > Sent: Monday, December 29, 2003 9:39 AM > > To: Multiple recipients of list ORACLE-L > > > > I don't have the book with me right now, but I am > > obviously missing something in the "forward > > attribution" concept as it doe
RE: sql trace - forward attribution
In-line... Cary Millsap Hotsos Enterprises, Ltd. http://www.hotsos.com Upcoming events: - Performance Diagnosis 101: 1/27 Atlanta - SQL Optimization 101: 2/16 Dallas - Hotsos Symposium 2004: March 7-10 Dallas - Visit www.hotsos.com for schedule details... -Original Message- Boris Dali Sent: Monday, January 05, 2004 8:59 AM To: Multiple recipients of list ORACLE-L Thanks, Cary. Could you elaborate what do you mean by "wait events associated with COMMIT processing"? Why does Oracle need this "exchange of messages" with the client (well, with the app server really in my case of a 3-tier deployment) to perform a commit? [Cary Millsap] The event most often associated with COMMIT processing that is attributed to cursor #0 is 'log file sync'. In any event, as I described earlier in my case I think Cursor #0 doesn't fall in neither of the two uses you mentioned. Bug 2425312 is RPC related as I understand. I don't work distributed (single DB) and app server (and clients - thin) don't have their own SQL engine, so all SQL processing is happening strictly on the DB server. So this doesn't seem to apply to me. [Cary Millsap] Oracle Forms and one of Oracle's report writers (I forget the name) trigger this bug). And I see Cursor #0 used with no commits/rollbacks as part of one Oracle transaction. I see these WAIT #0 flying back and forth between DB and the app server sometimes 20 times just before stored procs are called and I can't figure out why. Another bug? [Cary Millsap] I'm very curious, too. I don't know the answer. Can you produce a minimal test case that reproduces the behavior? Thank you, Boris Dali. --- Cary Millsap <[EMAIL PROTECTED]> wrote: > Boris, > > Cursor #0 seems reserved for two special uses: (1) > wait events > associated with COMMIT processing (also, of course, > ROLLBACK and > SAVEPOINT), and (2) wait events associated with > dbcalls not instrumented > because of bug 2425312. > > > Cary Millsap > Hotsos Enterprises, Ltd. > http://www.hotsos.com > > Upcoming events: > - Performance Diagnosis 101: 1/27 Atlanta > - SQL Optimization 101: 2/16 Dallas > - Hotsos Symposium 2004: March 7-10 Dallas > - Visit www.hotsos.com for schedule details... > > > -Original Message- > Boris Dali > Sent: Thursday, January 01, 2004 10:29 AM > To: Multiple recipients of list ORACLE-L > > Thanks a lot for your reply, Cary. > > One follow-up question. What would motivate "a chat" > of sometimes 5, sometimes 10-20 'SQL*Net message > to/from client' consecutive wait lines emitted to > the > trace file in the following manner: > > WAIT #0: nam='SQL*Net message to client' ela= 2 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 678 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 3463 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 3322 > p1=1413697536 p2=1 p3=0 > > > I see this pattern of "message exchanges" before > calling a stored code from the app server (OCI), so > using forward attribution it is a call to a stored > code that it to blame correct? > I can't of course eliminate a call to a stored code > but is there something that can be done to minimize > amount of these 'SQL*Net message...' lines? While > the > latency of these waits is low, these 3-5 > milliseconds > get accumulated slowly, but surely. > > Also does cursor #0 has some special meaning in > traces? I can't seem to create a test-case where I > get > cursor #0 emitted for me and yet tracing real > applications I see it all over (like in the excerpt > above) > > > I guess I have more than one follow-up question :-( > > Thanks, > Boris Dali. > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > >WAIT #31: nam='SQL*Net message from client' ela= > > 692 p1=1413697536 p2=1 > > p3=0 > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 > > p3=0 >FETCH > > > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > > >WAIT #31: nam='SQL*Net message from client' ela= > > 2295 p1=1413697536 > > p2=1 p3=0 > > > > > > > Boris, "SQL*Net message..." events are > > "between-call" events. Their > > times are not included in the following dbcall's > > elapsed time. But it > > *is* appropriate to "blame" the dbcall that > follows > > for the time > > consumed by the event. That is, if you can > eliminate > > the dbcall that > > follows, then you can eliminate the between-call > > event (and its elapsed > > time). The "assignment of blame" is what "forward > > attribution" is about. > > > > > > Cary Millsap > > Hotsos Enterprises, Ltd. > > http://www.hotsos.com > > > > Upcoming events: > > - Performance Diagnosis 101: 1/27 Atlanta > > - SQL Optimization 101: 2
RE: sql trace - forward attribution
Thanks, Cary. Could you elaborate what do you mean by "wait events associated with COMMIT processing"? Why does Oracle need this "exchange of messages" with the client (well, with the app server really in my case of a 3-tier deployment) to perform a commit? In any event, as I described earlier in my case I think Cursor #0 doesn't fall in neither of the two uses you mentioned. Bug 2425312 is RPC related as I understand. I don't work distributed (single DB) and app server (and clients - thin) don't have their own SQL engine, so all SQL processing is happening strictly on the DB server. So this doesn't seem to apply to me. And I see Cursor #0 used with no commits/rollbacks as part of one Oracle transaction. I see these WAIT #0 flying back and forth between DB and the app server sometimes 20 times just before stored procs are called and I can't figure out why. Another bug? Thank you, Boris Dali. --- Cary Millsap <[EMAIL PROTECTED]> wrote: > Boris, > > Cursor #0 seems reserved for two special uses: (1) > wait events > associated with COMMIT processing (also, of course, > ROLLBACK and > SAVEPOINT), and (2) wait events associated with > dbcalls not instrumented > because of bug 2425312. > > > Cary Millsap > Hotsos Enterprises, Ltd. > http://www.hotsos.com > > Upcoming events: > - Performance Diagnosis 101: 1/27 Atlanta > - SQL Optimization 101: 2/16 Dallas > - Hotsos Symposium 2004: March 7-10 Dallas > - Visit www.hotsos.com for schedule details... > > > -Original Message- > Boris Dali > Sent: Thursday, January 01, 2004 10:29 AM > To: Multiple recipients of list ORACLE-L > > Thanks a lot for your reply, Cary. > > One follow-up question. What would motivate "a chat" > of sometimes 5, sometimes 10-20 'SQL*Net message > to/from client' consecutive wait lines emitted to > the > trace file in the following manner: > > WAIT #0: nam='SQL*Net message to client' ela= 2 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 678 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 3463 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #0: nam='SQL*Net message from client' ela= 3322 > p1=1413697536 p2=1 p3=0 > > > I see this pattern of "message exchanges" before > calling a stored code from the app server (OCI), so > using forward attribution it is a call to a stored > code that it to blame correct? > I can't of course eliminate a call to a stored code > but is there something that can be done to minimize > amount of these 'SQL*Net message...' lines? While > the > latency of these waits is low, these 3-5 > milliseconds > get accumulated slowly, but surely. > > Also does cursor #0 has some special meaning in > traces? I can't seem to create a test-case where I > get > cursor #0 emitted for me and yet tracing real > applications I see it all over (like in the excerpt > above) > > > I guess I have more than one follow-up question :-( > > Thanks, > Boris Dali. > > --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > >WAIT #31: nam='SQL*Net message from client' ela= > > 692 p1=1413697536 p2=1 > > p3=0 > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 > > p3=0 >FETCH > > > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > > >WAIT #31: nam='SQL*Net message from client' ela= > > 2295 p1=1413697536 > > p2=1 p3=0 > > > > > > > Boris, "SQL*Net message..." events are > > "between-call" events. Their > > times are not included in the following dbcall's > > elapsed time. But it > > *is* appropriate to "blame" the dbcall that > follows > > for the time > > consumed by the event. That is, if you can > eliminate > > the dbcall that > > follows, then you can eliminate the between-call > > event (and its elapsed > > time). The "assignment of blame" is what "forward > > attribution" is about. > > > > > > Cary Millsap > > Hotsos Enterprises, Ltd. > > http://www.hotsos.com > > > > Upcoming events: > > - Performance Diagnosis 101: 1/27 Atlanta > > - SQL Optimization 101: 2/16 Dallas > > - Hotsos Symposium 2004: March 7-10 Dallas > > - Visit www.hotsos.com for schedule details... > > > > > > -Original Message- > > Boris Dali > > Sent: Monday, December 29, 2003 9:39 AM > > To: Multiple recipients of list ORACLE-L > > > > I don't have the book with me right now, but I am > > obviously missing something in the "forward > > attribution" concept as it doesn't seem to help me > > in > > explanation of the following lines: > > > > > > WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > WAIT #31: nam='SQL*Net message from client' ela= > 692 > > p1=1413697536 p2=1 p3=0 > > WAIT #31: nam='SQL*Net message to client' ela= 1 > > p1=1413697536 p2=1 p3=0 > > FETCH
RE: sql trace - forward attribution
Boris, Cursor #0 seems reserved for two special uses: (1) wait events associated with COMMIT processing (also, of course, ROLLBACK and SAVEPOINT), and (2) wait events associated with dbcalls not instrumented because of bug 2425312. Cary Millsap Hotsos Enterprises, Ltd. http://www.hotsos.com Upcoming events: - Performance Diagnosis 101: 1/27 Atlanta - SQL Optimization 101: 2/16 Dallas - Hotsos Symposium 2004: March 7-10 Dallas - Visit www.hotsos.com for schedule details... -Original Message- Boris Dali Sent: Thursday, January 01, 2004 10:29 AM To: Multiple recipients of list ORACLE-L Thanks a lot for your reply, Cary. One follow-up question. What would motivate "a chat" of sometimes 5, sometimes 10-20 'SQL*Net message to/from client' consecutive wait lines emitted to the trace file in the following manner: WAIT #0: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message from client' ela= 678 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message from client' ela= 3463 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message from client' ela= 3322 p1=1413697536 p2=1 p3=0 I see this pattern of "message exchanges" before calling a stored code from the app server (OCI), so using forward attribution it is a call to a stored code that it to blame correct? I can't of course eliminate a call to a stored code but is there something that can be done to minimize amount of these 'SQL*Net message...' lines? While the latency of these waits is low, these 3-5 milliseconds get accumulated slowly, but surely. Also does cursor #0 has some special meaning in traces? I can't seem to create a test-case where I get cursor #0 emitted for me and yet tracing real applications I see it all over (like in the excerpt above) I guess I have more than one follow-up question :-( Thanks, Boris Dali. --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > >WAIT #31: nam='SQL*Net message from client' ela= > 692 p1=1413697536 p2=1 > p3=0 > >WAIT #31: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 > p3=0 >FETCH > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > >WAIT #31: nam='SQL*Net message from client' ela= > 2295 p1=1413697536 > p2=1 p3=0 > > > > Boris, "SQL*Net message..." events are > "between-call" events. Their > times are not included in the following dbcall's > elapsed time. But it > *is* appropriate to "blame" the dbcall that follows > for the time > consumed by the event. That is, if you can eliminate > the dbcall that > follows, then you can eliminate the between-call > event (and its elapsed > time). The "assignment of blame" is what "forward > attribution" is about. > > > Cary Millsap > Hotsos Enterprises, Ltd. > http://www.hotsos.com > > Upcoming events: > - Performance Diagnosis 101: 1/27 Atlanta > - SQL Optimization 101: 2/16 Dallas > - Hotsos Symposium 2004: March 7-10 Dallas > - Visit www.hotsos.com for schedule details... > > > -Original Message- > Boris Dali > Sent: Monday, December 29, 2003 9:39 AM > To: Multiple recipients of list ORACLE-L > > I don't have the book with me right now, but I am > obviously missing something in the "forward > attribution" concept as it doesn't seem to help me > in > explanation of the following lines: > > > WAIT #31: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #31: nam='SQL*Net message from client' ela= 692 > p1=1413697536 p2=1 p3=0 > WAIT #31: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > FETCH > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > WAIT #31: nam='SQL*Net message from client' ela= > 2295 > p1=1413697536 p2=1 p3=0 > > > Shouldn't 1 + 692 + 1 (and possibly + 2295 ???) be > less than 261? > > Oracle 9.2.0.4.0 on HP-UX 11.11 > > Thanks, > Boris Dali. > > __ > > Post your free ad now! http://personals.yahoo.ca > -- > Please see the official ORACLE-L FAQ: > http://www.orafaq.net > -- > Author: Boris Dali > INET: [EMAIL PROTECTED] > > Fat City Network Services-- 858-538-5051 > http://www.fatcity.com > San Diego, California-- Mailing list and web > hosting services > - > To REMOVE yourself from this mailing list, send an > E-Mail message > to: [EMAIL PROTECTED] (note EXACT spelling of > 'ListGuru') and in > the message BODY, include a line containing: UNSUB > ORACLE-L > (or the name of mailing list you want to be removed > from). You may > also send the HELP command for other information > (like subscribing). > > -- > Please see the official ORACLE-L FAQ: > http://www.orafaq.net > -- > Author: Cary Millsap > INET:
RE: sql trace - forward attribution
Thanks a lot for your reply, Cary. One follow-up question. What would motivate "a chat" of sometimes 5, sometimes 10-20 'SQL*Net message to/from client' consecutive wait lines emitted to the trace file in the following manner: WAIT #0: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message from client' ela= 678 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message from client' ela= 3463 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0 WAIT #0: nam='SQL*Net message from client' ela= 3322 p1=1413697536 p2=1 p3=0 I see this pattern of "message exchanges" before calling a stored code from the app server (OCI), so using forward attribution it is a call to a stored code that it to blame correct? I can't of course eliminate a call to a stored code but is there something that can be done to minimize amount of these 'SQL*Net message...' lines? While the latency of these waits is low, these 3-5 milliseconds get accumulated slowly, but surely. Also does cursor #0 has some special meaning in traces? I can't seem to create a test-case where I get cursor #0 emitted for me and yet tracing real applications I see it all over (like in the excerpt above) I guess I have more than one follow-up question :-( Thanks, Boris Dali. --- Cary Millsap <[EMAIL PROTECTED]> wrote: > > > >WAIT #31: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > >WAIT #31: nam='SQL*Net message from client' ela= > 692 p1=1413697536 p2=1 > p3=0 > >WAIT #31: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 > p3=0 >FETCH > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > >WAIT #31: nam='SQL*Net message from client' ela= > 2295 p1=1413697536 > p2=1 p3=0 > > > > Boris, "SQL*Net message..." events are > "between-call" events. Their > times are not included in the following dbcall's > elapsed time. But it > *is* appropriate to "blame" the dbcall that follows > for the time > consumed by the event. That is, if you can eliminate > the dbcall that > follows, then you can eliminate the between-call > event (and its elapsed > time). The "assignment of blame" is what "forward > attribution" is about. > > > Cary Millsap > Hotsos Enterprises, Ltd. > http://www.hotsos.com > > Upcoming events: > - Performance Diagnosis 101: 1/27 Atlanta > - SQL Optimization 101: 2/16 Dallas > - Hotsos Symposium 2004: March 7-10 Dallas > - Visit www.hotsos.com for schedule details... > > > -Original Message- > Boris Dali > Sent: Monday, December 29, 2003 9:39 AM > To: Multiple recipients of list ORACLE-L > > I don't have the book with me right now, but I am > obviously missing something in the "forward > attribution" concept as it doesn't seem to help me > in > explanation of the following lines: > > > WAIT #31: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > WAIT #31: nam='SQL*Net message from client' ela= 692 > p1=1413697536 p2=1 p3=0 > WAIT #31: nam='SQL*Net message to client' ela= 1 > p1=1413697536 p2=1 p3=0 > FETCH > #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 > WAIT #31: nam='SQL*Net message from client' ela= > 2295 > p1=1413697536 p2=1 p3=0 > > > Shouldn't 1 + 692 + 1 (and possibly + 2295 ???) be > less than 261? > > Oracle 9.2.0.4.0 on HP-UX 11.11 > > Thanks, > Boris Dali. > > __ > > Post your free ad now! http://personals.yahoo.ca > -- > Please see the official ORACLE-L FAQ: > http://www.orafaq.net > -- > Author: Boris Dali > INET: [EMAIL PROTECTED] > > Fat City Network Services-- 858-538-5051 > http://www.fatcity.com > San Diego, California-- Mailing list and web > hosting services > - > To REMOVE yourself from this mailing list, send an > E-Mail message > to: [EMAIL PROTECTED] (note EXACT spelling of > 'ListGuru') and in > the message BODY, include a line containing: UNSUB > ORACLE-L > (or the name of mailing list you want to be removed > from). You may > also send the HELP command for other information > (like subscribing). > > -- > Please see the official ORACLE-L FAQ: > http://www.orafaq.net > -- > Author: Cary Millsap > INET: [EMAIL PROTECTED] > > Fat City Network Services-- 858-538-5051 > http://www.fatcity.com > San Diego, California-- Mailing list and web > hosting services > - > To REMOVE yourself from this mailing list, send an > E-Mail message > to: [EMAIL PROTECTED] (note EXACT spelling of > 'ListGuru') and in > the message BODY, include a line containing: UNSUB > ORACLE-L > (or the name of mailing list you want to be removed > from). You may > also send the HELP command for other information > (like subscribing).
RE: sql trace - forward attribution
> >WAIT #31: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0 >WAIT #31: nam='SQL*Net message from client' ela= 692 p1=1413697536 p2=1 p3=0 >WAIT #31: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0 >FETCH #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 >WAIT #31: nam='SQL*Net message from client' ela= 2295 p1=1413697536 p2=1 p3=0 > Boris, "SQL*Net message..." events are "between-call" events. Their times are not included in the following dbcall's elapsed time. But it *is* appropriate to "blame" the dbcall that follows for the time consumed by the event. That is, if you can eliminate the dbcall that follows, then you can eliminate the between-call event (and its elapsed time). The "assignment of blame" is what "forward attribution" is about. Cary Millsap Hotsos Enterprises, Ltd. http://www.hotsos.com Upcoming events: - Performance Diagnosis 101: 1/27 Atlanta - SQL Optimization 101: 2/16 Dallas - Hotsos Symposium 2004: March 7-10 Dallas - Visit www.hotsos.com for schedule details... -Original Message- Boris Dali Sent: Monday, December 29, 2003 9:39 AM To: Multiple recipients of list ORACLE-L I don't have the book with me right now, but I am obviously missing something in the "forward attribution" concept as it doesn't seem to help me in explanation of the following lines: WAIT #31: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0 WAIT #31: nam='SQL*Net message from client' ela= 692 p1=1413697536 p2=1 p3=0 WAIT #31: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0 FETCH #31:c=0,e=261,p=0,cr=7,cu=0,mis=0,r=4,dep=0,og=4,tim=2001475650589 WAIT #31: nam='SQL*Net message from client' ela= 2295 p1=1413697536 p2=1 p3=0 Shouldn't 1 + 692 + 1 (and possibly + 2295 ???) be less than 261? Oracle 9.2.0.4.0 on HP-UX 11.11 Thanks, Boris Dali. __ Post your free ad now! http://personals.yahoo.ca -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Boris Dali INET: [EMAIL PROTECTED] Fat City Network Services-- 858-538-5051 http://www.fatcity.com San Diego, California-- Mailing list and web hosting services - To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing). -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Cary Millsap INET: [EMAIL PROTECTED] Fat City Network Services-- 858-538-5051 http://www.fatcity.com San Diego, California-- Mailing list and web hosting services - To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).
