此分析报告基于用户所提供之logMiner 信息和alter.log作为分析依据。
1.2 简单描述
3月26日14:15分左右orcl数据库中业务正常流程事务操作INSERT和UPDATE，该事务DML操作涉及到多张表包括OBJ# 82378″。该事务在执行INSERT/UPDATE操作后一直未提交事务即COMMIT操作。该事务的唯一ID XID为” 0012001B0001FD1F”。
在3月26号的15:36分左右该XID为” 0012001B0001FD1F”的事务被异常回滚，可以在Logminer信息中找到如下信息：
2016/3/26 15:36 rollback;
回滚的undo语句：
| update “UNKNOWN”.”OBJ# 82378″ set “COL 3” = NULL, “COL 30” = NULL, “COL 31” = NULL, “COL 36” = HEXTORAW(‘393939393939’) where ROWID = ‘AAAUHKAAGAAJF6aAAQ’;
delete from “UNKNOWN”.”OBJ# 82378″ where ROWID = ‘AAAUHKAAGAAJF6aAAQ’; |
通过模拟事故测试发现：
- 当应用程序设计不当，主动发起不合理的回滚
- 当Oracle会话或进程被kill session或kill进程时也会被动回滚
上述2种情况下，其logminer挖掘出的日志情况与本例中的实际logmnr结果并无差别，事务均有一个rollback类型的redo opcode对应的rollback;语句所回滚，且对应的session信息也没有区别。
由于上述存在2种可能，且目前无法通过有限的logmnr数据找出其中的区别。故针对本次的异常回滚问题提供多方面的建议。
上述2种测试模拟情况详见 附录的场景1、2。
3.结果与建议
1、此例中发生问题的一个主要原因在于事务开始后一直没有有效提交，故最为重要的建议是检查代码中是否存在执行了DML事务后没有及时提交的问题，在PRO*C语言中执行SQL并及时COMMIT提交，语句如：
EXEC SQL COMMIT WORK RELEASE;
具体代码可以参考：http://docs.oracle.com/cd/B28359_01/appdev.111/b28427/pc_03dbc.htm#i1509
2、由于无法确认是否Oracle session/process异常退出，故建议考虑在应用程序中增加记录Oracle报错的日志，这样当Oracle session/process异常退出时，应用程序日志应当能捕捉到例如ORA-03113 “end-of-file on communication channel”的报错。
3、若数据库的负载不高则考虑打开10046 trace即SQL跟踪功能以便了解SQL执行的详细情况，或酌情考虑打开数据库审计audit功能。
附录：模拟测试过程
创建一张测试表test(id,text)。
测试事务使用语句：
| insert into test values(1,’a’);
update test set text=’test’ where id=1; |
场景1：
应用程序自身主动发起不合理的回滚操作，即执行rollback;语句。通过日志挖掘可以发下如下情况：
会出现一个rollback，然后所有在这个事务中的语句全部回滚，并且是在同一个会话中发生。
现象与客户提交的信息相符，下面是客户方提供的信息：
可以发下在3月26号的15:36分左右，确实出现了回滚操作。在数据库的alert.log中相关时间段无任何报错或告警详细。
在会话中使用rollback 回滚事务：
| insert into test values(1,’a’);
update test set text=’test’ where id=1; rollback; |
切换日志:
| alter system switch logfile; |
使用LogMiner分析产生的日志：
| –附加日志
exec DBMS_LOGMNR.ADD_LOGFILE(‘/u01/app/oracle/product/11.2.0/db_1/dbs/arch1_112_904574553.dbf’,dbms_logmnr.NEW); –启动分析 exec DBMS_LOGMNR.START_LOGMNR(OPTIONS =>SYS.DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG);
–查询结果 select * from v$logmnr_contents; |
结果如下：
场景2：使用alter kill session杀掉会话和在系统层面kill掉进程
在会话中运行测试语句：
| insert into test values(1,’a’);
update test set text=’test’ where id=1; insert into test values(1,’a’); insert into test values(1,’a’); insert into test values(1,’a’);
|
查询到相关会话的sid和相关系统层面的PID
| select * from v$session
select * from v$process |
然后使用alter system kill session ‘xxx,xxx’杀掉会话。或在系统层面直接kill -9 掉相关进程。再和之前一样的步骤进行日志挖掘分析。可以得到相同的结果：
检查这些日志挖掘信息，都是在一个事务中的所有语句回滚，并且是在一个会话中完成的。
Comment