-
October 2026 (4)
-
July 2026 (1)
-
June 2026 (2)
-
April 2026 (1)
-
January 2026 (4)
-
December 2025 (1)
-
September 2025 (3)
-
August 2025 (1)
-
July 2025 (3)
-
June 2025 (1)
-
May 2025 (1)
-
February 2025 (1)
-
November 2024 (1)
-
October 2024 (1)
-
September 2024 (1)
-
April 2024 (3)
-
January 2024 (1)
-
October 2023 (1)
-
September 2023 (3)
-
August 2023 (1)
-
June 2023 (1)
-
April 2023 (3)
-
March 2023 (2)
-
February 2023 (1)
-
January 2023 (1)
-
December 2022 (2)
-
October 2022 (2)
-
September 2022 (2)
-
August 2022 (2)
-
July 2022 (1)
-
June 2022 (1)
-
May 2022 (2)
-
April 2022 (2)
-
March 2022 (1)
-
February 2022 (2)
-
January 2022 (1)
-
December 2021 (1)
-
November 2021 (1)
-
October 2021 (2)
-
July 2021 (1)
-
June 2021 (1)
-
May 2021 (1)
-
April 2021 (3)
-
March 2021 (2)
-
January 2021 (1)
-
November 2020 (3)
-
September 2020 (1)
-
August 2020 (1)
-
May 2020 (3)
-
April 2020 (3)
-
February 2020 (2)
-
January 2020 (1)
-
December 2019 (2)
-
August 2019 (2)
-
April 2019 (1)
-
November 2018 (5)
- Oracle row cache objects Event: 10222, Dtrace Script (I)
- Row Cache Objects, Row Cache Latch on Object Type: Plsql vs Java Call (Part-1) (II)
- Row Cache Objects, Row Cache Latch on Object Type: Plsql vs Java Call (Part-2) (III)
- Row Cache and Sql Executions (IV)
- Latch: row cache objects Contentions and Scalability (V)
-
October 2018 (2)
-
July 2018 (3)
-
April 2018 (1)
-
March 2018 (2)
-
February 2018 (1)
-
January 2018 (4)
-
October 2017 (2)
-
September 2017 (2)
-
July 2017 (3)
-
May 2017 (8)
- JDBC, Oracle object/collection, dbms_pickler, NOPARALLEL sys.type$ query
- PLSQL Context Switch Functions and Cost
- Oracle Datetime (1) - Concepts
- Oracle Datetime (2) - Examples
- Oracle Datetime (3) - Assignments
- Oracle Datetime (4) - Comparisons
- Oracle Datetime (5) - SQL Arithmetic
- Oracle Datetime (6) - PLSQL Arithmetic
-
March 2017 (3)
-
February 2017 (1)
-
January 2017 (1)
-
November 2016 (1)
-
September 2016 (2)
-
August 2016 (1)
-
June 2016 (1)
-
May 2016 (1)
-
April 2016 (1)
-
February 2016 (1)
-
January 2016 (3)
-
December 2015 (1)
-
November 2015 (1)
-
September 2015 (2)
-
August 2015 (1)
-
July 2015 (2)
-
June 2015 (1)
-
April 2015 (2)
-
January 2015 (1)
-
December 2014 (1)
-
November 2014 (2)
-
May 2014 (3)
-
March 2014 (2)
-
November 2013 (3)
-
September 2013 (1)
-
June 2013 (2)
-
April 2013 (2)
-
March 2013 (3)
-
December 2012 (1)
-
November 2012 (2)
-
July 2012 (1)
-
May 2012 (1)
-
April 2012 (1)
-
February 2012 (1)
-
November 2011 (2)
-
July 2011 (1)
-
May 2011 (3)
-
April 2011 (1)
Thursday, October 8, 2026
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:
Open one UNIX window, and two Sqlplus sessions (SID-1 and SID-2).
On UNIX Window, find ckpt process and its associated control files,
set GDB breakpoint when pread64 on them.
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".
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":
After 900 seconds, alert.log shows:
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.
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
At first, we create one table and one Plsql package using it.
We query dba_dependencies to list the dependencies:
We modify the table again with SQL Trace level 12 (contains bind variables):
In fact, Oracle has one query to reveal such difference.
(sys.dependency$ contains column p_timestamp, which is not exposed in dba_dependencies).
We use SQL trace again to track how Oracle makes Package Body Valid when package programs are invoked:
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
First we create a table with 2 rows, and a Plsql code to update them.
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.
Here the output from both sessions.
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.
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.
Run the same test on Oracle 19.31, no empty entry can be found.
Here is a 19.32 OJVM fix which uses ZipInputStream.getNextEntry.
(method entryRead is added to verfiy InputStream.read(buffer)).
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);
}
}
Subscribe to:
Posts (Atom)