故障描述
某次,一套已经运行数年的Oracle 11gR2 RAC环境,用户在检查Alert数据库告警日志时不经意间看到performing DML/DDL operation over object in bin.告警信息,由于该条信息并不是错误或者告警,因此并不影响系统的稳定运行。但却成功的引起了用户的兴趣,该条日志的背后究竟发生了什么,才会在告警日志中打印出来。本篇将提供分析思路,旨在为了找出它背后的“真相”。
根因分析
通过解读日志本身,大概就能够评估跟数据库回收站对象相关,并且是对回收站对象做DDL和DML操作导致,验证如下:对回收站的表执行DML(delete),观测命令执行情况,如下:
alert告警日志输出,如下:
对回收站的表执行DDL(drop),观测命令执行情况,如下:
alert告警日志输出,如下:
因此,很快就得出结论,应该是数据库中有SQL语句对回收站对象进行DML/DDL,才会导致alert告警日志出现相关日志。但是,用户很快就驳回了这一结论,理由是业务侧不会对回收站中的对象做处理,同时运维侧也没有做过类似的变更操作。所以,现在又带来了新的问题,既然不是人为手动触发,那这类日志是怎么被触发。数据库系统中的哪些动作会存在可能,带着疑问,去MOS平台模糊匹配,看看是否能找到想要的答案。在MOS上,确实找到了引起出现这类日志的集中场景:场景一,参考文章ORA-38301: can not perform DDL/DML over objects in Recycle Bin (Doc ID 578075.1)
场景二,参考文章ORA-604 ORA-38301 ORA-30511 on alter/drop tablespace or other DDL/DML for objects in Recycle Bin - purge dba_recyclebin not helping (Doc ID 1484583.1)
场景三,参考文章'ORA-38301: can not perform DDL/DML over objects in Recycle Bin' while gathering DBMS_STATS (Doc ID 1542641.1)
这几种场景虽然都可能是原因,但是与用户沟通之后,都被否决掉了。那还有什么原因可能会导致,此时陷入了思考。不经意间,突然想起,该用户之前有一套别的Oracle系统,当时有一个跑批慢的案例,最终定位出来是由于访问recyclebin$很慢,导致跑批时间很长,而recyclebin$相关的SQL是业务语句递归调用执行的,那本次故障会不会也是相同的原因。所幸的是,笔者电脑上还保留着上次案例处理的10046分析日志,在该日志中确实找到了回收站对象的语句,如下:
分析到此处,为什么告警日志中频繁出现performing DML/DDL operation over object in bin的原因也能得到解释了。为了进一步验证结论的准确性,建议用户清空回收站,在跟踪观测alert日志是否继续产生该条信息,后续得到反馈日志中的信息没了。
