在Oracle 10205上发现了这个错误信息。
在alert中详细错误信息为:
Wed Jan 12 15:36:24 EAT 2011
Shutting down instance (immediate)
Wed Jan 12 15:36:24 EAT 2011
Shutting down instance: further logons disabled
Wed Jan 12 15:36:24 EAT 2011
Stopping background process CJQ0
Wed Jan 12 15:36:24 EAT 2011
Stopping background process QMNC
Wed Jan 12 15:36:26 EAT 2011
Stopping background process MMNL
Wed Jan 12 15:36:27 EAT 2011
Stopping background process MMON
License high water mark = 11
Wed Jan 12 15:36:28 EAT 2011
Job queue slave processes stopped
Wed Jan 12 15:36:30 EAT 2011
ALTER DATABASE CLOSE NORMAL
Wed Jan 12 15:36:30 EAT 2011
SMON: disabling tx recovery
SMON: disabling cache recovery
Wed Jan 12 15:36:33 EAT 2011
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
Thread 2 closed at log sequence 13854
Successful close of redo thread 2
Wed Jan 12 15:36:36 EAT 2011
Completed: ALTER DATABASE CLOSE NORMAL
Wed Jan 12 15:36:36 EAT 2011
ALTER DATABASE DISMOUNT
Completed: ALTER DATABASE DISMOUNT
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
Wed Jan 12 15:38:05 EAT 2011
OUT OF MEMORY for message buffers
Wed Jan 12 15:38:05 EAT 2011
Errors in file /opt/oracle/db/admin/orcl/bdump/orcl2_lms0_24081.trc:
ORA-00600: internal error code, arguments: [kjccgmb:1], [], [], [], [], [], [], []
Wed Jan 12 15:38:05 EAT 2011
OUT OF MEMORY for message buffers
Wed Jan 12 15:38:05 EAT 2011
Errors in file /opt/oracle/db/admin/orcl/bdump/orcl2_lms1_24083.trc:
ORA-00600: internal error code, arguments: [kjccgmb:1], [], [], [], [], [], [], []
Wed Jan 12 15:38:06 EAT 2011
Trace dumping is performing id=[cdmp_20110112153806]
Wed Jan 12 15:39:32 EAT 2011
Errors in file /opt/oracle/db/admin/orcl/bdump/orcl2_lms0_24081.trc:
ORA-00600: internal error code, arguments: [kjccgmb:1], [], [], [], [], [], [], []
Wed Jan 12 15:39:32 EAT 2011
LMS0: terminating instance due to error 484
Wed Jan 12 15:39:32 EAT 2011
System state dump is made for local instance
System State dumped to trace file /opt/oracle/db/admin/orcl/bdump/orcl2_diag_24073.trc
Wed Jan 12 15:39:32 EAT 2011
Errors in file /opt/oracle/db/admin/orcl/bdump/orcl2_diag_24073.trc:
ORA-00484: LMS* process terminated with error
Wed Jan 12 15:39:32 EAT 2011
Trace dumping is performing id=[cdmp_20110112153932]
Wed Jan 12 15:39:34 EAT 2011
Shutting down instance (abort)
License high water mark = 11
Wed Jan 12 15:39:38 EAT 2011
Instance terminated by LMS0, pid = 24081
Wed Jan 12 15:39:39 EAT 2011
Instance terminated by USER, pid = 17989
Wed Jan 12 15:41:00 EAT 2011
而对应的trace信息:
$ more /opt/oracle/db/admin/orcl/bdump/orcl2_lms0_24081.trc
/opt/oracle/db/admin/orcl/bdump/orcl2_lms0_24081.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production
With the Partitioning, Real Application Clusters, Data Mining and Real Application Testing options
ORACLE_HOME = /opt/oracle/db
System name: HP-UX
Node name: hisdb2
Release: B.11.31
Version: U
Machine: ia64
Instance name: orcl2
Redo thread mounted by this instance: 0
Oracle process number: 7
Unix process pid: 24081, image: oracle@hisdb2 (LMS0)
*** SERVICE NAME:() 2011-01-11 14:59:27.444
*** SESSION ID:(1650.1) 2011-01-11 14:59:27.444
0 GCS shadows cancelled, 0 closed
0 GCS resources traversed, 0 cancelled
LMS 0: 618968 GCS resources on freelist, 619008 on array, 619008 allocated
0 GCS shadows traversed, 0 replayed, 0 duplicates
RCFG(4) lms 0 finished replaying gcs resources
0 write requests issued in 28 GCS resources
.
.
.
0 PIs marked suspect, 0 flush PI msgs
lms 0 finished fixing gcs write protocol
*** 2011-01-12 15:36:43.846
=================================
Begin 4031 Diagnostic Information
=================================
The following information assists Oracle in diagnosing
causes of ORA-4031 errors. This trace may be disabled
by setting the init.ora _4031_dump_bitvec = 0
=====================================
Allocation Request Summary Informaton
=====================================
Current information setting: 04014fff
SGA Heap Dump Interval=3600 seconds
Dump Interval=300 seconds
Last Dump Time=01/12/2011 15:36:35
Dump Count=1
Allocation request for: ges regular m
Heap: c000000100e36920, size: 480
******************************************************
HEAP DUMP heap name="sga heap(1,1)" desc=c000000100e36920
extent sz=0xfe0 alt=216 het=32767 rec=9 flg=-126 pc=0
parent=0000000000000000 wner=0000000000000000 nex=0000000000000000 xsz=0x1000000
latch set 1 of 2
durations enabled for this heap
reserved granules for root 0 (granule size 16777216)
====================
Process State Object
====================
----------------------------------------
SO: c00000023f8fc8f8, type: 2, owner: 0000000000000000, flag: INIT/-/-/0x00
(process) Oracle pid=7, calls cur/top: c00000023cf87400/c00000023cf85578, flag: (6) SYSTEM
int error: 0, call error: 0, sess error: 0, txn error 0
(post info) last post received: 0 0 94
last post received-location: KJCS Post snd proxy to flush msg
last process to post me: c00000023f8fd8f8 1 0
last post sent: 0 0 98
last post sent-location: kjbrcvdscn: scn acked
last process posted by me: c00000023f8fd8f8 1 0
(latch info) wait_event=0 bits=20
holding (efd=6) c000000100e11fa8 Child KJC message pool free list level=5 child#=1
Location from where latch is held: kjcsmpav: allocate a msg buffer:
Context saved from call: 0
state=busy, wlstate=free
waiters [orapid (seconds since: put on list, posted, alive check)]:
8 (8, 1294817803, 8)
waiter count=1
Process Group: DEFAULT, pseudo proc: c00000023fa74fe8
O/S info: user: oracle, term: UNKNOWN, ospid: 24081
OSD pid info: Unix process pid: 24081, image: oracle@hisdb2 (LMS0)
PSO child state object changes :
Dump of memory from 0xC00000023F89C3A0 to 0xC00000023F89C5A8
C00000023F89C3A0 00000008 00000000 C0000002 3B72BDF0 [............;r..]
C00000023F89C3B0 00000010 000313F4 C0000002 3CF85578 [............<.ux>.
.
.
0xc000000100000000 - 0xc000000241003000 shm (5) rwx : -XS-
******************* End of process map dump ****************
==============================
Memory Utilization of Subpool 1
================================
Allocation Name Size
_________________________ __________
"free memory " 65315360
"miscellaneous " 0
"trace buffer " 278528
"dsktab_kfgsg " 50440
"gcs res hash bucket " 524288
.
.
.
"KFG SO child " 5312
"KGKP randnum " 40000
==============================
Memory Utilization of Subpool 2
================================
Allocation Name Size
_________________________ __________
"free memory " 39095504
"miscellaneous " 0
"dpslut_kfdsg " 512
"File Space Usage " 11344
"trace buffer " 327680
"trace_knlasg " 504
"ges big msg buffers " 15936168
.
.
.
SGA Heap Dump Count = 0
===============================
End 4031 Diagnostic Information
===============================
kjcsmpav: error 4031 detected
kjcsmpav: error 4031 detected
kjcsmpav: error 4031 detected
kjcsmpav: error 4031 detected
kjcsmpav: error 4031 detected
kjcsmpav: error 4031 detected
.
.
.
kjcsmpav: error 4031 detected
*** 2011-01-12 15:38:04.245
kjcsmpav: error 4031 detected
kjcsmpav: error 4031 detected
kjcsmpav: error 4031 detected
可以看到,在关闭数据库的过程中,Oracle出现了ORA-600(KJCCGMB:1)的错误,而这这个错误中,出现了大量的ORA-4031错误。
这显然是Oracle在回收或释放内存的时候出现的bug。
检查了metalink文档,对应的bug信息是BUG 6126415,Oracle在11.1.0.7才FIXED这个bug,这个问题可能发生在小于11.2的任何版本上。
好在内存不足的问题只是发生在关闭数据库的时候,最大影响不过是使用SHUTDOWN ABORT来关闭数据库,对数据库的日常使用没有影响。
来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/4227/viewspace-684070/,如需转载,请注明出处,否则将追究法律责任。
转载于:http://blog.itpub.net/4227/viewspace-684070/