Library cache latches gone in Oracle 11g

In Oracle 11g even more library cache operations have been changed to use KGX mutexes instead of latches.

In Oracle 10.2.0.2+ the library cache pin latch usage was replaced with mutexes whenever _kks_use_mutex_pin was true, also few other things like V$SQLSTATS arrays and parent cursor examination were protected by mutexes. However the traversing of library cache hash chains (the right child cursor lookup using kksfbc()) was still protected by library cache latches which could become a problem with frequent soft parsing combined with too little cursor cache and long library cache hash chains (remember, the library cache latches were always taken exclusively even for plain hash chain scanning).

In 11g all library cache related latches except “library cache load lock” are gone and corresponding operations are protected by mutexes instead. The “library cache” latches have been replaced by “Library Cache” mutexes for example.

Here are couple queries which illustrate the change.

Executed on 10.2.0.3:

SQL> select name from v$latch where lower(name) like '%library%';

NAME
--------------------------------------------------
library cache pin allocation
library cache lock allocation
library cache hash chains
library cache lock
library cache
library cache pin
library cache load lock

7 rows selected.

SQL> select name from v$event_name where name like '%library%';

NAME
----------------------------------------------------------------
latch: library cache
latch: library cache lock
latch: library cache pin
library cache pin
library cache lock
library cache load lock
library cache revalidation
library cache shutdown

8 rows selected.

Same queries executed on 11.1.0.6 and the bold lines above are gone:

SQL> select name from v$latch where lower(name) like '%library%';

NAME
----------------------------------------------------------------
library cache load lock

SQL> select name from v$event_name where name like '%library%';

NAME
----------------------------------------------------------------
library cache pin
library cache lock
library cache load lock
library cache: mutex X
library cache: mutex S
OSD IPC library
library cache revalidation
library cache shutdown

8 rows selected.

Looks like the developers have thrown out library cache latching mechanism in 11g as the mutexes introduced in 10.2 have proven to work fine (and they have managed to implement mutexes for protecting (almost) the full set of library cache operations).
So there is no way to revert back to old behaviour using _kks_use_mutex_pin=false (and you wouldn’t need to do this anyway, btw). The parameter is still there though and out of interest I checked what happens if I set it to false and bounced the instance.

As, expected, I started getting error messages like following right after startup:

ORA-03113: end-of-file on communication channel

ORA-00600: internal error code, arguments: [kglGetSessionUOL], [7], [], [], [], [], [], []

This is a good example of dangers with undocumented parameters – they may work ok in one version (and platform) but could cause serious trouble anywhere else.

Anyway, back to mutexes. In 10g you see there are 3 types of mutexes used:

SQL> select * from v$mutex_sleep;

MUTEX_TYPE                       LOCATION                                     SLEEPS  WAIT_TIME
-------------------------------- ---------------------------------------- ---------- ----------
Cursor Stat                      kksFindCursorStat [KKSSTALOC3]                  339        775
Cursor Parent                    kkspsc0 [KKSPRTLOC26]                          1507     123969
Cursor Parent                    kksLoadChild [KKSPRTLOC5]                       170        372
Cursor Parent                    kksLoadChild [KKSPRTLOC4]                       385       3799
Cursor Parent                    kksfbc [KKSPRTLOC2]                            1649      22484
Cursor Parent                    kksfbc [KKSPRTLOC1]                             128       1599
Cursor Pin                       kksLockDelete [KKSCHLPIN6]                     3505     928387
Cursor Pin                       kkslce [KKSCHLPIN2]                           15343  160394917
Cursor Pin                       kksfbc [KKSCHLFSP2]                            3219    9065433

9 rows selected.

In 11g there are couple additional mutexes, one (and most important) of them is Library Cache mutex:

SQL> select distinct mutex_type from v$mutex_sleep_history;

MUTEX_TYPE
--------------------------------
Library Cache
Cursor Pin
Cursor Parent
Cursor Stat

(I had to sample v$mutex_sleep_history instead of v$mutex_sleep on 11g as the latter was empty on 11g… it may be that the mutex get operations have been tuned further to not maintain the counters just to save even few more CPU cycles every get)

So, starting from 11g, each library cache bucket is protected by a separate mutex (yes all 131072 of them!).

Previously we had all those buckets were hashed to and protected by max 67 library cache latches which inevitably were prone to unnecessary false contention in case of many cursors being executed concurrently. Now this issue should be resolved once and for all. Of course the library cache mutexes still don’t solve all problems in the world (especially the ones related to excessive hard parsing!), for example there’s still a chance of hash collision of two entirely different cursors. Also, if there are many child cursors under a parent and the application cursor management is poor (e.g. cursors are closed after every execution and no session cursor caching is done) then you could still have contention on the mutex due continuous library cache hash chain traversing.

This entry was posted in Oracle and tagged , . Bookmark the permalink.

63 Responses to Library cache latches gone in Oracle 11g

  1. The mutex implementation is not completely issue free yet on 11g. We’ve had a number of production issues with waits on “cursor : pin s wait on x” blocking select statements.

  2. tanelp says:

    That’s why I don’t recommend 11g for production yet :)

  3. Dion Cho says:

    Thanks for good information!

  4. Jeff Holt says:

    How much of this decision process has Server Technologies documented?

    The number of bytes allocated to pthread_mutex_t (if they’re using pthread) is on the order of 24 bytes. Its definition places no contraints on the number of mutexes beyond what can be stored in the process heap. So, the memory required to store even a million mutexes (let alone a hundred thousand or so) does not concern me.

    What concerns me is that Server Technologies is essentially throwing away over 20 years experience regarding how their RDBMS acts under load. Their spin lock code should reflect that intimate knowledge.

    What they’re doing is taking mutexes and assuming they work well for the RDBMS. The mutex, at least in its POSIX form, is not nearly as robust as Oracle’s spin lock code. That in itself justifies suspicion.

    I’m perfectly willing to stand corrected if ST gives a compelling argument. Until then, I think we should at least question their decision.

  5. tanelp says:

    Jeff, the Oracle KGX mutexes I was talking about are just memory locations in SGA, somewhat like latches (but smaller). Oracle engineers have decided to call these mutexes (as they have similar characteristics to OS mutexes with their refcounters).

    As far as library cache latching is considered, not too much has changed (well for me it’s easy to say that, I didn’t have to code that change;-)
    Instead of 67 library cache latches which indirectly protect lots of library cache hash buckets, now every bucket has a mutex directly protecting it and library cache latches aren’t needed anymore.

    If Oracle used OS pthread mutexes for library cache latching, this would take us back to 80′s as throughput is concerned – issuing a syscall instead of just lock & few memory ops would make the library cache mechanism a big bottleneck…

  6. tanelp says:

    Jeff, I might have misinterpreted your initial comment… I think the KGX mutexes are actually an evolution from latching mechanism, now that memory’s cheap and you can have a separate mutex protecting every cursor child, library cache bucket etc. Oracle mutexes are still spinlocks (they can spin & sleep if the client requests so), their main benefit is that they are flexible enough to be embedded in any higher level structure – and have one mutex per shared structure element for avoiding any false contention.

  7. Tanel,
    did i understand you right?
    a latch was something like a global structure to keep a global structure and many objects of it (like shared pool) save – now mutexes are aligned to every object so contention is much reduced. So mutexes are much more fine-graded;
    did i get the point?

    Karl

  8. tanelp says:

    Hi Karl,

    Yep, Oracle developers have chosen to use much more fine grained locking in various places in 10.2 and 11g.

    This is thanks to mutexes being smaller than latches in memory footprint and their flexibility – you can embed mutexes in other structures like cursor handles whenever they are created.

    So, from 10.2 every parent and child cursor has a mutex built into it, from 11g every library cache hash bucket is protected by separate mutex (there still may be multiple KGL objects protected by a Library Cache mutex if there’s multiple child cursors under a parent or if libcache object hash values collide).

  9. binzhang says:

    I found that TOP wait event library cache pin was replaced by event “cursor:pin S” while there’re excessive executions in 10g.

    Upgrade CPU is still an efficient way to deal with capacity problem.

    Thanks,
    Bin

  10. Andrew Filmer says:

    Would really appreciate a comment on this:

    We have a 24-CPU HP SuperDome, normally runs at 70-80% utilisation during peak hours.

    Application is OLTP, typically 1500 sessions connected, 20 active sessions.

    Oracle version 10.2.0.4.0

    Did an application upgrade 2 days ago, and since then, the CPU utilisation is up by 20%, occassionally hits 100%.

    Since then, sporadically get a bunch of sessions waiting on cursor: pin s, the SQL being executed by the waiting sessions is:

    SELECT SYS_CONTEXT(‘userenv’, ‘sessionid’) FROM DUAL;

    Read Dominic’s comment on Aug 3rd, and sounds similar.

    Why does CPU starvation cause this?

    Thanks

    Andrew

  11. Andrew,

    that’s a very common problem which plagued (and still does) a lot of people starting from 10.2.0.2 (where mutexes became ON by default). The immediate solution for you might be turning mutexes off using _kks_use_mutex_pin=false which should solve your problem.

    You may try to reference v$mutex_sleep_history — this will give you an idea during what time you experience the problem at it most, might give you some clues if you’ll be able to match it with other workload data.

    The important thing here is not to confuse cause and effect, the CPU starvation might be result of your problem, not the cause.

    Not sure removing this option from 11G was a good choice. Though you have to draw a line somewhere and abandon the legacy code, it doesn’t look like it is the right time.

  12. Tanel Poder says:

    If Andrew’s Superdome runs on PA-RISC CPUs, the issue may be in a bug (#5399325), described in metalink note 433631.1

    This has to do with Oracle using latches for simulating KGX Mutexes as apparently PA-RISC CPUs dont support atomic CAS operations required for mutex operation..

    The bug *should* be fixed in 10.2.0.4 though.

    The _kks_use_mutex_pin should be used as a temporary workaround in case of bugs. Every case where using mutexes gives worse scalability than with latches is likely a bug (not an inherend design issue) as with mutexes every resource normally has their own lock (compared to latches where one lock protects many resources). Thus by design, mutexes scale better, if they don’t in practice, it’s a code bug.

  13. Prashant says:

    Hi Tanel,
    I am running 11.1.0.7 on RHEL AS4U6 and I see a lot of ‘cursor: pin S wait on X’ waits while we do stress test of our application. This is one of the top 2 wait events in the database right now. Not sure whether the patch for the bug (5399325) was ever made part of 11.1.0.7 patchset. What would you suggest?

    Thanks.

  14. Tanel Poder says:

    Hi Prashant,

    The “cursor: pin S wait on X” wait is different from “cursor: pin S” which was mentioned above. Seeing lots of “cursor: pin S” usually means a bug or an issue with HP PA-RISC simulated mutexes.

    Seeing “cursor: pin S wait on X” means either shared pool pressure (cursor subheaps aged out and loaded back in) or again a bug :)

    11g has instrumentation though, can you paste me the output from v$mutex_sleep and some lines from v$mutex_sleep_history?

  15. Tanel Poder says:

    Btw there are more reasons for “cursor: pin S wait on X” waits in addition to the two mentioned above, but lets see what v$mutex_sleep% views say.

    Got to go to sleep now, will get back tomorrow.

  16. Tanel Poder says:

    Prashant, Here are also few known issues related to 10g:

    http://momendba.blogspot.com/2007/06/cursor-pin-s-wait-on-x-wait-event-in.html

    Even though you’re on 11g, its good to read through the notes.

  17. Prashant says:

    Note that this happens after we flush the shared pool right before getting ready to start a performance test. After about 5 mins it goes away. But there is heavy contention in the beginning.

    Here is v$mutex_sleep:

    MUTEX_TYPE LOCATION SLEEPS WAIT_TIME

    Library Cache kgllldl2 112 20 0
    Library Cache kglllal3 111 14 0
    Library Cache kglllal1 109 26 0
    Library Cache kglhdgn2 106 7638 0
    Library Cache kglhdgc1 102 13 0
    Library Cache kglpndl1 95 61623 0
    Library Cache kglpnal1 90 10859 0
    Library Cache kgllkdl1 85 776515 0
    Library Cache kgllkal3 82 1 0
    Library Cache kglrfcl1 79 9201 0
    Library Cache kglobld1 75 182 0
    Library Cache kglobpn1 71 12943 0
    Library Cache kglhdgn1 62 2016794 0
    Library Cache kglabl1 58 9645 0
    Library Cache kgllkc1 57 9697 0
    Library Cache kgluhfs1 53 2 0
    Library Cache kglkhfs1 52 9 0
    Library Cache kglic1 49 3604497 0
    Library Cache kglnti1 46 2 0
    Library Cache kglati1 45 11988 0
    Library Cache kgldtin1 42 1460 0
    Library Cache kgldtld1 40 2 0
    Library Cache kglpin1 4 125072 0
    Library Cache kglget2 2 2345 0
    Cursor Stat kkocsStoreBindAwareStats [KKSSTALOC8] 548 14566
    Cursor Parent kkshbbr [KKSPRTLOC15] 1 3393
    Cursor Parent kkshbsf [KKSPRTLOC14] 1 7
    Cursor Parent kkshdelq [KKSPRTLOC13] 1 10
    Cursor Parent kksLoadChild [KKSPRTLOC4] 41 2421
    Cursor Parent kksfbc [KKSPRTLOC2] 264 10597
    Cursor Parent kksfbc [KKSPRTLOC1] 1323 110755
    Cursor Pin kksLockDelete [KKSCHLPIN6] 771 13810
    Cursor Pin kksxsccmp [KKSCHLPIN5] 6 35111
    Cursor Pin kksSetBindType [KKSCHLPIN4] 10 103537
    Cursor Pin kksSetBindType [KKSCHLPIN3] 1 3
    Cursor Pin kkslce [KKSCHLPIN2] 1083534 3340618435
    Cursor Pin kksfbc [KKSCHLPIN1] 61 160078
    Cursor Pin kksfbc [KKSCHLFSP2] 2672 3430067

    Here is data for only “Cursor Pin” type from v$mutex_sleep_history. The rest of the columns e.g. P* are either zero or NULL.

    SLEEP_TIMESTAMP MUTEX_TYPE GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION MUTEX_VALUE

    2/20/2009 2:21:30.186058 PM Cursor Pin 102886 1 345 399 kksLockDelete [KKSCHLPIN6] 0000000000000002
    2/20/2009 2:21:26.475093 PM Cursor Pin 798 457 344 319 kkslce [KKSCHLPIN2] 0000013F00000000
    2/20/2009 2:21:11.313089 PM Cursor Pin 792 448 399 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:20:15.843330 PM Cursor Pin 16 94 345 327 kkslce [KKSCHLPIN2] 0000014700000000
    2/20/2009 2:20:15.722354 PM Cursor Pin 777 446 345 378 kkslce [KKSCHLPIN2] 0000017A00000000
    2/20/2009 2:18:46.469569 PM Cursor Pin 732 428 378 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:18:46.359532 PM Cursor Pin 13 83 378 319 kkslce [KKSCHLPIN2] 0000013F00000000
    2/20/2009 2:18:46.238545 PM Cursor Pin 727 418 378 311 kkslce [KKSCHLPIN2] 0000013700000000
    2/20/2009 2:17:55.673060 PM Cursor Pin 11 62 345 393 kkslce [KKSCHLPIN2] 0000018900000000
    2/20/2009 2:17:55.556251 PM Cursor Pin 682 383 345 376 kkslce [KKSCHLPIN2] 0000017800000000
    2/20/2009 2:17:55.268789 PM Cursor Pin 679 367 322 314 kkslce [KKSCHLPIN2] 0000013A00000000
    2/20/2009 2:17:18.576463 PM Cursor Pin 649 365 380 393 kkslce [KKSCHLPIN2] 0000018900000000
    2/20/2009 2:16:58.403967 PM Cursor Pin 630 353 354 355 kkslce [KKSCHLPIN2] 0000016300000000
    2/20/2009 2:16:58.285654 PM Cursor Pin 628 343 355 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:16:58.085246 PM Cursor Pin 412774 7 321 415 kksfbc [KKSCHLFSP2] 00
    2/20/2009 2:16:57.901863 PM Cursor Pin 19288 1 381 0 kksLockDelete [KKSCHLPIN6] 0000000000000002
    2/20/2009 2:16:37.809913 PM Cursor Pin 614 333 388 415 kkslce [KKSCHLPIN2] 0000019F00000000
    2/20/2009 2:16:24.755687 PM Cursor Pin 596 330 360 387 kkslce [KKSCHLPIN2] 0000018300000000
    2/20/2009 2:15:22.171604 PM Cursor Pin 542 299 388 320 kkslce [KKSCHLPIN2] 0000014000000000
    2/20/2009 2:15:16.980338 PM Cursor Pin 532 292 415 406 kkslce [KKSCHLPIN2] 0000019600000000
    2/20/2009 2:14:52.964388 PM Cursor Pin 509 277 395 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:13:28.958697 PM Cursor Pin 16857 1 364 360 kksfbc [KKSCHLFSP2] 0000016800000001
    2/20/2009 2:12:57.968951 PM Cursor Pin 421 254 398 348 kkslce [KKSCHLPIN2] 0000015C00000000
    2/20/2009 2:12:13.215425 PM Cursor Pin 9 52 380 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:11:49.895382 PM Cursor Pin 18378 2 395 326 kksfbc [KKSCHLFSP2] 0000014600000001
    2/20/2009 2:11:35.918073 PM Cursor Pin 348 233 314 380 kkslce [KKSCHLPIN2] 0000017C00000000
    2/20/2009 2:11:35.796553 PM Cursor Pin 7 40 380 359 kkslce [KKSCHLPIN2] 0000016700000000
    2/20/2009 2:11:23.477772 PM Cursor Pin 75504 49 321 389 kksLockDelete [KKSCHLPIN6] 0000018500000002
    2/20/2009 2:10:59.433684 PM Cursor Pin 70759 48 392 311 kksfbc [KKSCHLFSP2] 0000013700000001
    2/20/2009 2:10:56.768807 PM Cursor Pin 307 202 313 310 kkslce [KKSCHLPIN2] 0000013600000000
    2/20/2009 2:10:44.494906 PM Cursor Pin 5 31 378 344 kkslce [KKSCHLPIN2] 0000015800000000
    2/20/2009 2:10:42.555609 PM Cursor Pin 289 168 344 397 kkslce [KKSCHLPIN2] 0000018D00000000
    2/20/2009 2:10:38.631228 PM Cursor Pin 23321 9 379 338 kksfbc [KKSCHLFSP2] 0000000000000001
    2/20/2009 2:10:19.418357 PM Cursor Pin 267 154 332 381 kkslce [KKSCHLPIN2] 0000017D00000000
    2/20/2009 2:09:06.989506 PM Cursor Pin 5444 1 397 360 kksLockDelete [KKSCHLPIN6] 0000000000000002
    2/20/2009 2:08:39.944810 PM Cursor Pin 18796 1 327 388 kksxsccmp [KKSCHLPIN5] 0000018400000001
    2/20/2009 2:08:20.270592 PM Cursor Pin 175 114 354 390 kkslce [KKSCHLPIN2] 0000018600000000
    2/20/2009 2:07:12.929330 PM Cursor Pin 1 10 314 381 kkslce [KKSCHLPIN2] 0000017D00000000
    2/20/2009 2:07:00.007183 PM Cursor Pin 109 66 360 331 kkslce [KKSCHLPIN2] 0000014B00000000
    2/20/2009 2:05:28.341261 PM Cursor Pin 34632 3 389 332 kksfbc [KKSCHLFSP2] 0000014C00000000
    2/20/2009 2:05:28.341261 PM Cursor Pin 34632 3 389 332 kksfbc [KKSCHLFSP2] 0000014C00000000
    2/20/2009 2:05:27.134542 PM Cursor Pin 34032 2 350 408 kksLockDelete [KKSCHLPIN6] 0000019800000002
    2/20/2009 2:05:02.301966 PM Cursor Pin 31 22 395 344 kkslce [KKSCHLPIN2] 0000015800000000
    2/20/2009 2:04:38.668483 PM Cursor Pin 583 1 406 390 kksLockDelete [KKSCHLPIN6] 0000018600000002
    2/20/2009 2:04:38.600969 PM Cursor Pin 9 6 359 311 kkslce [KKSCHLPIN2] 0000013700000000
    2/20/2009 2:04:38.568026 PM Cursor Pin 9 5 311 314 kkslce [KKSCHLPIN2] 0000013A00000000
    2/20/2009 2:04:38.443001 PM Cursor Pin 1 6 405 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:04:38.443001 PM Cursor Pin 1 6 405 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:04:38.414474 PM Cursor Pin 9 7 326 388 kkslce [KKSCHLPIN2] 0000018400000000
    2/20/2009 2:04:38.369192 PM Cursor Pin 1 1 388 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:04:23.359184 PM Cursor Pin 1 1 406 376 kkslce [KKSCHLPIN2] 0000017800000000
    2/20/2009 2:04:23.347590 PM Cursor Pin 1 38 406 376 kkslce [KKSCHLPIN2] 0000017800000000
    2/20/2009 2:04:11.496675 PM Cursor Pin 1 21 390 314 kkslce [KKSCHLPIN2] 0000013A00000000
    2/20/2009 2:04:11.476722 PM Cursor Pin 1 4580 321 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:04:04.482417 PM Cursor Pin 1 3 399 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:04:04.466917 PM Cursor Pin 1 10 408 388 kkslce [KKSCHLPIN2] 0000018400000000
    2/20/2009 2:04:04.410671 PM Cursor Pin 1 5 332 390 kkslce [KKSCHLPIN2] 0000018600000000
    2/20/2009 2:04:04.389476 PM Cursor Pin 1 12 362 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:04:04.355414 PM Cursor Pin 1 4 390 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:04:04.318826 PM Cursor Pin 1 8 390 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:04:01.352992 PM Cursor Pin 1 2 390 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:04:01.337676 PM Cursor Pin 1 14 390 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:04:01.323755 PM Cursor Pin 1 11 408 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:57.414563 PM Cursor Pin 1 1 388 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:57.414563 PM Cursor Pin 1 1 388 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:57.056609 PM Cursor Pin 1 1 354 362 kkslce [KKSCHLPIN2] 0000016A00000000
    2/20/2009 2:03:57.034229 PM Cursor Pin 1 4 362 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:56.932281 PM Cursor Pin 1 2 338 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:56.906708 PM Cursor Pin 1 1 362 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:56.897550 PM Cursor Pin 1 1 354 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:56.810319 PM Cursor Pin 1 1 354 362 kkslce [KKSCHLPIN2] 0000016A00000000
    2/20/2009 2:03:56.791915 PM Cursor Pin 1 2 362 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:56.762475 PM Cursor Pin 1 2 338 362 kkslce [KKSCHLPIN2] 0000016A00000000
    2/20/2009 2:03:54.318286 PM Cursor Pin 1 28 332 362 kkslce [KKSCHLPIN2] 0000016A00000000
    2/20/2009 2:03:46.366916 PM Cursor Pin 1 70 405 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:46.200872 PM Cursor Pin 1 4 338 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:46.111659 PM Cursor Pin 9 8 338 405 kkslce [KKSCHLPIN2] 0000019500000000
    2/20/2009 2:03:46.077153 PM Cursor Pin 9 25 405 399 kkslce [KKSCHLPIN2] 0000018F00000000
    2/20/2009 2:03:45.920916 PM Cursor Pin 1 14 326 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:45.887617 PM Cursor Pin 1 4 405 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:45.861153 PM Cursor Pin 1 4 405 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:45.849166 PM Cursor Pin 1 16 405 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:45.804141 PM Cursor Pin 1 4 405 399 kkslce [KKSCHLPIN2] 0000018F00000000
    2/20/2009 2:03:45.708696 PM Cursor Pin 1 7 326 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:45.689602 PM Cursor Pin 1 1 408 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:45.562281 PM Cursor Pin 1 1 408 388 kkslce [KKSCHLPIN2] 0000018400000000
    2/20/2009 2:03:44.499890 PM Cursor Pin 1 7 408 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:44.488655 PM Cursor Pin 1 1 354 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:44.487181 PM Cursor Pin 1 7 388 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:44.487181 PM Cursor Pin 1 7 388 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:44.477040 PM Cursor Pin 1 198 354 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:44.206150 PM Cursor Pin 1 5 332 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:44.180283 PM Cursor Pin 1 8 354 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:44.036597 PM Cursor Pin 1 2 354 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:43.777055 PM Cursor Pin 9 3 396 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:03:41.948047 PM Cursor Pin 1 552 396 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:03:40.787033 PM Cursor Pin 1 4 354 388 kkslce [KKSCHLPIN2] 0000018400000000
    2/20/2009 2:03:40.739913 PM Cursor Pin 1 4 332 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:40.728096 PM Cursor Pin 1 6 332 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:40.670291 PM Cursor Pin 1 3 405 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:40.648581 PM Cursor Pin 1 3 405 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:40.609100 PM Cursor Pin 1 4 332 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:40.593131 PM Cursor Pin 1 5 396 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:40.303240 PM Cursor Pin 9 89 321 388 kkslce [KKSCHLPIN2] 0000018400000000
    2/20/2009 2:03:39.936278 PM Cursor Pin 9 2 332 396 kkslce [KKSCHLPIN2] 0000018C00000000
    2/20/2009 2:03:39.807720 PM Cursor Pin 9 4 321 405 kkslce [KKSCHLPIN2] 0000019500000000
    2/20/2009 2:03:39.708073 PM Cursor Pin 9 8 321 405 kkslce [KKSCHLPIN2] 0000019500000000
    2/20/2009 2:03:39.239173 PM Cursor Pin 9 1 396 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:03:39.239173 PM Cursor Pin 9 1 396 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:03:38.771558 PM Cursor Pin 9 5 321 396 kkslce [KKSCHLPIN2] 0000018C00000000
    2/20/2009 2:03:38.746844 PM Cursor Pin 1 1 321 396 kkslce [KKSCHLPIN2] 0000018C00000000
    2/20/2009 2:03:38.738261 PM Cursor Pin 9 5 405 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:03:38.705499 PM Cursor Pin 9 8 405 396 kkslce [KKSCHLPIN2] 0000018C00000000
    2/20/2009 2:03:38.667530 PM Cursor Pin 9 2 405 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:03:38.528604 PM Cursor Pin 1 1 405 396 kkslce [KKSCHLPIN2] 0000018C00000000
    2/20/2009 2:03:38.473389 PM Cursor Pin 1 2 405 396 kkslce [KKSCHLPIN2] 0000018C00000000
    2/20/2009 2:03:38.402436 PM Cursor Pin 9 7 405 396 kkslce [KKSCHLPIN2] 0000018C00000000
    2/20/2009 2:03:37.740053 PM Cursor Pin 1 450 332 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:36.101510 PM Cursor Pin 1 1 332 405 kkslce [KKSCHLPIN2] 0000019500000000
    2/20/2009 2:03:35.754607 PM Cursor Pin 1 18 354 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:35.666611 PM Cursor Pin 1 9 354 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:35.083238 PM Cursor Pin 1 2 338 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:03:34.481772 PM Cursor Pin 1 17 354 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:34.262445 PM Cursor Pin 1 97 405 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:33.877571 PM Cursor Pin 1 1 405 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:33.822657 PM Cursor Pin 9 5 332 405 kkslce [KKSCHLPIN2] 0000019500000000
    2/20/2009 2:03:33.781023 PM Cursor Pin 1 1 396 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:33.772398 PM Cursor Pin 1 2 405 332 kkslce [KKSCHLPIN2] 0000014C00000000
    2/20/2009 2:03:33.707596 PM Cursor Pin 1 1 405 396 kkslce [KKSCHLPIN2] 0000018C00000000
    2/20/2009 2:03:33.271985 PM Cursor Pin 1 2 338 370 kkslce [KKSCHLPIN2] 0000017200000000
    2/20/2009 2:03:31.616695 PM Cursor Pin 1 1 408 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:31.247414 PM Cursor Pin 9 1 354 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:31.223828 PM Cursor Pin 1 1 354 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:31.025945 PM Cursor Pin 9 1 396 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:29.456930 PM Cursor Pin 1 5 326 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:29.429823 PM Cursor Pin 1 122 370 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:28.141076 PM Cursor Pin 1 2 354 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:27.215380 PM Cursor Pin 1 8 408 354 kkslce [KKSCHLPIN2] 0000016200000000
    2/20/2009 2:03:19.784694 PM Cursor Pin 1 1 354 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:19.620380 PM Cursor Pin 1 18 321 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:18.795438 PM Cursor Pin 1 2 354 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:18.773917 PM Cursor Pin 1 1 354 338 kkslce [KKSCHLPIN2] 0000015200000000
    2/20/2009 2:03:18.707602 PM Cursor Pin 1 6 326 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:18.618610 PM Cursor Pin 1 2 326 408 kkslce [KKSCHLPIN2] 0000019800000000
    2/20/2009 2:03:18.483609 PM Cursor Pin 1 7 326 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:03:18.439213 PM Cursor Pin 1 2 321 326 kkslce [KKSCHLPIN2] 0000014600000000
    2/20/2009 2:03:18.426098 PM Cursor Pin 1 2 326 321 kkslce [KKSCHLPIN2] 0000014100000000
    2/20/2009 2:02:02.982924 PM Cursor Pin 9 2 361 423 kkslce [KKSCHLPIN2] 000001A700000000
    2/20/2009 2:02:02.868121 PM Cursor Pin 9 1 361 423 kkslce [KKSCHLPIN2] 000001A700000000

  18. Prashant says:

    I checked Momen’s link. That’s not our problem. We are not gathering stats nor are we on 10.2.0.3.

    We are testing on 11.1.0.7.

    Sorry about the formatting above. Also, I forgot to put the query for v$mutex_sleep_history. Here it is:

    SELECT sleep_timestamp,
    mutex_type,
    gets,
    sleeps,
    requesting_session,
    blocking_session,
    location,
    mutex_value
    FROM v$mutex_sleep_history
    WHERE mutex_type = ‘Cursor Pin’
    AND sleep_timestamp >=
    TO_DATE (’2/20/2009 02:00:00 PM’, ‘MM/DD/YYYY HH12:MI:SS AM’)
    ORDER BY sleep_timestamp DESC;

  19. Tanel Poder says:

    Yep I knew you were on a different version, nevertheless it’s useful to know also loosely related bugs/issues to understand the current problem better.

    The kkslce location has to do with literal value replacement/evaluation as far as I know.

    Are you using cursor_sharing=FORCE/SIMILAR by any chance?

    Also, the mutex_identifier column shows the hash value of KGL object involved. If there’s a single/frequently occurring hash value in mutex sleep history, you can query v$sql to find which cursor is it (or if it doesnt return any rows then query kglnaown and kglnaobj columns from x$kglob by kglnahsh = hash_value) to see what object it is.

  20. Tanel Poder says:

    Btw you can use my msh.sql script for easy reporting of mutex sleep stuff – http://www.tanelpoder.com/files/scripts/msh.sql

    You can run it like that for example:

    @msh id,loc,blk “mutex_type=’Cursor Pin’ and loc like ‘kkslce%’”
    SQL> @msh id,loc,blk “mutex_type=’Cursor Pin’ and loc like ‘kkslce%’”

  21. Prashant says:

    cursor_sharing is set to EXACT.

    I ran following query:
    SELECT *
    FROM ( SELECT mutex_identifier, COUNT ( * )
    FROM v$mutex_sleep_history
    WHERE mutex_type = ‘Cursor Pin’
    GROUP BY mutex_identifier
    ORDER BY 2 DESC)
    WHERE ROWNUM < 5;

    MUTEX_IDENTIFIER COUNT(*)
    3930513219 40
    3772074376 12
    2358375738 5
    1935043648 3

    When ran following query with the top most mutex_identifier, I got 3 queries that were run during our perf test

    select kglnaown ,kglnaobj from sys.x$kglob where kglnahsh = 3930513219

    These 3 queries defer only by a value in an IN clause. The rest of the query is exactly the same. We had to write it this way (without using the bind variables) for a particular reason.

    msh.sql didn’t return anything.

    With all this, I am not sure if this is something that I need to worry about too much or not. After we are past first 10 mins of (hell) loading the shared_pool appropriately and hard parse out of the way, we seem to be okay. We are flushing the shared pool each time before the perf. test begins is in order to find out the initial startup time after an instance crash.

  22. Tanel Poder says:

    Before 11g, It’s normal to see library cache and shared pool latch contention after a shared pool flush as everything has to be loaded back in there.

    In 11g, there still will be shared pool latch contention when loading lots of objects – but there should not be much library cache *mutex* contention as different objects will likely hash to different hash buckets and every library cache hash bucket is protected by a separate mutex (and there’s 131072 separate buckets)

    However, if Oracle wants to create a lot of child cursors under the same parent then you still can end up with cursor pin mutex contention. Oracle takes the mutex on parent cursor in X mode if it needs to modify the child list for example. So if Oracle loads lots of children under a parent cursor, then the mutex in parent handle will be held in X mode a lot.

    So, lets estabilish whether you have lots of child cursors under any parent?

    SELECT hash_value, COUNT(*)
    FROM v$sql
    GROUP BY hash_value
    HAVING COUNT(*) > 10
    /

    ..or you could run that query for only the objects with hash values you saw from v$mutex_sleep_history. Note that the v$mutex_sleep_history is an in-memory array with limited size, the old sleeps will be aged out there quite fast in a busy system.

    What’s the value for CURSOR_SHARING parameter? Is it force or similar by any chance?

  23. Tanel Poder says:

    I looked around in Metalink a bit as one of the troublemakers in 11g may be the new feature adaptive cursor sharing.

    I found Metalink note 7213010.8, it’s about a bug causing lots of child cursors to be created under a single parent. Its supposedly fixed in 11.1.0.7 but you still can check whether your symptoms match.

  24. Prashant says:

    SELECT hash_value, COUNT ( * )
    FROM v$sql
    GROUP BY hash_value
    HAVING COUNT ( * ) > 10;

    HASH_VALUE COUNT(*)
    3711249830 16
    1320826287 12
    1611226212 21

    These 3 queries are by user SYS, SYSMAN and SYS respectively! :). But our last perf. test run was on Friday.

    SQL> show parameter CURSOR_SHARING

    NAME TYPE VALUE
    ———————————— ———– ——————————
    cursor_sharing string EXACT

    I will look at the metalink article you mentioned. Is adaptive cursor sharing in 11g turned ON by default? And what if I don’t want it to adapt?

  25. Tanel Poder says:

    Yep you should run the version count query when you see the problem, otherwise we might miss some important information.

    If you have AWR licenses, you can query DBA_HIST_SQLSTAT from your stress test start time and order it by VERSION_COUNT…

    Adaptive cursor sharing is enabled default – for statements with bind variables (cursors opened directly from PL/SQL will automatically use bind variables as well).

    IF you have bind variables in the statement with top sleeps (from the time when the problem occurred) then you could try to see if

    Adaptive cursor sharing can be disabled by this parameter:
    _optimizer_adaptive_cursor_sharing=false

    And the metalink note I mentioned describes this parameter as well which affects adaptive cursor sharing:
    _optimizer_extended_cursor_sharing=none

    As you have a stress test environment, if you still see significant cursor: pin S wait for X event when you start your load test and you see high version counts in v$sql right after that, you can disable ACS by setting these parameters.

    Important! But do this only in your test environment for finding out whether disabling ACS makes the problem go away. If yes, then raise a request with Oracle Support and provide them the evidence. If the problem doesn’t go away unset these parameters again and we can continue looking for the cause of that problem.

    Of course, there’s always a tradeoff – have you measured how much of total warm-up time is spent waiting for these mutexes?

  26. Dion Cho says:

    (I had to sample v$mutex_sleep_history instead of v$mutex_sleep on 11g as the latter was empty on 11g… it may be that the mutex get operations have been tuned further to not maintain the counters just to save even few more CPU cycles every get)

    It’s a bug. Metalink bug# 7202166

  27. Tanel Poder says:

    Yep I suspected that as another reason. Thanks for letting me know.

  28. DBA says:

    Hi Tanel,

    We are using 11.1.0.7 on Linux_x86_64. We are having a problem with “library cache: mutex X” wait. The CPU usage goes high to 99% and stays there until I shutdown the database (ABORT!). The client is shutdown but the sessions are active in the database and are waiting on that mutex wait event.
    Some people are saying there is a bug in 11g that was supposed to be fixed in 11.1.0.7. http://jhdba.wordpress.com/2008/03/31/11g-library-cache-mutex-x-known-bug/
    Have you come across such behavior with 11.1.0.7?

  29. DBA says:

    Hi Tanel,

    I posted a “library cache: mutex X” problem above. Have you come across that before?

    Thanks.

  30. Tanel Poder says:

    Hi DBA,

    It sure sounds like a bug. There was an issue with mutexes that when a get failed the mutex getter never slept for long time. It spinned for short time and then just yielded CPU (which is not a sleep – but just means the process goes off CPU, but not to sleep but to the end of the runqueue – trying to get back onto CPU immediately)

    That would explain why you had 99% CPU usage which didn’t “go away”. Even if you shut down the client and the sessions remain (processes aren’t killed) then the sessions may be stuck in this mutex get loop and never check whether they should exit.

    In 11.1.0.7 the yielding problem should have been fixed, but maybe not for all cases.

    If it happens again, I would try to dump x$mutex_sleep_history and take hanganalyze dumps. If your db is completely hung, then you can connect with “sqlplus -prelim” to take a hanganalyze dump without estabilishing a session in the instance.

  31. David Rydzewski says:

    Hi Tandel –

    I don’t have the specifics in front of me, but I remember reading Steve Adams’ book in regards to latching and it mentioned deadlock prevention in latches based on the latch level. Basically, latches need to be taken in certain order and if violated, Oracle throws an internal error.

    Do you know if the mutex mechanism also does this checking or is it assumed that the more granular level of the mutex (and careful coding) does not require this checking?

    Thanks,
    Dave

  32. Richard says:

    Hi Tanel – Does LatchProfX work with 11g?

  33. Tanel Poder says:

    @David Rydzewski
    David, this is a late reply, but I don’t think Mutexes have level sanity checking like latches do. Latches don’t really need it either for functioning, but this is more for debugging and sanity checks/assertions in case something goes wrong.

  34. Tanel Poder says:

    @Richard
    Hi Richard,

    Yes, latchprofx does work on 11g as well. In 11gR2 there was a new CBO transformation enabled which made older latchprofx versions not work and return only one row, but I have fixed this issue and uploaded a new version (v1.20) which works on 11gR2 too. 11gR1 doesn’t have this problem. So download the latest version and make sure it is v1.20 (or higher)

  35. sumartono says:

    Hi Tanel,
    I have similar performance issue 11gR1 just recently upgrade.I am using Solaris 10, what could I do to avoid such problem? I have opened SR with oracle, however it seems not much help, just collecting data and logfiles and do nothing, it is already more than a week.Your help will be appreciated.Thanks

  36. Tanel Poder says:

    @sumartono

    Can you describe exactly what issue are you seeing? (what are the symptoms, what’s the TOP5 wait section in statspack or AWR for example?)

  37. sumartono says:

    Dear Tanel,
    Thanks for your reply,In AWR, I have seen top 5 is “cursor: pin S wait on X” in the 2nd one after “DB CPU”. I have read your blog and try to set this parameter in init.ora: _first_spare_parameter = 10, however I am using solaris 10 and I do not know what parameter should be set in this OS,and it seems not pick up this paramater properly, the performance still same.If I can send you the AWR file, and what else to be checked, I will be very happy to do that, so that my performance issue can be solved.Thank in advance.

  38. Tanel Poder says:

    The “cursor: pin S wait on X” happens for different reasons than just “cursor: pin S”. The “cursor: pin S wait on X” happens for example when you have excessive hard parsing or lots of invalidation/flushing of library cache objects happening. Whenever I see lots of “cursor: pin S wait on X” waits, I check these things first:

    1) how many hard parses are done per second
    2) does the application use bind variables for frequently executed SQL
    3) does Automatic SGA Memory Manager resize shared pool during the problem time (resizing shared pool smaller will cause lots of library cache objects to be flushed out, which then have to be reloaded on next use, which causes hard parsing, which causes cursor: pin S wait on X waits… so check from V$SGA_DYNAMIC_COMPONENTS and V$SGA_RESIZE_OPS to see whether shared pool shrink operations frequently happen in your system

  39. sumartono says:

    V$SGA_RESIZE_OPS seems to be frequently shrinking.

    pasting few records here
    ****************************************************
    COMPONENT OPER_TYPE OPER_MODE PARAMETER INITIAL_SIZE START_TIME END_TIME
    shared pool GROW DEFERRED shared_pool_size CANCELLED 10/01/10 11:34:11 AM 10/01/10 11:35:12 AM
    DEFAULT buffer cache SHRINK DEFERRED 1459617792 CANCELLED 10/01/10 11:34:11 AM 10/01/10 11:35:12 AM
    shared pool GROW DEFERRED shared_pool_size CANCELLED 10/01/10 11:36:09 AM 10/01/10 11:37:10 AM
    DEFAULT buffer cache SHRINK DEFERRED 1409286144 CANCELLED 10/01/10 11:36:09 AM 10/01/10 11:37:10 AM
    DEFAULT buffer cache GROW DEFERRED 1493172224 COMPLETE 10/01/10 11:38:10 AM 10/01/10 11:38:10 AM
    shared pool SHRINK DEFERRED shared_pool_size COMPLETE 10/01/10 11:38:10 AM 10/01/10 11:38:10 AM
    DEFAULT buffer cache SHRINK DEFERRED 1426063360 COMPLETE 10/01/10 11:40:10 AM 10/01/10 11:40:14 AM

  40. Tanel Poder says:

    So, the issue may well be because of the SGA_TARGET and shared pool shrinking. It’s a common troublemaker by the way.

    Ideally you should verify whether these resize ops happen at the same times when you notice the problem (and also whether the “sql area evicted” and/or “CCursor + sql area evicted” v$sysstat variable jumps up during that time).

    To work around this, you can do either:

    1) stop using SGA_TARGET (and don’t use MEMORY_TARGET either), configure the SGA component sizes manually

    or

    2) Keep using SGA_TARGET (as it sets some PX related variables) but also set the shared_pool_size and db_cache_size manually, so that their values would be used as minimum allowed sizes for the pools. In such problem cases I sometimes even set the shared pool and db_cache (and other parameters) so that there wouldn’t be any room for the memory manager to resize any components and cause this flushing

    or

    3) Set _memory_broker_stat_interval to a larger value (it’s in seconds) so that the memory manager wouldn’t resize SGA so frequently (search for that parameter in MOS for official note about it)

  41. sumartono says:

    We have used oracle application 12.1.3, previously we were using old database oracle 9i and oracle apps 11.5.9 and solaris 9, we never facing this issue. I have no choice to migrate, because of the end of support products.

  42. Tanel Poder says:

    Yeah, 9i didn’t have SGA_TARGET and ASMM, 11g has…

  43. sumartono says:

    Dear Tanel,
    Thank you for your fast response, now I am trying set “_memory_broker_stat_interval”=999 as per MOS ID 742599.1, and will let you know the progress tommorrow – because this time not much user login in the night (Indonesia time). However what else can I do for better performance. I am too late to come to your recommendation of avoid using 11g (I am in 11.1.0.7.0 – 64bit). Thanks for your kindly help.

  44. Tanel Poder says:

    Look at the date of this article – it was written in 2008, over 2 years ago, back when 11.1.0.7 wasn’t out. Times have changed, patchsets have been released and bugs have become known since.

  45. sumartono says:

    Dear Tanel,
    You are right, but this 11.1.0.7 version even not better, one of the funny thing happen was when there is error:ORA-1653: unable to extend table APPLSYS.FND_LOG_MESSAGES in tablespace XXX, then as normal procedure done by dba will increase or adding datafile to that particular tablespace, but this is not true, it gives another error in the alter tablespace xxx add datafile ‘/dbf/dat25.dbf’ size 2000M
    *
    ERROR at line 1:
    ORA-00060: deadlock detected while waiting for resource.
    Searching in MOS saying it is Bug 8332021 and will be fixed in 11.2.0.2 (Server Patch Set)

  46. sumartono says:

    Dear Tanel,
    After altering the paramater “_memory_broker_stat_interval”=999 yesterday, shrinking share pool was not happening,so cursor: pin S wait on X also not showing in the TOP Five AWR, however the performance still not improvement,
    Top 5 Timed Foreground Events
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    Avg
    wait % DB
    Event Waits Time(s) (ms) time Wait Class
    —————————— ———— ———– —— —— ———-
    DB CPU 12,990 54.9
    db file sequential read 10,990,737 5,472 0 23.1 User I/O
    enq: TX – row lock contention 3 3,558 1.2E+06 15.0 Applica
    log file sync 30,880 592 19 2.5 Commit
    db file scattered read 23,090 376 16 1.6 User I/O

    Any other thing can I do?Thanks in advance

  47. maclean says:

    Hi tanel,
    The latch:library cache pin and latch:library cache lock has gone, then How does oracle allocate library cache pin/lock structure for non-cursor object?

  48. Mahesh says:

    There are infact so many bugs related to “library cache: mutex X” and some of them seem to be fixed (list available at the Mutex Contention section of the metalink article 1179583.1) in 11.2.0.2 patchset which was released on 11/17. You might want to search for the patch number 10098816 in metalink. I’m going to apply this patch on 11.1.0.7 on Tux64 and hoping that it’ll solve my probable bug 10145558(Selects on library cache V$/X$ views cause “library cache: mutex X” waits)!!

  49. Tanel Poder says:

    @Mahesh
    In fact, queries frequently walking through the entire library cache (V$SQL, V$SQLAREA, V$SQLPLAN* views) have always been a problem. Before libcache mutexes were introduced, such queries caused library cache latch contention (as walking through the complex library cache structure & linked lists requires some protection). The solution before 10.2 was to not query these views so frequently (stop that GUI “performance tuning” tool which polls V$SQL every 5 seconds etc).

    Starting from 10.2 you should query V$SQLSTATS instead where possible, that doesn’t visit the library cache, but a separate Cursor Stats array maintained by Oracle during SQL execution. If you need to access the library cache views, then you should identify which SQLIDs/hash values you want and search for these using the “=” condition (or a properly hinted IN) so that Oracle wouldn’t do “full scans” through the library cache, but a hash value based lookup instead.

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>