This discussion is archived
9 Replies Latest reply: Nov 26, 2012 5:36 AM by Nikolay Savvinov RSS

latch: row cache objects takes 80% of database time

stee1rat Newbie
Currently Being Moderated
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 Explorer
    Currently Being Moderated
    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 Guru
    Currently Being Moderated
    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 Newbie
    Currently Being Moderated
    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 Guru
    Currently Being Moderated
    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 Oracle ACE Director
    Currently Being Moderated
    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 Newbie
    Currently Being Moderated
    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 Guru
    Currently Being Moderated
    >
    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 Newbie
    Currently Being Moderated
    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 Guru
    Currently Being Moderated
    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

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points