Oracle 11.2 RAC自动启动报错诊断

原创

Oracle小混子 2013-07-09 10:12:03 ©著作权

文章标签 Oracle RAC 11.2 RAC RAC自动启动报错 文章分类 Oracle 数据库

©著作权归作者所有：来自51CTO博客作者Oracle小混子的原创作品，请联系作者获取转载授权，否则将追究法律责任

一个客户的11.2 RAC for Linux X86-64环境停电后出现了故障，RAC环境无法自动启动。

登录数据库服务器后，发现CLUSTER进程存在，于是尝试手工启动数据库：

$ sqlplus / as sysdba

SQL*Plus: Release 11.2.0.2.0 Production on Sun May 29 20:17:16 2011

Connected to an idle instance.

SQL> startup

ORA-01078: failure in processing system parameters

ORA-01565: error in identifying file '+DG_DATA/SPSP/spfileSPSP.ora'

ORA-17503: ksfdopn:2 Failed to open file +DG_DATA/SPSP/spfileSPSP.ora

ORA-15056: additional error message

ORA-17503: ksfdopn:2 Failed to open file +DG_DATA/spsp/spfilespsp.ora

ORA-15001: diskgroup "DG_DATA" does not exist or is not mounted

ORA-06512: at line 4

看来问题出在ASM磁盘组上，检查ASM磁盘组的告警日志：

NOTE: client SPSP2:SPSP registered, osid 14319, mbr 0x1

Sun May 29 16:58:31 2011

WARNING: Write Failed. group:1 disk:0 AU:12 offset:856064 size:4096

NOTE: unable to write any mirror side for diskgroup DG_ARCH

NOTE: cache initiating offline of disk 0 group DG_ARCH

NOTE: process 13597 initiating offline of disk 0.3915929597 (ARCH1) with mask 0x7e in group 1

Sun May 29 16:58:31 2011

WARNING: Disk ARCH1 in mode 0x7f is now being offlined

WARNING: Disk ARCH1 in mode 0x7f is now being taken offline

NOTE: initiating PST update: grp = 1, dsk = 0/0xe96857fd, mode = 0x15

GMON updating disk modes for group 1 at 21 for pid 15, osid 13597

ERROR: too many offline disks in PST (grp 1)

Sun May 29 16:58:31 2011

NOTE: cache dismounting (not clean) group 1/0x9C08A705 (DG_ARCH)

WARNING: Disk ARCH1 in mode 0x7f offline aborted

WARNING: Offline for disk ARCH1 in mode 0x7f failed.

Sun May 29 16:58:31 2011

NOTE: halting all I/Os to diskgroup 1 (DG_ARCH)

NOTE: unable to offline disks after getting write error for diskgroup DG_ARCH

NOTE: disk 0 had IO error

NOTE: LGWR doing non-clean dismount of group 1 (DG_ARCH)

NOTE: LGWR sync ABA=237.2255 last written ABA 237.2256

Sun May 29 16:58:32 2011

ERROR: ORA-15130 in COD recovery for diskgroup 1/0x9c08a705 (DG_ARCH)

ERROR: ORA-15130 thrown in RBAL for group number 1

Errors in file /oracle/gridbase/diag/asm/+asm/+ASM2/trace/+ASM2_rbal_13603.trc:

ORA-15130: diskgroup "DG_ARCH" is being dismounted

WARNING: Read Failed. group:1 disk:0 AU:1 offset:4096 size:4096

WARNING: Read Failed. group:1 disk:0 AU:1 offset:0 size:4096

ERROR: no PST quorum in group: required 1, found 0

ERROR: Could not heartbeat PST for grp 1. Force dismounting the disk group.

WARNING: Write Failed. group:2 disk:2 AU:1 offset:1044480 size:4096

WARNING: Write Failed. group:2 disk:1 AU:1 offset:1044480 size:4096

WARNING: Write Failed. group:2 disk:0 AU:1 offset:1044480 size:4096

WARNING: disk 0.3915929598 (VD1) not responding to heart beat

WARNING: disk 1.3915929599 (VD2) not responding to heart beat

ERROR: too many offline disks in PST (grp 2)

WARNING: disk 2.3915929600 (VD3) not responding to heart beat

ERROR: too many offline disks in PST (grp 2)

Sun May 29 16:58:32 2011

Errors in file /oracle/gridbase/diag/asm/+asm/+ASM2/trace/+ASM2_b001_14488.trc:

ORA-15130: diskgroup "" is being dismounted

WARNING: Write Failed. group:3 disk:0 AU:1 offset:1044480 size:4096

WARNING: disk 0.3915929601 (DATA1) not responding to heart beat

ERROR: too many offline disks in PST (grp 3)

WARNING: Write Failed. group:4 disk:0 AU:1 offset:1044480 size:4096

WARNING: disk 0.3915929603 (FLSH1) not responding to heart beat

ERROR: too many offline disks in PST (grp 4)

WARNING: Write Failed. group:5 disk:0 AU:1 offset:1044480 size:4096

WARNING: disk 0.3915929604 (REDO1) not responding to heart beat

ERROR: too many offline disks in PST (grp 5)

Sun May 29 16:58:32 2011

NOTE: process 14490 initiating offline of disk 0.3915929598 (VD1) with mask 0x7e in group 2

NOTE: process 14490 initiating offline of disk 1.3915929599 (VD2) with mask 0x7e in group 2

NOTE: process 14490 initiating offline of disk 2.3915929600 (VD3) with mask 0x7e in group 2

NOTE: checking PST: grp = 2

freeing rdom 4

WARNING: dirty detached from domain 4

NOTE: cache dismounted group 4/0x9C28A708 (DG_FLSH)

SQL> alter diskgroup DG_FLSH dismount force /* ASM SERVER */

NOTE: cache deleting context for group DG_FLSH 4/0x9c28a708

GMON dismounting group 4 at 30 for pid 38, osid 14494

NOTE: Disk in mode 0x8 marked for de-assignment

SUCCESS: diskgroup DG_FLSH was dismounted

SUCCESS: alter diskgroup DG_FLSH dismount force /* ASM SERVER */

ERROR: PST-initiated MANDATORY DISMOUNT of group DG_FLSH

NOTE: diskgroup resource ora.DG_FLSH.dg is offline

List of instances:

Dirty detach reconfiguration started (new ddet inc 1, cluster inc 2)

Global Resource Directory partially frozen for dirty detach

* dirty detach - domain 5 invalid = TRUE

19 GCS resources traversed, 0 cancelled

Dirty Detach Reconfiguration complete

freeing rdom 5

WARNING: dirty detached from domain 5

NOTE: cache dismounted group 5/0x9C38A709 (DG_REDO)

SQL> alter diskgroup DG_REDO dismount force /* ASM SERVER */

NOTE: cache deleting context for group DG_REDO 5/0x9c38a709

GMON dismounting group 5 at 31 for pid 39, osid 14496

NOTE: Disk in mode 0x8 marked for de-assignment

SUCCESS: diskgroup DG_REDO was dismounted

SUCCESS: alter diskgroup DG_REDO dismount force /* ASM SERVER */

ERROR: PST-initiated MANDATORY DISMOUNT of group DG_REDO

NOTE: diskgroup resource ora.DG_REDO.dg is offline

Sun May 29 16:58:36 2011

Errors in file /oracle/gridbase/diag/asm/+asm/+ASM2/trace/+ASM2_ora_13637.trc:

ORA-15078: ASM diskgroup was forcibly dismounted

NOTE: client exited [13627]

Sun May 29 16:58:40 2011

Shutting down instance (abort)

License high water mark = 15

USER (ospid: 13624): terminating the instance

Instance terminated by USER, pid = 13624

Sun May 29 16:58:41 2011

Instance shutdown complete

根据错误信息，ASM在尝试写磁盘组的时候出现了IO错误。

进一步检查CLUSTER的日志信息：

2011-05-29 00:00:19.569

[cssd(13270)]CRS-1649:An I/O error occured for voting file: ORCL:VD3; details at (:CSSNM00059:) in /oracle/product/11g/grid/log/oracle-01/cssd/ocssd.log.

2011-05-29 00:00:19.570

[cssd(13270)]CRS-1649:An I/O error occured for voting file: ORCL:VD2; details at (:CSSNM00059:) in /oracle/product/11g/grid/log/oracle-01/cssd/ocssd.log.

2011-05-29 00:00:19.678

[cssd(13270)]CRS-1649:An I/O error occured for voting file: ORCL:VD1; details at (:CSSNM00059:) in /oracle/product/11g/grid/log/oracle-01/cssd/ocssd.log.

2011-05-29 00:00:22.584

[cssd(13270)]CRS-1649:An I/O error occured for voting file: ORCL:VD3; details at (:CSSNM00060:) in /oracle/product/11g/grid/log/oracle-01/cssd/ocssd.log.

2011-05-29 00:00:22.584

[cssd(13270)]CRS-1649:An I/O error occured for voting file: ORCL:VD2; details at (:CSSNM00060:) in /oracle/product/11g/grid/log/oracle-01/cssd/ocssd.log.

2011-05-29 00:00:22.684

[cssd(13270)]CRS-1649:An I/O error occured for voting file: ORCL:VD1; details at (:CSSNM00060:) in /oracle/product/11g/grid/log/oracle-01/cssd/ocssd.log.

2011-05-29 00:00:24.818

[/oracle/product/11g/grid/bin/orarootagent.bin(13818)]CRS-5822:Agent '/oracle/product/11g/grid/bin/orarootagent_root' disconnected from server. Details at (:CRSAGF00117:) {0:1:4} in /oracle/product/11g/grid/log/oracle-01/agent/crsd/orarootagent_root/orarootagent_root.log.

2011-05-29 00:00:24.818

[/oracle/product/11g/grid/bin/oraagent.bin(13815)]CRS-5822:Agent '/oracle/product/11g/grid/bin/oraagent_grid' disconnected from server. Details at (:CRSAGF00117:) {0:2:8} in /oracle/product/11g/grid/log/oracle-01/agent/crsd/oraagent_grid/oraagent_grid.log.

2011-05-29 00:00:25.244