Troubleshooting high volume of trace files in 19.29.0
By admin | November 13th, 2025 | Category: 19c | No Comments »After patching a customer environment from 19.28.0 to 19.29.0, it immediately became clear that there is something wrong. A couple of days after the patching, the diagnostic_dest Filesystem was filling up with gigabytes of trace files, containing “Dump of memory” output like this:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 | *** 2025-11-13T20:56:09.238188+01:00 (DEMO(5)) *** SESSION ID:(403.58882) 2025-11-13T20:56:09.238214+01:00 *** CLIENT ID:() 2025-11-13T20:56:09.238217+01:00 *** SERVICE NAME:(demo) 2025-11-13T20:56:09.238220+01:00 *** MODULE NAME:(SQL*Plus) 2025-11-13T20:56:09.238224+01:00 *** ACTION NAME:() 2025-11-13T20:56:09.238227+01:00 *** CLIENT DRIVER:(SQL*PLUS) 2025-11-13T20:56:09.238229+01:00 *** CONTAINER ID:(5) 2025-11-13T20:56:09.238233+01:00 Dump of memory from 0x0000000075F97860 to 0x0000000075F97960 075F97860 00000000 00000000 00000000 00000000 [................] 075F97870 0000000D 00000000 41524150 4554454D [........PARAMETE] 075F97880 54435F52 00000058 00000000 00000000 [R_CTX...........] 075F97890 00000000 00000000 00000000 00000000 [................] Repeat 6 times 075F97900 00000009 00000000 49524156 454C4241 [........VARIABLE] 075F97910 00000031 00000000 00000000 00000000 [1...............] 075F97920 00000000 00000000 00000000 00000000 [................] Repeat 3 times Dump of memory from 0x00000000678C8798 to 0x00000000678C87E8 0678C8790 00656E6F 00000000 [one.....] 0678C87A0 00000000 00000000 00000000 00000000 [................] Repeat 2 times 0678C87D0 00000041 00B38F00 678C8780 00000000 [A..........g....] 0678C87E0 154CEE98 00000000 [..L.....] |
The string “_CTX” was pointing to application contexts which are heavily used by this application. Next step was to enable 10046 trace to get also information about SQL Statements that are causing this. So we found some application PL/SQL calls that were manipulating global contexts, but first we were unable to manually reproduce the issue ourselves in SQL*Plus.
On a DEV environment, I was able to use GDB (gnu debugger) to set a breakpoint to oracle database kernel function that is responsible for writing to diag trace files: ksdwrf. After the breakpoint is set, I execute “c” for continue and when it stops, I execute “bt” for backtrace which gives call stack when ksdwrf is called to print lines to trace file. This is then showing kernel functions kzctx… which again point to application contexts.
gdb -p <PID of oracle server process that is streaming these messages to trace file>
Example:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 | as root: gdb -p 244012 GNU gdb (Red Hat Enterprise Linux) 14.2-4.1.0.1.el9_6 Copyright (C) 2023 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-redhat-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: <https://www.gnu.org/software/gdb/bugs/>. Find the GDB manual and other documentation resources online at: <http://www.gnu.org/software/gdb/documentation/>. For help, type "help". Type "apropos word" to search for commands related to "word". Attaching to process 244012 Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/bin/oracle... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/bin/oracle) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libodm19.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libodm19.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libofs.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libofs.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libcell19.so... Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libskgxp19.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libskgxp19.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libskjcx19.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libskjcx19.so) Reading symbols from /lib64/librt.so.1... Reading symbols from .gnu_debugdata for /lib64/librt.so.1... (No debugging symbols found in .gnu_debugdata for /lib64/librt.so.1) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libclsra19.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libclsra19.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libdbcfg19.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libdbcfg19.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libhasgen19.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libhasgen19.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libskgxn2.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libskgxn2.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libocr19.so... Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libocrb19.so... Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libocrutl19.so... Reading symbols from /lib64/libaio.so.1... Reading symbols from .gnu_debugdata for /lib64/libaio.so.1... (No debugging symbols found in .gnu_debugdata for /lib64/libaio.so.1) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libons.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libons.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libmql1.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libmql1.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libipc1.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libipc1.so) Reading symbols from /lib64/libdl.so.2... Reading symbols from .gnu_debugdata for /lib64/libdl.so.2... (No debugging symbols found in .gnu_debugdata for /lib64/libdl.so.2) Reading symbols from /lib64/libm.so.6... Reading symbols from .gnu_debugdata for /lib64/libm.so.6... (No debugging symbols found in .gnu_debugdata for /lib64/libm.so.6) Reading symbols from /lib64/libpthread.so.0... Reading symbols from .gnu_debugdata for /lib64/libpthread.so.0... (No debugging symbols found in .gnu_debugdata for /lib64/libpthread.so.0) Reading symbols from /lib64/libnsl.so.1... Reading symbols from .gnu_debugdata for /lib64/libnsl.so.1... (No debugging symbols found in .gnu_debugdata for /lib64/libnsl.so.1) Reading symbols from /lib64/libresolv.so.2... Reading symbols from .gnu_debugdata for /lib64/libresolv.so.2... (No debugging symbols found in .gnu_debugdata for /lib64/libresolv.so.2) Reading symbols from /lib64/libc.so.6... (No debugging symbols found in /lib64/libc.so.6) Reading symbols from /lib64/ld-linux-x86-64.so.2... Reading symbols from /usr/lib64/libnuma.so.1... Reading symbols from .gnu_debugdata for /usr/lib64/libnuma.so.1... (No debugging symbols found in .gnu_debugdata for /usr/lib64/libnuma.so.1) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libshpkavx51219.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libshpkavx51219.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/rdbms/lib/odm/libnfsodm19.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/rdbms/lib/odm/libnfsodm19.so) Reading symbols from /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libnque19.so... (No debugging symbols found in /u01/app/oracle/product/19.29.0/dbhome_se2/lib/libnque19.so) [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". 0x00007f25542599ae in semtimedop () from /lib64/libc.so.6 --Type <RET> for more, q to quit, c to continue without paging--c Missing separate debuginfos, use: dnf debuginfo-install glibc-2.34-168.0.1.el9_6.23.x86_64 libaio-0.3.111-13.el9.x86_64 l ibnsl-2.34-168.0.1.el9_6.23.x86_64 numactl-libs-2.0.19-1.el9.x86_64 (gdb) break ksdwrf Breakpoint 1 at 0xe1d570 (gdb) c Continuing. Breakpoint 1, 0x0000000000e1d570 in ksdwrf () (gdb) bt #0 0x0000000000e1d570 in ksdwrf () #1 0x0000000000e1f022 in ksddmp2 () #2 0x000000000c84b32a in kzctxgset () #3 0x000000000c846e47 in kzctxgscv () #4 0x000000000c828f49 in kzctxesc () #5 0x0000000014449dc3 in pevm_icd_call_common () #6 0x0000000014441190 in pfrinstr_ICAL () #7 0x000000001443ffd4 in pfrrun_no_tool () #8 0x000000001443e938 in pfrrun () #9 0x000000001444a710 in plsql_run () #10 0x0000000014438ec7 in peicnt () #11 0x00000000053570ba in kkxexe () #12 0x000000000376ca4d in opiexe () #13 0x000000001412d56d in kpoal8 () #14 0x0000000014104440 in opiodr () #15 0x000000001439a577 in ttcpip () #16 0x000000000374df15 in opitsk () #17 0x0000000003753e27 in opiino () #18 0x0000000014104440 in opiodr () #19 0x0000000003749be6 in opidrv () #20 0x0000000004872215 in sou2o () #21 0x0000000000e0f2a6 in opimai_real () #22 0x000000000487ea71 in ssthrdmain () #23 0x0000000000e0f0d0 in main () (gdb) c Continuing. Breakpoint 1, 0x0000000000e1d570 in ksdwrf () (gdb) bt #0 0x0000000000e1d570 in ksdwrf () #1 0x0000000000e1f022 in ksddmp2 () #2 0x000000000c84e04b in kzctxglhu () #3 0x000000000c84b4d4 in kzctxgset () #4 0x000000000c846e47 in kzctxgscv () #5 0x000000000c828f49 in kzctxesc () #6 0x0000000014449dc3 in pevm_icd_call_common () #7 0x0000000014441190 in pfrinstr_ICAL () #8 0x000000001443ffd4 in pfrrun_no_tool () #9 0x000000001443e938 in pfrrun () #10 0x000000001444a710 in plsql_run () #11 0x0000000014438ec7 in peicnt () #12 0x00000000053570ba in kkxexe () #13 0x000000000376ca4d in opiexe () #14 0x000000001412d56d in kpoal8 () #15 0x0000000014104440 in opiodr () #16 0x000000001439a577 in ttcpip () #17 0x000000000374df15 in opitsk () #18 0x0000000003753e27 in opiino () #19 0x0000000014104440 in opiodr () #20 0x0000000003749be6 in opidrv () #21 0x0000000004872215 in sou2o () #22 0x0000000000e0f2a6 in opimai_real () #23 0x000000000487ea71 in ssthrdmain () #24 0x0000000000e0f0d0 in main () (gdb) c Continuing. |
So, now we had the call stack of the point in time when the write to the trace file was triggered. Maybe we can even get line numbers of these functions when executing “oradebug short_stack” while in breakpoint? So, after giving “c” (continue) and when the code again jumped to “Breakpoint 1, 0x0000000000e1d570 in ksdwrf ()”, in a new terminal, I executed
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 | sqlplus / as sysdba alter session set container = ...; oradebug setospid 244012 oradebug short_stack sedsts()+426 <-ksdxfstk()+63 <-ksdxcb()+872 <-sspuser()+243 <-__sighandler() <-ksdwrf() <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< call to function to write to trace <-ksddmp2()+66 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< call to Dump function <-kzctxglhu()+1403 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< global context function <-kzctxgset()+6580 <-kzctxgscv()+2263 <-kzctxesc()+9561 <-pevm_icd_call_common()+835 <-pfrinstr_ICAL()+128 <-pfrrun_no_tool()+52 <-pfrrun()+904 <-plsql_run()+752 <-peicnt()+279 <-kkxexe()+1178 <-opiexe()+18973 <-kpoal8()+2301 <-opiodr()+1264 <-ttcpip()+1255 <-opitsk()+1925 <-opiino()+935 <-opiodr()+1264 <-opidrv()+1094 <-sou2o()+165 <-opimai_real()+422 <-ssthrdmain()+417 <-main()+256 <-__libc_start_call_main()+128 |
So, obviously the Oracle developer of functions kzctx* introduced some debug output of memory regions into trace files and forgot to remove this debug code in 19.29.0. Unfortunately, even with exact line numbers, it is still difficult to convince the first level support engineers that this is a problem. In order to receive a bugfix, we need to provide a reproducible testcase. After a while, I was successful with the following code:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 | CREATE OR REPLACE CONTEXT parameter_ctx USING context_api accessed globally; CREATE OR REPLACE PACKAGE context_api AS PROCEDURE set_parameter(p_name IN VARCHAR2, p_value IN VARCHAR2); PROCEDURE clear_context (p_name IN VARCHAR2); PROCEDURE clear_all_context; END context_api; / CREATE OR REPLACE PACKAGE BODY context_api IS PROCEDURE set_parameter (p_name IN VARCHAR2, p_value IN VARCHAR2) IS BEGIN sys.DBMS_SESSION.set_context('parameter_ctx', p_name, p_value); END set_parameter; PROCEDURE clear_context (p_name IN VARCHAR2) IS BEGIN sys.DBMS_SESSION.clear_context('parameter_ctx', attribute => p_name); END clear_context; PROCEDURE clear_all_context IS BEGIN sys.DBMS_SESSION.clear_all_context('parameter_ctx'); END clear_all_context; END context_api; / EXEC context_api.set_parameter('variable1', 'one'); |
Beginning in 19.29.0, the call to context_api.set_parameter, which in turn executes DBMS_SESSION.SET_CONTEXT, creates a trace file with these lines:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 | *** 2025-11-13T20:56:09.238188+01:00 (DEMO(5)) *** SESSION ID:(403.58882) 2025-11-13T20:56:09.238214+01:00 *** CLIENT ID:() 2025-11-13T20:56:09.238217+01:00 *** SERVICE NAME:(demo) 2025-11-13T20:56:09.238220+01:00 *** MODULE NAME:(SQL*Plus) 2025-11-13T20:56:09.238224+01:00 *** ACTION NAME:() 2025-11-13T20:56:09.238227+01:00 *** CLIENT DRIVER:(SQL*PLUS) 2025-11-13T20:56:09.238229+01:00 *** CONTAINER ID:(5) 2025-11-13T20:56:09.238233+01:00 Dump of memory from 0x0000000075F97860 to 0x0000000075F97960 075F97860 00000000 00000000 00000000 00000000 [................] 075F97870 0000000D 00000000 41524150 4554454D [........PARAMETE] 075F97880 54435F52 00000058 00000000 00000000 [R_CTX...........] 075F97890 00000000 00000000 00000000 00000000 [................] Repeat 6 times 075F97900 00000009 00000000 49524156 454C4241 [........VARIABLE] 075F97910 00000031 00000000 00000000 00000000 [1...............] 075F97920 00000000 00000000 00000000 00000000 [................] Repeat 3 times Dump of memory from 0x00000000678C8798 to 0x00000000678C87E8 0678C8790 00656E6F 00000000 [one.....] 0678C87A0 00000000 00000000 00000000 00000000 [................] Repeat 2 times 0678C87D0 00000041 00B38F00 678C8780 00000000 [A..........g....] 0678C87E0 154CEE98 00000000 [..L.....] */ |
And if this code is executed millions of times, you end up with gigabytes of trace data in a couple of days. Now, I hope that Oracle Support will open a bug for this and that we get a fix soon. In the meantime, we have to delete tons of trace files every day.
Update 17.11.2025:
Oracle has finally opened a bug for this:
Bug 38658309 – HUGE TRACE FILES WITH “DUMP OF MEMORY” AFTER UPGRADING FROM 19.28.0 TO 19.29 ||APPLICATION CONTEXT
