某客户环境rac 19.3出现大量ORA-04031报错，导致业务不能正常运行。
|
1 2 3 4 5 |
[TOC00000] Jump to table of contents Dump continued from file: /oracle/base/diag/rdbms/xxx/xxx/trace/xxx_cjq0_xxx.trc [TOC00001] ORA-04031: unable to allocate 40 bytes of shared memory ("shared pool","unknown object","KGLH0^c112cc58","kglHeapInitialize:temp") |
可以看到该trace在分配KGLH0(heap 0)时出现ORA-04031
|
1 2 3 4 5 6 7 8 9 10 |
===================================== Allocation Request Summary Informaton ===================================== Current information setting: 04014fff SGA Heap Dump Interval=3600 seconds Dump Interval=300 seconds Last Dump Time=04/13/2022 15:20:48 Dump Count=1 Allocation request for: kglHeapInitialize:temp Requested from KGLH0^c112cc58, Heap: 0x14d3e8fa68, size: 40 |
报错显示sub heap KGLH0^c112cc58无法请求40 byte，所以报出了ORA-04031
查看报错subheap的信息
|
1 2 3 4 5 6 |
HEAP DUMP heap name="KGLH0^c112cc58" desc=0x14d3e8fa68 extent sz=0xfe8 alt=32767 het=56 rec=0 flg=0x2 opc=0 parent=0x601762a8 owner=0x14d3e8fa18 nex=(nil) xsz=0x20000000 heap=(nil) fl2=0x26, nex=(nil), idx=2 pdb id=1, src pdb id=1 Subheap has 0 bytes of memory allocated |
该subheap位于subpool 2，extent size为0xfe8(4076)，Subheap has 0 bytes of memory allocated，说明还没有extent挂在subheap下面，此次分配是第一个extent。根据chunk的分配原则，首先尝试在子堆中分配，如果子堆free list无法分配则向父堆申请，这时申请的chunk大小将会是extent size，并作为一个新的extent挂在子堆下，由于是第一个extent，那么请求的大小肯定不是40 bytes，而是向parent heap请求4076 byte作为第一个extent。
parent heap堆描述符为0x601762a8，即sga heap。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 |
HEAP DUMP heap name="sga heap" desc=0x601762a8 extent sz=0xfe0 alt=336 het=32767 rec=9 flg=0x82 opc=0 parent=(nil) owner=(nil) nex=(nil) xsz=0x1 heap=(nil) fl2=0x64, nex=(nil), idx=0 pdb id=1, src pdb id=1 ds for latch 1: 0x60177c00 0x6017c508 ds for latch 2: 0x6018c328 0x60190c30 ds for latch 3: 0x601a0a50 0x601a5358 ds for latch 4: 0x601b5178 0x601b9a80 ds for latch 5: 0x601c98a0 0x601ce1a8 ds for latch 6: 0x601ddfc8 0x601e28d0 ds for latch 7: 0x601f26f0 0x601f6ff8 reserved granule count 0 (granule size 536870912) |
此处可以看出该shared pool有7个subpool。由于报错出在subpool 2，所以看看subpool 2的内存占用情况以及free list
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 |
HEAP DUMP heap name="sga heap(2,0)" desc=0x6018c328 extent sz=0xfe0 alt=336 het=32767 rec=9 flg=0x82 opc=0 parent=(nil) owner=(nil) nex=(nil) xsz=0x20000000 heap=(nil) fl2=0x24, nex=(nil), idx=2, dsxvers=1, dsxflg=0x0 dsx first ext=0x1920000000 dsx empty ext bytes=0 subheap rc link=0x19200000d0,0x19200000d0 dsx heap size=45097147872, dsx heap depth=0 pdb id=1, src pdb id=1 latch set 2 of 7 durations enabled for this heap reserved granules for root 0 (granule size 536870912) (only free lists will be dumped) (dumping chunk summaries only in each section) FREE LISTS: Bucket 240 size=4096 free sz= 94208 chunks= 23 Bucket 241 size=4104 (empty) Bucket 242 size=4120 free sz= 52032 chunks= 11 sz range 4152 (2) to 8192 (1) Empty bucket sizes 8216 8752 8760 8768 Bucket 247 size=8776 free sz= 9312 chunks= 1 Bucket 248 size=9384 (empty) Bucket 249 size=9392 free sz= 43680 chunks= 4 sz range 10320 (1) to 11200 (1) Empty bucket sizes 12368 12376 16408 32792 65560 (due to latch contention avoidance, not all the free space has been counted) Total free space = 1846520 |
可以看到subpool 2 free list下面的bucket还有符合大小的chunk，为何没有分配呢？个人觉得此时的trace是报错之后生成的，很可能报错之后通过lru out了一些chunk，或者是shared pool growth。从trace中发现，该session确实在等待sga growth。但是是否growth成功可以通过mman trace验证。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 |
========================= User Session State Object ========================= ---------------------------------------- SO: 0x197fd33638, type: session (4), map: 0x1902cad7d0 state: LIVE (0x4532), flags: 0x1 owner: 0x197fefe778, proc: 0x197fefe778 link: 0x197fd33658[0x197dd610d8, 0x197dd548d8] child list count: 34, link: 0x197fd336a8[0x153ef7b200, 0x183dd68200] conid: 1, conuid: 1, SGA version=(1,0), pg: 0 SOC: 0x1902cad7d0, type: session (4), map: 0x197fd33638 state: LIVE (0x99fc), flags: INIT (0x1) (session) sid: 6331 ser: 3854 trans: (nil), creator: 0x18e1be3cf0 flags: (0x51) USR/- flags2: (0x40409) -/-/INC flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/- DID: 0005-010C-000000030005-010C-00000002, short-term DID: txn branch: (nil) con_id/con_uid/con_name: 1/1/CDB$ROOT con_logonuid: 1 con_logonid: 1 con_scuid: 1 con_scid: 1 edition#: 0 user#/name: 0/SYS oct: 0, prv: 0, sql: (nil), psql: 0x147d60fba0 stats: 0x14de3898d8, PX stats: 0x1296d044 service name: SYS$BACKGROUND Current Wait Stack: Not in wait; last wait ended 0.092661 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=(nil)/-1 Session Wait History: elapsed time of 0.092700 sec since last wait 0: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348206 seq_num=23551 snap_id=26 wait times: snap=0.000000 sec, exc=2.498672 sec, total=2.501008 sec wait times: max=infinite wait counts: calls=25 os=25 occurred after 0.000000 sec of elapsed time 1: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348231 seq_num=23550 snap_id=1 wait times: snap=0.000100 sec, exc=0.000100 sec, total=0.000100 sec wait times: max=infinite wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time 2: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348206 seq_num=23549 snap_id=25 wait times: snap=0.099889 sec, exc=2.498672 sec, total=2.500908 sec wait times: max=infinite wait counts: calls=25 os=25 occurred after 0.000000 sec of elapsed time 3: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348230 seq_num=23548 snap_id=1 wait times: snap=0.000102 sec, exc=0.000102 sec, total=0.000102 sec wait times: max=infinite wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time 4: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348206 seq_num=23547 snap_id=24 wait times: snap=0.099898 sec, exc=2.398783 sec, total=2.400917 sec wait times: max=infinite wait counts: calls=24 os=24 occurred after 0.000000 sec of elapsed time 5: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348229 seq_num=23546 snap_id=1 wait times: snap=0.000101 sec, exc=0.000101 sec, total=0.000101 sec wait times: max=infinite wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time 6: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348206 seq_num=23545 snap_id=23 wait times: snap=0.099873 sec, exc=2.298885 sec, total=2.300918 sec wait times: max=infinite wait counts: calls=23 os=23 occurred after 0.000000 sec of elapsed time 7: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348228 seq_num=23544 snap_id=1 wait times: snap=0.000133 sec, exc=0.000133 sec, total=0.000133 sec wait times: max=infinite wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time 8: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348206 seq_num=23543 snap_id=22 wait times: snap=0.099881 sec, exc=2.199012 sec, total=2.200912 sec wait times: max=infinite wait counts: calls=22 os=22 occurred after 0.000000 sec of elapsed time 9: waited for 'SGA: allocation forcing component growth' =0x0, =0x0, =0x0 wait_id=73348227 seq_num=23542 snap_id=1 wait times: snap=0.000105 sec, exc=0.000105 sec, total=0.000105 sec wait times: max=infinite wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time |
下面就应该去看看subpool 2的内存占用情况是否正常，是否有异常的组件占用了大量内存
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 |
============================================== TOP 10 MAXIMUM MEMORY USES FOR SGA HEAP SUB POOL 1 ---------------------------------------------- "SQLA 0006" 7604 MB "free memory " 6047 MB "SQLA 0001" 1512 MB "KGLH0 0006" 1232 MB "gcs resources 0001" 1088 MB "gcs shadows 0001" 594 MB "KGLHD 0006" 158 MB "db_block_hash_buckets 0001" 148 MB "KGLH0 0001" 114 MB "file queue buckets 0001" 84 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 2 ---------------------------------------------- "gcs dynamic shadows lms 0001" 32 GB 66% "free memory " 11 GB 22% "SQLA 0006" 2715 MB 5% "gcs resources 0001" 1088 MB 2% "gcs shadows 0001" 594 MB 1% "KGLH0 0006" 592 MB 1% "gc name table 0001" 256 MB 1% "db_block_hash_buckets 0001" 144 MB 0% "FileIdentificatonBlock 0001" 129 MB 0% "KGLHD 0006" 96 MB 0% ----------------------------------------- free memory 11 GB memory alloc. 38 GB Sub total 49 GB ============================================== TOP 10 MAXIMUM MEMORY USES FOR SGA HEAP SUB POOL 2 ---------------------------------------------- "gcs dynamic shadows lms 0001" 32 GB "free memory " 11 GB "SQLA 0006" 6322 MB "KGLH0 0006" 1188 MB "gcs resources 0001" 1088 MB "KGH: NO ACCESS 0001" 603 MB "gcs shadows 0001" 594 MB "gc name table 0001" 256 MB "SQLA 0001" 233 MB "KGLHD 0006" 164 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 3 ---------------------------------------------- "SQLA 0006" 5845 MB 48% "free memory " 1789 MB 15% "gcs resources 0001" 1089 MB 9% "KGLH0 0006" 1030 MB 8% "gcs shadows 0001" 594 MB 5% "SQLA 0001" 444 MB 4% "gc name table 0001" 256 MB 2% "db_block_hash_buckets 0001" 148 MB 1% "KGLHD 0006" 135 MB 1% "VIRTUAL CIRCUITS 0001" 113 MB 1% ----------------------------------------- free memory 1789 MB memory alloc. 10 GB Sub total 12 GB ============================================== TOP 10 MAXIMUM MEMORY USES FOR SGA HEAP SUB POOL 3 ---------------------------------------------- "SQLA 0006" 6716 MB "free memory " 5159 MB "KGLH0 0006" 1125 MB "gcs resources 0001" 1089 MB "gcs shadows 0001" 594 MB "SQLA 0001" 454 MB "gc name table 0001" 256 MB "db_block_hash_buckets 0001" 148 MB "KGLHD 0006" 146 MB "VIRTUAL CIRCUITS 0001" 113 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 4 ---------------------------------------------- "SQLA 0006" 5429 MB 46% "free memory " 1801 MB 15% "gcs resources 0001" 1089 MB 9% "KGLH0 0006" 1043 MB 9% "gcs shadows 0001" 594 MB 5% "SQLA 0001" 452 MB 4% "gc name table 0001" 256 MB 2% "KGLHD 0006" 153 MB 1% "db_block_hash_buckets 0001" 144 MB 1% "KGLH0 0001" 92 MB 1% ----------------------------------------- free memory 1801 MB memory alloc. 10 GB Sub total 12 GB ============================================== TOP 10 MAXIMUM MEMORY USES FOR SGA HEAP SUB POOL 4 ---------------------------------------------- "SQLA 0006" 6293 MB "free memory " 4531 MB "gcs resources 0001" 1089 MB "KGLH0 0006" 1073 MB "gcs shadows 0001" 594 MB "SQLA 0001" 455 MB "ges regular msg 0001" 276 MB "gc name table 0001" 256 MB "KGLHD 0006" 153 MB "db_block_hash_buckets 0001" 144 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 5 ---------------------------------------------- "SQLA 0006" 13 GB 42% "free memory " 11 GB 38% "KGLH0 0006" 2775 MB 9% "gcs resources 0001" 1088 MB 3% "gcs shadows 0001" 593 MB 2% "KGLHD 0006" 337 MB 1% "gc name table 0001" 256 MB 1% "KGLDA 0006" 167 MB 1% "db_block_hash_buckets 0001" 148 MB 0% "file queue buckets 0001" 84 MB 0% ----------------------------------------- free memory 11 GB memory alloc. 19 GB Sub total 31 GB ============================================== TOP 10 MAXIMUM MEMORY USES FOR SGA HEAP SUB POOL 5 ---------------------------------------------- "SQLA 0006" 22 GB "free memory " 11 GB "KGLH0 0006" 2911 MB "gcs resources 0001" 1088 MB "KGH: NO ACCESS 0001" 603 MB "gcs shadows 0001" 593 MB "KGLHD 0006" 376 MB "ges big msg 0001" 340 MB "gc name table 0001" 256 MB "KGLDA 0006" 176 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 6 ---------------------------------------------- "SQLA 0006" 5226 MB 44% "free memory " 2013 MB 17% "KGLH0 0006" 1196 MB 10% "gcs resources 0001" 1089 MB 9% "gcs shadows 0001" 593 MB 5% "SQLA 0001" 282 MB 2% "KGLHD 0006" 177 MB 2% "db_block_hash_buckets 0001" 148 MB 1% "KSRMA State Object 0001" 96 MB 1% "KGLH0 0001" 84 MB 1% ----------------------------------------- free memory 2013 MB memory alloc. 10 GB Sub total 12 GB ============================================== TOP 10 MAXIMUM MEMORY USES FOR SGA HEAP SUB POOL 6 ---------------------------------------------- "SQLA 0006" 6664 MB "free memory " 4778 MB "KGLH0 0006" 1349 MB "gcs resources 0001" 1089 MB "gcs shadows 0001" 593 MB "SQLA 0001" 285 MB "KGLHD 0006" 189 MB "db_block_hash_buckets 0001" 148 MB "KSRMA State Object 0001" 96 MB "KGLH0 0001" 84 MB ============================================== TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 7 ---------------------------------------------- "free memory " 4151 MB 35% "SQLA 0006" 2906 MB 25% "gcs resources 0001" 1089 MB 9% "KGLH0 0006" 715 MB 6% "SQLA 0001" 625 MB 5% "gcs shadows 0001" 594 MB 5% "SO private sga 0001" 284 MB 2% "ges big msg buffers 0001" 207 MB 2% "db_block_hash_buckets 0001" 144 MB 1% "ksipc state object 0001" 127 MB 1% ----------------------------------------- free memory 4151 MB memory alloc. 7625 MB Sub total 12 GB ============================================== TOP 10 MAXIMUM MEMORY USES FOR SGA HEAP SUB POOL 7 ---------------------------------------------- "SQLA 0006" 6080 MB "free memory " 4621 MB "gcs resources 0001" 1089 MB "KGLH0 0006" 887 MB "SQLA 0001" 671 MB "gcs shadows 0001" 594 MB "SO private sga 0001" 284 MB "ges big msg buffers 0001" 207 MB "db_block_hash_buckets 0001" 144 MB "KGLHD 0006" 139 MB TOTALS --------------------------------------- Total free memory 34 GB Total memory alloc. 105 GB Grand total 139 GB ============================================== |
可以很清晰的看到subpool 2的gcs dynamic shadows lms组件占用了32g内存，并且其他subpool都是正常的。这种多半是bug导致的。
查询mos文档发现匹配Bug 30223374 – Memory Leak Due to “gcs dynamic shadows lms” (Doc ID 30223374.8)
This fix has been superseded – please see the fixed version information for Bug:30318638 . The box below only shows versions where the code change/s for 30223374 are first included – those versions may not contain the later improved fix.
Fixed:
The fix for 30318638 is first included in