Skip to Main Content

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question.

Asked: February 01, 2008 - 2:50 pm UTC

Last updated: April 01, 2008 - 8:57 am UTC

Version: 9.2.0.8

Viewed 1000+ times

You Asked

What is your opinion on "best practice" of soft parsing. We have an instance that is soft parsing over 3800 times a second:

STATSPACK report for

DB Name DB Id Instance Inst Num Release Cluster Host
------------ ----------- ------------ -------- ----------- ------- ------------
cusdb 1083030182 cusdb 1 9.2.0.8.0 NO bnscqpd1

Snap Id Snap Time Sessions Curs/Sess Comment
--------- ------------------ -------- --------- -------------------
Begin Snap: 379269 21-Jan-08 12:00:05 1,912 2.8
End Snap: 379272 21-Jan-08 12:30:03 1,925 2.9
Elapsed: 29.97 (mins)

Cache Sizes (end)
~~~~~~~~~~~~~~~~~
Buffer Cache: 6,032M Std Block Size: 8K
Shared Pool Size: 1,504M Log Buffer: 4,608K

Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Redo size: 621,357.62 6,061.70
Logical reads: 99,239.66 968.14
Block changes: 4,238.09 41.35
Physical reads: 1,070.14 10.44
Physical writes: 181.68 1.77
User calls: 21,396.63 208.74
Parses: 3,872.55 37.78
Hard parses: 12.46 0.12
Sorts: 1,287.22 12.56
Logons: 0.04 0.00
Executes: 4,296.70 41.92
Transactions: 102.51

% Blocks changed per Read: 4.27 Recursive Call %: 3.58
Rollback per transaction %: 56.88 Rows per Sort: 19.38

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 99.98 Redo NoWait %: 100.00
Buffer Hit %: 98.92 In-memory Sort %: 100.00
Library Hit %: 100.20 Soft Parse %: 99.68
Execute to Parse %: 9.87 Latch Hit %: 99.55
Parse CPU to Parse Elapsd %: 92.50 % Non-Parse CPU: 95.41

Shared Pool Statistics Begin End
------ ------
Memory Usage %: 91.07 91.24
% SQL with executions>1: 26.60 24.69
% Memory for SQL w/exec>1: 33.36 31.83

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
CPU time 33,354 45.42
db file sequential read 1,846,550 30,063 40.94
latch free 236,788 3,161 4.30
db file parallel write 105,258 2,494 3.40
log file sync 82,828 2,189 2.98
-------------------------------------------------------------
Wait Events for DB: cusdb Instance: cusdb Snaps: 379269 -379272
-> s - second
-> cs - centisecond - 100th of a second
-> ms - millisecond - 1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)

Avg
Total Wait wait Waits
Event Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
db file sequential read 1,846,550 0 30,063 16 10.0
latch free 236,788 199,772 3,161 13 1.3
db file parallel write 105,258 0 2,494 24 0.6
log file sync 82,828 0 2,189 26 0.4
log file parallel write 127,946 0 991 8 0.7
buffer busy waits 38,764 2 450 12 0.2
log file sequential read 1,434 0 407 284 0.0
SQL*Net more data to client 1,216,519 0 245 0 6.6
db file scattered read 7,923 0 40 5 0.0
SQL*Net break/reset to clien 9,674 0 14 1 0.1
log file switch completion 155 0 13 84 0.0
LGWR wait for redo copy 1,689 107 5 3 0.0
enqueue 490 0 4 8 0.0
control file parallel write 736 0 4 5 0.0
db file parallel read 42 0 3 61 0.0
direct path write 484 0 1 2 0.0
log file single write 12 0 0 32 0.0
direct path read 1,692 0 0 0 0.0
async disk IO 2,808 0 0 0 0.0
library cache pin 12 0 0 17 0.0
control file sequential read 1,694 0 0 0 0.0
wait list latch free 8 0 0 12 0.0
direct path read (lob) 3 0 0 20 0.0
buffer deadlock 203 202 0 0 0.0
local write wait 1 0 0 18 0.0
db file single write 2 0 0 2 0.0
SQL*Net message from client 38,083,283 0 2,174,167 57 206.6
SQL*Net more data from clien 771,705 0 265 0 4.2
SQL*Net message to client 38,083,799 0 208 0 206.6
-------------------------------------------------------------
Background Wait Events for DB: cusdb Instance: cusdb Snaps: 379269 -3792
-> ordered by wait time desc, waits desc (idle events last)

Avg
Total Wait wait Waits
Event Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
db file parallel write 105,198 0 2,493 24 0.6
log file parallel write 127,913 0 990 8 0.7
log file sequential read 1,436 0 408 284 0.0
LGWR wait for redo copy 1,689 107 5 3 0.0
control file parallel write 726 0 4 5 0.0
direct path write 480 0 1 2 0.0
latch free 494 15 1 2 0.0
db file sequential read 114 0 1 6 0.0
db file scattered read 686 0 0 1 0.0
log file single write 12 0 0 32 0.0
direct path read 1,692 0 0 0 0.0
async disk IO 2,814 0 0 0 0.0
control file sequential read 916 0 0 0 0.0
db file single write 2 0 0 2 0.0
buffer busy waits 1 0 0 4 0.0
rdbms ipc message 327,475 2,099 11,890 36 1.8
smon timer 2,309 0 1,746 756 0.0
pmon timer 619 575 1,720 2778 0.0
-------------------------------------------------------------
SQL ordered by Gets for DB: cusdb Instance: cusdb Snaps: 379269 -379272
-> End Buffer Gets Threshold: 10000
-> Note that resources reported for PL/SQL includes the resources used by
all SQL statements called within the PL/SQL code. As individual SQL
statements are also reported, it is possible and valid for the summed
total % to exceed 100

Buffer Gets Executions Gets per Exec %Total Time (s) Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
626,074,800 10,323 60,648.5 350.9 6087.28 17744.76 1840019295
Module: JDBC Thin Client
select DISTINCT CUST_ID from (select a.CUST_ID from BO_MAPPING a whe
re BO_STATUS_CODE in (1,2,3,4,5,7) start with a.CUST_ID = :1 con
nect by prior a.CUST_ID = a.VOL_PARENT_CUST_ID and a.NODE_TYPE_ID <>
1 UNION ALL select a.CUST_ID from ORDER_TRANS a where exists (
select 1 from ORDER_MASTER c, ORDER_TRANS d where c.INT_ORDER_


etc

and Tom said...

I have written and said many times....

there are three types of parses (well, maybe four) in Oracle...

there is the dreaded hard parse - they are VERY VERY VERY bad.
there is the hurtful soft parse - they are VERY VERY very bad.
there is the hated softer soft parse you might be able to achieve with session cached cursors - they are VERY very very bad.

then there is the absence of a parse, no parse, silence. This is golden, this is perfect, this is the goal.



You are far from it:

Execute to Parse %: 9.87

As that goes to zero, that implies the number of parses = number of executions - horrible, worst practice, something to be avoide.

Maybe they can enable statement caching? So that the JDBC layer will fix their bug (by not closing SQL when they say "close it" - because they are closing it prematurely)



This needs to be REDUCED. Soft parses are simply better than a hard parse - but they are still a bad thing to be avoided.

Rating

  (3 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

Soft Parse

KEYUR.PATEL, March 31, 2008 - 8:21 pm UTC

Hello Tom,

I have following in my system

session cursor cache hits 64,455
parse count (hard) 21
parse count (total) 82,512

to_char(100 * sess / calls, '999999999990.00') || '%' cursor_cache_hits, ==> 78% Cursor Found in Session cache

to_char(100 * (calls - sess - hard) / calls, '999990.00') || '%' soft_parses, ==> 21% Soft Parse

to_char(100 * hard / calls, '999990.00') || '%' hard_parses ==> 0.025% Hard Parse

As in this database, there is almost no hard parse, but there is lot of soft parse, out of those soft parse, most of found in Session Cache, but still 21% not able to fit in session cached cursor.

do you think increasing session_cached_cursor would help upto some extent. At this moment session_cached_cursor is set to 40.

Once we achieve to cache 100% ( neary by 100%) of statement in memory, then what should be done to reduce soft parse ?

Application runs using plsql package only. There around 10 connection which persist over time and provide service to several thousand of end users.

Thanks

~ Keyur
Tom Kyte
April 01, 2008 - 8:57 am UTC

... do you think increasing session_cached_cursor would help upto some extent. ...

impossible to say. recursive sql done by us - won't be in the session cached cursor hits for example.


the only way to reduce parse calls to the database is......

to reduce the number of times you parse - that is something the APPLICATION and only the APPLICATION can do. They just must parse less...

Now, PLSQL uses the session_cached_cursor count to decide how many cursors to hold open (to NOT parse again) - so, given that you do everything in plsql - I'd be optimistic that increasing this value from 40 to 100 (100 being a pretty 'good' number that many people use as a baseline) might have an impact on reducing the number of times PARSE is done! Consider:

column oc noprint
set feedback off
set heading off
set embedded on
set echo off
set termout off
spool tmp.sql
select 1 oc, 'create or replace procedure p as l_rec dual%rowtype; begin' from dual
union all
select rownum+1 oc, 'select * into l_rec from dual d'||rownum||';' from dual connect by level <= 50
union all
select 10000 oc, 'end;' from dual
union all
select 10001 oc, '/' from dual
order by oc
/
spool off
set termout on
set feedback on
set heading on
@tmp
set echo on

connect /
alter session set session_cached_cursors = 40;
@mystat "parse count (total)"
begin
    for i in 1 .. 100
    loop
        p;
    end loop;
end;
/
@mystat2

connect /
alter session set session_cached_cursors = 100;
@mystat "parse count (total)"
begin
    for i in 1 .. 100
    loop
        p;
    end loop;
end;
/
@mystat2



when run... it will show something like this:

ops$tkyte%ORA10GR2> connect /
Connected.
ops$tkyte%ORA10GR2> alter session set session_cached_cursors = 40;

Session altered.

ops$tkyte%ORA10GR2> @mystat "parse count (total)"
ops$tkyte%ORA10GR2> set echo off
NAME                        VALUE
---------------------- ----------
parse count (total)            21

1 row selected.

ops$tkyte%ORA10GR2> begin
  2          for i in 1 .. 100
  3          loop
  4                  p;
  5          end loop;
  6  end;
  7  /

PL/SQL procedure successfully completed.

ops$tkyte%ORA10GR2> @mystat2
ops$tkyte%ORA10GR2> set echo off
NAME                        VALUE DIFF
---------------------- ---------- ------------------
parse count (total)          5025            5,004

1 row selected.

ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> connect /
Connected.
ops$tkyte%ORA10GR2> alter session set session_cached_cursors = 100;

Session altered.

ops$tkyte%ORA10GR2> @mystat "parse count (total)"
ops$tkyte%ORA10GR2> set echo off
NAME                        VALUE
---------------------- ----------
parse count (total)            21

1 row selected.

ops$tkyte%ORA10GR2> begin
  2          for i in 1 .. 100
  3          loop
  4                  p;
  5          end loop;
  6  end;
  7  /

PL/SQL procedure successfully completed.

ops$tkyte%ORA10GR2> @mystat2
ops$tkyte%ORA10GR2> set echo off
NAME                        VALUE DIFF
---------------------- ---------- ------------------
parse count (total)            75               54

1 row selected.



note that you will likely execute MORE than 100 sql statements - so you might not see this drastic a reduction - but feel free to play with the session cached cursors - the decrease will depending a lot on the ordering of your sql calls (do you call the same sql over and over and then switch to a different set or do you call 1,000 different statements in order, then 1,000 again and so on...)

Stress on UGA

KEYUR.PATEL, April 01, 2008 - 10:23 pm UTC

So If I would increase session_cache_cursor to 100, then i will see presure ou UGA. Because all connection are dedicated connection, UGA will be in PGA. So Do I look at PGA Advisor or stat for any performance degradation in PGA. At this moment, I have 100% optimal pass for PGA.

Thanks

High Soft Parse

Padmaja, October 09, 2009 - 12:48 am UTC

I have gone through the above scenerio ,It is very informative. we are also facing similar scenerio
in our environment . Below are run details, we have 8 different transactions and total trasnactions happened in the window are 38000
and user sql's are 15 per trasnaction on the average.

Begin Snap: 17692 06-Oct-09 19:50:38 306 9.8
End Snap: 17695 06-Oct-09 20:20:44 496 12.4
Elapsed: 30.10 (mins)
DB Time: 56.41 (mins)

Redo size: 195,218.05 4,395.22
Logical reads: 55,487.49 1,249.27
Block changes: 1,081.02 24.34
Physical reads: 37.40 0.84
Physical writes: 121.28 2.73
User calls: 3,250.79 73.19
Parses: 748.96 16.86
Hard parses: 168.37 3.79
Sorts: 42.21 0.95
Logons: 0.63 0.01
Executes: 2,726.37 61.38
Transactions: 44.42


Library Hit %: 95.57 Soft Parse %: 77.52
Execute to Parse %: 72.53 Latch Hit %: 99.60
Parse CPU to Parse Elapsd %: 21.23 % Non-Parse CPU: 89.08

CPU time 1,823 53.8
db file parallel write 155,543 804 5 23.7 System I/O
db file sequential read 67,673 780 12 23.0 User I/O
kksfbc child completion 12,132 660 54 19.5 Other
log file sync 108,553 430 4 12.7 Commit


parse time elapsed 951.54 28.11
hard parse elapsed time 140.03 4.14
failed parse elapsed time 74.89 2.2


opened cursors cumulative 66,499 36.82 0.83
parse count (failures) 304,102 168.36 3.79
parse count (hard) 304,105 168.37 3.79
parse count (total) 1,352,792 748.96 16.86

session_cached_cursors 400
sessions 6605
open_cursors 500
cursor_sharing FORCE

We are uisng OCI layer for database connections and program code is written in pro*c.


My question is

1) Why soft parses are high and where could be the problem ,even though the passed transaction
during that window are 38000?

We have also tried increasing session_cached_cursors to 1000 and open_cursors to 10000, but improvement is not observed.




more

Connor and Chris don't just spend all day on AskTOM. You can also catch regular content via Connor's blog and Chris's blog. Or if video is more your thing, check out Connor's channel and Chris's channel from their Youtube channels. And of course, keep up to date with AskTOM via the official twitter account.

More to Explore

Performance

Get all the information about database performance in the Database Performance guide.