Sunday, July 5, 2026

Blog List

Posted by at

Oracle Partition Split With LOB Segment Performance Test

In this Blog, at first, we run performance tests of partition split with LOB segment in different chunk size of BasicFiles and SecureFiles. Then we look their I/O access.

Note: Tested in Oracle 19c with: 
 
  db_block_size  8192 (default)
  db_securefile  permitted (default)


1. Test Code


We create a range partitioned table with one basicfile LOB: 

drop table test_tab purge;

create table test_tab (
  id            number,
  code          varchar2(10),
  name          varchar2(100),
  created_date  date,
  text          clob,
  constraint test_tab_pk primary key (id)
)
lob (text) store as basicfile (
--lob (text) store as securefile test_tab_sf_text (
--compress medium 
  enable      storage in row
--  chunk       32768   -- 8192 (default), 32768=4*8192, no effect for securefile
)
partition by range (created_date)
(
  partition test_tab_2026 values less than (maxvalue)
);

create index test_tab#code         on test_tab (code);
create index test_tab#created_date on test_tab (created_date) local;

create or replace procedure test_tab_fill(p_row_cnt number, p_lob_len_kb number) as
  l_lob clob := empty_clob();
  l_len number;
begin
  insert into test_tab 
  select level id, rpad('ABC', 8, 'X') code, rpad('ABC', 80, 'X') name, to_date('22-NOV-202'||(mod(level,7)),'DD-MON-YYYY') created_date, empty_clob() text
  from dual connect by level <= p_row_cnt; 
  
  dbms_lob.createtemporary(l_lob, true, dbms_lob.session);
  
  for i in 1..p_lob_len_kb loop
    dbms_lob.append(dest_lob => l_lob, src_lob => rpad('ABC', 1024, 'X'));  
  end loop;
  
  update test_tab set text = rownum||l_lob; 
  commit;
end;
/


2. Basicfile Test


We will make two Basicfile tests, one with LOB chunk size 8192, one with LOB chunk size 32768.


2.1 Basicfile with Chunk 8192


We prepare and run test with: 

-- Fill table with 1000 rows, each contain one 8 MB Clob
exec test_tab_fill(1000, 1024*8);

exec dbms_stats.gather_table_stats(user, 'TEST_TAB', cascade => true);

select round(sum(length(text)/1024/1024)) mb, count(*), round(sum(length(text))/count(*)/1024) avg_len_kb from test_tab;

	        MB   COUNT(*) AVG_LEN_KB
	---------- ---------- ----------
	      8000       1000       8192

alter session set max_dump_file_size=unlimited;
alter session set tracefile_identifier = 'test_b8192';
alter session set events '10046 trace name context forever, level 12'; 

alter table test_tab
  split partition test_tab_2026 at (date'2025-12-31')
  into (partition test_tab_2025,
        partition test_tab_2026)
update indexes --parallel 8
;

  Elapsed: 00:08:56.18
  
alter session set events '10046 trace name context off';
It takes about 8 minutes.

Here the SQL trace: 

********************************************************************************
alter table test_tab
  split partition test_tab_2026 at (date'2025-12-31')
  into (partition test_tab_2025,
        partition test_tab_2026)
update indexes --parallel 8

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1     99.30     533.69    2064038    2113185    5401904        1000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     99.31     533.70    2064038    2113185    5401904        1000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 49
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  LOAD AS SELECT  TEST_TAB (cr=2112099 pr=2064025 pw=2064028 time=533571542 us starts=1)
      1000       1000       1000   PARTITION RANGE SINGLE PARTITION: 1 1 (cr=31 pr=1 pw=0 time=9524 us starts=1 cost=2 size=184336 card=82)
      1000       1000       1000    TABLE ACCESS FULL TEST_TAB PARTITION: 1 1 (cr=31 pr=1 pw=0 time=8397 us starts=1 cost=2 size=184336 card=82)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                       364        0.01          0.26
  control file sequential read                 3260        0.11          1.97
  datafile move cleanup during resize           163        0.00          0.02
  Disk file operations I/O                      489        0.01          0.14
  Data file init write                          187        0.02          0.46
  direct path sync                              163        0.00          0.03
  db file single write                          163        0.02          0.04
  control file parallel write                   489        0.04          0.94
  DLM cross inst call completion                163        0.02          0.21
  direct path read                          2063998        0.24        433.13
  direct path write                            1906        0.06          4.93
  log file switch (private strand flush incomplete)
                                                  1        0.02          0.02
  local write wait                               16        0.00          0.01
  reliable message                                8        0.00          0.00
  enq: RO - fast object reuse                     4        0.00          0.00
  enq: CR - block range reuse ckpt                4        0.00          0.00
  write complete waits                            1        0.00          0.00
  PGA memory operation                            1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************
If during test, we monitor the test session: 

select event, p1, p2, p3, p1text, p2text, p3text, row_wait_obj#, row_wait_file#, row_wait_block#, row_wait_row# 
from v$session where sid = 912;

	EVENT                P1       P2  P3 P1TEXT       P2TEXT      P3TEXT     ROW_WAIT_OBJ# ROW_WAIT_FILE# ROW_WAIT_BLOCK# ROW_WAIT_ROW#
	----------------- ----- -------- --- ------------ ----------- ---------- ------------- -------------- --------------- -------------
	direct path write    22  5376932   1 file number  first dba   block cnt        6244876             22         3621774             0
         
         
select sample_time, event, p1, p2, p3, p1text, p2text, p3text, current_obj#, current_file#, current_block#, current_row#
from v$active_session_history t 
where sample_time > sysdate-35/1440
  and session_id = 912
  and event in ('direct path read', 'direct path write')
order by t.sample_time;

	SAMPLE_TIME          EVENT                P1       P2  P3 P1TEXT       P2TEXT     P3TEXT     CURRENT_OBJ# CURRENT_FILE# CURRENT_BLOCK# CURRENT_ROW#
	-------------------- ----------------- ----- -------- --- ------------ ---------- ---------- ------------ ------------- -------------- ------------
	03-JUL-2026 13:09:37 direct path write    22  5376932   1 file number  first dba  block cnt       6244876            22        3621774            0
	03-JUL-2026 13:11:18 direct path write    22  5673340   1 file number  first dba  block cnt       6244876            22        2374684            0
	03-JUL-2026 13:12:30 direct path write    22  5890030   1 file number  first dba  block cnt       6244876            22        3427384            0


	SAMPLE_TIME          EVENT                P1       P2  P3 P1TEXT       P2TEXT     P3TEXT     CURRENT_OBJ# CURRENT_FILE# CURRENT_BLOCK# CURRENT_ROW#
	-------------------- ----------------- ----- -------- --- ------------ ---------- ---------- ------------ ------------- -------------- ------------
	03-JUL-2026 13:12:41 direct path read     22  3609403   1 file number  first dba  block cnt       6244876            22        3609403            0
	03-JUL-2026 13:12:39 direct path read     22  3573182   1 file number  first dba  block cnt       6244876            22        3573182            0
	03-JUL-2026 13:12:36 direct path read     22  3514427   1 file number  first dba  block cnt       6244876            22        3514427            0


select * from sys.lobfrag$ where fragobj# = 6244876;

	  FRAGOBJ# PARENTOBJ# TABFRAGOBJ# INDFRAGOBJ#      FRAG# F        TS#      FILE#     BLOCK#      CHUNK PCTVERSION$  FRAGFLAGS    FRAGPRO     SPARE1     SPARE2     SPARE3
	---------- ---------- ----------- ----------- ---------- - ---------- ---------- ---------- ---------- ----------- ---------- ---------- ---------- ---------- ----------
	   6244876    6244875     6244874     6244878         10 P       4140       1024     999930          1          10         97          2


select object_name, subobject_name, object_id, data_object_id, object_type from dba_objects where object_name = 'TEST_TAB';

	OBJECT_NAM SUBOBJECT_NAME   OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE
	---------- --------------- ---------- -------------- ---------------
	TEST_TAB   TEST_TAB_2025      6244883        6244883 TABLE PARTITION
	TEST_TAB   TEST_TAB_2026      6244874        6244884 TABLE PARTITION
	TEST_TAB                      6244873                TABLE


select table_name, column_name, segment_name, index_name, chunk, securefile from dba_lobs where table_name = 'TEST_TAB';

	TABLE_NAME COLUMN_NAM SEGMENT_NAME              INDEX_NAME                     CHUNK SEC
	---------- ---------- ------------------------- ------------------------- ---------- ---
	TEST_TAB   TEXT       SYS_LOB0006244873C00005$$ SYS_IL0006244873C00005$$        8192 NO


select table_name, column_name, lob_name, partition_name, lob_partition_name, lob_indpart_name, partition_position, chunk 
from dba_lob_partitions where table_name = 'TEST_TAB';

	TABLE_NAME COLUMN_NAM LOB_NAME                  PARTITION_NAME  LOB_PARTITION_NAME   LOB_INDPART_NAME     PARTITION_POSITION      CHUNK
	---------- ---------- ------------------------- --------------- -------------------- -------------------- ------------------ ----------
	TEST_TAB   TEXT       SYS_LOB0006244873C00005$$ TEST_TAB_2025   SYS_LOB_P647334      SYS_IL_P647336                        1       8192
	TEST_TAB   TEXT       SYS_LOB0006244873C00005$$ TEST_TAB_2026   SYS_LOB_P647335      SYS_IL_P647337                        2       8192


$ > fgrep 'direct path read' testdb_ora_2472818_test_b8192.trc

	WAIT #139722977275192: nam='direct path read' ela= 527 file number=22 first dba=1047862 block cnt=1 obj#=6244876 tim=24601964026630
	WAIT #139722977275192: nam='direct path read' ela= 356 file number=22 first dba=1047863 block cnt=1 obj#=6244876 tim=24601964027037
	WAIT #139722977275192: nam='direct path read' ela= 934 file number=22 first dba=1047857 block cnt=1 obj#=6244876 tim=24601964028034


$ > fgrep 'direct path read' testdb_ora_2472818_test_b8192.trc|wc

  2063998 30959970 270521981
With strace, we can see: 


$ > strace -p 

io_submit(0x7f13d15dd000, 1, [{aio_data=0x7f13c9a50488, aio_lio_opcode=IOCB_CMD_PREAD, aio_fildes=264, aio_buf=0x7f13caee1000, aio_nbytes=8192, aio_offset=24147320832}]) = 1
io_getevents(0x7f13d15dd000, 2, 128, [{data=0x7f13ca651ef8, obj=0x7f13ca651ef8, res=8192, res2=0}, {data=0x7f13c9a50488, obj=0x7f13c9a50488, res=8192, res2=0}], {tv_sec=0, tv_nsec=0}) = 2
io_submit(0x7f13d15dd000, 1, [{aio_data=0x7f13ca6525f8, aio_lio_opcode=IOCB_CMD_PWRITE, aio_fildes=264, aio_buf="(\242\0\0\261\3210\0\261\341\323:|\f\2\4\320A\0\0XJ_\0\0\0\0\1\0\0!\v"..., aio_nbytes=8192, aio_offset=26209558528}]) = 1
Above output shows "direct path read" is with "block cnt" = 1 (1 data block of size 8192, aio_nbytes=8192).

Note FRAGOBJ# = 6244876 in sys.lobfrag$ is a temporay object used during partition split, it does not exist on dba_objects. 

select * from dba_objects where object_id = 6244876 or data_object_id = 6244876;
  no rows selected
  
select * from sys.obj$ where obj#  = 6244876 or dataobj# = 6244876;
  no rows selected
Also Oracle has a Limitation:
Oracle partition split using Parallel DML (PDML) does not work for BASICFILE LOB segment when specifying parallel clause
although Xplan still showed "PX COORDINATOR". 

********************************************************************************

ALTER TABLE t 
  SPLIT PARTITION t1_2017 AT (TO_DATE('31-DEC-2015 23:59:59', 'DD-MON-YYYY HH24:MI:SS'))
  INTO (PARTITION t1_2015,
        PARTITION t1_2017)
UPDATE INDEXES PARALLEL 8

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      4.85       7.69      88712      95141     235000         192
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      4.85       7.69      88712      95141     235000         192

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 49  
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  LOAD AS SELECT  T  (cr=94793 pr=88708 pw=88709 time=7609875 us starts=1)
       192        192        192   PX COORDINATOR  (cr=3 pr=0 pw=0 time=33097 us starts=1)
         0          0          0    PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us starts=0 cost=2 size=41280 card=192)
         0          0          0     PX BLOCK ITERATOR PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us starts=0 cost=2 size=41280 card=192)
         0          0          0      TABLE ACCESS FULL T1 PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us starts=0 cost=2 size=41280 card=192)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PX Deq: Join ACK                                8        0.00          0.00
  PX Deq: Parse Reply                             8        0.01          0.02
  PX Deq: Execute Reply                          13        0.00          0.00
  db file sequential read                         8        0.00          0.02
  direct path read                            88702        0.00          3.76
  direct path write                             198        0.02          0.05
  PX Deq: Signal ACK EXT                          8        0.00          0.00
  PX Deq: Slave Session Stats                     8        0.00          0.00
  enq: PS - contention                            1        0.00          0.00
  reliable message                                8        0.00          0.00
  enq: RO - fast object reuse                     4        0.00          0.00
  enq: CR - block range reuse ckpt                4        0.00          0.00
  log file sync                                   1        0.00          0.00
  PGA memory operation                            1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.01          0.01
********************************************************************************


2.2 Basicfile with Chunk 32768


We further make a test of LOB Chunk Size: 32768 (4*8192): 

--------------------- chunk 32768 -----------------------

drop table test_tab purge;

create table test_tab (
  id            number,
  code          varchar2(10),
  name          varchar2(100),
  created_date  date,
  text          clob,
  constraint test_tab_pk primary key (id)
)
lob (text) store as basicfile (
--lob (text) store as securefile test_tab_sf_text (
--compress medium 
  enable      storage in row
  chunk       32768   -- 8192 (default), 32768=4*8192, no effect for securefile
)
partition by range (created_date)
(
  partition test_tab_2026 values less than (maxvalue)
);

create index test_tab#code         on test_tab (code);
create index test_tab#created_date on test_tab (created_date) local;


-- Fill table with 1000 rows, each contain one 8 MB Clob
exec test_tab_fill(1000, 1024*8);

exec dbms_stats.gather_table_stats(user, 'TEST_TAB', cascade => true);
Then we make the split test: 

alter session set max_dump_file_size=unlimited;
alter session set tracefile_identifier = 'test_b32768';
alter session set events '10046 trace name context forever, level 12'; 

alter table test_tab
  split partition test_tab_2026 at (date'2025-12-31')
  into (partition test_tab_2025,
        partition test_tab_2026)
update indexes --parallel 8
;

Elapsed: 00:05:49.63

alter session set events '10046 trace name context off';
It takes 349 seconds with CHUNK=32768, compared to above 533 seconds of CHUNK=8192.

Here SQL trace: 

********************************************************************************

alter table test_tab
  split partition test_tab_2026 at (date'2025-12-31')
  into (partition test_tab_2025,
        partition test_tab_2026)
update indexes --parallel 8

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1     34.70     349.05    2064014    2094838    2877842        1000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     34.70     349.05    2064014    2094838    2877842        1000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 49
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  LOAD AS SELECT  TEST_TAB (cr=2093924 pr=2064009 pw=2064028 time=348998633 us starts=1)
      1000       1000       1000   PARTITION RANGE SINGLE PARTITION: 1 1 (cr=30 pr=0 pw=0 time=9147 us starts=1 cost=10 size=281000 card=1000)
      1000       1000       1000    TABLE ACCESS FULL TEST_TAB PARTITION: 1 1 (cr=30 pr=0 pw=0 time=8270 us starts=1 cost=10 size=281000 card=1000)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  direct path read                           509092        0.42        313.25
  direct path write                            1489        0.05          2.25
  db file sequential read                        14        0.02          0.08
  PGA memory operation                            2        0.00          0.00
  reliable message                                8        0.00          0.00
  enq: RO - fast object reuse                     4        0.00          0.00
  enq: CR - block range reuse ckpt                4        0.00          0.00
  write complete waits                            1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.01          0.01
********************************************************************************
And monitoring output: 

select table_name, column_name, segment_name, index_name, chunk, securefile from dba_lobs where table_name = 'TEST_TAB';

	TABLE_NAME COLUMN_NAM SEGMENT_NAME              INDEX_NAME                     CHUNK SEC
	---------- ---------- ------------------------- ------------------------- ---------- ---
	TEST_TAB   TEXT       SYS_LOB0006244894C00005$$ SYS_IL0006244894C00005$$       32768 NO

select event, p1, p2, p3, p1text, p2text, p3text, row_wait_obj#, row_wait_file#, row_wait_block#, row_wait_row#
from v$session where sid = 912;

	EVENT                        P1         P2         P3 P1TEXT          P2TEXT          P3TEXT          ROW_WAIT_OBJ# ROW_WAIT_FILE# ROW_WAIT_BLOCK# ROW_WAIT_ROW#
	-------------------- ---------- ---------- ---------- --------------- --------------- --------------- ------------- -------------- --------------- -------------
	direct path read             22    5217040          4 file number     first dba       block cnt             6244897             22         5217040             0


$ > strace  -p 2472818

	io_submit(0x7f13d15dd000, 1, [{aio_data=0x7f13ca2814f0, aio_lio_opcode=IOCB_CMD_PREAD, aio_fildes=264, aio_buf=0x7f13ca299000, aio_nbytes=32768, aio_offset=36884873216}]) = 1
	io_getevents(0x7f13d15dd000, 2, 128, [{data=0x7f13ca6502f8, obj=0x7f13ca6502f8, res=32768, res2=0}], {tv_sec=0, tv_nsec=0}) = 1
	io_getevents(0x7f13d15dd000, 1, 128, [{data=0x7f13ca2814f0, obj=0x7f13ca2814f0, res=32768, res2=0}], {tv_sec=600, tv_nsec=0}) = 1
Above output shows "direct path read" is with "block cnt" = 4 (4 data blocks of size 8192, aio_nbytes=32768), compared to "block cnt" = 1 (1 data block of size 8192).


3 Securefile Test


Now we make one more test with securefile: 

--------------------- securefile -----------------------

drop table test_tab purge;

create table test_tab (
  id            number,
  code          varchar2(10),
  name          varchar2(100),
  created_date  date,
  text          clob,
  constraint test_tab_pk primary key (id)
)
--lob (text) store as basicfile (
lob (text) store as securefile test_tab_sf_text (
--compress medium 
  enable      storage in row
--  chunk       32768   -- 8192 (default), 32768=4*8192, no effect for securefile
)
partition by range (created_date)
(
  partition test_tab_2026 values less than (maxvalue)
);

create index test_tab#code         on test_tab (code);
create index test_tab#created_date on test_tab (created_date) local;


-- Fill table with 1000 rows, each contain one 8 MB Clob
exec test_tab_fill(1000, 1024*8);

exec dbms_stats.gather_table_stats(user, 'TEST_TAB', cascade => true);

select round(sum(length(text)/1024/1024)) mb, count(*), round(sum(length(text))/count(*)/1024) avg_len_kb from test_tab;

	        MB   COUNT(*) AVG_LEN_KB
	---------- ---------- ----------
	      8000       1000       8192
Then we make the split test: 

alter session set max_dump_file_size=unlimited;
alter session set tracefile_identifier = 'test_sec';
alter session set events '10046 trace name context forever, level 12'; 

alter table test_tab
  split partition test_tab_2026 at (date'2025-12-31')
  into (partition test_tab_2025,
        partition test_tab_2026)
update indexes --parallel 8
;

Elapsed: 00:01:18.87

alter session set events '10046 trace name context off';
It takes 78 seconds, compared to basicfile of 533 seconds (CHUNK=8192) and 349 seconds (CHUNK=32768).

Her SQL trace: 

********************************************************************************

alter table test_tab
  split partition test_tab_2026 at (date'2025-12-31')
  into (partition test_tab_2025,
        partition test_tab_2026)
update indexes --parallel 8

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1     21.50      78.46    2082018      44947     103278        1000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     21.51      78.47    2082018      44947     103278        1000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 49
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  LOAD AS SELECT  TEST_TAB (cr=44142 pr=2082015 pw=2082024 time=78415081 us starts=1)
      1000       1000       1000   PARTITION RANGE SINGLE PARTITION: 1 1 (cr=30 pr=0 pw=0 time=9530 us starts=1 cost=10 size=255000 card=1000)
      1000       1000       1000    TABLE ACCESS FULL TEST_TAB PARTITION: 1 1 (cr=30 pr=0 pw=0 time=9027 us starts=1 cost=10 size=255000 card=1000)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  direct path read                             5899        0.31         54.81
  local write wait                              664        0.19          0.42
  reliable message                               10        0.00          0.00
  enq: CR - block range reuse ckpt                6        0.00          0.00
  db file sequential read                        66        0.02          0.04
  direct path write                              71        0.02          0.24
  control file sequential read                  480        0.03          0.21
  datafile move cleanup during resize            24        0.00          0.00
  Disk file operations I/O                       72        0.03          0.09
  Data file init write                           42        0.02          0.24
  direct path sync                               24        0.00          0.00
  db file single write                           24        0.00          0.00
  control file parallel write                    72        0.00          0.06
  DLM cross inst call completion                 24        0.00          0.01
  enq: RO - fast object reuse                     4        0.01          0.01
  PGA memory operation                            1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.01          0.01
********************************************************************************
And monitoring output: 

select table_name, column_name, segment_name, index_name, chunk, securefile from dba_lobs where table_name = 'TEST_TAB';

	TABLE_NAME COLUMN_NAM SEGMENT_NAME              INDEX_NAME                     CHUNK SECUREFILE
	---------- ---------- ------------------------- ------------------------- ---------- ---------------
	TEST_TAB   TEXT       TEST_TAB_SF_TEXT          SYS_IL0006244918C00005$$        8192 YES


select sample_time, event, p1, p2, p3, p1text, p2text, p3text, current_obj#, current_file#, current_block#, current_row#
from v$active_session_history t 
where sample_time > sysdate-5/1440
  and session_id = 912
  and event in ('direct path read', 'direct path write') 
order by t.sample_time;

	SAMPLE_TIME          EVENT                        P1         P2         P3 P1TEXT          P2TEXT          P3TEXT          CURRENT_OBJ# CURRENT_FILE# CURRENT_BLOCK# CURRENT_ROW#
	-------------------- -------------------- ---------- ---------- ---------- --------------- --------------- --------------- ------------ ------------- -------------- ------------
	03-JUL-2026 14:48:23 direct path read             22    5607312        128 file number     first dba       block cnt            6244921            22        5607312            0
	03-JUL-2026 14:48:24 direct path read             22    4057350        128 file number     first dba       block cnt            6244921            22        4057350            0
	03-JUL-2026 14:48:25 direct path read             22    4086036        128 file number     first dba       block cnt            6244921            22        4086036            0


$ > strace  -p 2472818

	io_submit(0x7f13d15dd000, 1, [{aio_data=0x681ca000, aio_lio_opcode=IOCB_CMD_PREAD, aio_fildes=264, aio_buf=0x16f400000, aio_nbytes=1048576, aio_offset=32394772480}]) = 1
	io_submit(0x7f13d15dd000, 1, [{aio_data=0x8ea63e48, aio_lio_opcode=IOCB_CMD_PREAD, aio_fildes=264, aio_buf=0x16f300000, aio_nbytes=1048576, aio_offset=32395821056}]) = 1
	io_submit(0x7f13d15dd000, 1, [{aio_data=0x8c41ddb0, aio_lio_opcode=IOCB_CMD_PREAD, aio_fildes=264, aio_buf=0x16f200000, aio_nbytes=1048576, aio_offset=32396869632}]) = 1
	io_submit(0x7f13d15dd000, 1, [{aio_data=0x66503b30, aio_lio_opcode=IOCB_CMD_PREAD, aio_fildes=264, aio_buf=0x16fa00000, aio_nbytes=1048576, aio_offset=32397918208}]) = 1
Above output shows "direct path read" is with "block cnt" = 128 (128 data blocks of size 8192, aio_nbytes=1048576).
Posted by at

Sunday, June 21, 2026

Oracle single session "library cache lock" self deadlock: ORA-04020

Following previous Blog Oracle 12c single session "library cache lock (cycle)" deadlock, we will look one more case:
     ORA-04020: deadlock inside one single session.

Note: Tested in Oracle 19c


1. Test Setup 


drop table test_tab;

drop table test_tab_v1;

drop table test_tab_v2;

create table test_tab as select 'ABC123' name, level c0 from dual connect by level <= 10; 

create table test_tab_v1 as select level c0 from dual connect by level <= 5; 

create table test_tab_v2 as select level c0 from dual connect by level <= 10;

create or replace function test_fun (p_x number) return number is
  l_x number;
begin
  select c0 into l_x from test_tab where name = 'ABC123' and  c0 = p_x;
  return l_x;
end;
/

create or replace package test_pkg is
  procedure p1 (p_x number);
end;
/

create or replace package body test_pkg is
  procedure p1 (p_x number) is
    l_x number;
  begin
    l_x := test_fun(p_x);
  end;
end;
/

create or replace force view test_view as
  with sq1 as (select distinct c0 vc0, test_fun(c0) vc1 from test_tab_v1)
  select * from test_tab_v2 v2, sq1 v1 where v2.c0 = v1.vc0;

create or replace procedure test_ddl_table(p_cnt number) as
begin
  for i in 1..p_cnt loop
    execute immediate 'alter table test_tab add(ks_c'||i||' number)';
    dbms_session.sleep(0.1);
  end loop;
end;
/  

create or replace procedure test_ddl_view(p_cnt number) as
begin
  for i in 1..p_cnt loop
    execute immediate 'alter view test_view compile';
  end loop;
end;
/   

create or replace procedure test_exec_call(p_cnt number) as
begin
  for i in 1..p_cnt loop
    test_pkg.p1(mod(i, 10) +1);
    dbms_session.sleep(0.1);
  end loop;
end;
/


2. Test Run


Open two Sqlplus sessions: SESS-1 and SESS-2.


2.1 In SESS-1, run: 


exec test_ddl_table(300);


2.2 In SESS-2, run: 


exec test_ddl_view(10000);
After a few seconds, SESS-2 throws error: 

ERROR:
ORA-24344: success with compilation error
ORA-06512: at "K.TEST_DDL_VIEW", line 4
ORA-06512: at line 1
One can check object status by: 

select object_name, object_id, data_object_id, object_type, created, last_ddl_time, timestamp, status from dba_objects 
 where object_name in ('TEST_PKG', 'TEST_FUN', 'TEST_VIEW', 'TEST_TAB', 'TEST_TAB_V1', 'TEST_TAB_V2', 'TEST_DDL_TABLE', 'TEST_DDL_VIEW', 'TEST_EXECC_CALL') 
 order by status, object_name;

OBJECT_NAME     OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE  CREATED              LAST_DDL_TIME        TIMESTAMP           STATUS
-------------- ---------- -------------- ------------ -------------------- -------------------- ------------------- ------------
TEST_FUN          6236412                FUNCTION     2026-JUN-18 11:13:56 2026-JUN-21 08:37:46 2026-06-21:08:37:46 INVALID
TEST_PKG          6236411                PACKAGE BODY 2026-JUN-18 11:11:44 2026-JUN-21 08:37:46 2026-06-21:08:37:46 INVALID
TEST_VIEW         6236423                VIEW         2026-JUN-18 11:28:39 2026-JUN-21 08:38:29 2026-06-21:08:38:29 INVALID
TEST_DDL_TABLE    6236774                PROCEDURE    2026-JUN-20 09:30:49 2026-JUN-20 09:30:49 2026-06-20:09:30:49 VALID
TEST_DDL_VIEW     6236775                PROCEDURE    2026-JUN-20 09:30:49 2026-JUN-20 09:30:49 2026-06-20:09:30:49 VALID
TEST_PKG          6236410                PACKAGE      2026-JUN-18 11:09:46 2026-JUN-20 10:12:43 2026-06-18:11:20:14 VALID
TEST_TAB          6236945        6236945 TABLE        2026-JUN-21 08:37:45 2026-JUN-21 08:38:39 2026-06-21:08:38:39 VALID
TEST_TAB_V1       6236946        6236946 TABLE        2026-JUN-21 08:37:45 2026-JUN-21 08:37:45 2026-06-21:08:37:45 VALID
TEST_TAB_V2       6236947        6236947 TABLE        2026-JUN-21 08:37:46 2026-JUN-21 08:37:46 2026-06-21:08:37:46 VALID


select name, type, '0X'||trim('0' from addr) addr, to_number(addr, 'XXXXXXXXXXXXXXXXXX') addr_num, hash_value, type 
  from v$db_object_cache v 
 where name in ('TEST_PKG', 'TEST_FUN', 'TEST_VIEW', 'TEST_TAB', 'TEST_TAB_V1', 'TEST_TAB_V2', 'TEST_DDL_TABLE', 'TEST_DDL_VIEW', 'TEST_EXECC_CALL')
 order by v.name;

NAME           TYPE         ADDR           ADDR_NUM HASH_VALUE TYPE
-------------- ------------ ------------ ---------- ---------- ------------
TEST_DDL_TABLE PROCEDURE    0X96A00E48   2527071816 2793044217 PROCEDURE
TEST_DDL_VIEW  PROCEDURE    0X6B5A398    1801075072 2396118748 PROCEDURE
TEST_FUN       FUNCTION     0X80CDF188   2160980360 2391147328 FUNCTION
TEST_PKG       PACKAGE      0X88C948C8   2294892744 3673762546 PACKAGE
TEST_PKG       PACKAGE BODY 0X737B9C48   1937480776 2937683311 PACKAGE BODY
TEST_TAB       TABLE        0X70F1F1B    1894904240 1905210899 TABLE
TEST_TAB_V1    TABLE        0X71FAA968   1912252776 2228492516 TABLE
TEST_TAB_V2    TABLE        0X97BBD6A8   2545669800  580752620 TABLE
TEST_VIEW      VIEW         0X70BF69B8   1891592632 1492527927 VIEW
To repeat the test, re-execute Test Setup at first, then make the test.


3. trc file


Following trc file shows: 

   ORA-04020: deadlock detected while trying to lock object K.TEST_FUN
with object handle: 0x80cdf188, which is TEST_FUN (ADDR = 0X80CDF188 in above v$db_object_cache output).

It is a self session deadlock because waiting session and blocking session are the same (0xb89008b8 17).

Blog Blog Oracle 12c single session "library cache lock (cycle)" deadlock contains more detail analysis on this behaviour,
for example, 

	waiting session (0xb89008b8   17) = blocking session (0xb89008b8   17)
	waiting mode (X)                 != blocking mode (s)
	waiting lock (0x62d127d0)        != blocking lock (0x83c3f830)
	waiting Flags=[0000]             != blocking Flags=CNB/PNC/[0003]
	waiting SavepointNum=d56d7       > blocking SavepointNum=d56ab 
    waiting/blocking HandleIvd=6236945=TEST_TAB


Trace file /orabin/app/oracle/admin/testdb/diag/rdbms/testdb/testdb/trace/testdb_ora_323537.trc
Version 19.30.0.0.0
Oracle process number: 48
Unix process pid: 323537, image: oracle@testdb

*** SESSION ID:(17.58059) 2026-06-21T08:38:29.493117+02:00
 
A deadlock among DDL and parse locks is detected.
This deadlock is usually due to user errors in
the design of an application or from issuing a set
of concurrent statements which can cause a deadlock.
This should not be reported to Oracle Support.
The following information may aid in finding
the errors which cause the deadlock:
ORA-04020: deadlock detected while trying to lock object K.TEST_FUN
Short stack dump of current process:
----- Abridged Call Stack Trace -----
ksedsts()+426<-kgllkde()+1182<-kglLockWait()+2503<-kgllkal()+2030<-kglLock()+1426<-kglget()+297<-kqlvld()+851<-kglgob()+3504<-kgldpo0()+726<-qcdlgpo()+772<-qcsRslvPLSQLInvoc1()+979<-qcsRslvPLSQLInvoc()+96<-qcsRslvName()+676<-qcsridn()+115<-qcsraic()+431<-qcspqbDescendents()+546
<-qcspqb()+283<-qcspqbDescendents()+4286<-qcspqb()+283<-kkmdrv()+180<-opiSem()+2167<-opiprs()+528<-kksParseChildCursor()+524<-rpiswu2()+2004<-kksLoadChild()+5339<-kxsGetRuntimeLock()+2335<-kksfbc()+19863<-opiexe()+2982<-opiosq0()+4482<-opipls()+21173<-opiodr()+1264
<-rpidrus()+198<-skgmstack()+65<-rpidru()+151<-rpiswu2()+543<-rpidrv()+1281<-psddr0()+467<-psdnal()+624<-pevm_EXIM()+282<-pfrinstr_EXIM()+43<-pfrrun_no_tool()+60<-pfrrun()+904<-plsql_run()+752<-peicnt()+279<-kkxexe()+720<-opiexe()+31613<-kpoal8()+2301<-opiodr()+1264
<-ttcpip()+1232<-opitsk()+1908<-opiino()+935<-opiodr()+1264<-opidrv()+1094<-sou2o()+165<-opimai_real()+422<-ssthrdmain()+417<-main()+256<-__libc_start_main()+229<-_start()+46 
----- End of Abridged Call Stack Trace -----
Partial short call stack signature: 0xce99135a9a693f97
--------------------------------------------------------
 object handle   waiting session   sid  waiting lock    mode blocking session  sid  blocking lock   mode
---------------- ---------------- ----- --------------- ---- ---------------- ----- --------------- ----
 0x80cdf188      0xb89008b8        17   0x62d127d0      X    0xb89008b8        17   0x83c3f830      S
--------------------------------------------------------
---------- DUMP OF WAITING AND BLOCKING LOCKS ----------
--------------------------------------------------------
------------- WAITING LOCK -------------
----------------------------------------
SO: 0x66147068, type: LIBRARY OBJECT LOCK (118), map: 0x62d127d0
    state: LIVE (0x4532), flags: 0x1
    owner: 0xaefc0968, proc: 0xb8eebc90
    link: 0x66147088[0xa5f638e0, 0xaefc09d8]
    child list count: 0, link: 0x661470d8[0x661470d8, 0x661470d8]
    pg: 0
SOC: 0x62d127d0, type: LIBRARY OBJECT LOCK (118), map: 0x66147068
     state: LIVE (0x99fc), flags: INIT (0x1)

LibraryObjectLock:  Address=0x62d127d0 Handle=0x80cdf188 RequestMode=X 
  CanBeBrokenCount=708 Incarnation=708 ExecutionCount=0 
  
  User=0xb89008b8 Session=0xb89008b8 ReferenceCount=0 
  Flags=[0000] SavepointNum=d56d7 
LibraryHandle:  Address=0x80cdf188 Hash=8e860340 LockMode=S PinMode=S LoadLockMode=0 Status=INVL 
  ObjectName:  Name=K.TEST_FUN   
    FullHashValue=e7a045fef628c10c7c8dcf7b8e860340 Namespace=TABLE/PROCEDURE(01) Type=FUNCTION(08) ContainerId=0 ContainerUid=0 Identifier=6236412 OwnerIdn=49 
  Statistics:  InvalidationCount=674 ExecutionCount=0 LoadCount=696 ActiveLocks=1 ActivePins=1 TotalLockCount=163897 TotalPinCount=163874 
  Counters:  BrokenCount=708 RevocablePointer=708 KeepDependency=0 Version=0 BucketInUse=63688 HandleInUse=63688 HandleReferenceCount=0 
  Concurrency:  DependencyMutex=0x80cdf238(0, 326246, 0, 0) Mutex=0x80cdf2d8(0, 1479323, 6, 0) 
  Flags=PIN/TIM/VER/[40002801] Flags2=[0000] HandleIvd=6236945 
  WaitersLists:  
    Lock=0x80cdf218[0x62d12800,0x62d12800] 
    Pin=0x80cdf1f8[0x80cdf1f8,0x80cdf1f8] 
    LoadLock=0x80cdf270[0x80cdf270,0x80cdf270] 
  Timestamp:  Current=06-21-2026 08:37:46 
  HandleReference:  Address=0x80cdf358 Handle=0xa0670d70 Flags=OWN[200] 
  LibraryObject:  Address=0x903c0190 HeapMask=0000-0015-0015-0000 Flags=EXS/LOC[0004] Flags2=/CSC[4000000] Flags3=[0000] PublicFlags=NST[0001] 
    DataBlocks:  
      Block:  #='0' name=KGLH0^8e860340 pins=0 Change=NONE   
        Heap=0x80cdefc8 Pointer=0x903c0270 Extent=0x903c00d0 Flags=I/-/P/A/-/-/- 
        FreedLocation=0 Alloc=2.179688 Size=3.976562 LoadTime=06-21-2026 06:38:20 
      Block:  #='2' name=PLDIA^8e860340 pins=1 Change=NONE   
        Heap=0x903c0620 Pointer=0x80763550 Extent=0x80763490 Flags=I/-/P/A/-/-/- 
        FreedLocation=0 Alloc=13.593750 Size=15.820312 LoadTime=06-21-2026 06:38:20 
      Block:  #='4' name=PLMCD^8e860340 pins=1 Change=NONE   
        Heap=0x903c0778 Pointer=0x955b7e68 Extent=0x955b7da8 Flags=I/-/P/A/-/-/- 
        FreedLocation=0 Alloc=2.554688 Size=3.937500 LoadTime=06-21-2026 06:38:20 
------------- WAITING SESSION -------------
  sid: 17 ser: 58059 audsid: 102774880 user: 49/K
    flags: (0x8000041) USR/- flags2: (0x48009) -/DDLT2/INC
    flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
  pid: 48 O/S info: user: oracle, term: UNKNOWN, ospid: 323537
    image: oracle@testdb
  client details:
    O/S info: user: U000380, term: WCLINBDOXKKDUGS, ospid: 6132:51788
    machine: SYS\WCLINBDOXKKDUGS program: sqlplus.exe
    application name: SQL*Plus, hash value=3669949024
  current SQL:
  alter view test_view compile
------------- BLOCKING LOCK ------------
----------------------------------------
SO: 0x87edd848, type: LIBRARY OBJECT LOCK (118), map: 0x83c3f830
    state: LIVE (0x4532), flags: 0x1
    owner: 0xa5f51dd0, proc: 0xb8eebc90
    link: 0x87edd868[0xb8f018c0, 0x87e13a98]
    child list count: 0, link: 0x87edd8b8[0x87edd8b8, 0x87edd8b8]
    pg: 0
SOC: 0x83c3f830, type: LIBRARY OBJECT LOCK (118), map: 0x87edd848
     state: LIVE (0x99fc), flags: INIT (0x1)

LibraryObjectLock:  Address=0x83c3f830 Handle=0x80cdf188 Mode=S 
  CallPin=0x90ab9830 CanBeBrokenCount=708 Incarnation=707 ExecutionCount=0 
  
  User=0xb89008b8 Session=0xb89008b8 ReferenceCount=3 
  Flags=CNB/PNC/[0003] SavepointNum=d56ab 
LibraryHandle:  Address=0x80cdf188 Hash=8e860340 LockMode=S PinMode=S LoadLockMode=0 Status=INVL 
  ObjectName:  Name=K.TEST_FUN   
    FullHashValue=e7a045fef628c10c7c8dcf7b8e860340 Namespace=TABLE/PROCEDURE(01) Type=FUNCTION(08) ContainerId=0 ContainerUid=0 Identifier=6236412 OwnerIdn=49 
  Statistics:  InvalidationCount=674 ExecutionCount=0 LoadCount=696 ActiveLocks=1 ActivePins=1 TotalLockCount=163897 TotalPinCount=163874 
  Counters:  BrokenCount=708 RevocablePointer=708 KeepDependency=0 Version=0 BucketInUse=63688 HandleInUse=63688 HandleReferenceCount=0 
  Concurrency:  DependencyMutex=0x80cdf238(0, 326246, 0, 0) Mutex=0x80cdf2d8(0, 1479323, 6, 0) 
  Flags=PIN/TIM/VER/[40002801] Flags2=[0000] HandleIvd=6236945 
  WaitersLists:  
    Lock=0x80cdf218[0x62d12800,0x62d12800] 
    Pin=0x80cdf1f8[0x80cdf1f8,0x80cdf1f8] 
    LoadLock=0x80cdf270[0x80cdf270,0x80cdf270] 
  Timestamp:  Current=06-21-2026 08:37:46 
  HandleReference:  Address=0x80cdf358 Handle=0xa0670d70 Flags=OWN[200] 
  LibraryObject:  Address=0x903c0190 HeapMask=0000-0015-0015-0000 Flags=EXS/LOC[0004] Flags2=/CSC[4000000] Flags3=[0000] PublicFlags=NST[0001] 
    DataBlocks:  
      Block:  #='0' name=KGLH0^8e860340 pins=0 Change=NONE   
        Heap=0x80cdefc8 Pointer=0x903c0270 Extent=0x903c00d0 Flags=I/-/P/A/-/-/- 
        FreedLocation=0 Alloc=2.179688 Size=3.976562 LoadTime=06-21-2026 06:38:20 
      Block:  #='2' name=PLDIA^8e860340 pins=1 Change=NONE   
        Heap=0x903c0620 Pointer=0x80763550 Extent=0x80763490 Flags=I/-/P/A/-/-/- 
        FreedLocation=0 Alloc=13.593750 Size=15.820312 LoadTime=06-21-2026 06:38:20 
      Block:  #='4' name=PLMCD^8e860340 pins=1 Change=NONE   
        Heap=0x903c0778 Pointer=0x955b7e68 Extent=0x955b7da8 Flags=I/-/P/A/-/-/- 
        FreedLocation=0 Alloc=2.554688 Size=3.937500 LoadTime=06-21-2026 06:38:20 
--------------------------------------------------------
This lock request was aborted.
Posted by at

Tuesday, June 9, 2026

One More Case of DBMS_ALERT deadlock

Following the previous Blog One case of dbms_alert.signal deadlock
< in this Blog, we will demonstrate one more case of DBMS_ALERT deadlock.

Note: Tested in Oracle 19c

Open two Sqplus sessions: SESS-1 and SESS-2.


1. At T1, login to SESS-1, register two alert interests: alert_1 and alert_2, then exit the session: 


exec dbms_alert.register('alert_1');

exec dbms_alert.register('alert_2');

exit;


2. At T2, re-login to SESS-1 (sid: 552), check two registered names: 



-- watch two registered names, whose session is not alive.

select * from sys.dbms_alert_info where name like 'ALERT%';

NAME            SID             CHANGED    MESSAGE
--------------- --------------- ---------- ---------------
ALERT_1         0228CD530001    N
ALERT_2         0228CD530001    N

-- determines if the specified session is active.
declare
  l_unique_sid varchar2(30) := '0228CD530001';
begin
  if not dbms_session.is_session_alive(l_unique_sid) then
    dbms_output.put_line('Not Alive: (sid: ' ||to_number(substr(l_unique_sid, 1, 4), 'XXXX')||
                                ', serial#: '||to_number(substr(l_unique_sid, 5, 4), 'XXXX')||
                                   ', inst: '||to_number(substr(l_unique_sid, 9, 4), 'XXXX')||')');
  end if;
end;
/

Not Alive: (sid: 552, serial#: 52563, inst: 1)

3. At T3, continue in SESS-1, send signal: alert_2 


SQL (sid:552) > exec dbms_alert.signal('alert_2', 'alert_msg_2');

4. At T4, login to SESS-2 (sid: 16), register one alert interests: alert_3 


SQL (sid:16) > exec dbms_alert.register('alert_3');

--Note that this call is with default cleanup = true to perform cleanup of any extant orphaned pipes.

5. At T5, in SESS-1, check TX lock, SESS-2 (sid:16) is blocked by SESS-1 (sid: 552) 


SQL (sid:552) > select * from  v$lock where type = 'TX';

ADDR             KADDR             SID TY        ID1        ID2      LMODE    REQUEST      CTIME      BLOCK     CON_ID
---------------- ---------------- ---- -- ---------- ---------- ---------- ---------- ---------- ---------- ----------
00000000B4310970 00000000B43109A0   16 TX    5505024     782554          0          6        132          0          0
00000000ADB30E70 00000000ADB30EA8  552 TX    5505024     782554          6          0        169          1          0
00000000ADBCFAB8 00000000ADBCFAF0   16 TX    6291482     236621          6          0        132          0          0

3 rows selected.

6. At T6, in SESS-1, send signal: alert_1 


SQL (sid:552) > exec dbms_alert.signal('alert_1', 'alert_msg_1');

7. Both sessions throw ORA-00060 


SQL (sid:16) > exec dbms_alert.register('alert_3');
BEGIN dbms_alert.register('alert_3'); END;

*
ERROR at line 1:
ORA-00060: deadlock detected while waiting for resource
ORA-06512: at "SYS.DBMS_ALERT", line 82
ORA-06512: at "SYS.DBMS_ALERT", line 82
ORA-06512: at "SYS.DBMS_ALERT", line 103
ORA-06512: at line 1


SQL (sid:552) > exec dbms_alert.signal('alert_1', 'alert_msg_1');
BEGIN dbms_alert.signal('alert_1', 'alert_msg_1'); END;

*
ERROR at line 1:
ORA-00060: deadlock detected while waiting for resource
ORA-06512: at "SYS.DBMS_ALERT", line 431
ORA-06512: at line 1

8. Both Deadlock trc files: 


=================== testdb_ora_1851008.trc ===================

Unix process pid: 1851008, image: oracle@testdb

*** SESSION ID:(16.33150) 2026-06-09T15:35:47.444358+02:00
 
Deadlock graph:
                                          ------------Blocker(s)-----------  ------------Waiter(s)------------
Resource Name                             process session holds waits serial  process session holds waits serial
TX-0060001A-00039C4D-00000000-00000000         66      16     X        33150      63     552           X  57779
TX-00540000-000BF0DA-00000000-00000000         63     552     X        57779      66      16           X  33150
 
----- Information for waiting sessions -----
Session 16:
Holds resource TX-0060001A-00039C4D-00000000-00000000 acquired 204 seconds ago.
  sid: 16 ser: 33150 audsid: 131915016 user: 0/SYS
    flags: (0x41) USR/- flags2: (0x40009) -/-/INC
    flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
  pid: 66 O/S info: user: oracle, term: UNKNOWN, ospid: 1851008
    image: oracle@testdb
  client details:
    O/S info: user: U000380, term: WCLINBDOXKKDUGS, ospid: 42636:42136
    machine: SYS\WCLINBDOXKKDUGS program: sqlplus.exe
    application name: SQL*Plus, hash value=3669949024
  current SQL:
  DELETE DBMS_ALERT_INFO WHERE SID = :B1 
 
Session 552:
Holds resource TX-00540000-000BF0DA-00000000-00000000 acquired 241 seconds ago.
  sid: 552 ser: 57779 audsid: 131915017 user: 0/SYS
    flags: (0x41) USR/- flags2: (0x40009) -/-/INC
    flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
  pid: 63 O/S info: user: oracle, term: UNKNOWN, ospid: 1851016
    image: oracle@testdb
  client details:
    O/S info: user: U000380, term: WCLINBDOXKKDUGS, ospid: 57408:55064
    machine: SYS\WCLINBDOXKKDUGS program: sqlplus.exe
    application name: SQL*Plus, hash value=3669949024
  current SQL:
  UPDATE DBMS_ALERT_INFO SET CHANGED = 'Y', MESSAGE = :B2 WHERE NAME = UPPER(:B1 )


session 16: DID 0001-0042-0000011E	session 552: DID 0001-003F-000005CF 
session 552: DID 0001-003F-000005CF	session 16: DID 0001-0042-0000011E 
 
Rows waited on:
  Session 16: obj - rowid = 003C067C - AAPAZ8AG+AAAXuhAAC
  (dictionary objn - 3933820, file - 446, block - 97185, slot - 2)
  Session 552: obj - rowid = 003C067C - AAPAZ8AG+AAAXuhAAB
  (dictionary objn - 3933820, file - 446, block - 97185, slot - 1)


=================== testdb_ora_1851016.trc ===================

Unix process pid: 1851016, image: oracle@testdb

*** SESSION ID:(552.57779) 2026-06-09T15:35:50.836313+02:00

Deadlock graph:
                                          ------------Blocker(s)-----------  ------------Waiter(s)------------
Resource Name                             process session holds waits serial  process session holds waits serial
TX-00540000-000BF0DA-00000000-00000000         63     552     X        57779      61     196           X   9237
TX-005B0001-000BE24C-00000000-00000000         61     196     X         9237      63     552           X  57779
 
----- Information for waiting sessions -----
Session 552:
Holds resource TX-00540000-000BF0DA-00000000-00000000 acquired 245 seconds ago.
  sid: 552 ser: 57779 audsid: 131915017 user: 0/SYS
    flags: (0x41) USR/- flags2: (0x40009) -/-/INC
    flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
  pid: 63 O/S info: user: oracle, term: UNKNOWN, ospid: 1851016
    image: oracle@testdb
  client details:
    O/S info: user: U000380, term: WCLINBDOXKKDUGS, ospid: 57408:55064
    machine: SYS\WCLINBDOXKKDUGS program: sqlplus.exe
    application name: SQL*Plus, hash value=3669949024
  current SQL:
  UPDATE DBMS_ALERT_INFO SET CHANGED = 'Y', MESSAGE = :B2 WHERE NAME = UPPER(:B1 )
 
Session 196:
Holds resource TX-005B0001-000BE24C-00000000-00000000 acquired 3 seconds ago.
  sid: 196 ser: 9237 audsid: 131915018 user: 0/SYS
    flags: (0x10041) USR/- flags2: (0x40009) -/-/INC
    flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
  pid: 61 O/S info: user: oracle, term: UNKNOWN, ospid: 1850047
    image: oracle@testdb (J006)
  client details:
    O/S info: user: oracle, term: UNKNOWN, ospid: 1850047
    machine: testdb program: oracle@testdb (J006)
    application name: task-911-2 hash value=1117638710
    action name: bgp: loop: init, hash value=2828460256
  current SQL:
  DELETE DBMS_ALERT_INFO WHERE SID = :B1 
 

session 552: DID 0001-003F-000005CF	session 196: DID 0001-003D-000004C1 
session 196: DID 0001-003D-000004C1	session 552: DID 0001-003F-000005CF 
 
Rows waited on:
  Session 552: obj - rowid = 003C067C - AAPAZ8AG+AAAXuhAAB
  (dictionary objn - 3933820, file - 446, block - 97185, slot - 1)
  Session 196: obj - rowid = 003C067C - AAPAZ8AG+AAAXuhAAC
  (dictionary objn - 3933820, file - 446, block - 97185, slot - 2)

9. Repeat Test


To repeat test, exit both SESS-1 and SESS-2, open a third SESS-3, and register a new alert to cleanup alert_1, alert_2, alert_3. Then repeat above test steps. 

exec dbms_alert.register('alert_other');

10. Reasoning


Two alert interests are inserted (registered) into sys.dbms_alert_info in the order of alert_1 and alert_2, both with the same unique_session_id: 0228CD530001.

When we register alert interest: alert_3, DBMS_ALERT first performs cleanup of not alive sessions by delete in default order: alert_1 and alert_2.

Whereas we frist send (update) signal: alert_2, then alert_1.

In this case, Updates vs Delete are interfered in crossing row order, hence Deadlock.
Posted by at
Subscribe to: Posts (Atom)