Oracle FAQ | Your Portal to the Oracle Knowledge Grid |
Home -> Community -> Mailing Lists -> Oracle-L -> High Parse Calls(--> high latch free events)
Hi All,
Oracle Version: 8162
OS: Solaris ( SunOS 5.6)
We are doing load test on our application and db. During the load test we ran Statspack ( before and after) and took the snap report fo the start and end timestamps, during the load we say very high parse calls per sec( 900 parse req/ sec peak, and 285 parse req/sec average), In the statspack report, in the top 5 wait events. event ' Latch Free' has waits for 9000, here is the partial statspack report. CPU idil time is around 30% during the load test.
Question is even if the statements being parsed are found in the shared pool and shared ( developers are using bind variables..identical statements ...etc etc)the load of a parse call is high? What areas I should be looking and candidates for the tuning.
Thanks for any help,
Siva
partial Stats Pack Report:
cache Sizes
db_block_buffers: 131072
db_block_size: 8192
log_buffer: 5242880 shared_pool_size: 314572800
Load Profile
Per Second Per Transaction --------------- --------------- Redo size: 43,522.47 597.57 Logical reads: 1,164.26 15.99 Block changes: 292.49 4.02 Physical reads: 1.01 0.01 Physical writes: 2.50 0.03 User calls: 1,524.96 20.94 Parses: 285.49 3.92 Hard parses: 0.00 0.00 Sorts: 22.77 0.31 Transactions: 72.83 Rows per Sort: 10.44 Pct Blocks changed / Read: 25.12 Recursive Call Pct: 15.98 Rollback / transaction Pct: 0.70
Instance Efficiency Percentages (Target 100%)
Buffer Nowait Ratio: 99.44
Buffer Hit Ratio: 99.91
Library Hit Ratio: 100.01
Redo NoWait Ratio: 100.00
In-memory Sort Ratio: 99.96
Soft Parse Ratio: 100.00
Latch Hit Ratio: 99.44
Top 5 Wait Events
~~~~~~~~~~~~~~~~ Wait % Total Event Waits Time (cs) WtTime
-------------------------------------------- ------------ ------------ ------- log file sync 38,815 56,837 81.58 log file parallel write 18,998 6,492 9.32 latch free 9,206 3,192 4.58 buffer busy waits 3,184 2,381 3.42 db file parallel write 70 262 .38 -------------------------------------------------------------
->cs - centisecond - 100th of a second
->ms - millisecond - 1000th of a second (unit often used for disk IO timings)
Avg Total Wait wait Waits Event Waits Timeouts Time (cs) (ms)/txn
---------------------------- ------------ ---------- ----------- ----- ------ log file sync 38,815 0 56,837 15 1.1 log file parallel write 18,998 0 6,492 3 0.5 latch free 9,206 8,321 3,192 3 0.3 buffer busy waits 3,184 4 2,381 7 0.1 db file parallel write 70 0 262 37 0.0 SQL*Net more data to client 10,140 0 167 0 0.3 control file parallel write 176 0 110 6 0.0 enqueue 337 0 91 3 0.0 direct path write 227 0 33 1 0.0 direct path read 309 0 32 1 0.0 refresh controlfile command 112 0 22 2 0.0 control file sequential read 741 0 19 0 0.0 LGWR wait for redo copy 162 0 14 1 0.0 log file switch completion 3 0 14 47 0.0 file open 317 0 4 0 0.0 log file single write 4 0 4 10 0.0 file identify 4 0 0 0 0.0 log file sequential read 2 0 0 0 0.0 db file sequential read 1 0 0 0 0.0 db file single write 1 0 0 0 0.0 SQL*Net message from client 747,297 0 4,894,938 66 20.9 SQL*Net message to client 747,297 0 502 0 20.9 -------------------------------------------------------------
Background Wait Events
Avg Total Wait wait Waits Event Waits Timeouts Time (cs) (ms)/txn
---------------------------- ------------ ---------- ----------- ----- ------ log file parallel write 18,998 0 6,492 3 0.5 db file parallel write 70 0 262 37 0.0 control file parallel write 176 0 110 6 0.0 direct path read 120 0 26 2 0.0 LGWR wait for redo copy 162 0 14 1 0.0 file open 317 0 4 0 0.0 log file single write 4 0 4 10 0.0 control file sequential read 374 0 3 0 0.0 direct path write 60 0 1 0 0.0 file identify 4 0 0 0 0.0 log file sequential read 2 0 0 0 0.0 db file sequential read 1 0 0 0 0.0 db file single write 1 0 0 0 0.0 rdbms ipc message 35,448 429 205,163 58 1.0 smon timer 2 2 61,443 ##### 0.0 pmon timer 159 159 48,965 3080 0.0
Instance Activity Stats
Statistic Total per Second per Trans --------------------------------- ---------------- ------------ ------------ parse count (total) 139,890 285.5 3.9 parse time cpu 11,138 22.7 0.3 parse time elapsed 20,408 41.7 0.6
Buffer wait Statistics
Tot Wait Avg Class Waits Time (cs) Time (cs) ------------------ ----------- ---------- --------- data block 2,990 2,326 1 undo block 67 41 1 undo header 127 22 0
Latch Activity
->"Pct Misses" should be very close to 0.0
Pct Avg Pct Get Get Sleeps Nowait Nowait Latch Name Requests Miss /Miss RequestsMiss
------------------------------- ------------ ------ ------ ----------- ------ Active checkpoint queue latch 232 0.0 0 Checkpoint queue latch 15,196 0.0 0 Token Manager 122 0.0 0 archive control 120 0.0 0 archive process latch 1 0.0 0 cache buffers chains 1,386,788 0.4 0.1 3,221 0.7 cache buffers lru chain 300,673 0.0 0.0 7,770 0.0 dml lock allocation 83,994 0.0 0.0 0 dropped object history latch 5 0.0 0 enqueue hash chains 156,451 0.2 0.1 0 enqueues 272,986 0.1 0.1 0 job_queue_processes parameter l 7 0.0 0 ktm global data 1 0.0 0 latch wait list 7,363 1.0 0.1 7,327 0.1 library cache 1,292,955 1.9 0.3 0 list of block allocation 70,950 0.0 0.0 0 loader state object freelist 20 0.0 0 messages 131,361 0.1 0.0 0 ncodef allocation latch 7 0.0 0 redo allocation 110,048 0.1 0.0 0 redo writing 148,423 0.5 0.0 0 row cache objects 1,546 0.0 0 sequence cache 3 0.0 0 session allocation 279,492 0.3 0.0 0 session idle bit 1,634,184 0.1 0.3 0 session switching 7 0.0 0 shared pool 483 0.0 0 sort extent pool 11 0.0 0 transaction allocation 111,840 0.1 0.0 0 transaction branch allocation 7 0.0 0 undo global data 226,340 0.2 0.0 0 -------------------------------------------------------------
Latch Sleep breakdown
Get Spin & Latch Name Requests Misses Sleeps Sleeps 1-4 ---------------------------- ------------ ----------- ----------- ------------ library cache 1,292,955 25,000 7,891 17723/6695/5 56/26/0 cache buffers chains 1,386,788 5,005 540 4469/532/4/0 /0 session idle bit 1,634,184 1,950 633 1329/609/12/ 0/0 session allocation 279,492 838 22 816/22/0/0/0 redo writing 148,423 719 19 700/19/0/0/0 undo global data 226,340 430 13 417/13/0/0/0 enqueues 272,986 380 44 336/44/0/0/0 enqueue hash chains 156,451 289 32 261/24/4/0/0 transaction allocation 111,840 99 2 98/0/1/0/0 redo allocation 110,048 96 3 93/3/0/0/0 latch wait list 7,363 76 5 72/3/1/0/0 dml lock allocation 83,994 39 1 38/1/0/0/0 list of block allocation 70,950 28 1 27/1/0/0/0 -------------------------------------------------------------
Latch Miss Sources
No Wait Latch Name Where MissesSleeps
------------------------------ -------------------------- ------- ----------- cache buffers chains kcbgtcr: kslbegin 0 378 cache buffers chains kcbchg: kslbegin: bufs not 0 83 cache buffers chains kcbgcur: kslbegin 0 40 cache buffers chains kcbchg: kslbegin: call CR 0 21 cache buffers chains kcbnlc 0 7 cache buffers chains kcbrls: kslbegin 0 5 cache buffers chains kcbzwb 0 5 cache buffers chains kcbzgb: scan from tail. no 0 1 dml lock allocation ktaidm 0 1 enqueue hash chains ksqgtl3 0 24 enqueue hash chains ksqrcl 0 8 enqueues ksqies 0 30 enqueues ksqgtl2 0 12 enqueues ksqgel: create enqueue 0 2 latch wait list kslges 8 4 latch wait list kslfre 6 1 library cache kglhdgn: child: 0 7,333 library cache kglpnal: child: alloc spac 0 198 library cache kglpnal: child: before pro 0 161 library cache kglpnc: child 0 85 library cache kgldte: child 0 0 25 library cache kgllkdl: child: cleanup 0 24 library cache kglhdgc: child: 0 23 library cache kglupc: child 0 22 library cache kgllkdl: child: free pin 0 17 list of block allocation ktlbbl 0 1 redo allocation kcrfwr: redo allocation 0 3 redo writing kcrfsr 0 12 redo writing kcrfss 0 6 redo writing kcrfwi: after write 0 1 session allocation ksucri 0 12 session allocation ksuxds: not user session 0 10 session idle bit ksupuc: set busy 0 334 session idle bit ksupuc: clear busy 0 266 session idle bit ksuxds 0 33 transaction allocation ktcxba 0 2 undo global data kturdc: KSLBEGIN 0 5 undo global data ktubnd 0 4 undo global data ktudba: KSLBEGIN 0 3 undo global data ktudnx: KSLBEGIN 0
-- Please see the official ORACLE-L FAQ: http://www.orafaq.com -- Author: Valiveru, Siva INET: SValiveru_at_ea.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).Received on Tue May 22 2001 - 12:07:35 CDT