9 Replies Latest reply: Nov 26, 2012 7:36 AM by Nikolay Savvinov RSS

    latch: row cache objects takes 80% of database time

    stee1rat
      Hello, All!

      I'm new to this forum and i'm not sure if i'm able to post questions like this here.

      I'm facing the problem with really high concurrences for row cache objects in a database.
      Could someone help me to find the reason for it or send me in the right direction in my searching?

      Here's the excerpt from AWR for last 3,5 hours:
      Top 5 Timed Foreground Events
      ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                                                                 Avg
                                                                wait   % DB
      Event                                 Waits     Time(s)   (ms)   time Wait Class
      ------------------------------ ------------ ----------- ------ ------ ----------
      latch: row cache objects        127,452,881   3,058,038     24   80.3 Concurrenc
      cursor: pin S wait on X             476,147     271,907    571    7.1 Concurrenc
      db file sequential read          22,066,495     233,666     11    6.1 User I/O
      DB CPU                                          193,349           5.1
      library cache: mutex X            5,000,294      17,950      4     .5 Concurrenc
      
      
      Dictionary Cache Stats               DB/Inst: ---------  Snaps: 26314-26328
      -> "Pct Misses"  should be very low (< 2% in most cases)
      -> "Final Usage" is the number of cache entries being used
      
                                         Get    Pct    Scan   Pct      Mod      Final
      Cache                         Requests   Miss    Reqs  Miss     Reqs      Usage
      ------------------------- ------------ ------ ------- ----- -------- ----------
      dc_awr_control                     769    0.0       0   N/A       28          1
      dc_files                        15,318   39.6       0   N/A        0        666
      dc_global_oids                  37,214    4.8       0   N/A        0         43
      dc_histogram_data         1.537971E+09    0.0       0   N/A        0     21,233
      dc_object_grants               143,088    0.9       0   N/A        0        187
      dc_objects                 143,387,924    0.0       0   N/A        9      6,471
      dc_profiles                    382,829    0.0       0   N/A        0          1
      dc_rollback_segments         1,416,812    0.0       0   N/A        0     10,272
      dc_segments                 33,731,523    0.1       0   N/A       21      4,126
      dc_sequences                       907   56.0       0   N/A      907          6
      dc_tablespace_quotas                36   47.2       0   N/A        0          2
      dc_tablespaces               2,301,889    0.0       0   N/A        0        158
      dc_users                    61,573,004    0.0       0   N/A        0        268
      global database name           391,810    0.0       0   N/A        0          1
      outstanding_alerts               3,480  100.0       0   N/A        1          0
                -------------------------------------------------------------
      The version of database is 11.2.0.2.0

      Edited by: user2586601 on Nov 21, 2012 3:53 AM
        • 1. Re: latch: row cache objects takes 80% of database time
          Fabricio_Jorge
          This is possibly related to the shared pool size. Check the Shared Pool Advisor (in the same AWR report).
          • 2. Re: latch: row cache objects takes 80% of database time
            Dom Brooks
            Welcome to the forum.
            i'm not sure if i'm able to post questions like this here.
            Absolutely.
            Here's the excerpt from AWR for last 3,5 hours:
            In general, too long a period but in this case the message seems clear.

            dc_histogram_data stands out in the dictionary cache stats

            You might want to look at the top SQL sections to see if there are any clues.
            Other valuable sesions include the load profile, top section confirmation of the interval. etc

            Also, see Alex Fatkulin's post here on a row cache issue:
            http://afatkulin.blogspot.co.uk/2012/02/latch-row-cache-objects.html
            • 3. Re: latch: row cache objects takes 80% of database time
              stee1rat
              Fabricio_Jorge wrote:
              This is possibly related to the shared pool size. Check the Shared Pool Advisor (in the same AWR report).
              Here's the exerpt from AWR with Shared Pool Advisory and it doesn't look like increasing it's size would help.
              Shared Pool Advisory                        DB/Inst: ---------  Snap: 14128
              -> SP: Shared Pool     Est LC: Estimated Library Cache   Factr: Factor
              -> Note there is often a 1:Many correlation between a single logical object
                 in the Library Cache, and the physical number of memory objects associated
                 with it.  Therefore comparing the number of Lib Cache objects (e.g. in
                 v$librarycache), with the number of Lib Cache Memory Objects is invalid.
              
                                                     Est LC Est LC  Est LC Est LC
                Shared    SP   Est LC                  Time   Time    Load   Load       Est LC
                  Pool  Size     Size       Est LC    Saved  Saved    Time   Time      Mem Obj
               Size(M) Factr      (M)      Mem Obj      (s)  Factr     (s)  Factr     Hits (K)
              -------- ----- -------- ------------ -------- ------ ------- ------ ------------
                 8,704    .8      134       10,969 3.39E+07    1.0 7.3E+06    1.0      361,719
                 9,728    .9    1,160       86,983 3.39E+07    1.0 7.3E+06    1.0    2,760,418
                10,752   1.0    2,182      112,350 3.41E+07    1.0 7.1E+06    1.0    2,778,598
                11,776   1.1    3,206      136,107 3.42E+07    1.0 7.0E+06    1.0    2,783,046
                12,800   1.2    4,229      159,827 3.43E+07    1.0 6.9E+06    1.0    2,786,134
                13,824   1.3    5,252      183,659 3.43E+07    1.0 6.9E+06    1.0    2,788,711
                14,848   1.4    6,276      207,154 3.44E+07    1.0 6.8E+06    1.0    2,790,677
                15,872   1.5    7,299      231,110 3.44E+07    1.0 6.8E+06    1.0    2,792,236
                16,896   1.6    8,323      255,273 3.44E+07    1.0 6.8E+06    1.0    2,793,673
                17,920   1.7    9,347      280,009 3.45E+07    1.0 6.7E+06    1.0    2,795,017
                18,944   1.8   10,370      304,142 3.45E+07    1.0 6.7E+06     .9    2,796,299
                19,968   1.9   11,394      328,614 3.45E+07    1.0 6.7E+06     .9    2,797,454
                20,992   2.0   12,417      352,466 3.46E+07    1.0 6.6E+06     .9    2,798,515
                        -------------------------------------------------------------
              Dom Brooks wrote:Welcome to the forum.
              Thanks!
              Dom Brooks wrote:
              Here's the excerpt from AWR for last 3,5 hours:
              In general, too long a period but in this case the message seems clear.
              Well, the AWR reports for shorter periods, even for 2 closest snapshots shows the same statistics, it only varies from 75% to 80% of db time for row cache objects. And the graph in the grid control is constant, without any peaks.
              Dom Brooks wrote:
              dc_histogram_data stands out in the dictionary cache stats
              Yes, and the html report shows dc_histogram_defs is also about 62kk, i have no idea why it's not in the text AWR report :)
              Anyway, where should i look then? I'm really new in resolving cache issues.
              • 4. Re: latch: row cache objects takes 80% of database time
                Dom Brooks
                Look at the top SQL sections to see if there's any obvious clue.

                Also run an ASH report and look at the ASH raw data in V$ACTIVE_SESSION_HISTORY and DBA_HIST_ACTIVE_SESS_HISTORY for sessions waiting on this latch.
                • 5. Re: latch: row cache objects takes 80% of database time
                  Jonathan Lewis
                  stee1rat wrote:

                  Here's the excerpt from AWR for last 3,5 hours:
                  Top 5 Timed Foreground Events
                  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                  Avg
                  wait   % DB
                  Event                                 Waits     Time(s)   (ms)   time Wait Class
                  ------------------------------ ------------ ----------- ------ ------ ----------
                  latch: row cache objects        127,452,881   3,058,038     24   80.3 Concurrenc
                  cursor: pin S wait on X             476,147     271,907    571    7.1 Concurrenc
                  db file sequential read          22,066,495     233,666     11    6.1 User I/O
                  DB CPU                                          193,349           5.1
                  library cache: mutex X            5,000,294      17,950      4     .5 Concurrenc
                  
                  
                  Dictionary Cache Stats               DB/Inst: ---------  Snaps: 26314-26328
                  -> "Pct Misses"  should be very low (< 2% in most cases)
                  -> "Final Usage" is the number of cache entries being used
                  
                  Get    Pct    Scan   Pct      Mod      Final
                  Cache                         Requests   Miss    Reqs  Miss     Reqs      Usage
                  ------------------------- ------------ ------ ------- ----- -------- ----------
                  dc_awr_control                     769    0.0       0   N/A       28          1
                  dc_files                        15,318   39.6       0   N/A        0        666
                  dc_global_oids                  37,214    4.8       0   N/A        0         43
                  dc_histogram_data         1.537971E+09    0.0       0   N/A        0     21,233
                  dc_object_grants               143,088    0.9       0   N/A        0        187
                  dc_objects                 143,387,924    0.0       0   N/A        9      6,471
                  dc_profiles                    382,829    0.0       0   N/A        0          1
                  dc_rollback_segments         1,416,812    0.0       0   N/A        0     10,272
                  dc_segments                 33,731,523    0.1       0   N/A       21      4,126
                  dc_sequences                       907   56.0       0   N/A      907          6
                  dc_tablespace_quotas                36   47.2       0   N/A        0          2
                  dc_tablespaces               2,301,889    0.0       0   N/A        0        158
                  dc_users                    61,573,004    0.0       0   N/A        0        268
                  global database name           391,810    0.0       0   N/A        0          1
                  outstanding_alerts               3,480  100.0       0   N/A        1          0
                  -------------------------------------------------------------
                  Large numbers of waits on the library cache latches and mutexes tend to be associated with optimization, as do gets on the column stats (as indicated by the gets on dc_histogram_data). However, you also have high figures for dc_segments, dc_objects, and dc_users: the first two may be associated with frequent truncates and reloads of objects, the latter with large numbers of logons or calls to "authid current_user" procedures.

                  You've already had some advice about looking for further evidence, but two things I would want to see from the AWR report are: Load Profile - may give us some obvious clues, and 'SQL ordered by Version Count' which may give us further hints about undesirable library cache activity (SQL ordered by Parse calls is a third port of call, and any "instance activity" statistics with the word "parse" in their name a fourth).


                  Regards
                  Jonathan Lewis
                  • 6. Re: latch: row cache objects takes 80% of database time
                    stee1rat
                    I've just looked in v$session and noticed that most sessions, i would say 90% of them, having the same query text, but different literals (and different sql_ids). Could it be the reason for the high row cache objects concurrency? Could setting cursor_sharing=true help here?

                    There's 2 different types of queries with a lot of child cursors in 'SQL ordered by Version Count'. When i look in v$sql_shared_cursor view for this queries there's auth_check_mismatch and translation_mismatch as a reason for new child ('Y').
                    Version Count     Executions      SQL Id     SQL Module     SQL Text
                    151     37     ausdggjdkcz4y      mgr@ironman (TNS V1-V3)     SELECT column1 FROM DBUSER.US_u...
                    112     158     a19a07xfjahf1      mgr@ironman (TNS V1-V3)     SELECT column1, column2...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    109     84     bc99f5u93skvg      mgr@ironman (TNS V1-V3)     UPDATE table1 SET column1=0 WHE...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    94     54     3vabq80zuq8vc      mgr@ironman (TNS V1-V3)     DELETE table4 WHERE column1=:...
                    Here's the load profile:
                    Load Profile              Per Second    Per Transaction   Per Exec   Per Call
                    ~~~~~~~~~~~~         ---------------    --------------- ---------- ----------
                          DB Time(s):              302.0                1.9       0.12       0.09
                           DB CPU(s):               15.3                0.1       0.01       0.00
                           Redo size:          296,608.8            1,826.6
                       Logical reads:          167,834.1            1,033.6
                       Block changes:            1,691.3               10.4
                      Physical reads:            3,208.6               19.8
                     Physical writes:              185.0                1.1
                          User calls:            3,539.0               21.8
                              Parses:            1,167.2                7.2
                         Hard parses:              514.4                3.2
                    W/A MB processed:                6.8                0.0
                              Logons:               30.4                0.2
                            Executes:            2,502.8               15.4
                           Rollbacks:                0.3                0.0
                        Transactions:              162.4
                    • 7. Re: latch: row cache objects takes 80% of database time
                      Nikolay Savvinov
                      >
                      Hi
                      Load Profile              Per Second    Per Transaction   Per Exec   Per Call
                      ~~~~~~~~~~~~         ---------------    --------------- ---------- ----------
                      DB Time(s):              302.0                1.9       0.12       0.09
                      DB CPU(s):               15.3                0.1       0.01       0.00
                      Redo size:          296,608.8            1,826.6
                      Logical reads:          167,834.1            1,033.6
                      Block changes:            1,691.3               10.4
                      Physical reads:            3,208.6               19.8
                      Physical writes:              185.0                1.1
                      User calls:            3,539.0               21.8
                      Parses:            1,167.2                7.2
                      Hard parses:              514.4                3.2
                      W/A MB processed:                6.8                0.0
                      Logons:               30.4                0.2
                      Executes:            2,502.8               15.4
                      Rollbacks:                0.3                0.0
                      Transactions:              162.4
                      500 hard parses per second is a high number, considering the number of user calls is not that high (3,500 per second). Use force_matching_signature to identify SQL that can benefit from using bind variables, or consider setting CURSOR_SHARING = force (requires extensive testing).

                      There is a very good chance that once you reduce the number of hard parsing rate, your latching problem will go away.

                      Best regards,
                      Nikolay
                      • 8. Re: latch: row cache objects takes 80% of database time
                        stee1rat
                        Thanks, everybody. It really looks like the problem is in this queries with literals.
                        Unfortunately I don't have a chance to try cursor_sharing parameter, 'cause it's a production database and this changes couldn't be done at this moment.
                        • 9. Re: latch: row cache objects takes 80% of database time
                          Nikolay Savvinov
                          Hi,

                          you can still solve your problem by using stored outline with force_match parameter (so that the plan be forced for all values of the literal),
                          see the link below for an example:

                          http://tonyhasler.wordpress.com/2011/12/16/force_match-for-stored-outlines-andor-sql-baselines/

                          Best regards,
                          Nikolay