Blog List

• October 2026 (4)
  
  1. Instance Terminated When ORA-00494: enqueue [CF] held for too long by CKPT and Killed
  2. Oracle Package Body Invalid without DBA_ERRORS: Case Study
  3. Oracle TX Row Deadlock (ORA-00060) Catch-Retry Endless Loop Test
  4. Oracle 19.32 OJVM ZipFile.getInputStream(ZipEntry entry) empty
• July 2026 (1)
  
  1. Oracle Partition Split With LOB Segment Performance Test
• June 2026 (2)
  
  1. Oracle single session "library cache lock" self deadlock: ORA-04020
  2. One More Case of DBMS_ALERT deadlock
• April 2026 (1)
  
  1. One Oracle TDE Performance Test
• January 2026 (4)
  
  1. Oracle ORA-01426: numeric overflow and PL/SQL Runtime MCODE
  2. Oracle SQL MEMBER vs. IN Comparison Condition Performance - Part1
  3. Oracle SQL MEMBER vs. IN Comparison Condition Performance - Part2
  4. "Disk file operations I/O" with (FileOperation: 8, fileno: 0, filetype: 8) Test
• December 2025 (1)
  
  1. Three Oracle cursor error Tests
• September 2025 (3)
  
  1. ORA-06502: NULL index table key value and plsql_optimize_level
  2. "ORA-00001: unique constraint violated" Debugging
  3. Oracle Database Stuck on DB Writer Wait Event: "oradebug request completion"
• August 2025 (1)
  
  1. Reading CLOB Line by Line with SQL and Plsql: ChatGPT and Gemini Implementations
• July 2025 (3)
  
  1. Reading CLOB Line by Line with SQL and Plsql
  2. "library cache: bucket mutex X" on V$ Fixed Views: Case Test
  3. Oracle dbms_hprof: Uncatchable Time in PL/SQL Nested Program Units
• June 2025 (1)
  
  1. ORA-01002: fetch out of sequence: One Case Test
• May 2025 (1)
  
  1. Oracle ORA-00600 [pfrsfm: stack mismatch] and [pfrsfm: stack mismatch] Reproducing
• February 2025 (1)
  
  1. One Oracle CLOB Space Usage Test
• November 2024 (1)
  
  1. Oracle Self-tune checkpointing lag of log switch
• October 2024 (1)
  
  1. Find the skipped rows in select for update skip locked
• September 2024 (1)
  
  1. One OracleJVM TIME_MODEL Test
• April 2024 (3)
  
  1. Oracle AQ Dequeue 'KTC latch subh' Memory Leak and Dequeue Long Running Test
  2. One Test of Oracle Object Collection MEMBER OF Function
  3. In Memoriam of Prof. Niklaus Wirth: One Email on Program Debugging
• January 2024 (1)
  
  1. One Test on the Different Errors of Oracle Global Temporary Tables vs. Private Temporary Tables
• October 2023 (1)
  
  1. ORA-28268: Exceeded the maximum allowed size for Context information in a session
• September 2023 (3)
  
  1. Oracle Index Root Modification CBC Latch Contention: Workaround Studies
  2. Oracle 19.18 Wait Event 'latch: cache buffers chains' P3: block number
  3. Oracle Index Range Scan with LIKE Condition on Wildcard '_'
• August 2023 (1)
  
  1. Oracle SYS_GUID Composition
• June 2023 (1)
  
  1. One Deadlock of 'row cache lock' and 'library cache lock'
• April 2023 (3)
  
  1. Oracle Multi-Consumer AQ dequeue with dbms_aq.listen Wait Events (I)
  2. Oracle Multi-Consumer AQ dequeue with dbms_aq.listen Performance Model (II)
  3. Oracle Multi-Consumer AQ dequeue with dbms_aq.listen Performance Analysis and Workaround (III)
• March 2023 (2)
  
  1. One Test of Oracle JSON Plsql PGA Memory Leak
  2. One Test of ORA-00600: [KGL-heap-size-exceeded] With AQ Subscriber
• February 2023 (1)
  
  1. Oracle Scalar Subquery Caching and Non-deterministic Functions
• January 2023 (1)
  
  1. Oracle dbms_crypto.randombytes and Enhancement Suggestion
• December 2022 (2)
  
  1. OracleJVM JAVA_JIT_ENABLED Linux /dev/shm mount noexec EPERM and Performance
  2. One Test of Oracle too many parse errors with ORA-12850 and ORA-12872
• October 2022 (2)
  
  1. How many times SYSDATE is called in SQL and Plsql ?
  2. Oracle WITH subquery_factoring_clause TEMP TABLE TRANSFORMATION and log file sync
• September 2022 (2)
  
  1. Update Restart and Undo Extends
  2. Proposal for ORA-04030 incident/trace files Enhancement to list Plsql package Memory Usage
• August 2022 (2)
  
  1. Oracle Global Temporary Table ORA-01555 and Undo Retention
  2. Oracle Global Temporary Table ORA-01555 and XML Data Size
• July 2022 (1)
  
  1. Plsql ORA-00600 by JDBC Call Exception Catch
• June 2022 (1)
  
  1. Tests of Oracle ORA-01866: the datetime class is invalid
• May 2022 (2)
  
  1. How volatile is ORA-00600 [qernsRowP] ?
  2. One Case of ORA-00036: Maximum Number Of Recursive SQL Levels (50) Exceeded
• April 2022 (2)
  
  1. Oracle Write Consistency and ORA-30926: "unable to get a stable set of rows in the source tables"
  2. Oracle Write Consistency and ORA-00600: [13030], [20]
• March 2022 (1)
  
  1. Index Skip Scan With First Column of Composite Index Specified
• February 2022 (2)
  
  1. Oracle Kill Session Crashes DB Instance
  2. How to determine session's CURRVAL of an oracle sequence without error and without modify ?
• January 2022 (1)
  
  1. Oracle SQL Monitoring Shared Pool "keomg: entry list " Memory Leak
• December 2021 (1)
  
  1. How to count the inserts and updates from merge ?
• November 2021 (1)
  
  1. Oracle dbms_aq.dequeue_array Shared Pool "KTC Latch Subh" Memory Leak
• October 2021 (2)
  
  1. Oracle Temp Space Usage Monitoring and View v$tempseg_usage
  2. Oracle sessiontimezone Format Changed After Calling dbms_scheduler/dbms_job Subprograms
• July 2021 (1)
  
  1. Oracle Program and Table dc_objects "row cache lock"
• June 2021 (1)
  
  1. Oracle dbms_alert and its Wait Events
• May 2021 (1)
  
  1. Oracle 19c new shared pool "SO private sga" and "SO private so latch" Performance Impacts
• April 2021 (3)
  
  1. Oracle PLITBLM "library cache: mutex X"
  2. The Third Test of ORA-04025: maximum allowed library object lock
  3. Oracle forall DML save exceptions and ORA-04030: out of process memory (callheap,psdalf:RPI allocations)
• March 2021 (2)
  
  1. Oracle Temp File Read Time Stats Problem
  2. Oracle deallocate_unused_clause and its effect
• January 2021 (1)
  
  1. DBMS_SCHEDULER Job Not Running and Used Slaves
• November 2020 (3)
  
  1. OracleJVM integer Array Size Limit and Out of Memory Error
  2. Oracle LOB Chunksize and Buffersize
  3. One case of dbms_alert.signal deadlock
• September 2020 (1)
  
  1. The Second Test of ORA-600 [4156] Rolling Back To Savepoint
• August 2020 (1)
  
  1. Row Cache Object and Row Cache Mutex Case Study
• May 2020 (3)
  
  1. 12cR2 Index Usage Tracking Manual Flushing
  2. One "row cache lock" Test Case
  3. ORA-600 [504] LATCH HIERARCHY ERROR Deadlock
• April 2020 (3)
  
  1. Index Service ITL and Recursive Transaction
  2. Index Block Split Point Distribution
  3. Cache Buffer Chains Latch Contention Case Study-3: index root block Modification Blocking
• February 2020 (2)
  
  1. Cache Buffer Chains Latch Contention Case Study-2: Reverse Primary Key Index
  2. Cache Buffer Chains Latch Contention Case Study-1: Reverse Key Index
• January 2020 (1)
  
  1. Oracle Unique Index Non-Consistency Read with RowCR
• December 2019 (2)
  
  1. Oracle Database and Java Datetime Conversion Differences across Daylight Saving Time (DST)
  2. Oracle 19.4 OracleJVM JAVA_JIT_ENABLED Not Working on AIX
• August 2019 (2)
  
  1. Oracle 18 New Wait Event: 'index (re)build lock or pin object'
  2. PDML Disabled on Nonpartitioned IOT
• April 2019 (1)
  
  1. LOB ORA-22924: snapshot too old and Fix
• November 2018 (5)
  
  1. Oracle row cache objects Event: 10222, Dtrace Script (I)
  2. Row Cache Objects, Row Cache Latch on Object Type: Plsql vs Java Call (Part-1) (II)
  3. Row Cache Objects, Row Cache Latch on Object Type: Plsql vs Java Call (Part-2) (III)
  4. Row Cache and Sql Executions (IV)
  5. Latch: row cache objects Contentions and Scalability (V)
• October 2018 (2)
  
  1. Oracle ROWCACHE Views and Contents
  2. Result Cache: RC Enqueue and Contention (V)
• July 2018 (3)
  
  1. row cache mutex in Oracle 12.2.0.1.0
  2. plshprof command-line utility in Oracle 12.2.0.1.0
  3. 12c Online Statistics Gathering for Direct Path Insert and 3 Side Effects
• April 2018 (1)
  
  1. TM Lock and No Transaction Commit, TX & TM Locks and No Transaction Visible
• March 2018 (2)
  
  1. 'enq: RO - fast object reuse' and 'enq: KO - fast object checkpoint' Final Blocker
  2. Oracle 12.1 Wait Event: 'log file sync: SCN ordering' Demo
• February 2018 (1)
  
  1. SYS.LOADER_DIR_OBJS Query: Privileges and Performance
• January 2018 (4)
  
  1. Oracle Logical Read: Current Gets Access Path and Cost
  2. Oracle Logical Read: Consistent Gets Access Path and Cost
  3. Oracle Physical Read Access Path and Cost
  4. Oracle Latch Misses, Spin_gets, Sleeps and Recurrent_Misses
• October 2017 (2)
  
  1. ORA-04025 library object lock on DATABASE Truncate Triggers
  2. Result Cache: 0 rows updated Invalidations (IV)
• September 2017 (2)
  
  1. Result Cache: RC Latch Contention and PL/SQL Exception Handler (III)
  2. Result Cache: RC Latch Contention and RESULT_CACHE_MAX_SIZE(II)
• July 2017 (3)
  
  1. nls_database_parameters, dc_props, latch: row cache objects
  2. v$database select and control file sequential read
  3. Getting Oracle Transaction Commit SCN
• May 2017 (8)
  
  1. JDBC, Oracle object/collection, dbms_pickler, NOPARALLEL sys.type$ query
  2. PLSQL Context Switch Functions and Cost
  
  
  3. Oracle Datetime (1) - Concepts
  4. Oracle Datetime (2) - Examples
  5. Oracle Datetime (3) - Assignments
  6. Oracle Datetime (4) - Comparisons
  7. Oracle Datetime (5) - SQL Arithmetic
  8. Oracle Datetime (6) - PLSQL Arithmetic
• March 2017 (3)
  
  1. Oracle 12c PL/SQL Function in the WITH Clause: wrong result
  2. Oracle abstract_lob Memory Leak
  3. PL/SQL Function Result Cache Invalidation (I)
• February 2017 (1)
  
  1. Oracle JVM Java OutOfMemoryError and lazy GC
• January 2017 (1)
  
  1. ORA-600 [4156] SAVEPOINT and PL/SQL Exception Handling
• November 2016 (1)
  
  1. "library cache: mutex X" and Application Context
• September 2016 (2)
  
  1. PL/SQL Multidimensional Collection Memory Usage and Performance
  1. dbms_session.get_package_memory_utilization and limitations
• August 2016 (1)
  
  1. ORA-04025 library object lock on AQ queue and SQL cursor
• June 2016 (1)
  
  1. SQL Parsing in serializable transaction throws ORA-08177: can't serialize access for this transaction
• May 2016 (1)
  
  1. Oracle Fixed Table Practice
• April 2016 (1)
  
  1. sql_id and idn to shared pool subpool
• February 2016 (1)
  
  1. Native Code Files: Ora-7445 [Ioc_pin_shared_executable_object()] Reproducing
• January 2016 (3)
  
  1. Performance of Oracle Object Collection Comparisons - Part2
  2. Performance of Oracle Object Collection Comparisons - Part1
  3. Foreign Keys and Library Cache Locks: Analysis
• December 2015 (1)
  
  1. Oracle bigfile tablespace pre-allocation and session blocking
• November 2015 (1)
  
  1. Oracle 12c single session "library cache lock (cycle)" deadlock
• September 2015 (2)
  
  1. SQL DML Exceptions, Rollbacks and PL/SQL Exception Handlers
  2. Limit PGA Memory Usage
• August 2015 (1)
  
  1. Latch _SPIN_COUNT: adaptive
• July 2015 (2)
  
  1. Redo Practice
  2. UNDO Practice
• June 2015 (1)
  
  1. Temporary LOB Memory Allocation and Freeing in JAVA
• April 2015 (2)
  
  1. IBM AIX POWER7 CPU Usage and Throughput
  2. Oracle 11.2.0.4.0 AWR "Tablespace IO Stats" Column Names Shifted
• January 2015 (1)
  
  1. open_cursors, session_cached_cursors: cursordump
• December 2014 (1)
  
  1. Local prefixed vs. nonprefixed indexes: Column Null Values
• November 2014 (2)
  
  1. reverse key index: the remedy is worse than the symptoms
  2. Low High Water Mark, High High Water Mark, and Parallel Query
• May 2014 (3)
  
  1. Oracle 11g AUTO_SAMPLE_SIZE performance on Small Tables
  2. java stored procedure calls and latch: row cache objects, and performance
  3. java stored procedure calls and latch: row cache objects
• March 2014 (2)
  
  1. dbms_aq.dequeue - latch: row cache objects on AIX
  2. Hot Block Identification and latch: cache buffers chains
• November 2013 (3)
  
  1. Remove Stale Native Code Files on AIX
  2. PGA, SGA memory usage watching from UNIX
  3. ORA-04030 incident file and alert.log
• September 2013 (1)
  
  1. Execution Switching between "direct path read" and "db file scattered read"
• June 2013 (2)
  
  1. Oracle PL/SQL Collection Memory Reclaim 
  2. dbms_alert lock hash collision
• April 2013 (2)
  
  1. cursor: pin S wait on X
  2. Shared Pool - Free Memory, Fragmentation ?
• March 2013 (3)
  
  1. Shared Pool - SQLA and KGLH0
  2. Shared Pool - Memory Allocation - unbalanced
  3. Shared Pool - KKSSP
• December 2012 (1)
  
  1. Delete Restart and new Active Undo Extent
• November 2012 (2)
  
  1. One Oracle AQ Deadlock
  2. Oracle Java OutOfMemoryError
• July 2012 (1)
  
  1. One Mutex Collision Test
• May 2012 (1)
  
  1. Why shared pool is doubled ?
• April 2012 (1)
  
  1. High system time utilization on fast machine
• February 2012 (1)
  
  1. Is latch misses statistic gathered or deduced ?
• November 2011 (2)
  
  1. One Oracle 12g Pre-announce of bug fix in dbms_debug_jdwp
  2. Oracle 11gR2 single session "library cache pin"
• July 2011 (1)
  
  1. Redo/Undo explosion from thick declared table insert
• May 2011 (3)
  
  1. ORA-04027: self-deadlock during automatic validation
  2. Foreign Key on Nested Table
  3. Update Restart and new Active Undo Extent
• April 2011 (1)
  
  1. dbms_session package_memory_utilization

Instance Terminated When ORA-00494: enqueue [CF] held for too long by CKPT and Killed

Oracle Instance is being terminated due to CKPT holding enqueue CF too long and CKPT is killed by Oracle Background Process.
This Blog demonstrates one step-by-step test case.

Note: Tested in Oracle 19c with:

1. Test Steps

Open one UNIX window, and two Sqlplus sessions (SID-1 and SID-2).

1.1 UNIX Window

On UNIX Window, find ckpt process and its associated control files,
set GDB breakpoint when pread64 on them.

 
$ > ps -efl |grep ckpt
0 S oracle     81749       1  0  80   0 - 1246636 -    11:34 ?        00:00:00 ora_ckpt_testdb01

$ > lsof -p 81749 | grep control

ora_ckpt_ 81749 oracle  256uW  REG    8,1  32620544  671095912 /oratestdb01/oradata/testdb01/control01.ctl
ora_ckpt_ 81749 oracle  257uW  REG    8,1  32620544  671095913 /oratestdb01/oradata/testdb01/control02.ctl
ora_ckpt_ 81749 oracle  258uW  REG    8,1  32620544  671095914 /oratestdb01/oradata/testdb01/control03.ctl

Here gdb commands and output:

 
$ > gdb -p 81749

(gdb) display $rdi
  1: $rdi = 31
(gdb) break pread64 if $rdi == 256 || $rdi == 257 || $rdi == 258
  Breakpoint 1 at 0x7fc984de9870 (2 locations)
(gdb) info b
  Num     Type           Disp Enb Address            What
  1       breakpoint     keep y   
          stop only if $rdi == 256 || $rdi == 257 || $rdi == 258
  1.1                         y     0x00007fc984de9870 
  1.2                         y     0x00007fc9855052b0 
(gdb) c
  Continuing.

Breakpoint 1, 0x00007fc9855052b0 in pread64 () from /lib64/libpthread.so.0
  1: $rdi = 256
(gdb) info r
  rax            0x1                 1
  rbx            0x0                 0
  rcx            0x4000              16384
  rdx            0x4000              16384
  rsi            0x7fc9827a1000      140503454191616
  rdi            0x100               256

1. 2. Sqlplus SID-1

On the first Sqlplus session, run some DML and then force Oracle Database to perform a checkpoint.
CKPT starts to read control files, and stops on pread64 breakpoint.
Oracle v$session shows CKPT event "control file sequential read".

 
create table ksun_tab as 
select level x, rpad('ABC', 500, 'X') y from dual connect by level <= 1e4; 

Sqlplus > update ksun_tab set y = rpad('ABC', 500, 'x');

  10000 rows updated.

Sqlplus > commit;

  Commit complete.

Sqlplus > alter system checkpoint;
  ERROR:
  ORA-03114: not connected to ORACLE
  
  alter system checkpoint
  *
  ERROR at line 1:
  ORA-03113: end-of-file on communication channel
  Process ID: 80361
  Session ID: 283 Serial number: 3022

1.3. Sqlplus SID-2

On the second Sqlplus session, force Oracle Database to begin writing to a new redo log file group (log switch),
and Oracle Database also begins to perform a checkpoint, hence LGWR is blocked with Event: "enq: CF - contention":

 
Sqlplus > alter system switch logfile;
  ERROR:
  ORA-03114: not connected to ORACLE
  
  alter system switch logfile
  *
  ERROR at line 1:
  ORA-03113: end-of-file on communication channel
  Process ID: 81230
  Session ID: 24 Serial number: 25591

1.4. Instance is being terminated

After 900 seconds, alert.log shows:

 
Cause - 'Instance is being terminated due to ospid CKPT holding an enqueue CF'

Hiddne parameter "_controlfile_enqueue_timeout" controls file enqueue timeout in seconds with default 900 seconds.

2. DB alert.log

alert.log shows that CKPT is killed by one Background processes (e.g, LGWR, ARCn, TTnn, MMON) due to
ORA-00494: enqueue [CF] held for too long (more than 900 seconds) by CKPT.

 
Errors in file /orabin/app/oracle/admin/testdb01/diag/rdbms/testdb01/testdb01/trace/testdb01_mmon_80100.trc  (incident=33857):
ORA-00494: enqueue [CF] held for too long (more than 900 seconds) by 'inst 1, osid 80070'
Incident details in: /orabin/app/oracle/admin/testdb01/diag/rdbms/testdb01/testdb01/incident/incdir_33857/testdb01_mmon_80100_i33857.trc
2026-08-25T10:37:19.316424+02:00
Killing enqueue blocker (pid=80070) on resource CF-00000000-00000000-00000000-00000000 by (pid=80100)
 by killing session 273.24900
KILL SESSION for sid=(273, 24900):
  Reason = RAC enqueue blocker
  Mode = KILL SOFT -/-/-
  Requestor = MMON (orapid = 32, ospid = 80100, inst = 1)
  Owner = Process: CKPT (orapid = 21, ospid = 80070)
  Result = ORA-29
Killing enqueue blocker (pid=80070) on resource CF-00000000-00000000-00000000-00000000 by (pid=80100)
 by terminating the process
MMON (ospid: 80100): terminating the instance due to ORA error 2103
Cause - 'Instance is being terminated due to ospid 80070 holding an enqueue CF-00000000-00000000-00000000-00000000)'
2026-08-25T10:37:19.372998+02:00
System state dump requested by (instance=1, osid=80100 (MMON)), summary=[abnormal instance termination].

3. Background Incident and Trc files

 
Dump continued from file: /orabin/app/oracle/admin/testdb01/diag/rdbms/testdb01/testdb01/trace/testdb01_mmon_80100.trc
[TOC00001]
ORA-00494: enqueue [CF] held for too long (more than 900 seconds) by 'inst 1, osid 80070'

[TOC00001-END]
[TOC00002]
========= Dump for incident 33857 (ORA 494) ========
[TOC00003]
----- Beginning of Customized Incident Dump(s) -----
-------------------------------------------------------------------------------
ENQUEUE [CF] HELD FOR TOO LONG
 
enqueue holder: 'inst 1, osid 80070'
 
Process 'inst 1, osid 80070' is holding an enqueue for maximum allowed time.
The process will be terminated after collecting some diagnostics.
It is possible the holder may release the enqueue before the termination 
is attempted. If so, the process will not be terminated and 
this incident will only be served as a warning.
Oracle Support Services triaging information: to find the root-cause, look
at the call stack of process 'inst 1, osid 80070' located below. Ask the
developer that owns the first NON-service layer in the stack to investigate.
Common service layers are enqueues (ksq), latches (ksl), library cache
pins and locks (kgl), and row cache locks (kqr).

  [880 samples,                                            10:35:48 - 10:50:48]
    waited for 'control file sequential read', seq_num: 16046
      p1: 'file#'=0x0
      p2: 'block#'=0x1
      p3: 'blocks'=0x1
      
Problem Key: ORA 494
Error: ORA-494 [[CF]] [900] [1] [80070] [] [] [] [] [] [] [] []
[00]: dbgexExplicitEndInc [diag_dde]
[01]: dbgeEndDDEInvocationImpl [diag_dde]
[02]: dbgeEndSpltInvokOnRec [diag_dde]
[03]: dbgePostErrorKGE [diag_dde]
[04]: dbkePostKGE_kgsf [rdbms_dde]
[05]: kgeade []
[06]: kgeselv []
[07]: ksesec3 [KSE]
[08]: ksdx_cmdreq_wait_for_pending [VOS]<-- Signaling
[09]: ksdxdocmdmultex [VOS]


*Note: 10:35:48 - 10:50:48 is 15 minutes (900 seconds)

4. bpftrace CKPT io_submit

 
bpftrace -v -e 'tracepoint:syscalls:sys_enter_io_submit /strncmp("ora_ckpt", comm, 7) == 0/ {
              $iocb_sizeof = sizeof(struct iocb);
              $reqs = args->nr;
              $iocbpp_ptr = (struct iocb **)args->iocbpp;
              time("%H:%M:%S --- ");
              printf("%s, iocb_sizeof: %d, io_submit I/O request: %d\n", comm, $iocb_sizeof, $reqs);
              $i = 1; while ($i <= $reqs) { $iocbpp_ptr_2 = (struct iocb **)($iocbpp_ptr + $iocb_sizeof*($i-1));
                                            $iocbpp_struct = (struct iocb *)(*$iocbpp_ptr_2);
                                            printf("--- File: %d --- ptr_2 %p, aio_fildes: %d, aio_nbytes: %d, aio_offset: %ld, aio_lio_opcode(1=PWRITE): %d, aio_data:0X%X\n",
                                                   $i, $iocbpp_ptr_2, $iocbpp_struct->aio_fildes, $iocbpp_struct->aio_nbytes, $iocbpp_struct->aio_offset, $iocbpp_struct->aio_lio_opcode, $iocbpp_struct->aio_data);
                                            @All_CNT = count(); @CNT[$iocbpp_struct->aio_fildes] = count(); @SUM[$iocbpp_struct->aio_fildes] = sum( $iocbpp_struct->aio_nbytes);
                                            if ($i > 50) { break; }
                                            $i++ }
              printf("\n");}'

Oracle Package Body Invalid without DBA_ERRORS: Case Study

This Blog demonstrates the case in which Oracle Package Spec/Body Invalid, but no entry stored in DBA_ERRORS.
We reveal Oracle Internals with SQL Trace, and shows approach to detect such Invalid.

Note: Tested in Oracle 19c

1. Test Code

At first, we create one table and one Plsql package using it.

drop table test_tab;

create table test_tab(x1 number(2));

insert into test_tab (x1) values (1);

commit;

select * from test_tab;

drop package test_pkg;

create or replace package test_pkg as
  --b_ret test_tab.x1%type;  -- this makes both Package Spec and Body INVALID
  function func1 (p_x number) return number;
end;
/

create or replace package body test_pkg as
  function func1 (p_x number) return number as
    l_ret number;
  begin
    -- comment out this query to make Package Body not depend on any table
    select x1 into l_ret from test_tab where x1 = p_x;   
    return l_ret;
  end;
end;  
/

2. Modify Table to trigger Package Body Invalid

We query dba_dependencies to list the dependencies:

select name, type, referenced_name, referenced_type, dependency_type from dba_dependencies where name = 'TEST_PKG';

NAME       TYPE            REFERENCED REFERENCED DEPENDENCY
---------- --------------- ---------- ---------- ----------
TEST_PKG   PACKAGE         STANDARD   PACKAGE    HARD
TEST_PKG   PACKAGE BODY    STANDARD   PACKAGE    HARD
TEST_PKG   PACKAGE BODY    TEST_TAB   TABLE      HARD
TEST_PKG   PACKAGE BODY    TEST_PKG   PACKAGE    HARD 

Modify test_tab to invalidate package body:

alter table test_tab modify x1 number(9);

--  alter table test_tab add x2 number(9);
--  alter table test_tab drop column x2;

ALTER SESSION SET NLS_DATE_FORMAT         ='YYYY-MON-DD HH24:MI:SS';    
ALTER SESSION SET NLS_TIMESTAMP_FORMAT    ='YYYY-MON-DD HH24:MI:SS';

select object_name, object_id, data_object_id, created, last_ddl_time, timestamp, status 
  from dba_objects where object_name in ( 'TEST_PKG', 'TEST_TAB');
  
  OBJECT_NAM  OBJECT_ID DATA_OBJECT_ID CREATED              LAST_DDL_TIME        TIMESTAMP           STATUS
  ---------- ---------- -------------- -------------------- -------------------- ------------------- ----------
  TEST_TAB      6256609        6256609 2026-AUG-25 13:41:38 2026-AUG-25 13:46:02 2026-08-25:13:46:02 VALID
  TEST_PKG      6256610                2026-AUG-25 13:43:24 2026-AUG-25 13:43:24 2026-08-25:13:43:24 VALID
  TEST_PKG      6256611                2026-AUG-25 13:43:24 2026-AUG-25 13:43:24 2026-08-25:13:43:24 INVALID

-- dba_objects.status= decode(o.status, 0, 'N/A', 1, 'VALID', 'INVALID')
select obj#, name, type#, ctime, mtime, stime, status from sys.obj$ o where name = 'TEST_PKG';  

     OBJ# NAME            TYPE# CTIME                MTIME                STIME                STATUS
  ------- ---------- ---------- -------------------- -------------------- -------------------- ------
  6256610 TEST_PKG            9 2026-AUG-25 13:43:24 2026-AUG-25 13:43:24 2026-AUG-25 13:43:24      1
  6256611 TEST_PKG           11 2026-AUG-25 13:43:24 2026-AUG-25 13:43:24 2026-AUG-25 13:43:24      5

When we query dba_errors, no entries found:

select * from dba_errors where name = 'TEST_PKG';

  no rows selected

select * from sys.error$ e, dba_objects o 
 where e.obj# = o.object_id and object_name in ( 'TEST_PKG', 'TEST_TAB');

  no rows selected

If we invoke package program, Package Body becomes VALID:

declare
  l_ret number;
begin
  l_ret := test_pkg.func1(1);
  dbms_output.put_line('l_ret = '||l_ret);
end;
/

  l_ret = 1

select object_name, object_id, data_object_id, created, last_ddl_time, timestamp, status 
  from dba_objects where object_name in ( 'TEST_PKG', 'TEST_TAB');

  OBJECT_NAM  OBJECT_ID DATA_OBJECT_ID CREATED              LAST_DDL_TIME        TIMESTAMP           STATUS
  ---------- ---------- -------------- -------------------- -------------------- ------------------- -------
  TEST_TAB      6256609        6256609 2026-AUG-25 13:41:38 2026-AUG-25 14:11:44 2026-08-25:14:11:44 VALID
  TEST_PKG      6256610                2026-AUG-25 13:43:24 2026-AUG-25 13:43:24 2026-08-25:13:43:24 VALID
  TEST_PKG      6256611                2026-AUG-25 13:43:24 2026-AUG-25 14:12:08 2026-08-25:14:12:08 VALID

3. SQL Trace to Reveal Dependency and Invalid

We modify the table again with SQL Trace level 12 (contains bind variables):

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

alter table test_tab add x1 number(11);   

alter session set events '10046 trace name context off';

TEST_PKG Body is INVALID:

select object_name, object_id, data_object_id, created, last_ddl_time, timestamp, status 
  from dba_objects where object_name in ( 'TEST_PKG', 'TEST_TAB');

  OBJECT_NAM  OBJECT_ID DATA_OBJECT_ID CREATED              LAST_DDL_TIME        TIMESTAMP           STATUS
  ---------- ---------- -------------- -------------------- -------------------- ------------------- -------
  TEST_TAB      6256609        6256609 2026-AUG-25 13:41:38 2026-AUG-25 14:16:41 2026-08-25:14:16:41 VALID
  TEST_PKG      6256610                2026-AUG-25 13:43:24 2026-AUG-25 13:43:24 2026-08-25:13:43:24 VALID
  TEST_PKG      6256611                2026-AUG-25 13:43:24 2026-AUG-25 14:12:08 2026-08-25:14:12:08 INVALID  

-- dba_objects.status= decode(o.status, 0, 'N/A', 1, 'VALID', 'INVALID')
--   set test_pkg package body sys.OBJ$.status = 5, i.e, dba_objects.status = 'INVALID'
--   no any modification of sys.ERROR$ for test_pkg package body 

Open trc file, we can see that TIMESTAMP (Bind#4 stime) of TEST_TAB is updated as value="8/25/2026 14:16:41":

=== Update Table: TEST_TAB (OBJECT_ID = 6256609), set mtime(Bind#4)="8/25/2026 14:16:41", set stime(Bind#4)="8/25/2026 14:16:41", status(Bind#5)=1 (VALID)

PARSING IN CURSOR #139943683342520 len=409 dep=1 uid=0 oct=6 lid=0 tim=843833534857 hv=696165170 ad='9ecdf3e8' sqlid='c3utnxsnrx8tk'
update obj$ set obj#=:4, type#=:5,ctime=:6,mtime=:7,stime=:8,status=:9,
  dataobj#=:10,flags=:11,oid$=:12,spare1=:13,spare2=:14,spare3=:15,signature=
  :16,spare7=:17,spare8=:18,spare9=:19, dflcollid=decode(:20,0,null,:20),
  creappid=:21,creverid=:22, modappid=:23,modverid=:24,crepatchid=:25,
  modpatchid=:26 
where
 owner#=:1 and name=:2 and namespace=:3 and remoteowner is null and linkname 
  is null and subname is null

BINDS #139943683342520:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=48 off=0
  kxsbbbfp=7f472d7acfe8  bln=22  avl=05  flg=05
  value=6256609
 Bind#1
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=24
  kxsbbbfp=7f472d7ad000  bln=22  avl=02  flg=01
  value=2
 Bind#2
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=989ee31d  bln=07  avl=07  flg=09
  value="8/25/2026 13:41:38"
 Bind#3
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=989ee324  bln=07  avl=07  flg=09
  value="8/25/2026 14:16:41"
 Bind#4
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=989ee32b  bln=07  avl=07  flg=09
  value="8/25/2026 14:16:41"
 Bind#5
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=72 off=0
  kxsbbbfp=7f472d7acf88  bln=22  avl=02  flg=05
  value=1

  ......
  
 Bind#25
  oacdty=01 mxl=32(08) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=989ee106  bln=32  avl=08  flg=09
  value="TEST_TAB"
 Bind#26
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7f472d7ace68  bln=22  avl=02  flg=05
  value=1

For Package Body TEST_PKG (OBJECT_ID = 6256611), its status(Bind#5) is updated as value=5 (INVALID):

=== update package body: TEST_PKG (OBJECT_ID = 6256611), set status(Bind#5)=5 (INVALID)

update obj$ set obj#=:4, type#=:5,ctime=:6,mtime=:7,stime=:8,status=:9,
       dataobj#=:10,flags=:11,oid$=:12,spare1=:13,spare2=:14,spare3=:15,signature=:16,spare7=:17,spare8=:18,spare9=:19, 
       dflcollid=decode(:20,0,null,:20),creappid=:21,creverid=:22, modappid=:23,modverid=:24,crepatchid=:25,modpatchid=:26 
 where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null and linkname is null and subname is null

BINDS #139943683342520:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=48 off=0
  kxsbbbfp=7f472e0e19a8  bln=22  avl=05  flg=05
  value=6256611
 Bind#1
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=24
  kxsbbbfp=7f472e0e19c0  bln=22  avl=02  flg=01
  value=11
 Bind#2
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=988e02ad  bln=07  avl=07  flg=09
  value="8/25/2026 13:43:24"
 Bind#3
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=988e02b4  bln=07  avl=07  flg=09
  value="8/25/2026 14:12:8"
 Bind#4
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=988e02bb  bln=07  avl=07  flg=09
  value="8/25/2026 14:12:8"
 Bind#5
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=72 off=0
  kxsbbbfp=7f472e0e1948  bln=22  avl=02  flg=05
  value=5
  
 ......
 
 Bind#25
  oacdty=01 mxl=32(08) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=988e0096  bln=32  avl=08  flg=09
  value="TEST_PKG"
 Bind#26
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7f472e0e1828  bln=22  avl=02  flg=05
  value=2

Package Body TEST_PKG INVALID is due to the difference between p_timestamp (25-AUG-2026 14:11:44) of its dependency and stime (25-AUG-2026 14:16:41) of its dependent Table TEST_TAB.
In fact, Oracle has one query to reveal such difference.
(sys.dependency$ contains column p_timestamp, which is not exposed in dba_dependencies).

  select do.obj#                                                         d_obj,
         do.name                                                         d_name,
         do.type#                                                        d_type,
         po.obj#                                                         p_obj,
         po.name                                                         p_name,
         to_char (d.p_timestamp, 'DD-MON-YYYY HH24:MI:SS')               "P_Timestamp",
         to_char (po.stime, 'DD-MON-YYYY HH24:MI:SS')                    "STIME",
         decode (sign (po.stime - d.p_timestamp), 0, 'SAME', '*DIFFER*') "CHECK"
    from sys.obj$ do, sys.dependency$ d, sys.obj$ po
   where d.p_obj# = po.obj#(+) and d.d_obj# = do.obj# 
     --and do.status=1 /*dependent is valid*/
     --and po.status=1 /*parent is valid*/
     --and po.stime != d.p_timestamp /*parent timestamp not match*/
      and do.name = 'TEST_PKG'
order by 2, 1;

    D_OBJ D_NAME     D_TYPE      P_OBJ P_NAME     P_Timestamp                   STIME                         CHECK
  ------- ---------- ------ ---------- ---------- ----------------------------- ----------------------------- ----------
  6256610 TEST_PKG        9       1219 STANDARD   16-JUL-2018 00:00:00          16-JUL-2018 00:00:00          SAME
  6256611 TEST_PKG       11       1219 STANDARD   16-JUL-2018 00:00:00          16-JUL-2018 00:00:00          SAME
  6256611 TEST_PKG       11    6256609 TEST_TAB   25-AUG-2026 14:11:44          25-AUG-2026 14:16:41          *DIFFER*
  6256611 TEST_PKG       11    6256610 TEST_PKG   25-AUG-2026 13:43:24          25-AUG-2026 13:43:24          SAME

4. Invoke Makes Valid

We use SQL trace again to track how Oracle makes Package Body Valid when package programs are invoked:

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

declare
  l_ret number;
begin
  l_ret := test_pkg.func1(1);
  dbms_output.put_line('l_ret = '||l_ret);
end;
/ 

alter session set events '10046 trace name context off';

We can see at first that the entry in dependency$ for d_obj#: TEST_PKG (OBJECT_ID = 6256611) and p_obj#: TEST_TAB (OBJECT_ID = 6256609) is updated to p_timestamp(Bind#0)="8/25/2026 14:16:41".

=== update dependency$ for d_obj#: TEST_PKG (OBJECT_ID = 6256611) and p_obj#: TEST_TAB (OBJECT_ID = 6256609), set p_timestamp(Bind#0)="8/25/2026 14:16:41"

PARSING IN CURSOR #139943671609592 len=93 dep=1 uid=0 oct=6 lid=0 tim=845811925428 hv=1207594200 ad='979c4718' sqlid='2hztt6j3znv6s'

update dependency$    set p_timestamp = :1, d_attrs = :2    
where
 d_obj# = :3 and p_obj# = :4
 
BINDS #139943671609592:

 Bind#0
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=18 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=989ee68c  bln=08  avl=07  flg=09
  value="8/25/2026 14:16:41"
 Bind#1
  oacdty=23 mxl=32(05) mxlc=00 mal=00 scl=00 pre=00
  oacflg=18 fl2=0001 frm=00 csi=00 siz=32 off=0
  kxsbbbfp=7f472d7aa1d0  bln=32  avl=05  flg=09
  value=00030000
 Bind#2
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=08 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7f472d3a1850  bln=22  avl=05  flg=05
  value=6256611
 Bind#3
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=08 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7f472d3a1820  bln=24  avl=05  flg=05
  value=6256609

Then status of package body: TEST_PKG (OBJECT_ID = 6256611) is updated to status(Bind#5)=1 (VALID):

=== update package body: TEST_PKG (OBJECT_ID = 6256611), set status(Bind#5)=1 (VALID)

PARSING IN CURSOR #139943671609432 len=409 dep=1 uid=0 oct=6 lid=0 tim=845811927174 hv=696165170 ad='9ecdf3e8' sqlid='c3utnxsnrx8tk'

update obj$ set obj#=:4, type#=:5,ctime=:6,mtime=:7,stime=:8,status=:9,
  dataobj#=:10,flags=:11,oid$=:12,spare1=:13,spare2=:14,spare3=:15,signature=
  :16,spare7=:17,spare8=:18,spare9=:19, dflcollid=decode(:20,0,null,:20),
  creappid=:21,creverid=:22, modappid=:23,modverid=:24,crepatchid=:25,
  modpatchid=:26 
where
 owner#=:1 and name=:2 and namespace=:3 and remoteowner is null and linkname 
  is null and subname is null
  
BINDS #139943671609432:

 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=48 off=0
  kxsbbbfp=7f472d709e00  bln=22  avl=05  flg=05
  value=6256611
 Bind#1
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=0 off=24
  kxsbbbfp=7f472d709e18  bln=22  avl=02  flg=01
  value=11
 Bind#2
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=988e02ad  bln=07  avl=07  flg=09
  value="8/25/2026 13:43:24"
 Bind#3
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=988e02b4  bln=07  avl=07  flg=09
  value="8/25/2026 14:12:8"
 Bind#4
  oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=00 csi=00 siz=8 off=0
  kxsbbbfp=988e02bb  bln=07  avl=07  flg=09
  value="8/25/2026 14:12:8"
 Bind#5
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=72 off=0
  kxsbbbfp=7f472d8bb938  bln=22  avl=02  flg=05
  value=1

  ......
  
 Bind#25
  oacdty=01 mxl=32(08) mxlc=00 mal=00 scl=00 pre=00
  oacflg=10 fl2=0001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=988e0096  bln=32  avl=08  flg=09
  value="TEST_PKG"
 Bind#26
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7f472d8bb770  bln=22  avl=02  flg=05
  value=2

We re-run the query, it shows P_Timestamp of Package Body TEST_PKG is SAME as STIME of TEST_TAB, both are "25-AUG-2026 14:16:41". Therefore, Package Body TEST_PKG becomes VALID.

  select do.obj#                                                         d_obj,
         do.name                                                         d_name,
         do.type#                                                        d_type,
         po.obj#                                                         p_obj,
         po.name                                                         p_name,
         to_char (d.p_timestamp, 'DD-MON-YYYY HH24:MI:SS')               "P_Timestamp",
         to_char (po.stime, 'DD-MON-YYYY HH24:MI:SS')                    "STIME",
         decode (sign (po.stime - d.p_timestamp), 0, 'SAME', '*DIFFER*') "CHECK"
    from sys.obj$ do, sys.dependency$ d, sys.obj$ po
   where d.p_obj# = po.obj#(+) and d.d_obj# = do.obj# 
     --and do.status=1 /*dependent is valid*/
     --and po.status=1 /*parent is valid*/
     --and po.stime != d.p_timestamp /*parent timestamp not match*/
      and do.name = 'TEST_PKG'
order by 2, 1;

    D_OBJ D_NAME     D_TYPE      P_OBJ P_NAME     P_Timestamp                   STIME                         CHECK
  ------- ---------- ------ ---------- ---------- ----------------------------- ----------------------------- ----------
  6256610 TEST_PKG        9       1219 STANDARD   16-JUL-2018 00:00:00          16-JUL-2018 00:00:00          SAME
  6256611 TEST_PKG       11       1219 STANDARD   16-JUL-2018 00:00:00          16-JUL-2018 00:00:00          SAME
  6256611 TEST_PKG       11    6256609 TEST_TAB   25-AUG-2026 14:16:41          25-AUG-2026 14:16:41          SAME
  6256611 TEST_PKG       11    6256610 TEST_PKG   25-AUG-2026 13:43:24          25-AUG-2026 13:43:24          SAME

Oracle TX Row Deadlock (ORA-00060) Catch-Retry Endless Loop Test

In this Blog, we will show a Plsql program with TX Row Deadlock Catch-Retry, which will run in endless loop
if not restricted with deadlock counter.

Note: Tested in Oracle 19c

1. Test Setup

First we create a table with 2 rows, and a Plsql code to update them.

drop table test_dl_tab;

create table test_dl_tab as select level id, 0 cnt from dual connect by level <=2; 

select * from  test_dl_tab;

create or replace procedure test_dl_proc(p_id_1 number, p_id_2 number, p_dl_limit number := 100, p_sleep_init number := 10, p_sleep_dl number := 2) as
  e_deadlock_detected exception;
  pragma exception_init(e_deadlock_detected, -60);
  l_start      number := dbms_utility.get_time;
  l_end        number := dbms_utility.get_time;
  l_time_limit number := (p_dl_limit * (3 + p_sleep_dl) + 30);
  l_dl_cnt     number := 0;
begin
  update test_dl_tab set cnt = cnt + 1 where id = p_id_1;
  dbms_session.sleep(p_sleep_init);
  l_start := dbms_utility.get_time;
  l_end   := dbms_utility.get_time;
  while l_dl_cnt < p_dl_limit and (l_end - l_start)/100 < l_time_limit loop
    begin
      update test_dl_tab set cnt = cnt + 1 where id = p_id_2;
      dbms_session.sleep(p_sleep_dl);
    exception when e_deadlock_detected then
      l_dl_cnt := l_dl_cnt + 1;
      dbms_session.sleep(p_sleep_dl);
    end;
    l_end   := dbms_utility.get_time;
  end loop;
  
  -- commit needed
  -- Deadlock is a statement level rollback, locked source still locked. Other session is in TX Wait
  -- Otherwise "log buffer space" in TX waiting session
  commit;   
  dbms_output.put_line('Deadlock Hits = '||l_dl_cnt||' Within (seconds) = '||((l_end - l_start)/100));
end;
/

2. Test Run

Open two Sqlplus windows (SESSION-1 and SESSION-2), in SESSION-1, we update Row 1, then Row 2 with deadlock counter limited by 20. Whereas in SESSION-2, they are updated in reverse order.

-- Start in SESSION-1 
exec test_dl_proc(1, 2, 20);

-- Start in SESSION-2 within 10 seconds of SESSION-1 start
exec test_dl_proc(2, 1, 20);

3. Test Outcome

Here the output from both sessions.

-- SESSION-1 
SQL > exec test_dl_proc(1, 2, 20);
  Deadlock Hits = 20 Within (seconds) = 103.68

-- SESSION-2
SQL > exec test_dl_proc(2, 1, 20);
  Deadlock Hits = 19 Within (seconds) = 131.78

If they are not limited, the test will run in an endless loop.

Oracle 19.32 OJVM ZipFile.getInputStream(ZipEntry entry) empty

This Blogs shows that in 19.32 OJVM, ZipFile.getInputStream(ZipEntry entry) can return empty for some of entries,
whereas in lower version (e.g.19.31), all entries are not empty.

1. Test Code

create or replace java source named s."DocxZipReadTest" as

import java.io.*;
import java.util.zip.*;

public class DocxZipReadTest {

  public static void readZip(String zipInFilePathname) throws IOException {
    ZipInputStream zipInStream   = new ZipInputStream(new FileInputStream(zipInFilePathname));
    System.out.println("zipInFilePathname = " + zipInFilePathname);

    ZipEntry    entry;
    ZipFile     zFile = new ZipFile(zipInFilePathname);
    InputStream inStream;
    int         counter     = 0;

    while ((entry = zipInStream.getNextEntry()) != null) {
      counter++;
      inStream = zFile.getInputStream(entry);   //@TODO can return null, fail

      if (inStream != null) {
        System.out.println(counter + ": === Read Check existed, Name = " + entry.getName() + ", Size() = " + entry.getSize());
        inStream.close();
      } else {
        System.out.println(counter + ": ===>>> Read Check NULL, Name = " + entry.getName() + "  is InputStream Null !!! <<<===");
        //inStream.read(byte[] b) throws NullPointerException
      }
    }
    zipInStream.close();
  }
}
/

create or replace procedure readDocxZipReadTest(p_zipFilePathAndName varchar2) as language java
name 'DocxZipReadTest.readZip(java.lang.String)';
/

2. 19.32 Test Output

Create a MS docx file (Microsoft Word for Microsoft 365 MSO 64-bit): test_create_1.docx, and put it under /tmp directory.

Run following test, the output shows that among 34 entries, 9 are marked with "InputStream Null".
If we read from those entries, Java throws NullPointerException.

SQl > select version_full from v$instance;

  VERSION_FULL
  -----------------
  19.32.0.0.0

SQl > select dbms_java.get_ojvm_property(propstring=>'java.version') java_version from dual;

  JAVA_VERSION
  ---------------
  1.8.0_501

SQl > set serveroutput on size 50000
SQl > exec dbms_java.set_output(50000);

SQl > exec readDocxZipReadTest('/tmp/test_create_1.docx');

  zipInFilePathname = /tmp/test_create_1.docx
    1: ===>>> Read Check NULL, Name = [Content_Types].xml  is InputStream Null !!! <<<===
    2: ===>>> Read Check NULL, Name = _rels/.rels  is InputStream Null !!! <<<===
    3: === Read Check existed, Name = word/document.xml, Size() = 3930
    4: ===>>> Read Check NULL, Name = word/_rels/document.xml.rels  is InputStream Null !!! <<<===
    5: === Read Check existed, Name = word/footnotes.xml, Size() = 3172
    6: === Read Check existed, Name = word/endnotes.xml, Size() = 3166
    7: === Read Check existed, Name = word/header2.xml, Size() = 4479
    8: === Read Check existed, Name = word/footer2.xml, Size() = 5762
    9: === Read Check existed, Name = word/header1.xml, Size() = 4548
    10: === Read Check existed, Name = word/footer1.xml, Size() = 8581
    11: === Read Check existed, Name = word/_rels/header1.xml.rels, Size() = 289
    12: === Read Check existed, Name = word/_rels/header2.xml.rels, Size() = 289
    13: === Read Check existed, Name = word/theme/theme1.xml, Size() = 6735
    14: === Read Check existed, Name = word/media/image1.png, Size() = 35674
    15: === Read Check existed, Name = word/settings.xml, Size() = 5996
    16: === Read Check existed, Name = customXml/item1.xml, Size() = 289
    17: === Read Check existed, Name = customXml/itemProps1.xml, Size() = 341
    18: === Read Check existed, Name = customXml/item2.xml, Size() = 219
    19: === Read Check existed, Name = customXml/itemProps2.xml, Size() = 335
    20: === Read Check existed, Name = customXml/item3.xml, Size() = 17627
    21: === Read Check existed, Name = customXml/itemProps3.xml, Size() = 1277
    22: === Read Check existed, Name = customXml/item4.xml, Size() = 1059
    23: === Read Check existed, Name = customXml/itemProps4.xml, Size() = 675
    24: === Read Check existed, Name = word/numbering.xml, Size() = 52220
    25: === Read Check existed, Name = word/styles.xml, Size() = 56750
    26: === Read Check existed, Name = word/webSettings.xml, Size() = 1069
    27: === Read Check existed, Name = word/fontTable.xml, Size() = 2893
    28: ===>>> Read Check NULL, Name = docProps/core.xml  is InputStream Null !!! <<<===
    29: ===>>> Read Check NULL, Name = docProps/app.xml  is InputStream Null !!! <<<===
    30: === Read Check existed, Name = docMetadata/LabelInfo.xml, Size() = 307
    31: ===>>> Read Check NULL, Name = customXml/_rels/item1.xml.rels  is InputStream Null !!! <<<===
    32: ===>>> Read Check NULL, Name = customXml/_rels/item2.xml.rels  is InputStream Null !!! <<<===
    33: ===>>> Read Check NULL, Name = customXml/_rels/item3.xml.rels  is InputStream Null !!! <<<===
    34: ===>>> Read Check NULL, Name = customXml/_rels/item4.xml.rels  is InputStream Null !!! <<<===

3. 19.31 Test Output

Run the same test on Oracle 19.31, no empty entry can be found.

SQL > select version_full from v$instance;

  VERSION_FULL
  -----------------
  19.31.0.0.0

SQL > select dbms_java.get_ojvm_property(propstring=>'java.version') java_version from dual;

  JAVA_VERSION
  ---------------
  1.8.0_491

SQL > exec readDocxZipReadTest('/tmp/test_create_1.docx');
  zipInFilePathname = /tmp/test_create_1.docx
    1: === Read Check existed, Name = [Content_Types].xml, Size() = 2913
    2: === Read Check existed, Name = _rels/.rels, Size() = 736
    3: === Read Check existed, Name = word/document.xml, Size() = 4082
    4: === Read Check existed, Name = word/_rels/document.xml.rels, Size() = 2301
    5: === Read Check existed, Name = word/footnotes.xml, Size() = 3172
    6: === Read Check existed, Name = word/endnotes.xml, Size() = 3166
    7: === Read Check existed, Name = word/header2.xml, Size() = 4479
    8: === Read Check existed, Name = word/footer2.xml, Size() = 5762
    9: === Read Check existed, Name = word/header1.xml, Size() = 4548
    10: === Read Check existed, Name = word/footer1.xml, Size() = 8581
    11: === Read Check existed, Name = word/_rels/header1.xml.rels, Size() = 289
    12: === Read Check existed, Name = word/_rels/header2.xml.rels, Size() = 289
    13: === Read Check existed, Name = word/theme/theme1.xml, Size() = 6735
    14: === Read Check existed, Name = word/media/image1.png, Size() = 35674
    15: === Read Check existed, Name = word/settings.xml, Size() = 6100
    16: === Read Check existed, Name = customXml/item1.xml, Size() = 289
    17: === Read Check existed, Name = customXml/itemProps1.xml, Size() = 341
    18: === Read Check existed, Name = customXml/item2.xml, Size() = 219
    19: === Read Check existed, Name = customXml/itemProps2.xml, Size() = 335
    20: === Read Check existed, Name = customXml/item3.xml, Size() = 17627
    21: === Read Check existed, Name = customXml/itemProps3.xml, Size() = 1277
    22: === Read Check existed, Name = customXml/item4.xml, Size() = 1059
    23: === Read Check existed, Name = customXml/itemProps4.xml, Size() = 675
    24: === Read Check existed, Name = word/numbering.xml, Size() = 52220
    25: === Read Check existed, Name = word/styles.xml, Size() = 56750
    26: === Read Check existed, Name = word/webSettings.xml, Size() = 1069
    27: === Read Check existed, Name = word/fontTable.xml, Size() = 2893
    28: === Read Check existed, Name = docProps/core.xml, Size() = 741
    29: === Read Check existed, Name = docProps/app.xml, Size() = 711
    30: === Read Check existed, Name = docMetadata/LabelInfo.xml, Size() = 307
    31: === Read Check existed, Name = customXml/_rels/item1.xml.rels, Size() = 296
    32: === Read Check existed, Name = customXml/_rels/item2.xml.rels, Size() = 296
    33: === Read Check existed, Name = customXml/_rels/item3.xml.rels, Size() = 296
    34: === Read Check existed, Name = customXml/_rels/item4.xml.rels, Size() = 296

4. Fix

Here is a 19.32 OJVM fix which uses ZipInputStream.getNextEntry.
(method entryRead is added to verfiy InputStream.read(buffer)).

create or replace java source named s."DocxZipReadTest" as

import java.io.*;
import java.util.zip.*;

public class DocxZipReadTest {

  public static void readZip(String zipInFilePathname) throws IOException {
    ZipInputStream zipInStream   = new ZipInputStream(new FileInputStream(zipInFilePathname));
    System.out.println("zipInFilePathname = " + zipInFilePathname);

    ZipEntry    entry;
    //ZipFile     zFile = new ZipFile(zipInFilePathname);
    InputStream inStream;
    int         counter     = 0;

    while ((entry = zipInStream.getNextEntry()) != null) {
      counter++;
      inStream = (InputStream)zipInStream;   

      if (inStream != null) {
        System.out.println(counter + ": === Read Check existed, Name = " + entry.getName() + ", Size() = " + entry.getSize());
      } else {
        System.out.println(counter + ": ===>>> Read Check NULL, Name = " + entry.getName() + "  is InputStream Null !!! <<<===");
        //inStream.read(byte[] b) throws NullPointerException
      }
      //entryRead(inStream);
    }
    zipInStream.close();
  }

   static void entryRead(InputStream inStream) throws IOException {
    int  num;
    int  writeCount = 0;
    long byteCount  = 0;
    byte[] buffer   = new byte[10000];
    while ((num = inStream.read(buffer)) > 0) {
      writeCount++;
      byteCount  += num;
    }
    System.out.println("------------------- entryRead byteCount = " + byteCount + " by writeCount = " + writeCount);
  }
}

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 in 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

In AWR, we can see the Object 6244876 is marked as "MISSING" and "UNDEFINED":

Segments by Direct Physical Reads

Owner	Tablespace Name	Object Name	Subobject Name	Object Type	Obj#	Dataobj#	Direct Reads	% Total
** MISSING **	TS1	** MISSING: 6244876/6244876 **	** MISSING **	UNDEFINED	6244876	6244876	2,064,000	99.74%

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 shows "PX COORDINATOR".

********************************************************************************
 
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     79.28     487.94    2064058    2111515    5387886        1000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     79.28     487.95    2064058    2111515    5387886        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=2110582 pr=2064056 pw=2064028 time=487838760 us starts=1)
      1000       1000       1000   PX COORDINATOR  (cr=5 pr=0 pw=0 time=39947 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=281000 card=1000)
         0          0          0     PX BLOCK ITERATOR PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us starts=0 cost=2 size=281000 card=1000)
         0          0          0      TABLE ACCESS FULL TEST_TAB PARTITION: 1 1 (cr=0 pr=0 pw=0 time=0 us starts=0 cost=2 size=281000 card=1000)
 
 
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.03
  PX Deq: Execute Reply                          52        0.00          0.00
  direct path read                          2063997        0.18        414.42
  direct path write                            1057        0.06          0.82
  db file sequential read                        58        0.03          0.43
  log file switch (private strand flush incomplete)
                                                  1        0.03          0.03
  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
  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.01          0.01

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

2.2 Basicfile with Chunk 32768

We further create 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 create 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).