Device doubling at OS level resulting ORA-15196 on ASM level
(Doc ID 2267331.1)
Last updated on OCTOBER 03, 2022
Applies to:
Oracle Database - Enterprise Edition - Version 10.2.0.1 and laterOracle Database Cloud Schema Service - Version N/A and later
Oracle Database Exadata Cloud Machine - Version N/A and later
Oracle Database Exadata Express Cloud Service - Version N/A and later
Oracle Cloud Infrastructure - Database Service - Version N/A and later
Information in this document applies to any platform.
Symptoms
Production diskgroup dismounted with ORA-15196 .
Few diskgroup getting mounted and when client,ie,database tries to access it ,diskgroup is getting dismounted.
SQL> alter diskgroup DG mount
NOTE: cache registered group DG number=7 incarn=0xaba86804
NOTE: cache began mount (not first) of group DG number=7 incarn=0xaba86804
NOTE: Assigning number (7,11) to disk (ORCL:DISK1)
NOTE: Assigning number (7,12) to disk (ORCL:DISK2)
NOTE: Assigning number (7,13) to disk (ORCL:DISK3)
Sun Jun 08 04:10:37 2014
GMON querying group 7 at 20 for pid 44, osid 31774
NOTE: cache opening disk 11 of grp 7: DISK1 label:DISK1 <<-----
NOTE: cache opening disk 12 of grp 7: DISK2 label:DISK2
NOTE: GMON heartbeating for grp 2
GMON querying group 2 at 41 for pid 33, osid 379167
Mon Apr 24 15:24:55 2017
NOTE: cache opening disk 0 of grp 2: DISK4 label:DISK4
NOTE: cache opening disk 1 of grp 2: DISK5 label:DISK5
NOTE: cache opening disk 2 of grp 2: DISK6 label:DISK6
NOTE: cache opening disk 3 of grp 2: DISK7 label:DISK7
NOTE: cache opening disk 4 of grp 2: DISK8 label:DISK8
NOTE: cache opening disk 11 of grp 2: DISK1 label:DISK1
NOTE: cache opening disk 12 of grp 2: DISK2 label:DISK2
NOTE: cache opening disk 13 of grp 2: DISK3 label:DISK3
NOTE: F1X0 found on disk 13 au 2 fcn 0.5440598
NOTE: cache opening disk 14 of grp 2: DISK9 label:DISK9
NOTE: cache opening disk 15 of grp 2: DISK10 label:DISK10
NOTE: cache opening disk 16 of grp 2: DISK11 label:DISK11
NOTE: cache opening disk 17 of grp 2: DISK12 label:DISK12
NOTE: cache opening disk 18 of grp 2: DISK13 label:DISK13
NOTE: cache opening disk 19 of grp 2: DISK14 label:DISK14
NOTE: cache opening disk 20 of grp 2: DISK15 label:DISK15
NOTE: cache opening disk 21 of grp 2: DISK16 label:DISK16
NOTE: cache opening disk 22 of grp 2: DISK17 label:DISK17
NOTE: cache opening disk 23 of grp 2: DISK18 label:DISK18
NOTE: cache mounting (first) external redundancy group 2/0x0DBE0A14 (DG)
* allocate domain 2, invalid = TRUE
kjbdomatt send to inst 4
NOTE: attached to recovery domain 2
NOTE: cache recovered group 2 to fcn 0.7054917
NOTE: redo buffer size is 256 blocks (1053184 bytes)
Mon Apr 24 15:24:55 2017
NOTE: LGWR attempting to mount thread 1 for diskgroup 2 (DG)
NOTE: LGWR found thread 1 closed at ABA 124.3467
NOTE: LGWR mounted thread 1 for diskgroup 2 (DG)
NOTE: LGWR opening thread 1 at fcn 0.7054917 ABA 125.3468
NOTE: cache mounting group 2/0x0DBE0A14 (DG) succeeded
NOTE: cache ending mount (success) of group DG number=2 incarn=0x0dbe0a14
Mon Apr 24 15:24:55 2017
NOTE: Instance updated compatible.asm to 10.1.0.0.0 for grp 2
SUCCESS: diskgroup DG was mounted
SUCCESS: ALTER DISKGROUP DG MOUNT /* asm agent *//* {3:22070:2} */
NOTE: cache dismounted group 2/0x0B899B31 (DG)
SQL> alter diskgroup DG dismount force /* ASM SERVER:193567537 */
Tue Apr 25 21:09:25 2017
Sweep [inc][560235]: completed
System State dumped to trace file <ASM Trace directory>/+ASM3_ora_2118819_i560235.trc
Tue Apr 25 21:09:25 2017
NOTE: cache deleting context for group DG 2/0x0b899b31
Tue Apr 25 21:09:25 2017
Dumping diagnostic data in directory=[cdmp_20170425210925], requested by (instance=3, osid=2118819), summary=[incident=560235].
GMON dismounting group 2 at 225 for pid 56, osid 2118863
NOTE: Disk DISK4 in mode 0x7f marked for de-assignment
NOTE: Disk DISK5 in mode 0x7f marked for de-assignment
NOTE: Disk DISK6 in mode 0x7f marked for de-assignment
NOTE: Disk DISK7 in mode 0x7f marked for de-assignment
NOTE: Disk DISK8 in mode 0x7f marked for de-assignment
NOTE: Disk DISK1 in mode 0x7f marked for de-assignment <<----
NOTE: Disk DISK2 in mode 0x7f marked for de-assignment
NOTE: Disk DISK3 in mode 0x7f marked for de-assignment
NOTE: Disk DISK9 in mode 0x7f marked for de-assignment
NOTE: Disk DISK10 in mode 0x7f marked for de-assignment
NOTE: Disk DISK11 in mode 0x7f marked for de-assignment
NOTE: Disk DISK12 in mode 0x7f marked for de-assignment
NOTE: Disk DISK13 in mode 0x7f marked for de-assignment
NOTE: Disk DISK14 in mode 0x7f marked for de-assignment
NOTE: Disk DISK15 in mode 0x7f marked for de-assignment
NOTE: Disk DISK16 in mode 0x7f marked for de-assignment
Tue Apr 25 21:09:50 2017
SQL> ALTER DISKGROUP ARCH_DG MOUNT /* asm agent *//* {3:36980:15931} */
Tue Apr 25 21:09:56 2017
NOTE: GMON heartbeating for grp 2
GMON querying group 2 at 228 for pid 36, osid 2120954
NOTE: cache opening disk 0 of grp 2: DISK4 label:DISK4
NOTE: cache opening disk 1 of grp 2: DISK5 label:DISK5
NOTE: cache opening disk 2 of grp 2: DISK6 label:DISK6
NOTE: cache opening disk 3 of grp 2: DISK7 label:DISK7
NOTE: cache opening disk 4 of grp 2: DISK8 label:DISK8
NOTE: cache opening disk 11 of grp 2: DISK1 label:DISK1 <<-----
NOTE: cache opening disk 12 of grp 2: DISK2 label:DISK2
NOTE: cache opening disk 13 of grp 2: DISK3 label:DISK3
NOTE: F1X0 found on disk 13 au 2 fcn 0.5440598
As per mount ,its seeing disk DISK1 as 11 th disk for this diskgroup.
From PST we saw there are 24 disks .
From disk directory we see 6 missing disks in FORCING state,
kfddde[4].imbal33[3]: 0 ; 0x8e0: 0x00000000
kfddde[5].entry.incarn: 1 ; 0x8e4: A=1 NUMM=0x0
kfddde[5].entry.hash: 5 ; 0x8e8: 0x00000005 <<----
kfddde[5].entry.refer.number:4294967295 ; 0x8ec: 0xffffffff
kfddde[5].entry.refer.incarn: 0 ; 0x8f0: A=0 NUMM=0x0
kfddde[5].dsknum: 5 ; 0x8f4: 0x0005
kfddde[5].state: 6 ; 0x8f6: KFDSTA_FORCING
kfddde[5].ddchgfl: 0 ; 0x8f7: 0x00
kfddde[5].dskname: DISK1 ; 0x8f8: length=15
kfddde[5].fgname: DISK1 ; 0x918: length=15
kfddde[5].crestmp.hi: 32983092 ; 0x938: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[5].crestmp.lo: 3260072960 ; 0x93c: USEC=0x0 MSEC=0x31 SECS=0x25 MINS=0x30
kfddde[5].failstmp.hi: 0 ; 0x940: HOUR=0x0 DAYS=0x0 MNTH=0x0 YEAR=0x0
kfddde[5].failstmp.lo: 0 ; 0x944: USEC=0x0 MSEC=0x0 SECS=0x0 MINS=0x0
kfddde[5].timer: 0 ; 0x948: 0x00000000
kfddde[5].size: 57341 ; 0x94c: 0x0000dffd
kfddde[5].srRloc.super.hiStart: 0 ; 0x950: 0x00000000
kfddde[5].srRloc.super.loStart: 0 ; 0x954: 0x00000000
kfddde[5].srRloc.super.length: 0 ; 0x958: 0x00000000
kfddde[5].srRloc.incarn: 0 ; 0x95c: 0x00000000
kfddde[5].dskrprtm: 0 ; 0x960: 0x00000000
kfddde[5].start0: 0 ; 0x964: 0x00000000
kfddde[5].size0: 57341 ; 0x968: 0x0000dffd
kfddde[5].used0: 2 ; 0x96c: 0x00000002
kfddde[5].slot: 0 ; 0x970: 0x00000000
kfddde[5].imbal00[0]: 0 ; 0x974: 0x00000000
kfddde[6].entry.incarn: 1 ; 0xaa4: A=1 NUMM=0x0
kfddde[6].entry.hash: 6 ; 0xaa8: 0x00000006
kfddde[6].entry.refer.number:4294967295 ; 0xaac: 0xffffffff
kfddde[6].entry.refer.incarn: 0 ; 0xab0: A=0 NUMM=0x0
kfddde[6].dsknum: 6 ; 0xab4: 0x0006 <<------
kfddde[6].state: 6 ; 0xab6: KFDSTA_FORCING
kfddde[6].ddchgfl: 0 ; 0xab7: 0x00
kfddde[6].dskname: DISK2 ; 0xab8: length=15
kfddde[6].fgname: DISK2 ; 0xad8: length=15
kfddde[6].crestmp.hi: 32983092 ; 0xaf8: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[6].crestmp.lo: 3260072960 ; 0xafc: USEC=0x0 MSEC=0x31 SECS=0x25 MINS=0x30
kfddde[6].failstmp.hi: 0 ; 0xb00: HOUR=0x0 DAYS=0x0 MNTH=0x0 YEAR=0x0
kfddde[6].failstmp.lo: 0 ; 0xb04: USEC=0x0 MSEC=0x0 SECS=0x0 MINS=0x0
kfddde[6].timer: 0 ; 0xb08: 0x00000000
kfddde[6].size: 57341 ; 0xb0c: 0x0000dffd
kfddde[6].srRloc.super.hiStart: 0 ; 0xb10: 0x00000000
kfddde[6].srRloc.super.loStart: 0 ; 0xb14: 0x00000000
kfddde[6].imbal33[2]: 0 ; 0xc5c: 0x00000000
kfddde[6].imbal33[3]: 0 ; 0xc60: 0x00000000
kfddde[7].entry.incarn: 1 ; 0xc64: A=1 NUMM=0x0
kfddde[7].entry.hash: 7 ; 0xc68: 0x00000007
kfddde[7].entry.refer.number:4294967295 ; 0xc6c: 0xffffffff
kfddde[7].entry.refer.incarn: 0 ; 0xc70: A=0 NUMM=0x0
kfddde[7].dsknum: 7 ; 0xc74: 0x0007 <<------
kfddde[7].state: 6 ; 0xc76: KFDSTA_FORCING
kfddde[7].ddchgfl: 0 ; 0xc77: 0x00
kfddde[7].dskname: DISK3 ; 0xc78: length=15
kfddde[7].fgname: DISK3 ; 0xc98: length=15
kfddde[7].crestmp.hi: 32983092 ; 0xcb8: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[7].crestmp.lo: 3260072960 ; 0xcbc: USEC=0x0 MSEC=0x31 SECS=0x25 MINS=0x30
kfddde[7].failstmp.hi: 0 ; 0xcc0: HOUR=0x0 DAYS=0x0 MNTH=0x0 YEAR=0x0
kfddde[7].failstmp.lo: 0 ; 0xcc4: USEC=0x0 MSEC=0x0 SECS=0x0 MINS=0x0
kfddde[7].timer: 0 ; 0xcc8: 0x00000000
kfddde[7].size: 57341 ; 0xccc: 0x0000dffd
kfddde[7].srRloc.super.hiStart: 0 ; 0xcd0: 0x00000000
kfddde[7].srRloc.super.loStart: 0 ; 0xcd4: 0x00000000
kfddde[7].srRloc.super.length: 0 ; 0xcd8: 0x00000000
kfddde[7].srRloc.incarn: 0 ; 0xcdc: 0x00000000
kfddde[7].dskrprtm: 0 ; 0xce0: 0x00000000
kfddde[7].start0: 0 ; 0xce4: 0x00000000
kfddde[7].size0: 57341 ; 0xce8: 0x0000dffd
kfddde[7].used0: 2 ; 0xcec: 0x00000002
kfddde[0].entry.incarn: 1 ; 0x024: A=1 NUMM=0x0
kfddde[0].entry.hash: 8 ; 0x028: 0x00000008
kfddde[0].entry.refer.number:4294967295 ; 0x02c: 0xffffffff
kfddde[0].entry.refer.incarn: 0 ; 0x030: A=0 NUMM=0x0
kfddde[0].dsknum: 8 ; 0x034: 0x0008 <<------
kfddde[0].state: 6 ; 0x036: KFDSTA_FORCING
kfddde[0].ddchgfl: 0 ; 0x037: 0x00
kfddde[0].dskname: DISK1 ; 0x038: length=15
kfddde[0].fgname: DISK1 ; 0x058: length=15
kfddde[0].crestmp.hi: 32983092 ; 0x078: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[0].crestmp.lo: 3761036288 ; 0x07c: USEC=0x0 MSEC=0x337 SECS=0x2 MINS=0x38
kfddde[0].failstmp.hi: 0 ; 0x080: HOUR=0x0 DAYS=0x0 MNTH=0x0 YEAR=0x0
kfddde[0].failstmp.lo: 0 ; 0x084: USEC=0x0 MSEC=0x0 SECS=0x0 MINS=0x0
kfddde[0].timer: 0 ; 0x088: 0x00000000
kfddde[0].size: 57341 ; 0x08c: 0x0000dffd
kfddde[0].srRloc.super.hiStart: 0 ; 0x090: 0x00000000
kfddde[0].srRloc.super.loStart: 0 ; 0x094: 0x00000000
kfddde[0].srRloc.super.length: 0 ; 0x098: 0x00000000
kfddde[0].srRloc.incarn: 0 ; 0x09c: 0x00000000
kfddde[0].dskrprtm: 0 ; 0x0a0: 0x00000000
kfddde[0].imbal33[3]: 0 ; 0x1e0: 0x00000000
kfddde[1].entry.incarn: 1 ; 0x1e4: A=1 NUMM=0x0
kfddde[1].entry.hash: 9 ; 0x1e8: 0x00000009
kfddde[1].entry.refer.number:4294967295 ; 0x1ec: 0xffffffff
kfddde[1].entry.refer.incarn: 0 ; 0x1f0: A=0 NUMM=0x0
kfddde[1].dsknum: 9 ; 0x1f4: 0x0009 <<------
kfddde[1].state: 6 ; 0x1f6: KFDSTA_FORCING
kfddde[1].ddchgfl: 0 ; 0x1f7: 0x00
kfddde[1].dskname: DISK2 ; 0x1f8: length=15
kfddde[1].fgname: DISK2 ; 0x218: length=15
kfddde[1].crestmp.hi: 32983092 ; 0x238: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[1].crestmp.lo: 3761036288 ; 0x23c: USEC=0x0 MSEC=0x337 SECS=0x2 MINS=0x38
kfddde[1].failstmp.hi: 0 ; 0x240: HOUR=0x0 DAYS=0x0 MNTH=0x0 YEAR=0x0
kfddde[1].failstmp.lo: 0 ; 0x244: USEC=0x0 MSEC=0x0 SECS=0x0 MINS=0x0
kfddde[1].timer: 0 ; 0x248: 0x00000000
kfddde[1].size: 57341 ; 0x24c: 0x0000dffd
kfddde[1].srRloc.super.hiStart: 0 ; 0x250: 0x00000000
kfddde[2].dsknum: 10 ; 0x3b4: 0x000a <<------
kfddde[2].state: 6 ; 0x3b6: KFDSTA_FORCING
kfddde[2].ddchgfl: 0 ; 0x3b7: 0x00
kfddde[2].dskname: DISK3 ; 0x3b8: length=15
kfddde[2].fgname: DISK3 ; 0x3d8: length=15
kfddde[2].crestmp.hi: 32983092 ; 0x3f8: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[2].crestmp.lo: 3761036288 ; 0x3fc: USEC=0x0 MSEC=0x337 SECS=0x2 MINS=0x38
kfddde[2].failstmp.hi: 0 ; 0x400: HOUR=0x0 DAYS=0x0 MNTH=0x0 YEAR=0x0
kfddde[2].failstmp.lo: 0 ; 0x404: USEC=0x0 MSEC=0x0 SECS=0x0 MINS=0x0
kfddde[2].timer: 0 ; 0x408: 0x00000000
kfddde[2].size: 57341 ; 0x40c: 0x0000dffd
kfddde[2].srRloc.super.hiStart: 0 ; 0x410: 0x00000000
kfddde[2].srRloc.super.loStart: 0 ; 0x414: 0x00000000
File_name :: DG_DD.lst
And earlier that disk was ungracefully removed.
Line 537: kfddde[5].dskname: DISK1 ; 0x8f8: length=15
Line 538: kfddde[5].fgname: DISK1 ; 0x918: length=15
Line 863: kfddde[0].dskname: DISK1 ; 0x038: length=15
Line 864: kfddde[0].fgname: DISK1 ; 0x058: length=15
Line 1163: kfddde[3].dskname: DISK1 ; 0x578: length=15
Line 1164: kfddde[3].fgname: DISK1 ; 0x598: length=15
kfddde[0].dsknum: 8 ; 0x034: 0x0008
kfddde[0].state: 6 ; 0x036: KFDSTA_FORCING
kfddde[0].ddchgfl: 0 ; 0x037: 0x00
kfddde[0].dskname: DISK1 ; 0x038: length=15
kfddde[0].fgname: DISK1 ; 0x058: length=15
kfddde[0].crestmp.hi: 32983092 ; 0x078: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[0].crestmp.lo: 3761036288 ; 0x07c: USEC=0x0 MSEC=0x337 SECS=0x2 MINS=0x38
kfddde[0].failstmp.hi: 0 ; 0x080: HOUR=0x0 DAYS=0x0 MNTH=0x0 YEAR=0x0
kfddde[0].failstmp.lo: 0 ; 0x084: USEC=0x0 MSEC=0x0 SECS=0x0 MINS=0x0
kfddde[0].timer: 0 ; 0x088: 0x00000000
kfddde[0].size: 57341 ; 0x08c: 0x0000dffd
Disk 5 was created on
kfddde[1].crestmp.hi: 32983092 ; 0x238: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[1].crestmp.lo: 3761036288 ; 0x23c: USEC=0x0 MSEC=0x337 SECS=0x2 MINS=0x38
Disk 11 was created on,
kfddde[3].entry.refer.incarn: 0 ; 0x570: A=0 NUMM=0x0
kfddde[3].dsknum: 11 ; 0x574: 0x000b
kfddde[3].state: 2 ; 0x576: KFDSTA_NORMAL
kfddde[3].ddchgfl: 0 ; 0x577: 0x00
kfddde[3].dskname: DISK1 ; 0x578: length=15
kfddde[3].fgname: DISK1 ; 0x598: length=15
kfddde[3].crestmp.hi: 32983092 ; 0x5b8: HOUR=0x14 DAYS=0x1 MNTH=0x2 YEAR=0x7dd
kfddde[3].crestmp.lo: 3931164672 ; 0x5bc: USEC=0x0 MSEC=0x34 SECS=0x25 MINS=0x3a
kfddde[3].failstmp.hi: 0 ; 0x5c0: HOUR=0x0 DAYS=0x0 MNTH=0x0 YEAR=0x0
all are created on 2013-02-01 20:56 hours. <<----
Resulting ,
Tue Apr 25 22:02:12 2017
NOTE: client prd:prd registered, osid 1444810, mbr 0x2
Tue Apr 25 22:02:23 2017
WARNING: cache read a corrupt block: group=2(DG) dsk=2 blk=115 disk=2 (DISK6) incarn=3915082989 au=0 blk=115 count=1
Errors in file <Trace directory>/+ASM1_ora_1444981.trc:
ORA-15196: invalid ASM block header [kfc.c:26368] [obj_kfbl] [2147483650] [115] [2147483649 != 2147483650]
NOTE: a corrupted block from group DG was dumped to <Trace directory>/+ASM1_ora_1444981.trc
WARNING: cache read (retry) a corrupt block: group=2(DG) dsk=2 blk=115 disk=2 (DISK6) incarn=3915082989 au=0 blk=115 count=1
Errors in file <Trace directory>/+ASM1_ora_1444981.trc:
ORA-15196: invalid ASM block header [kfc.c:26368] [obj_kfbl] [2147483650] [115] [2147483649 != 2147483650]
ORA-15196: invalid ASM block header [kfc.c:26368] [obj_kfbl] [2147483650] [115] [2147483649 != 2147483650]
ERROR: cache failed to read group=2(DG) dsk=2 blk=115 from disk(s): 2(DISK6)
ORA-15196: invalid ASM block header [kfc.c:26368] [obj_kfbl] [2147483650] [115] [2147483649 != 2147483650]
ORA-15196: invalid ASM block header [kfc.c:26368] [obj_kfbl] [2147483650] [115] [2147483649 != 2147483650]
NOTE: cache initiating offline of disk 2 group DG
NOTE: process _user1444981_+asm1 (1444981) initiating offline of disk 2.3915082989 (DISK6) with mask 0x7e in group 2
NOTE: initiating PST update: grp = 2, dsk = 2/0xe95b6ced, mask = 0x6a, op = clear
ASM is looking for wrong block and checksum mismatch of the block.
Changes
Cause
To view full details, sign in with your My Oracle Support account. |
|
Don't have a My Oracle Support account? Click to get started! |
In this Document
| Symptoms |
| Changes |
| Cause |
| Solution |
| References |