Re: How to understand trace result

From: Toon Koppelaars <toon.koppelaars_at_rulegen.com>
Date: Sat, 10 Jan 2009 15:45:55 +0100
Message-ID: <ecf3dae70901100645p59c4b4bbq695fb5ae60e691dd_at_mail.gmail.com>



Eriovaldo,

Ahhh yes....

What's there to say? You seem to have an application that performs an awfull lot of SQL statements.
On average they take about 10 LIO's. Which need not be a bad thing. Also every statement seems to be a single row operation (typical.....).

This yet another proof that the Oracle DBMS is lightning fast: it is serving over 800 thousand SQL statements in roughly 10 minutes. Try doing that with another DBMS...

Your issue here is not the database.
Your issue is the application. Why is it submitting such an absurd amount of SQL statements?
I bet this a mid-tier centric architected application (where the database is dumb bit store).

call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 280247 7.17 6.92 0 736
> 6 0
> Execute 838921 72.83 74.21 272 79225 10914
> 10758
> Fetch 841865 619.19 629.54 136 7889481 1
> 842533
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 1961033 699.21 710.68 408 7969442 10921
> 853291
>

Toon

(Fat database evangelist)

On Sat, Jan 10, 2009 at 3:21 PM, Eriovaldo Andrietta <ecandrietta_at_gmail.com>wrote:

> Hi friends
>
> I am getting some trace files to analyze and I would like to understande
> what means each number below.
> Could someone give me some explanation.
> These numbers are result of getting session trace for around 5 minutes
> only.
> Regards
> Eriovaldo
>
>
>
> ********************************************************************************
>
> OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
>
> call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 0 0.00 0.00 0 0
> 0 0
> Execute 0 0.00 0.00 0 0
> 0 0
> Fetch 0 0.00 0.00 0 0
> 0 0
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 0 0.00 0.00 0 0
> 0 0
>
> Misses in library cache during parse: 0
>
>
> OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
>
> call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 280247 7.17 6.92 0 736
> 6 0
> Execute 838921 72.83 74.21 272 79225 10914
> 10758
> Fetch 841865 619.19 629.54 136 7889481 1
> 842533
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 1961033 699.21 710.68 408 7969442 10921
> 853291
>
> Misses in library cache during parse: 211
> Misses in library cache during execute: 170
>
> Elapsed times include waiting on following events:
> Event waited on Times Max. Wait Total
> Waited
> ---------------------------------------- Waited ----------
> ------------
> db file sequential read 278 0.05
> 1.73
> latch: library cache 15 0.00
> 0.00
> latch: shared pool 10 0.00
> 0.00
> undo segment extension 1 0.00
> 0.00
> db file scattered read 10 0.02
> 0.09
> log file sync 1 0.00
> 0.00
> reliable message 3 0.00
> 0.00
> rdbms ipc reply 3 0.01
> 0.02
> enq: RO - fast object reuse 2 0.00
> 0.00
> latch: row cache objects 1 0.00
> 0.00
>
> 279017 user SQL statements in session.
> 2835 internal SQL statements in session.
> 281852 SQL statements in session.
>

-- 
+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-
Toon Koppelaars
RuleGen BV
+31-615907269
Toon.Koppelaars_at_RuleGen.com
www.RuleGen.com

Author: "Applied Mathematics for Database Professionals"

--
http://www.freelists.org/webpage/oracle-l
Received on Sat Jan 10 2009 - 08:45:55 CST

Original text of this message