ORA-4031 Troubleshooting – Issue with durations in 11gR2
By Martin | September 3rd, 2017 | Category: 11g, 11gR2, Oracle Database | No Comments »I recently had to troubleshoot an ORA-4031 issue at a client site. The issue reappeared 3 times within 2 months and only after escalating the SR to SEV1 and being quite persistent for an explanation, the second engineer attempting to solve the issue finally got it right. Being curious, I digged into the trace files again to confirm and understand the issue here. This blog post describes the method to analyze the issue and how to troubleshoot.
- First, when the issue first appears, it creates a 4031 trace file, which does not really give enough information to solve the problem. So I asked Oracle Support for specific trace events to properly diagnose it. He correctly mentioned event 10235 level 65536 and heapdump level 536870914 but required an instance restart. After explaining that this is not really possible and researching myself, I found these two events, which do not really need an instance restart. Event 10235 was not really necessary in this case, because the description of the allocations did not matter here.
ALTER system SET events '4031 trace name HEAPDUMP level 536870914, lifetime 1; name errorstack level 3, lifetime 1'; |
- Now, after the issue appeared again, we finally had the relevant diagnostic information.
Allocation Request Summary Informaton ===================================== Allocation request for: kglsim object batch ... Heap: 0x6007b278, size: 3896 ****************************************************** HEAP DUMP heap name="sga heap(3,0)" desc=0x6007b278 extent sz=0xfe0 alt=248 het=32767 rec=9 flg=-126 opc=2 ... durations enabled for this heap reserved granules for root 0 (granule size 134217728) Total heap size =2684352800. (2559 MB) Total free space = 38360 Total reserved free space =120837856 (115MB) Permanent space =2563474760 ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 1 ---------------------------------------------- "free memory " 6597 MB 71% "gcs resources " 1080 MB 12% "gcs shadows " 748 MB 8% "db_block_hash_buckets " 200 MB 2% "kglsim object batch " 189 MB 2% "kglsim heap " 112 MB 1% "gcs res hash bucket " 64 MB 1% "ges big msg buffers " 54 MB 1% "dbktb: trace buffer " 51 MB 1% "KGLH0 " 48 MB 1% ----------------------------------------- free memory 6597 MB memory alloc. 2747 MB Sub total 9344 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 2 ---------------------------------------------- "free memory " 6641 MB 70% "gcs resources " 1080 MB 11% "gcs shadows " 747 MB 8% "db_block_hash_buckets " 512 MB 5% "gcs res hash bucket " 64 MB 1% "kglsim object batch " 59 MB 1% "dbktb: trace buffer " 51 MB 1% "KGLH0 " 44 MB 0% "kglsim heap " 35 MB 0% "ges enqueues " 22 MB 0% ----------------------------------------- free memory 6641 MB memory alloc. 2831 MB Sub total 9472 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 3 ---------------------------------------------- "free memory " 6488 MB 71% "gcs resources " 1080 MB 12% "gcs shadows " 747 MB 8% "db_block_hash_buckets " 200 MB 2% "kglsim object batch " 105 MB 1% "gc name table " 72 MB 1% "gcs res hash bucket " 64 MB 1% "kglsim heap " 63 MB 1% "dbktb: trace buffer " 51 MB 1% "KGLH0 " 46 MB 1% ----------------------------------------- free memory 6488 MB memory alloc. 2600 MB Sub total 9088 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 4 ---------------------------------------------- "free memory " 6663 MB 70% "gcs resources " 1080 MB 11% "gcs shadows " 749 MB 8% "db_block_hash_buckets " 512 MB 5% "kglsim object batch " 59 MB 1% "dbktb: trace buffer " 51 MB 1% "KGLH0 " 47 MB 0% "kglsim heap " 35 MB 0% "FileOpenBlock " 35 MB 0% "ges enqueues " 22 MB 0% ----------------------------------------- free memory 6663 MB memory alloc. 2809 MB Sub total 9472 MB TOTALS --------------------------------------- Total free memory 26 GB Total memory alloc. 11 GB Grand total 37 GB |
- This shows that 4031 was triggered for memory allocation request in sga heap (3,0) with size of 3896. This is smaller than 4400 bytes (_shared_pool_reserved_min_alloc), so the request can not be served the the shared pool reserved area. Next, we can see that we have 4 subpools (kghdsidx_count) and each of them has around 6 GB of free memory. So, in total, we have 37 GB shared pool with 26 GB of it free, but one mini-subpool (duration 0) of subpool 3 still has run out of free contigous memory bigger than 3792 bytes.
- Running Tanel´s heapdump_analyzer, I could verify that the largest chunk for sga heap(3,0) was indeed 3792 bytes and that all bigger chunks were allocated by “PERM” allocations.
./heapdump_analyzer ./PROD1_ora_27396.trc > heap.txt grep -e "---" -e "Total_size" -e "sga heap(3,0)" heap.txt -- Heapdump Analyzer v1.00 by Tanel Poder ( http://www.tanelpoder.com ) Total_size #Chunks Chunk_size, From_heap, Chunk_type, Alloc_reason ---------- ------- ------------ ----------------- ----------------- ----------------- 114123720 17 6713160 , sga heap(3,0), R-free, 28442152 1 28442152 , sga heap(3,0), perm, perm ... 7485000 1 7485000 , sga heap(3,0), perm, perm 6713080 1 6713080 , sga heap(3,0), R-free, 6712104 1 6712104 , sga heap(3,0), R-perm, perm ... 3028568 1 3028568 , sga heap(3,0), perm, perm ... 8928 4 2232 , sga heap(3,0), perm, perm 7864 1 7864 , sga heap(3,0), perm, perm 5488 2 2744 , sga heap(3,0), perm, perm 3792 1 3792 , sga heap(3,0), free, <<<<<<<<<<<<<< ... |
This shows that the first chunk of chunk_type “free” is of 3792 bytes, but request was for 3896 bytes. The
subpool (3,0) only has R-free (for shared_pool_reserved area) and PERM allocations of bigger size. The subpool (3,0) consists of 20 Extents á (128M Granule size). Each extent has
Researching the issue with “PERM” allocations brought me to:
ORA-4031: unable to allocate 4160 bytes of shared memory (“shared pool”,”unknown object”,”sga heap(4,0)”,”modification “) (Doc ID 1675470.1)
This note also confirms that the classification in 4 durations leads to a weak spot of duration 0 in any subpool for memory allocations due to high PERM utilization. The note mentions patch 8857940, which was also finally recommended by the support engineer.
HEAP DUMP heap name="sga heap(1,0)" desc=0x600680e8 Total heap size =2818570440 Total free space = 28008 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< Total reserved free space =127549960 HEAP DUMP heap name="sga heap(1,1)" desc=0x60069940 Total heap size =805305840 Total free space =632590232 Total reserved free space = 40243520 HEAP DUMP heap name="sga heap(1,2)" desc=0x6006b198 Total heap size =1879046960 Total free space =1734275840 Total reserved free space = 93975928 HEAP DUMP heap name="sga heap(1,3)" desc=0x6006c9f0 Total heap size =4294964480 Total free space =4072007248 Total reserved free space =214821040 HEAP DUMP heap name="sga heap(2,0)" desc=0x600719b0 Total heap size =2952788080 Total free space = 19144 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< Total reserved free space =147689440 HEAP DUMP heap name="sga heap(2,1)" desc=0x60073208 Total heap size =671088200 Total free space =524561448 Total reserved free space = 33565720 HEAP DUMP heap name="sga heap(2,2)" desc=0x60074a60 Total heap size =1879046960 Total free space =1738701544 Total reserved free space = 93984160 HEAP DUMP heap name="sga heap(2,3)" desc=0x600762b8 Total heap size =4429182120 Total free space =4202264536 Total reserved free space =221534200 HEAP DUMP heap name="sga heap(3,0)" desc=0x6007b278 Total heap size =2684352800 Total free space = 38360 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< Total reserved free space =120837856 HEAP DUMP heap name="sga heap(3,1)" desc=0x6007cad0 Total heap size =671088200 Total free space =526361840 Total reserved free space = 33565720 HEAP DUMP heap name="sga heap(3,2)" desc=0x6007e328 Total heap size =1879046960 Total free space =1736230384 Total reserved free space = 93977784 HEAP DUMP heap name="sga heap(3,3)" desc=0x6007fb80 Total heap size =4294964480 Total free space =4076323080 Total reserved free space =214821040 HEAP DUMP heap name="sga heap(4,0)" desc=0x60084b40 Total heap size =2952788080 Total free space = 8536 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< Total reserved free space =140977632 HEAP DUMP heap name="sga heap(4,2)" desc=0x60087bf0 Total heap size =1879046960 Total free space =1735347144 Total reserved free space = 93984160 HEAP DUMP heap name="sga heap(4,3)" desc=0x60089448 Total heap size =4429182120 Total free space =4198496144 Total reserved free space =221534200 |
For reference, these are the relevant parameters. Please note that all of these are set to default, except _kghdsidx_count which was reduced from 4 earlier and _ksmg_granule_size which was reduced to 128M.
NAME VALUE ---------------------------------------- -------------------- __shared_pool_size 38923141120 _dm_max_shared_pool_pct 1 _enable_shared_pool_durations TRUE _io_shared_pool_size 4194304 _kghdsidx_count 4 _ksmg_granule_size 134217728 _memory_imm_mode_without_autosga TRUE _shared_pool_max_size 0 _shared_pool_minsize_on FALSE _shared_pool_reserved_min_alloc 4400 _shared_pool_reserved_pct 5 shared_pool_reserved_size 1946157056 shared_pool_size 38654705664 |
Thanks to Tanel, Riyaj and Hatem Mahmoud
