row cache lock

[Roshan]

Oracle DB 12.1.0.2 RAC 2 nodes.

Hello Erman,

can you please advise why is there row cache lock when dropping a table?

Trace file: dware11_ora_6124_TICKET_TRACE.trc
Sort options: default

********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************

SQL ID: f8ubn7n5zt0nh Plan Hash: 0

drop table TB_MT_TT_PEND_CBS_NEW purge


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.01     171.51          0          0          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.01     171.51          0          0          0           0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 102

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  row cache lock                                 58        3.00        171.50
  SQL*Net break/reset to client                   1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        1.56          1.56
********************************************************************************

SQL ID: 5hrvvu1r771m5 Plan Hash: 1279162032

SELECT VALUE$
FROM
 SYS.PROPS$ WHERE NAME = 'OGG_TRIGGER_OPTIMIZATION'


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0          2          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          2          0           0

Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: SYS   (recursive depth: 1)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  TABLE ACCESS FULL PROPS$ (cr=2 pr=0 pw=0 time=41 us cost=2 size=28 card=1)




********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.01     171.51          0          0          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.01     171.51          0          0          0           0

Misses in library cache during parse: 1

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       2        0.00          0.00
  SQL*Net message from client                     2        1.56          1.56
  row cache lock                                 58        3.00        171.50
  SQL*Net break/reset to client                   1        0.00          0.00


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0          2          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          2          0           0

Misses in library cache during parse: 1

    1  user  SQL statements in session.
    1  internal SQL statements in session.
    2  SQL statements in session.
********************************************************************************
Trace file: dware11_ora_6124_TICKET_TRACE.trc
Trace file compatibility: 11.1.0.7
Sort options: default

       1  session in tracefile.
       1  user  SQL statements in trace file.
       1  internal SQL statements in trace file.
       2  SQL statements in trace file.
       2  unique SQL statements in trace file.
     224  lines in trace file.
     173  elapsed seconds in trace file.

Thanks,

Roshan

[ErmanArslansOracleBlog]

You waited for row cache lock for the following statement ->

drop table TB_MT_TT_PEND_CBS_NEW purge

So it is a drop table purge operation.

We need to see the details about the session to tell you something useful..
There are bugs recorded for these types issues..

We need to check the call stack and the wait details (wait stack) to check the situation properly.

[Roshan]

How do we check the call stack and wait details? Is it the V$SESSION_WAIT,V$SYSTEM_EVENT and V$SESSION_EVENT?

[ErmanArslansOracleBlog]

There are failure modes in this context, but actually your session could do its job, so it could drop the table, but it seem it took some time and that's your concern..
v$rowcache will give you some hints, but these should be recorded in the trace file.
Don't you see the wait details and the call stack in the trace file?
Can you reproduce the issue? If so, enable trace and reproduce.. Once you reproduce the issue and get the trace, let me see that trace..
A session level 10046 trace will be sufficient for now.

[Roshan]

Thanks for the update.

Please find attached
dware11_ora_6124_TICKET_TRACE.prf

[ErmanArslansOracleBlog]

That trace doesn't help.. It just shows us that, drop table operation completed in 171 secs due to row cache lock.. So it doesn't crash, it doesn't hang and it doesn't create a deadlock situation.. It just takes some time to complete..

You need to reproduce the issue and while you are waiting for that drop operation; you should identify the cache that is being waited by your session.

While the drop operation is waiting; you should run the following;

select p1text,p1,p2text,p2,p3text,p3 from v$session where event='row cache lock';

select parameter,count,gets,getmisses,modifications from v$rowcache where cache#=<p1_from_above>

According to the value returned from query above, here are the suggestions;

DC_SEQUENCES
For DC_SEQUENCES, consider caching sequences using the cache option.

DC_OBJECTS
Look for any object compilation activity which might require an exclusive lock, blocking other activities

DC_SEGMENTS
Contention here is most likely to be due to segment allocation.  Investigate what segments are being created at the time.

DC_USERS
This may occur if a session issues a GRANT to a user and that user is in the process of logging on to the database. Investigate why grants are being made while the users are active.

DC_TABLESPACES
The most likely cause is the allocation of new extents. If extent sizes are set low then the application may constantly be requesting new extents and causing contention. Do you have objects with small extent sizes that are rapidly growing? (You may be able to spot these by looking for objects with large numbers of extents). Check the trace for insert/update activity, check the objects inserted into for number of extents.

[Roshan]

Thank you. I will try the steps.

[Roshan]

Hello Erman,

happy new year.

I generated the trace file again and saw 'direct path write temp' wait event. I generated AWR report (1576956.1) and saw I/O was not an issue. Maybe I need to increase PGA?

pga_aggregate_limit  big integer 9000M
pga_aggregate_target big integer 3726M

dware11_ora_10928_TICKETJAN2.prf
awrrpt_1_20263_20264.html

Thanks,

Roshan

[Roshan]

export.xlsx

Should I increase to 31g?

[ErmanArslansOracleBlog]

This trace doesn't represent the same issue. We don't have a significant row cache lock wait there Roshan.
so I guess you shouldn't reproduce the issue..

You got some direct path write temp wait there. But that's for :

SQL ID: 2z9xtas2f76d8 Plan Hash: 0
create table  BIREPORT.TB

I don't see the whole create table statemement, but probably there is a sort there.
Remember those waits; are typically caused by sort operations which cannot be completed in memory.

These types of is generally seen during the following operations:

Index Creation
Aggregation/Group By
Order By SQL's
UNION/Intersect/Minus Operations

Anyways, this is an another case, and it doesn't seem related with the actual one..
But in case if you want to address some direct path write temp, just check the following MOS note:

How to Address High Wait Times for the 'direct path write temp' Wait Event (Doc ID 1576956.1)