LOG FILE ----------------------- Filename =gpnms4_j000_22234.trc.log See the following error: *** 2010-05-22 21:47:37.388 ORA-12012: error on auto execute of job 2 ORA-04031: unable to allocate 4064 bytes of shared memory ("shared pool","select SYSDATE+(30 / (24*60)...","sga heap(4,0)","kglsim heap") *** 2010-05-22 21:47:37.410 ORA-00604: error occurred at recursive SQL level 1 ORA-04031: unable to allocate 4064 bytes of shared memory ("shared pool","select sysdate+(64)/(24*60) ...","sga heap(6,0)","kglsim heap") ORA-12012: error on auto execute of job 2 ORA-04031: unable to allocate 4064 bytes of shared memory ("shared pool","select SYSDATE+(30 / (24*60)...","sga heap(4,0)","kglsim heap")
TRACE FILE gpnms4_j000_22234.trc
------------ *** SERVICE NAME:(SYS$USERS) 2010-05-22 21:47:37.240 *** SESSION ID:(121.20137) 2010-05-22 21:47:37.240 *** 2010-05-22 21:47:37.240 ================================= 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=05/22/2010 21:47:37 Dump Count=1 Allocation request for: kglsim heap Heap: 380048e48, size: 4064 ****************************************************** HEAP DUMP heap name="sga heap(4,0)" desc=380048e48 extent sz=0xfe0 alt=216 het=32767 rec=9 flg=-125 opc=2 parent=0 owner=0 nex=0 xsz=0x1000000 latch set 4 of 6 durations enabled for this heap reserved granules for root 0 (granule size 16777216) ==================== Process State Object ==================== ---------------------------------------- SO: 5761a3750, type: 2, owner: 0, flag: INIT/-/-/0x00 (process) Oracle pid=37, calls cur/top: 56e79bdc8/572cd9160, flag: (0) - int error: 0, call error: 0, sess error: 0, txn error 0 (post info) last post received: 1359 0 4 last post received-location: kslpsr last process to post me: 57f156848 1 6 last post sent: 0 0 24 last post sent-location: ksasnd last process posted by me: 57f156848 1 6 (latch info) wait_event=0 bits=60 holding (efd=19) 5731bf3a0 Child shared pool sim alloc level=6 child#=12 Location from where latch is held: kglsim_chk_heaplist: alloc: Context saved from call: 0 state=busy, wlstate=free holding (efd=19) 5711d3de0 Child library cache level=5 child#=15 Location from where latch is held: kglobpn: child:: latch Context saved from call: 22 state=busy, wlstate=free Process Group: DEFAULT, pseudo proc: 57416ad08 O/S info: user: oracle, term: UNKNOWN, ospid: 22234 OSD pid info: Unix process pid: 22234, image: oracle@SHUDBa1 (J000) SO: 5761d48b0, type: 4, owner: 5761a3750, flag: INIT/-/-/0x00 (session) sid: 121 trans: 0, creator: 5761a3750, flag: (40000041) USR/- BSY/-/-/-/-/- DID: 0001-0025-0060BC7E, short-term DID: 0000-0000-00000000 txn branch: 0 oct: 0, prv: 0, sql: 0, psql: 0, user: 93/WUBIAO O/S info: user: oracle, term: UNKNOWN, ospid: 22234, machine: SHUDBa1 program: oracle@SHUDBa1 (J000) last wait for 'SGA: allocation forcing component growth' blocking sess=0x0 seq=2 wait_time=10349 seconds since wait started=0 =0, =0, =0 Dumping Session Wait History for 'SGA: allocation forcing component growth' count=1 wait_time=10349 =0, =0, =0 for 'db file sequential read' count=1 wait_time=89 file#=7, block#=6f767, blocks=1 temporary object counter: 0 ----- Call Stack Trace ----- ksm_4031_dump <- ksmasg <- kghnospc <- kghalo <- kglsim_chk_heaplist <- kglsim_upd_newhp <- 3076 <- kglUpdateSimulator <- kglobpn <- kglpim <- qcdlgtd <- qcsfplob <- qcsprfro <- qcsprfro_tree <- qcsprfro_tree <- qcspafq <- qcspqbDescendents <- qcspqb <- kkmdrv <- opiSem <- opiprs <- kksParseChildCursor <- rpiswu2 <- kksLoadChild <- kxsGetRuntimeLock <- kksfbc <- kkspsc0 <- kksParseCursor <- opiosq0 <- opiodr <- rpidrus <- skgmstack <- rpidru <- rpiswu2 <- rpidrv <- rpisplu <- rpispl <- kkjfnd <- kkjex1e <- kkjsexe <- kkjrdp <- opirip <- opidrv <- sou2o <- opimai_real <- main ============================== Memory Utilization of Subpool 1 ================================ Allocation Name Size _________________________ __________ "free memory " 390197664 "obj stat memo " 403349328 "KGH: NO ACCESS " 16695456 ============================== Memory Utilization of Subpool 2 ================================ Allocation Name Size _________________________ __________ "free memory " 319286368 "obj stat memo " 380580336 "KGH: NO ACCESS " 16728160 ============================== Memory Utilization of Subpool 3 ================================ Allocation Name Size _________________________ __________ "free memory " 325262592 "obj stat memo " 351782568 "KGH: NO ACCESS " 16728160 ============================== Memory Utilization of Subpool 4 ================================ Allocation Name Size _________________________ __________ "free memory " 556035112 "obj stat memo " 551594016 "KGH: NO ACCESS " 32394336 ============================== Memory Utilization of Subpool 5 ================================ Allocation Name Size _________________________ __________ "free memory " 577033336 "obj stat memo " 432672408 "KGH: NO ACCESS " 16736320 ============================== Memory Utilization of Subpool 6 ================================ Allocation Name Size _________________________ __________ "free memory " 333050648 "obj stat memo " 406731024 "KGH: NO ACCESS " 16719968 LIBRARY CACHE STATISTICS: namespace gets hit ratio pins hit ratio reloads invalids -------------- --------- --------- --------- --------- ---------- ---------- CRSR 2214572558 0.355 3977649054 0.403 81251674 34891116 TABL 69900473 0.844 438948912 0.885 11952398 0 BODY 1126452 0.970 86610514 0.999 50956 0 TRGR 104735463 0.994 156443548 0.994 369130 0 INDX 23588405 0.667 47086339 0.801 1478850 0 CLST 2746262 0.997 4303977 0.994 15628 0
SQL> select * from v$sgastat where name='obj stat memo'; POOL NAME BYTES ------------ -------------------------- ---------- shared pool obj stat memo 1454448 SQL> alter system flush shared_pool; System altered. SQL> select * from v$sgastat where name='obj stat memo'; POOL NAME BYTES ------------ -------------------------- ---------- shared pool obj stat memo 1454448
Trace file shows indeed a high size for the ‘obj stat memo’ component but also some imbalance between the subpools.
Bug 5573238 is not an issue here as fixed as from 10.2.0.4 but the workaround can be used here as well. So, setting
“statistics_level”=basic or “_object_statistics”=false should also workaround this issue.The imbalance of the subpools on the other hand might be caused by bug 6271590 which is fixed as from PSU patch
10.2.0.4.2.I would suggest to apply the latest PSU patch available right now and that is 10.2.0.4.4.
For the ‘obj stat memo’ issue, you have to choose between further investigating the issue or using the workaround by
setting “statistics_level”=basic or “_object_statistics”=false.If you want to further investigate the issue, we will need a more detailed heapdump of the ORA-4031.
To Do:
1. Apply PSU patch 10.2.0.4.4 (patch 9352164) on top of patchset 10.2.0.42. Regarding the ‘obj stat memo’ issue:
a) Workaround the issue by setting “statistics_level”=basic or “_object_statistics”=false
+
Bounce the instance-OR-
b) Further investigate the issue:
Set following parameters in the init.ora file (SPFILE/PFILE):
SQL> alter system set max_dump_file_size = unlimited scope=spfile;
SQL> alter system set events ‘4031 trace name heapdump level 536870914’ scope=spfile;Bounce the instance
Once the ORA-4031 reoccurs, provide alert+trace file
So imbalance between subpool can be fixed , and will reduce the likelihood of 4031 occurrence. But we can never flush huge memory used by “obj stat memory”,i think it’s awful .
Leave a Reply