V$ENQUEUE_STATISTICS gives detailed information (several rows for same enqueues with different reasons) and statistics.
select * from v$enqueue_statistics where eq_type in ('RO', 'KO');
EQ_NAME EQ REQ_REASON TOTAL_REQ# TOTAL_WAIT# SUCC_REQ# FAILED_REQ# CUM_WAIT_TIME REQ_DESCRIPTION
-------------------------- -- ---------------------- ---------- ----------- --------- ----------- ------------- ----------------------------------------
Multiple Object Reuse RO fast object reuse 1,039 82 1,038 0 1,040,219 Coordinates fast object reuse
Multiple Object Reuse RO contention 0 0 0 0 0 Coordinates flushing of multiple objects
Multiple Object Checkpoint KO fast object checkpoint 60 6 60 0 870,104 Coordinates fast object checkpoint
Reuse Block Range CR block range reuse ckpt 1,848 15 1,848 0 20 Coordinates fast block range reuse ckpt
If (TOTAL_REQ# - SUCC_REQ# > 0 and FAILED_REQ# = 0), there exists on-going EQ requests.Note: All tests are done in Oracle 12.1.0.2 on Solaris.
1. Test Setup
--Test DB is configured with:
-- db_writer_processes=2
drop table tab1;
create table tab1 as select level x, rpad('ABC', 100, 'X') y from dual connect by level < 1000000;
2. 'enq: KO - fast object checkpoint' Test
Suspend one of DB WRITERs, for example, DBW1:
SQL> oradebug setorapid 12
Oracle pid: 12, Unix process pid: 19980, image: oracle@s5d00003 (DBW1)
SQL> oradebug suspend
Statement processed.
Run query:
SQL (543) > select /*+ parallel(t 4) */ count(*) from tab1 t where x < 100000;
Both blocker_sid and final_blocking_session are same, that is, CKPT (SID: 361):
SQL (123) > select c.chain_id, c.chain_signature, c.sid, c.blocker_sid bsid, final_blocking_session final_bsid, s.program, s.sql_id, s.event
from v$wait_chains c, v$session s
where c.sid = s.sid order by c.chain_id, s.program;
CHAIN_ID CHAIN_SIGNATURE SID BSID FINAL_BSID PROGRAM SQL_ID EVENT
-------- ------------------------------------------------------- --- ---- ---------- ----------- ------------- -------------------------------
1 'rdbms ipc message'<='enq: KO - fast object checkpoint' 361 (CKPT) rdbms ipc message
1 'rdbms ipc message'<='enq: KO - fast object checkpoint' 543 361 361 sqlplus.exe 4wwzmhypuvnc6 enq: KO - fast object checkpoint
SQL (123) > select sql_id, executions, substr(sql_text, 1, 60) sql_text from v$sql v where sql_id = '4wwzmhypuvnc6';
SQL_ID EXECUTIONS SQL_TEXT
------------- ---------- ------------------------------------------------------------
4wwzmhypuvnc6 0 select /*+ parallel(t 4) */ count(*) from tab1 t where x < 1
After test, resume DBW1:
SQL> oradebug resume
By the way, to make above behavior repeatable, each time tab1 has to be dropped and recreated.
3. 'enq: RO - fast object reuse' Test
Again suspend DBW1 (same behaviour if suspend LGWR):
SQL> oradebug setorapid 12
Oracle pid: 12, Unix process pid: 19980, image: oracle@s5d00003 (DBW1)
SQL> oradebug suspend
Statement processed.
Run statement:
SQL (543) > truncate table tab1;
Both blocker_sid and final_blocking_session are same, that is, CKPT (SID: 361):
SQL (123) > select c.chain_id, c.chain_signature, c.sid, c.blocker_sid bsid, final_blocking_session final_bsid, s.program, s.sql_id, s.event
from v$wait_chains c, v$session s
where c.sid = s.sid order by c.chain_id, s.program;
CHAIN_ID CHAIN_SIGNATURE SID BSID FINAL_BSID PROGRAM SQL_ID EVENT
-------- -------------------------------------------------- --- ---- ---------- ----------- ------------- ---------------------------
1 'rdbms ipc message'<='enq: RO - fast object reuse' 361 (CKPT) rdbms ipc message
1 'rdbms ipc message'<='enq: RO - fast object reuse' 543 361 361 sqlplus.exe 83w7b0h5ug6ph enq: RO - fast object reuse
SQL (123) > select sql_id, executions, substr(sql_text, 1, 60) sql_text from v$sql v where sql_id = '83w7b0h5ug6ph';
SQL_ID EXECUTIONS SQL_TEXT
------------- ---------- -------------------
83w7b0h5ug6ph 0 truncate table tab1
After test, resume DBW1:
SQL> oradebug resume
By the way, we observed: "enq: CR - block range reuse ckpt", also blocked by CKPT,
when deleting many rows which are inserted by PL/SQL bulk SQL "forall insert into values"
(to observe it clearnly, at first suspend DBWn).Query to list all CKPT related Enqueues in a long running DB
select * from V$ENQUEUE_STATISTICS
where (lower(req_description) like '%checkpo%' or lower(req_description) like '%ckpt%' or lower(req_description) like '%fast%reuse%'
or eq_type in ('CF', 'CR', 'KO', 'RO', 'TC', 'RT', 'HW'))
and total_req# > 0;
4. FINAL_BLOCKING_SESSION
In both above tests, CKPT is shown as final_blocking_session, but in reality, that is DBW1 suspended. The reason is probably because Foreground process only communicates with CKPT, and has no direct IPC call of DB WRITER processes.
Oracle MOS documented this behavior:
MOS Resolving Issues Where 'enq: RO - fast object reuse' Contention Seen During Drop or Truncate Operations (Doc ID 1475659.1)
The RO enqueue known as "Multiple object reuse" enqueue, is used to synchronise operations between foreground process and a background process such as DBWR or CKPT. It is typically used when dropping objects or truncating tables. Following is the sequence of events When a truncate/drop occurs: 1.Foreground process acquires the "RO" enqueue in exclusive mode 2.Cross instance calls (or one call if it is a single object) are issued ("CI" enqueue is acquired) 3.CKPT Processes on each of instances requests the DBWR to write the dirty buffers to the disk and invalidate all the clean buffers. 4.After DBWR completes writing all blocks, the foreground process releases the RO enqueue.
5. Discussions
KO enqueue is triggered by SELECT table FULL scan, which requires writing all dirty buffer blocks into disk datafiles and updating Extent Bitmap in Segment Header Extent.
RO enqueue is triggered by TRUNCATE table, which requires cleaning up (write) segment header (bitmap info), that is the 2nd Block (Extent Bitmap) in Segment Header Extent for small table.
When both enqueues appear in top Wait Events, following Events can be also observed:
free buffer waits buffer busy waits local write wait write complete waitsFor "free buffer waits", P3 (set-id#) reveals the responsible DBWR.
Blog: ASSM Truncate demonstrated RO enqueue when truncating table with big "INITIAL", and explained that the blocks written were the space management bitmap blocks for the extent(s) that remained after the truncate (storage_clause "INITIAL" specifies the size of the first extent of the object. Oracle allocates space for this extent when you create the schema object).
6. row cache lock
In 'enq: RO - fast object reuse' Test, if we open one more Sqlplus Session (SID=726) and perform the same tab1 truncate, we observe "row cache lock" with "cache id = 8" (dc_objects/dc_object_grants).
drop table tab1;
create table tab1 as select level x, rpad('ABC', 100, 'X') y from dual connect by level < 1000000;
SQL> oradebug setorapid 12
Oracle pid: 12, Unix process pid: 19980, image: oracle@s5d00003 (DBW1)
SQL> oradebug suspend
Statement processed.
SQL (543) > truncate table tab1;
SQL (726) > truncate table tab1;
select c.wait_event_text, c.sid, c.blocker_sid bsid, s.final_blocking_session final_bsid,
s.program, s.sql_id, s.p1text, s.p1, s.p2text, s.p2, s.p3text, s.p3
from v$wait_chains c, v$session s
where c.sid = s.sid order by c.chain_id, s.program;
WAIT_EVENT_TEXT SID BSID FINAL_BSID PROGRAM SQL_ID P1TEXT P1 P2TEXT P2 P3TEXT P3
--------------------------- --- ---- ---------- ------------ ------------- --------- ------------- ------ ------ ------ --
rdbms ipc message 361 (CKPT) timeout 300 0 0
row cache lock 726 543 361 sqlplus.exe 83w7b0h5ug6ph cache id 8 mode 0 request 3
enq: RO - fast object reuse 543 361 361 sqlplus.exe 83w7b0h5ug6ph name|mode 1,380,909,062 2 65,563 0 1
If we create one second table (tab2), and let new Sqlplus Session (SID=726) truncate tab2,
both sessions are on "enq: RO - fast object reuse", no more "row cache lock" observed.
drop table tab1;
create table tab1 as select level x, rpad('ABC', 100, 'X') y from dual connect by level < 1000000;
drop table tab2;
create table tab2 as select level x, rpad('ABC', 100, 'X') y from dual connect by level < 1000000;
SQL> oradebug setorapid 12
Oracle pid: 12, Unix process pid: 19980, image: oracle@s5d00003 (DBW1)
SQL> oradebug suspend
Statement processed.
SQL (543) > truncate table tab1;
SQL (726) > truncate table tab2;
select c.wait_event_text, c.sid, c.blocker_sid bsid, s.final_blocking_session final_bsid,
s.program, s.sql_id, s.p1text, s.p1, s.p2text, s.p2, s.p3text, s.p3
from v$wait_chains c, v$session s
where c.sid = s.sid order by c.chain_id, s.program;
WAIT_EVENT_TEXT SID BSID FINAL_BSID PROGRAM SQL_ID P1TEXT P1 P2TEXT P2 P3TEXT P3
--------------------------- --- ---- ---------- ------------ ------------- --------- ------------- ------ ------ ------ --
rdbms ipc message 361 (CKPT) timeout 300 0 0
enq: RO - fast object reuse 543 361 361 sqlplus.exe 83w7b0h5ug6ph name|mode 1,380,909,062 2 65,563 0 1
enq: RO - fast object reuse 726 361 361 sqlplus.exe 2wdshw3gfd81s name|mode 1,380,909,062 2 65,564 0 1
select sql_id, executions, substr(sql_text, 1, 60) sql_text
from v$sql v where sql_id in ('83w7b0h5ug6ph', '2wdshw3gfd81s');
SQL_ID EXECUTIONS SQL_TEXT
------------- ---------- -------------------
2wdshw3gfd81s 0 truncate table tab2
83w7b0h5ug6ph 0 truncate table tab1