FAQ
Hi

Can anybody explain the events like
SQL*Net message from client,rdbms ipc message
PX Idle Wait,slave wait ...

Can I assume a i/o bottleneck from the following
statistics as most of the i/o events are having high
wait time.

select * from v$system_event
order by TIME_WAITED;

The last few entries are as follows.....

EVENT TOTAL_WAITS

TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT

SQL*Net more data to client 888137 0 12365
0.013922402
db file parallel write 2445 0 17606
7.200818
db file scattered read 7823 0 18336
2.34385786
db file sequential read 27779 0 55490
1.99755211
control file parallel write 27194 0 70593
2.59590351

log file sync 29700 1 145295
4.89208754
log file parallel write 30511 2 146311
4.7953525
io done 35551 567 270796
7.61711344
smon timer 278 273 8404285
30231.241
pmon timer 27350 27349
8413237 307.613784
SQL*Net message from client 498526 0 17655561
35.415527
rdbms ipc message 112693 80775
33193981 294.552288
PX Idle Wait 164145 164139
33650049 205.001974
slave wait 433146 392872
40839651 94.2861091

Regards
Bhulu

Do You Yahoo!?
LAUNCH - Your Yahoo! Music Experience
http://launch.yahoo.com
--
Please see the official ORACLE-L FAQ: http://www.orafaq.com
--
Author: S B
INET: bhulubhuli_at_yahoo.com

Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
San Diego, California -- Public Internet access / Mailing Lists
--------------------------------------------------------------------

To REMOVE yourself from this mailing list, send an E-Mail message
to: ListGuru_at_fatcity.com (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).

Search Discussions

  • Greg Moore at May 16, 2002 at 10:03 am

    Can I assume a i/o bottleneck from the following

    select * from v$system_event
    order by TIME_WAITED;
    No. Wait events may only make up a small amount of processing that Oracle
    is doing for you.

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Greg Moore
    INET: sqlgreg_at_pacbell.net

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Hately Mike at May 16, 2002 at 10:14 am
    Hi,
    far better than getting individual descriptions is to research for yourself
    (this isn't an RTFM message honestly).
    Good sources of information for this subject are Anjo Kolk's excellent
    document on wait events and enqueues
    (http://www.dbatoolbox.com/WP2001/dbamisc/events.pdf) and the Oracle
    documentation set, specifically the Oracle Server Reference (Appendix A I
    think), wait events.

    Cheers,
    Mike

    -----Original Message-----
    Sent: 16 May 2002 10:33
    To: Multiple recipients of list ORACLE-L

    Hi

    Can anybody explain the events like
    SQL*Net message from client,rdbms ipc message
    PX Idle Wait,slave wait ...

    Can I assume a i/o bottleneck from the following
    statistics as most of the i/o events are having high
    wait time.

    select * from v$system_event
    order by TIME_WAITED;

    The last few entries are as follows.....

    EVENT TOTAL_WAITS

    TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT

    SQL*Net more data to client 888137 0 12365
    0.013922402
    db file parallel write 2445 0 17606
    7.200818
    db file scattered read 7823 0 18336
    2.34385786
    db file sequential read 27779 0 55490
    1.99755211
    control file parallel write 27194 0 70593
    2.59590351

    log file sync 29700 1 145295
    4.89208754
    log file parallel write 30511 2 146311
    4.7953525
    io done 35551 567 270796
    7.61711344
    smon timer 278 273 8404285
    30231.241
    pmon timer 27350 27349
    8413237 307.613784
    SQL*Net message from client 498526 0 17655561
    35.415527
    rdbms ipc message 112693 80775
    33193981 294.552288
    PX Idle Wait 164145 164139
    33650049 205.001974
    slave wait 433146 392872
    40839651 94.2861091

    Regards
    Bhulu



    This email and any attached to it are confidential and intended only for the
    individual or
    entity to which it is addressed. If you are not the intended recipient,
    please let us know
    by telephoning or emailing the sender. You should also delete the email and
    any attachment
    from your systems and should not copy the email or any attachment or
    disclose their content
    to any other person or entity. The views expressed here are not necessarily
    those of
    Churchill Insurance Group plc or its affiliates or subsidiaries. Thank you.
    Churchill Insurance Group plc. Company Registration Number - 2280426.
    England.
    Registered Office: Churchill Court, Westmoreland Road, Bromley, Kent BR1
    1DP.

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Hately Mike
    INET: Mike.Hately_at_churchill.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • John Kanagaraj at May 16, 2002 at 9:39 pm
    Greg,
    Can I assume a i/o bottleneck from the following

    select * from v$system_event
    order by TIME_WAITED;
    No. Wait events may only make up a small amount of
    processing that Oracle
    is doing for you.
    Hmm.... I wouldn't think so. If there were just _one_ overall view that I
    could check to determine an Oracle bottleneck, it would be this view. A
    rollup of V$SESSION_WAIT is also effective in determining the _current_
    bottleneck.

    As to the original question: (And as with many other questions) It depends!
    The average_wait times displayed by V$SYSTEM_EVENT against specific events
    is a good indication of the 'bottleneck'. Just yesterday, I was debugging
    'slow response' from a test database. The top wait events were for 'direct
    path read' and 'direct path write', with inordinate values for AV_WAIT (upto
    932 CS or 9 secs!). This clearly pointed to some misconfigured Async I/O (It
    was on a Sun box where async_io default to TRUE). I then had the SA look at
    the Async config and it turns out that the Veritas layer was misconfigured -
    hopefully this has been sorted out. There have been numerous other examples
    - and I am not alone here - where DBAs have used V$SYSTEM_EVENT to determine
    the bottleneck. If I were 'S B', I would look at the avarage wait values for
    I/O and compare them to the manufacturer's claims. If they don't match or or
    not close, then it _may_ be an I/O bottleneck.

    I would recommend purchasing (or even stoop to the level of purloining a
    copy from a friend!) the most excellent 'Oracle Performance Tuning 101' book
    written by Gaja and Kirti from this list. This question is dealt in great
    detail therein, and I am sure they would be happy to answer any further
    queries.

    John Kanagaraj
    Oracle Applications DBA
    DBSoft Inc
    (W): 408-970-7002

    The manuals for Oracle are here: http://tahiti.oracle.com
    The manual for Life is here: http://www.gospelcom.net

    The opinions and statements above are entirely my own and not those of my
    employer or clients **

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: John Kanagaraj
    INET: john.kanagaraj_at_hds.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Greg Moore at May 16, 2002 at 11:18 pm
    John,
    Hmm.... I wouldn't think so. If there were just _one_ overall view that I
    could check to determine an Oracle bottleneck, it would be this view.
    Maybe not one, but what about two? At the same time v$system_event is
    checked a couple of times, so you can see a time slice, v$sysstat can be
    checked, focusing on CPU used by this session, parse time cpu and recursive
    cpu usage. One view gives wait time, one gives CPU time.

    The absolute values from v$system_event are meaningful as relative values
    when compared with the three from v$sysstat. If most time is spent on CPU
    (say 95%) then the waits, while they are there, might not deserve to be
    called a bottleneck. If you manage to reduce them by 50%, you've only
    improved performance by two or three percent. Waits may have been reduced
    by 50%, but users probably won't even notice. Of course, if waits are
    95%....

    The issue today seems to be how to treat the three v$sysstat values. Some
    say CPU used by this session is the true measure of total CPU, yet I have a
    database where recursive cpu usage is 4x bigger than CPU used by this
    session. That apparently happens because plain SQL time is recorded in CPU
    used by this session, but SQL inside PL/SQL is recorded in recursive cpu
    usage.

    Sending a StatsPack through oraperf and figuring out how the first section
    (Response Breakdown) uses the three values from v$sysstat reveals Anjo
    Kolk's thinking on this....

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Greg Moore
    INET: sqlgreg_at_pacbell.net

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • John Kanagaraj at May 20, 2002 at 11:33 pm
    Hi Greg,
    Maybe not one, but what about two? At the same time v$system_event is
    checked a couple of times, so you can see a time slice,
    v$sysstat can be
    checked, focusing on CPU used by this session, parse time cpu
    and recursive
    cpu usage. One view gives wait time, one gives CPU time.
    There is a lot to be said about using V$SYSSTAT too. The point is that the
    CHR is derived out of V$SYSSTAT and hence one needs to be careful. Also,
    some of the values in V$SYSSTAT have meaning only in V$SESSTAT.... A lot can
    be deduced from sesstat, and the real interesting ones such as V$ROWCACHE
    haven't been explored to their fullest depths yet. I think the point I was
    trying to get across was that V$SYSTEM_EVENT is a good place to start, not
    neccessarily the only view....

    John Kanagaraj

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: John Kanagaraj
    INET: john.kanagaraj_at_hds.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Anjo Kolk at May 21, 2002 at 1:48 am
    Download the YAPP paper;-)

    Anjo.

    John Kanagaraj wrote:
    Greg,
    Can I assume a i/o bottleneck from the following

    select * from v$system_event
    order by TIME_WAITED;
    No. Wait events may only make up a small amount of
    processing that Oracle
    is doing for you.
    Hmm.... I wouldn't think so. If there were just _one_ overall view that I
    could check to determine an Oracle bottleneck, it would be this view. A
    rollup of V$SESSION_WAIT is also effective in determining the _current_
    bottleneck.

    As to the original question: (And as with many other questions) It depends!
    The average_wait times displayed by V$SYSTEM_EVENT against specific events
    is a good indication of the 'bottleneck'. Just yesterday, I was debugging
    'slow response' from a test database. The top wait events were for 'direct
    path read' and 'direct path write', with inordinate values for AV_WAIT (upto
    932 CS or 9 secs!). This clearly pointed to some misconfigured Async I/O (It
    was on a Sun box where async_io default to TRUE). I then had the SA look at
    the Async config and it turns out that the Veritas layer was misconfigured -
    hopefully this has been sorted out. There have been numerous other examples
    - and I am not alone here - where DBAs have used V$SYSTEM_EVENT to determine
    the bottleneck. If I were 'S B', I would look at the avarage wait values for
    I/O and compare them to the manufacturer's claims. If they don't match or or
    not close, then it _may_ be an I/O bottleneck.

    I would recommend purchasing (or even stoop to the level of purloining a
    copy from a friend!) the most excellent 'Oracle Performance Tuning 101' book
    written by Gaja and Kirti from this list. This question is dealt in great
    detail therein, and I am sure they would be happy to answer any further
    queries.

    John Kanagaraj
    Oracle Applications DBA
    DBSoft Inc
    (W): 408-970-7002

    The manuals for Oracle are here: http://tahiti.oracle.com
    The manual for Life is here: http://www.gospelcom.net

    ** The opinions and statements above are entirely my own and not those of my
    employer or clients **

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: John Kanagaraj
    INET: john.kanagaraj_at_hds.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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.com
    --
    Author: Anjo Kolk
    INET: anjo_at_oraperf.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Anjo Kolk at May 21, 2002 at 1:48 am
    In short:

    Oracle is either using CPU or is waiting on a resource.
    If oracle is waiting on a resource, it could be an Oracle event
    (v$system_event/v$session_event), BUT what about waits that are not registered there
    ..... like
    waiting for CPU, waiting for a memory page to be paged in ......

    So just looking at v$system_event is dangerous. Looking v$system_event and v$sysstat
    is much better but still not perfect. The third way is ....... (mail me;-))

    Anjo.

    S B wrote:
    Hi

    Can anybody explain the events like
    SQL*Net message from client,rdbms ipc message
    PX Idle Wait,slave wait ...

    Can I assume a i/o bottleneck from the following
    statistics as most of the i/o events are having high
    wait time.

    select * from v$system_event
    order by TIME_WAITED;

    The last few entries are as follows.....

    EVENT TOTAL_WAITS
    TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT
    -----------------------------------------------------------------------------------
    SQL*Net more data to client 888137 0 12365
    0.013922402
    db file parallel write 2445 0 17606
    7.200818
    db file scattered read 7823 0 18336
    2.34385786
    db file sequential read 27779 0 55490
    1.99755211
    control file parallel write 27194 0 70593
    2.59590351
    log file sync 29700 1 145295
    4.89208754
    log file parallel write 30511 2 146311
    4.7953525
    io done 35551 567 270796
    7.61711344
    smon timer 278 273 8404285
    30231.241
    pmon timer 27350 27349
    8413237 307.613784
    SQL*Net message from client 498526 0 17655561
    35.415527
    rdbms ipc message 112693 80775
    33193981 294.552288
    PX Idle Wait 164145 164139
    33650049 205.001974
    slave wait 433146 392872
    40839651 94.2861091

    Regards
    Bhulu

    __________________________________________________
    Do You Yahoo!?
    LAUNCH - Your Yahoo! Music Experience
    http://launch.yahoo.com
    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: S B
    INET: bhulubhuli_at_yahoo.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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.com
    --
    Author: Anjo Kolk
    INET: anjo_at_oraperf.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Greg Moore at May 21, 2002 at 7:13 am

    So just looking at v$system_event is dangerous.
    Looking v$system_event and v$sysstat
    is much better but still not perfect. The third
    way is ....... (mail me;-))
    Anjo,

    Jared has an even hand on the tiller. Go ahead an post an informative
    example of how the v$ views don't allow you to diagnose a specific problem,
    and how Precise products do. We wanna know, and I don't imagine he'll mind.

    These little hints, and half sentences that end with an ellipsis, are
    getting on my nerves!;-)

    Greg

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Greg Moore
    INET: sqlgreg_at_pacbell.net

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Jared.Still_at_radisys.com at May 21, 2002 at 7:47 pm

    Go ahead an post an informative example of
    how the v$ views don't allow you to diagnose a specific problem,
    and how Precise products do.
    We wanna know, and I don't imagine he'll mind.
    Indeed I won't mind. Go ahead, tell us. :)

    Jared

    Greg Moore
    Sent by: root_at_fatcity.com
    05/21/2002 12:13 AM
    Please respond to ORACLE-L



    To: Multiple recipients of list ORACLE-L
    cc:
    Subject: Re: I/O EVENTS
    So just looking at v$system_event is dangerous.
    Looking v$system_event and v$sysstat
    is much better but still not perfect. The third
    way is ....... (mail me;-))
    Anjo,

    Jared has an even hand on the tiller. Go ahead an post an informative
    example of how the v$ views don't allow you to diagnose a specific
    problem,
    and how Precise products do. We wanna know, and I don't imagine he'll
    mind.

    These little hints, and half sentences that end with an ellipsis, are
    getting on my nerves!;-)

    Greg

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Greg Moore
    INET: sqlgreg_at_pacbell.net

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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.com
    --
    Author:
    INET: Jared.Still_at_radisys.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Cary Millsap at May 22, 2002 at 4:08 am
    I have an example for you (Anjo, I hope you won't mind). A prospect we
    visited once upon a time had been fighting a performance problem with an
    Oracle Payroll program. They "knew" what their problem was: very
    clearly, v$system_event was telling them that their overwhelmingly
    dominant system performance problem was waits for "latch free." (Well,
    no it wasn't. It was waits for the Oracle Payroll program.;) )

    Actually, the v$system_event view indicated clearly that the top wait
    event was "SQL*Net message from client" (and some other "SQL*Net %"
    stuff), but of course every good DBA knows that you have to discard all
    the "SQL*Net" events because they are "idle" events.

    Three months of trying and failing to fix the problem led finally to a
    last-resort, desperation hardware upgrade. Twelve 700MHz CPUs became
    twelve new 1,024MHz CPUs. (Don't ask why "waits for latch free" was
    translated as "need to upgrade CPUs.") And unfortunately, the Payroll
    program got *slower*. Not just "seemed slower"--*was* slower.

    After the upgrade failed to help, these guys finally let us come see
    them. We traced the Payroll process (10046, level 8), very carefully
    initiating the trace immediately after the initiation of the Payroll
    run, and very carefully terminating the trace immediately after the
    completion of the Payroll run. The key here is that every second of data
    in the trace file was a second of somebody's response time.

    The result was a really fun story. The thing ran in about 33 minutes.
    Here's a summary of what was in the session's trace file:

    Oracle Kernel Event Duration Calls Avg

    ------------------------------ ------------------ -------- ----------
    SQL*Net message from client 984.01s 49.6% 95,161 0.010340s
    SQL*Net more data from client 418.82s 21.1% 3,345 0.125208s
    db file sequential read 279.54s 14.1% 45,085 0.006200s
    CPU service 248.69s 12.5% 222,760 0.001116s
    unaccounted-for 27.73s 1.4%
    latch free 23.69s 1.2% 34,695 0.000683s
    log file sync 1.09s 0.1% 506 0.002154s
    SQL*Net more data to client 0.83s 0.0% 15,982 0.000052s
    log file switch completion 0.28s 0.0% 3 0.093333s
    enqueue 0.25s 0.0% 106 0.002358s
    SQL*Net message to client 0.24s 0.0% 95,161 0.000003s
    buffer busy waits 0.22s 0.0% 67 0.003284s
    db file scattered read 0.01s 0.0% 2 0.005000s
    SQL*Net break/reset to client 0.00s 0.0% 2 0.000000s
    ------------------------------ ------------------ -------- ----------
    Total 1,985.40s 100.0%

    Well, waits for "latch free" accounted for only 1.2% of the total
    response time. If the DBAs had been completely successful in eliminating
    "latch free" waits from their system, it would have made only a 1.2%
    difference in the runtime of this program. Point 1: This
    program's bottleneck is not the same as its system's system-wide average
    bottleneck. This happens all the time. You can NOT see this
    type of problem when you look only at system-wide average statistics.

    You probably didn't pay much heed to the first thing you should have
    noticed: slightly more than 70% of this program's runtime was consumed
    by so-called "server idle" time. ??! You can't ignore this time, even if
    people do call it "idle." Idle or not, this time was part of someone's
    response time, so we need to deal with it. Now if we hadn't collected
    our statistics so carefully (with proper time scope and proper program
    scope), then we would have seen probably much more "SQL*Net message from
    client" time in our data. If you make that particular collection error,
    then you *have* to disregard the so-called "idle" wait time.

    What was the Payroll program's problem? A couple of things. First, we
    knew that the Payroll program was running on the same host as Oracle.
    But the latency per call on the "SQL*Net message from client" event
    looked suspiciously LAN-like (order of 10ms), not IPC-like (order of 1ms
    or less). So we checked the tnsnames.ora file. Turns out that to
    conserve administration effort, the DBAs had decided to use a single
    tnsnames.ora file system-wide. So the Payroll program was using the same
    TCP/IP protocol that the system's PC clients were using. Just by
    switching the protocol to BEQ instead of TCP in the db server's
    tnsnames.ora file (a change that took about 15 minutes to test, 20
    seconds to implement, and about a week to navigate through change
    control), we eliminated about 50% of the program's runtime.

    Next, what's with the "SQL*Net more data from client"? The developers of
    this particular Payroll program did a pretty bad thing in their code:
    they passed several really long (10KB) SQL texts from the client to the
    server in their parse calls (oh yeh, and with no bind variables either).
    Anyway, each time the Oracle kernel received a packet containing only
    part of a SQL statement, it tallied to "SQL*Net more data from client"
    while it waited for the next piece. Of course, communicating via the
    network interface card instead of IPC didn't help, but passing huge SQL
    statements from the app to the db is bad form to begin with (see Ixora
    for more detail on just how bad this is).

    Finally, realize that Oracle tallies to "SQL*Net message from client"
    pretty much every time it's "between" working on db call fulfillment.
    Therefore, there were on the order of 95,161 db calls during this
    33-minute period. Looking at the SQL, we discovered that of course,
    since the app developers didn't use bind variables, there was a parse
    call for almost every execute. This accounted for thousands of
    unnecessary parse calls. Next, each execute call manipulated only zero
    or one row, which added up to dozens of execute calls for each single
    SQL statement with a multi-row result source. The program could have
    performed the business function with a fraction of the db calls.

    Oh yes... Why did the Payroll program get *slower* after the upgrade?
    Little Payroll program time was spent using CPU, so the upgrade had very
    little direct positive effect upon the program. Most of the program's
    time was spent waiting for network latency. Other programs ran at the
    same time as this Payroll job. The CPU upgrade made *them* faster, which
    intensified *their* constant number of network calls into a smaller time
    window. The result was increased competition for the network during the
    Payroll run. Therefore, every network I/O call the Payroll call made was
    a little slower than before the CPU upgrade. The increase in network
    response time overwhelmed the tiny direct improvement of the CPU time
    reduction, resulting in a net degradation of Payroll performance. ...Not
    a good thing, because this Payroll program had a higher business
    priority than everything else on the system at the same time.

    The End.

    * *

    So, some wrap-up:

    Looking at v$session_event is better than looking at v$system_event
    for these things. When you collect system-wide data to solve a single
    program's performance problem, your irrelevant data can bury your
    relevant data. We see this all the time. Any time you query
    v$system_event and ask about the top-line events you see, your
    vulnerable to this problem.

    Furthermore, looking even at v$session_event tells you NOTHING about
    the user's experience. When a v$ query tells you that there's "SQL*Net
    message from client" time, you can't know without more data whether this
    stuff showed up in someone's response time, or if it corresponded to
    time when the USER was actually idle.

    Another important reason that looking at v$session_event data can
    mislead you is that there's no record of CPU time in there. To find
    that, you have to go to something like v$sesstat. The "CPU used by this
    session" statistic is supposed to give you the CPU time you need, but
    various bugs prevent you from getting what you need in many cases.

    Response time = CPU from sesstat + waits from session_event + an
    unaccounted-for gap in time. Lots of people believe that the "gap" is a
    deficiency of 10046 data: it's not. The irony is that the same
    deficiency is even worse in v$ table methods; you just can't tell that
    there even *is* a gap: you can't compute gap=R-(cpu+waits), because with
    v$-based methods you don't know what R is. This "gap" is one of those
    things that we've discovered how to interpret reliably after some work.
    For more information, see some of our Hotsos Profiler documentation at
    www.hotsos.com/dnloads/1/kevents and click "unaccounted-for" (the
    document is free, but you have to register). (Bear with us, most of the
    event documentation on our kevents page is pre-beta, but the
    "unaccounted-for" document is pretty much complete.)

    How Precise gets around all those problems is by polling Oracle
    shared memory (the things underneath the v$ tables) with extraordinary
    frequency in a "lightweight way" (directly from memory). How Hotsos gets
    around them is by using 10046 level-8 trace data. But to use 10046, you
    must be able to predict that a performance problem will occur in the
    near future (for example, because it's repeatable). We teach both data
    collection approaches in our Clinic, but we have relied upon 10046-based
    analysis exclusively (using our own Hotsos Profiler tool) since 2000.

    No matter how you collect the data, as long as you do it correctly,
    the response time-based optimization method works with extraordinary
    efficiency. Since about 1995, Anjo (whom I regard to be the Father of
    the response-time based Oracle optimization method) has been able within
    a few minutes to find and fix performance problems that have evaded
    detection for months or even years. It's rare anymore for any of us to
    spend more than about an hour diagnosing and repairing a performance
    problem once we have the right data.

    ...But the hit ratio stuff lives on, I think for two reasons: (1) Not
    enough people understand the response-time based diagnostic methods yet
    (but we're working on that!); and (2) Ratio-based techniques, when
    combined with time & materials-based billing contracts, are extremely
    effective at maximizing consulting revenue.


    Cary Millsap
    Hotsos Enterprises, Ltd.
    cary.millsap_at_hotsos.com
    http://www.hotsos.com

    Next Hotsos Clinic events
    June 11-13 - Los Angeles
    July 9-11 - New York

    -----Original Message-----
    Sent: Tuesday, May 21, 2002 2:13 AM
    To: Multiple recipients of list ORACLE-L
    So just looking at v$system_event is dangerous.
    Looking v$system_event and v$sysstat
    is much better but still not perfect. The third
    way is ....... (mail me;-))
    Anjo,

    Jared has an even hand on the tiller. Go ahead an post an informative
    example of how the v$ views don't allow you to diagnose a specific
    problem,
    and how Precise products do. We wanna know, and I don't imagine he'll
    mind.

    These little hints, and half sentences that end with an ellipsis, are
    getting on my nerves!;-)

    Greg

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Greg Moore
    INET: sqlgreg_at_pacbell.net

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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.com
    --
    Author: Cary Millsap
    INET: cary.millsap_at_hotsos.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Jack Silvey at May 22, 2002 at 5:28 am
    Cary,

    This is greatness.

    Jack

    Cary Millsap wrote:
    I have an example for you (Anjo, I hope you won't
    mind). A prospect we
    visited once upon a time had been fighting a
    performance problem with an
    Oracle Payroll program. They "knew" what their
    problem was: very
    clearly, v$system_event was telling them that their
    overwhelmingly
    dominant system performance problem was waits for
    "latch free." (Well,
    no it wasn't. It was waits for the Oracle Payroll
    program.;) )

    Actually, the v$system_event view indicated clearly
    that the top wait
    event was "SQL*Net message from client" (and some
    other "SQL*Net %"
    stuff), but of course every good DBA knows that you
    have to discard all
    the "SQL*Net" events because they are "idle" events.

    Three months of trying and failing to fix the
    problem led finally to a
    last-resort, desperation hardware upgrade. Twelve
    700MHz CPUs became
    twelve new 1,024MHz CPUs. (Don't ask why "waits for
    latch free" was
    translated as "need to upgrade CPUs.") And
    unfortunately, the Payroll
    program got *slower*. Not just "seemed
    slower"--*was* slower.

    After the upgrade failed to help, these guys finally
    let us come see
    them. We traced the Payroll process (10046, level
    8), very carefully
    initiating the trace immediately after the
    initiation of the Payroll
    run, and very carefully terminating the trace
    immediately after the
    completion of the Payroll run. The key here is that
    every second of data
    in the trace file was a second of somebody's
    response time.

    The result was a really fun story. The thing ran in
    about 33 minutes.
    Here's a summary of what was in the session's trace
    file:

    Oracle Kernel Event Duration
    Calls Avg

    ------------------------------ ------------------
    -------- ----------
    SQL*Net message from client 984.01s 49.6%
    95,161 0.010340s
    SQL*Net more data from client 418.82s 21.1%
    3,345 0.125208s
    db file sequential read 279.54s 14.1%
    45,085 0.006200s
    CPU service 248.69s 12.5%
    222,760 0.001116s
    unaccounted-for 27.73s 1.4%

    latch free 23.69s 1.2%
    34,695 0.000683s
    log file sync 1.09s 0.1%
    506 0.002154s
    SQL*Net more data to client 0.83s 0.0%
    15,982 0.000052s
    log file switch completion 0.28s 0.0%
    3 0.093333s
    enqueue 0.25s 0.0%
    106 0.002358s
    SQL*Net message to client 0.24s 0.0%
    95,161 0.000003s
    buffer busy waits 0.22s 0.0%
    67 0.003284s
    db file scattered read 0.01s 0.0%
    2 0.005000s
    SQL*Net break/reset to client 0.00s 0.0%
    2 0.000000s
    ------------------------------ ------------------
    -------- ----------
    Total 1,985.40s 100.0%

    Well, waits for "latch free" accounted for only 1.2%
    of the total
    response time. If the DBAs had been completely
    successful in eliminating
    "latch free" waits from their system, it would have
    made only a 1.2%
    difference in the runtime of this program. Point 1:
    This
    program's bottleneck is not the same as its system's
    system-wide average
    bottleneck. This happens all the time.
    You can NOT see this
    type of problem when you look only at system-wide
    average statistics.

    You probably didn't pay much heed to the first thing
    you should have
    noticed: slightly more than 70% of this program's
    runtime was consumed
    by so-called "server idle" time. ??! You can't
    ignore this time, even if
    people do call it "idle." Idle or not, this time was
    part of someone's
    response time, so we need to deal with it. Now if we
    hadn't collected
    our statistics so carefully (with proper time scope
    and proper program
    scope), then we would have seen probably much more
    "SQL*Net message from
    client" time in our data. If you make that
    particular collection error,
    then you *have* to disregard the so-called "idle"
    wait time.

    What was the Payroll program's problem? A couple of
    things. First, we
    knew that the Payroll program was running on the
    same host as Oracle.
    But the latency per call on the "SQL*Net message
    from client" event
    looked suspiciously LAN-like (order of 10ms), not
    IPC-like (order of 1ms
    or less). So we checked the tnsnames.ora file. Turns
    out that to
    conserve administration effort, the DBAs had decided
    to use a single
    tnsnames.ora file system-wide. So the Payroll
    program was using the same
    TCP/IP protocol that the system's PC clients were
    using. Just by
    switching the protocol to BEQ instead of TCP in the
    db server's
    tnsnames.ora file (a change that took about 15
    minutes to test, 20
    seconds to implement, and about a week to navigate
    through change
    control), we eliminated about 50% of the program's
    runtime.

    Next, what's with the "SQL*Net more data from
    client"? The developers of
    this particular Payroll program did a pretty bad
    thing in their code:
    they passed several really long (10KB) SQL texts
    from the client to the
    server in their parse calls (oh yeh, and with no
    bind variables either).
    Anyway, each time the Oracle kernel received a
    packet containing only
    part of a SQL statement, it tallied to "SQL*Net more
    data from client"
    while it waited for the next piece. Of course,
    communicating via the
    network interface card instead of IPC didn't help,
    but passing huge SQL
    statements from the app to the db is bad form to
    begin with (see Ixora
    for more detail on just how bad this is).

    Finally, realize that Oracle tallies to "SQL*Net
    message from client"
    pretty much every time it's "between" working on db
    call fulfillment.
    Therefore, there were on the order of 95,161 db
    calls during this
    33-minute period. Looking at the SQL, we discovered
    that of course,
    since the app developers didn't use bind variables,
    there was a parse
    call for almost every execute. This accounted for
    thousands of
    unnecessary parse calls. Next, each execute call
    manipulated only zero
    or one row, which added up to dozens of execute
    calls for each single
    SQL statement with a multi-row result source. The
    program could have
    performed the business function with a fraction of
    the db calls.

    Oh yes... Why did the Payroll program get *slower*
    after the upgrade?
    Little Payroll program time was spent using CPU, so
    the upgrade had very
    little direct positive effect upon the program. Most
    of the program's
    time was spent waiting for network latency. Other
    programs ran at the
    same time as this Payroll job. The CPU upgrade made
    *them* faster, which
    intensified *their* constant number of network calls
    into a smaller time
    window. The result was increased competition for the
    network during the
    === message truncated ===

    Do You Yahoo!?
    LAUNCH - Your Yahoo! Music Experience
    http://launch.yahoo.com

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Jack Silvey
    INET: jack_silvey_at_yahoo.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Cherie_Machler_at_gelco.com at May 22, 2002 at 1:13 pm
    Cary,

    Thanks for this meaty example and especially for the analysis afterwards.
    Real-life examples like this are so much more revealing and insightful than
    any amount of theoretical discussion.

    We could learn so much if once a month someone would post the statistics
    and output from their performance problem as well as the background story
    and then discussed the solution in detail.

    I must admit that you guys have impressed the heck out of me with this
    story. I would be very kindly disposed to bringing HOTSOS in to fix a
    serious performance problem.

    Cherie Machler
    Oracle DBA
    Gelco Information Network

    "Cary Millsap"

    otsos.com> cc:
    Sent by: Subject: RE: I/O EVENTS
    root_at_fatcity.co
    m

    05/21/02 11:08
    PM
    Please respond
    to ORACLE-L

    I have an example for you (Anjo, I hope you won't mind). A prospect we
    visited once upon a time had been fighting a performance problem with an
    Oracle Payroll program. They "knew" what

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author:
    INET: Cherie_Machler_at_gelco.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------

    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • S B at May 22, 2002 at 1:38 pm
    Hi Cary,

    I also have a same problem but could not solve it yet

    I have two m/cs and with identical DB layout etc and
    running the
    same pro*C code under same data volume.The top waits
    are as follows.

    1.oracle-8.0.5 ( 2 processor/RAM 512 MB)

    Total run time 45 mins

    Event wait(cs) %
    -----------------------------------------------------------
    CPU used by this session 218625
    73.03299471
    SQL*Net message from client 37013
    12.36441502
    db file sequential read 18074
    6.037728286
    SQL*Net more data to client 8891
    2.970091966
    write complete waits 8341

    2.786361161

    2.oracle-8.1.7 ( 2 processor/RAM 512 MB)

    Total run time 2.2 hrs

    Event wait(cs) %
    -----------------------------------------------------------
    SQL*Net message from client 463790
    61.85186173
    CPU used by this session 229327
    30.5834578
    SQL*Net more data to client 32388
    4.319321455
    db file sequential read 21698
    2.893683986
    log file sync 1788
    0.23845087
    SQL*Net message to client 530

    0.070681745

    See the amount of CPU time is almost same in both m/c
    and
    the great diff is being in the "SQL*Net message from
    client"

    I have also seen that in both the m/c the program
    running
    with (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))
    i.e
    using BEQ.

    Question :-

    How to reduce wait time for "SQL*Net message from
    client"
    In the above case,connection is established without
    a
    connect string( i.e tnsnames.ora is not used.), so
    will a change in tnsnames.ora really help ?

    Bhulu

    Cary Millsap wrote:
    I have an example for you (Anjo, I hope you won't
    mind). A prospect we
    visited once upon a time had been fighting a
    performance problem with an
    Oracle Payroll program. They "knew" what their
    problem was: very
    clearly, v$system_event was telling them that their
    overwhelmingly
    dominant system performance problem was waits for
    "latch free." (Well,
    no it wasn't. It was waits for the Oracle Payroll
    program.;) )

    Actually, the v$system_event view indicated clearly
    that the top wait
    event was "SQL*Net message from client" (and some
    other "SQL*Net %"
    stuff), but of course every good DBA knows that you
    have to discard all
    the "SQL*Net" events because they are "idle" events.

    Three months of trying and failing to fix the
    problem led finally to a
    last-resort, desperation hardware upgrade. Twelve
    700MHz CPUs became
    twelve new 1,024MHz CPUs. (Don't ask why "waits for
    latch free" was
    translated as "need to upgrade CPUs.") And
    unfortunately, the Payroll
    program got *slower*. Not just "seemed
    slower"--*was* slower.

    After the upgrade failed to help, these guys finally
    let us come see
    them. We traced the Payroll process (10046, level
    8), very carefully
    initiating the trace immediately after the
    initiation of the Payroll
    run, and very carefully terminating the trace
    immediately after the
    completion of the Payroll run. The key here is that
    every second of data
    in the trace file was a second of somebody's
    response time.

    The result was a really fun story. The thing ran in
    about 33 minutes.
    Here's a summary of what was in the session's trace
    file:

    Oracle Kernel Event Duration
    Calls Avg

    ------------------------------ ------------------
    -------- ----------
    SQL*Net message from client 984.01s 49.6%
    95,161 0.010340s
    SQL*Net more data from client 418.82s 21.1%
    3,345 0.125208s
    db file sequential read 279.54s 14.1%
    45,085 0.006200s
    CPU service 248.69s 12.5%
    222,760 0.001116s
    unaccounted-for 27.73s 1.4%

    latch free 23.69s 1.2%
    34,695 0.000683s
    log file sync 1.09s 0.1%
    506 0.002154s
    SQL*Net more data to client 0.83s 0.0%
    15,982 0.000052s
    log file switch completion 0.28s 0.0%
    3 0.093333s
    enqueue 0.25s 0.0%
    106 0.002358s
    SQL*Net message to client 0.24s 0.0%
    95,161 0.000003s
    buffer busy waits 0.22s 0.0%
    67 0.003284s
    db file scattered read 0.01s 0.0%
    2 0.005000s
    SQL*Net break/reset to client 0.00s 0.0%
    2 0.000000s
    ------------------------------ ------------------
    -------- ----------
    Total 1,985.40s 100.0%

    Well, waits for "latch free" accounted for only 1.2%
    of the total
    response time. If the DBAs had been completely
    successful in eliminating
    "latch free" waits from their system, it would have
    made only a 1.2%
    difference in the runtime of this program. Point 1:
    This
    program's bottleneck is not the same as its system's
    system-wide average
    bottleneck. This happens all the time.
    You can NOT see this
    type of problem when you look only at system-wide
    average statistics.

    You probably didn't pay much heed to the first thing
    you should have
    noticed: slightly more than 70% of this program's
    runtime was consumed
    by so-called "server idle" time. ??! You can't
    ignore this time, even if
    people do call it "idle." Idle or not, this time was
    part of someone's
    response time, so we need to deal with it. Now if we
    hadn't collected
    our statistics so carefully (with proper time scope
    and proper program
    scope), then we would have seen probably much more
    "SQL*Net message from
    client" time in our data. If you make that
    particular collection error,
    then you *have* to disregard the so-called "idle"
    wait time.

    What was the Payroll program's problem? A couple of
    things. First, we
    knew that the Payroll program was running on the
    same host as Oracle.
    But the latency per call on the "SQL*Net message
    from client" event
    looked suspiciously LAN-like (order of 10ms), not
    IPC-like (order of 1ms
    or less). So we checked the tnsnames.ora file. Turns
    out that to
    conserve administration effort, the DBAs had decided
    to use a single
    tnsnames.ora file system-wide. So the Payroll
    program was using the same
    TCP/IP protocol that the system's PC clients were
    using. Just by
    switching the protocol to BEQ instead of TCP in the
    db server's
    tnsnames.ora file (a change that took about 15
    minutes to test, 20
    seconds to implement, and about a week to navigate
    through change
    control), we eliminated about 50% of the program's
    runtime.

    Next, what's with the "SQL*Net more data from
    client"? The developers of
    this particular Payroll program did a pretty bad
    thing in their code:
    they passed several really long (10KB) SQL texts
    from the client to the
    server in their parse calls (oh yeh, and with no
    bind variables either).
    Anyway, each time the Oracle kernel received a
    packet containing only
    part of a SQL statement, it tallied to "SQL*Net more
    data from client"
    while it waited for the next piece. Of course,
    communicating via the
    network interface card instead of IPC didn't help,
    but passing huge SQL
    statements from the app to the db is bad form to
    begin with (see Ixora
    for more detail on just how bad this is).

    Finally, realize that Oracle tallies to "SQL*Net
    message from client"
    pretty much every time it's "between" working on db
    call fulfillment.
    Therefore, there were on the order of 95,161 db
    calls during this
    33-minute period. Looking at the SQL, we discovered
    that of course,
    since the app developers didn't use bind variables,
    there was a parse
    call for almost every execute. This accounted for
    thousands of
    unnecessary parse calls. Next, each execute call
    manipulated only zero
    or one row, which added up to dozens of execute
    calls for each single
    SQL statement with a multi-row result source. The
    program could have
    performed the business function with a fraction of
    the db calls.

    Oh yes... Why did the Payroll program get *slower*
    after the upgrade?
    Little Payroll program time was spent using CPU, so
    the upgrade had very
    little direct positive effect upon the program. Most
    of the program's
    time was spent waiting for network latency. Other
    programs ran at the
    same time as this Payroll job. The CPU upgrade made
    *them* faster, which
    intensified *their* constant number of network calls
    into a smaller time
    window. The result was increased competition for the
    network during the
    === message truncated ===

    Do You Yahoo!?
    LAUNCH - Your Yahoo! Music Experience
    http://launch.yahoo.com

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: S B
    INET: bhulubhuli_at_yahoo.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Greg Moore at May 23, 2002 at 12:38 am

    the latency per call on the "SQL*Net message
    from client" event looked suspiciously LAN-like
    (order of 10ms), not IPC-like (order of 1ms or less)
    Oracle Kernel Event Duration Calls Avg
    ------------------------------ ------------------ -------- ----------
    SQL*Net message from client 984.01s 49.6% 95,161 0.010340s
    Cary,

    To me it looks like the average wait is about one hundredth of a second. I
    must be missing something.

    Greg

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Greg Moore
    INET: sqlgreg_at_pacbell.net

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Cary Millsap at May 23, 2002 at 5:08 am
    0.010340 second ~ 10/1,000 second = 10ms (= 1/100 second)

    If the number had been on the order of 0.001 (1ms) or less, it would've
    looked more IPC-like.


    Cary Millsap
    Hotsos Enterprises, Ltd.
    cary.millsap_at_hotsos.com
    http://www.hotsos.com

    -----Original Message-----
    Sent: Wednesday, May 22, 2002 7:38 PM
    To: Multiple recipients of list ORACLE-L
    the latency per call on the "SQL*Net message
    from client" event looked suspiciously LAN-like
    (order of 10ms), not IPC-like (order of 1ms or less)
    Oracle Kernel Event Duration Calls Avg
    ------------------------------ ------------------ -------- ----------
    SQL*Net message from client 984.01s 49.6% 95,161 0.010340s
    Cary,

    To me it looks like the average wait is about one hundredth of a second.
    I
    must be missing something.

    Greg

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Greg Moore
    INET: sqlgreg_at_pacbell.net

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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.com
    --
    Author: Cary Millsap
    INET: cary.millsap_at_hotsos.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Greg Moore at May 23, 2002 at 9:46 pm
    Cary,

    In a TKPROF report, there is a small table at the top. It includes a column
    for CPU time and another for Elapsed Time.

    Suppose the total line shows CPU = 3.00 and elapsed = 5.00. You would think
    that the two seconds difference would be for waits, but that doesn't seem to
    be true.

    Since you have investigated trace files quite a bit, do you have an idea
    what these two TKPROF totals actually represent? If the difference between
    these two isn't waits, what is it?
    From a pragmatic point of view, if all I have is a TKPROF report is there
    anything useful I can learn from seeing these two totals?

    Thanks.

    Greg

    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Greg Moore
    INET: sqlgreg_at_pacbell.net

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).
  • Stephane Faroult at May 23, 2002 at 10:19 pm

    Greg Moore wrote:

    Cary,

    In a TKPROF report, there is a small table at the top. It includes a column
    for CPU time and another for Elapsed Time.

    Suppose the total line shows CPU = 3.00 and elapsed = 5.00. You would think
    that the two seconds difference would be for waits, but that doesn't seem to
    be true.

    Since you have investigated trace files quite a bit, do you have an idea
    what these two TKPROF totals actually represent? If the difference between
    these two isn't waits, what is it?
    From a pragmatic point of view, if all I have is a TKPROF report is there
    anything useful I can learn from seeing these two totals?

    Thanks.

    - Greg
    Greg,

    Waits refer to Oracle resources, mostly. Elapsed is, well, just
    elapsed time and CPU time the amount of time for which the CPU ran just
    for you. But you may well be waiting at the OS level without waiting for
    any particular Oracle resource - think about being in the run queue,
    ready to run, while the CPU is busy servicing somebody else. You're
    waiting, and yet Oracle doesn't really know of it - or may not know of
    it.
    I guess that Oracle measures waits by taking an algorithm similar to :

    start_time = get_time_stamp();
    if (get_resource() == 0)
    {
    /* Got it */
    wait_time = wait_time + (get_time_stamp() - start_time);
    ...

    A wait time measured this way is actually some _elapsed_ time - during
    the get_resource() call Oracle certainly used CPU, but may well also
    have waited for some very low-level system resources. In other words,
    you can consider that Oracle wait times are something pretty unrelated
    to the elapsed/cpu times. It's elapsed time, but elapsed time doing
    nothing useful.

    One thing is certain : the less Oracle waits, the less your users will
    wait too. That said, most often when they are waiting Oracle is busy ...

    --
    Regards,

    Stephane Faroult
    Oriole Software
    --
    Please see the official ORACLE-L FAQ: http://www.orafaq.com
    --
    Author: Stephane Faroult
    INET: sfaroult_at_oriole.com

    Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
    San Diego, California -- Public Internet access / Mailing Lists
    --------------------------------------------------------------------
    To REMOVE yourself from this mailing list, send an E-Mail message
    to: ListGuru_at_fatcity.com (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).

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
grouporacle-l @
categoriesoracle
postedMay 16, '02 at 9:33a
activeMay 23, '02 at 10:19p
posts18
users10
websiteoracle.com

People

Translate

site design / logo © 2022 Grokbase