昨天,经历了职业生涯中最令人心惊胆颤的危机,差点要去买锄头准备回家种地去了。-_-!!
早上5点钟,被同事叫醒,说应用程序连数据库报TNS没响应。于是开始登录数据库主机。登录的时候,用常用的浮动IP连接,没响应,此时第一个反映就是是不是数据库主机挂了?难道要去机房?现在可是奥运前期,进出机房是件挺麻烦的事情……再试了试实际IP,幸好,登录进去了。check了一下进程和alertlog,发现是控制文件的读取有问题了:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 |
Tue Jun 10 04:17:51 2008 Errors in file /oracle/app/oracle/admin/sd168/bdump/sd168_arc0_7605.trc: ORA-00202: controlfile: '/dev/vg_ora1/rctrl_128m_01' ORA-27091: skgfqio: unable to queue I/O ORA-27072: skgfdisp: I/O error HP-UX Error: 5: I/O error Additional information: 1 Tue Jun 10 04:17:51 2008 KCF: write/open error block=0x44a online=1 Tue Jun 10 04:17:51 2008 Errors in file /oracle/app/oracle/admin/sd168/bdump/sd168_lgwr_7595.trc: ORA-00345: redo log write error block 84121 count 2 ORA-00312: online log 2 thread 1: '/dev/vg_ora1/rredo_256m_02' ORA-65535: Message 65535 not found; product=RDBMS; facility=ORA Tue Jun 10 04:17:51 2008 KCF: write/open error block=0xa251 online=1 file=7 /dev/vg_ora1/rdata_1g_004 Tue Jun 10 04:17:51 2008 Errors in file /oracle/app/oracle/admin/sd168/udump/sd168_ora_16308.trc: ORA-00202: controlfile: '/dev/vg_ora1/rctrl_128m_01' ORA-27091: skgfqio: unable to queue I/O ORA-27072: skgfdisp: I/O error HP-UX Error: 5: I/O error Additional information: 1 file=1 /dev/vg_ora1/rsys_512m_01 error=65535 txt: '' Tue Jun 10 04:17:51 2008 Errors in file /oracle/app/oracle/admin/sd168/udump/sd168_ora_16562.trc: ORA-00604: error occurred at recursive SQL level 1 ORA-01115: IO error reading block from file 1 (block # 820) ORA-01110: data file 1: '/dev/vg_ora1/rsys_512m_01' ORA-27091: skgfqio: unable to queue I/O ORA-27072: skgfdisp: I/O error HP-UX Error: 25: Not a typewriter Additional information: 819 error=65535 txt: '' Tue Jun 10 04:17:51 2008 Errors in file /oracle/app/oracle/admin/sd168/bdump/sd168_ckpt_7597.trc: ORA-00206: error in writing (block 3, # blocks 1) of controlfile ORA-00202: controlfile: '/dev/vg_ora1/rctrl_128m_01' ORA-65535: Message 65535 not found; product=RDBMS; facility=ORA Tue Jun 10 04:17:51 2008 …… |
赶紧请主机工程师也登录上来检查,主机工程师上来之后,重新把VG mount了一次,也重新在db01激活了一次(有做HP的MC双机热备),再次启动数据库,又是报错:
1 2 3 4 5 6 |
SQL> startup ORA-27091: skgfqio: unable to queue I/O ORA-27072: skgfdisp: I/O error HP-UX Error: 6: No such device or address Additional information: 720939 SQL> |
坏了,vg_ora1上的spfile读不出来了,那换备份的pfile,用pfile到nomount,接着到mount时,再次报错:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
SQL> startup nomount pfile='?/dbs/initsd168.ora.bak'; ORACLE instance started. Total System Global Area 6453957408 bytes Fixed Size 746272 bytes Variable Size 2147483648 bytes Database Buffers 4294967296 bytes Redo Buffers 10760192 bytesSQL> alter database mount; alter database mount * ERROR at line 1: ORA-00205: error in identifying controlfile, check alert log for more info SQL> |
查alertlog是控制文件1的问题,ok,在pfile中去掉控制文件1,再次mount,OK,没问题,再次open,报错找不到system的数据文件!!
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 |
SQL> startup nomount pfile='?/dbs/initsd168.ora.bak2'; ORACLE instance started. Total System Global Area 6453957408 bytes Fixed Size 746272 bytes Variable Size 2147483648 bytes Database Buffers 4294967296 bytes Redo Buffers 10760192 bytes SQL> SQL> SQL> alter database mount; Database altered. SQL> alter database open; alter database open * ERROR at line 1: ORA-01122: database file 1 failed verification check ORA-01110: data file 1: '/dev/vg_ora1/rsys_512m_01' ORA-01251: Unknown File Header Version read for file number 1 SQL> |
看来vg_ora1上的lv(裸设备)全完了!!
开始着手恢复措施:一方面,请主机工程师着手vg_ora1的恢复;另一方面,开始在db02上搭建环境,在上面做数据库的恢复。可是,一看备份,寒了,legato的数据库全备不知道被那个兄弟给disable了,最近的一次全备是今年的4月的!要追加2个月的arch,不知道要多久……-_-!!
进一步检查,备份的磁带还被recycle了。当时那个寒呀……
只好寄希望在主机那边的存储恢复了,终于,经过仔细的检查,发现vg_ora1上链路挂错了,重新配置后,数据库启动了……成功!此时已经中午12点半了。
通过这次事故,得到的教训还是很深刻的:
(1)备份高于一切,没有合适的备份,神仙都没办法救。必须保证备份的有效性和时效性。
(2)单点存储很危险,虽然有主机层面的MC双机热备,但是仅仅是存储挂在A机还是挂在B机的区别,要是存储坏了,后果很严重……就算有备份,恢复也是需要一段时间。如果有条件的话,还是做个DG比较安全……
(3)要有合适的还原策略,还原方案、还原脚本必须提前准备妥当,而不是待事故发生以后现场找数据库需要的LV,再划分VG和LV,再编写restore/recover脚本进行还原。
附:HP的诊断报告节选:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 |
•故障过程 2008年6月10日凌晨4:10,PV c14t0d2从系统中消失 Jun 10 04:10:39 sd-db01 vmunix: AUTOPATH : Path 0xbc0a0200 failed! Rerouting toalternate path Jun 10 04:10:39 sd-db01 vmunix: LVM: VG 64 0x010000: Lost quorum. 2008年6月10日凌晨4:17,PVc14t0d2复现,但是并非原先的Vdisk,从而产生“冲突”告警 Jun 10 04:17:48 sd-db01 vmunix: AUTOPATH : LUN collision occurred at:c16t0d2 Jun 10 04:17:48 sd-db01 vmunix: AUTOPATH : LUN collision occurred at:c10t0d2 Jun 10 04:17:48 sd-db01 vmunix: AUTOPATH : LUN collision occurred at:c14t0d2 Jun 10 04:17:48 sd-db01 vmunix: AUTOPATH : LUN collision occurred at:c12t0d2 2008年6月10日凌晨4:29, PV c14t0d6 产生“冲突”告警 Jun 10 04:29:41 sd-db01 vmunix: AUTOPATH : LUN collision occurred at:c14t0d6 2008年6月10日凌晨4:37,惠普响应中心接到贵方主机工程师报修,因为EVA中的Vdisk重新做过present,因而导致相应的vg_ora1不能激活,运行在该VG上的数据库无法启动。 起初受条件限制,惠普响应中心工程师无法直接远程登录系统,但了解到试图激活vg_ora1时,操作系统将有如下报错信息出现: vgchange: Warning: couldn't query physical volume "/dev/dsk/c14t0d2": The specified path does not correspond to physical volume attached to this volume group vgchange: Warning: couldn't query physical volume "/dev/dsk/c16t0d2": The specified path does not correspond to physical volume attached to this volume group vgchange: Warning: couldn't query physical volume "/dev/dsk/c10t0d2": The specified path does not correspond to physical volume attached to this volume group vgchange: Warning: couldn't query physical volume "/dev/dsk/c12t0d2": The specified path does not correspond to physical volume attached to this volume group vgchange: Warning: couldn't query all of the physical volumes. 惠普工程师根据综合判断,指导用户用vgcfgrestore命令,将c14t0d2恢复到vg_ora1中。但由于此时的c14t0d2并非原来vg_ora1中所含PV,因而数据库无法启动。由于忽略了c14t0d2与c14t0d6两PV盘符颠倒,后面大部分时间是在做数据库诊断。 2008年 6月10日早上6:04,贵方主机工程师重新启动主机操作系统,问题依旧。 2008年6月10日早7:12,在使用vgimport命令对vg_ora1进行重建中,系统将盘头信息属于vg_ora1的所有PV同时归于旗下,因而会产生c14t0d2与c14t0d6同时属于该vg的现象。但是vg信息中记录该vg只包含一块PV,因而OS误将c14t0d6作为了c14t0d2的副路径(alternate link)。 Jun 10 07:12:36 sd-db01 LVM[5595]: vgexport -p -s -v -m newvg_ora1.map /dev/vg_ora1 Jun 10 07:13:12 sd-db01 LVM[5616]: vgexport /dev/vg_ora1 Jun 10 07:14:38 sd-db01 LVM[5704]: vgimport -s -v -m ./newvg_ora1.map /dev/vg_ora1 这为后面的进一步排查带来了更大的困难。 2008年6月10日中午12:17,在惠普远程后线专家反复分析检查后,终于发现问题所在,重建vg_ora1并在其后恢复应用。 Jun 10 12:17:02 sd-db01 LVM[14378]: vgexport -p -s -v -m vg_ora1.map /dev/vg_ora 1 Jun 10 12:19:20 sd-db01 LVM[14415]: vgchange -a n vg_ora1 Jun 10 12:19:40 sd-db01 LVM[14488]: vgexport vg_ora1 Jun 10 12:21:57 sd-db01 LVM[14521]: vgimport -m vg_ora1.map /dev/vg_ora1 /dev/ds k/c10t0d6 Jun 10 12:22:37 sd-db01 su: + tg root-oracle Jun 10 12:24:16 sd-db01 LVM[14586]: vgchange -c n vg_ora1 Jun 10 12:25:12 sd-db01 LVM[14675]: vgchange -a y vg_ora1 Jun 10 12:26:38 sd-db01 LVM[14700]: vgextend /dev/vg_ora1 /dev/dsk/c12t0d6 /dev/ dsk/c14t0d6 /dev/dsk/c16t0d6 Jun 10 12:26:38 sd-db01 LVM[14700]: Volume Group configuration for /dev/vg_ora1 has been saved in /etc/lvmconf/vg_ora1.conf •故障分析 根据现场处理过程以及响应中心分析的结果,我们认为造成本次故障是如下原因: 1.对EVA上的Vdisk调整时将正在使用的Vdisk做了unpresent动作 2.重新present时将两个Vdisk顺序颠倒 |
PS:HP的auto path也不是个什么好东西:“在使用vgimport命令对vg_ora1进行重建中,系统将盘头信息属于vg_ora1的所有PV同时归于旗下,因而会产生c14t0d2与c14t0d6同时属于该vg的现象。但是vg信息中记录该vg只包含一块PV,因而OS误将c14t0d6作为了c14t0d2的副路径(alternate link)。”
13条评论
好险啊,连我都能感觉到。。~ 再加一万个小心。。
好紧张哦,体会到了备份高于一切的意思了。
经历了4次心寒。。。。可想而知,当时是多大的打击。
死的心都有了。
当时那个悔啊。不可能的都在瞬间出现了。
。。。
只有经历过这样的事情,人才会成长,才能改变自己的思维以及想法。
备份永远是主要的。
人才都是这么锻炼出来的,这个时候才能体现出我们的价值:)
高手=辛苦的学习+血泪的教训
恭喜,你又想高手的目标迈进一步!
发现vg_ora1上链路挂错了,重新配置后,数据库启动了
请问这是在哪步挂错了?
造成这个问题的最出原因是什么?
re yxyup:见HP的故障报告。
造成这个问题的最出原因是什么?
re yxyup:和auto path的配置原理有关,里面的一些配置很容易引起自动挂载vg的时候有错误的配置。
确实惊险,不过好在有惊无险!
老兄,确实很惊险!
备份高于一切,小心驶得万年船!
学习了! 先努力向你靠近中 o(∩_∩)o…
惊险啊
sd 三墩,zj mobile ? 楼主是和三少 在某oracle服务商 xxx 服务过的吧?