Thinking Out Loud

July 23, 2016

Troubleshooting ORA-02049: timeout: distributed transaction waiting for lock

Filed under: oracle — mdinh @ 10:45 pm

Controlling Connections Established by Database Links

Tracing can be done using – ALTER SYSTEM SET EVENTS ‘2049 trace name ERRORSTACK level 3’;

Nice note from MOS.

How to Obtain a System State Trace BEFORE the Error ORA-2049 Occurs, While Still Experiencing the Contention (Doc ID 789517.1)

Commit after select from dblink – blocking lock.

Session 1:
++++++++++
04:44:51 ARROW:(DEMO@leo):PRIMARY>
04:45:30 ARROW:(DEMO@leo):PRIMARY> select name from v$pdbs@mdinh_april;

NAME
------------------------------
APRIL

Elapsed: 00:00:00.01
04:45:36 ARROW:(DEMO@leo):PRIMARY> commit;

Commit complete.

Elapsed: 00:00:00.00
04:45:41 ARROW:(DEMO@leo):PRIMARY>
04:45:49 ARROW:(DEMO@leo):PRIMARY> update t set id=-9999;

++++++++++
Session 2:
04:45:18 ARROW:(DEMO@leo):PRIMARY> update t set id=100;

1 row updated.

Elapsed: 00:00:00.00
04:45:21 ARROW:(DEMO@leo):PRIMARY> @/media/sf_working/sql/b.sql

STATE      USERNAME        SID_SERIAL   SQL_ID          SEQ# EVENT                STATUS    MIN MACHINE              OSUSER     PROGRAM
---------- --------------- ------------ ------------- ------ -------------------- -------- ---- -------------------- ---------- ---------------
BLOCKING   DEMO            32,17        74nhxnyztg454    402 SQL*Net message to c ACTIVE      0 arrow.localdomain    oracle     sqlplus@arrow.l
WAITING    *DEMO           41,271       1qfpvr7brd2pq    113 enq: TX - row lock c ACTIVE      8 arrow.localdomain    oracle     sqlplus@arrow.l

Elapsed: 00:00:00.01

STATE      USERNAME        SQL_ID        SQL_TEXT
---------- --------------- ------------- --------------------------------------------------------------------------------
BLOCKING   DEMO            7741d4und71ph with s as ( SELECT decode(level,1,'BLOCKING','WAITING') state, LPAD('*',(level-1
WAITING    *DEMO           1qfpvr7brd2pq update t set id=-9999

Elapsed: 00:00:00.00
04:54:19 ARROW:(DEMO@leo):PRIMARY> select count(*) from t;

  COUNT(*)
----------
         1

Elapsed: 00:00:00.01
05:00:49 ARROW:(DEMO@leo):PRIMARY>

No commit after select from dblink – ORA-02049: timeout: distributed transaction waiting for lock.

Session is automatically killed based on database paraneter tributed_lock_timeout (default is 60s)

Session 1:
++++++++++
21:58:06 ARROW:(DEMO@leo):PRIMARY> update t set id=100;

1 row updated.

Elapsed: 00:00:00.01
21:58:14 ARROW:(DEMO@leo):PRIMARY>

Session 2:
+++++++++
21:58:45 ARROW:(DEMO@leo):PRIMARY> select name from v$pdbs@mdinh_april;

NAME
------------------------------
APRIL

Elapsed: 00:00:00.00
21:58:51 ARROW:(DEMO@leo):PRIMARY> update t set id=1;
update t set id=1
       *
ERROR at line 1:
ORA-02049: timeout: distributed transaction waiting for lock


Elapsed: 00:01:00.01
21:59:59 ARROW:(DEMO@leo):PRIMARY>

Don’t forget to commit or rollback after using dblinks.

UPDATED: Tried to determine if there was a way to monitor distributed transaction and in this test case was not able to.

Session 1: 
++++++++++
15:59:32 ARROW:(MDINH@leo):PRIMARY> update demo.t set id=100;

1 row updated.

Elapsed: 00:00:00.01
15:59:43 ARROW:(MDINH@leo):PRIMARY>

Session 2: Distributed Transaction
++++++++++
16:00:43 ARROW:(DEMO@leo):PRIMARY> select name from v$pdbs@mdinh_april;

NAME
------------------------------
APRIL

Elapsed: 00:00:00.00
16:00:47 ARROW:(DEMO@leo):PRIMARY> update t set id=-9999;
update t set id=-9999
       *
ERROR at line 1:
ORA-02049: timeout: distributed transaction waiting for lock


Elapsed: 00:10:00.00
16:10:57 ARROW:(DEMO@leo):PRIMARY> update t set id=-9999;
update t set id=-9999
*
ERROR at line 1:
ORA-02049: timeout: distributed transaction waiting for lock


Elapsed: 00:10:00.01
16:23:03 ARROW:(DEMO@leo):PRIMARY>

Session 3: Monitoring
++++++++++
16:21:23 ARROW:(SYS@leo):PRIMARY> show parameter distributed_lock_timeout

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
distributed_lock_timeout             integer     600
16:21:35 ARROW:(SYS@leo):PRIMARY> @b.sql

STATE      USERNAME        SID_SERIAL   SQL_ID          SEQ# EVENT                STATUS    MIN MACHINE              OSUSER     PROGRAM
---------- --------------- ------------ ------------- ------ -------------------- -------- ---- -------------------- ---------- ---------------
BLOCKING   MDINH           26,3                           32 SQL*Net message from INACTIVE   22 arrow.localdomain    oracle     sqlplus@arrow.l
WAITING    *DEMO           16,23        1qfpvr7brd2pq     70 enq: TX - row lock c ACTIVE      9 arrow.localdomain    oracle     sqlplus@arrow.l

Elapsed: 00:00:00.01

STATE      USERNAME        SQL_ID        SQL_TEXT
---------- --------------- ------------- --------------------------------------------------------------------------------
BLOCKING   MDINH           4cnt32uym27j2 update demo.t set id=100
WAITING    *DEMO           1qfpvr7brd2pq update t set id=-9999

Elapsed: 00:00:00.00
16:21:38 ARROW:(SYS@leo):PRIMARY> @b.sql

STATE      USERNAME        SID_SERIAL   SQL_ID          SEQ# EVENT                STATUS    MIN MACHINE              OSUSER     PROGRAM
---------- --------------- ------------ ------------- ------ -------------------- -------- ---- -------------------- ---------- ---------------
BLOCKING   MDINH           26,3                           32 SQL*Net message from INACTIVE   22 arrow.localdomain    oracle     sqlplus@arrow.l
WAITING    *DEMO           16,23        1qfpvr7brd2pq     70 enq: TX - row lock c ACTIVE      9 arrow.localdomain    oracle     sqlplus@arrow.l

Elapsed: 00:00:00.01

STATE      USERNAME        SQL_ID        SQL_TEXT
---------- --------------- ------------- --------------------------------------------------------------------------------
BLOCKING   MDINH           4cnt32uym27j2 update demo.t set id=100
WAITING    *DEMO           1qfpvr7brd2pq update t set id=-9999

Elapsed: 00:00:00.00
16:22:10 ARROW:(SYS@leo):PRIMARY> @b.sql

STATE      USERNAME        SID_SERIAL   SQL_ID          SEQ# EVENT                STATUS    MIN MACHINE              OSUSER     PROGRAM
---------- --------------- ------------ ------------- ------ -------------------- -------- ---- -------------------- ---------- ---------------
BLOCKING   MDINH           26,3                           32 SQL*Net message from INACTIVE   23 arrow.localdomain    oracle     sqlplus@arrow.l
WAITING    *DEMO           16,23        1qfpvr7brd2pq     70 enq: TX - row lock c ACTIVE     10 arrow.localdomain    oracle     sqlplus@arrow.l

Elapsed: 00:00:00.01

STATE      USERNAME        SQL_ID        SQL_TEXT
---------- --------------- ------------- --------------------------------------------------------------------------------
BLOCKING   MDINH           4cnt32uym27j2 update demo.t set id=100
WAITING    *DEMO           1qfpvr7brd2pq update t set id=-9999

Elapsed: 00:00:00.00
16:22:56 ARROW:(SYS@leo):PRIMARY> @b.sql

no rows selected

Elapsed: 00:00:00.01

no rows selected

Elapsed: 00:00:00.00
16:23:12 ARROW:(SYS@leo):PRIMARY>
Advertisements

Leave a Comment »

No comments yet.

RSS feed for comments on this post. TrackBack URI

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

Blog at WordPress.com.

%d bloggers like this: