Thursday, October 8, 2026

Blog List

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);
  }
}