Re: Interpreting statspack report

From: Pascal <pascal.oegerli_at_postmail.ch>
Date: 23 Nov 2005 13:39:40 -0800
Message-ID: <1132781980.108742.280080@g44g2000cwa.googlegroups.com>

Jonathan Lewis schrieb:

> "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

Hey Jonathan,

Thanks for your reply. The machine is a server that runs about 50 databases. The customer is a large telecomunications company in Switzerland. Unfortunately, I have no acces to the server itself, I only have some statspack reports.

The particularly expensive statment gets the labels for the fields of a screen of the application. It is executed once when a user navigates to any screen. I will ask the developers if it is possible to load all text at the beginning of the application and put it in the application server cache. I think this would be a big gain.

Regards

Pascal Received on Wed Nov 23 2005 - 15:39:40 CST