10g ASM lost disk log

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