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:2 NOTE: F1X0 copy 3 relocating from 65534:4294967294 to 65534:4294967294 Tue Jun 19 15:37:20 GMT+08:00 2012NOTE: X->S down convert bast on F1B3 bastCount=2 NOTE: X->S down convert bast on F1B3 bastCount=3 NOTE: X->S down convert bast on F1B3 bastCount=4 NOTE: X->S down convert bast on F1B3 bastCount=5 NOTE: X->S down convert bast on F1B3 bastCount=6 NOTE: X->S down convert bast on F1B3 bastCount=7 NOTE: X->S down convert bast on F1B3 bastCount=8 NOTE: X->S down convert bast on F1B3 bastCount=9 NOTE: X->S down convert bast on F1B3 bastCount=10 NOTE: X->S down convert bast on F1B3 bastCount=11 NOTE: X->S down convert bast on F1B3 bastCount=12 NOTE: X->S down convert bast on F1B3 bastCount=13 NOTE: X->S down convert bast on F1B3 bastCount=14 NOTE: X->S down convert bast on F1B3 bastCount=15 NOTE: X->S down convert bast on F1B3 bastCount=16 NOTE: X->S down convert bast on F1B3 bastCount=17 NOTE: X->S down convert bast on F1B3 bastCount=18 NOTE: X->S down convert bast on F1B3 bastCount=19 NOTE: X->S down convert bast on F1B3 bastCount=20 NOTE: X->S down convert bast on F1B3 bastCount=21 Tue 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=1 Tue Jun 19 15:37:42 GMT+08:00 2012NOTE: initializing header on grp 1 disk DATA_0004 NOTE: initializing header on grp 1 disk DATA_0006 NOTE: initializing header on grp 1 disk DATA_0008 NOTE: initializing header on grp 1 disk DATA_0009 NOTE: cache opening disk 4 of grp 1: DATA_0004 path:/dev/rhdiskpower0 NOTE: cache opening disk 6 of grp 1: DATA_0006 path:/dev/rhdiskpower1 NOTE: cache opening disk 8 of grp 1: DATA_0008 path:/dev/rhdiskpower2 NOTE: cache opening disk 9 of grp 1: DATA_0009 path:/dev/rhdiskpower3 NOTE: requesting all-instance disk validation for group=1 Tue 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 = 1 Tue 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=1 Tue 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 = 1 NOTE: requesting all-instance membership refresh for group=1 Tue 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 2 Tue 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 operation Tue Jun 19 15:38:32 GMT+08:00 2012NOTE: stopping process ARB0 Tue 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 10 Starting background process ARB0 Tue Jun 19 15:38:35 GMT+08:00 2012NOTE: PST update: grp = 2 NOTE: requesting all-instance membership refresh for group=2 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB1 ARB0 started with pid=20, OS id=5898374 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB2 ARB1 started with pid=21, OS id=5374366 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB3 ARB2 started with pid=22, OS id=4456744 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB4 ARB3 started with pid=23, OS id=8782054 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB5 ARB4 started with pid=24, OS id=8454504 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB6 ARB5 started with pid=25, OS id=5963930 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB7 ARB6 started with pid=26, OS id=6357166 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB8 ARB7 started with pid=27, OS id=7209164 Tue Jun 19 15:38:35 GMT+08:00 2012Starting background process ARB9 ARB8 started with pid=28, OS id=6488284 Tue 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=5308840 Tue 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:2 NOTE: F1X0 copy 3 relocating from 65534:4294967294 to 65534:4294967294 Tue 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=2 NOTE: X->S down convert bast on F1B3 bastCount=3 NOTE: X->S down convert bast on F1B3 bastCount=4 NOTE: X->S down convert bast on F1B3 bastCount=5 NOTE: X->S down convert bast on F1B3 bastCount=6 NOTE: X->S down convert bast on F1B3 bastCount=7 NOTE: X->S down convert bast on F1B3 bastCount=8 NOTE: X->S down convert bast on F1B3 bastCount=9 Tue 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=10 NOTE: X->S down convert bast on F1B3 bastCount=11 NOTE: X->S down convert bast on F1B3 bastCount=12 NOTE: X->S down convert bast on F1B3 bastCount=13 NOTE: X->S down convert bast on F1B3 bastCount=14 NOTE: X->S down convert bast on F1B3 bastCount=15 NOTE: X->S down convert bast on F1B3 bastCount=16 NOTE: X->S down convert bast on F1B3 bastCount=17 NOTE: X->S down convert bast on F1B3 bastCount=18 NOTE: X->S down convert bast on F1B3 bastCount=19 NOTE: X->S down convert bast on F1B3 bastCount=20 NOTE: X->S down convert bast on F1B3 bastCount=21 Tue Jun 19 15:44:26 GMT+08:00 2012NOTE: cache initiating offline of disk 6 group 1 Tue 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 10496000 Additional information: -1 Tue 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 10500096 Additional information: -1 Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5127 diskname:/dev/rhdiskpower0 Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5125 diskname:/dev/rhdiskpower3 Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: process 7274698 initiating offline of disk 6.3277973293 (DATA_0006) with mask 0x3 in group 1 Tue Jun 19 15:44:26 GMT+08:00 2012 rq:110d431d8 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 Tue Jun 19 15:44:26 GMT+08:00 2012 rq:110d42c90 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 Tue 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 10504192 Additional information: -1 Tue 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:2 Tue Jun 19 15:44:26 GMT+08:00 2012 status:2 Tue Jun 19 15:44:26 GMT+08:00 2012ERROR: failed to copy file +DATA.291, extent 716 Tue Jun 19 15:44:26 GMT+08:00 2012NOTE: PST update: grp = 1, dsk = 6, mode = 0x6 Tue Jun 19 15:44:26 GMT+08:00 2012ERROR: failed to copy file +DATA.291, extent 906 Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5129 diskname:/dev/rhdiskpower1 Tue 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 10479616 Additional information: -1 Tue Jun 19 15:44:26 GMT+08:00 2012 rq:110d42fc8 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 Tue Jun 19 15:44:26 GMT+08:00 2012WARNING: IO Failed. au:5117 diskname:/dev/rhdiskpower2 Tue Jun 19 15:44:26 GMT+08:00 2012 status:2 Tue Jun 19 15:44:26 GMT+08:00 2012ERROR: failed to copy file +DATA.291, extent 1355 Tue Jun 19 15:44:26 GMT+08:00 2012 rq:110d43020 buffer:11086b800 au_offset(bytes):0 iosz:1048576 operation:1 Tue Jun 19 15:44:26 GMT+08:00 2012 status:2 ERROR: failed to copy file +DATA.291, extent 1567 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 2056 Additional information: -1 Tue 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 2056 Additional information: -1 WARNING: 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:2 ERROR: failed to copy file +DATA.291, extent 764 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 2056 Additional information: -1 Tue 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 10498048 Additional information: -1 Tue 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:2 ERROR: failed to copy file +DATA.291, extent 1130 Tue 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:2 ERROR: failed to copy file +DATA.291, extent 582 Tue 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:2 ERROR: failed to copy file +DATA.291, extent 1015 Tue 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:2 ERROR: failed to copy file +DATA.291, extent 1445 Tue 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:2 ERROR: failed to copy file +DATA.291, extent 1243 Tue Jun 19 15:44:28 GMT+08:00 2012NOTE: PST update: grp = 1, dsk = 6, mode = 0x4 Tue 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_0006 Tue Jun 19 15:44:31 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror side NOTE: cache initiating offline of disk 8 group 1 WARNING: process 7274698 initiating offline of disk 8.3277973294 (DATA_0008) with mask 0x3 in group 1 NOTE: PST update: grp = 1, dsk = 8, mode = 0x6 Tue 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 = 0x4 Tue 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_0008 Tue Jun 19 15:44:37 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror side NOTE: cache initiating offline of disk 9 group 1 WARNING: process 7274698 initiating offline of disk 9.3277973295 (DATA_0009) with mask 0x3 in group 1 NOTE: PST update: grp = 1, dsk = 9, mode = 0x6 Tue 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:2 NOTE: cache initiating offline of disk 5 group 2 WARNING: process 5046626 initiating offline of disk 5.3277973287 (SDATA_0005) with mask 0x3 in group 2 NOTE: PST update: grp = 2, dsk = 5, mode = 0x6 Tue 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 = 0x4 Tue 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 = 0x4 Tue 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_0009 Tue Jun 19 15:44:43 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror side NOTE: cache initiating offline of disk 4 group 1 WARNING: process 7274698 initiating offline of disk 4.3277973292 (DATA_0004) with mask 0x3 in group 1 NOTE: PST update: grp = 1, dsk = 4, mode = 0x6 NOTE: cache closing disk 5 of grp 2: SDATA_0005 Tue 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 side Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB8 for group number 1 Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB7 for group number 1 Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB9 for group number 1 Tue 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 disk Tue 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 failed Tue 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 failed Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB6 for group number 1 Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB5 for group number 1 Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB2 for group number 1 Tue 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 disk Tue 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 failed Tue 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 disk Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB3 for group number 1 Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB0 for group number 1 Tue 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 failed Tue 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 disk Tue Jun 19 15:44:43 GMT+08:00 2012NOTE: stopping process ARB7 Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15080 thrown in ARB4 for group number 1 Tue Jun 19 15:44:43 GMT+08:00 2012NOTE: stopping process ARB8 NOTE: stopping process ARB9 NOTE: stopping process ARB6 NOTE: stopping process ARB5 Tue 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 failed NOTE: stopping process ARB2 NOTE: stopping process ARB3 NOTE: stopping process ARB0 NOTE: stopping process ARB4 Tue Jun 19 15:44:43 GMT+08:00 2012ERROR: ORA-15081 thrown in ARB1 for group number 1 Tue 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 disk Tue Jun 19 15:44:43 GMT+08:00 2012NOTE: stopping process ARB1 Tue Jun 19 15:44:46 GMT+08:00 2012NOTE: PST update: grp = 1, dsk = 4, mode = 0x4 Tue 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 = 1 Tue 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_0004 Tue Jun 19 15:44:49 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror side NOTE: cache initiating offline of disk 7 group 2 WARNING: process 7274698 initiating offline of disk 7.3277973289 (SDATA_0007) with mask 0x3 in group 2 NOTE: PST update: grp = 2, dsk = 7, mode = 0x6 Tue 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 = 0x4 Tue 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_0007 Tue Jun 19 15:44:56 GMT+08:00 2012NOTE: DBWR successfully wrote to at least one mirror side Tue 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 = 1 Tue 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:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower16 rq:11087eed0 buffer:110881200 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower20 rq:11087f1e0 buffer:110882400 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower20 rq:11087f1e0 buffer:110882400 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower6 rq:11087f800 buffer:110884800 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower6 rq:11087f800 buffer:110884800 au_offset(bytes):0 iosz:4096 operation:0 status:2 SUCCESS: refreshed membership for 2/0xa15117e7 (SDATA) Tue Jun 19 15:44:56 GMT+08:00 2012NOTE: X->S down convert bast on F1B3 bastCount=22 Tue 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 = 1 Tue 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=1 Tue 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 completed Tue Jun 19 15:45:05 GMT+08:00 2012NOTE: starting rebalance of group 1/0x5e1117e5 (DATA) at power 1 Starting background process ARB0 ARB0 started with pid=20, OS id=10486162 Tue 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:4294967294 NOTE: F1X0 copy 3 relocating from 65534:4294967294 to 65534:4294967294 Tue Jun 19 15:45:05 GMT+08:00 2012NOTE: X->S down convert bast on F1B3 bastCount=2 NOTE: X->S down convert bast on F1B3 bastCount=3 NOTE: X->S down convert bast on F1B3 bastCount=4 NOTE: X->S down convert bast on F1B3 bastCount=5 NOTE: X->S down convert bast on F1B3 bastCount=6 NOTE: X->S down convert bast on F1B3 bastCount=7 NOTE: X->S down convert bast on F1B3 bastCount=8 NOTE: X->S down convert bast on F1B3 bastCount=9 NOTE: X->S down convert bast on F1B3 bastCount=10 NOTE: X->S down convert bast on F1B3 bastCount=11 NOTE: X->S down convert bast on F1B3 bastCount=12 NOTE: X->S down convert bast on F1B3 bastCount=13 NOTE: X->S down convert bast on F1B3 bastCount=14 NOTE: X->S down convert bast on F1B3 bastCount=15 NOTE: X->S down convert bast on F1B3 bastCount=16 NOTE: X->S down convert bast on F1B3 bastCount=17 NOTE: X->S down convert bast on F1B3 bastCount=18 NOTE: X->S down convert bast on F1B3 bastCount=19 NOTE: X->S down convert bast on F1B3 bastCount=20 NOTE: X->S down convert bast on F1B3 bastCount=21 NOTE: cache closing disk 6 of grp 2: SDATA_0006 NOTE: cache closing disk 8 of grp 2: SDATA_0008 NOTE: cache closing disk 9 of grp 2: SDATA_0009 NOTE: X->S down convert bast on F1B3 bastCount=22 Tue 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 completed Tue 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 ARB0 Tue 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 = 1 Tue 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 offline WARNING: offline disk number 5 has references (20926 AUs) SUCCESS: disk number 6 force dropped offline WARNING: offline disk number 7 has references (20924 AUs) SUCCESS: disk number 8 force dropped offline SUCCESS: disk number 9 force dropped offline NOTE: PST update: grp = 1 Tue 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.076 kfgbDoorBellBast: BAST release invoked, gn=1 kfgbDoorBellBast: BAST released, gn=1 NOTE: PST update: grp = 1 kfgbDoorBellArm: value block read: 00000001 *** 2012-06-19 15:44:56.101 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower16 rq:11087eed0 buffer:110881200 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower16 rq:11087eed0 buffer:110881200 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower20 rq:11087f1e0 buffer:110882400 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower20 rq:11087f1e0 buffer:110882400 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower6 rq:11087f800 buffer:110884800 au_offset(bytes):0 iosz:4096 operation:0 status:2 WARNING: IO Failed. au:0 diskname:/dev/rhdiskpower6 rq:11087f800 buffer:110884800 au_offset(bytes):0 iosz:4096 operation:0 status:2 kfgbDoorBellArm: value block read: 00000003 kfgbDoorBellBast: BAST release invoked, gn=1 kfgbDoorBellBast: BAST released, gn=1 kfgbDoorBellArm: value block read: 00000003 kfgbRebalGrp: queued rebalance (power 1) for group 1/0x5e1117e5 (DATA) kfgbDoorBellArm: value block read: 00000003 *** 2012-06-19 15:45:07.568 kfgbDoorBellBast: BAST release invoked, gn=2 kfgbDoorBellBast: BAST released, gn=2 kfgbDoorBellArm: value block read: 00000001 *** 2012-06-19 15:50:38.645 kfgbDoorBellBast: BAST release invoked, gn=2 kfgbDoorBellBast: BAST released, gn=2 kfgbDoorBellArm: value block read: 00000002 *** 2012-06-19 15:55:56.239 kfgbRelease: de-queued rebalance of group 1/0x5e1117e5 (DATA) kfgbDoorBellArm: value block read: 00000003 kfgbExpellNow: checking for empty ASM disks, gn=1 NOTE: PST update: grp = 1 NOTE: PST update: grp = 1 kfgbDoorBellArm: value block modify: 00000004 RDBMS ALERT.LOG Tue 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 1 Tue 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/O ORA-27072: File I/O error IBM AIX RISC System/6000 Error: 5: I/O error Additional information: 7 Additional information: 7871200 Additional information: -1 Tue 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 1 WARNING: 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 1 Tue Jun 19 15:28:39 GMT+08:00 2012SUCCESS: disk DATA_0008 (8.3279471123) dropped from diskgroup DATA SUCCESS: disk DATA_0009 (9.3279471124) dropped from diskgroup DATA Tue 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 instance ORA-03113: end-of-file on communication channel Tue Jun 19 15:35:10 GMT+08:00 2012ASMB: terminating instance due to error 15064 Tue Jun 19 15:35:10 GMT+08:00 2012System state dump is made for local instance System State dumped to trace file /u01/app/oracle/admin/culprodb/bdump/culprodb1_diag_4391248.trc Tue Jun 19 15:35:11 GMT+08:00 2012Shutting down instance (abort) License high water mark = 12 Tue 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 = 5046620 Tue Jun 19 15:35:16 GMT+08:00 2012Instance terminated by USER, pid = 7274646
[…] 10g ASM lost disk log […]