1 2 Previous Next 20 Replies Latest reply on Aug 2, 2012 7:07 AM by Severity

    Library cache mutex X


      I'm having problem with my database performance as in the awr report at Top 5 Timed Foreground Events it shows following event

      Event      Waits     Time(s)     Avg wait (ms)     % DB time     Wait Class
      library cache: mutex X     10,858,394     1,520     0     7.14     Concurrency

      i've vheck GV$MUTEX_SLEEP and it returns following rows

      1     Library Cache     kglllal3 111     15777     0
      1     Library Cache     kglllal1 109     10     0
      1     Library Cache     kglhdgn2 106     16737862     0
      1     Library Cache     kglpndl1 95     3134876     0
      1     Library Cache     kglpnal1 90     1290     0
      1     Library Cache     kglpnck1 88     1     0
      1     Library Cache     kgllkdl1 85     2187799     0
      1     Library Cache     kglobld1 75     8     0
      1     Library Cache     kglobpn1 71     19670     0
      1     Library Cache     kglhdgh1 64     97134     0
      1     Library Cache     kglhdgn1 62     2083845     0
      1     Library Cache     kgllkc1 57     12439     0
      1     Library Cache     kglic1 49     2177116     0
      1     Library Cache     kglnti1 46     1     0
      1     Library Cache     kgldtin1 42     26     0
      1     Library Cache     kglini1 32     1     0
      1     Library Cache     kglpin1 4     24842037     0
      1     Library Cache     kglget2 2     3441465     0
      1     Cursor Stat     kkocsStoreBindAwareStats [KKSSTALOC8]     730598     79711035
      1     Cursor Parent     kksfbc [KKSPRTLOC2]     3     60
      1     Cursor Parent     kksfbc [KKSPRTLOC1]     1     56
      1     Cursor Pin     kksLockDelete [KKSCHLPIN6]     2761145     1270979468
      1     Cursor Pin     kksxsccmp [KKSCHLPIN5]     860     2050581
      1     Cursor Pin     kksSetBindType [KKSCHLPIN4]     1     7588
      1     Cursor Pin     kkslce [KKSCHLPIN2]     420193     1608410712
      1     Cursor Pin     kksfbc [KKSCHLPIN1]     49467     2565452
      1     Cursor Pin     kksfbc [KKSCHLFSP2]     14708295     4222683412

      i'm using with R12 EBS in HP UX 11.23
      i'm newbie in this and need some advice to fix or overcome this

        • 1. Re: Library cache mutex X
          • 2. Re: Library cache mutex X
            Bobby Durrett
            What makes you think this wait represents a problem?

            A problem would be if you have an application program that needs to run in a certain period of time to meet your needs but it isn't.

            If you have a problem then you need to figure out what that program is spending its time on in the database.

            So, if it is spending 90% of its time on a particular wait and if it is running 10 times longer than normal then that wait would matter.

            If you got rid of the wait then you could potentially make the program run 10 times faster.

            But, if you problem program is spending 90% of its time running on the cpu and a small fraction of 1% of its time on a particular wait then the wait isn't an issue.

            I can't tell from what you posted because it is part of an AWR report which reports the waits and CPU from all of the sessions on the system and may not
            represent any particular program that is slow. Also, it looks like the wait in question is only 7% of the total time so it wouldn't seem to indicate an
            overall system problem that would be hurting all of your programs.

            - Bobby
            • 3. Re: Library cache mutex X
              Severity wrote:

              I'm having problem with my database performance as in the awr report at Top 5 Timed Foreground Events it shows following event
              NEWS FLASH!
              You will always have FIVE items in this report.
              Zero to Five of them may indicate a problem exists.
              Zero to Five of them may be safely ignored.

              When you start with the wrong question, no matter how good an answer you get, it won't matter very much.
              • 4. Re: Library cache mutex X
                Nikolay Savvinov

                library cache contention is typically caused by excessive parsing, sometimes in combination with:

                1) massive cursor invalidation due to stats gathering during busy hours
                2) shared pool housekeeping bugs (e.g. ASMM resizing pools too frequently)
                3) parsing bugs

                I would start by looking carefully at load profile section (or posting it here).

                P.S. Please use
                 tags when posting AWR excerpts                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
                • 5. Re: Library cache mutex X

                  Thx for the replies, this wait becomes problem because every time this wait occurs users are complaining that the EBS R12 application is slow,
                  users said it took longer than usual when they trying to save a loading account, validating, opening EBS program etc

                  i've log an SR and the oracle support recommend me to add parameter SCHED_NOAGE Note 218027.1 and he said that "this wait involves a wait for an X holder then the main approach to reducing waits is to identify the reason for either long or frequent acquisition of the mutex/es in X mode and tackle that".

                  the problem that i have now are how to identify the root cause of wait for an x holder so i can tackle it, and how to set the right value for SCHED_NOAGE as the valid range are between 178 to 255 and there is no dictionary table for the parameter

                  i'm also hoping that there would be any other advice or solution for this problem

                  • 6. Re: Library cache mutex X
                    here is the load profile from the AWR report
                    Per Second     Per Transaction     Per Exec     Per Call
                    DB Time(s):     9.3     0.2     0.00     0.02
                    DB CPU(s):     2.1     0.1     0.00     0.00
                    Redo size:     1,021,411.5     23,775.8            
                    Logical reads:     97,592.1     2,271.7            
                    Block changes:     7,998.3     186.2            
                    Physical reads:     1,896.8     44.2            
                    Physical writes:     272.7     6.4            
                    User calls:     590.3     13.7            
                    Parses:     206.8     4.8            
                    Hard parses:     2.2     0.1            
                    W/A MB processed:     9,112,875.5     212,123.6            
                    Logons:     1.5     0.0            
                    Executes:     6,689.2     155.7            
                    Rollbacks:     1.9     0.0            
                    Transactions:     43.0                        
                    • 7. Re: Library cache mutex X
                      Nikolay Savvinov

                      1) you have 10 times more executes than user calls -- suggest you look at Top SQL by executions
                      2) 2 rollbacks every second - not necessarily a problem, but makes one wonder. Lots of failed transactions? Any of these rollbacks expensive?
                      3) what are remaining top timed events?

                      Best regards,
                      • 9. Re: Library cache mutex X

                        here is the top sql by executions
                        Executions      Rows Processed     Rows per Exec     CPU per Exec (s)     Elap per Exec (s)      SQL Id     SQL Module     SQL Text
                        21,686,144     21,680,273     1.00     0.00     0.00     0ran6wn9g0dtk      GICPRHLD      SELECT PHASE_CODE FROM FND_CON...
                        477,352     216,266     0.45     0.00     0.00     7qs7fx89194u1      JDBC Thin Client      SELECT PROFILE_OPTION_VALUE FR...
                        387,094     0     0.00     0.00     0.00     0y9hz0w9scvtg      e:SQLAP:frm:APXINWKB      SELECT 'N' FROM AP_INVOICE_LIN...
                        279,584     16,556     0.06     0.00     0.00     55dc767ajydh3      ICM@oaprdabc (TNS V1-V3)      SELECT PROFILE_OPTION_VALUE FR...
                        183,457     171,673     0.94     0.00     0.00     0wmwsjy9kd92f      JDBC Thin Client      SELECT PROFILE_OPTION_ID, APP...
                        100,287     100,286     1.00     0.00     0.00     1v818hwxjxy58      e:SQLAP:frm:APXINWKB      select FND_FLEX_VALUES_VL.FLEX...
                        50,799     50,799     1.00     0.00     0.00     6mnk2h6s82kt1      INCTCW      select to_char(CODE_COMBINATIO...
                        49,442     49,442     1.00     0.00     0.00     cnnnzd24ay339      e:SQLAP:frm:APXINWKB      select to_char(CODE_COMBINATIO...
                        45,040     0     0.00     0.00     0.00     5413z9jjdk8bn      INCTCW      SELECT reservation_...
                        35,861     35,861     1.00     0.00     0.00     0mdnts20d60yr      INCTCW      declare v_ret number := 0...
                        yes, some rollbacks are expensive
                        here is the latest remaining top timed events when this waits occurs
                        DB CPU           12,323           22.23      
                        enq: TX - row lock contention     56     5,265     94012     9.50     Application
                        db file sequential read     1,148,188     4,228     4     7.63     User I/O
                        log file sync     51,619     2,027     39     3.66     Commit
                        library cache: mutex X     17,419,349     1,716     0     3.10     Concurrency

                        • 10. Re: Library cache mutex X
                          Nikolay Savvinov

                          1) well you can see that one of the statements was executed 21M times during the period of the AWR report (which was what btw -- 1 hour?) -- that looks like a lot, doesn't it? Can you identify this statement -- is it called from PL/SQL, or application server code? Is there really a necessity to call the same query 21M times during that period? Is this query consuming a lot of resources -- does it show up in other top SQL lists?

                          Also, is the statement always executed from the same session, or concurrently from many different sessions? If the latter, then it could explain the mutexes -- look at ASH data to confirm

                          2) about your top events -- one thing that leaps into the eye is that the sum is far from 100% -- where is the rest? btw what is the situation with resource consumption on the database server host -- in particular, CPU usage? any signs of CPU scheduling latency?

                          Best regards,
                          • 11. Re: Library cache mutex X
                            Bobby Durrett
                            Would you mind posting the "Operating System Statistics" part of your AWR report?

                            This might show if your CPU was pegged out and you had a huge queue for the CPU.

                            - Bobby
                            • 12. Re: Library cache mutex X
                              Here is the OS statistics
                              Operating System Statistics
                                  *TIME statistic values are diffed. All others display actual values. End Value is displayed if different
                                  ordered by statistic type (CPU Use, Virtual Memory, Hardware Config), Name
                              Statistic     Value     End Value
                              AVG_BUSY_TIME     155,971      
                              AVG_IDLE_TIME     19,081      
                              AVG_IOWAIT_TIME     15,601      
                              AVG_SYS_TIME     23,944      
                              AVG_USER_TIME     131,980      
                              BUSY_TIME     624,065      
                              IDLE_TIME     76,495      
                              IOWAIT_TIME     62,530      
                              SYS_TIME     95,959      
                              USER_TIME     528,106      
                              LOAD     2     2
                              OS_CPU_WAIT_TIME     16,931,338,100      
                              VM_IN_BYTES     183,332,864      
                              VM_OUT_BYTES     258,355,200      
                              PHYSICAL_MEMORY_BYTES     17,149,018,112      
                              NUM_CPUS     4      
                              TCP_RECEIVE_SIZE_DEFAULT     32,768      
                              TCP_RECEIVE_SIZE_MAX     1,073,725,440      
                              TCP_RECEIVE_SIZE_MIN     8,192      
                              TCP_SEND_SIZE_DEFAULT     32,768      
                              TCP_SEND_SIZE_MAX     2,147,483,647      
                              TCP_SEND_SIZE_MIN     8,192      
                              • 13. Re: Library cache mutex X
                                1) the awr report was taken with elapsed time of 38 minutes,
                                The statement called from EBS application server, its an interface program, and yes its necessity so we would know the process status of every rows that's been running by interface
                                and the statement is executed concurrently by many different session from about 4-7 sessions almost every time and yes it sometimes shows up in top sql but not always, so i'm not sure if the statement consuming lot of resources.
                                are there any tools besides explain plan to measures it ??

                                2) about the resource consumption we also use the database server as a host for tape manager, and could u pls explain what is CPU scheduling latency?


                                • 14. Re: Library cache mutex X
                                  Nikolay Savvinov

                                  I suspect that countrary to your claim, this statement is not running from an application server -- otherwise, we would've seen more "user calls" (at least one per execution) -- it's probably running from a PL/SQL routine.

                                  In any case, I can summarize your situation as follow:

                                  1) your system seems to be experiencing extreme CPU starvation -- OS_CPU_WAIT_TIME that processes on the OS spend much more time waiting for CPU than running on CPU (BUSY_TIME)
                                  2) CPU is by far your biggest problem, and should be addressed before anything else -- look at "SQL by CPU" to see what's eating it in this database, and use OS tools (like vmstat or whatever is available on your platform) to see on other processes that may be consuming it (according to the AWR report, your database only takes 2 CPUs out of 4 on the average)
                                  3) something isn't quite right about this frequently executed statement -- has it always been running like this? can you obtain an AWR for no-problem time and see whether it was running same number of times per hour? talk to the application architect about this statement and whether it's possible to reduce the execution frequency -- if not, then at least make sure it's soft-parsed as little as possible (use session cursor caching, keep the cursor open in the code as long as possible for reuse instead of opening/closing etc.)

                                  Best regards,

                                  P.S. DBA_HIST_SQLSTAT will tell you about resource consumption by a specific statement
                                  1 2 Previous Next