转载自love wife & love life —Roger 的Oracle技术博客
本文链接地址: ORA-01591: lock held by in-doubt distributed transaction
昨天某客户遇到一个问题是关于两阶段分布式事务的，大概是内容是 一个定时job执行失败，然后报如下错误：
Sun Oct 9 02:38:12 2011 Errors in file /ora/app/admin/oraapp/bdump/oraapp1_j000_643178.trc: ORA-12012: error on auto execute of job 84 ORA-01591: lock held by in-doubt distributed transaction 19.3.5343485 ORA-06512: at "SODB_ADMIN.PKG_SODB_MAINTAIN", line 1064 ORA-06512: at line 1 Sun Oct 9 02:59:45 2011 Thread 1 advanced to log sequence 63561 |
这里我们首先需要关注是 ORA-01591 错误，
Error: ORA 1591
Text: lock held by in-doubt distributed transaction <num >
-------------------------------------------------------------------------------
Cause: An attempt was made to access a resource locked by a dead two-phase
commit transaction that is in prepared state.
Action: Match the transaction number in the message with the GLOBAL_TRAN_ID
column of the DBA_2PC_PENDING table to determine the database link and
the state of the transaction.
Attempt to repair network connections to the coordinator and commit
point, if necessary.
If timely repair is not possible, contact the database administrator
at the commit point, if known, to resolve the pending transaction.
|
如上是mos关于该错误的一个描述，当然，引起该错误的原因可能有很多很多。 关于分布式事务，其实可以这样理解，就是一个完整的事务，其中包含的多个操作分布在 两个以上的数据库中，只有这些操作都全部完成了，该事务才算完成，不然该事务都将失败。 换句话说，如果该事务失败了，其中涉及到操作表A，那么当其他session访问到表A时将出现 ORA-01591错误。 至于具体说为什么分布式事务会失败，那么就要具体分析了，可能是程序本身的问题或者网络 问题等等。 我们回到我客户的问题上来，既然是分布事务，那么我们就查询dba_2pc_pending视图： 查询结果如下；
LOCAL_TRAN_ID STATE FAIL_TIME OS_USER DB_USER ---------------------- ---------------- ------------ ---------- ---------- 56.29.120915 prepared 09-SEP-11 t3smisbw 19.3.5343485 prepared 01-OCT-11 t3smisbw 12.15.3794557 prepared 03-OCT-11 t3smisbw |
从上可以看到，目前该库有3个失败的分布事务，其中 19.3.5343485 是我们需要处理的。 关于字段LOCAL_TRAN_ID的解释，大家可以去查看dba_2pc_pending的说明，这里只简单的 描述一下； LOCAL_TRAN_ID 格式为：xidusn + xidslot + xidsqn 下面继续查询当前系统回滚段中是否还有如上几个失败的分布式事务信息：
SQL> SELECT KTUXEUSN, 2 KTUXESLT, 3 KTUXESQN, /* Transaction ID */ 4 KTUXESTA STATUS, 5 KTUXECFL Flags 6 FROM x$ktuxe 7 WHERE ktuxesta != 'INACTIVE' 8 AND ktuxeusn IN(56,19,12) ORDER BY 1; KTUXEUSN KTUXESLT KTUXESQN STATUS FLAGS ---------- ---------- ---------- ---------------- ------------------------ 12 15 3794557 PREPARED SCO|COL|REV|EXTDTX 19 3 5343485 PREPARED SCO|COL|REV|DEAD|EXTDTX 56 29 120915 PREPARED SCO|COL|REV|EXTDTX |
我们可以发现，仍然存在，这处理就简单了，处理之前我还需要说明一下的是：
根据分布事务的状态（state）不同，我们需要采取不同的方法进行处理，稍后进行一个
简单的总结，这里我继续描述如何处理该问题。
通过如下两个小步骤进行处理：
rollback force '19.3.5343485';
execute dbms_transaction.purge_lost_db_entry('19.3.5343485');
然后再次执行该job，正常。
当然这仅仅是一个处理的办法，我们最终的目的是想知道为什么该分布事务会执行失败呢？
先来查询该job的基本信息：
SQL> SELECT job,SCHEMA_USER,LAST_DATE,NEXT_DATE,BROKEN,FAILURES,INSTANCE 2 FROM dba_jobs; JOB SCHEMA_USER LAST_DATE NEXT_DATE B FAILURES INSTANCE --- ------------ ------------ ------------ - ---------- ---------- ............ 83 SODB_ADMIN 10-OCT-11 11-OCT-11 N 0 0 84 SODB_ADMIN 07-OCT-11 11-OCT-11 N 12 0 85 SODB_ADMIN 10-OCT-11 11-OCT-11 N 0 0 ............ 13 ROWS selected. JOB SCHEMA_USER LAST_DATE NEXT_DATE B FAILURES INTERVAL INSTANCE --- ----------- --------- ---------- - -------- ------------------------------------------- -------- .......... 84 SODB_ADMIN 07-OCT-11 11-OCT-11 N 12 trunc(sysdate)+1+2/24+25/24/60 0 85 SODB_ADMIN 10-OCT-11 11-OCT-11 N 0 trunc(sysdate)+1+2/24+50/24/60 0 .......... 13 ROWS selected. |
该job (job number为84) 已经执行失败12次了，INTERVAL是该job的执行间隔。对于dba_jobs中的 FAILURES字段， 该字段最大值为16，每次执行失败后该值递增，但是一旦执行成功后将被清0. 从报错信息来看，该job执行失败问题出在PKG_SODB_MAINTAIN的1064行，通过dbms_metadata获取定义后，发现 如下信息： 该过程执行到如下步骤时失败：
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 |
PROCEDURE refine_msg (p_date IN DATE)
IS
v_id NUMBER;
BEGIN
proc_expired_msg_log (p_date - pkg_sodb.get_expired_msg_days);
proc_expired_msg_tbm (p_date - pkg_sodb.get_expired_tbm_days);
EXCEPTION
WHEN OTHERS
THEN
ROLLBACK;
pkg_sodb.add_event_log ('SODB',
'PKG_SODB_MAINTAIN',
'Refine_Msg',
'DB_ERROR',
3,
SYSDATE,
'êy?Y?a2ù×÷òì3￡',
NULL,
v_id
);
COMMIT;
RAISE;
END refine_msg;
|
其中: Proc_Expired_Msg_Log 和 Proc_Expired_Msg_Tbm 为存储过程；
Get_Expired_Msg_Days 和 Get_Expired_Tbm_Days 为过程PKG_SODB中的2个函数；
这样来看似乎问题就出在这里，我怀疑可能是业务逻辑什么的可能有问题，比如
该 Proc_Expired_Msg_Log(p_date - PKG_SODB.Get_Expired_Msg_Days) 有可能计算出来
是负数吗？或者说执行到该步时，后面的rolllback操作时，其他前面的事务是否还存在关联？
不是开发出身，分析起来有些麻烦，主要是这几个包里面包含了太多的存储过程和函数，
看起来就头晕，最好建议客户找开发商看看这几个包。
补充：关于分布式事务处理的简单总结
++++++ 常规处理步骤 ++++++
1. Identify the id OF the TRANSACTION:
COLUMN global_tran_id format a25
COLUMN DATABASE format a22
COLUMN global_name format a22
SELECT * FROM global_name;
SELECT LOCAL_TRAN_ID, GLOBAL_TRAN_ID,to_char(FAIL_TIME,'dd-mon-yyyy HH24:MI:SS'),STATE, MIXED FROM DBA_2PC_PENDING;
SELECT LOCAL_TRAN_ID, IN_OUT,INTERFACE, DATABASE FROM DBA_2PC_NEIGHBORS;
2. Purge the TRANSACTION:
EXECUTE DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('<transaction_id>');
COMMIT;
3. Confirm that the TRANSACTION has been purged:
SELECT LOCAL_TRAN_ID, GLOBAL_TRAN_ID,to_char(FAIL_TIME,'dd-mon-yyyy HH24:MI:SS'),STATE, MIXED FROM DBA_2PC_PENDING;
SELECT LOCAL_TRAN_ID, IN_OUT,INTERFACE, DATABASE FROM DBA_2PC_NEIGHBORS;
其中有如下五种state：
collecting
-- execute DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('1.10.255'）；
prepared
-- rollback force tran_id/commit force tran_id;
EXECUTE DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('1.10.255');
committed
-- execute DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('1.10.255');
forced commit
-- execute DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('1.10.255');
forced ROLLBACK
-- execute DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('1.10.255');
++++++ 如果遇到ORA-30019错误，可以采取如下方式：++++++
ALTER SESSION SET "_smu_debug_mode" = 4;
EXECUTE DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('1.10.255');
====== 情况1 在dba_2pc_pending表中还有事务记录，但是实际已经不存在该事务了
SELECT LOCAL_TRAN_ID,
GLOBAL_TRAN_ID,
to_char(FAIL_TIME, 'dd-mon-yyyy HH24:MI:SS'),
STATE,
MIXED
FROM DBA_2PC_PENDING;
LOCAL_TRAN_ID 1.92.66874 prepared
1 为回滚段号
SELECT KTUXEUSN,
KTUXESLT,
KTUXESQN, /* Transaction ID */
KTUXESTA STATUS,
KTUXECFL Flags
FROM x$ktuxe
WHERE ktuxesta != 'INACTIVE'
AND ktuxeusn = 1
返回为0
如果当状态为prepared，且事务表中也不存在相关信息，那么我们只能手工进行清理：
++++++ 使用如下方式进行手工处理：++++++
SET TRANSACTION USE ROLLBACK segment SYSTEM;
DELETE FROM sys.pending_trans$ WHERE local_tran_id = '1.92.66874';
DELETE FROM sys.pending_sessions$ WHERE local_tran_id = '1.92.66874';
DELETE FROM sys.pending_sub_sessions$ WHERE local_tran_id = '1.92.66874';
commit;
====== 情况2 在dba_2pc_pending表中无法查到分布式事务信息，但是实际上却是存在该分布式事务的
SELECT LOCAL_TRAN_ID,
GLOBAL_TRAN_ID,
to_char(FAIL_TIME, 'dd-mon-yyyy HH24:MI:SS'),
STATE,
MIXED
FROM DBA_2PC_PENDING;
查询无记录
SELECT local_tran_id, state
FROM dba_2pc_pending
WHERE local_tran_id = ' 1.92.66874 '; -- 为空
SELECT KTUXEUSN,
KTUXESLT,
KTUXESQN, /* Transaction ID */
KTUXESTA STATUS,
KTUXECFL Flags
FROM x$ktuxe
WHERE ktuxesta != 'INACTIVE'
AND ktuxeusn = 1;
查询有记录
====== 此种情况下，我们无法手工进行ROLLBACK或commit ======
++++++ 我们用如下的方式手工清理：++++++
ALTER system disable distributed recovery ;
INSERT INTO pending_trans $
(LOCAL_TRAN_ID,
GLOBAL_TRAN_FMT,
GLOBAL_ORACLE_ID,
STATE,
STATUS,
SESSION_VECTOR,
RECO_VECTOR,
TYPE #,
FAIL_TIME,
RECO_TIME)
VALUES
(' 1.92.66874 ',
306206,
' XXXXXXX.12345.1.2.3 ',
' prepared ',
' P ',
hextoraw(' 00000001 '),
hextoraw(' 00000000 '),
0,
sysdate,
sysdate);
INSERT INTO pending_sessions $
VALUES
(' 1.92.66874 ',
1,
hextoraw(' 05004F003A1500000104 '),
' C ',
0,
30258592,
'',
146);
commit ;
commit force ' 1.92.66874 ' ;
++++++ 此时如果commit force还是出现报错，需要继续执行：++++++
1. DELETE FROM pending_trans $ WHERE local_tran_id = '1.92.66874' ;
2. DELETE FROM pending_sessions $ WHERE local_tran_id = '1.92.66874' ;
3. commit ;
4. ALTER system enable distributed recovery ;
5. ALTER SESSION SET " _smu_debug_mode " = 4 ;
6. EXEC dbms_transaction.purge_lost_db_entry ( '1.92.66874' )
====== 另外我们还可以通过如下SQL来捕获到导致分布式事务失败的SQL：======
++++++ 获取local_tran_id ++++++
SELECT a.sql_text, s.osuser, s.username
FROM v$transaction t, v$session s, v$sqlarea a
WHERE s.taddr = t.addr
AND a.address = s.prev_sql_addr
AND t.xidusn = 1
AND t.xidslot = 25
AND t.xidsqn = 589367;
如果 v$session 和 v$sqlarea 已经无法查到，那么我们还可以关联一些 dba_hist_* 试图进行查询。
|