Index are used to speed up the select statements.
But over a period of time, they may get fragmented because of constant DML’s occurring on the table. These bloated indexes may slow down the select or may cause plan flips too.
One way to avoid all these is to rebuild indexes.However, many of us might have faced issues while rebuilding indexes. Sometimes, it causes performance issues (due to enq TM contention) or the command won’t come out.
Ever wonder, why the index rebuilding is suddenly taking such a long time. Why my session is not coming out or exactly where is it stuck.
This post is intended to explore the internals of online index rebuild in oracle11g. I have developed a customized script which will tell exactly where the session is stuck.
https://fordba.wordpress.com/2011/03/30/ndx-progress-sql/
The script is just an anonymous plsql block and does not perform any DDL/DML.
It queries various v$ views to present the current picture before you and does not cause or have any adverse impact
For online index rebuild oracle requires 2 latches. One at the beginning and one at the end of the operation.
Online Index Rebuild Stages (No Parallel)
During Online index rebuild oracle performs following in the given order :-
- Create the journal table (inside index owner schema) SYS_JOURNAL_<objectid_index>
- Wait for the first latch (enq: TX – row lock contention)
- As soon as it gets latch, will perform db file sequential read to merge journal entries
- Will start scattered read of the base table
- Will again perform the sequential read to merge the journal entries which got generated during scattered read.
- Will perform direct path read temp.
- wait for the end latch
The good thing about index rebuild in 11g is , it does not cause locking for the DML’s (enq TM contention, which was there in 10g).
Test Case
Environment:- Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 – 64bit Production
1. Create a new table and insert few records.
SESSION1>CREATE TABLE mytab as select * from dba_objects; Table created. SESSION1>insert into mytab select * from mytab; 12459 rows created. SESSION1>/ 12459 rows created. SESSION1>create index mytab_idx on myt(owner,OBJECT_NAME,SUBOBJECT_NAME); Index created.
You may want to insert more rows to grow the size of index.
2. Insert a new records into the table.
SESSION1>insert into mytab select * from mytab where rownum<10; 9 rows created.
3. Open a new session (note down its sid) and issue alter index command.
SESSION2>select sid from v$mystat where rownum<2; SID ---------- 2195 1 row selected. SESSION2>ALTER INDEX MYTAB_IDX REBUILD ONLINE;
4. Open a new session to see exactly whats happening.
SESSION3>@ndx-progress.sql Enter value for sid: 2195 SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE SQL ID IS ---->drs3mtb5w9knb JOURNAL TABLE IS ---->SYS_JOURNAL_98701 TABLE NAME IS ---->MYTAB EVENT_NAME IS ---->enq: TX - row lock contention JOURNAL COUNT ---->0 STAGE ---->Waiting for first latch. PROGRESS ---->No Tx started after index rebuild has commited yet. There are 0 rows in journal table ------------SESSIONS BLOCKING FIRST LATCH ARE------------- SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE 2161 19807 INACTIVE 425 0 NONE 9babjv8yq8ru3 SQL*Plus db-fc-admin-6001.iad6.amazon.com ------------SESSIONS THAT MAY BLOCK LAST LATCH ARE------------- SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE NO POTENTIAL BLOCKERS FOUND FOR THE LAST LATCH
5. In the above output, you can see the session is waiting on enq: TX – row lock contention and has not acquired the first latch.
It will keep on waiting for all the transactions which have started before issueing index rebuild.
For any transactions started after index rebuild comand issued, they will cause locking at the last stage when end latch is required.
In case they commit, there entries will go into the journal table.
Lets open another session and insert few rows and wait for 30 seconds(This is the limit i set in my script to find potential blockers)
SESSION4>insert into mytab select * from mytab where rownum<101; 100 rows created.
6. Lets check whats happening again. The journal count is still 0, since session 4 has not commited yet and the session is appearing on potential blockers list
SESSION3>/ Enter value for sid: 2195 SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE SQL ID IS ---->drs3mtb5w9knb JOURNAL TABLE IS ---->SYS_JOURNAL_98701 TABLE NAME IS ---->MYTAB EVENT_NAME IS ---->enq: TX - row lock contention JOURNAL COUNT ---->0 STAGE ---->Waiting for first latch. PROGRESS ---->No Tx started after index rebuild has commited yet. There are 0 rows in journal table ------------SESSIONS BLOCKING FIRST LATCH ARE------------- SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE 2161 19807 INACTIVE 1015 0 NONE 9babjv8yq8ru3 SQL*Plus db-fc-admin-6001.iad6.amazon.com ------------SESSIONS THAT MAY BLOCK LAST LATCH ARE------------- SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE 2164 36539 INACTIVE 130 0 NONE 9babjv8yq8ru3 SQL*Plus db-fc-admin-6001.iad6.amazon.com
7. Lets commit from session 4 and see the difference in count of journal table. It will disappear from potential blockers list as it has committed and there will be entries into the journal table
SESSION3>/ Enter value for sid: 2195 SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE SQL ID IS ---->drs3mtb5w9knb JOURNAL TABLE IS ---->SYS_JOURNAL_98701 TABLE NAME IS ---->MYTAB EVENT_NAME IS ---->enq: TX - row lock contention JOURNAL COUNT ---->100 STAGE ---->Waiting for first latch. PROGRESS ---->Few Tx started after index rebuild command have been commited and there is/are 100 rows into journal table ------------SESSIONS BLOCKING FIRST LATCH ARE------------- SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE 2161 19807 INACTIVE 1134 0 NONE 9babjv8yq8ru3 SQL*Plus db-fc-admin-6001.iad6.amazon.com ------------SESSIONS THAT MAY BLOCK LAST LATCH ARE------------- SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE NO POTENTIAL BLOCKERS FOUND FOR THE LAST LATCH
8. So far we have observed that index is stuck. Lets insert few more rows (100k approx) so that we could observe step3 else we wont able to catch the initial db file sequential read merging and check the status.
SESSION4>insert into mytab select * from mytab where rownum<100001; 100000 rows created. SESSION4>commit; Commit complete.
——————————-check from session 3———————-
SESSION3>/
Enter value for sid: 2195
SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE
SQL ID IS ---->drs3mtb5w9knb
JOURNAL TABLE IS ---->SYS_JOURNAL_98701
TABLE NAME IS ---->MYTAB
EVENT_NAME IS ---->enq: TX - row lock contention
JOURNAL COUNT ---->100100
STAGE ---->Waiting for first latch.
PROGRESS ---->Few Tx started after index rebuild command have been commited and there is/are 100100 rows into journal table
------------SESSIONS BLOCKING FIRST LATCH ARE-------------
SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE
2161 19807 INACTIVE 1717 0 NONE 9babjv8yq8ru3 SQL*Plus db-fc-admin-6001.iad6.amazon.com
------------SESSIONS THAT MAY BLOCK LAST LATCH ARE-------------
SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE
NO POTENTIAL BLOCKERS FOUND FOR THE LAST LATCH
9. Insert few more rows again from session 4, to ensure we block the last latch too.
SESSION4>insert into mytab select * from mytab where rownum<100; 99 rows created.
10. Lets commit from session 1 to release initial lock and check status from session 3.
SESSION3>/ Enter value for sid: 2195 SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE SQL ID IS ---->drs3mtb5w9knb JOURNAL TABLE IS ---->SYS_JOURNAL_98701 TABLE NAME IS ---->MYTAB EVENT_NAME IS ---->db file sequential read JOURNAL COUNT ---->0 STAGE ---->First latch acquired.db file sequential read going on. Direct path read pending after this step. PROGRESS ---->All Tx started before index rebuild have been commited (first latch acquired and cleared) and no entries into journal table now.
As we can see, oracle always merge the journal table entries before performing scatterd read(FTS on base table).
Once that gets completed, oracle will start scattered read. Scattered read does not need any lock, so at this time our session 4 wont lock the index rebuild. it will lock during last phase.
SESSION3>/ Enter value for sid: 2195 SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE SQL ID IS ---->drs3mtb5w9knb JOURNAL TABLE IS ---->SYS_JOURNAL_98701 TABLE NAME IS ---->MYTAB EVENT_NAME IS ---->db file scattered read JOURNAL COUNT ---->0 STAGE ---->First latch acquired. FTS going on PROGRESS ---->All Tx started before index rebuild have been commited (first latch acquired and cleared) and no entries into journal table now.
Once that is done,oracle will perform sequential read and direct path read temp to merge entries generated during scattered read and then will wait for end latch.
Enter value for sid: 2195 SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE SQL ID IS ---->drs3mtb5w9knb JOURNAL TABLE IS ---->SYS_JOURNAL_98701 TABLE NAME IS ---->MYTAB EVENT_NAME IS ---->enq: TX - row lock contention JOURNAL COUNT ---->0 STAGE ---->Operation completed.Waiting for ending latch PROGRESS ---->All Tx started before index rebuild have been commited (first latch acquired and cleared) and no entries into journal table now. ------------SESSIONS BLOCKING LAST LATCH ARE------------- SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE 2164 36539 INACTIVE 367 0 NONE 9babjv8yq8ru3 SQL*Plus db-fc-admin-6001.iad6.amazon.com
Once commit, index rebuild fiishes
Online Index Rebuild Stages (Parallel Clause)
Oracle performs following sequence of events with parallel clause
- Create the journal table (inside index owner schema) SYS_JOURNAL_<objectid_index>
- Wait for the “first latch” (enq: TX – row lock contention)
- As soon as it gets latch, will perform , it will spawn its slave process
- Slave process will perform db file sequential read to merge the journal table entries
- Each slave process will perform scattered read for its bunch of blocks.
- Slave process will again perform the sequential read to merge the journal entries which got generated during scattered read.
- slave process job will end here here.
- Master process will wait for the “end latch”.
Test Case
Insert few records from the first session to block index rebuild.
SESSION1>insert into mytab select * from mytab where rownum<101; 100 rows created.
Open another session and rebuild index with parallel clause
SESSION2>ALTER INDEX MYTAB_IDX REBUILD ONLINE parallel 4;
Checking the status
SESSION3>/
Enter value for sid: 2195
SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE parallel 4
SQL ID IS ---->7qr6scnthqh0f
JOURNAL TABLE IS ---->SYS_JOURNAL_98701
TABLE NAME IS ---->MYTAB
EVENT_NAME IS ---->enq: TX - row lock contention
JOURNAL COUNT ---->0
STAGE ---->Waiting for first latch.
PROGRESS ---->No transaction started after rebuiding has committed.
------------SESSIONS BLOCKING FIRST LATCH ARE-------------
SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE
2161 19807 INACTIVE 152 0 NONE 9babjv8yq8ru3 SQL*Plus db-fc-admin-6001.iad6.amazon.com
------------SESSIONS THAT MAY BLOCK LAST LATCH ARE-------------
SID SERIAL STATUS LAST_CALL_ET COMMAND SQL_ID PREV_SQL_ID MODULE MACHINE
NO POTENTIAL BLOCKERS FOUND FOR THE LAST LATCH
As we commit the first session, parallel process will start the processing.
SESSION3>/ Enter value for sid: 2195 SQL TEXT IS ---->ALTER INDEX MYTAB_IDX REBUILD ONLINE parallel 4 SQL ID IS ---->7qr6scnthqh0f JOURNAL TABLE IS ---->SYS_JOURNAL_98701 TABLE NAME IS ---->MYTAB EVENT_NAME IS ---->PX Deq: Execute Reply JOURNAL COUNT ---->0 STAGE ---->First latch acquired. Parallel processing going on ------------TOTAL SLAVES ARE------------- SID SERIAL DEGREE REQ_DEGREE EVENT 2149 46710 4 4 direct path read temp 2154 22192 4 4 PX Deq: Execution Msg 2156 23451 4 4 PX Deq: Execution Msg 2157 2939 4 4 PX Deq: Execution Msg 2159 55050 4 4 direct path read temp 2168 5080 4 4 direct path read temp 2184 46569 4 4 direct path read temp 2193 3495 4 4 PX Deq: Execution Msg ------------LONGOPS SLAVES ARE------------- SID SERIAL TOTALWORK SOFAR TIME REMAINING ELAPSED SECONDS OPNAME EVENT 2168 5080 40531 16913 20 14 Sort Output direct path read temp 2149 46710 37403 16918 17 14 Sort Output direct path read temp 2159 55050 32739 16872 14 15 Sort Output direct path read temp 2184 46569 30720 17012 11 14 Sort Output direct path read temp
For DBA 