ORACLE Bug 4431215 引发的血案—原因分析篇

抱歉上文编辑不下，才续写此文

可为什么该目录会丢失呢，原因是因为ORACLE的BUG，且看故障元凶：Bug 4431215的定位过程，看如下三个日志，节点1在归档到8211发生错误，节点2在归档到6852发生错误，而1点钟有个RMAN定时JOB发起2级备份，备份后会删除归档日志，从RMAN日志可以看出，最大的备份号分别为8210和6851，这和节点ALERT日志是完全一致的，可见在RMAN备份后归档便发生了错误，而RMAN备份后的瞬间，归档目录是空的，这难免让人想到ORACLE在ASM环境下的一个BUG：“在ASM上建立的目录名称和SID前缀相同，则这个目录下的所有目录一旦为空，就会被ASM实例自动删除，不管这个目录是ASM自动建立，还是用户手工建立的。”。登陆ORACLE官方站点确认有该BUG：“Bug 4431215 - "backup archivelog all delete input" from RMAN removes ASM directory [ID 4431215.8]”，至此故障调查完成。

1. 节点1日志： 
2. Wed Jul 13 01:22:55 2011 
3. Thread 1 advanced to log sequence 8210 (LGWR switch) 
4.   Current log# 2 seq# 8210 mem# 0: +DATA/port/onlinelog/group_2.264.697238179 
5.   Current log# 2 seq# 8210 mem# 1: +DATA/port/onlinelog/group_2.265.697238179 
6. Wed Jul 13 01:23:00 2011 
7. ALTER SYSTEM ARCHIVE LOG 
8. Wed Jul 13 01:23:01 2011 
9. Thread 1 cannot allocate new log, sequence 8211 
10. Checkpoint not complete 
11.   Current log# 2 seq# 8210 mem# 0: +DATA/port/onlinelog/group_2.264.697238179 
12.   Current log# 2 seq# 8210 mem# 1: +DATA/port/onlinelog/group_2.265.697238179 
13.  
14. 节点2日志： 
15. Wed Jul 13 01:20:27 2011 
16. Thread 2 advanced to log sequence 6851 (LGWR switch) 
17.   Current log# 3 seq# 6851 mem# 0: +DATA/port/onlinelog/group_3.268.697238217 
18.   Current log# 3 seq# 6851 mem# 1: +DATA/port/onlinelog/group_3.269.697238219 
19. Thread 2 cannot allocate new log, sequence 6852 
20. Checkpoint not complete 
21.   Current log# 3 seq# 6851 mem# 0: +DATA/port/onlinelog/group_3.268.697238217 
22.   Current log# 3 seq# 6851 mem# 1: +DATA/port/onlinelog/group_3.269.697238219 
23. Wed Jul 13 01:20:36 2011 
24. Thread 2 advanced to log sequence 6852 (LGWR switch) 
25.   Current log# 4 seq# 6852 mem# 0: +DATA/port/onlinelog/group_4.270.697238219 
26.   Current log# 4 seq# 6852 mem# 1: +DATA/port/onlinelog/group_4.271.697238221 
27.  
28. 故障发生前的RMAN备份日志，备份完成后删除备份的归档日志： 
29. channel d1: specifying archive log(s) in backup set 
30. input archive log thread=1 sequence=8180 recid=22515 stamp=756327382 
31. input archive log thread=1 sequence=8181 recid=22516 stamp=756327390 
32. input archive log thread=1 sequence=8182 recid=22517 stamp=756327399 
33. input archive log thread=1 sequence=8183 recid=22519 stamp=756327406 
34. input archive log thread=1 sequence=8184 recid=22520 stamp=756327418 
35. input archive log thread=1 sequence=8185 recid=22521 stamp=756327426 
36. input archive log thread=1 sequence=8186 recid=22522 stamp=756327434 
37. input archive log thread=1 sequence=8187 recid=22524 stamp=756327443 
38. input archive log thread=1 sequence=8188 recid=22525 stamp=756327453 
39. input archive log thread=1 sequence=8189 recid=22527 stamp=756327462 
40. input archive log thread=1 sequence=8190 recid=22528 stamp=756327469 
41. input archive log thread=1 sequence=8191 recid=22529 stamp=756327477 
42. input archive log thread=1 sequence=8192 recid=22531 stamp=756327488 
43. input archive log thread=1 sequence=8193 recid=22532 stamp=756327496 
44. input archive log thread=1 sequence=8194 recid=22533 stamp=756327505 
45. input archive log thread=1 sequence=8195 recid=22535 stamp=756327514 
46. input archive log thread=1 sequence=8196 recid=22536 stamp=756327523 
47. input archive log thread=1 sequence=8197 recid=22537 stamp=756327538 
48. input archive log thread=1 sequence=8198 recid=22538 stamp=756327653 
49. input archive log thread=1 sequence=8199 recid=22540 stamp=756327664 
50. input archive log thread=1 sequence=8200 recid=22541 stamp=756327673 
51. input archive log thread=1 sequence=8201 recid=22543 stamp=756327686 
52. input archive log thread=1 sequence=8202 recid=22544 stamp=756327695 
53. input archive log thread=1 sequence=8203 recid=22545 stamp=756327704 
54. input archive log thread=1 sequence=8204 recid=22547 stamp=756327717 
55. input archive log thread=1 sequence=8205 recid=22548 stamp=756329007 
56. input archive log thread=1 sequence=8206 recid=22549 stamp=756338512 
57. input archive log thread=1 sequence=8207 recid=22551 stamp=756343058 
58. input archive log thread=1 sequence=8208 recid=22552 stamp=756345806 
59. input archive log thread=1 sequence=8209 recid=22553 stamp=756350578 
60. input archive log thread=1 sequence=8210 recid=22555 stamp=756350584 
61. input archive log thread=2 sequence=6800 recid=22340 stamp=756264103 
62. input archive log thread=2 sequence=6801 recid=22345 stamp=756265938 
63. input archive log thread=2 sequence=6802 recid=22356 stamp=756266232 
64. input archive log thread=2 sequence=6803 recid=22357 stamp=756266255 
65. input archive log thread=2 sequence=6804 recid=22359 stamp=756266260 
66. input archive log thread=2 sequence=6805 recid=22362 stamp=756266269 
67. input archive log thread=2 sequence=6806 recid=22363 stamp=756266272 
68. input archive log thread=2 sequence=6807 recid=22365 stamp=756266287 
69. input archive log thread=2 sequence=6808 recid=22369 stamp=756267485 
70. input archive log thread=2 sequence=6809 recid=22376 stamp=756291174 
71. input archive log thread=2 sequence=6810 recid=22380 stamp=756293726 
72. input archive log thread=2 sequence=6811 recid=22386 stamp=756299397 
73. input archive log thread=2 sequence=6812 recid=22390 stamp=756311219 
74. input archive log thread=2 sequence=6813 recid=22396 stamp=756313749 
75. input archive log thread=2 sequence=6814 recid=22402 stamp=756316744 
76. input archive log thread=2 sequence=6815 recid=22406 stamp=756319318 
77. input archive log thread=2 sequence=6816 recid=22412 stamp=756325509 
78. input archive log thread=2 sequence=6817 recid=22415 stamp=756326651 
79. input archive log thread=2 sequence=6818 recid=22420 stamp=756326683 
80. input archive log thread=2 sequence=6819 recid=22425 stamp=756326710 
81. input archive log thread=2 sequence=6820 recid=22428 stamp=756326732 
82. input archive log thread=2 sequence=6821 recid=22433 stamp=756326756 
83. input archive log thread=2 sequence=6822 recid=22438 stamp=756326780 
84. input archive log thread=2 sequence=6823 recid=22441 stamp=756326801 
85. input archive log thread=2 sequence=6824 recid=22445 stamp=756326823 
86. input archive log thread=2 sequence=6825 recid=22450 stamp=756326850 
87. input archive log thread=2 sequence=6826 recid=22455 stamp=756326878 
88. input archive log thread=2 sequence=6827 recid=22460 stamp=756326905 
89. input archive log thread=2 sequence=6828 recid=22464 stamp=756326930 
90. input archive log thread=2 sequence=6829 recid=22468 stamp=756326951 
91. input archive log thread=2 sequence=6830 recid=22472 stamp=756326969 
92. input archive log thread=2 sequence=6831 recid=22477 stamp=756326991 
93. input archive log thread=2 sequence=6832 recid=22481 stamp=756327012 
94. channel d1: starting piece 1 at 13-JUL-11 
95. channel d1: finished piece 1 at 13-JUL-11 
96. piece handle=/u01/rmanbak/arch_ZJPORT_1hmha00r_1_1 tag=BKARCH comment=NONE 
97. channel d1: backup set complete, elapsed time: 00:03:17 
98. channel d1: deleting archive log(s) 
99. archive log filename=+DATA/zjport/archivelog/1_8180_697238176.dbf recid=22515 stamp=756327382 
100. archive log filename=+DATA/zjport/archivelog/1_8181_697238176.dbf recid=22516 stamp=756327390 
101. archive log filename=+DATA/zjport/archivelog/1_8182_697238176.dbf recid=22517 stamp=756327399 
102. archive log filename=+DATA/zjport/archivelog/1_8183_697238176.dbf recid=22519 stamp=756327406 
103. archive log filename=+DATA/zjport/archivelog/1_8184_697238176.dbf recid=22520 stamp=756327418 
104. archive log filename=+DATA/zjport/archivelog/1_8185_697238176.dbf recid=22521 stamp=756327426 
105. archive log filename=+DATA/zjport/archivelog/1_8186_697238176.dbf recid=22522 stamp=756327434 
106. archive log filename=+DATA/zjport/archivelog/1_8187_697238176.dbf recid=22524 stamp=756327443 
107. archive log filename=+DATA/zjport/archivelog/1_8188_697238176.dbf recid=22525 stamp=756327453 
108. archive log filename=+DATA/zjport/archivelog/1_8189_697238176.dbf recid=22527 stamp=756327462 
109. archive log filename=+DATA/zjport/archivelog/1_8190_697238176.dbf recid=22528 stamp=756327469 
110. archive log filename=+DATA/zjport/archivelog/1_8191_697238176.dbf recid=22529 stamp=756327477 
111. archive log filename=+DATA/zjport/archivelog/1_8192_697238176.dbf recid=22531 stamp=756327488 
112. archive log filename=+DATA/zjport/archivelog/1_8193_697238176.dbf recid=22532 stamp=756327496 
113. archive log filename=+DATA/zjport/archivelog/1_8194_697238176.dbf recid=22533 stamp=756327505 
114. archive log filename=+DATA/zjport/archivelog/1_8195_697238176.dbf recid=22535 stamp=756327514 
115. archive log filename=+DATA/zjport/archivelog/1_8196_697238176.dbf recid=22536 stamp=756327523 
116. archive log filename=+DATA/zjport/archivelog/1_8197_697238176.dbf recid=22537 stamp=756327538 
117. archive log filename=+DATA/zjport/archivelog/1_8198_697238176.dbf recid=22538 stamp=756327653 
118. archive log filename=+DATA/zjport/archivelog/1_8199_697238176.dbf recid=22540 stamp=756327664 
119. archive log filename=+DATA/zjport/archivelog/1_8200_697238176.dbf recid=22541 stamp=756327673 
120. archive log filename=+DATA/zjport/archivelog/1_8201_697238176.dbf recid=22543 stamp=756327686 
121. archive log filename=+DATA/zjport/archivelog/1_8202_697238176.dbf recid=22544 stamp=756327695 
122. archive log filename=+DATA/zjport/archivelog/1_8203_697238176.dbf recid=22545 stamp=756327704 
123. archive log filename=+DATA/zjport/archivelog/1_8204_697238176.dbf recid=22547 stamp=756327717 
124. archive log filename=+DATA/zjport/archivelog/1_8205_697238176.dbf recid=22548 stamp=756329007 
125. archive log filename=+DATA/zjport/archivelog/1_8206_697238176.dbf recid=22549 stamp=756338512 
126. archive log filename=+DATA/zjport/archivelog/1_8207_697238176.dbf recid=22551 stamp=756343058 
127. archive log filename=+DATA/zjport/archivelog/1_8208_697238176.dbf recid=22552 stamp=756345806 
128. archive log filename=+DATA/zjport/archivelog/1_8209_697238176.dbf recid=22553 stamp=756350578 
129. archive log filename=+DATA/zjport/archivelog/1_8210_697238176.dbf recid=22555 stamp=756350584=======节点1的归档备份到8210 
130. archive log filename=+DATA/zjport/archivelog/2_6800_697238176.dbf recid=22340 stamp=756264103 
131. archive log filename=+DATA/zjport/archivelog/2_6801_697238176.dbf recid=22345 stamp=756265938 
132. archive log filename=+DATA/zjport/archivelog/2_6802_697238176.dbf recid=22356 stamp=756266232 
133. archive log filename=+DATA/zjport/archivelog/2_6803_697238176.dbf recid=22357 stamp=756266255 
134. archive log filename=+DATA/zjport/archivelog/2_6804_697238176.dbf recid=22359 stamp=756266260 
135. archive log filename=+DATA/zjport/archivelog/2_6805_697238176.dbf recid=22362 stamp=756266269 
136. archive log filename=+DATA/zjport/archivelog/2_6806_697238176.dbf recid=22363 stamp=756266272 
137. archive log filename=+DATA/zjport/archivelog/2_6807_697238176.dbf recid=22365 stamp=756266287 
138. archive log filename=+DATA/zjport/archivelog/2_6808_697238176.dbf recid=22369 stamp=756267485 
139. archive log filename=+DATA/zjport/archivelog/2_6809_697238176.dbf recid=22376 stamp=756291174 
140. archive log filename=+DATA/zjport/archivelog/2_6810_697238176.dbf recid=22380 stamp=756293726 
141. archive log filename=+DATA/zjport/archivelog/2_6811_697238176.dbf recid=22386 stamp=756299397 
142. archive log filename=+DATA/zjport/archivelog/2_6812_697238176.dbf recid=22390 stamp=756311219 
143. archive log filename=+DATA/zjport/archivelog/2_6813_697238176.dbf recid=22396 stamp=756313749 
144. archive log filename=+DATA/zjport/archivelog/2_6814_697238176.dbf recid=22402 stamp=756316744 
145. archive log filename=+DATA/zjport/archivelog/2_6815_697238176.dbf recid=22406 stamp=756319318 
146. archive log filename=+DATA/zjport/archivelog/2_6816_697238176.dbf recid=22412 stamp=756325509 
147. archive log filename=+DATA/zjport/archivelog/2_6817_697238176.dbf recid=22415 stamp=756326651 
148. archive log filename=+DATA/zjport/archivelog/2_6818_697238176.dbf recid=22420 stamp=756326683 
149. archive log filename=+DATA/zjport/archivelog/2_6819_697238176.dbf recid=22425 stamp=756326710 
150. archive log filename=+DATA/zjport/archivelog/2_6820_697238176.dbf recid=22428 stamp=756326732 
151. archive log filename=+DATA/zjport/archivelog/2_6821_697238176.dbf recid=22433 stamp=756326756 
152. archive log filename=+DATA/zjport/archivelog/2_6822_697238176.dbf recid=22438 stamp=756326780 
153. archive log filename=+DATA/zjport/archivelog/2_6823_697238176.dbf recid=22441 stamp=756326801 
154. archive log filename=+DATA/zjport/archivelog/2_6824_697238176.dbf recid=22445 stamp=756326823 
155. archive log filename=+DATA/zjport/archivelog/2_6825_697238176.dbf recid=22450 stamp=756326850 
156. archive log filename=+DATA/zjport/archivelog/2_6826_697238176.dbf recid=22455 stamp=756326878 
157. archive log filename=+DATA/zjport/archivelog/2_6827_697238176.dbf recid=22460 stamp=756326905 
158. archive log filename=+DATA/zjport/archivelog/2_6828_697238176.dbf recid=22464 stamp=756326930 
159. archive log filename=+DATA/zjport/archivelog/2_6829_697238176.dbf recid=22468 stamp=756326951 
160. archive log filename=+DATA/zjport/archivelog/2_6830_697238176.dbf recid=22472 stamp=756326969 
161. archive log filename=+DATA/zjport/archivelog/2_6831_697238176.dbf recid=22477 stamp=756326991 
162. archive log filename=+DATA/zjport/archivelog/2_6832_697238176.dbf recid=22481 stamp=756327012 
163. channel d1: starting compressed archive log backupset 
164. channel d1: specifying archive log(s) in backup set 
165. input archive log thread=2 sequence=6833 recid=22484 stamp=756327033 
166. input archive log thread=2 sequence=6834 recid=22488 stamp=756327058 
167. input archive log thread=2 sequence=6835 recid=22492 stamp=756327082 
168. input archive log thread=2 sequence=6836 recid=22497 stamp=756327112 
169. input archive log thread=2 sequence=6837 recid=22501 stamp=756327145 
170. input archive log thread=2 sequence=6838 recid=22505 stamp=756327170 
171. input archive log thread=2 sequence=6839 recid=22510 stamp=756327198 
172. input archive log thread=2 sequence=6840 recid=22513 stamp=756327222 
173. input archive log thread=2 sequence=6841 recid=22518 stamp=756327253 
174. input archive log thread=2 sequence=6842 recid=22523 stamp=756327287 
175. input archive log thread=2 sequence=6843 recid=22526 stamp=756327311 
176. input archive log thread=2 sequence=6844 recid=22530 stamp=756327336 
177. input archive log thread=2 sequence=6845 recid=22534 stamp=756327363 
178. input archive log thread=2 sequence=6846 recid=22539 stamp=756327505 
179. input archive log thread=2 sequence=6847 recid=22542 stamp=756327535 
180. input archive log thread=2 sequence=6848 recid=22546 stamp=756327566 
181. input archive log thread=2 sequence=6849 recid=22550 stamp=756341841 
182. input archive log thread=2 sequence=6850 recid=22554 stamp=756350429 
183. input archive log thread=2 sequence=6851 recid=22556 stamp=756350436 
184. channel d1: starting piece 1 at 13-JUL-11 
185. channel d1: finished piece 1 at 13-JUL-11 
186. piece handle=/u01/rmanbak/arch_ZJPORT_1imha073_1_1 tag=BKARCH comment=NONE 
187. channel d1: backup set complete, elapsed time: 00:00:16 
188. channel d1: deleting archive log(s) 
189. archive log filename=+DATA/zjport/archivelog/2_6833_697238176.dbf recid=22484 stamp=756327033 
190. archive log filename=+DATA/zjport/archivelog/2_6834_697238176.dbf recid=22488 stamp=756327058 
191. archive log filename=+DATA/zjport/archivelog/2_6835_697238176.dbf recid=22492 stamp=756327082 
192. archive log filename=+DATA/zjport/archivelog/2_6836_697238176.dbf recid=22497 stamp=756327112 
193. archive log filename=+DATA/zjport/archivelog/2_6837_697238176.dbf recid=22501 stamp=756327145 
194. archive log filename=+DATA/zjport/archivelog/2_6838_697238176.dbf recid=22505 stamp=756327170 
195. archive log filename=+DATA/zjport/archivelog/2_6839_697238176.dbf recid=22510 stamp=756327198 
196. archive log filename=+DATA/zjport/archivelog/2_6840_697238176.dbf recid=22513 stamp=756327222 
197. archive log filename=+DATA/zjport/archivelog/2_6841_697238176.dbf recid=22518 stamp=756327253 
198. archive log filename=+DATA/zjport/archivelog/2_6842_697238176.dbf recid=22523 stamp=756327287 
199. archive log filename=+DATA/zjport/archivelog/2_6843_697238176.dbf recid=22526 stamp=756327311 
200. archive log filename=+DATA/zjport/archivelog/2_6844_697238176.dbf recid=22530 stamp=756327336 
201. archive log filename=+DATA/port/archivelog/2_6845_697238176.dbf recid=22534 stamp=756327363 
202. archive log filename=+DATA/port/archivelog/2_6846_697238176.dbf recid=22539 stamp=756327505 
203. archive log filename=+DATA/port/archivelog/2_6847_697238176.dbf recid=22542 stamp=756327535 
204. archive log filename=+DATA/port/archivelog/2_6848_697238176.dbf recid=22546 stamp=756327566 
205. archive log filename=+DATA/port/archivelog/2_6849_697238176.dbf recid=22550 stamp=756341841 
206. archive log filename=+DATA/port/archivelog/2_6850_697238176.dbf recid=22554 stamp=756350429 
207. archive log filename=+DATA/port/archivelog/2_6851_697238176.dbf recid=22556 stamp=756350436==========节点2的归档备份到8210 
208. Finished backup at 13-JUL-11 
209.   
210. released channel: d1 
211.   
212. executing global script: global_bkctl 
213.   
214. allocated channel: d1 
215. channel d1: sid=906 instance=port1 devtype=DISK 
216.   
217. Starting backup at 13-JUL-11 
218. channel d1: starting compressed full datafile backupset 
219. channel d1: specifying datafile(s) in backupset 
220. including current control file in backupset 
221. channel d1: starting piece 1 at 13-JUL-11 
222. channel d1: finished piece 1 at 13-JUL-11 
223. piece handle=/u01/rmanbak/backupctl.ctl tag=BKCTL comment=NONE 
224. channel d1: backup set complete, elapsed time: 00:00:02 
225. Finished backup at 13-JUL-11 
226.   
227. released channel: d1 
228.   
229. Recovery Manager complete. 

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

我们最后的处理：

通过ASMCDM在+DATA下新建了archivelog目录，然后在此目录下新建子目录，为什么不建立文件（因为笔者没有找到10G ASM下建文件的命令，如果有人知道，烦请指导，谢谢）

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