一封备库报警邮件的分析(r6笔记第82天)

对于orabbix报出的警报，自己都是心怀敬畏，因为这些表面的现象如果深入分析没准就能有所收获，当然目的还是解决问题，不是一味追求指标。 今天收到的报警邮件如下，然后在两分钟后问题自动恢复。 ### ZABBIX-监控系统: ------------------------------------ 报警内容: DG_issue ------------------------------------ 报警级别: PROBLEM ------------------------------------ 监控项目: dg_issue：2015-10-08 03:59:38.0Log Transport ServicesErrorPING[ARC1]: Error 1089 when pinging standby (DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=adb1.xxxx.com)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=sadb1_XPT)(INSTANCE_NAME=adb1)(SERVER=dedicated))). ------------------------------------ 报警时间:2015.10.08-04:00:22 这是个一主两备的环境，因为这个问题是在主库的v$dataguard_status报出，而且对于1089的错误，oracle的解释如下： $ oerr ora 1089 01089, 00000, "immediate shutdown in progress - no operations are permitted" // *Cause: The SHUTDOWN IMMEDIATE command was used to shut down // a running ORACLE instance, so your operations have been // terminated. // *Action: Wait for the instance to be restarted, or contact your DBA. 所以还是分析了一下备库在问题时间段内的负载情况，没有发现明显的抖动。 sar的结果如下： 03:50:01 AM all 0.06 0.00 0.03 0.00 0.00 99.91 04:00:01 AM all 0.06 0.00 0.04 0.00 0.00 99.90 04:10:01 AM all 0.11 0.00 0.05 0.23 0.00 99.61 04:20:01 AM all 0.07 0.00 0.04 0.00 0.00 99.90 04:30:01 AM all 0.06 0.00 0.03 0.00 0.00 99.90 04:40:01 AM all 0.06 0.00 0.03 0.00 0.00 99.91 04:50:01 AM all 0.06 0.00 0.03 0.00 0.00 99.91 那么错误是从主库抛出的，来看看主库中的错误日志。就会发现在问题时间段尝试连接出错了，可能备库正在做shutdown immediate的操作。 Thu Oct 08 02:19:38 CST 2015 Thread 1 advanced to log sequence 7659 (LGWR switch) Current log# 1 seq# 7659 mem# 0: /U01/app/oracle/oradata/adb1/redo01.log Thu Oct 08 03:59:38 CST 2015 ARC1: Attempting destination LOG_ARCHIVE_DEST_2 network reconnect (1089) ARC1: Destination LOG_ARCHIVE_DEST_2 network reconnect abandoned PING[ARC1]: Error 1089 when pinging standby (DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=xxxx.com)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=sadb1_XP T)(INSTANCE_NAME=adb1)(SERVER=dedicated))). 好了，问题的背景就是这样，那么是否有备库中的crontab来触发这类操作呢。 直白的看，好像没有和shutdown immediate相关的操作。 $ crontab -l 2-9,12-29,31-59 * * * * . $HOME/.adb1profile;$HOME/dbadmin/scripts/lsnr_check.sh 0 1 * * 1 . $HOME/.adb1profile;$HOME/dbadmin/scripts/lsnr_log.sh 43 1 * * * . $HOME/.adb1profile;$HOME/dbadmin/scripts/expdpfull.sh #20 1 * * * . $HOME/.adb1profile;$HOME/dbadmin/scripts/rman_full_backup.sh 因为这是一个10g的备库，所以尝试做expdp还是需要把备库置为read-only状态才可以做的。开启日志应用还是会有shutdown的操作，所以这个还是一个可能的疑点。 另外一个备库，db uniq name指定错误，应该是s2accdb1 查看逻辑备库的脚本，看到确实有dgmgrl 做的read-only的操作，这样问题就对上了。 备库1中的备份脚本如下： $ less $HOME/dbadmin/scripts/expdpfull.sh #!/bin/bash 。。。 export expfile dgmgrl / "edit database sadb1 set state='READ-ONLY'" if [ $? -ne 0 ]; then echo "set read-only failed!" exit 1 fi ... 备库2中的备份脚本如下： $ less $HOME/dbadmin/scripts/expdpfull.sh #!/bin/bash 。。。 export expfile dgmgrl / "edit database sadb1 set state='READ-ONLY'" if [ $? -ne 0 ]; then echo "set read-only failed!" exit 1 fi ... 如果仔细查看就会发现问题，两个脚本的内容是一致的，里面所指的database是同一个备库，也就意味着在同样的时间里，两个客户端同时发出请求，对同一个备库做read-only的操作，这种操作还是有很大的风险的。 那么备库2运行脚本的时候，把备库1置为read-only,然后尝试在备库2做逻辑备份，会不会成功呢，结果肯定是不行。 可以在备库2中看到备份脚本运行了，但是没有生成备份，备份日志中只有一条错误警告。 -rw-r--r-- 1 oracle oinstall 159 Oct 8 01:44 accdb1_20151008.log $ less accdb1_20151008.log EXP-00008: ORACLE error 1219 encountered ORA-01219: database not open: queries allowed on fixed tables/views only EXP-00000: Export terminated unsuccessfully 问题到此确实发现了备库中的一个大的问题，通过一个小小的报警就能有如此的收获，其实还有更多的隐患，既然查看了备库的日志，那么其中的ora错误是格外需要关注的。 结果发现备库中竟然每天都会有大量的ora错误，是和redo相关的错误。 Errors in file /U01/app/oracle/admin/adb1/bdump/adb1_mrp0_3644.trc: ORA-00313: open failed for members of log group 1 of thread 1 ORA-00312: online log 1 thread 1: '/U01/app/oracle/oradata/adb1/redo01.log' ORA-27037: unable to obtain file status Linux-x86_64 Error: 2: No such file or directory Additional information: 3 Thu Oct 08 03:24:43 CST 2015 Errors in file /U01/app/oracle/admin/adb1/bdump/adb1_mrp0_3644.trc: ORA-19527: physical standby redo log must be renamed ORA-00312: online log 1 thread 1: '/U01/app/oracle/oradata/adb1/redo01.log' Clearing online redo logfile 1 complete Media Recovery Log /U01/app/oracle/admin/adb1/arch/1_7658_782788423.dbf Thu Oct 08 03:24:44 CST 2015 Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT NODELAY Thu Oct 08 03:24:45 CST 2015 Media Recovery Waiting for thread 1 sequence 7659 Thu Oct 08 03:25:29 CST 2015 Redo Shipping Client Connected as PUBLIC -- Connected User is Valid RFS[1015]: Assigned to RFS process 3928 RFS[1015]: Identified database type as 'physical standby' RFS[1015]: Archived Log: '/U01/app/oracle/admin/adb1/arch/1_7659_782788423.dbf' Thu Oct 08 03:25:35 CST 2015 Media Recovery Log /U01/app/oracle/admin/adb1/arch/1_7659_782788423.dbf Media Recovery Waiting for thread 1 sequence 7660 尽管有大量的ora错误，但是依然可以正常接收日志，使用dg broker来查看 DGMGRL> show configuration; Configuration Name: adb1 Enabled: YES Protection Mode: MaxPerformance Fast-Start Failover: DISABLED Databases: adb1 - Primary database sadb1 - Physical standby database s2adb1 - Physical standby database Current status for "accdb1": SUCCESS 可以看到验证是正常的，但是还是有潜在的问题，那么备库中的错误怎么和redo有关系呢。 如果使用show database verbose查看，是能发现一个潜在的问题的。 DGMGRL> show database verbose sadb1 Database Name: sadb1 Role: PHYSICAL STANDBY Enabled: YES Intended State: ONLINE Instance(s): adb1 Properties: InitialConnectIdentifier = 'sadb1' ObserverConnectIdentifier = '' LogXptMode = 'ARCH' Dependency = '' DelayMins = '0' Binding = 'OPTIONAL' MaxFailure = '0' MaxConnections = '1' ReopenSecs = '300' NetTimeout = '180' LogShipping = 'ON' PreferredApplyInstance = '' ApplyInstanceTimeout = '0' ApplyParallel = 'AUTO' StandbyFileManagement = 'auto' ArchiveLagTarget = '0' LogArchiveMaxProcesses = '2' LogArchiveMinSucceedDest = '1' DbFileNameConvert = '' LogFileNameConvert = '' FastStartFailoverTarget = '' StatusReport = '(monitor)' InconsistentProperties = '(monitor)' InconsistentLogXptProps = '(monitor)' SendQEntries = '(monitor)' LogXptStatus = '(monitor)' RecvQEntries = '(monitor)' HostName = 'xxxx.com' SidName = 'adb1' LocalListenerAddress = '(ADDRESS=(PROTOCOL=TCP)(HOST=xxxx.com)(PORT=1521))' StandbyArchiveLocation = '/U01/app/oracle/admin/adb1/arch' AlternateLocation = '' LogArchiveTrace = '0' LogArchiveFormat = '%t_%s_%r.dbf' LatestLog = '(monitor)' TopWaitEvents = '(monitor)' Current status for "sadb1": SUCCESS 这个时候可以尝试使用edit语句修改这些配置 edit database sadb1 set property LogFileNameConvert='/U01/app/oracle/oradata/adb1,/U01/app/oracle/oradata/adb1'; edit database sadb1 set property DbFileNameConvert='/U01/app/oracle/oradata/adb1,/U01/app/oracle/oradata/adb1'; 在spfile层级修改还是需要启动备库的，现在spfile定义一下。 alter system set db_file_name_convert='/U01/app/oracle/oradata/adb1','/U01/app/oracle/oradata/adb1' scope=spfile; alter system set log_file_name_convert='/U01/app/oracle/oradata/adb1','/U01/app/oracle/oradata/adb1' scope=spfile; 这个时候检查dg broker就会抛出下面的错误。 DGMGRL> show configuration; Configuration Name: adb1 Enabled: YES Protection Mode: MaxPerformance Fast-Start Failover: DISABLED Databases: adb1 - Primary database sadb1 - Physical standby database s2adb1 - Physical standby database Current status for "adb1": Warning: ORA-16608: one or more databases have warnings 对于这一类问题，如果不是很清楚，可以按照下面的思路来查。 DGMGRL> show database verbose sadb1; Database Name: sadb1 Role: PHYSICAL STANDBY Enabled: YES Intended State: ONLINE Instance(s): adb1 Properties: InitialConnectIdentifier = 'sadb1' ObserverConnectIdentifier = '' LogXptMode = 'ARCH' Dependency = '' DelayMins = '0' Binding = 'OPTIONAL' MaxFailure = '0' MaxConnections = '1' ReopenSecs = '300' NetTimeout = '180' LogShipping = 'ON' PreferredApplyInstance = '' ApplyInstanceTimeout = '0' ApplyParallel = 'AUTO' StandbyFileManagement = 'auto' ArchiveLagTarget = '0' LogArchiveMaxProcesses = '2' LogArchiveMinSucceedDest = '1' DbFileNameConvert = '/U01/app/oracle/oradata/adb1,/U01/app/oracle/oradata/adb1' LogFileNameConvert = '/U01/app/oracle/oradata/adb1,/U01/app/oracle/oradata/adb1' FastStartFailoverTarget = '' StatusReport = '(monitor)' InconsistentProperties = '(monitor)' InconsistentLogXptProps = '(monitor)' SendQEntries = '(monitor)' LogXptStatus = '(monitor)' RecvQEntries = '(monitor)' HostName = 'xxxx.com' SidName = 'adb1' LocalListenerAddress = '(ADDRESS=(PROTOCOL=TCP)(HOST=xxxx.com)(PORT=1521))' StandbyArchiveLocation = '/U01/app/oracle/admin/adb1/arch' AlternateLocation = '' LogArchiveTrace = '0' LogArchiveFormat = '%t_%s_%r.dbf' LatestLog = '(monitor)' TopWaitEvents = '(monitor)' Current status for "sadb1": Warning: ORA-16792: configuration property value is inconsistent with database setting 然后使用下面的命令来查看不匹配的地方。 DGMGRL> show database sadb1 'InconsistentProperties'; INCONSISTENT PROPERTIES INSTANCE_NAME PROPERTY_NAME MEMORY_VALUE SPFILE_VALUE BROKER_VALUE adb1 DbFileNameConvert /U01/app/oracle/oradata/adb1,/U01/app/oracle/oradata/adb1 /U01/app/oracle/oradata/adb1,/U01/app/oracle/oradata/adb1 adb1 LogFileNameConvert /U01/app/oracle/oradata/adb1,/U01/app/oracle/oradata/adb1 /U01/app/oracle/oradata/adb1,/U01/app/oracle/oradata/adb1 可以看到memory_value,spfile_value,broker_value还是不匹配的。 所以还是需要启动备库的。启动之后问题就会自然修复，对于这类ora错误可以参考mos文档。 ORA-19527 reported in Standby Database when starting Managed Recovery (文档 ID 352879.1) 所以经过以上处理，两个备库的处理思路就清晰了，备份也存在，日志中的ora错误也能够基本消除。