此分析报告基于用户所提供之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 掉相关进程。再和之前一样的步骤进行日志挖掘分析。可以得到相同的结果:
检查这些日志挖掘信息,都是在一个事务中的所有语句回滚,并且是在一个会话中完成的。
Leave a Reply