ORA-15081: failed to submit an I/O operation to a disk-存储挂载异常

今天驻地运维的兄弟在QQ上找我，说报告系统的RAC使用不了，Oracle RAC服务无法启动，

现像：

 [oracle@rac1 ~]$ crs_stat -t
CRS-0184: Cannot communicate with the CRS daemon. 

 [oracle@rac2 ~]$ crs_stat -t
CRS-0184: Cannot communicate with the CRS daemon. 

分析 数据库日志：

日志大量报I/O错误，根据经验这是存储层面出现问题，让驻地运维的兄弟去机房看看存储磁盘是不是挂了，10分钟后告诉我，存储电源线松了，我晕，电源竟然不搞冗余，省几千来块钱没必要了！还好这不是生产环境，不然肯定又被批了！

解决：

我让运维的兄弟先把服务器关掉，存储也关掉，先开存储-->（5分钟左右）开启一台DB服务器-(观察RAC服务器起来后)--->再开启另外一台DB服务

数据库RAC服务正常应用 。

2014-10-23 08:00:04.026000 +08:00

Thread 1 advanced to log sequence 273 (LGWR switch)
  Current log# 1 seq# 273 mem# 0: +DATA/reportdb/onlinelog/group_1.297.861203105
2014-10-23 11:30:15.832000 +08:00
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:835804
 iop:0x2b81f05f1000 bufp:0x2b81ef908a00 offset(bytes):876404064256 iosz:16384 operation:1(Read) synchronous:1
 result: 4 osderr:0x3 osderr1:0x2e pid:757
WARNING: failed to read mirror side 1 of virtual extent 4 logical extent 0 of file 300 in group 1 from disk DATA  allocation unit 835804 reason error; if possible,will try another mirror side 
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:835800
 iop:0x2b93fecec000 bufp:0x2b93ff189e00 offset(bytes):876399837184 iosz:16384 operation:1(Read) synchronous:1
 result: 4 osderr:0x3 osderr1:0x2e pid:15697
WARNING: failed to read mirror side 1 of virtual extent 0 logical extent 0 of file 300 in group 1 from disk DATA  allocation unit 835800 reason error; if possible,will try another mirror side 
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:835800
 iop:0x2b726c038dd0 bufp:0x2b726b947e00 offset(bytes):876399869952 iosz:16384 operation:2(Write) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:806
Errors in file /u01/app/oracle/diag/rdbms/reportdb/reportdb1/trace/reportdb1_ckpt_806.trc:
ORA-15080: synchronous I/O operation to a disk failed
WARNING: failed to write mirror side 1 of virtual extent 0 logical extent 0 of file 300 in group 1 on disk 0 allocation unit 835800
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1340069
 iop:0x2acf1ad87c30 bufp:0x2acf46893e00 offset(bytes):1405164191744 iosz:122880 operation:2(Write) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:20870
Errors in file /u01/app/oracle/diag/rdbms/reportdb/reportdb1/trace/reportdb1_ora_20870.trc:
ORA-15080: synchronous I/O operation to a disk failed
WARNING: failed to write mirror side 1 of virtual extent 2045 logical extent 0 of file 299 in group 1 on disk 0 allocation unit 1340069
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:835804
 iop:0x2b81f05f1000 bufp:0x2b81ef908a00 offset(bytes):876404064256 iosz:16384 operation:1(Read) synchronous:1
 result: 4 osderr:0x3 osderr1:0x2e pid:757
WARNING: failed to read mirror side 1 of virtual extent 4 logical extent 0 of file 300 in group 1 from disk DATA  allocation unit 835804 reason error; if possible,will try another mirror side 
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1317163
 iop:0x2abfb9408a50 bufp:0x2abfddf46000 offset(bytes):1381145509888 iosz:262144 operation:1(Read) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:20757
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1040548
 iop:0x2abfb940a920 bufp:0x2abfddc46000 offset(bytes):1091093659648 iosz:262144 operation:1(Read) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:20757
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1040548
-----------------------------node2 alertlog

WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1040548
 iop:0x2abfb940b2b0 bufp:0x2abfddcc6000 offset(bytes):1091094183936 iosz:262144 operation:1(Read) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:20757
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1040548
 iop:0x2abfb94093e0 bufp:0x2abfddd06000 offset(bytes):1091094446080 iosz:262144 operation:1(Read) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:20757
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1317163
 iop:0x2abfb9406410 bufp:0x2abfddf86000 offset(bytes):1381145772032 iosz:262144 operation:1(Read) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:20757
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1317163
 iop:0x2abfb9408830 bufp:0x2abfddfc6000 offset(bytes):1381146034176 iosz:262144 operation:1(Read) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:20757
WARNING: IO Failed. subsys:/opt/oracle/extapi/64/asm/orcl/1/libasm.so dg:1, diskname:ORCL:DATA disk:0x0.0xe968bd99 au:1317163
 iop:0x2abfb940d5c0 bufp:0x2abfde006000 offset(bytes):1381146296320 iosz:262144 operation:1(Read) synchronous:0
 result: 4 osderr:0x3 osderr1:0x2e pid:20757
WARNING: failed to read mirror side 1 of virtual extent 10915 logical extent 0 of file 318 in group 1 from disk DATA  allocation unit 1317163 reason error; if possible,will try another mirror side
WARNING: failed to read mirror side 1 of virtual extent 10540 logical extent 0 of file 309 in group 1 from disk DATA  allocation unit 1040548 reason error; if possible,will try another mirror side
Errors in file /u01/app/oracle/diag/rdbms/reportdb/reportdb1/trace/reportdb1_ckpt_806.trc:
ORA-00206: error in writing (block 3, # blocks 1) of control file
ORA-00202: control file: '+DATA/reportdb/controlfile/current.300.861203103'
ORA-15081: failed to submit an I/O operation to a disk
ORA-15081: failed to submit an I/O operation to a disk
Errors in file /u01/app/oracle/diag/rdbms/reportdb/reportdb1/trace/reportdb1_ckpt_806.trc:
ORA-00221: error on write to control file
ORA-00206: error in writing (block 3, # blocks 1) of control file
ORA-00202: control file: '+DATA/reportdb/controlfile/current.300.861203103'
ORA-15081: failed to submit an I/O operation to a disk
ORA-15081: failed to submit an I/O operation to a disk
CKPT (ospid: 806): terminating the instance due to error 221
System state dump is made for local instance
ORA-1092 : opitsk aborting process
System State dumped to trace file /u01/app/oracle/diag/rdbms/reportdb/reportdb1/trace/reportdb1_diag_745.trc
2014-10-23 11:30:17.953000 +08:00
Trace dumping is performing id=[cdmp_20141023113016]
Instance terminated by CKPT, pid = 806
-------------------------------------asm log
2014-10-17 15:48:57.878000 +08:00
Starting background process ASMB
ASMB started with pid=21, OS id=722
2014-10-17 15:49:03.009000 +08:00
NOTE: ASMB process exiting due to lack of ASM file activity for 5 seconds
2014-10-23 11:30:16.057000 +08:00
WARNING: Disk DATA in mode 0x7f is now being offlined
WARNING: Disk DATA in mode 0x7f offline aborted
Trace dumping is performing id=[cdmp_20141023113016]
2014-10-23 11:30:18.829000 +08:00
NOTE: ASM client reportdb1:reportdb died unexpectedly.
NOTE: ASM client orcl1:orcl died unexpectedly.
NOTE: Process state recorded in trace file /u01/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_ora_822.trc
NOTE: Process state recorded in trace file /u01/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_ora_14782.trc
Trace dumping is performing id=[cdmp_20141023113018]
2014-10-23 11:30:27.118000 +08:00
 Received dirty detach msg from node 1 for dom 1
Dirty detach reconfiguration started (old inc 12, new inc 12)
List of nodes:
 0 1
 Global Resource Directory partially frozen for dirty detach
* dirty detach - domain 1 invalid = TRUE
 4530 GCS resources traversed, 0 cancelled
 7279 GCS shadows traversed, 3614 replayed
Dirty Detach Reconfiguration complete
Trace dumping is performing id=[cdmp_20141023113027]
NOTE: PST enabling heartbeating (grp 1)
2014-10-23 11:30:29.036000 +08:00
Errors in file /u01/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_smon_13847.trc:
ORA-15032: not all alterations performed
ORA-29702: error occurred in Cluster Group Service operation
ORA-29702: error occurred in Cluster Group Service operation
SMON (ospid: 13847): terminating the instance due to error 15032
System state dump is made for local instance
System State dumped to trace file /u01/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_diag_13823.trc
Trace dumping is performing id=[cdmp_20141023113029]
Instance terminated by SMON, pid = 13847