一个备库中ORA错误信息的分析 (r6笔记第69天)

最近也在处理一些遗留的问题，所以对于使用orabbix的报警还是心怀敬畏之心，一方面是我们让它能够做全方位的监控，另一方面也让我发现我们还是存在不少的小问题，小问题虽小，但是放大了，就是大麻烦，甚至数据库事故。 自从上次在社群分享了DB time的抖动案例之后，有不少的朋友似乎对这个工具很感兴趣，我做这个分享的一个主要原因就是希望大家在有些细节中发现问题，至于我分享的问题原因，都是各种各样的小问题，有些朋友也纳闷这种错误似乎还是比较低级的，通过一般的监控都应该解决，但是确实存在，发现了解决了，就是我们的最终目的。 前几天又收到一条报警短信，提示某个备库报了ora错误，但是短信中也没有提到更多的ora信息，首先连接到主库看看是否dg出了问题，使用dgmgrl进行验证，没有发现任何问题。 然后登录到备库，查看ora日志，发现了这么一段错误内容。 Redo Shipping Client Connected as PUBLIC -- Connected User is Valid RFS[1873]: Assigned to RFS process 3095 RFS[1873]: Identified database type as 'physical standby' RFS[1873]: Archived Log: '/opt/app/oracle/fra/SEXTDB3/archivelog/2015_09_22/o1_mf_1_2997_c016jv19_.arc' Tue Sep 22 08:00:31 2015 Media Recovery Log /opt/app/oracle/fra/SEXTDB3/archivelog/2015_09_22/o1_mf_1_2997_c016jv19_.arc Media Recovery Waiting for thread 1 sequence 2998 Tue Sep 22 09:18:01 2015 ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL Tue Sep 22 09:18:06 2015 MRP0: Background Media Recovery cancelled with status 16037 Tue Sep 22 09:18:06 2015 Errors in file /opt/app/oracle/admin/extradb/bdump/extdb_mrp0_3067.trc: ORA-16037: user requested cancel of managed recovery operation Recovery interrupted! Tue Sep 22 09:18:08 2015 Errors in file /opt/app/oracle/admin/extradb/bdump/extdb_mrp0_3067.trc: ORA-16037: user requested cancel of managed recovery operation Tue Sep 22 09:18:08 2015 MRP0: Background Media Recovery process shutdown (extdb) Tue Sep 22 09:18:09 2015 Managed Standby Recovery Canceled (extdb) Tue Sep 22 09:18:09 2015 Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL Tue Sep 22 09:18:11 2015 ALTER DATABASE OPEN READ ONLY Tue Sep 22 09:18:11 2015

从错误信息来看，似乎是日志应用的mrp终止了，但是查看后面的日志发现最新的日志已经成功应用了，如果没有其他人的操作，那么这个操作就是自动触发的了。 首先可以排除人为的操作。 我通过下面的脚本从alert日志中抓取最近几天的ORA错误情况，发现每天早晨的8点，9点左右，数据库都会启动到read only状态，然后稍过几分钟，又会切换回日志应用状态。 tail -10000 alert_extradb.log| grep -A1 -B1 "READ ONLY" -- Sun Sep 20 09:18:05 2015 ALTER DATABASE OPEN READ ONLY Sun Sep 20 09:18:05 2015 -- Physical standby database opened for read only access. Completed: ALTER DATABASE OPEN READ ONLY Sun Sep 20 09:18:05 2015 -- Sun Sep 20 16:00:05 2015 ALTER DATABASE OPEN READ ONLY Sun Sep 20 16:00:05 2015 -- Physical standby database opened for read only access. Completed: ALTER DATABASE OPEN READ ONLY Sun Sep 20 16:00:05 2015 -- Mon Sep 21 08:00:10 2015 ALTER DATABASE OPEN READ ONLY Mon Sep 21 08:00:10 2015 -- Physical standby database opened for read only access. Completed: ALTER DATABASE OPEN READ ONLY Mon Sep 21 08:00:11 2015 -- Mon Sep 21 09:18:10 2015 ALTER DATABASE OPEN READ ONLY Mon Sep 21 09:18:10 2015 -- Physical standby database opened for read only access. Completed: ALTER DATABASE OPEN READ ONLY Mon Sep 21 09:18:10 2015

好了，基本可以定位问题不是人为触发。应该是crontab或者scheduler来触发的了。 查看crontab，查看时间点相近的配置，就发现了两条相关的记录，时间戳和ORA的时间戳是一致的。 0 8,16 * * * (/bin/bash /home/oracle/dbadmin/scripts/query/query_for_xxxxx.sh 2>&1 > /dev/null) 18 9 * * * . $HOME/.extradbprofile;$HOME/dbadmin/scripts/query_data/query_mail.sh 6563 本来问题到此就基本明白了，是因为crontab触发的查询报出的ora错误，那么为什么查询还会需要一次又一次的read only呢，还是因为这是一个10gR2的库。 有时候应用部门有这种查询的需求，但是又不能人工每天去查，就让系统每天定时触发，然后发送邮件即可。 那么我们就默认保持现状吧，查看了一下这几个脚本 dgmgrl / "edit database sextdb3 set state='READ-ONLY'" 查询部分 发送邮件 dgmgrl / "edit database sextdb3 set state='online'" 查看这几个脚本已经有好些年头了。是否业务部门还需要这样的查询，本来想联系一下他们，顺着脚本中的邮箱去查看，但是发现这几个人已经不在通讯录中了，那么这就意味着这种查询可能不再需要了。 简单的讨论和核查后，确认这两个job已经不再需要了，这样这个问题就基本解决了，早上再也没有这两个ORA报警了，想想心里又会少咯噔几下。