Home > Troubleshooting > Detecting Deadlock Source Part 2

Detecting Deadlock Source Part 2

This is very simple  deadlock case.Instad of event 10046 ( that I have used in previous blog ) to identify initial TX locks this time
I  have used flashback version query and flashback transaction query .

So here is demo:

First craete table and populate some rows:

create table t(a int primary key);

insert into t select rownum from dba_tables where rownum <5;
commit;

SQL> @ct

Table created.
4 rows created.
Commit complete.

SQL> select * from t;

A
———-
1
2
3
4

Now cause deadlock by running these updates in 2 different session is following order:

Session 1:

update t set a=5 where a=1;
update t set a=6 where a=2;

Session 2:

update t set a=7 where a=3;
update t set a=8 where a=4;

Session 1:

update t set a=9 where a=3;

Session 2:

update t set a=10 where a=1;

Last update will cause deadlock and my session 1 will die:

update t set a=9 where a=3
*
ERROR at line 1:
ORA-00060: deadlock detected while waiting for resource

Now when I select from t and see what it looks like:

SQL> select * from t;

A
———-
5
6
7
8

Diagnostic part:

I will first run flashback version query to get transaction ID ( XID ) for my transactions:

SQL> ALTER SESSION SET nls_timestamp_format = ‘DD-MON-YYYY HH24:MI:SS.FF3′;

SQL> l
1  SELECT     VERSIONS_XID
2      ,      VERSIONS_STARTTIME
3      ,      VERSIONS_ENDTIME
4      ,      VERSIONS_STARTSCN
5      ,      VERSIONS_ENDSCN
6      ,      VERSIONS_OPERATION
7      ,      a
8      FROM   miladin.t VERSIONS BETWEEN TIMESTAMP MINVALUE AND MAXVALUE
9     ORDER  BY
10*            VERSIONS_STARTTIME
SQL> /

VERSIONS_XID     VERSIONS_STARTTIME             VERSIONS_ENDTIME               VERSIONS_STARTSCN VERSIONS_ENDSCN V          A
—————- —————————— —————————— —————– ————— – ———-
0A0015008B3D0000 23-APR-2009 14:08:54.000                                               30260800                 U          5
0A0015008B3D0000 23-APR-2009 14:08:54.000                                               30260800                 U          6
05000A00162C0000 23-APR-2009 14:09:00.000                                               30260807                 U          7
05000A00162C0000 23-APR-2009 14:09:00.000                                               30260807                 U          8
23-APR-2009 14:09:00.000                                30260807            3
23-APR-2009 14:09:00.000                                30260807            4
23-APR-2009 14:08:54.000                                30260800            1
23-APR-2009 14:08:54.000                                30260800            2

8 rows selected.

I got 2 diffrent versions XID’s (for each transaction) as expected.Remember this is simple case.In real world example you will get more rows but try to narrow your search.Check deadlock time from LMD trace and other trace files.

Last column display column values.Note new values and U ( update operation ) next to it and also previous values.

Now let’s run flashback transaction query for these XID’s. Most valuable information to get from flashback transaction query is sql_undo

SQL> SELECT
undo_sql
FROM flashback_transaction_query
WHERE xid = HEXTORAW(’0A0015008B3D0000′)
/

UNDO_SQL
————————————————————————–
update “MILADIN”.”T” set “A” = ’2′ where ROWID = ‘AAAXfoAAEAAAAG2AAB’;
update “MILADIN”.”T” set “A” = ’1′ where ROWID = ‘AAAXfoAAEAAAAG2AAA’;

and for second transaction:

SQL> SELECT
undo_sql
FROM flashback_transaction_query
WHERE xid = HEXTORAW(’05000A00162C0000′)
/

UNDO_SQL
—————————————————————————
update “MILADIN”.”T” set “A” = ’4′ where ROWID = ‘AAAXfoAAEAAAAG2AAD’;
update “MILADIN”.”T” set “A” = ’3′ where ROWID = ‘AAAXfoAAEAAAAG2AAC’;

From LMD trace file which will be under trace dump destination I will get  queries involved with deadlocks.

Current SQL Statement:
update t set a=10 where a=1

user session for deadlock lock 0x10fa988d0
sid: 128 ser: 102 audsid: 508526 user: 128/MILADIN flags: 0×100045
pid: 47 O/S info: user: oracle, term: UNKNOWN, ospid: 21135
image: oracle (TNS V1-V3)
client details:
O/S info: user: oracle, term: pts/1, ospid: 21028
machine: stpqldb01 program: sqlplus@ (TNS V1-V3)
application name: SQL*Plus, hash value=3669949024
Current SQL Statement:
update t set a=9 where a=3

Let’s look for first value involved with deadlock ( update t set a=10 where a=1 ).

SQL> SELECT
undo_sql
FROM flashback_transaction_query
WHERE xid = HEXTORAW(’0A0015008B3D0000′)
AND start_timestamp >= TO_TIMESTAMP (’2009-04-22 11:00:00′,’YYYY-MM-DD HH:MI:SS’) –  time  close to  deadlock time
/

UNDO_SQL
——————————————————————————–
update “MILADIN”.”T” set “A” = ’2′ where ROWID = ‘AAAXfoAAEAAAAG2AAB’;
update “MILADIN”.”T” set “A” = ’1′ where ROWID = ‘AAAXfoAAEAAAAG2AAA’;

I interested in update statement where  a=1 or

update “MILADIN”.”T” set “A” = ’1′ where ROWID = ‘AAAXfoAAEAAAAG2AAA’;

and

SQL> select a from t where rowid= ‘AAAXfoAAEAAAAG2AAA’;

A
———-
5

For second update  involved with deadlock ( update t set a=9 where a=3)  I will look for transaction where a=3 :

SQL>
SELECT
undo_sql
FROM flashback_transaction_query
WHERE xid = HEXTORAW(’05000A00162C0000′)
AND start_timestamp >= TO_TIMESTAMP (’2009-04-22 11:00:00′,’YYYY-MM-DD HH:MI:SS’) –  time close to  deadlock time
/

UNDO_SQL
——————————————————————————–
update “MILADIN”.”T” set “A” = ’4′ where ROWID = ‘AAAXfoAAEAAAAG2AAD’;
update “MILADIN”.”T” set “A” = ’3′ where ROWID = ‘AAAXfoAAEAAAAG2AAC’;

( you can narrow search of you query if this query returns too much rows )

or:

update “MILADIN”.”T” set “A” = ’3′ where ROWID = ‘AAAXfoAAEAAAAG2AAC’;

and from a table iteself:

SQL> select a from t where rowid= ‘AAAXfoAAEAAAAG2AAC’;

A
———-
7

UNDO statements are :

update “MILADIN”.”T” set “A” = ’1′ where ROWID = ‘AAAXfoAAEAAAAG2AAA’; ( a=5)
update “MILADIN”.”T” set “A” = ’3′ where ROWID = ‘AAAXfoAAEAAAAG2AAC’; ( a=7)

or initial statements with TX locks ( oposite from undo_sql )

update t set a=5 where a=1;
update t set a=7 where a=3;

Keep in mind tha Flashback transaction queries might take long time to finish.So narrow your search as much as possible.
Here are some other queries that you might need to narrow qury results in case that you have real case.

SELECT * FROM miladin.test
AS OF TIMESTAMP (SYSTIMESTAMP – INTERVAL ’1′ MINUTE)   -  one minute

SELECT versions_xid XID, versions_startscn START_SCN,
versions_endscn END_SCN, versions_operation OPERATION,      — limit to certain column value
a FROM mmodrakovic.test
VERSIONS BETWEEN SCN MINVALUE AND MAXVALUE
where a= 3;

SELECT xid, start_scn, commit_scn, operation, table_name, table_owner    – narrow to specific table and timestamp
FROM flashback_transaction_query
WHERE table_name=’T’
AND   table_owner=’MILADIN’
AND start_timestamp >=
TO_TIMESTAMP (’2009-04-22 11:00:00′,’YYYY-MM-DD HH:MI:SS’);

About these ads
Categories: Troubleshooting
  1. May 1, 2009 at 11:39 am | #1

    Thanks for the very useful post Miladin.

    I thought I should show the results of this approach with my own locking example.

    http://oracledoug.com/serendipity/index.php?/archives/1495-Diagnosing-Locking-Problems-using-ASHLogMiner-The-End.html

    It wasn’t too successful in that case but I wasn’t really expecting it to be and your approach is perfect for the type of problem it is aimed at.

    Cheers,

    Doug

  2. May 9, 2009 at 4:08 am | #2

    Doug,

    Thanks for comment.Deadlocks are not that easy to fix and these are just two different approaches.

    Miladin

  1. August 15, 2009 at 12:57 pm | #1

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Follow

Get every new post delivered to your Inbox.

Join 41 other followers

%d bloggers like this: