Note: Tested in Oracle 19.17
Update (2023-04-15): With the reproducible test code, Oracle delivered fix:
Patch 35166750: PLSQL JSON DOM API INTERNAL ERROR, QJSNPLSDESTROY CALLED TOO OFTEN AND NOT IMPLEMENTED
1. Test Setup
We create a helper procedure to report PGA usage, one procedure to test JSON, one procedure to test scalar type VARCHAR2.
create or replace procedure rpt_pga(p_name varchar) as
l_v$process_mem varchar2(4000);
l_v$process_memory_mem varchar2(4000);
l_used_mem_mb number;
p_sid number; -- := sys.dbms_support.mysid;
begin
select sid into p_sid from v$mystat where rownum=1;
select round(pga_used_mem/1024/1024),
'Used/Alloc/Freeable/Max >>> '||
round(pga_used_mem/1024/1024) ||'/'||round(pga_alloc_mem/1024/1024)||'/'||
round(pga_freeable_mem/1024/1024)||'/'||round(pga_max_mem/1024/1024)
into l_used_mem_mb, l_v$process_mem
from v$process where addr = (select paddr from v$session where sid = p_sid);
select 'Category(Alloc/Used/Max) >>> '||
listagg(Category||'('||round(allocated/1024/1024)||'/'||
round(used/1024/1024)||'/'||round(max_allocated/1024/1024)||') > ')
within group (order by Category desc) name_usage_list
into l_v$process_memory_mem
from v$process_memory
where pid = (select pid from v$process
where addr = (select paddr from v$session where sid = p_sid));
dbms_output.put_line(rpad(p_name, 15, '-')||'PGA Used(MB): '||l_used_mem_mb);
dbms_output.put_line(rpad(chr(32), 18, chr(32))||rpad(l_v$process_mem, 50));
dbms_output.put_line(rpad(chr(32), 18, chr(32))||l_v$process_memory_mem);
end;
/
--test_json (Json)
create or replace procedure test_json(p_run number, p_loop number) as
type t_tab is table of json_object_t index by pls_integer;
l_tab t_tab;
begin
for i in 1..p_run loop
dbms_output.put_line(rpad('*', 30, '*')||' RUN-'||i||rpad('*', 30, '*'));
rpt_pga('Init');
for i in 1..p_loop loop
l_tab(i) := new json_object_t('{ "abcd":12345 }');
end loop;
rpt_pga('After Create');
l_tab.delete;
--l_tab := new t_tab();
dbms_session.free_unused_user_memory;
rpt_pga('Aftre Free');
end loop;
dbms_output.put_line('');
end;
/
--test_scalar (varchar2)
create or replace procedure test_scalar(p_run number, p_loop number) as
type t_tab is table of varchar2(32000) index by pls_integer;
l_tab t_tab;
begin
for i in 1..p_run loop
dbms_output.put_line(rpad('*', 30, '*')||' RUN-'||i||rpad('*', 30, '*'));
rpt_pga('Init');
for i in 1..p_loop loop
l_tab(i) := '{ "abcd":'|| rpad('12345', 30000, '-') ||'}';
end loop;
rpt_pga('After Create');
l_tab.delete;
--l_tab := new t_tab();
dbms_session.free_unused_user_memory;
rpt_pga('Aftre Free');
dbms_output.put_line('');
end loop;
end;
/
2. Test Run
Open two Sqplus sessions, run following two tests:
In Session-1: exec test_json(3, 10000);
In Session-2: exec test_scalar(3, 10000);
SQL > exec test_json(3, 10000);
****************************** RUN-1******************************
Init-----------PGA Used(MB): 7
Used/Alloc/Freeable/Max >>> 7/8/1/10
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/3/3) > Other(4//4) > Freeable(1/0/) >
After Create---PGA Used(MB): 1253
Used/Alloc/Freeable/Max >>> 1253/1267/0/1267
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(4/4/4) > Other(1263//1263) >
Aftre Free-----PGA Used(MB): 1252
Used/Alloc/Freeable/Max >>> 1252/1267/1/1267
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/2/4) > Other(1263//1263) > Freeable(1/0/) >
****************************** RUN-2******************************
Init-----------PGA Used(MB): 1252
Used/Alloc/Freeable/Max >>> 1252/1267/1/1267
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/2/4) > Other(1263//1263) > Freeable(1/0/) >
After Create---PGA Used(MB): 2501
Used/Alloc/Freeable/Max >>> 2501/2531/0/2531
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(4/4/4) > Other(2527//2527) >
Aftre Free-----PGA Used(MB): 2500
Used/Alloc/Freeable/Max >>> 2500/2531/1/2531
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/4) > Other(2528//2528) > Freeable(1/0/) >
****************************** RUN-3******************************
Init-----------PGA Used(MB): 2500
Used/Alloc/Freeable/Max >>> 2500/2531/1/2531
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/4) > Other(2528//2528) > Freeable(1/0/) >
After Create---PGA Used(MB): 3749
Used/Alloc/Freeable/Max >>> 3749/3779/0/3779
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(4/4/4) > Other(3775//3775) >
Aftre Free-----PGA Used(MB): 3748
Used/Alloc/Freeable/Max >>> 3748/3779/1/3779
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/4) > Other(3776//3776) > Freeable(1/0/) >
when the used nested table is deleted and dbms_session.free_unused_user_memory is called.
The PGA memory is all allocated in Category "Other".
Here the output of test_scalar:
SQL > exec test_scalar(3, 10000);
****************************** RUN-1******************************
Init-----------PGA Used(MB): 7
Used/Alloc/Freeable/Max >>> 7/8/1/10
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/3/3) > Other(5//5) > Freeable(1/0/) >
After Create---PGA Used(MB): 320
Used/Alloc/Freeable/Max >>> 320/322/0/322
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(316/315/316) > Other(6//6) >
Aftre Free-----PGA Used(MB): 7
Used/Alloc/Freeable/Max >>> 7/322/315/322
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/2/316) > Other(4//4) > Freeable(315/0/) >
****************************** RUN-2******************************
Init-----------PGA Used(MB): 7
Used/Alloc/Freeable/Max >>> 7/322/315/322
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/2/316) > Other(4//4) > Freeable(315/0/) >
After Create---PGA Used(MB): 320
Used/Alloc/Freeable/Max >>> 320/322/1/322
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(316/314/316) > Other(5//5) > Freeable(1/0/) >
Aftre Free-----PGA Used(MB): 7
Used/Alloc/Freeable/Max >>> 7/322/315/322
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/316) > Other(5//5) > Freeable(315/0/) >
****************************** RUN-3******************************
Init-----------PGA Used(MB): 7
Used/Alloc/Freeable/Max >>> 7/322/315/322
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/316) > Other(5//5) > Freeable(315/0/) >
After Create---PGA Used(MB): 320
Used/Alloc/Freeable/Max >>> 320/322/1/322
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(315/314/316) > Other(6//6) > Freeable(1/0/) >
Aftre Free-----PGA Used(MB): 7
Used/Alloc/Freeable/Max >>> 7/322/315/322
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/316) > Other(5//5) > Freeable(315/0/) >
when the used nested table is deleted and dbms_session.free_unused_user_memory is called.
3. ORA-04030 Test and Incident File
The above test_json showed that 3 RUNs took 3748 MB, we can make a test with 30 RUNs to check if it reaches 32 GB PGA limit and hence:
ORA-04030: out of process memory
The test hit ORA-04030 in RUN 27.
SQL > exec test_json(30, 10000);
****************************** RUN-1******************************
Init-----------PGA Used(MB): 7
Used/Alloc/Freeable/Max >>> 7/8/0/10
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/3/3) > Other(4//4) > Freeable(0/0/) >
After Create---PGA Used(MB): 1253
Used/Alloc/Freeable/Max >>> 1253/1267/0/1267
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(4/4/4) > Other(1263//1263) >
Aftre Free-----PGA Used(MB): 1252
Used/Alloc/Freeable/Max >>> 1252/1267/1/1267
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/2/4) > Other(1263//1263) > Freeable(1/0/) >
****************************** RUN-2******************************
Init-----------PGA Used(MB): 1252
Used/Alloc/Freeable/Max >>> 1252/1267/1/1267
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(3/2/4) > Other(1263//1263) > Freeable(1/0/) >
After Create---PGA Used(MB): 2501
Used/Alloc/Freeable/Max >>> 2501/2531/0/2531
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(4/4/4) > Other(2527//2527) >
Aftre Free-----PGA Used(MB): 2500
Used/Alloc/Freeable/Max >>> 2500/2531/1/2531
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/4) > Other(2528//2528) > Freeable(1/0/) >
.....
****************************** RUN-26******************************
Init-----------PGA Used(MB): 31044
Used/Alloc/Freeable/Max >>> 31044/31075/1/31075
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/4) > Other(31071//31071) > Freeable(1/0/) >
After Create---PGA Used(MB): 32293
Used/Alloc/Freeable/Max >>> 32293/32323/0/32323
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(4/4/4) > Other(32319//32319) >
Aftre Free-----PGA Used(MB): 32292
Used/Alloc/Freeable/Max >>> 32292/32323/1/32323
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/4) > Other(32319//32319) > Freeable(1/0/) >
****************************** RUN-27******************************
Init-----------PGA Used(MB): 32292
Used/Alloc/Freeable/Max >>> 32292/32323/1/32323
Category(Alloc/Used/Max) >>> SQL(0/0/6) > PL/SQL(2/2/4) > Other(32319//32319) > Freeable(1/0/) >
BEGIN test_json(30, 10000); END;
ERROR at line 1:
ORA-40441: JSON syntax error
ORA-06512: at "SYS.JDOM_T", line 4
ORA-06512: at "SYS.JSON_OBJECT_T", line 28
ORA-06512: at "TEST_JSON", line 9
ORA-06512: at line 1
Elapsed: 00:00:30.71
incident/incdir_51062/testdb_ora_30363_i51062.trc
ORA-04030: out of process memory when trying to allocate 65584 bytes (qjsngGetSessio,qjsnplsAllocMem)
=======================================
TOP 10 MEMORY USES FOR THIS PROCESS
---------------------------------------
*** 2023-03-07T09:36:56.901600+01:00
97% 31 GB, 3414723 chunks: "qjsnplsAllocMem "
qjsngGetSessio ds=0x7fb2ecb36af8 dsprt=0x7fb2ec627228
3% 876 MB, 525337 chunks: "free memory "
qjsnCrPlsHeap ds=0x7fab015e4ea8 dsprt=0x7fb2ecb36af8
0% 106 MB, 262669 chunks: "qjsnCrPlsHeap "
qjsngGetSessio ds=0x7fb2ecb36af8 dsprt=0x7fb2ec627228
0% 36 MB, 525338 chunks: "qjsnCrPls_durArr "
qjsnCrPlsHeap ds=0x7fab015e4ea8 dsprt=0x7fb2ecb36af8
0% 30 MB, 18 chunks: "free memory "
top uga heap ds=0x7fb2f2197e00 dsprt=(nil)
=========================================
REAL-FREE ALLOCATOR DUMP FOR THIS PROCESS
-----------------------------------------
Dump of Real-Free Memory Allocator Heap [0x7fb2ed325000]
mag=0xfefe0001 flg=0x5000007 fds=0x0 blksz=65536
blkdstbl=0x7fb2ed325018, iniblk=524288 maxblk=524288 numsegs=321
In-use num=1464 siz=34226634752, Freeable num=4 siz=1507328, Free num=3 siz=13041664
Client alloc 34228142080 Client freeable 1507328
Internal RfPga 33425920K RgPga 1275K
================================
----- Current SQL Statement for this session (sql_id=2rs9n85h4rb90) -----
BEGIN test_json(30, 10000); END;
----- PL/SQL Call Stack -----
object line object
handle number name
0x98f121e0 4 type body SYS.JDOM_T.PARSE
0x98f1c368 28 type body SYS.JSON_OBJECT_T.JSON_OBJECT_T
0x9adad518 9 procedure TEST_JSON
0x98ef1180 1 anonymous block
--------------------- Binary Stack Dump ---------------------
FRAME [8] (kghnospc()+2639 -> dbgeEndDDEInvocationImpl())
FRAME [9] (kghalf()+2350 -> kghnospc())
FRAME [10] (qjsngAllocMem()+545 -> kghalf())
FRAME [11] (LpxMemAlloc()+1669 -> qjsngAllocMem())
FRAME [12] (jzn0DomPutName()+2868 -> LpxMemAlloc())
FRAME [13] (jzn0DomStoreFieldName()+129 -> jzn0DomPutName())
FRAME [14] (jzn0DomLoadFromInputEventSrc()+2775 -> jzn0DomStoreFieldName())
FRAME [15] (qjsnPlsCreateFromStr()+332 -> jzn0DomLoadFromInputEventSrc())
FRAME [16] (qjsnplsParse()+183 -> qjsnPlsCreateFromStr())
FRAME [17] (spefcpfa()+204 -> qjsnplsParse())
FRAME [18] (spefmccallstd()+551 -> spefcpfa())
FRAME [19] (peftrusted()+139 -> spefmccallstd())
FRAME [20] (psdexsp()+285 -> peftrusted())
FRAME [21] (rpiswu2()+2004 -> psdexsp())
FRAME [22] (kxe_push_env_internal_pp_()+362 -> rpiswu2())
FRAME [23] (kkx_push_env_for_ICD_for_new_session()+149 -> kxe_push_env_internal_pp_())
FRAME [24] (psdextp()+387 -> kkx_push_env_for_ICD_for_new_session())
FRAME [25] (pefccal()+663 -> psdextp())
FRAME [26] (pefcal()+223 -> pefccal())
FRAME [27] (pevm_FCAL()+171 -> pefcal())
FRAME [28] (pfrinstr_FCAL()+62 -> pevm_FCAL())
FRAME [29] (pfrrun_no_tool()+60 -> pfrinstr_FCAL())
FRAME [30] (pfrrun()+902 -> pfrrun_no_tool())
FRAME [31] (plsql_run()+747 -> pfrrun())
