10g中存储掉电导致一个failgroup中的asm disk全部丢失，可能导致RDBMS INSTANCE HANG住几秒到一分钟的时间，相关ASM日志如下： alert.log :
Tue Jun 19 15:37:19 GMT+08:00 2012NOTE: assigning ARB0 to group 2/0xa15117e7 (SDATA)Tue Jun 19 15:37:20 GMT+08:00 2012NOTE: F1X0 copy 2 relocating from 10:2 to 9:2NOTE: F1X0 copy 3 relocating from 65534:4294967294 to 65534:4294967294Tue Jun 19 15:37:20 GMT+08:00 2012NOTE: X->S down convert bast on F1B3 bastCount=2NOTE: X->S down convert bast on F1B3 bastCount=3NOTE: X->S down convert bast on F1B3 bastCount=4NOTE: X->S down convert bast on F1B3 bastCount=5NOTE: X->S down convert bast on F1B3 bastCount=6NOTE: X->S down convert bast on F1B3 bastCount=7NOTE: X->S down convert bast on F1B3 bastCount=8NOTE: X->S down convert bast on F1B3 bastCount=9NOTE: X->S down convert bast on F1B3 bastCount=10NOTE: X->S down convert bast on F1B3 bastCount=11NOTE: X->S down convert bast on F1B3 bastCount=12NOTE: X->S down convert bast on F1B3 bastCount=13NOTE: X->S down convert bast on F1B3 bastCount=14NOTE: X->S down convert bast on F1B3 bastCount=15NOTE: X->S down convert bast on F1B3 bastCount=16NOTE: X->S down convert bast on F1B3 bastCount=17NOTE: X->S down convert bast on F1B3 bastCount=18NOTE: X->S down convert bast on F1B3 bastCount=19NOTE: X->S down convert bast on F1B3 bastCount=20NOTE: X->S down convert bast on F1B3 bastCount=21Tue Jun 19 15:37:41 GMT+08:00 2012SQL> alter diskgroup data add failgroup fg2 disk '/dev/rhdiskpower0' force, '/dev/rhdiskpower1' force , '/dev/rhdiskpower2' force , '/dev/rhdiskpower3' force Tue Jun 19 15:37:41 GMT+08:00 2012NOTE: reconfiguration of group 1/0x5e1117e5 (DATA), full=1Tue Jun 19 15:37:42 GMT+08:00 2012NOTE: initializing header on grp 1 disk DATA_0004NOTE: initializing header on grp 1 disk DATA_0006NOTE: initializing header on grp 1 disk DATA_0008NOTE: initializing header on grp 1 disk DATA_0009NOTE: cache opening disk 4 of grp 1: DATA_0004 path:/dev/rhdiskpower0NOTE: cache opening disk 6 of grp 1: DATA_0006 path:/dev/rhdiskpower1NOTE: cache opening disk 8 of grp 1: DATA_0008 path:/dev/rhdiskpower2NOTE: cache opening disk 9 of grp 1: DATA_0009 path:/dev/rhdiskpower3NOTE: requesting all-instance disk validation for group=1Tue Jun 19 15:37:42 GMT+08:00 2012NOTE: disk validation pending for group 1/0x5e1117e5 (DATA)SUCCESS: validated disks for 1/0x5e1117e5 (DATA)Tue Jun 19 15:37:44 GMT+08:00 2012NOTE: PST update: grp = 1Tue Jun 19 15:37:44 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)NOTE: group DATA: relocated PST to: disk 0004 (PST copy 1)Tue Jun 19 15:37:44 GMT+08:00 2012NOTE: requesting all-instance membership refresh for group=1Tue Jun 19 15:37:44 GMT+08:00 2012NOTE: membership refresh pending for group 1/0x5e1117e5 (DATA)SUCCESS: refreshed membership for 1/0x5e1117e5 (DATA)Tue Jun 19 15:38:06 GMT+08:00 2012SQL> alter diskgroup data rebalance power 10 Tue Jun 19 15:38:06 GMT+08:00 2012NOTE: PST update: grp = 1NOTE: requesting all-instance membership refresh for group=1Tue Jun 19 15:38:06 GMT+08:00 2012NOTE: membership refresh pending for group 1/0x5e1117e5 (DATA)SUCCESS: refreshed membership for 1/0x5e1117e5 (DATA)Tue Jun 19 15:38:32 GMT+08:00 2012SQL> alter diskgroup sdata rebalance power 10 Tue Jun 19 15:38:32 GMT+08:00 2012ERROR: ORA-1013 thrown in ARB0 for group number 2Tue Jun 19 15:38:32 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb0_5374362.trc:ORA-01013: user requested cancel of current operationTue Jun 19 15:38:32 GMT+08:00 2012NOTE: stopping process ARB0Tue Jun 19 15:38:35 GMT+08:00 2012NOTE: rebalance interrupted for group 2/0xa15117e7 (SDATA)Tue Jun 19 15:38:35 GMT+08:00 2012NOTE: starting rebalance of group 1/0x5e1117e5 (DATA) at power 10Starting background process ARB0Tue Jun 19 15:38:35 GMT+08:00 2012NOTE: PST update: grp = 2NOTE: requesting all-instance membership refresh for group=2Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB1ARB0 started with pid=20, OS id=5898374Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB2ARB1 started with pid=21, OS id=5374366Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB3ARB2 started with pid=22, OS id=4456744Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB4ARB3 started with pid=23, OS id=8782054Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB5ARB4 started with pid=24, OS id=8454504Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB6ARB5 started with pid=25, OS id=5963930Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB7ARB6 started with pid=26, OS id=6357166Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB8ARB7 started with pid=27, OS id=7209164Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB9ARB8 started with pid=28, OS id=6488284Tue Jun 19 15:38:35 GMT+08:00 2012NOTE: membership refresh pending for group 2/0xa15117e7 (SDATA)NOTE: assigning ARB0 to group 1/0x5e1117e5 (DATA)ARB9 started with pid=29, OS id=5308840Tue Jun 19 15:38:35 GMT+08:00 2012NOTE: assigning ARB1 to group 1/0x5e1117e5 (DATA)NOTE: assigning ARB2 to group 1/0x5e1117e5 (DATA)NOTE: assigning ARB3 to group 1/0x5e1117e5 (DATA)NOTE: assigning ARB4 to group 1/0x5e1117e5 (DATA)NOTE: assigning ARB5 to group 1/0x5e1117e5 (DATA)NOTE: assigning ARB6 to group 1/0x5e1117e5 (DATA)NOTE: assigning ARB7 to group 1/0x5e1117e5 (DATA)Tue Jun 19 15:38:36 GMT+08:00 2012NOTE: F1X0 copy 2 relocating from 5:4294967294 to 9:2NOTE: F1X0 copy 3 relocating from 65534:4294967294 to 65534:4294967294Tue Jun 19 15:38:36 GMT+08:00 2012NOTE: assigning ARB8 to group 1/0x5e1117e5 (DATA)NOTE: assigning ARB9 to group 1/0x5e1117e5 (DATA)Tue Jun 19 15:38:37 GMT+08:00 2012NOTE: X->S down convert bast on F1B3 bastCount=2NOTE: X->S down convert bast on F1B3 bastCount=3NOTE: X->S down convert bast on F1B3 bastCount=4NOTE: X->S down convert bast on F1B3 bastCount=5NOTE: X->S down convert bast on F1B3 bastCount=6NOTE: X->S down convert bast on F1B3 bastCount=7NOTE: X->S down convert bast on F1B3 bastCount=8NOTE: X->S down convert bast on F1B3 bastCount=9Tue Jun 19 15:38:38 GMT+08:00 2012SUCCESS: refreshed membership for 2/0xa15117e7 (SDATA)Tue Jun 19 15:38:39 GMT+08:00 2012NOTE: X->S down convert bast on F1B3 bastCount=10NOTE: X->S down convert bast on F1B3 bastCount=11NOTE: X->S down convert bast on F1B3 bastCount=12NOTE: X->S down convert bast on F1B3 bastCount=13NOTE: X->S down convert bast on F1B3 bastCount=14NOTE: X->S down convert bast on F1B3 bastCount=15NOTE: X->S down convert bast on F1B3 bastCount=16NOTE: X->S down convert bast on F1B3 bastCount=17NOTE: X->S down convert bast on F1B3 bastCount=18NOTE: X->S down convert bast on F1B3 bastCount=19NOTE: X->S down convert bast on F1B3 bastCount=20NOTE: X->S down convert bast on F1B3 bastCount=21Tue Jun 19 15:44:26 GMT+08:00 2012NOTE: cache initiating offline of disk 6 group 1Tue Jun 19 15:44:26 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb4_8454504.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 10496000Additional information: -1Tue Jun 19 15:44:26 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb9_5308840.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 10500096Additional information: -1Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5127 diskname:/dev/rhdiskpower0Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5125 diskname:/dev/rhdiskpower3Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: process 7274698 initiating offline of disk 6.3277973293 (DATA_0006) with mask 0x3 in group 1Tue Jun 19 15:44:26 GMT+08:00 2012 rq:110d431d8 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1Tue Jun 19 15:44:26 GMT+08:00 2012 rq:110d42c90 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1Tue Jun 19 15:44:26 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb5_5963930.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 10504192Additional information: -1Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: Disk 6 in group 1 in mode: 0x7,state: 0x2 will be taken offline (local:y)Tue Jun 19 15:44:26 GMT+08:00 2012 status:2Tue Jun 19 15:44:26 GMT+08:00 2012 status:2Tue Jun 19 15:44:26 GMT+08:00 2012ERROR: failed to copy file +DATA.291, extent 716Tue Jun 19 15:44:26 GMT+08:00 2012NOTE: PST update: grp = 1, dsk = 6, mode = 0x6Tue Jun 19 15:44:26 GMT+08:00 2012ERROR: failed to copy file +DATA.291, extent 906Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5129 diskname:/dev/rhdiskpower1Tue Jun 19 15:44:26 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb3_8782054.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 10479616Additional information: -1Tue Jun 19 15:44:26 GMT+08:00 2012 rq:110d42fc8 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5117 diskname:/dev/rhdiskpower2Tue Jun 19 15:44:26 GMT+08:00 2012 status:2Tue Jun 19 15:44:26 GMT+08:00 2012ERROR: failed to copy file +DATA.291, extent 1355Tue Jun 19 15:44:26 GMT+08:00 2012 rq:110d43020 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1Tue Jun 19 15:44:26 GMT+08:00 2012 status:2ERROR: failed to copy file +DATA.291, extent 1567Tue Jun 19 15:44:26 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_gmon_7602242.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 2056Additional information: -1Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: Disk 4 in group 1 in mode: 0x7,state: 0x2 will be taken offline (local:y)Tue Jun 19 15:44:26 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_gmon_7602242.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 2056Additional information: -1WARNING: Disk 8 in group 1 in mode: 0x7,state: 0x2 will be taken offline (local:y)Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5128 diskname:/dev/rhdiskpower0 rq:110d431d8 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 status:2ERROR: failed to copy file +DATA.291, extent 764Tue Jun 19 15:44:26 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_gmon_7602242.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 2056Additional information: -1Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: Disk 9 in group 1 in mode: 0x7,state: 0x2 will be taken offline (local:y)NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:26 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb7_7209164.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 10498048Additional information: -1Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5126 diskname:/dev/rhdiskpower3 rq:110d42f48 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 status:2ERROR: failed to copy file +DATA.291, extent 1130Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5127 diskname:/dev/rhdiskpower3 rq:110d43258 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 status:2ERROR: failed to copy file +DATA.291, extent 582Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5118 diskname:/dev/rhdiskpower2 rq:110d432d8 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 status:2ERROR: failed to copy file +DATA.291, extent 1015Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5117 diskname:/dev/rhdiskpower2 rq:110d42d10 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 status:2ERROR: failed to copy file +DATA.291, extent 1445Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5129 diskname:/dev/rhdiskpower1 rq:110d42f48 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 status:2ERROR: failed to copy file +DATA.291, extent 1243Tue Jun 19 15:44:28 GMT+08:00 2012NOTE: PST update: grp = 1, dsk = 6, mode = 0x4Tue Jun 19 15:44:28 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)NOTE: cache closing disk 6 of grp 1: DATA_0006Tue Jun 19 15:44:31 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror sideNOTE: cache initiating offline of disk 8 group 1WARNING: process 7274698 initiating offline of disk 8.3277973294 (DATA_0008) with mask 0x3 in group 1NOTE: PST update: grp = 1, dsk = 8, mode = 0x6Tue Jun 19 15:44:31 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:34 GMT+08:00 2012NOTE: PST update: grp = 1, dsk = 8, mode = 0x4Tue Jun 19 15:44:34 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)NOTE: cache closing disk 8 of grp 1: DATA_0008Tue Jun 19 15:44:37 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror sideNOTE: cache initiating offline of disk 9 group 1WARNING: process 7274698 initiating offline of disk 9.3277973295 (DATA_0009) with mask 0x3 in group 1NOTE: PST update: grp = 1, dsk = 9, mode = 0x6Tue Jun 19 15:44:37 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:37 GMT+08:00 2012WARNING: IO Failed. au:16 diskname:/dev/rhdiskpower4 rq:110446a30 buffer:7000000127b4000 au_offset(bytes):770048 iosz:4096 operation:1 status:2NOTE: cache initiating offline of disk 5 group 2WARNING: process 5046626 initiating offline of disk 5.3277973287 (SDATA_0005) with mask 0x3 in group 2NOTE: PST update: grp = 2, dsk = 5, mode = 0x6Tue Jun 19 15:44:38 GMT+08:00 2012WARNING: found another non-responsive disk 9.3277973291 (SDATA_0009) that will be taken offline WARNING: found another non-responsive disk 8.3277973290 (SDATA_0008) that will be taken offline WARNING: found another non-responsive disk 7.3277973289 (SDATA_0007) that will be taken offline WARNING: found another non-responsive disk 6.3277973288 (SDATA_0006) that will be taken offline WARNING: Disk 9 in group 2 in mode: 0x7,state: 0x2 will be taken offline (local:y)WARNING: Disk 8 in group 2 in mode: 0x7,state: 0x2 will be taken offline (local:y)WARNING: Disk 7 in group 2 in mode: 0x7,state: 0x2 will be taken offline (local:y)WARNING: Disk 6 in group 2 in mode: 0x7,state: 0x2 will be taken offline (local:y)NOTE: group SDATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:40 GMT+08:00 2012NOTE: PST update: grp = 1, dsk = 9, mode = 0x4Tue Jun 19 15:44:40 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:40 GMT+08:00 2012NOTE: PST update: grp = 2, dsk = 5, mode = 0x4Tue Jun 19 15:44:40 GMT+08:00 2012NOTE: group SDATA: relocated PST to: disk 0000 (PST copy 0)NOTE: cache closing disk 9 of grp 1: DATA_0009Tue Jun 19 15:44:43 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror sideNOTE: cache initiating offline of disk 4 group 1WARNING: process 7274698 initiating offline of disk 4.3277973292 (DATA_0004) with mask 0x3 in group 1NOTE: PST update: grp = 1, dsk = 4, mode = 0x6NOTE: cache closing disk 5 of grp 2: SDATA_0005Tue Jun 19 15:44:43 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:43 GMT+08:00 2012NOTE: LGWR successfully wrote to at least one mirror sideTue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB8 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB7 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB9 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb8_6488284.trc:ORA-15081: failed to submit an I/O operation to a diskTue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb7_7209164.trc:ORA-15080: synchronous I/O operation to a disk failedTue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb9_5308840.trc:ORA-15080: synchronous I/O operation to a disk failedTue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB6 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB5 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB2 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb6_6357166.trc:ORA-15081: failed to submit an I/O operation to a diskTue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb5_5963930.trc:ORA-15080: synchronous I/O operation to a disk failedTue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb2_4456744.trc:ORA-15081: failed to submit an I/O operation to a diskTue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB3 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB0 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb3_8782054.trc:ORA-15080: synchronous I/O operation to a disk failedTue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb0_5898374.trc:ORA-15081: failed to submit an I/O operation to a diskTue Jun 19 15:44:43 GMT+08:00 2012NOTE: stopping process ARB7Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB4 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012NOTE: stopping process ARB8NOTE: stopping process ARB9NOTE: stopping process ARB6NOTE: stopping process ARB5Tue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb4_8454504.trc:ORA-15080: synchronous I/O operation to a disk failedNOTE: stopping process ARB2NOTE: stopping process ARB3NOTE: stopping process ARB0NOTE: stopping process ARB4Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB1 for group number 1Tue Jun 19 15:44:43 GMT+08:00 2012Errors in file /u01/app/oracle/admin/+ASM/bdump/+asm1_arb1_5374366.trc:ORA-15081: failed to submit an I/O operation to a diskTue Jun 19 15:44:43 GMT+08:00 2012NOTE: stopping process ARB1Tue Jun 19 15:44:46 GMT+08:00 2012NOTE: PST update: grp = 1, dsk = 4, mode = 0x4Tue Jun 19 15:44:46 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:47 GMT+08:00 2012WARNING: rebalance not completed for group 1/0x5e1117e5 (DATA)Tue Jun 19 15:44:47 GMT+08:00 2012SUCCESS: rebalance completed for group 1/0x5e1117e5 (DATA) NOTE: PST update: grp = 1Tue Jun 19 15:44:47 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)NOTE: cache closing disk 4 of grp 1: DATA_0004Tue Jun 19 15:44:49 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror sideNOTE: cache initiating offline of disk 7 group 2WARNING: process 7274698 initiating offline of disk 7.3277973289 (SDATA_0007) with mask 0x3 in group 2NOTE: PST update: grp = 2, dsk = 7, mode = 0x6Tue Jun 19 15:44:50 GMT+08:00 2012NOTE: group SDATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:52 GMT+08:00 2012NOTE: PST update: grp = 2, dsk = 7, mode = 0x4Tue Jun 19 15:44:52 GMT+08:00 2012NOTE: group SDATA: relocated PST to: disk 0000 (PST copy 0)NOTE: cache closing disk 7 of grp 2: SDATA_0007Tue Jun 19 15:44:56 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror sideTue Jun 19 15:44:56 GMT+08:00 2012WARNING: offline disk number 5 has references (10684 AUs)WARNING: offline disk number 7 has references (10676 AUs)NOTE: PST update: grp = 1Tue Jun 19 15:44:56 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:44:56 GMT+08:00 2012WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower16 rq:11087eed0 buffer:110881200 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower16 rq:11087eed0 buffer:110881200 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower20 rq:11087f1e0 buffer:110882400 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower20 rq:11087f1e0 buffer:110882400 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower6 rq:11087f800 buffer:110884800 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower6 rq:11087f800 buffer:110884800 au_offset(bytes):0 iosz:4096 operation:0 status:2SUCCESS: refreshed membership for 2/0xa15117e7 (SDATA)Tue Jun 19 15:44:56 GMT+08:00 2012NOTE: X->S down convert bast on F1B3 bastCount=22Tue Jun 19 15:44:56 GMT+08:00 2012NOTE: membership refresh pending for group 1/0x5e1117e5 (DATA)SUCCESS: refreshed membership for 1/0x5e1117e5 (DATA)Tue Jun 19 15:44:59 GMT+08:00 2012WARNING: PST-initiated drop disk 1(1578178533).4(3277973292) (DATA_0004)NOTE: PST update: grp = 1Tue Jun 19 15:45:00 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:45:00 GMT+08:00 2012NOTE: requesting all-instance membership refresh for group=1Tue Jun 19 15:45:00 GMT+08:00 2012NOTE: membership refresh pending for group 1/0x5e1117e5 (DATA)SUCCESS: refreshed membership for 1/0x5e1117e5 (DATA)Tue Jun 19 15:45:02 GMT+08:00 2012SUCCESS: PST-initiated disk drop completedTue Jun 19 15:45:05 GMT+08:00 2012NOTE: starting rebalance of group 1/0x5e1117e5 (DATA) at power 1Starting background process ARB0ARB0 started with pid=20, OS id=10486162Tue Jun 19 15:45:05 GMT+08:00 2012NOTE: assigning ARB0 to group 1/0x5e1117e5 (DATA)Tue Jun 19 15:45:05 GMT+08:00 2012NOTE: F1X0 copy 2 relocating from 9:2 to 5:4294967294NOTE: F1X0 copy 3 relocating from 65534:4294967294 to 65534:4294967294Tue Jun 19 15:45:05 GMT+08:00 2012NOTE: X->S down convert bast on F1B3 bastCount=2NOTE: X->S down convert bast on F1B3 bastCount=3NOTE: X->S down convert bast on F1B3 bastCount=4NOTE: X->S down convert bast on F1B3 bastCount=5NOTE: X->S down convert bast on F1B3 bastCount=6NOTE: X->S down convert bast on F1B3 bastCount=7NOTE: X->S down convert bast on F1B3 bastCount=8NOTE: X->S down convert bast on F1B3 bastCount=9NOTE: X->S down convert bast on F1B3 bastCount=10NOTE: X->S down convert bast on F1B3 bastCount=11NOTE: X->S down convert bast on F1B3 bastCount=12NOTE: X->S down convert bast on F1B3 bastCount=13NOTE: X->S down convert bast on F1B3 bastCount=14NOTE: X->S down convert bast on F1B3 bastCount=15NOTE: X->S down convert bast on F1B3 bastCount=16NOTE: X->S down convert bast on F1B3 bastCount=17NOTE: X->S down convert bast on F1B3 bastCount=18NOTE: X->S down convert bast on F1B3 bastCount=19NOTE: X->S down convert bast on F1B3 bastCount=20NOTE: X->S down convert bast on F1B3 bastCount=21NOTE: cache closing disk 6 of grp 2: SDATA_0006NOTE: cache closing disk 8 of grp 2: SDATA_0008NOTE: cache closing disk 9 of grp 2: SDATA_0009NOTE: X->S down convert bast on F1B3 bastCount=22Tue Jun 19 15:45:07 GMT+08:00 2012NOTE: membership refresh pending for group 2/0xa15117e7 (SDATA)SUCCESS: refreshed membership for 2/0xa15117e7 (SDATA)Tue Jun 19 15:45:08 GMT+08:00 2012SUCCESS: PST-initiated disk drop completedTue Jun 19 15:50:41 GMT+08:00 2012SUCCESS: refreshed membership for 2/0xa15117e7 (SDATA)Tue Jun 19 15:55:53 GMT+08:00 2012NOTE: stopping process ARB0Tue Jun 19 15:55:56 GMT+08:00 2012WARNING: rebalance not completed for group 1/0x5e1117e5 (DATA)Tue Jun 19 15:55:56 GMT+08:00 2012SUCCESS: rebalance completed for group 1/0x5e1117e5 (DATA) NOTE: PST update: grp = 1Tue Jun 19 15:55:56 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)Tue Jun 19 15:55:56 GMT+08:00 2012SUCCESS: disk number 4 force dropped offlineWARNING: offline disk number 5 has references (20926 AUs)SUCCESS: disk number 6 force dropped offlineWARNING: offline disk number 7 has references (20924 AUs)SUCCESS: disk number 8 force dropped offlineSUCCESS: disk number 9 force dropped offlineNOTE: PST update: grp = 1Tue Jun 19 15:55:56 GMT+08:00 2012NOTE: group DATA: relocated PST to: disk 0000 (PST copy 0)rbal trace:*** 2012-06-19 15:44:56.076kfgbDoorBellBast: BAST release invoked, gn=1kfgbDoorBellBast: BAST released, gn=1NOTE: PST update: grp = 1kfgbDoorBellArm: value block read: 00000001*** 2012-06-19 15:44:56.101WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower16 rq:11087eed0 buffer:110881200 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower16 rq:11087eed0 buffer:110881200 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower20 rq:11087f1e0 buffer:110882400 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower20 rq:11087f1e0 buffer:110882400 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower6 rq:11087f800 buffer:110884800 au_offset(bytes):0 iosz:4096 operation:0 status:2WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower6 rq:11087f800 buffer:110884800 au_offset(bytes):0 iosz:4096 operation:0 status:2kfgbDoorBellArm: value block read: 00000003kfgbDoorBellBast: BAST release invoked, gn=1kfgbDoorBellBast: BAST released, gn=1kfgbDoorBellArm: value block read: 00000003kfgbRebalGrp: queued rebalance (power 1) for group 1/0x5e1117e5 (DATA)kfgbDoorBellArm: value block read: 00000003*** 2012-06-19 15:45:07.568kfgbDoorBellBast: BAST release invoked, gn=2kfgbDoorBellBast: BAST released, gn=2kfgbDoorBellArm: value block read: 00000001*** 2012-06-19 15:50:38.645kfgbDoorBellBast: BAST release invoked, gn=2kfgbDoorBellBast: BAST released, gn=2kfgbDoorBellArm: value block read: 00000002*** 2012-06-19 15:55:56.239kfgbRelease: de-queued rebalance of group 1/0x5e1117e5 (DATA)kfgbDoorBellArm: value block read: 00000003kfgbExpellNow: checking for empty ASM disks, gn=1NOTE: PST update: grp = 1NOTE: PST update: grp = 1kfgbDoorBellArm: value block modify: 00000004RDBMS ALERT.LOGTue Jun 19 15:09:22 GMT+08:00 2012Thread 2 advanced to log sequence 37 (thread recovery)Tue Jun 19 15:15:15 GMT+08:00 2012WARNING: failed to write mirror side 0 of virtual extent 0 of file 280 in group 1 WARNING: process 6029392 initiating offline of disk 9.3279471124 (DATA_0009) with mask 0x3 in group 1Tue Jun 19 15:15:15 GMT+08:00 2012Errors in file /u01/app/oracle/admin/culprodb/bdump/culprodb1_smon_4915536.trc:ORA-27091: unable to queue I/OORA-27072: File I/O errorIBM AIX RISC System/6000 Error: 5: I/O errorAdditional information: 7Additional information: 7871200Additional information: -1Tue Jun 19 15:15:15 GMT+08:00 2012WARNING: failed to read mirror side 1 of virtual extent 32 logical extent 0 of file 284 in group 1 from disk 7 allocation unit 4294967295; if possible, will try another mirror side Tue Jun 19 15:15:15 GMT+08:00 2012WARNING: failed to write mirror side 0 of virtual extent 2 of file 277 in group 1 Tue Jun 19 15:15:15 GMT+08:00 2012WARNING: process 4849996 initiating offline of disk 7.3279471122 (DATA_0007) with mask 0x3 in group 1WARNING: failed to write mirror side 0 of virtual extent 2 of file 277 in group 1 WARNING: process 4849996 initiating offline of disk 7.3279471122 (DATA_0007) with mask 0x3 in group 1Tue Jun 19 15:28:39 GMT+08:00 2012SUCCESS: disk DATA_0008 (8.3279471123) dropped from diskgroup DATASUCCESS: disk DATA_0009 (9.3279471124) dropped from diskgroup DATATue Jun 19 15:35:10 GMT+08:00 2012Errors in file /u01/app/oracle/admin/culprodb/bdump/culprodb1_asmb_5046620.trc:ORA-15064: communication failure with ASM instanceORA-03113: end-of-file on communication channelTue Jun 19 15:35:10 GMT+08:00 2012ASMB: terminating instance due to error 15064Tue Jun 19 15:35:10 GMT+08:00 2012System state dump is made for local instanceSystem State dumped to trace file /u01/app/oracle/admin/culprodb/bdump/culprodb1_diag_4391248.trcTue Jun 19 15:35:11 GMT+08:00 2012Shutting down instance (abort)License high water mark = 12Tue Jun 19 15:35:11 GMT+08:00 2012Trace dumping is performing id=[cdmp_20120619153510]Tue Jun 19 15:35:15 GMT+08:00 2012Instance terminated by ASMB, pid = 5046620Tue Jun 19 15:35:16 GMT+08:00 2012Instance terminated by USER, pid = 7274646