ORACLE Bug 4431215 引发的血案—处理篇

 今早一大早就到了公司，正想去享受美味早餐，出于职业反映去检查了下几个核心RAC数据库，居然发现其中一个RAC数据库的两个节点的ALERT日志均有错误，其中一个节点更是持续滚动输出，马上提起12分的精神开始面对这新的挑战。初步查看发现，两个节点通过PL/SQL均不能连接，但是本机能正常登陆，而查询业务语句只有在节点1可以运行，但节点1也经常处于HANG这个状态。
    说来也巧，昨天由于机房检修，我们这个RAC库的DATAGUARD从库被列入了停机的黑名单，因此故障发生时DG从库是处于关机状态下的，也就意味着归档不能从主库同步到从库，我的脑海里首先不自觉的就把该错误和DG从库联系到一起，以至于一定时间内干扰了对问题的认识，并导致处理方案并不是最优的，今天晚上就不得不花费数小时来弥补这不是最优的选项，但是想想业务在半小时内得到了恢复，这是最让人欣慰的。

错误日志：

1. 节点1的ALERT日志： 
2. Wed Jul 13 04:06:26 2011 
3. >>> WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! pid=214 
4. System State dumped to trace file /u01/app/oracle/admin/port/udump/port1_ora_4668.trc 
5. Wed Jul 13 06:26:59 2011 
6. Errors in file /u01/app/oracle/admin/port/bdump/port1_j000_3593.trc: 
7. ORA-12012: error on auto execute of job 42780 
8. ORA-27468: "." is locked by another process 
9. Wed Jul 13 06:49:44 2011 
10. Errors in file /u01/app/oracle/admin/port/bdump/port1_j001_4323.trc: 
11. ORA-12012: error on auto execute of job 42781 
12. ORA-27468: "." is locked by another process 
13. Wed Jul 13 07:25:30 2011 
14. Errors in file /u01/app/oracle/admin/port/bdump/port1_j000_3593.trc: 
15. ORA-12012: error on auto execute of job 42780 
16. ORA-27468: "." is locked by another process 
17. Wed Jul 13 07:49:45 2011 
18. Errors in file /u01/app/oracle/admin/port/bdump/port1_j001_4323.trc: 
19. ORA-12012: error on auto execute of job 42781 
20. ORA-27468: "." is locked by another process 
21.  
22. 节点2的ALERT日志： 
23. Tue Jul 12 22:57:19 2011 
24. Thread 2 advanced to log sequence 6850 (LGWR switch) 
25.   Current log# 4 seq# 6850 mem# 0: +DATA/port/onlinelog/group_4.270.697238219 
26.   Current log# 4 seq# 6850 mem# 1: +DATA/port/onlinelog/group_4.271.697238221 
27. Wed Jul 13 01:20:27 2011 
28. Thread 2 advanced to log sequence 6851 (LGWR switch) 
29.   Current log# 3 seq# 6851 mem# 0: +DATA/port/onlinelog/group_3.268.697238217 
30.   Current log# 3 seq# 6851 mem# 1: +DATA/port/onlinelog/group_3.269.697238219 
31. Thread 2 cannot allocate new log, sequence 6852 
32. Checkpoint not complete 
33.   Current log# 3 seq# 6851 mem# 0: +DATA/port/onlinelog/group_3.268.697238217 
34.   Current log# 3 seq# 6851 mem# 1: +DATA/port/onlinelog/group_3.269.697238219 
35. Wed Jul 13 01:20:36 2011 
36. Thread 2 advanced to log sequence 6852 (LGWR switch) 
37.   Current log# 4 seq# 6852 mem# 0: +DATA/port/onlinelog/group_4.270.697238219 
38.   Current log# 4 seq# 6852 mem# 1: +DATA/port/onlinelog/group_4.271.697238221 
39. Wed Jul 13 01:51:41 2011 
40. Thread 2 advanced to log sequence 6853 (LGWR switch) 
41.   Current log# 3 seq# 6853 mem# 0: +DATA/port/onlinelog/group_3.268.697238217 
42.   Current log# 3 seq# 6853 mem# 1: +DATA/port/onlinelog/group_3.269.697238219 
43. Wed Jul 13 01:51:41 2011 
44. ARCH: Archival stopped, error occurred. Will continue retrying 
45. Wed Jul 13 01:51:41 2011 
46. ORACLE Instance port2 - Archival Error 
47. Wed Jul 13 01:51:41 2011 
48. ORA-16038: log 4 sequence# 6852 cannot be archived 
49. ORA-00254: error in archive control string '' 
50. ORA-00312: online log 4 thread 2: '+DATA/port/onlinelog/group_4.270.697238219' 
51. ORA-00312: online log 4 thread 2: '+DATA/port/onlinelog/group_4.271.697238221' 
52. ORA-15173: entry 'archivelog' does not exist in directory 'port' 

    从以上日志可以看出，故障发生时间在01:20:27-01:21:36之间，为什么这么说，因为在01：21：36时候已经出现“Checkpoint not complete”错误了，其实就是归档出了问题。但在查看具体错误的时候笔者犯了经验注意的错误，因为从库也有archivelog目录，而恰恰故障前一天停止了从库服务器，且要命的是PLSQL连接提示00257错误，这个错误经验性的让人想到是日志空间满了，不单是笔者，支援的同事和第三方维保支持人员也都进行了管辖思维，错误的判断成了是DG从库不能传输日志导致的故障，事实上只要仔细看如上的“ORA-15173: entry 'archivelog' does not exist in directory 'port'”错误和ORA-00254错误，应该可以定位故障是主库归档的问题。

    由于这个小小的疏忽，且由于处理时效的限制，在采取备份、删除归档日志:

1. backup archivelog all format '/u01/archive/arch_%U'; 
2. delete noprompt archivelog until time 'sysdate -3'; 
3. delete noprompt archivelog until time 'sysdate -2'; 
4. delete noprompt archivelog until time 'sysdate -1'; 
5. delete noprompt archivelog until time 'sysdate -0'; 

向从库传输日志无果后.便匆匆忙忙的启用了主库的非归档模式。而就是这小小的模式变动，导致了DG从库需要在今晚从主库导出全库数据，然后恢复，然后同步日志，而对于180G以上的数据量加上从库本地磁盘的属性，决定了这个过程是相当的漫长，我们在维护报告中把维护窗口从当天22：00一直申请到了次日5：00.

   事实上只要处理时间稍微充裕那么一点，我们不难发现更简便的方法，通过ASMCMD直接创建丢失的archivelog目录就可以了。

1. [oradba@oracle1 rmanbak]$ export ORACLE_SID=+ASM1 
2. [oradba@oracle1 rmanbak]$ asmcmd 
3. ASMCMD> cd data 
4. ASMCMD> mkdir archivelog 
5. ASMCMD> ls 
6. PORT/ 
7. archivelog/ 

 本文转自zylhsy 51CTO博客，原文链接：http://blog.51cto.com/yunlongzheng/610312，如需转载请自行联系原作者