Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Usenet -> c.d.o.server -> Re: Interpreting statspack report

Re: Interpreting statspack report

From: Jonathan Lewis <jonathan_at_jlcomp.demon.co.uk>
Date: Wed, 23 Nov 2005 20:17:06 +0000 (UTC)
Message-ID: <dm2io2$h78$1@nwrdmz02.dmz.ncs.ea.ibs-infra.bt.com>


"Pascal Oegerli" <pascal.oegerli_at_edorex.ch> wrote in message news:dm2aj5$sl6$1_at_news.hispeed.ch...
> Hello,
>
> Is anybody out there who can verify my reflections on the following
> Statspack Report?
>
> STATSPACK report for
>
> DB Name DB Id Instance Inst Num Release Cluster Host
> ------------ ----------- ------------ -------- ----------- ------- ------------
> PMCSHG 3476772697 PMCSHG 1 9.2.0.6.0 NO
> ms009005
>
> Snap Id Snap Time Sessions Curs/Sess Comment
> --------- ------------------ -------- --------- -------------------
> Begin Snap: 7213 22-Nov-05 09:42:04 81 28,061.7 ~
> End Snap: 7214 22-Nov-05 10:42:07 95 24,116.8 ~
> Elapsed: 60.05 (mins)
>
> Cache Sizes (end)
> ~~~~~~~~~~~~~~~~~
> Buffer Cache: 576M Std Block Size: 8K
> Shared Pool Size: 528M Log Buffer: 4,000K
>
> Load Profile
> ~~~~~~~~~~~~ Per Second Per Transaction
> --------------- ---------------
> Redo size: 34,445.58 17,287.56
> Logical reads: 15,711.60 7,885.35
> Block changes: 55.43 27.82
> Physical reads: 685.85 344.22
> Physical writes: 6.99 3.51
> User calls: 113.94 57.19
> Parses: 60.26 30.24
> Hard parses: 6.41 3.22
> Sorts: 11.53 5.79
> Logons: 0.34 0.17
> Executes: 278.88 139.97
> Transactions: 1.99
>
> % Blocks changed per Read: 0.35 Recursive Call %: 82.67
> Rollback per transaction %: 0.01 Rows per Sort: 303.44
>
> Instance Efficiency Percentages (Target 100%)
> ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> Buffer Nowait %: 100.00 Redo NoWait %: 100.00
> Buffer Hit %: 96.08 In-memory Sort %: 99.93
> Library Hit %: 97.68 Soft Parse %: 89.36
> Execute to Parse %: 78.39 Latch Hit %: 99.94
> Parse CPU to Parse Elapsd %: 53.89 % Non-Parse CPU: 85.36
>
> Shared Pool Statistics Begin End
> ------ ------
> Memory Usage %: 88.53 88.59
> % SQL with executions>1: 45.10 31.29
> % Memory for SQL w/exec>1: 39.58 17.86
>
> Top 5 Timed Events
> ~~~~~~~~~~~~~~~~~~ %
> Total
> Event Waits Time (s) Ela
> Time
> -------------------------------------------- ------------ ----------- --------
> CPU time ~ 3,805
> 84.92
> db file scattered read 343,220 210 4.70
> SQL*Net more data to client 436,462 183 4.07
> db file sequential read 41,423 96 2.14
> log file parallel write 8,207 68 1.51
>
> @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
> 85% of the whole Time is CPU time. So I have to look closer at this,
> agree?
> @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
>
> parse time cpu 55,695 15.5 7.8
> recursive cpu usage 258,990 71.9 36.1
>
> @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
> Recursive CPU is 2589 seconds of 3'805 total CPU time. That means, I have:
> either a lot of PL/SQL
> or very expensive buffer handling in the buffer cache
> So let's have a look at these SQL Statments:
> @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
>
> CPU Elapsd
> Buffer Gets Executions Gets per Exec %Total Time (s) Time (s) Hash
> Value
> --------------- ------------ -------------- ------ -------- --------- ----------
> 16,668,489 103 161,830.0 29.4 166.73 219.96
> 2693357960
> Module: w3wp.exe
> begin "PA_ANTENNA"."P_CUD"(p_action=>:p_action, p_rec_status=>:p
> _rec_status, p_azimut=>:p_azimut, p_mod_user=>:p_mod_user, p_con
> n_cells=>:p_conn_cells, p_antenna_id=>:p_antenna_id, p_antennamo
> del_id=>:p_antennamodel_id, p_ret_id=>:p_ret_id, p_antenna_set_i
> d=>:p_antenna_set_id, p_preamplifier_id=>:p_preamplifier_id, p_e
>
> 5,936,120 48,747 121.8 10.5 1114.58 1570.03
> 3004224063
> Module: w3wp.exe
> SELECT A.CAPTION, A.LANG_ID FROM X_MLTEXT A WHERE ML_ID=:B1 ORDE
> R BY LANG_ID DESC
>
> 2,794,360 19,353 144.4 4.9 524.16 847.55
> 1434437237
> Module: w3wp.exe
> SELECT A.CAPTION, A.LANG_ID FROM X_MLTEXT A, X_ML B WHERE B.ML_I
> D_CODE = LOWER(:B1 ) AND A.ML_ID=B.ML_ID ORDER BY LANG_ID DESC
>
> 1,924,208 10,934 176.0 3.4 371.70 615.85
> 838048417
> Module: w3wp.exe
> select pa_ml.f_get(1,'msg_reallydel') from dual
>
> @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
> Would you agree that theses statments are very critical ones (especially
> the second one)
> due to their Buffer gets and CPU times?
> Is this the right approach that I'm going?
>
> Thank you very much for your advice.
>
> Pascal
>

If the problem you are addressing is:

    "the system is generally slow"
or

    "the machine is working too hard for what we're doing" then your approach seems to be perfectly reasonable, and your conclusions correct.

The particularly expensive statement looks as if it should be returning only a few rows (that's pure guesswork based on column names) so the cost per execution looks unreasonable, and the difference you can make by (say) just halving the CPU cost of that statement looks a worthwhile saving, so it's worth a little time.

-- 
Regards

Jonathan Lewis

http://www.jlcomp.demon.co.uk/faq/ind_faq.html
The Co-operative Oracle Users' FAQ

http://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
Cost Based Oracle: Fundamentals

http://www.jlcomp.demon.co.uk/appearances.html
Public Appearances - schedule updated 4th Nov 2005
Received on Wed Nov 23 2005 - 14:17:06 CST

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US