Sunday, November 28, 2021

Oracle dbms_aq.dequeue_array Shared Pool "KTC Latch Subh" Memory Leak

This Blog will try to demonstrate shared pool "KTC Latch Subh" memory leak when using AQ array dequeue: dbms_aq.dequeue_array (enqueue_array and dequeue_array introduced in 10g).

Note 1: Tested in Oracle 19c with following settings:
 
  -- disable autosga to generate ORA-04031
  alter system set "_memory_imm_mode_without_autosga"=false;
 
  -- set small shared_pool to quickly hit ORA-04031 due to "KTC latch subh"
  alter system set shared_pool_size=1008M scope=spfile;  
  
  -- set 3 subpools in shared_pool
  alter system set "_kghdsidx_count"=3 scope=spfile; 
 
Note 2: The behaviour was first observed by other people in Oracle applications.


1. "KTC latch subh" Memory Leak Test


At first, we run test_aq_loop (see section 4 "Test Code") to make 3 array_enqueue / array_dequeue calls with array_size: 1000, 2000, and 3000 one after another. Each time the same number of messages are first enqueued and then dequeued.

The output shows that 'KTC latch subh' memory is increased progressively from 0.5 MB to 6 MB. The increase only occurs in Dequeue_Array, but not Enqueue_Array.

SQL > select round(bytes/1024/1024, 2) KTC_MB from v$sgastat where name = 'KTC latch subh';
    KTC_MB
    ------
       .05
 
SQL > exec test_aq_loop('ArrayEnq',  'ArrayDeq',  3, 0, 1e3);
 
  RUN = 1 at 06:27:46
    Enqueue_Array.Size = 1000, KTC latch subh MB = .05
    Dequeue_Array.Size = 1000, KTC latch subh MB = 1.04
    Enqueue_Array.Size = 2000, KTC latch subh MB = 1.05
    Dequeue_Array.Size = 2000, KTC latch subh MB = 3.03
    Enqueue_Array.Size = 3000, KTC latch subh MB = 3.04
    Dequeue_Array.Size = 3000, KTC latch subh MB = 6.01
   
    Elapsed: 00:00:03.34
 
SQL > select round(bytes/1024/1024, 2) KTC_MB from v$sgastat where name = 'KTC latch subh';
    KTC_MB
    ------
      6.01
Then make 3 array_enqueue / array_dequeue calls with 10 times bigger array_size: 10000, 20000, and 30000 one after another.

The output shows that 'KTC latch subh' memory is increased progressively from 6 MB to 55 MB. Again the increase only occurs in Dequeue_Array, but not Enqueue_Array.

SQL > exec test_aq_loop('ArrayEnq',  'ArrayDeq',  3, 0, 1e4);
 
  RUN = 2 at 06:28:41
    Enqueue_Array.Size = 10000, KTC latch subh MB = 6.01
    Dequeue_Array.Size = 10000, KTC latch subh MB = 15.93
    Enqueue_Array.Size = 20000, KTC latch subh MB = 15.94
    Dequeue_Array.Size = 20000, KTC latch subh MB = 25.85
    Enqueue_Array.Size = 30000, KTC latch subh MB = 25.86
    Dequeue_Array.Size = 30000, KTC latch subh MB = 55.61
   
    Elapsed: 00:00:23.01
 
SQL > select round(bytes/1024/1024, 2) KTC_MB from v$sgastat where name = 'KTC latch subh';
 
    KTC_MB
    ------
     55.61
As a third test, make 3 array_enqueue / array_dequeue calls with 100 times bigger array_size: 100000, 200000, and 300000 one after another.

The output shows that 'KTC latch subh' memory reaches 445 MB from 55 MB and process terminated with "ORA-04031: unable to allocate 872 for KTC latch subh". Same as above two tests, the increase only occurs in Dequeue_Array, but not Enqueue_Array.

Only first two Dequeue_Array calls succeeded, the third Dequeue_Array call requires more than 445 MB "KTC latch subh" and no more free memory is available for 'KTC latch subh'.

SQL > exec test_aq_loop('ArrayEnq',  'ArrayDeq',  3, 0, 1e5);
 
  RUN = 3 at 06:30:14
  Enqueue_Array.Size = 100000, KTC latch subh MB = 55.61
  Dequeue_Array.Size = 100000, KTC latch subh MB = 154.79
  Enqueue_Array.Size = 200000, KTC latch subh MB = 154.8
  Dequeue_Array.Size = 200000, KTC latch subh MB = 350.19
  Enqueue_Array.Size = 300000, KTC latch subh MB = 350.19
  BEGIN test_aq_loop('ArrayEnq',  'ArrayDeq',  3, 0, 1e5); END;
 
  *
  ERROR at line 1:
  ORA-04031: unable to allocate 456 bytes of shared memory ("shared pool","select cols,audit$,textlengt...","SQLA^ca34c3df","opixpop:kctdef")
  ORA-06512: at "K.TEST_AQ_LOOP", line 15
  ORA-06512: at "K.TEST_AQ_LOOP", line 58
  ORA-04031: unable to allocate 872 bytes of shared memory ("shared pool","unknown object","KTC latch subh","KTCCC OBJECT")
  ORA-06512: at "SYS.DBMS_AQ", line 1107
  ORA-06512: at "K.TEST_DEQ_ARRAY", line 16
  ORA-06512: at "K.TEST_AQ_LOOP", line 49
  ORA-06512: at line 1
 
  Elapsed: 00:08:11.47
 
SQL > select round(bytes/1024/1024, 2) KTC_MB from v$sgastat where name = 'KTC latch subh';
    KTC_MB
    ------
     445.9
We can also list 'KTC latch subh' KSMCHPAR areas ("DS" or "desc"), each of which contains a set of Chunks. There are 11 such areas (more areas in bigger shared_pool). Average Chunk size is about 4 KB. (above ORA-04031 occurs when unable to allocate 872 bytes).

select ksmchpar, round(sum(ksmchsiz)/1024/1024, 2) mb, count(*), round(avg(ksmchsiz)) avg, min(ksmchsiz) min, max(ksmchsiz) max
  from  x$ksmsp
 where ksmchcom = 'KTC latch subh'
 group by ksmchpar order by mb desc;
 
  KSMCHPAR                 MB   COUNT(*)        AVG        MIN        MAX
  ---------------- ---------- ---------- ---------- ---------- ----------
  00000000934D5B50     199.52      50031       4182        920       4320
  00000000934D58A8     126.21      32822       4032        920       4320
  00000000934D5DF8      99.76      25016       4182       1000       4320
  00000000934D5BD8      19.96       5002       4184       2616       4320
  00000000934D5C60          2        502       4184       4184       4320
  00000000934D5A40          1        254       4148        920       4320
  00000000934D59B8        .01          2       4252       4184       4320
  00000000934D5930        .01          2       4252       4184       4320
  00000000934D5CE8        .01          2       4252       4184       4320
  00000000934D5D70        .01          3       1899        504       4320
  00000000934D5AC8        .01          2       4252       4184       4320
 
  11 rows selected.
To further identify memory usage, we can pick one KSMCHPAR and make a heapdump, for example:

  oradebug dump heapdump_addr 2 0x00000000934D5B50        
The dump file list all "KTC latch subh" Chunks, each of which is noted with "sz= 4144". The most noticeable text is "TEST_Q", which is exactly the queue_name used in our Test Code.

  ******************************************************
  HEAP DUMP heap name="KTC latch subh"  desc=0x934d5b50
   extent sz=0x1040 alt=32767 het=32767 rec=9 flg=0x3 opc=0
   parent=0x601476e0 owner=(nil) nex=(nil) xsz=0x1040 heap=(nil)
   fl2=0x24, fl3=0x0, nex=(nil), idx=1, dur=1, dsxvers=1, dsxflg=0x0
  dsx first ext=0x849428e0
   dsx empty ext bytes=207207648  subheap rc link=0x84942960,0x84942960
   dsx heap size=207211904, dsx heap depth=1
   pdb id=0, src pdb id=0
  EXTENT 0 addr=0x667a9180
    Chunk        0667a9190 sz=     4144    free      "               "
  Dump of memory from 0x00000000667A9190 to 0x00000000667AA1C0
  0667A9190 00001031 D0B38F00 00000000 00000000  [1...............]
  0667A91A0 667AA1F8 00000000 84942930 00000000  [..zf....0)......]
  0667A91B0 01010101 00000000 00000000 00000000  [................]
  0667A91C0 00000000 00000000 00000000 00000000  [................]
  ...
  0667A9EB0 00000000 00000000 00000000 00000000  [................]
          Repeat 6 times
  0667A9F20 00000001 54534554 0000515F 00000000  [....TEST_Q......]
  0667A9F30 00000000 00000000 00000000 00000000  [................]
By the way, above "SQLA^ca34c3df" can be found by:

select hash_value, sql_id, last_active_time, executions, rows_processed, sql_text  --, v.*
  from v$sqlarea v where hash_value = to_number('ca34c3df', 'xxxxxxxxx');
 
  HASH_VALUE SQL_ID        LAST_ACTIVE_TIME     EXECUTIONS ROWS_PROCESSED SQL_TEXT
  ---------- ------------- ---------------- ---------- -------------- ------------------------------------------------------------------------------------------
  3392455647 c1aqra3539hyz         07:25:03          2              2 select cols,audit$,textlength,intcols,nvl(property,0),flags,rowid from view$ where obj#=:1
During the test, we also record the "KTC latch subh" and PGA allocation in table test_aq_array_runs. Here the details about each STEP of every RUN.

We can see KTC_SUBH_MB increase in each ArrayDeq (KTC_DELTA > 0), but not ArrayEnq (KTC_DELTA = 0). Therefore it seems memory leak in dbms_aq.dequeue_array. The memory increased size is almost linear to dequeue array_size.

select d.*, ktc_subh_mb - lag(ktc_subh_mb) over (partition by run order by step) ktc_delta
  from test_aq_array_runs d order by 1, 2, 3;
 
  RUN STEP TIME      ACTION                    ARRAY_SIZE KTC_SUBH_MB PGA_ALLOC_MB SUBH_DETAILS                                              KTC_DELTA
  --- ---- --------  ------------------------- ---------- ----------- ------------ -------------------------------------------------------- ----------
    1    0 06:27:47  ArrayEnq-ArrayDeq Start                        0           11 ksmchcls: (freeabl=0MB, CNT=3); (recr=0MB, CNT=9)
    1    1 06:27:48  ArrayEnq                        1000           0           23 ksmchcls: (freeabl=0MB, CNT=4); (recr=0MB, CNT=9)                 0
    1    1 06:27:48  ArrayDeq                        1000           1           40 ksmchcls: (freeabl=1MB, CNT=256); (recr=0MB, CNT=9)               1
    1    2 06:27:48  ArrayEnq                        2000           1           44 ksmchcls: (freeabl=1MB, CNT=257); (recr=0MB, CNT=9)               0
    1    2 06:27:49  ArrayDeq                        2000           3           58 ksmchcls: (freeabl=3MB, CNT=757); (recr=0MB, CNT=9)               2
    1    3 06:27:49  ArrayEnq                        3000           3           58 ksmchcls: (freeabl=3MB, CNT=757); (recr=0MB, CNT=10)              0
    1    3 06:27:50  ArrayDeq                        3000           6           76 ksmchcls: (freeabl=6MB, CNT=1510); (recr=0MB, CNT=10)             3
 
    2    0 06:28:42  ArrayEnq-ArrayDeq Start                        6           10 ksmchcls: (freeabl=6MB, CNT=1510); (recr=0MB, CNT=10)
    2    1 06:28:44  ArrayEnq                       10000           6          120 ksmchcls: (freeabl=6MB, CNT=1511); (recr=0MB, CNT=10)             0
    2    1 06:28:45  ArrayDeq                       10000          16          202 ksmchcls: (freeabl=16MB, CNT=4011); (recr=0MB, CNT=10)           10
    2    2 06:28:50  ArrayEnq                       20000          16          218 ksmchcls: (freeabl=16MB, CNT=4011); (recr=0MB, CNT=11)            0
    2    2 06:28:53  ArrayDeq                       20000          26          380 ksmchcls: (freeabl=26MB, CNT=6511); (recr=0MB, CNT=11)           10
    2    3 06:29:00  ArrayEnq                       30000          26          380 ksmchcls: (freeabl=26MB, CNT=6512); (recr=0MB, CNT=11)            0
    2    3 06:29:04  ArrayDeq                       30000          56          562 ksmchcls: (freeabl=56MB, CNT=14013); (recr=0MB, CNT=11)          30
 
    3    0 06:30:14  ArrayEnq-ArrayDeq Start                       56           10 ksmchcls: (freeabl=56MB, CNT=14013); (recr=0MB, CNT=11)
    3    1 06:30:43  ArrayEnq                      100000          56          981 ksmchcls: (freeabl=56MB, CNT=14013); (recr=0MB, CNT=11)           0
    3    1 06:31:09  ArrayDeq                      100000         155         1817 ksmchcls: (freeabl=156MB, CNT=39027); (recr=0MB, CNT=11)         99
    3    2 06:32:19  ArrayEnq                      200000         155         1961 ksmchcls: (freeabl=156MB, CNT=39028); (recr=0MB, CNT=11)          0
    3    2 06:33:52  ArrayDeq                      200000         350         3595 ksmchcls: (freeabl=352MB, CNT=88304); (recr=0MB, CNT=11)        195
    3    3 06:36:00  ArrayEnq                      300000         350         2893 ksmchcls: (freeabl=352MB, CNT=88305); (recr=0MB, CNT=11)          0
Above output shows that all allocated memory are with Chunk type: "freeabl" (Freeable), no Chunk type "recr" (Recreatable). But they cannot be evicted even with flushing shared_pool ("alter system flush shared_pool"). The last resort is DB restart.

Chunk types are documented in Oracle MOS: "Troubleshooting and Diagnosing ORA-4031 Error [Video] (Doc ID 396940.1)"

  Chunk types:
 
    Normal (freeable) chunks - These chunks are allocated in such a way that the user can explicitly free
    the chunk once they have finished with the memory.
   
    Free chunks - These chunks are free and available for reuse should a request come into the pool for
    this chunk size or smaller.
   
    Recreatable chunks - This is a special form of "freeable" memory.  These chunks are placed on an
    LRU list when they are unpinned.   If memory is needed, we go to the LRU list and free "recreatable"
    memory that hasn't been used for a while.
    
    Permanent chunks - These chunks can be allocated in different ways.   Some chunks are allocated
    and will remain in use for the "life" of the instance.   Some "permanent" chunks are allocated but can
    be used over and over again internally as they are available.


2. ORA-04031 incident file


In ORA-04031 incident file, Call Stack shows that ORA-04031 is raised in "ktccAddCbkObj" calling to "kghalo", which hit no space "kghnospc".

----- Call Stack -----                                                     
 FRAME [1]  (ksedst1()+95 -> kgdsdst())                                                 
 FRAME [2]  (ksedst()+58 -> ksedst1())                                                  
 FRAME [3]  (dbkedDefDump()+23448 -> ksedst())                                          
 FRAME [4]  (ksedmp()+577 -> dbkedDefDump())                                            
 FRAME [5]  (dbgexPhaseII()+2092 -> ksedmp())                                           
 FRAME [6]  (dbgexExplicitEndInc()+285 -> dbgexPhaseII())                               
 FRAME [7]  (dbgeEndDDEInvocationImpl()+314 -> dbgexExplicitEndInc())  
                  
 FRAME [8]  (kghnospc()+4787 -> dbgeEndDDEInvocationImpl())                              
 FRAME [9]  (kghalo()+4255 -> kghnospc())                                               
 FRAME [10] (ktccAddCbkObj()+487 -> kghalo())                                           
 FRAME [11] (kwqidracbk()+255 -> ktccAddCbkObj())                                      
 FRAME [12] (kwqidcpmc()+2716 -> kwqidracbk())                                         
 FRAME [13] (kwqidafm0()+6345 -> kwqidcpmc())                                           
 FRAME [14] (kwqididqx()+2368 -> kwqidafm0())                                          
 FRAME [15] (kwqideqarr()+2295 -> kwqididqx())                                         
 FRAME [16] (kwqideqarr0()+49 -> kwqideqarr())                                         
 FRAME [17] (spefcifa()+1286 -> kwqideqarr0())                                         
 FRAME [18] (spefmccallstd()+436 -> spefcifa())                                        
 FRAME [19] (peftrusted()+139 -> spefmccallstd())                                      
 FRAME [20] (psdexsp()+280 -> peftrusted())                                            
 FRAME [21] (rpiswu2()+2077 -> 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()+90 -> pefcal())                                               
 FRAME [28] (pfrinstr_FCAL()+62 -> pevm_FCAL())                                        
 FRAME [29] (pfrrun_no_tool()+52 -> pfrinstr_FCAL())                                    
 FRAME [30] (pfrrun()+902 -> pfrrun_no_tool())                                         
 FRAME [31] (plsql_run()+1498 -> pfrrun())                                             
In fact, kghalo first calls kghfnd_in_free_lists, but no space found, thus jump to kghnospc (no space found).

  #0  0x0000000004e19e5d in kghfnd_in_free_lists ()
  #1  0x0000000004e177ad in kghalo ()
  #2  0x0000000001d1ccf7 in ktccAddCbkObj ()
ORA-04031 incident file also shows the detail memory allocation in each subpools (we set "_kghdsidx_count"=3 in our test), where "KTC latch subh" are ranked as the highest.

By the way, three occurrences of "SO private sga" in each of three subpools showed that the bug revealed in Blog: Oracle 19c new shared pool "SO private sga" and "SO private so latch" Performance Impacts is fixed in this test DB.

  ==============================================
  TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 1
  ----------------------------------------------
  "KTC latch subh                 "   198 MB 48%
  "free memory                    "    69 MB 17%
  "FileIdentificatonBlock         "    13 MB  3%
  "ksunfy_meta 1                  "  9324 KB  2%
  "SQLA                           "  8702 KB  2%
  "SO private sga                 "  8223 KB  2%
  "KGLH0                          "  6878 KB  2%
  "db_block_hash_buckets          "  5440 KB  1%
  "private strands                "  5187 KB  1%
  "KGLS                           "  4221 KB  1%
      
  ==============================================
  TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 2
  ----------------------------------------------
  "KTC latch subh                 "   146 MB 46%
  "free memory                    "    51 MB 16%
  "ksunfy_meta 1                  "  9324 KB  3%
  "SO private sga                 "  8777 KB  3%
  "ksipc state object             "  7602 KB  2%
  "KSRMA State Object             "  5705 KB  2%
  "db_block_hash_buckets          "  5504 KB  2%
  "private strands                "  5320 KB  2%
  "ASH buffers                    "  4096 KB  1%
  "KSFD SGA I/O b                 "  4092 KB  1%
      
  ==============================================
  TOP 10 MEMORY USES FOR SGA HEAP SUB POOL 3
  ----------------------------------------------
  "KTC latch subh                 "   101 MB 37%
  "free memory                    "    45 MB 17%
  "ksunfy_meta 1                  "  9324 KB  3%
  "SO private sga                 "  8925 KB  3%
  "SQLA                           "  7807 KB  3%
  "KGLH0                          "  6938 KB  2%
  "db_block_hash_buckets          "  5444 KB  2%
  "private strands                "  5187 KB  2%
  "PLMCD                          "  4619 KB  2%
  "ASH buffers                    "  4096 KB  1%
In incident file, we can also find above heapdump KSMCHPAR: desc=0x934d5b50, which is marked as "ds=0x934d5b50".

For "KSMCHPAR = 00000000934D5B50" in above x$ksmsp query, size (199.52 MB) and chunk count (50031) is noted as "sz=209213168 ct= 50031" in incident file.

  Chunk        0667a9168 sz=     4184    freeable  "KTC latch subh "  ds=0x934d5b50
  Chunk        0667aa1c0 sz=     4184    freeable  "KTC latch subh "  ds=0x934d5b50
  ...
  Chunk        084677d58 sz=     4184    freeable  "KTC latch subh "  ds=0x934d5b50
       ds        0934d5b50 sz=209213168 ct=    50031
Pick one Chunk addr, for example, 0667a9168, with following query, it can be found by "lower(ksmchptr) like '%0667a9168'" in x$ksmsp.

select * from x$ksmsp
 where ksmchcom = 'KTC latch subh' and ksmchpar = '00000000934D5B50' and lower(ksmchptr) like '%0667a9168';   
 
  ADDR               INDX INST_ID CON_ID   KSMCHIDX KSMCHDUR KSMCHCOM       KSMCHPTR         KSMCHSIZ KSMCHCLS KSMCHTYP KSMCHPAR
  ---------------- ------ ------- ------ ---------- -------- -------------- ---------------- -------- -------- -------- ----------------
  00007F05EBE80DF8 235272       1      0          1        1 KTC latch subh 00000000667A9168     4184 freeabl         0 00000000934D5B50


3. Other enqueue/dequeue Cases


If we make message "single enqueue/single dequeue" or "array enqueue/ single dequeue", there are no 'KTC latch subh' memory leak observed.

  exec test_aq_loop('SingleEnq', 'SingleDeq', 3, 0, 1e3);
  exec test_aq_loop('ArrayEnq',  'SingleDeq', 3, 0, 1e3);
But with "single enqueue/array dequeue", we can also observe the similar 'KTC latch subh' memory leak as "array enqueue/array dequeue".

  exec test_aq_loop('SingleEnq', 'ArrayDeq',  3, 0, 1e3);
In conclusion, this Blog demonstrated "KTC Latch Subh" memory leak in dbms_aq.dequeue_array.


4. Test Code


----==================== 1. AQ Setup====================----
 
begin sys.dbms_aqadm.drop_queue_table(queue_table => 'TEST_QTAB', force=> TRUE); end;
/
 
drop type payload_rec force;
 
create or replace noneditionable type payload_rec force as object(r1 number, r2 varchar2(10))
/
 
drop type test_payload force;
 
create or replace noneditionable type test_payload is object (id number, txt varchar2(1000), lob clob, rec payload_rec)
/                                                                             
 
drop type test_payload_array force;
 
create  or replace noneditionable type test_payload_array as table of test_payload;
/
 
begin
  sys.dbms_aqadm.create_queue_table
   (queue_table            => 'TEST_QTAB'
    ,queue_payload_type    => 'TEST_PAYLOAD'
    ,compatible            => '10.0.0'  --'8.1'
    ,sort_list             => 'PRIORITY,ENQ_TIME'
    ,multiple_consumers    =>  false
    ,message_grouping      =>  0
    ,comment               =>  'KS Test Queue Table'
    ,secure                =>  false);
end;
/
 
begin
  sys.dbms_aqadm.stop_queue ( queue_name => 'TEST_Q');
  sys.dbms_aqadm.drop_queue ( queue_name => 'TEST_Q');
end;
/
 
begin
  sys.dbms_aqadm.create_queue
   (queue_name          => 'TEST_Q'
   ,queue_table         => 'TEST_QTAB'
   ,queue_type          =>  sys.dbms_aqadm.normal_queue
   ,max_retries         =>  100
   ,retry_delay         =>  2
   ,retention_time      =>  604800
   ,comment             => 'KS Test Queue');
end;
/
 
begin sys.dbms_aqadm.start_queue(queue_name => 'TEST_Q', enqueue => true, dequeue => true); end;
/

----==================== 2. Single Enqueue / Dequeue ====================----
 
create or replace procedure test_enq_single(p_id number := 1) as
  l_enqueue_options          dbms_aq.enqueue_options_t;
  l_message_properties       dbms_aq.message_properties_t;
  l_payload_rec              payload_rec;
  l_payload                  test_payload;
  l_message_handle           raw(16);
 
  l_array_msg_properties     dbms_aq.message_properties_array_t := dbms_aq.message_properties_array_t();
  l_array_payloads           test_payload_array := new test_payload_array();
  l_array_msg_ids            dbms_aq.msgid_array_t;
  l_array_errors             dbms_aq.error_array_t;
  l_enq_cnt                  number;
begin
  l_payload_rec := payload_rec(p_id, 'XXXYYY');
  l_payload     := test_payload(p_id, rpad('ABC', 1000, 'X'), rpad('CBA', 7000, 'X'), l_payload_rec);
 
  dbms_aq.enqueue(queue_name         => 'TEST_Q',
                  enqueue_options    => l_enqueue_options,
                  message_properties => l_message_properties,
                  payload            => l_payload,
                  msgid              => l_message_handle);
  commit;
end;
/             
 
-- exec test_enq_single(1);
 
create or replace procedure test_deq_single(p_dur number := 1) as
  l_dequeue_options       dbms_aq.dequeue_options_t;
  l_message_properties    dbms_aq.message_properties_t;
  l_payload               test_payload;
                l_message_handle        raw(16);
begin
                l_dequeue_options.wait := p_dur;
               
  dbms_aq.dequeue(queue_name         => 'TEST_Q',
                  dequeue_options    => l_dequeue_options,
                  message_properties => l_message_properties,
                  payload            => l_payload,
                  msgid              => l_message_handle);
       
  --dbms_output.put_line ('MSG id : ' || l_payload.id);
  commit;
 
  exception when others then dbms_output.put_line ('Error: ' || SQLERRM);
end;
/
                                                                                                               
-- exec test_deq_single();
 
create or replace procedure test_enq_single_loop (p_cnt number, p_id number := 1) as
  l_subh_mb                  number;
begin
  for i in 1..p_cnt loop
    test_enq_single(i);
  end loop;
  select round(sum(bytes)/1024/1024, 2) into l_subh_mb from v$sgastat s where name = 'KTC latch subh';
  dbms_output.put_line ('SingleEnqueCNT = '||p_cnt||', KTC latch subh MB = '||l_subh_mb);
end;
/
 
-- exec test_enq_single_loop(10);
 
create or replace procedure test_deq_single_loop (p_cnt number, p_dur number := 1) as
  l_subh_mb                  number;
begin
  for i in 1..p_cnt loop
    test_deq_single(p_dur);
  end loop;
  select round(sum(bytes)/1024/1024, 2) into l_subh_mb from v$sgastat s where name = 'KTC latch subh';
  dbms_output.put_line ('SingleDequeCNT = '||p_cnt||', KTC latch subh MB = '||l_subh_mb);
end;
/
 
-- exec test_deq_single_loop(10);

----==================== 3. Array Enqueue / Dequeue ====================----
 
create or replace procedure test_enq_array(p_array_size number := 1) as
  l_enqueue_options          dbms_aq.enqueue_options_t;
  l_message_properties       dbms_aq.message_properties_t;
  l_array_msg_properties     dbms_aq.message_properties_array_t := dbms_aq.message_properties_array_t();
  l_payload_rec              payload_rec;
  l_array_payloads           test_payload_array := new test_payload_array();
  l_array_msg_ids            dbms_aq.msgid_array_t;
  l_array_errors             dbms_aq.error_array_t;
  l_enq_cnt                  number;
  l_subh_mb                  number;
begin
  for i in 1..p_array_size loop
    l_payload_rec :=  payload_rec(i, 'XXXYYY');
    l_array_payloads.extend;
    l_array_payloads(l_array_payloads.last) := test_payload(i, rpad('ABC', 1000, 'X'), rpad('CBA', 7000, 'X'), l_payload_rec);
    l_array_msg_properties.extend;
    l_array_msg_properties(l_array_msg_properties.last) := l_message_properties;
  end loop;
 
  l_enq_cnt := dbms_aq.enqueue_array(
                       queue_name               => 'TEST_Q',
                       enqueue_options          => l_enqueue_options,
                       array_size               => l_array_payloads.count,
                       message_properties_array => l_array_msg_properties,
                      payload_array            => l_array_payloads,
                       msgid_array              => l_array_msg_ids,
                       error_array              => l_array_errors);
  commit;
 
  select round(sum(bytes)/1024/1024, 2) into l_subh_mb from v$sgastat s where name = 'KTC latch subh';
  dbms_output.put_line('Enqueue_Array.Size = '||l_enq_cnt||', KTC latch subh MB = '||l_subh_mb);
end;
/                             
 
-- exec test_enq_array(3);
 
create or replace procedure test_deq_array(p_array_size number := 1, p_sleep number := 5) as
   l_dequeue_options       dbms_aq.dequeue_options_t;
   l_array_msg_properties  dbms_aq.message_properties_array_t;
   l_array_payloads        test_payload_array;
   l_array_msg_ids         dbms_aq.msgid_array_t;
   l_deq_cnt               number;
   l_subh_mb                  number;
begin
   l_array_payloads := test_payload_array();
   l_array_payloads.extend(p_array_size);
   l_array_msg_properties := dbms_aq.message_properties_array_t();
   l_array_msg_properties.extend(p_array_size);
   l_array_msg_ids := dbms_aq.msgid_array_t();
   l_dequeue_options.wait := p_sleep;
 
   l_deq_cnt := dbms_aq.dequeue_array(
                        queue_name               => 'TEST_Q',
                        dequeue_options          => l_dequeue_options,
                        array_size               => p_array_size,
                        message_properties_array => l_array_msg_properties,
                        payload_array            => l_array_payloads,
                        msgid_array              => l_array_msg_ids);
  
   select round(sum(bytes)/1024/1024, 2) into l_subh_mb from v$sgastat s where name = 'KTC latch subh';
   dbms_output.put_line('Dequeue_Array.Size = '||l_deq_cnt||', KTC latch subh MB = '||l_subh_mb);
   commit;
  
    --for i in 1..l_deq_cnt loop
    --  dbms_output.put_line ('Payload id: ' || l_array_payloads(i).id);
    --end loop;
end;
/
 
-- exec test_deq_array(3);

----==================== 4. Loop Test Setup and Test Outcome Recording ====================----
drop table test_aq_array_runs;
 
create table test_aq_array_runs(run number, step number, time date, action varchar2(30), array_size number,
                                ktc_subh_mb number, pga_alloc_mb number, subh_details varchar2(300));
 
 

----==================== 5. Array-Single Enqueue / Dequeue Loop ====================----
 
create or replace procedure test_aq_loop(p_enq_mode varchar2, p_deq_mode varchar2, p_steps number := 1, p_base_size number := 0, p_delta_size number := 100000) as
  l_array_size  number;
  l_run         number := 0;
  l_step        number := 0;
  l_purge_opt   dbms_aqadm.aq$_purge_options_t;
 
  procedure save_stats (p_name varchar2) as
    l_subh_mb         number;
    l_pga_mb          number;
    l_subh_details    varchar2(300);
  begin
    select round(sum(bytes)/1024/1024) into l_subh_mb
      from v$sgastat s where name = 'KTC latch subh';
     
    select round(pga_alloc_mem/1024/1024) into l_pga_mb
      from v$session s, v$process p where s.paddr=p.addr and s.sid in (select sid from v$mystat where rownum=1);
     
   select 'ksmchcls: '|| listagg(subh_areas, '; ') within group (order by subh_areas) into l_subh_details
     from (select '('||ksmchcls||'='||round(sum(ksmchsiz)/1024/1024)||'MB, CNT='||count(*)||')' subh_areas
             from sys.x_ksmsp where lower(ksmchcom) like 'ktc%subh' group by ksmchcls);
  
   insert into test_aq_array_runs values (l_run, l_step, sysdate, p_name, l_array_size, l_subh_mb, l_pga_mb, l_subh_details);
   commit;
  end;
begin
  --l_purge_opt.block := true;
  --dbms_aqadm.purge_queue_table(queue_table => 'TEST_QTAB', purge_condition => null, purge_options => l_purge_opt);
  --select state, count(*) from test_qtab where q_name = 'TEST_Q' group by state;  -- 0 READY, 1 WAITING, 2 RETAINED or PROCESSED, 3 EXPIRED
 
  select nvl(max(run), 0) + 1 into l_run from test_aq_array_runs;
  dbms_output.put_line ('RUN = '||l_run||' at '||sysdate);
  save_stats(p_enq_mode||'-'||p_deq_mode||' Start');
 
  for i in 1..p_steps loop
    l_step       := i;
    l_array_size := p_base_size + (l_step*p_delta_size);
   
    -- Enqueue Array or Single
    if p_enq_mode = 'ArrayEnq' then
      test_enq_array(l_array_size);
      save_stats('ArrayEnq');
    else
      test_enq_single_loop(l_array_size);
      save_stats('SingleEnq');
    end if;
   
    -- Dequeue Array or Single
    if p_deq_mode =  'ArrayDeq' then
      test_deq_array(l_array_size);
      save_stats('ArrayDeq');
    else
      test_deq_single_loop(l_array_size);
      save_stats('SingleDeq');     
    end if;
  end loop;
 
  exception when others then
    save_stats('Error');
    raise;
end;
/
 
 
-- exec test_aq_loop('SingleEnq', 'SingleDeq', 3, 0, 1e1);
-- exec test_aq_loop('ArrayEnq',  'SingleDeq', 3, 0, 1e1);
-- exec test_aq_loop('SingleEnq', 'ArrayDeq',  3, 0, 1e1);
-- exec test_aq_loop('ArrayEnq',  'ArrayDeq',  3, 0, 1e1);