ORA-01075,ORA-09925 Read-only file system问题一例

OEL 5.7 + ORACLE RAC 11.2.0.2 在运行过程中系统监控台出现journal commit I/O error的信息:

SQL> oradebug 
Message from syslogd@ at Fri Oct 14 21:17:08 2011 ...
vrh1 kernel: journal commit I/O error

[root@vrh1 ~]# tail /var/log/messages
Oct 14 21:02:49 vrh1 kernel: [Oracle OKS] ODLM hash size 62500
Oct 14 21:02:49 vrh1 kernel: OKSK-00004: Module load succeeded. Build information:   
(LOW DEBUG) USM_11.2.0.3.0_LINUX.X64_110803.1 2011/08/04 10:23:50
Oct 14 21:02:50 vrh1 kernel: ADVMK-00001: Module load succeeded. Build information:  
(LOW DEBUG) - USM_11.2.0.3.0_LINUX.X64_110803.1 built on 2011/08/04 10:28:15.
Oct 14 21:02:51 vrh1 kernel: [Oracle ACFS] FCB hash size 62500
Oct 14 21:02:51 vrh1 kernel: [Oracle ACFS] buffer cache size 276MB (41713 buckets)
Oct 14 21:02:51 vrh1 kernel: [Oracle ACFS] DLM hash size 62500
Oct 14 21:02:51 vrh1 kernel: ACFSK-0037: Module load succeeded. Build information:   
(LOW DEBUG) USM_11.2.0.3.0_LINUX.X64_110803.1 2011/08/04 10:32:50
Oct 14 21:02:51 vrh1 kernel: OKSK-00010: Persistent OKS log opened at /g01/11.2.0.3/grid/log/vrh1/acfs/acfs.log.0.
Oct 14 21:03:46 vrh1 avahi-daemon[3666]: Registering new address record for 192.168.1.162 on eth0.
Oct 14 21:17:08 vrh1 kernel: attempt to access beyond end of devic

[root@vrh1 ~]# mount
/dev/mapper/VolGroup00-LogVol00 on / type ext3 (rw)
proc on /proc type proc (rw)
sysfs on /sys type sysfs (rw)
devpts on /dev/pts type devpts (rw,gid=5,mode=620)
/dev/sda1 on /boot type ext3 (rw)
tmpfs on /dev/shm type tmpfs (rw)
tmpfs on /dev/shm type tmpfs (rw,size=1500m)
none on /proc/sys/fs/binfmt_misc type binfmt_misc (rw)
sunrpc on /var/lib/nfs/rpc_pipefs type rpc_pipefs (rw)

mount: warning: /etc/mtab is not writable (e.g. read-only filesystem).
       It's possible that information reported by mount(8) is not
       up to date. For actual information about system mount points
       check the /proc/mounts file.

[root@vrh1 ~]# cat /proc/mounts 
rootfs / rootfs rw 0 0
/dev/root / ext3 ro,data=ordered 0 0
/dev /dev tmpfs rw 0 0
/proc /proc proc rw 0 0
/sys /sys sysfs rw 0 0
/proc/bus/usb /proc/bus/usb usbfs rw 0 0
devpts /dev/pts devpts rw 0 0
/dev/sda1 /boot ext3 rw,data=ordered 0 0
tmpfs /dev/shm tmpfs rw 0 0
tmpfs /dev/shm tmpfs rw 0 0
none /proc/sys/fs/binfmt_misc binfmt_misc rw 0 0
sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw 0 0
/etc/auto.misc /misc autofs rw,fd=7,pgrp=3377,timeout=300,minproto=5,maxproto=5,indirect 0 0
-hosts /net autofs rw,fd=13,pgrp=3377,timeout=300,minproto=5,maxproto=5,indirect 0 0

  root根目录变成read-only，无法写文件系统，Oracle因为无法写audit文件也无法正常登陆 ：  

[root@vrh1 ~]# pwd
/root

[root@vrh1 ~]# touch a
touch: cannot touch `a': Read-only file system

[oracle@vrh1 ~]$ sp

SQL*Plus: Release 11.2.0.3.0 Production on Fri Oct 14 21:17:52 2011

Copyright (c) 1982, 2011, Oracle.  All rights reserved.

ERROR:
ORA-09925: Unable to create audit trail file
Linux-x86_64 Error: 30: Read-only file system
Additional information: 9925
ORA-01075: you are currently logged on

此时adrci 诊断工具也会变得无法使用

[oracle@vrh1 ~]$ adrci

ADRCI: Release 11.2.0.3.0 - Production on Fri Oct 14 21:26:43 2011

Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.

ADR base = "/s01/orabase"
adrci> show home
ADR Homes: 
diag/tnslsnr/vrh1/listener
diag/rdbms/vprod/VPROD1
diag/rdbms/g11r2/G11R2
adrci> set home diag/rdbms/vprod/VPROD1
adrci> show alert 

ADR Home = /s01/orabase/diag/rdbms/vprod/VPROD1:
*************************************************************************
DIA-48001: internal error code, arguments: [dbgvcis_ostream_write_1], [], [], [], [], [], [], []
DIA-48121: error with opening the ADR stream file [/tmp/alert_6894_47621_VPROD1_1.ado] [0]
DIA-48180: OS open system call failure
Linux-x86_64 Error: 30: Read-only file system
Additional information: 1

此时可以尝试remount root文件系统:

[root@vrh1 ~]# mount -o remount,rw /
mount: block device /dev/VolGroup00/LogVol00 is write-protected, mounting read-only

remount 不成功可能是文件系统存在corruption了

[root@vrh1 ~]# dmesg

EXT3-fs error (device dm-0): ext3_free_blocks: Freeing blocks not in datazone - block = 539784035, count = 1
Aborting journal on device dm-0.
EXT3-fs error (device dm-0): ext3_free_blocks: Freeing blocks not in datazone - block = 1885630053, count = 1
EXT3-fs error (device dm-0): ext3_free_blocks: Freeing blocks not in datazone - block = 808464416, count = 1
EXT3-fs error (device dm-0): ext3_free_blocks: Freeing blocks not in datazone - block = 808464432, count = 1
EXT3-fs error (device dm-0): ext3_free_blocks: Freeing blocks not in datazone - block = 808464432, count = 1
EXT3-fs error (device dm-0): ext3_free_blocks: Freeing blocks not in datazone - block = 1714630704, count = 1
EXT3-fs error (device dm-0): ext3_free_blocks: Freeing blocks not in datazone - block = 808585830, count = 1
EXT3-fs error (device dm-0): ext3_free_blocks: Freeing blocks not in datazone - block = 825045297, count = 1
EXT3-fs error (device dm-0): ext3_free_bloc

EXT3-fs error (device dm-0) in ext3_free_blocks_sb: Journal has aborted
EXT3-fs error (device dm-0) in ext3_reserve_inode_write: Journal has aborted
EXT3-fs error (device dm-0) in ext3_reserve_inode_write: Journal has aborted
EXT3-fs error (device dm-0) in ext3_orphan_del: Journal has aborted
EXT3-fs error (device dm-0) in ext3_truncate: Journal has aborted
journal commit I/O error
ext3_abort called.
EXT3-fs error (device dm-0): ext3_journal_start_sb: Detected aborted journal
Remounting filesystem read-only
ext3_abort called.
EXT3-fs error (device dm-0): ext3_remount: Abort forced by user
ext3_abort called.
EXT3-fs error (device dm-0): ext3_remount: Abort forced by user
ext3_abort called.
EXT3-fs error (device dm-0): ext3_remount: Abort forced by user
ext3_abort called.
EXT3-fs error (device dm-0): ext3_remount: Abort forced by user
ext3_abort called.
EXT3-fs error (device dm-0): ext3_remount: Abort forced by user
ext3_abort called.
EXT3-fs error (device dm-0): ext3_remount: Abort forced by user

dmesg发现EXT-3 文件系统存在问题。 使用fsck命令修复文件系统:

[root@vrh1 ~]# fsck
fsck 1.39 (29-May-2006)
e2fsck 1.39 (29-May-2006)
/dev/VolGroup00/LogVol00: recovering journal
Resize inode not valid.  Recreate? yes

/dev/VolGroup00/LogVol00 was not cleanly unmounted, check forced.
Pass 1: Checking inodes, blocks, and sizes
Root inode is not a directory.  Clear? yes

Reserved inode 3 () has invalid mode.  Clear? yes

Inode 3, i_blocks is 8, should be 0.  Fix? yes

Reserved inode 4 () has invalid mode.  Clear? yes

Inode 4, i_blocks is 8, should be 0.  Fix? yes

Reserved inode 6 () has invalid mode.  Clear? yes

Inode 6, i_blocks is 8, should be 0.  Fix? yes

Inode 8, i_blocks is 0, should be 262416.  Fix? yes

Reserved inode 9 () has invalid mode.  Clear? yes

Inode 9, i_blocks is 16, should be 0.  Fix? yes

Reserved inode 10 () has invalid mode.  Clear? yes

Inode 10, i_blocks is 16, should be 0.  Fix? yes

Inode 196716 has illegal block(s).  Clear? yes

Illegal block #12 (3560079808) in inode 196716.  CLEARED.
Illegal block #14 (1316876525) in inode 196716.  CLEARED.
Illegal block #15 (1316876163) in inode 196716.  CLEARED.
Illegal block #16 (1311179080) in inode 196716.  CLEARED.
Illegal block #37 (185253578) in inode 196716.  CLEARED.
Illegal block #44 (3560079808) in inode 196716.  CLEARED.
Illegal block #46 (1316876321) in inode 196716.  CLEARED.
Illegal block #47 (1316876163) in inode 196716.  CLEARED.
Illegal block #48 (1311179080) in inode 196716.  CLEARED.
Illegal block #69 (185253579) in inode 196716.  CLEARED.
Illegal block #76 (3560079808) in inode 196716.  CLEARED.
Too many illegal blocks in inode 196716.
Clear inode? yes

Inode 196728 has illegal block(s).  Clear? yes

Illegal block #11276 (3560079780) in inode 196728.  CLEARED.
Illegal block #11278 (1316876361) in inode 196728.  CLEARED.
Illegal block #11279 (1316876102) in inode 196728.  CLEARED.
Illegal block #11280 (1312304746) in inode 196728.  CLEARED.
Illegal block #11301 (185250670) in inode 196728.  CLEARED.
Illegal block #11308 (3560079780) in inode 196728.  CLEARED.
Illegal block #11310 (1316876361) in inode 196728.  CLEARED.
Illegal block #11311 (1316876102) in inode 196728.  CLEARED.
Illegal block #11312 (1312304746) in inode 196728.  CLEARED.
Illegal block #11333 (185250671) in inode 196728.  CLEARED.
Illegal block #11340 (3560079780) in inode 196728.  CLEARED.
Too many illegal blocks in inode 196728.
Clear inode? yes

Inode 196684 has illegal block(s).  Clear? yes

Illegal block #14 (1318562824) in inode 196684.  CLEARED.
Illegal block #15 (1315154713) in inode 196684.  CLEARED.
Illegal block #16 (1307022373) in inode 196684.  CLEARED.
Illegal block #37 (3017086173) in inode 196684.  CLEARED.
Illegal block #46 (1318562824) in inode 196684.  CLEARED.
Illegal block #47 (1313011230) in inode 196684.  CLEARED.
Illegal block #48 (1313011230) in inode 196684.  CLEARED.
Illegal block #54 (1969383788) in inode 196684.  CLEARED.
Illegal block #55 (778332533) in inode 196684.  CLEARED.
Illegal block #56 (825126771) in inode 196684.  CLEARED.
Illegal block #69 (80758554) in inode 196684.  CLEARED.