oracle版本:10.2.0.4 RAC
主机:sun solaris 前些天数据库主机分区损坏,修复后数据库启动成功,但是数据库日志有异常
如下
Fri Sep  3 22:25:52 2010
Errors in file /oracle/app/oracle/admin/sdh/bdump/sdh_mmon_1874.trc:
ORA-00600: internal error code, arguments: [kmgs_parameter_update_timeout_1], [1565], [], [], [], [], [], []
ORA-01565: error in identifying file '/dev/md/rdsk/d125'
ORA-27086: unable to lock file - already in use
SVR4 Error: 11: Resource temporarily unavailable
Additional information: 8
Additional information: 26368异常频率有时候是十几分钟一次,有时候是几小时一次。直到9月12日出现下列异常后 数据库实例关闭。
Sun Sep 12 01:07:12 2010
Errors in file /oracle/app/oracle/admin/sdh/bdump/sdh_mmon_11943.trc:
ORA-00600: internal error code, arguments: [kmgs_parameter_update_timeout_1], [1565], [], [], [], [], [], []
ORA-01565: error in identifying file '/dev/md/rdsk/d125'
ORA-27086: unable to lock file - already in use
SVR4 Error: 11: Resource temporarily unavailable
Additional information: 8
Additional information: 26368
Thread 1 cannot allocate new log, sequence 5146
Checkpoint not complete
  Current log# 3 seq# 5145 mem# 0: /dev/md/rdsk/d134
  Current log# 3 seq# 5145 mem# 1: /dev/md/rdsk/d133
Sun Sep 12 01:07:17 2010
Thread 1 advanced to log sequence 5146 (LGWR switch)
  Current log# 1 seq# 5146 mem# 0: /dev/md/rdsk/d129
  Current log# 1 seq# 5146 mem# 1: /dev/md/rdsk/d130
Sun Sep 12 01:07:18 2010
Errors in file /oracle/app/oracle/admin/sdh/bdump/sdh_dbw0_26368.trc:
ORA-00600: internal error code, arguments: [ksprcvsp1], [0], [0], [], [], [], [], []
Thread 1 cannot allocate new log, sequence 5147
Checkpoint not complete
  Current log# 1 seq# 5146 mem# 0: /dev/md/rdsk/d129
  Current log# 1 seq# 5146 mem# 1: /dev/md/rdsk/d130
Sun Sep 12 01:07:21 2010
Restarting dead background process MMON
MMON started with pid=121, OS id=13289
Sun Sep 12 01:07:23 2010
Errors in file /oracle/app/oracle/admin/sdh/bdump/sdh_dbw0_26368.trc:
ORA-00600: internal error code, arguments: [kmgs_parameter_update_timeout_1], [600], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [ksprcvsp1], [0], [0], [], [], [], [], []
Sun Sep 12 01:07:26 2010
Errors in file /oracle/app/oracle/admin/sdh/bdump/sdh_dbw0_26368.trc:
ORA-00600: internal error code, arguments: [kmgs_parameter_update_timeout_1], [600], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [ksprcvsp1], [0], [0], [], [], [], [], []
Sun Sep 12 01:07:26 2010
DBW0: terminating instance due to error 471
Instance terminated by DBW0, pid = 26368
Mon Sep 13 11:30:28 2010
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
目前启动数据库失败,报异常Mon Sep 13 16:51:21 2010
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 3
Using LOG_ARCHIVE_DEST_1 parameter default value as /oracle/app/oracle/product/10.2.0/dbs/arch
Autotune of undo retention is turned off.
LICENSE_MAX_USERS = 0
SYS auditing is disabled
ksdpec: called for event 13740 prior to event group initialization
Starting up ORACLE RDBMS Version: 10.2.0.4.0.
System parameters with non-default values:
  spfile                   = /dev/md/rdsk/d125
  compatible               = 10.2.0.1.0
  db_name                  = sdh
PMON started with pid=2, OS id=9810
PSP0 started with pid=4, OS id=9812
MMAN started with pid=3, OS id=9814
DBW0 started with pid=5, OS id=9816
DBW1 started with pid=6, OS id=9818
DBW2 started with pid=7, OS id=9820
DBW3 started with pid=8, OS id=9822
DBW4 started with pid=10, OS id=9824
ALTER DATABASE CLOSE NORMAL
ORA-1507 signalled during: ALTER DATABASE CLOSE NORMAL...
ARCH: Archival disabled due to shutdown: 1090
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
ARCH: Archival disabled due to shutdown: 1090
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
Mon Sep 13 16:51:21 2010
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 3
Using LOG_ARCHIVE_DEST_1 parameter default value as /oracle/app/oracle/product/10.2.0/dbs/arch
Autotune of undo retention is turned off.
LICENSE_MAX_USERS = 0
SYS auditing is disabled
ksdpec: called for event 13740 prior to event group initialization
Starting up ORACLE RDBMS Version: 10.2.0.4.0.
System parameters with non-default values:
  spfile                   = /dev/md/rdsk/d125
  compatible               = 10.2.0.1.0
  db_name                  = sdh
PMON started with pid=2, OS id=9810
PSP0 started with pid=4, OS id=9812
MMAN started with pid=3, OS id=9814
DBW0 started with pid=5, OS id=9816
DBW1 started with pid=6, OS id=9818
DBW2 started with pid=7, OS id=9820
DBW3 started with pid=8, OS id=9822
DBW4 started with pid=10, OS id=9824
DBW5 started with pid=9, OS id=9826
DBW6 started with pid=12, OS id=9828
DBW7 started with pid=11, OS id=9830
DBW8 started with pid=14, OS id=9832
DBW9 started with pid=13, OS id=9834
DBWa started with pid=16, OS id=9836
DBWb started with pid=18, OS id=9838
LGWR started with pid=15, OS id=9840
CKPT started with pid=17, OS id=9842
SMON started with pid=19, OS id=9844
RECO started with pid=21, OS id=9846
MMON started with pid=20, OS id=9848
MMNL started with pid=22, OS id=9850
Mon Sep 13 16:51:24 2010
ALTER DATABASE   MOUNT
Mon Sep 13 16:51:28 2010
Setting recovery target incarnation to 1
ORA-1079 signalled during: ALTER DATABASE   MOUNT...
Shutting down instance: further logons disabled
Mon Sep 13 16:55:35 2010
Stopping background process MMNL
Mon Sep 13 16:55:36 2010
Stopping background process MMON
Mon Sep 13 16:55:37 2010
Shutting down instance (immediate)
License high water  = 1
Mon Sep 13 16:55:37 2010
ALTER DATABASE CLOSE NORMAL
ORA-1507 signalled during: ALTER DATABASE CLOSE NORMAL...
ARCH: Archival disabled due to shutdown: 1089
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
ARCH: Archival disabled due to shutdown: 1089
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active

解决方案 »

  1.   

    查询了METALINK,发现是Oracle的bug在文档Doc ID: 5399699.8中对这个错误进行了描述。这个错误影响10.2.0.3和10.2.0.4版本,在10.2.0.5和11.1.0.6中解决了这个错误。问题是MMON进程在尝试更新SPFILE中的内存参数时,由于长时间没有办法更新参数,导致的超时,引发的这个错误。不过当前和文档中描述的不同之处在于,当前使用的是裸设备,而不是ASM。这个bug对系统影响不大,不打补丁也没有什么影响。
      

  2.   

    这是目前数据库启动的情况。
    SQL> startup nomount;
    ORACLE instance started.Total System Global Area  599785472 bytes
    Fixed Size                  2140152 bytes
    Variable Size             117135368 bytes
    Database Buffers          402653184 bytes
    Redo Buffers               77856768 bytesSQL> alter database mount;
    alter database mount
    *
    ERROR at line 1:
    ORA-01079: ORACLE database was not properly created, operation aborted我从网上查了下mount应该只是装载控制文件,确认数据文件和logfile的位置看这个情况是不是 控制文件 或者 logfile 文件损坏了?有这样个情况之前是因为solaris系统的分区被损坏了
    这是系统日志
    Sep  3 13:23:25 WLAN20_DB md_stripe: [ID 641072 kern.warning] WARNING: md: d131: write error on /dev/dsk/c2t0d31s6
    Sep  3 13:23:25 WLAN20_DB md_stripe: [ID 641072 kern.warning] WARNING: md: d132: write error on /dev/dsk/c2t0d32s6
    Sep  3 13:23:26 WLAN20_DB md_stripe: [ID 641072 kern.warning] WARNING: md: d126: write error on /dev/dsk/c2t0d26s6
    Sep  3 13:23:26 WLAN20_DB md_stripe: [ID 641072 kern.warning] WARNING: md: d127: write error on /dev/dsk/c2t0d27s6
    Sep  3 14:28:33 WLAN20_DB su: [ID 810491 auth.crit] 'su oracle' failed for root on /dev/pts/3
    Sep  3 16:16:12 WLAN20_DB su: [ID 810491 auth.crit] 'su root' failed for oracle on /dev/pts/10
    Sep  3 16:17:03 WLAN20_DB su: [ID 810491 auth.crit] 'su oracle' failed for oracle on /dev/pts/10
    Sep  3 16:50:03 WLAN20_DB WBEM_Logging_Service[21720]: [ID 786276 daemon.notice] A secure session was timeout and closed for user "root" from host "WLAN20_DB" with session identifier 1283501985955.