A few days ago I found myself investigating a session that had become blocked during the middle of the night. This session happened to belong to a critical application so caused an on call engineer to be paged, but by the time they looked the session had become unblocked and the application was back happy and running again. I only found out the next morning so was investigating somewhat after the fact. I decided to have a look at what the active session history could shed on the problem. There is a lot of information out there about what ASH can do for you and I heartily recommend reading them.
I was fortunate in that the application whose session was being blocked was still connected to the database, so I could easily identify a SID, and had logged when it was paused. I could then could generate a report on active session history based on just that session_id (it’s quite frustrating that, for example, V$session uses the column SID for the session identifier, while V$active_session_history uses SESSION_ID for the session identifier, am I alone in finding inconsistencies like this really annoying and a clear case of a lack of communication within oracle!?!) Anyway I ran some very simple sql along the lines of:
select session_id, event, sql_id, blocking_session
where sample_time between (sysdate - 6/24) and (sysdate - 5/24)
and session_id = &sid
It produced output like the following:
So I could see that this application had been blocked because some other session had locked a row my application was interested in updating. But There is no misprint in the blocking session information, it was not present in the case I was examing, this was Oracle version 10.2.0.3. What a pain. I could see sql_id and could find out easily what sql my blocked application was trying to run, but V$active_session_history was not telling me what was causing the blockage.
In the end I looked at an awr report for the period covering the blockage and saw a database job was running and a knowledge of what the job was showing enabled us to be sure this was the culprit. But it lead to the conclusion that jobs scheduled with DBMS_JOB do not show up as a blocking session in the V$active_session_history view.
It’s pretty trivial to reproduce:
SQL> create table t (time timestamp); Table created SQL> insert into t select sysdate from dual 1 row created. SQL> commit; Commit complete. SQL> create or replace procedure update_t as begin update t set time = (select sysdate from dual); dbms_lock.sleep(120); commit; end; / Procedure created. SQL> declare num_job BINARY_INTEGER; begin dbms_job.submit(job => num_job, what => ‘update_t;’, next_date => sysdate + 1/(24*20), interval => ‘(sysdate+1/86400) + mod(trunc(sysdate+(1/86400)+(1/24),”HH24”) - (sysdate+1/86400),1/96)’); commit; end; /
Now all you have to do is run the update in another session while the database job is running. Then when you query V$active_session_history, you too will be able to a session that is blocked with row lock contention but has no blocking session information. Not earth shattering perhaps, but it was surprising to me to see a session shown as blocked but not blocking_session information. So now you know, if you see these symptoms, your blocking session could well have been a database jobs. Of course, you are probably all using DBMS_SCHEDULER by now, anyone know if this shows as a blocking session in v$active_session_history?