自动精简配置(Thin Provisioning)导致asm异常

有朋友在一个存储空间给asm使用,发生空间不足,然后使用另外一个存储中的lun给asm的data磁盘组增加asm disk,运行了大概1天之后,asm磁盘组直接dismount,数据库crash.然后就无法正常mount.包括这个存储上的几个其他磁盘组也无法正常mount.
数据库异常日志

Sun Oct 23 08:43:59 2016
SUCCESS: diskgroup DATA was dismounted
SUCCESS: diskgroup DATA was dismounted
Sun Oct 23 08:44:00 2016
Errors in file /oracle/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_lmon_79128.trc:
ORA-00202: control file: '+DATA/orcl/controlfile/current.278.892363163'
ORA-15078: ASM diskgroup was forcibly dismounted
Sun Oct 23 08:44:00 2016
Errors in file /oracle/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_lgwr_79174.trc:
ORA-00345: redo log write error block 15924 count 2
ORA-00312: online log 2 thread 1: '+DATA/orcl/onlinelog/group_2.274.892363167'
ORA-15078: ASM diskgroup was forcibly dismounted
ORA-15078: ASM diskgroup was forcibly dismounted
Errors in file /oracle/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_lgwr_79174.trc:
ORA-00202: control file: '+DATA/orcl/controlfile/current.278.892363163'
ORA-15078: ASM diskgroup was forcibly dismounted
Errors in file /oracle/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_lgwr_79174.trc:
ORA-00204: error in reading (block 1, # blocks 1) of control file
ORA-00202: control file: '+DATA/orcl/controlfile/current.278.892363163'
ORA-15078: ASM diskgroup was forcibly dismounted
Sun Oct 23 08:44:00 2016
LGWR (ospid: 79174): terminating the instance due to error 204
Sun Oct 23 08:44:00 2016
opiodr aborting process unknown ospid (79742) as a result of ORA-1092
Sun Oct 23 08:44:01 2016
ORA-1092 : opitsk aborting process
Sun Oct 23 08:44:01 2016
ORA-1092 : opitsk aborting process
System state dump requested by (instance=1, osid=79174 (LGWR)), summary=[abnormal instance termination].
System State dumped to trace file /oracle/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_diag_79118.trc
Instance terminated by LGWR, pid = 79174

很明显,数据库异常是由于asm diskgroup dismount,因此分析asm 日志

asm 日志

Sun Oct 23 07:00:31 2016
Time drift detected. Please check VKTM trace file for more details.
Sun Oct 23 08:43:55 2016
Errors in file /oracle/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_arb0_8755.trc:
ORA-27061: waiting for async I/Os failed
Linux-x86_64 Error: 5: Input/output error
Additional information: -1
Additional information: 1048576
WARNING: Write Failed. group:1 disk:2 AU:1222738 offset:0 size:1048576
ERROR: failed to copy file +DATA.524, extent 15030
ERROR: ORA-15080 thrown in ARB0 for group number 1
Errors in file /oracle/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_arb0_8755.trc:
ORA-15080: synchronous I/O operation to a disk failed
Sun Oct 23 08:43:55 2016
NOTE: stopping process ARB0
NOTE: rebalance interrupted for group 1/0xec689cdd (DATA)
NOTE: ASM did background COD recovery for group 1/0xec689cdd (DATA)
NOTE: starting rebalance of group 1/0xec689cdd (DATA) at power 1
Starting background process ARB0
Sun Oct 23 08:43:56 2016
ARB0 started with pid=24, OS id=103554 
NOTE: assigning ARB0 to group 1/0xec689cdd (DATA) with 1 parallel I/O
Errors in file /oracle/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_arb0_103554.trc:
ORA-27061: waiting for async I/Os failed
Linux-x86_64 Error: 5: Input/output error
Additional information: -1
Additional information: 1048576
WARNING: Write Failed. group:1 disk:2 AU:1222738 offset:0 size:1048576
ERROR: failed to copy file +DATA.256, extent 6570
ERROR: ORA-15080 thrown in ARB0 for group number 1
Errors in file /oracle/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_arb0_103554.trc:
ORA-15080: synchronous I/O operation to a disk failed
NOTE: stopping process ARB0
Sun Oct 23 08:43:58 2016
Errors in file /oracle/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_dbw0_8521.trc:
ORA-27061: waiting for async I/Os failed
Linux-x86_64 Error: 5: Input/output error
Additional information: -1
Additional information: 4096
WARNING: Write Failed. group:1 disk:3 AU:6789 offset:24576 size:4096
NOTE: cache initiating offline of disk 3 group DATA
NOTE: process _dbw0_+asm1 (8521) initiating offline of disk 3.3915934787 (DATA_0003) with mask 0x7e in group 1
Sun Oct 23 08:43:58 2016
WARNING: Disk 3 (DATA_0003) in group 1 mode 0x7f is now being offlined
WARNING: Disk 3 (DATA_0003) in group 1 in mode 0x7f is now being taken offline on ASM inst 1
NOTE: initiating PST update: grp = 1, dsk = 3/0xe9686c43, mask = 0x6a, op = clear
GMON updating disk modes for group 1 at 14 for pid 14, osid 8521
ERROR: Disk 3 cannot be offlined, since diskgroup has external redundancy.
ERROR: too many offline disks in PST (grp 1)
Sun Oct 23 08:43:58 2016
NOTE: cache dismounting (not clean) group 1/0xEC689CDD (DATA) 
NOTE: messaging CKPT to quiesce pins Unix process pid: 103577, image: oracle@node1 (B000)
WARNING: Disk 3 (DATA_0003) in group 1 mode 0x7f offline is being aborted
WARNING: Offline of disk 3 (DATA_0003) in group 1 and mode 0x7f failed on ASM inst 1
NOTE: halting all I/Os to diskgroup 1 (DATA)
Sun Oct 23 08:43:59 2016
NOTE: LGWR doing non-clean dismount of group 1 (DATA)
NOTE: LGWR sync ABA=160.10145 last written ABA 160.10145

错误信息很明显,由于Write Failed导致asm diskgroup dismount.

系统日志

Oct 23 08:43:55 node1 kernel: sd 6:0:12:1: [sdd]  Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 23 08:43:55 node1 kernel: sd 6:0:12:1: [sdd]  Sense Key : Data Protect [current] 
Oct 23 08:43:55 node1 kernel: sd 6:0:12:1: [sdd]  Add. Sense: Space allocation failed write protect
Oct 23 08:43:55 node1 kernel: sd 6:0:12:1: [sdd] CDB: Write(16): 8a 00 00 00 00 02 e7 18 37 f9 00 00 00 07 00 00
Oct 23 08:43:55 node1 kernel: end_request: critical space allocation error, dev sdd, sector 12467058681
Oct 23 08:43:55 node1 kernel: end_request: critical space allocation error, dev dm-3, sector 12467058681
Oct 23 08:43:55 node1 kernel: sd 8:0:6:1: [sdh]  Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 23 08:43:55 node1 kernel: sd 8:0:6:1: [sdh]  Sense Key : Data Protect [current] 
Oct 23 08:43:55 node1 kernel: sd 8:0:6:1: [sdh]  Add. Sense: Space allocation failed write protect
Oct 23 08:43:55 node1 kernel: sd 8:0:6:1: [sdh] CDB: Write(16): 8a 00 00 00 00 02 e7 18
Oct 23 08:43:55 node1 kernel: sd 6:0:4:1: [sdb]  Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 23 08:43:55 node1 kernel: sd 6:0:4:1: [sdb]  Sense Key : Data Protect [current] 
Oct 23 08:43:55 node1 kernel: sd 6:0:4:1: [sdb]   33Add. Sense: Space allocation failed write protect
Oct 23 08:43:55 node1 kernel: sd 6:0:4:1: [sdb] CDB: Write(16): 8a 00 00 00 00 02 e7 18 30 00 00 00 03 f9 00 00
Oct 23 08:43:55 node1 kernel: end_request: critical space allocation error, dev sdb, sector 12467056640
Oct 23 08:43:55 node1 kernel: f9 00 00 04 00
Oct 23 08:43:55 node1 kernel: end_request: critical space allocation error, dev dm-3, sector 12467056640
Oct 23 08:43:55 node1 kernel: 00 00
Oct 23 08:43:55 node1 kernel: end_request: critical space allocation error, dev sdh, sector 12467057657
Oct 23 08:43:55 node1 kernel: end_request: critical space allocation error, dev dm-3, sector 12467057657
Oct 23 08:43:57 node1 kernel: sd 8:0:6:1: [sdh]  Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 23 08:43:57 node1 kernel: sd 8:0:6:1: [sdh]  Sense Key : Data Protect [current] 
Oct 23 08:43:57 node1 kernel: sd 8:0:6:1: [sdh]  Add. Sense: Space allocation failed write protect
Oct 23 08:43:57 node1 kernel: sd 8:0:6:1: [sdh] CDB: Write(16): 8a 00 00 00 00 02 e7 18 37 f9 00 00 00 07 00 00
Oct 23 08:43:57 node1 kernel: end_request: critical space allocation error, dev sdh, sector 12467058681
Oct 23 08:43:57 node1 kernel: end_request: critical space allocation error, dev dm-3, sector 12467058681
Oct 23 08:43:57 node1 kernel: sd 8:0:12:1: [sdj]  Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 23 08:43:57 node1 kernel: sd 8:0:12:1: [sdj]  Sense Key : Data Protect [current] 
Oct 23 08:43:57 node1 kernel: sd 8:0:12:1: [sdj]  Add. Sense: Space allocation failed write protect
Oct 23 08:43:57 node1 kernel: sd 8:0:12:1: [sdj] CDB: Write(16): 8a 00 00 00 00 02 e7 18 30 00 00 00 03 f9 00 00
Oct 23 08:43:57 node1 kernel: end_request: critical space allocation error, dev sdj, sector 12467056640
Oct 23 08:43:57 node1 kernel: end_request: critical space allocation error, dev dm-3, sector 12467056640
Oct 23 08:43:57 node1 kernel: sd 6:0:4:1: [sdb]  Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 23 08:43:57 node1 kernel: sd 6:0:4:1: [sdb]  Sense Key : Data Protect [current] 
Oct 23 08:43:57 node1 kernel: sd 6:0:4:1: [sdb]  Add. Sense: Space allocation failed write protect
Oct 23 08:43:57 node1 kernel: sd 6:0:4:1: [sdb] CDB: Write(16): 8a 00 00 00 00 02 e7 18 33 f9 00 00 04 00 00 00
Oct 23 08:43:58 node1 kernel: sd 6:0:4:1: [sdb]  Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 23 08:43:58 node1 kernel: sd 6:0:4:1: [sdb]  Sense Key : Data Protect [current] 
Oct 23 08:43:58 node1 kernel: sd 6:0:4:1: [sdb]  Add. Sense: Space allocation failed write protect
Oct 23 08:43:58 node1 kernel: sd 6:0:4:1: [sdb] CDB: Write(16): 8a 00 00 00 00 03 3b 7e 78 30 00 00 00 08 00 00
Oct 23 10:50:59 node1 init: oracle-ohasd main process (6150) killed by TERM signal

错误信息为:critical space allocation error,严重空间分配错误.也就是linux在分配空间之时发生错误.在换而言之,由于分配空间错误导致asm 磁盘组dismount.

查看多路径信息

[root@node1 ~]# multipath -ll
36000d31003190c000000000000000003 dm-3 COMPELNT,Compellent Vol
size=80T features='1 queue_if_no_path' hwhandler='0' wp=rw
`-+- policy='round-robin 0' prio=1 status=active
  |- 6:0:9:1  sdd 8:48  active ready running
  `- 8:0:9:1  sdi 8:128 active ready running
delldisk2 (36000d310031908000000000000000003) dm-4 COMPELNT,Compellent Vol
size=8.0T features='1 queue_if_no_path' hwhandler='0' wp=rw
`-+- policy='round-robin 0' prio=1 status=active
  |- 6:0:12:1 sde 8:64  active ready running
  |- 8:0:6:1  sdh 8:112 active ready running
  |- 6:0:4:1  sdb 8:16  active ready running
  `- 8:0:12:1 sdj 8:144 active ready running
delldisk1 (36000d31003190a000000000000000007) dm-2 COMPELNT,Compellent Vol
size=12T features='1 queue_if_no_path' hwhandler='0' wp=rw
`-+- policy='round-robin 0' prio=1 status=active
  |- 6:0:1:1  sda 8:0   active ready running
  |- 8:0:2:1  sdf 8:80  active ready running
  |- 6:0:7:1  sdc 8:32  active ready running
  `- 8:0:3:1  sdg 8:96  active ready running

很明显报错的都是同一个lun(delldisk2),也就是存储空间使用完的存储.也就是说,由于delldisk2存储的空间使用尽了导致系统出现分配空间错误,从而导致asm 写失败,进而导致数据库异常.这种问题的本质其实就是存储给系统分配了8T,但是实际存储可以使用的空间不足8T,而os按照8T来使用从而出现该问题.专业名字叫做”存储精简卷”.因此各位在存储配置之时需要注意该问题.因为这种情况的出现一般只是写io异常,读依旧正常,因此不会丢失数据.

kfed read asm disk header

kfed读取数据磁盘头主要参数解释说明

   % kfed read /dev/raw/raw1
     
   kfbh.endian:                          1 ; 0x000: 0x01
   kfbh.hard:                          130 ; 0x001: 0x82
   kfbh.type:                            1 ; 0x002: KFBTYP_DISKHEAD
   kfbh.datfmt:                          1 ; 0x003: 0x01
   kfbh.block.blk:                       0 ; 0x004: T=0 NUMB=0x0
   kfbh.block.obj:              2147483648 ; 0x008: TYPE=0x8 NUMB=0x0
   kfbh.check:                  2932902794 ; 0x00c: 0xaed08b8a
   kfbh.fcn.base:                        0 ; 0x010: 0x00000000
   kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
   kfbh.spare1:                          0 ; 0x018: 0x00000000
   kfbh.spare2:                          0 ; 0x01c: 0x00000000
   kfdhdb.driver.provstr:         ORCLDISK ; 0x000: length=8
   kfdhdb.driver.reserved[0]:            0 ; 0x008: 0x00000000
   kfdhdb.driver.reserved[1]:            0 ; 0x00c: 0x00000000
   kfdhdb.driver.reserved[2]:            0 ; 0x010: 0x00000000
   kfdhdb.driver.reserved[3]:            0 ; 0x014: 0x00000000
   kfdhdb.driver.reserved[4]:            0 ; 0x018: 0x00000000
   kfdhdb.driver.reserved[5]:            0 ; 0x01c: 0x00000000
   kfdhdb.compat:                168820736 ; 0x020: 0x0a100000
   kfdhdb.dsknum:                        0 ; 0x024: 0x0000
   kfdhdb.grptyp:                        1 ; 0x026: KFDGTP_EXTERNAL
   kfdhdb.hdrsts:                        3 ; 0x027: KFDHDR_MEMBER
   kfdhdb.dskname:              ASM01_0000 ; 0x028: length=10
   kfdhdb.grpname:                   ASM01 ; 0x048: length=5
   kfdhdb.fgname:               ASM01_0000 ; 0x068: length=10
   kfdhdb.capname:                         ; 0x088: length=0
   kfdhdb.crestmp.hi:             32837774 ; 0x0a8: HOUR=0xe DAYS=0x4 MNTH=0x4 YEAR=0x7d4
   kfdhdb.crestmp.lo:           1555722240 ; 0x0ac: USEC=0x0 MSEC=0x29c SECS=0xb MINS=0x17
   kfdhdb.mntstmp.hi:             32837774 ; 0x0b0: HOUR=0xe DAYS=0x4 MNTH=0x4 YEAR=0x7d4
   kfdhdb.mntstmp.lo:           1563864064 ; 0x0b4: USEC=0x0 MSEC=0x1ab SECS=0x13 MINS=0x17
   kfdhdb.secsize:                     512 ; 0x0b8: 0x0200
   kfdhdb.blksize:                    4096 ; 0x0ba: 0x1000
   kfdhdb.ausize:                  1048576 ; 0x0bc: 0x00100000
   kfdhdb.mfact:                    113792 ; 0x0c0: 0x0001bc80
   kfdhdb.dsksize:                    9075 ; 0x0c4: 0x00002373
   kfdhdb.pmcnt:                         2 ; 0x0c8: 0x00000002
   kfdhdb.fstlocn:                       1 ; 0x0cc: 0x00000001
   kfdhdb.altlocn:                       2 ; 0x0d0: 0x00000002
   kfdhdb.f1b1locn:                      2 ; 0x0d4: 0x00000002
   kfdhdb.redomirrors[0]:                0 ; 0x0d8: 0x0000
   kfdhdb.redomirrors[1]:                0 ; 0x0da: 0x0000
   kfdhdb.redomirrors[2]:                0 ; 0x0dc: 0x0000
   kfdhdb.redomirrors[3]:                0 ; 0x0de: 0x0000
   kfdhdb.ub4spare[0]:                   0 ; 0x0e0: 0x00000000
   ...
   kfdhdb.ub4spare[60]:                  0 ; 0x1d0: 0x00000000
   kfdhdb.acdb.aba.seq:                  0 ; 0x1d4: 0x00000000
   kfdhdb.acdb.aba.blk:                  0 ; 0x1d8: 0x00000000
   kfdhdb.acdb.ents:                     0 ; 0x1dc: 0x0000
   kfdhdb.acdb.ub2spare:                 0 ; 0x1de: 0x0000
 
  Breakdown:

   kfbh.endian  
     kf3.h   /* endianness of writer */ 
       Little endian = 1  
       Big endian = 0
  
   kfbh.hard    
     kf3.h   /* H.A.R.D. magic # and block size */  

  kfbh.type
    kf3.h    /* metadata block type               */

  kfbh.datfmt
    kf3.h   /* metadata block data format        */

  kfbh.block
    kf3.h   /* block location of this block      */
      blk -- Disk header should have T=0 and NUMB=0x0
      obj -- Disk header should have TYPE=0x8 NUMB=<disknumber>
    blk and obj values are derived from a series of macros in kf3.h.  See 
    "KFBL Macros" in kf3.h for more information.

  kfbh.check
    kf3.h   /* check value to verify consistency */

  kfbh.fcn
    kf3.h   /* change number of last change      */
     
  kfdhdb.driver
    kf3.h   /* OSMLIB driver reserved block  */
       If no driver is defined "ORCLDISK" is used.  
      
  kfdhdb.compat
    kf3.h   /* Comaptible software version   */
      example: 0x0a100000 
      You get:      
          a=10 1=1 so 10.1.0.0.0

  kfdhdb.dsknum
    kf3.h   /* OSM disk number               *
      This is the disk number.  The first disk being "0".  There can be up to
      ub2 disks in a diskgroup.  This allows for 65336 disks 0 through 65335.

  kfdhdb.grptyp
    kf3.h   /* Disk group type               */

  kfdhdb.hdrsts
    kf3.h   /* Disk header status            */
      This is what is used to determine if a disk is available or not to 
      the diskgroup.  0x03 is the correct value for a valid status.

  kfdhdb.dskname   /* OSM disk name       */
  kfdhdb.grpname   /* OSM disk group name */
  kfdhdb.fgname    /* Failure group name  */
  kfdhdb.capname   /* Capacity grp, unused*/
    kf3.h 

  kfdhdb.crestmp   /* Creation timestamp            */
  kfdhdb.mntstmp   /* Mount timestamp               */
    kf3.h To derive the hi and low time`from an unformated dump use the 
    "KFTS Macros" in kf3.h.

  kfdhdb.secsize
    kf3.h   /* Disk sector size (bytes)      */
      This is the physical sector size of the disk in bytes. All I/O's to the
      disk are described in physical sectors. This must be a power of 2. An
      ideal value would be 4096, but most disks are formatted with 512 byte
      sectors. (from asmlib.h)

  kfdhdb.blksize
    kf3.h   /* Metadata block (bytes)        */
       
  kfdhdb.ausize
    kf3.h   /* Allocation Unit (bytes)       */

  kfdhdb.mfact 
    kf3.h   /* Stride between phys addr AUs  */
     
  kfdhdb.dsksize
    kf3.h   /* Disk size in AUs              */
      Mulitply by AUs to get actual size of disk when added.  
         
  kfdhdb.pmcnt
    kf3.h   /* Permanent phys addressed AUs  */
      Number of physically addressed allocation units.

  kfdhdb.fstlocn
    kf3.h   /* First FreeSpace table blk num */
      Used to find freespace.

  kfdhdb.altlocn
    kf3.h   /* First Alocation table blk num */
      Used to find alocated space.

  kfdhdb.f1b1locn
    kf3.h   /* File Directory blk 1 AU num   */
      Beginging for file directory.

oracle asm系列文章汇总—www.xifenfie.com

为了方便大家更容易的查看相关asm内容,今天(2016年7月28日)对asm的相关文章进行了汇总整理.如果有asm相关的其他问题,可以通过手机(17813235971)或者QQ(107644445)交流
远程访问ASM
ASMCMD常用命令
ASM简单管理(1)
ASM简单管理(2)
找回ASM中数据文件
bbed修改ASM中数据
ASM迁移至文件系统
普通库迁移至ASM存储
使用dd复制asm中文件
配置Oracle ASM磁盘
ASM中磁盘组权限设置
监控asm disk磁盘性能
create spfile to asm
pvid=yes导致asm无法mount—ASM恢复案例
asm数据文件迁移(os–>asm)
asm数据文件迁移(asm–>asm)
asm数据文件迁移(asm–>os)
asm disk格式化为ntfs恢复—ASM恢复案例
通过ftp/http拷贝asm中文件
ASM DISK HEADER 备份与恢复
手工修复ASM DISK HEADER 异常
asm disk header 彻底损坏恢复—ASM恢复案例
ASM未正常启动,使用dd找回数据文件
asm disk被格式化为ext4文件系统恢复—ASM恢复案例
ORACLE 12C ASM 新特性:共享密码文件
asm备份元数据之md_backup和md_restore
分区无法识别导致asm diskgroup无法mount—ASM恢复案例
使用losetup实现linux普通文件做asm disk
Oracle异常恢复前备份保护现场建议—ASM环境
多cpu环境中运行root.sh失败,asm报ORA-04031
asmlib异常报ORA-00600[kfklLibFetchNext00]
因asm sga_target设置不当导致11gr2 rac无法正常启动
asm disk误设置pvid导致asm diskgroup无法mount恢复—ASM恢复案例
使用_asm_allow_only_raw_disks实现普通文件做asm disk
ORACLE 12C RAC修改ocr/votedisk/asm spfile所在磁盘组名称
使用asm disk header 自动备份信息恢复异常asm disk header
分享oracleasm createdisk重新创建asm disk后数据0丢失恢复案例—ASM恢复案例
ADHU(ASM Disk Header Utility)—asm disk header备份恢复工具
How to Get the Contents of an Spfile on ASM when ASM/GRID is down
ORA-15042: ASM disk “N” is missing from group number “M” 故障恢复—ASM恢复案例

分区无法识别导致asm diskgroup无法mount

有客户咨询由于主机重启之后,导致四个磁盘组中的data2磁盘组无法mount(报ORA-15032,ORA-15017,ORA-15063),数据库无法open,让我们帮忙分析解决

Wed Mar 09 18:10:53 2016
NOTE: Assigning number (1,1) to disk (/dev/oracleasm/disks/VOL011)
Wed Mar 09 18:10:53 2016
ERROR: no read quorum in group: required 1, found 0 disks
NOTE: cache dismounting (clean) group 1/0xBD42B778 (DATA2) 
NOTE: messaging CKPT to quiesce pins Unix process pid: 45093, image: oracle@BA (TNS V1-V3)
NOTE: dbwr not being msg'd to dismount
NOTE: lgwr not being msg'd to dismount
NOTE: cache dismounted group 1/0xBD42B778 (DATA2) 
NOTE: cache ending mount (fail) of group DATA2 number=1 incarn=0xbd42b778
NOTE: cache deleting context for group DATA2 1/0xbd42b778
GMON dismounting group 1 at 16 for pid 18, osid 45093
NOTE: Disk DATA2_0001 in mode 0x9 marked for de-assignment
ERROR: diskgroup DATA2 was not mounted
ORA-15032: not all alterations performed
ORA-15017: diskgroup "DATA2" cannot be mounted
ORA-15063: ASM discovered an insufficient number of disks for diskgroup "DATA2"
ERROR: ALTER DISKGROUP DATA2 MOUNT  /* asm agent *//* {0:0:431} */

这里很明显由于缺少asm disk导致data2无法正常mount,进一步分析发现data2是有两块磁盘组成

Mon Sep 14 13:14:35 2015
SQL> create diskgroup data2 external redundancy  disk '/dev/oracleasm/disks/VOL010','/dev/oracleasm/disks/VOL011' 
NOTE: Assigning number (4,0) to disk (/dev/oracleasm/disks/VOL010)
NOTE: Assigning number (4,1) to disk (/dev/oracleasm/disks/VOL011)
NOTE: initializing header on grp 4 disk DATA2_0000
NOTE: initializing header on grp 4 disk DATA2_0001
NOTE: initiating PST update: grp = 4
Mon Sep 14 13:14:35 2015
GMON updating group 4 at 29 for pid 26, osid 51535
NOTE: group DATA2: initial PST location: disk 0000 (PST copy 0)
NOTE: PST update grp = 4 completed successfully 
NOTE: cache registered group DATA2 number=4 incarn=0xea085f62
NOTE: cache began mount (first) of group DATA2 number=4 incarn=0xea085f62
NOTE: cache opening disk 0 of grp 4: DATA2_0000 path:/dev/oracleasm/disks/VOL010
NOTE: cache opening disk 1 of grp 4: DATA2_0001 path:/dev/oracleasm/disks/VOL011
NOTE: cache creating group 4/0xEA085F62 (DATA2)
NOTE: cache mounting group 4/0xEA085F62 (DATA2) succeeded
NOTE: allocating F1X0 on grp 4 disk DATA2_0000
NOTE: diskgroup must now be re-mounted prior to first use
NOTE: cache dismounting (clean) group 4/0xEA085F62 (DATA2) 
NOTE: messaging CKPT to quiesce pins Unix process pid: 51535, image: oracle@BA (TNS V1-V3)
NOTE: lgwr not being msg'd to dismount
NOTE: cache dismounted group 4/0xEA085F62 (DATA2) 
GMON dismounting group 4 at 30 for pid 26, osid 51535
GMON dismounting group 4 at 31 for pid 26, osid 51535
NOTE: Disk DATA2_0000 in mode 0x7e marked for de-assignment
NOTE: Disk DATA2_0001 in mode 0x7e marked for de-assignment
SUCCESS: diskgroup DATA2 was created

结合这部分信息,我们可以确定data2磁盘组是由两个磁盘组构成,分别为VOL010和VOL011,现在由于只发现了VOL011,因此data2磁盘组无法正常mount.观察发现该系统使用的是asmlib,通过oracleasm querydisk命令结合fdisk的盘符,
oracleasm-querydisk


基本上可以确定VOL010丢失应该在mpathb盘(由于只有该盘和分区未被使用,其他盘和分区已经全部被现在可以查询到的asmlib使用作为asmdisk)之上

Disk /dev/mapper/mpathb: 3846.7 GB, 3846677987328 bytes
255 heads, 63 sectors/track, 467665 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk identifier: 0x00000000

             Device Boot      Start         End      Blocks   Id  System
/dev/mapper/mpathbp1               1      267350  2147483647+  ee  GPT

Disk /dev/mapper/mpathbp1: 3846.7 GB, 3846675890176 bytes
255 heads, 63 sectors/track, 467665 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk identifier: 0xb84bb99a

                Device Boot      Start         End      Blocks   Id  System
/dev/mapper/mpathbp1p1               1      200513  1610620641   83  Linux
/dev/mapper/mpathbp1p2          200514      267349   536860170   83  Linux
/dev/mapper/mpathbp1p3          267350      467665  1609038270   83  Linux

这里我们发现奇怪现象:mpathb盘先使用parted分为一个mapthbp1分区,然后又使用fdisk分了三个p1p1,p1p2,p1p3三个子分区.然后我们查看/dev/mapper/中的设备情况
mpathb


发现没有p1p1,p1p2,p1p3这三个本该属于mapthb上的子分区.现在基本上明确,是由于对mapthb先使用了parted分区,然后再使用fdisk分区,在操作系统重启之后,无法正常识别相关子分区导致该问题.到此解决该问题的思路有三种.
1. 因为磁盘分区表信息是正常的,就是分区表信息没有同步到操作系统之上,想办法同步过去即可,os部分内容,此处忽略
2. 使用数据文件重组的方式直接对data2这两个asm disk进行重组,这里因为三个子分区未发现,直接对mapthbp1分区进行扫描即可,参考:asm disk header 彻底损坏恢复
3. 因为分区对于asm disk来说主要就是设置了磁盘的偏移量和大小,如果找到磁盘的偏移量,然后确定asm disk大小,直接通过dd命令把该部分dd到新的磁盘设备之上,然后直接mount磁盘组即可,这里重点讲解第三种方法恢复处理
使用dd出来mapthp1的磁盘头,然后使用bbed找出来偏移量,主要依据是第一次出现01820101信息的部分

BBED> d
 File: bp1 (0)
 Block: 64               Offsets:    0 to   63           Dba:0x00000000
------------------------------------------------------------------------
 01820101 00000000 00000080 bc60223c 00000000 00000000 00000000 00000000
 4f52434c 4449534b 564f4c30 31300000 00000000 00000000 00000000 00000000

 <32 bytes per line>

BBED> show all
        FILE#           0
        BLOCK#          64
        OFFSET          0
        DBA             0x00000000 (0 0,64)
        FILENAME        bp1
        BIFILE          bifile.bbd
        LISTFILE
        BLOCKSIZE       512
        MODE            Browse
        EDIT            Unrecoverable
        IBASE           Dec
        OBASE           Dec
        WIDTH           80
        COUNT           64
        LOGFILE         log.bbd
        SPOOL           No

这里基本上可以定位到asm disk header对于mapthbp1的偏移量为32256,dd出来asm disk header分析
dd


使用kfed查看磁盘头信息
kfed
kfed2


现在基本上可以确定,asm disk大小为1572871M,磁盘的偏移量为32256,然后使用dd命令把这部分dd到新的磁盘设备上,然后oracleasm scandisks后
asm-mount
asmcd-lsdg
oracle-open


data2 mount成功,数据库正常open,此数据库完美恢复

ORA-15032 ORA-15040 ORA-15042 asm故障恢复

接到一个朋友恢复请求,19个lun的asm 磁盘组,由于其中一个lun有问题,他们进行了增加一个新lun,删除老lun的方法操作,但是操作一半hang住了(因为坏的lun是底层损坏,无法完成rebalance),然后存储工程师继续修复异常lun,非常幸运异常lun修复好了,但是高兴过了头,直接从存储上删除了新加入的lun(已经rebalance一部分数据进去了),这个时候asm dg彻底趴下了,不能mount成功,请求恢复支持。由于某种原因,无法从lun层面恢复,只能让我们提供数据库层面恢复

Mon Sep 21 19:52:35 2015
SQL> alter diskgroup  dg_XFF add disk '/dev/rhdisk116' size 716800M drop disk dg_XFF_0012
NOTE: Assigning number (1,20) to disk (/dev/rhdisk116)
NOTE: requesting all-instance membership refresh for group=1
NOTE: initializing header on grp 1 disk DG_XFF_0020
NOTE: requesting all-instance disk validation for group=1
Mon Sep 21 19:52:44 2015
NOTE: skipping rediscovery for group 1/0xb94738f1 (DG_XFF) on local instance.
NOTE: requesting all-instance disk validation for group=1
NOTE: skipping rediscovery for group 1/0xb94738f1 (DG_XFF) on local instance.
NOTE: initiating PST update: grp = 1
Mon Sep 21 19:52:44 2015
GMON updating group 1 at 25 for pid 27, osid 12124486
NOTE: PST update grp = 1 completed successfully
NOTE: membership refresh pending for group 1/0xb94738f1 (DG_XFF)
GMON querying group 1 at 26 for pid 18, osid 10092734
NOTE: cache opening disk 20 of grp 1: DG_XFF_0020 path:/dev/rhdisk116
GMON querying group 1 at 27 for pid 18, osid 10092734
SUCCESS: refreshed membership for 1/0xb94738f1 (DG_XFF)
Mon Sep 21 19:52:47 2015
SUCCESS: alter diskgroup  dg_XFF add disk '/dev/rhdisk116' size 716800M drop disk dg_XFF_0012
NOTE: starting rebalance of group 1/0xb94738f1 (DG_XFF) at power 1
Starting background process ARB0
Mon Sep 21 19:52:47 2015
ARB0 started with pid=28, OS id=10944804
NOTE: assigning ARB0 to group 1/0xb94738f1 (DG_XFF) with 1 parallel I/O
NOTE: Attempting voting file refresh on diskgroup DG_XFF
Mon Sep 21 20:35:06 2015
SQL> ALTER DISKGROUP DG_XFF MOUNT  /* asm agent *//* {1:51107:7083} */
NOTE: cache registered group DG_XFF number=1 incarn=0xdd6f975a
NOTE: cache began mount (first) of group DG_XFF number=1 incarn=0xdd6f975a
NOTE: Assigning number (1,0) to disk (/dev/rhdisk10)
NOTE: Assigning number (1,1) to disk (/dev/rhdisk11)
NOTE: Assigning number (1,2) to disk (/dev/rhdisk16)
NOTE: Assigning number (1,3) to disk (/dev/rhdisk17)
NOTE: Assigning number (1,4) to disk (/dev/rhdisk22)
NOTE: Assigning number (1,5) to disk (/dev/rhdisk23)
NOTE: Assigning number (1,6) to disk (/dev/rhdisk28)
NOTE: Assigning number (1,7) to disk (/dev/rhdisk29)
NOTE: Assigning number (1,8) to disk (/dev/rhdisk33)
NOTE: Assigning number (1,9) to disk (/dev/rhdisk34)
NOTE: Assigning number (1,10) to disk (/dev/rhdisk4)
NOTE: Assigning number (1,11) to disk (/dev/rhdisk40)
NOTE: Assigning number (1,12) to disk (/dev/rhdisk41)
NOTE: Assigning number (1,13) to disk (/dev/rhdisk45)
NOTE: Assigning number (1,14) to disk (/dev/rhdisk46)
NOTE: Assigning number (1,15) to disk (/dev/rhdisk5)
NOTE: Assigning number (1,16) to disk (/dev/rhdisk52)
NOTE: Assigning number (1,17) to disk (/dev/rhdisk53)
NOTE: Assigning number (1,18) to disk (/dev/rhdisk57)
NOTE: Assigning number (1,19) to disk (/dev/rhdisk58)
Wed Sep 30 11:08:07 2015
NOTE: start heartbeating (grp 1)
GMON querying group 1 at 33 for pid 35, osid 4194488
NOTE: Assigning number (1,20) to disk ()
GMON querying group 1 at 34 for pid 35, osid 4194488
NOTE: cache dismounting (clean) group 1/0xDD6F975A (DG_XFF)
NOTE: dbwr not being msg'd to dismount
NOTE: lgwr not being msg'd to dismount
NOTE: cache dismounted group 1/0xDD6F975A (DG_XFF)
NOTE: cache ending mount (fail) of group DG_XFF number=1 incarn=0xdd6f975a
NOTE: cache deleting context for group DG_XFF 1/0xdd6f975a
GMON dismounting group 1 at 35 for pid 35, osid 4194488
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
NOTE: Disk  in mode 0x8 marked for de-assignment
ERROR: diskgroup DG_XFF was not mounted
ORA-15032: not all alterations performed
ORA-15040: diskgroup is incomplete
ORA-15042: ASM disk "20" is missing from group number "1"
ERROR: ALTER DISKGROUP DG_XFF MOUNT  /* asm agent *//* {1:51107:7083} */

这里比较明显,由于存储工程师直接删除了lun,这里导致磁盘组DG_XFF丢失asm disk 20,使得磁盘组无法直接mount,由于该磁盘组已经进行了较长时间的rebalance,丢失的盘中已经有大量数据(包括元数据),因此就算修改pst让磁盘组mount起来(不一定成功),也会丢失大量数据,也不一定可以直接拿出来里面的数据,如果只是加入盘,但是由于某种原因没有做rebalance,那我们直接可以通过修改pst,使得磁盘组mount起来。因此对于这样的情况,我们能够做的,只能从底层扫描磁盘,生成数据文件(因为有部分文件的元数据在丢失lun之上,如果直接使用现存元数据信息,直接拷贝,或者unload数据都会丢失大量数据),然后再进一步unload数据,完成恢复。需要恢复磁盘信息

grp# dsk# bsize ausize disksize diskname        groupname       path
---- ---- ----- ------ -------- --------------- --------------- -------------
   1    0  4096  4096K   179200 DG_XFF_0000     DG_XFF          /dev/rhdisk10
   1    1  4096  4096K   179200 DG_XFF_0001     DG_XFF          /dev/rhdisk11
   1    2  4096  4096K   179200 DG_XFF_0002     DG_XFF          /dev/rhdisk16
   1    3  4096  4096K   179200 DG_XFF_0003     DG_XFF          /dev/rhdisk17
   1    4  4096  4096K   179200 DG_XFF_0004     DG_XFF          /dev/rhdisk22
   1    5  4096  4096K   179200 DG_XFF_0005     DG_XFF          /dev/rhdisk23
   1    6  4096  4096K   179200 DG_XFF_0006     DG_XFF          /dev/rhdisk28
   1    7  4096  4096K   179200 DG_XFF_0007     DG_XFF          /dev/rhdisk29
   1    8  4096  4096K   179200 DG_XFF_0008     DG_XFF          /dev/rhdisk33
   1    9  4096  4096K   179200 DG_XFF_0009     DG_XFF          /dev/rhdisk34
   1   10  4096  4096K   179200 DG_XFF_0010     DG_XFF          /dev/rhdisk4
   1   11  4096  4096K   179200 DG_XFF_0011     DG_XFF          /dev/rhdisk40
   1   12  4096  4096K   179200 DG_XFF_0012     DG_XFF          /dev/rhdisk41
   1   13  4096  4096K   179200 DG_XFF_0013     DG_XFF          /dev/rhdisk45
   1   14  4096  4096K   179200 DG_XFF_0014     DG_XFF          /dev/rhdisk46
   1   15  4096  4096K   179200 DG_XFF_0015     DG_XFF          /dev/rhdisk5
   1   16  4096  4096K   179200 DG_XFF_0016     DG_XFF          /dev/rhdisk52
   1   17  4096  4096K   179200 DG_XFF_0017     DG_XFF          /dev/rhdisk53
   1   18  4096  4096K   179200 DG_XFF_0018     DG_XFF          /dev/rhdisk57
   1   19  4096  4096K   179200 DG_XFF_0019     DG_XFF          /dev/rhdisk58

这次运气比较好,丢失的磁盘组只是一个业务磁盘组,而且里面只有19个表空间,10个分区表,因此在数据字典完成的情况下,恢复10个分区表(一共6443个分区)的数据,整体恢复效果如下:
RECOVER


从整体数据量看恢复比例为:6003.26953/6027.26935*100%=99.6018127%,对于丢失了一个已经rebalance的大部分的lun,依旧能够恢复如此的数据,整体看非常理想.不得不说,老熊威武