Finding the blocking SQL in a lock wait
One of my pet peeves on Oracle is the inability to find out what SQL took out a lock that another user is waiting. It’s easy to find the waiting user and their SQL with v$session by looking at v$session.event where the event is an “enqueue” (v8 and v9) or “enq: TX – row lock contention” and then looking up their SQL via the v$session.sql_hash_value which joins to v$sql.hash_value for the v$sql.sql_text.
So far so good and easy.
Second step of finding the blocker is really easy starting in 10g because Oracle has a new field v$session.blocking_session which can be joined back to v$session.sid to find information on that user.
The rub is that there is no way to find the SQL text that the blocking session ran that took out the original blocking lock.
For the 2 day course I teach on Active Session History (ASH) and Oracle wait events, I wanted to show students how to actually get the blocking SQL text if they really had to. I went as far as looking at log miner to try and get the blocking SQL text and this works sometimes and sometimes it doesn’t. At that point I gave up, knowing the next step was dumping the redo logs which was more research than I felt like doing at the time.Luckily someone has picked up the torch – Doug Burns! On the Oaktable email list I shared my research with Doug and Doug took it even farther and posted it on his blog:
Diagnosing Locking Problems using ASH – Part 1 – try OEM 10g on Lock Problem
Diagnosing Locking Problems using ASH – Part 2 – look at raw ASH data, missing blocker SQL
Diagnosing Locking Problems using ASH – Part 3 – look at raw ASH data, find the blocker SQL
Diagnosing Locking Problems using ASH – Part 4 – misleading data from ASH
Diagnosing Locking Problems using ASH – Part 5 – logminer undependable
Diagnosing Locking Problems using ASH – Part 6 – overview of all the parts (table of contents)
Diagnosing Locking Problems using ASH/LogMiner – Part 7 – Redo log dump
Diagnosing Locking Problems using ASH/LogMiner – Part 8 – Redo log dump lacks “select for update”
Diagnosing Locking Problems using ASH/LogMiner – Part 9 – Redo log dump – search for traces of “select for update”
Final Post (thanks to JL for pointing out I’d left this off)
Long story short, the best way to try and see what changed (when there was a change and not a “select for update”) to cause the lock is to use flashback information. For example if or contention table was TEST_TAB and our field that we knew was modified “VAL1″ then we could try to find what it was changed from:
update test_tab set val1=’aa’ where id=1;
update test_tab set val1=’aaa’ where id=1;
Blocking info from ASH where wait is enq: TX – row lock contention
select distinct lpad(ltrim(to_char(p2,'XXXXXX')),6,'0')||'00'|| ltrim(to_char(mod(p3,256),'XX'))|| ltrim(to_char(trunc(p3/256),'XX'))||'0000' block_xid, to_char(p2,'XXXXXXXX') p2hex, to_char(p3,'XXXXXXXX') p3hex, trunc(p2/65536) usn, mod(p2,65536) slot, p3 sqn, xid wait_xid from v$active_session_history where event like 'enq: T%' and sample_time > sysdate - &v_minutes/(60*24) ; BLOCK_XID P2HEX P3HEX USN SLOT SQN WAIT_XID ---------------- --------- --------- ---------- ---------- ---------- ---------------- 0A0001007264000 A0001 6472 10 1 25714
Data from flashback, after session 1 commits (before the commit there is no data returned)
SELECT VERSIONS_XID , VERSIONS_STARTTIME , VERSIONS_ENDTIME , VERSIONS_STARTSCN , VERSIONS_ENDSCN , VERSIONS_OPERATION , id , val1 FROM TEST_TAB VERSIONS BETWEEN TIMESTAMP MINVALUE AND MAXVALUE where VERSIONS_XID=HEXTORAW('0A0001007264000') ORDER BY VERSIONS_STARTTIME / VERSIONS_XID VERSIONS_STARTTIME ENDTIME STARTSCN ENDSCN V VAL1 ---------------- --------------------- ------- -------- ------- - -------------- 0A00010072640000 15-OCT-13 06.46.30 PM 17042888 U aa
Now that’s not the blocking SQL but at least you can see what the value of the field was that the blocker changed it to, so you can guess to some degree what the actual SQL was. Not great, but better than nothing.