High library cache load lock waits in AWR

From: Neeraj Bhatia <neeraj.dba_at_gmail.com>
Date: Mon, 13 Jul 2009 18:58:58 +0530
Message-ID: <a8fd4d730907130628m47bdf117w44c8b177c6e04fa_at_mail.gmail.com>

 Hi All,

Today i faced a significant performance problem related to shared pool. I made some observations, thought it would be a nice idea to share them with Oracle experts. Please feel free to add your observations/recommendations and correct me where i am wrong.

Here are the excerpts from AWR report created for the problem timing. Database server is on 10.2.0.3 and running with 2*16 configuration. DB cache size is 4,000M and shared pool size is of 3008M.

 Snap Id
 Snap Time
 Sessions
 Cursors/Session
 Begin Snap:
 9994
 29-Jun-09 10:00:07
 672
 66.3
 End Snap:
 10001
 29-Jun-09 17:00:49
 651
 64.4
 Elapsed:

 420.70 (mins)

 DB Time:

 4,045.34 (mins)

• Very poor response time visible from difference between DB time and elapsed time. Load Profile:

   Per Second Per Transaction Redo size: 248,954.70 23,511.82 Logical reads: 116,107.04 10,965.40 Block changes: 1,357.13 128.17 Physical reads: 125.49 11.85 Physical writes: 51.49 4.86 User calls: 224.69 21.22 Parses: 235.22 22.21 Hard parses: 4.83 0.46 Sorts: 102.94 9.72 Logons: 1.12 0.11 Executes: 821.11 77.55 Transactions: 10.59

• User calls and Parse count are almost same, means most of the calls are for parse. Most of the parses are soft. Per transaction 22 parses are very high figure.
• Not much disk I/O activity. Most of the reads are being satisfy from memory.

Instance Efficiency

  Buffer Nowait %: 100.00 Redo NoWait %: 100.00 Buffer Hit %: 99.92 In-memory Sort %: 100.00 Library Hit %: 98.92 Soft Parse %: 97.95 Execute to Parse %: 71.35 Latch Hit %: 99.98 Parse CPU to Parse Elapsd %: 16.82 % Non-Parse CPU: 91.41

• Low execute to parse ratio denotes CPU is significantly busy in parsing. Soft Parse% showing, most of the parse are soft parses. It means we should concentrate on soft parsing activity.
  • Parse CPU to Parse Elapsed % is quite low, means some bottleneck is there related to parsing. It could be a side-effect of huge parsing pressure. Like CPU cycles are not available.

Shared Pool Statistics

  Begin End Memory Usage %: 81.01 81.92 % SQL with executions>1: 88.51 86.93 % Memory for SQL w/exec>1: 86.16 86.76

• Shared Pool memory seems ok (in 80% range)
• 88% of the SQLs are repeating ones. It's a good sign.

Top 5 Timed Events

  Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class library cache load lock 24,243 64,286 2,652 26.5 Concurrency db file sequential read 1,580,769 42,267 27 17.4 User I/O CPU time 33,039 13.6 latch: library cache 53,013 29,194 551 12.0 Concurrency db file scattered read 151,669 13,550 89 5.6 User I/O

Problem-1: Contention on Library cache: May be due to under-sized shared pool, incorrect parameters, poor application design, But since we already observed that most of the parses are soft parses and shared pool usgae in 80%, seems problem related to holding cursors. open_cursors/session_cached_cursors are red flags.

Problem-2: User I/O, may be due to poor SQLs, I/O sub-system, or poor physical design (wrong indexes are being used as DB file seq reads)

Wait Class

  Wait Class Waits %Time -outs Total Wait Time (s) Avg wait (ms) Waits /txn Concurrency 170,577 44.58 109,020 639 0.64

Wait Events

  Event Waits %Time -outs Total Wait Time (s) Avg wait (ms) Waits /txn library cache load lock 24,243 83.95 64,286 2652 0.09 db file sequential read 1,580,769 0.00 42,267 27 5.91 latch: library cache 53,013 0.00 29,194 551 0.20 db file scattered read 151,669 0.00 13,550 89 0.57 latch: shared pool 25,403 0.00 12,969 511 0.10 log file sync 176,671 0.37 4,528 26 0.66 enq: TM - contention 1,455 90.93 3,975 2732 0.01 db file parallel write 255,356 0.00 3,391 13 0.96

Instance Activity Stats

                       Statistic Total per Second per Trans

   parse count (failures)
 6,181
 0.24
 0.02
 parse count (hard)
 121,841
 4.83
 0.46
 parse count (total)
 5,937,336
 235.22
 22.21
 parse time cpu
 283,787
 11.24
 1.06
 parse time elapsed
 1,687,096
 66.84
 6.31

Latch Activity

  Latch Name Get Requests Pct Get Miss Avg Slps /Miss Wait Time (s) NoWait Requests Pct NoWait Miss
  library cache 85,042,375 0.15 0.43 29194 304,831 7.16 library cache load lock 257,089 0.00 1.20 0 69,065 0.00 library cache lock 41,467,300 0.02 0.07 6 2,714 0.07 library cache lock allocation 730,422 0.00 0.44 0 0 library cache pin 28,453,986 0.01 0.16 8 167 0.00 library cache pin allocation 509,000 0.00 0.38 0 0

Init.ora parameters

  cursor_sharing EXACT
  open_cursors 3000
  session_cached_cursors 0

• open_cursors value is too high. I have checked that maximum usage by a single session is 12%.
  -- session_cached_cursors are 0 causing soft parsing. 500/600 is good number
  to start with. cursor_sharing exact may cause hard parses. But here, hard parsing is comparatively small, we can ignore this.

From v$librarycache

NAMESPACE GETS GETHITS GETHITRATIO PINS PINHITRATIO RELOADS INVALIDATIONS
--------------- ---------- ---------- ----------- ---------- -----------

• ------------- SQL AREA 162827 25127 .154317159 748901435 .999153087 107941 81886
  • high invalidation count due to DDL like activities.
  • high reloads due to small library cache.
  • hit ratio too small.
  • Need to pin frequently executed objects into library cache.

Thanks,
Neeraj Bhatia

--

http://www.freelists.org/webpage/oracle-l Received on Mon Jul 13 2009 - 08:28:58 CDT