ITPub博客

首页 > IT基础架构 > 网络安全 > Analysing locking issues with LOGMINER

Analysing locking issues with LOGMINER

原创 网络安全 作者:jinava 时间:2005-02-14 17:17:06 0 删除 编辑

Deadlock example
----------------

One process does the following:
SQL> update dept set dname = 'dqkl' where deptno = 10;
1 row updated.
SQL> delete emp where empno = 7934;
1 row deleted.

Another process does the following and falls on a deadlock situation
SQL> update emp set sal = sal * 1.1 where empno = 7934;
1 row updated.
SQL> delete dept where deptno = 10;
delete dept where deptno = 10
*
ERROR at line 1:
ORA-00060: deadlock detected while waiting for resource
Information found in the user_dump_dest or background_dump_dest
---------------------------------------------------------------

When a deadlock like the previous example is encountered, the user_dump_dest will give following output on a non OPS/RAC database:
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

DEADLOCK DETECTED

Current SQL statement for this session:
delete dept where deptno = 10

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:
Deadlock graph:
                          ---------Blocker(s)-------- ---------Waiter(s)---------
Resource Name process session holds waits process session holds waits
TM-00009edb-00000000 15 12 SSX 14 13 SX
TX-00060058-0000012a 14 13 X 15 12 X
session 12: DID 0001-000F-00000002 session 13: DID 0001-000E-00000002
session 13: DID 0001-000E-00000002 session 12: DID 0001-000F-00000002
Rows waited on:
Session 13: no row
Session 12: obj - rowid = 00009ED9 - AAAJ7ZAABAAAIb0AAA
===================================================

PROCESS STATE
-------------
Process global information:
process: 264f484, call: 26c7788, xact: 29cec70, curses: 26735dc, usrses: 26735dc
----------------------------------------
SO: 264f484, type: 1, owner: 0, pt: 0, flag: INIT/-/-/0x00
(process) Oracle pid=15, calls cur/top: 26c7788/26c7788, flag: (0) -
int error: 0, call error: 0, sess error: 0, txn error 0
(post info) last post received: 85 0 4
last post received-location: kslpsr
last process to post me: 264d1cc 1 2
----------------------------------------
SO: 26735dc, type: 3, owner: 264f484, pt: 0, flag: INIT/-/-/0x00
(session) trans: 29cec70, creator: 264f484, flag: (41) USR/- BSY/-/-/-/-/-
DID: 0001-000F-00000002, short-term DID: 0000-0000-00000000
txn branch: 0
oct: 7, prv: 0, user: 48/SCOTT
application name: SQL*Plus, hash value=3669949024
last wait for 'enqueue' blocking sess=0x2673e48 seq=80 wait_time=-2
name|mode=54580006, id1=60058, id2=12a
----------------------------------------
SO: 29cec70, type: 25, owner: 26735dc, pt: 0, flag: INIT/-/-/0x00
(trans) bsn = 5, flg = 0x1e03, flg2 = 0x00, prx = 0x0, ros = 2147483647, spn = 16
efd = 5
parent xid: 0x0000.000.00000000
env: (scn: 0x0000.000b3620 xid: 0x0005.05a.00000131 uba: 0x0080019c.00bd.46)
cev: (spc = 922 usi = 5 ubk tsn: 1 rdba: 0x0080019c useg tsn: 1 rdba: 0x00800802
hwm uba: 0x0080019c.00bd.46 col uba: 0x00000000.0000.00
num bl: 1 bk list: 0x29bb3cc)
(enqueue) TX-0005005A-00000131 DID: 0001-000F-00000002
lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
res: 2729e2c, mode: X, prv: 2729e34, sess: 26735dc, proc: 264f484
xga: 0x0, heap: UGA
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

Following information will be dumped in the background_dump_dest in a file like lmd0_'pid'_'sid'.trc if each session of the deadlock sample is run on a separate instance of an OPS or RAC database.
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

*** 2002-06-08 08:57:40.447
*** SESSION ID:(3.1) 2002-06-08 08:57:40.259
Global Wait-For-Graph(WFG) at ddTS[0.1] :
BLOCKED 0xc000000002461b20 5 [0xa0017][0xe9],[TX] [65554,2] 0
BLOCKER 0xc00000000248cef0 5 [0xa0017][0xe9],[TX] [131082,2] 1
BLOCKED 0xc0000000023fe2c0 5 [0x80057][0xe8],[TX] [131082,2] 1
BLOCKER 0xc000000002462c60 5 [0x80057][0xe8],[TX] [65554,2] 0
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

Analyze of the dumps
--------------------

1. In an OPS, we only have the transaction_id of the deadlock, i.e.
TX-000A0017-000000E9 on instance 1 and TX-00080057-000000E8 on instance 0.
The logminer is the only tool available to get more information about
those transactions. Be aware there are different threads in an OPS system and thus different logfile/archive files to analyse.
2. The dump on a single instance gives more details: the statement that triggered the deadlock, a deadlock graph and the process dump of the deadlocked session. In this case, the statement is:
delete dept where deptno = 10
a. The row that could not be deleted can be found via the rowid:
SQL> select * from scott.dept where rowid = 'AAAJ7ZAABAAAIb0AAA';
DEPTNO DNAME LOC
---------- -------------- -------------
10 dqkl NEW YORK
b. The transaction that blocks this session was the TX-00060058-0000012a.
It can be also found in the id1 and id2 for the enqueue wait:
last wait for 'enqueue' blocking sess=0x2673e48 seq=80 wait_time=-2
name|mode=54580006, id1=60058, id2=12a
The logminer can be used to get more details about this transaction.
c. The deadlocked session itself is holding a lock TM-00009edb-00000000
that correspond to table emp. It can be controlled via following query:
SQL> select object_id, owner, object_name, object_type from dba_objects where object_id = to_number('00009EDB','XXXXXXXX');
OBJECT_ID OWNER OBJECT_NAME OBJECT_TYPE
---------- ----- ----------- -----------
40667 SCOTT EMP TABLE
d. The deadlocked session was using the transaction_id TX-0005005A-00000131
...
(enqueue) TX-0005005A-00000131 DID: 0001-000F-00000002
...
The logminer can be used to know why the deadlocked session was holding a lock on this table.
Information found via the logminer
----------------------------------
More information about how to setup the logminer can be found in .
The logfile (or archive file) to analyse can be found via v$log_history and the time of the error (query the first_time of v$log_history).
The transaction_id found in TX-0005005A-00000131, TX-00060058-0000012A,
TX-000A0017-000000E9 or TX-00080057-000000E8 is important to find all the DML performed by those transactions even if some of them have been rollbacked. The only DML that will not be found, is the one that has give the ORA-00060 error.
Once the logminer as been set up, e.g.
SQL> execute dbms_logmnr.add_logfile( '/oracle/oradata/ora81/redo01.log', dbms_logmnr.NEW);
SQL> execute dbms_logmnr.start_logmnr;
you can query the v$logmnr_contents view to find the DML of the transaction_id.
SQL> select session#, sql_redo from v$logmnr_contents where xidusn = to_number(substr('00060058', 1, 4), 'XXXX') and xidslt = to_number(substr('00060058', 5, 8), 'XXXX') and xidsqn = to_number('0000012A', 'XXXXXXXX');
SESSION# SQL_REDO
-------- ----------------------------------------------------------------------
13 set transaction read write;
13 update "UNKNOWN"."Objn:40665" set "Col[2]" = HEXTORAW('64716b6c') where ROWID = 'AAAJ7ZAABAAAIb0AAA';
13 delete from "UNKNOWN"."Objn:40667" where "Col[1]" = HEXTORAW('c25023')
and "Col[2]" = HEXTORAW('4d494c4c4552') and "Col[3]" = HEXTORAW('434c
45524b') and "Col[4]" = HEXTORAW('c24e53') and "Col[5]" = HEXTORAW('77
b60117010101') and "Col[6]" = HEXTORAW('c20f1f') and "Col[7]" IS NULL
and "Col[8]" = HEXTORAW('c10b') and ROWID = 'AAAJ7bAABAAAIQsAAN';
13 commit;
SQL> select session#, sql_redo from v$logmnr_contents where xidusn = to_number(substr('0005005A', 1, 4), 'XXXX') and xidslt = to_number(substr('0005005A', 5, 8), 'XXXX') and xidsqn = to_number('00000131', 'XXXXXXXX');
SESSION# SQL_REDO
-------- ----------------------------------------------------------------------
12 set transaction read write;
12 update "UNKNOWN"."Objn:40667" set "Col[6]" = HEXTORAW('c20f1f') whereROWID = 'AAAJ7bAABAAAIQsAAN';
12 commit;
The v$logmnr_contents gives also other interesting values like:
- timestamp
- username
- data_objd#
- row_id

The 'select for update' are not shown directly (undefined statement), but one row is added containing the data_objd# for each selected row.

RELATED DOCUMENTS
-----------------
How to setup LogMiner
FAQ about Detecting and Resolving Locking Conflicts

[@more@]

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/205087/viewspace-789926/,如需转载,请注明出处,否则将追究法律责任。

上一篇: Temporary Tablespace
下一篇: SQL Tuning
请登录后发表评论 登录
全部评论
  • 博文量
    32
  • 访问量
    40165