After deadlock occur, beside exception (ORA-00060), alert log entry is entered with message, one trace file in background_dump_dest directory is generated. In that trace file, between all others information about deadlock, it is very clearly written:
...
[Transaction Deadlock]
The following deadlock is not an ORACLE error. It is a deadlock due to user error in the design of an application or from issuing incorrect ad-hoc SQL. The following information may aid in determining the deadlock
...
[Transaction Deadlock]
The following deadlock is not an ORACLE error. It is a deadlock due to user error in the design of an application or from issuing incorrect ad-hoc SQL. The following information may aid in determining the deadlock
...
Because alert log and trace files are on the server side, where most of developers cannot reach, this is why all such problems fall in DBA hands, regardless most of us do not do design (!?) or program the database which we administer.
9i deadlock monitoring solution
While I was working in 2005 as DBA in one company with Oracle 9i, where deadlock was a serious and constant problem, I was tired from transferring all the time files to developers. This is why I created a standalone solution which capture deadlock and save all important data to two native Oracle tables. This 9i solution is available to download .Solution is implemented in separate schema (tools) which should have enough privileges for that. So this is one additional step is needed to be done for such a scenario. Because non privileged users can query "%$" views, I have to create replica with similar name and grant select to tools user:
create or replace SYS.VT$OBJ as select * from SYS.OBJ$;
GRANT SELECT ON SYS.VT$OBJ TO TOOLS;
Of course, other way was to implement the whole logic in SYS schema, but then in some future exports...this could be lost (exp doesn't export sys schema). GRANT SELECT ON SYS.VT$OBJ TO TOOLS;
Deadlock information are recorded in mentioned two tables (DEADLOCK_LOG_LOCKERS, DEADLOCK_LOG_WAITERS). The whole logic is automated through database trigger, which is fired when ORA-00060 occur.
CREATE OR REPLACE TRIGGER db_aserr_tgb
AFTER SERVERERROR
ON DATABASE
BEGIN
IF (IS_SERVERERROR (60)) THEN
deadlock_log_prc;
END IF;
EXCEPTION
WHEN OTHERS THEN
null;
END db_aserr_tgb;
/
AFTER SERVERERROR
ON DATABASE
BEGIN
IF (IS_SERVERERROR (60)) THEN
deadlock_log_prc;
END IF;
EXCEPTION
WHEN OTHERS THEN
null;
END db_aserr_tgb;
/
Finally, referenced deadlock_log_prc procedure in trigger, do the whole job-fill tables with information about deadlocks. If you perform code from picture at the beginning (attached source for this exampel is in RAR files as well) then on 9i database you get something like:
Notice that beside other information from session that caused deadlock, rightmost column contains SQL from session that survived.
Second table describes more with global data what was in the moment of deadlock.
Using ID and DEADLOG_DATE fields you can join tables and analyze the deadlock situation. Because I granted public select on both of tables developers were able to help them self with no intervention from DBA, what makes my work easier.
As you can see those two tables has almost all important data which you can find in trace file.
Non automatic usage
Because deadlock is in core classical exception, following, usual "developers like" code, will prevent deadlock logging:BEGIN
UPDATE....
EXCEPTION
WHEN OTHERS THEN
null;
END;
/
because exception is silently "crushed" in general exception handler without proper processing interesting part of it. UPDATE....
EXCEPTION
WHEN OTHERS THEN
null;
END;
/
So it is much, much better next code which will fix previous problem with missed logging, leaving the whole program functionality as it was:
DECLARE
my_deadlock_exc EXCEPTION;
PRAGMA EXCEPTION_INIT (my_deadloc_exc, -60);
BEGIN
UPDATE....
EXCEPTION
WHEN my_deadlock_exc THEN
deadlock_log_prc;
WHEN OTHERS THEN
null;
END;
As you can see, because trigger cannot be called implicitly, we are calling explicitly deadlock_log_prc which is in the case exception handler for deadlock exception.my_deadlock_exc EXCEPTION;
PRAGMA EXCEPTION_INIT (my_deadloc_exc, -60);
BEGIN
UPDATE....
EXCEPTION
WHEN my_deadlock_exc THEN
deadlock_log_prc;
WHEN OTHERS THEN
null;
END;
Whenever I had a chance, I always tried to learn developers to make some exception handlers at least for some harmless events (resource bussy, record not found etc)... to prevent hiding real problems in WHEN OTHERS part.
11g deadlock changes!
After that I was working as APPS 11i DBA, locking story passed away from my mind. The reason is very easy: in EBS there is no ref constraints-so deadlocks are very, very rare...frankly if they happened it is usually from the customization part.Recently I jump into one interesting post 11g is more deadlock sensitive than 10g?, which mentioned something about expanded logic in deadlock. As I have at home my 11gR1, I decided to test that immediately.
Very soon I realize that 11g-9i difference in this part are really huge. As you can see, my solution, which was perfectly working on 9i, on 11g, beside important data which must be captured, was capturing many others unnecessary data, which were not produced in 9i.
11g deadlock monitoring workaround
After some small investigation, the quickest solution can be done by adding additional filters before posting captured sqls. For that i have re changed a little bit logic in deadlock_log_prc procedure. Here is how it now it looks (change code is especially colored):CREATE OR REPLACE PROCEDURE deadlock_log_prc IS
/*------------------------------------------------------------------------------
Filename: 3_deadlock_log_prc.sql
Purpose : Procedure which fill deadlock monitoring tables with data
when deadlock occur
Date : 18.10.2005
Author : Damir Vadas
CR : 1500
Remarks : run as priviledged user
Should work on 9i-11g Oracle versions
Changes (DD.MM.YYYY):
27.11.2009. Damir Vadas
Rechanged logic for 11g databases (not too much tested-looks good)
----------------------------------------------------------------------------*/
PRAGMA AUTONOMOUS_TRANSACTION;
v_id INTEGER;
v_date DATE;
BEGIN
SELECT tools_seq.nextVal, sysdate
INTO v_id, v_date
FROM dual
;
INSERT INTO tools.deadlock_log_lockers (
id
, deadlog_date
, os_locker
, locker_schema
, locker_pid
, os_waiter
, waiter_schema
, waiter_pid
, sql_text_waiter
)
/* TX row locks */
WITH Q AS (
SELECT /*+ rule */
S_LOCKER.OSUSER OS_LOCKER
, S_LOCKER.USERNAME LOCKER_SCHEMA
, S_LOCKER.PROCESS LOCK_PID
, S_WAITER.OSUSER OS_WAITER
, S_WAITER.USERNAME WAITER_SCHEMA
, S_WAITER.PROCESS WAITER_PID
, (SELECT sql_fulltext from v$sql where sql_id = O.SQL_ID AND ROWNUM<=1)
SQL_TEXT
FROM
V$LOCK L_WAITER
, V$LOCK L_LOCKER
, V$SESSION S_WAITER
, V$SESSION S_LOCKER
, V$_LOCK L1_WAITER
, V$OPEN_CURSOR O
WHERE S_WAITER.SID = L_WAITER.SID
AND L_WAITER.TYPE IN ('TX')
AND S_LOCKER.sid = L_LOCKER.sid
AND L_LOCKER.ID1 = L_WAITER.ID1
AND L_WAITER.REQUEST > 0
AND L_LOCKER.LMODE > 0
AND L_WAITER.ADDR != L_LOCKER.ADDR
AND L1_WAITER.LADDR = L_WAITER.ADDR
AND L1_WAITER.KADDR = L_WAITER.KADDR
AND L1_WAITER.SADDR = O.SADDR
AND O.USER_NAME != 'SYS'
)
SELECT
v_id
, v_date
, OS_LOCKER
, LOCKER_SCHEMA
, LOCK_PID
, OS_WAITER
, WAITER_SCHEMA
, WAITER_PID
, CAST (DBMS_LOB.SUBSTR (SQL_TEXT, 4000) AS VARCHAR (4000))
FROM Q
/* table-level locks (TM) and mixed TM/TX TX/TM */
SELECT /*+ rule */
v_id
, v_date
, S_LOCKER.OSUSER OS_LOCKER
, S_LOCKER.USERNAME LOCKER_SCHEMA
, S_LOCKER.PROCESS LOCKER_PID
, S_WAITER.OSUSER OS_WAITER
, S_WAITER.USERNAME WAITER_SCHEMA
, S_WAITER.PROCESS WAITER_PID
, 'Table lock (TM): ' || U.NAME || '.' || O.NAME || ' - Mode held: '||
DECODE(L_LOCKER.LMODE,
0, 'None', /* same as Monitor */
1, 'Null', /* N */
2, 'Row-S (SS)', /* L */
3, 'Row-X (SX)', /* R */
4, 'Share', /* S */
5, 'S/Row-X (SSX)', /* C */
6, 'Exclusive', /* X */
'???: ' || to_char(L_LOCKER.LMODE)
) || ' / Mode requested: '||
DECODE(L_WAITER.REQUEST,
0, 'None', /* same as Monitor */
1, 'Null', /* N */
2, 'Row-S (SS)', /* L */
3, 'Row-X (SX)', /* R */
4, 'Share', /* S */
5, 'S/Row-X (SSX)', /* C */
6, 'Exclusive', /* X */
'???: '||to_char(RTRIM(L_WAITER.REQUEST))
)
SQL_TEXT_WAITER
FROM
SYS.VT$OBJ O
, SYS.USER$ U
, V$LOCK L_WAITER
, V$LOCK L_LOCKER
, V$SESSION S_WAITER
, V$SESSION S_LOCKER
WHERE S_WAITER.SID = L_WAITER.SID
AND L_WAITER.TYPE IN ('TM')
AND S_LOCKER.sid = L_LOCKER.sid
AND L_LOCKER.ID1 = L_WAITER.ID1
AND L_WAITER.REQUEST > 0
AND L_LOCKER.LMODE > 0
AND L_WAITER.ADDR != L_LOCKER.ADDR
AND L_WAITER.ID1 = O.OBJ#
AND U.USER# = O.OWNER#
;
INSERT INTO tools.deadlock_log_waiters (
id
, deadlog_date
, wait
, os_user
, process
, locker
, object_owner
, object_name
, program)
SELECT /*+ ordered */
v_id
, v_date
, DECODE(L.REQUEST,0,'NO','YES') WAIT
, S.OSUSER
, S.PROCESS
, S.USERNAME LOCKER
, U.NAME T_OWNER
, O.NAME OBJECT_NAME
, ' '||S.PROGRAM PROGRAM
FROM
V$LOCK L
, SYS.USER$ U
, SYS.VT$OBJ O
, V$SESSION S
WHERE U.USER# = O.OWNER#
AND S.SID = L.SID
AND L.ID1 = O.OBJ#
AND L.TYPE = 'TM'
AND U.NAME != 'SYS'
AND O.NAME != 'DEADLOCK_LOG_LOCKERS'
AND O.NAME != 'DEADLOCK_LOG_WAITERS'
UNION
SELECT /*+ ordered */
v_id
, v_date
, DECODE(L.REQUEST,0,'NO','YES') WAIT
, S.OSUSER
, S.PROCESS
, S.USERNAME LOCKER
, '-'
, 'Record(s)'
, ' '||S.PROGRAM PROGRAM
FROM
V$LOCK L
, V$SESSION S
WHERE S.SID = L.SID
AND L.TYPE = 'TX'
;
COMMIT;
EXCEPTION
WHEN OTHERS THEN
dbms_output.put_line(SQLERRM);
END;
/
/*------------------------------------------------------------------------------
Filename: 3_deadlock_log_prc.sql
Purpose : Procedure which fill deadlock monitoring tables with data
when deadlock occur
Date : 18.10.2005
Author : Damir Vadas
CR : 1500
Remarks : run as priviledged user
Should work on 9i-11g Oracle versions
Changes (DD.MM.YYYY):
27.11.2009. Damir Vadas
Rechanged logic for 11g databases (not too much tested-looks good)
----------------------------------------------------------------------------*/
PRAGMA AUTONOMOUS_TRANSACTION;
v_id INTEGER;
v_date DATE;
BEGIN
SELECT tools_seq.nextVal, sysdate
INTO v_id, v_date
FROM dual
;
INSERT INTO tools.deadlock_log_lockers (
id
, deadlog_date
, os_locker
, locker_schema
, locker_pid
, os_waiter
, waiter_schema
, waiter_pid
, sql_text_waiter
)
/* TX row locks */
WITH Q AS (
SELECT /*+ rule */
S_LOCKER.OSUSER OS_LOCKER
, S_LOCKER.USERNAME LOCKER_SCHEMA
, S_LOCKER.PROCESS LOCK_PID
, S_WAITER.OSUSER OS_WAITER
, S_WAITER.USERNAME WAITER_SCHEMA
, S_WAITER.PROCESS WAITER_PID
, (SELECT sql_fulltext from v$sql where sql_id = O.SQL_ID AND ROWNUM<=1)
SQL_TEXT
FROM
V$LOCK L_WAITER
, V$LOCK L_LOCKER
, V$SESSION S_WAITER
, V$SESSION S_LOCKER
, V$_LOCK L1_WAITER
, V$OPEN_CURSOR O
WHERE S_WAITER.SID = L_WAITER.SID
AND L_WAITER.TYPE IN ('TX')
AND S_LOCKER.sid = L_LOCKER.sid
AND L_LOCKER.ID1 = L_WAITER.ID1
AND L_WAITER.REQUEST > 0
AND L_LOCKER.LMODE > 0
AND L_WAITER.ADDR != L_LOCKER.ADDR
AND L1_WAITER.LADDR = L_WAITER.ADDR
AND L1_WAITER.KADDR = L_WAITER.KADDR
AND L1_WAITER.SADDR = O.SADDR
AND O.USER_NAME != 'SYS'
)
SELECT
v_id
, v_date
, OS_LOCKER
, LOCKER_SCHEMA
, LOCK_PID
, OS_WAITER
, WAITER_SCHEMA
, WAITER_PID
, CAST (DBMS_LOB.SUBSTR (SQL_TEXT, 4000) AS VARCHAR (4000))
FROM Q
WHERE
SUBSTR(UPPER(
CAST (DBMS_LOB.SUBSTR (SQL_TEXT, 4000) AS VARCHAR (4000))
)
,1,7)!='SELECT ' -- 11g
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'INSERT INTO SYS.AUD$')<=0 -- auditing
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'OBJ#')<=0 -- 11g
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'AUDIT$')<=0 -- 11
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'TABLE_1_FF')<=0 -- 11
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'DECLARE TYPE ATTRS_CUR IS REF CURSOR; M_CUR')<=0 -- 11
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'SDO_GEOR_DDL__TABLE$$')<=0 -- 11
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'BEGIN DBMS_OUTPUT.GET_LINES(:LINES, :NUMLINES); END;')<=0 -- 11
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'DEADLOCK_LOG_LOCKERS')<=0 -- log tables
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'DEADLOCK_LOG_WAITERS')<=0 -- log tables
AND INSTR(UPPER(RTRIM(Q.SQL_TEXT)), 'IS_SERVERERROR')<=0 -- log trigger which monitor deadlocks
UNION/* table-level locks (TM) and mixed TM/TX TX/TM */
SELECT /*+ rule */
v_id
, v_date
, S_LOCKER.OSUSER OS_LOCKER
, S_LOCKER.USERNAME LOCKER_SCHEMA
, S_LOCKER.PROCESS LOCKER_PID
, S_WAITER.OSUSER OS_WAITER
, S_WAITER.USERNAME WAITER_SCHEMA
, S_WAITER.PROCESS WAITER_PID
, 'Table lock (TM): ' || U.NAME || '.' || O.NAME || ' - Mode held: '||
DECODE(L_LOCKER.LMODE,
0, 'None', /* same as Monitor */
1, 'Null', /* N */
2, 'Row-S (SS)', /* L */
3, 'Row-X (SX)', /* R */
4, 'Share', /* S */
5, 'S/Row-X (SSX)', /* C */
6, 'Exclusive', /* X */
'???: ' || to_char(L_LOCKER.LMODE)
) || ' / Mode requested: '||
DECODE(L_WAITER.REQUEST,
0, 'None', /* same as Monitor */
1, 'Null', /* N */
2, 'Row-S (SS)', /* L */
3, 'Row-X (SX)', /* R */
4, 'Share', /* S */
5, 'S/Row-X (SSX)', /* C */
6, 'Exclusive', /* X */
'???: '||to_char(RTRIM(L_WAITER.REQUEST))
)
SQL_TEXT_WAITER
FROM
SYS.VT$OBJ O
, SYS.USER$ U
, V$LOCK L_WAITER
, V$LOCK L_LOCKER
, V$SESSION S_WAITER
, V$SESSION S_LOCKER
WHERE S_WAITER.SID = L_WAITER.SID
AND L_WAITER.TYPE IN ('TM')
AND S_LOCKER.sid = L_LOCKER.sid
AND L_LOCKER.ID1 = L_WAITER.ID1
AND L_WAITER.REQUEST > 0
AND L_LOCKER.LMODE > 0
AND L_WAITER.ADDR != L_LOCKER.ADDR
AND L_WAITER.ID1 = O.OBJ#
AND U.USER# = O.OWNER#
;
INSERT INTO tools.deadlock_log_waiters (
id
, deadlog_date
, wait
, os_user
, process
, locker
, object_owner
, object_name
, program)
SELECT /*+ ordered */
v_id
, v_date
, DECODE(L.REQUEST,0,'NO','YES') WAIT
, S.OSUSER
, S.PROCESS
, S.USERNAME LOCKER
, U.NAME T_OWNER
, O.NAME OBJECT_NAME
, ' '||S.PROGRAM PROGRAM
FROM
V$LOCK L
, SYS.USER$ U
, SYS.VT$OBJ O
, V$SESSION S
WHERE U.USER# = O.OWNER#
AND S.SID = L.SID
AND L.ID1 = O.OBJ#
AND L.TYPE = 'TM'
AND U.NAME != 'SYS'
AND O.NAME != 'DEADLOCK_LOG_LOCKERS'
AND O.NAME != 'DEADLOCK_LOG_WAITERS'
UNION
SELECT /*+ ordered */
v_id
, v_date
, DECODE(L.REQUEST,0,'NO','YES') WAIT
, S.OSUSER
, S.PROCESS
, S.USERNAME LOCKER
, '-'
, 'Record(s)'
, ' '||S.PROGRAM PROGRAM
FROM
V$LOCK L
, V$SESSION S
WHERE S.SID = L.SID
AND L.TYPE = 'TX'
;
COMMIT;
EXCEPTION
WHEN OTHERS THEN
dbms_output.put_line(SQLERRM);
END;
/
The whole 11g changed solution is packed in additional RAR file
What next
I'm perfectly aware that this approach is far from perfect, but for me and a frend of mine, who needed this code ASAP, this is acceptable working solution for a while. When I find some additional not necessary rows are shown in table, I'll just add new filter and it will be quickly fixed.When (and if!) I get time to re change that code I'll post it. In the meantime I'd like to get some enhancements from someone of you...if you have experience the same problems.
On 12th December I have added a small amount of code according vt$obj which was not clearly described. Thank you for that!
Cheers!