Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250915220005\orcl_j003_24308_bucket.trc Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options Windows NT Version V6.2 CPU : 32 - type 8664, 16 Physical Cores Process Affinity : 0x0x0000000000000000 Memory (Avail/Total): Ph:34716M/63366M, Ph+PgF:39306M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 24308, image: ORACLE.EXE (J003) *** 2025-09-15 22:00:05.239 *** SESSION ID:(233.35511) 2025-09-15 22:00:05.239 *** 2025-09-15 22:00:05.239 Process diagnostic dump for ORACLE.EXE (J003), OS id=24308, pid: 29, proc_ser: 83, sid: 233, sess_ser: 35511 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 24308 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_13090, hash value=2083831301 Current Wait Stack: Not in wait; last wait ended 2.817331 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.817357 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000186 sec, exc=0.000186 sec, total=0.000186 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.068414 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000009 sec, exc=0.000009 sec, total=0.000009 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.876540 sec of elapsed time 2: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.000004 sec, exc=0.000004 sec, total=0.000004 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.025156 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=37 seq_num=38 snap_id=1 wait times: snap=0.000003 sec, exc=0.000003 sec, total=0.000003 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.013013 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000071 sec, exc=0.000071 sec, total=0.000071 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049990 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.007258 sec, exc=0.007258 sec, total=0.007258 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007822 sec of elapsed time 6: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.000065 sec, exc=0.000065 sec, total=0.000065 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.262004 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.002577 sec, exc=0.002577 sec, total=0.002577 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000170 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.000119 sec, exc=0.000119 sec, total=0.000119 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007980 sec of elapsed time 9: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=31 seq_num=32 snap_id=1 wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.000054 sec of elapsed time Sampled Session History of session 233 serial 35511 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [5 samples, 22:00:01 - 22:00:05] not in wait at each sample [1 sample, 22:00:00] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-15 22:00:05.239 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 24308, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-15 01:28:21.619627 :CD899923:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:28:21.619879 :CD899924:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:28:21.619894 :CD899925:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:28:21.620106 :CD899926:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:28:21.620119 :CD899927:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:28:21.620328 :CD899928:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:28:21.620339 :CD899929:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:28:21.620545 :CD89992A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:28:21.620557 :CD89992B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:28:21.620762 :CD89992C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:28:21.620775 :CD89992D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:28:21.623315 :CD89992E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-15 01:58:25.573687 :CD8BF3BF:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-15 01:58:25.561 2025-09-15 01:58:25.573689 :CD8BF3C0:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24688 pso_num=29 pso_serial#=77 2025-09-15 01:58:25.573827 :CD8BF3C1:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24688 osp_idx=27 osp_ver=17671 osp_pg=0 (spawn #593066) 2025-09-15 01:58:25.573828 :CD8BF3C2:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-15 01:58:25.573828 :CD8BF3C3:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=72 time=2287156877 2025-09-15 01:58:25.573828 :CD8BF3C4:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-15 01:58:25.573828 :CD8BF3C5:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-15 01:58:25.573829 :CD8BF3C6:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-15 01:58:25.573829 :CD8BF3C7:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-15 01:58:25.573829 :CD8BF3C8:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-15 01:58:25.574344 :CD8BF3C9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-15 01:58:25.574388 :CD8BF3CF:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-15 01:58:25.578488 :CD8BF3E8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:58:25.578533 :CD8BF3E9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:58:25.578796 :CD8BF3EA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:58:25.578813 :CD8BF3EB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:58:25.579040 :CD8BF3EC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:58:25.579054 :CD8BF3ED:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:58:25.579266 :CD8BF3EE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:58:25.579279 :CD8BF3EF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:58:25.579489 :CD8BF3F0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:58:25.579501 :CD8BF3F1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:58:25.579704 :CD8BF3F2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 01:58:25.579717 :CD8BF3F3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 01:58:25.582338 :CD8BF3F4:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-15 08:25:11.349907 :CDAAA271:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-15 08:25:11.343 2025-09-15 08:25:11.349909 :CDAAA272:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24240 pso_num=29 pso_serial#=78 2025-09-15 08:25:11.350107 :CDAAA273:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24240 osp_idx=27 osp_ver=17672 osp_pg=0 (spawn #593961) 2025-09-15 08:25:11.350108 :CDAAA274:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-15 08:25:11.350108 :CDAAA275:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=73 time=2310362643 2025-09-15 08:25:11.350108 :CDAAA276:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-15 08:25:11.350109 :CDAAA277:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-15 08:25:11.350109 :CDAAA278:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-15 08:25:11.350109 :CDAAA279:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-15 08:25:11.350110 :CDAAA27A:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-15 08:25:11.352933 :CDAAA27B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-15 08:25:11.352980 :CDAAA281:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-15 08:25:11.353378 :CDAAA282:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-15 08:25:13.563352 :CDAAA3B4:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-15 08:25:13.556 2025-09-15 08:25:13.563353 :CDAAA3B5:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=19808 pso_num=29 pso_serial#=79 2025-09-15 08:25:13.563496 :CDAAA3B6:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=19808 osp_idx=27 osp_ver=17673 osp_pg=0 (spawn #593963) 2025-09-15 08:25:13.563497 :CDAAA3B7:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-15 08:25:13.563497 :CDAAA3B8:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=74 time=2310364862 2025-09-15 08:25:13.563498 :CDAAA3B9:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-15 08:25:13.563498 :CDAAA3BA:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-15 08:25:13.563498 :CDAAA3BB:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-15 08:25:13.563499 :CDAAA3BC:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-15 08:25:13.563499 :CDAAA3BD:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-15 08:25:13.564056 :CDAAA3BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-15 08:25:13.564093 :CDAAA3C4:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-15 08:25:13.564449 :CDAAA3C5:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-15 08:25:14.133097 :CDAAA8FE:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-15 08:25:14.119 2025-09-15 08:25:14.133099 :CDAAA8FF:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24532 pso_num=29 pso_serial#=80 2025-09-15 08:25:14.133294 :CDAAA900:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=24532 (legacy spawn) 2025-09-15 08:25:14.139647 :CDAAA901:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 08:25:14.139676 :CDAAA904:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 08:25:14.140026 :CDAAA90C:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-09-15 08:25:14.140878 :CDAAA918:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-15 08:25:14.149590 :CDAAA91B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-15 08:25:14.134 2025-09-15 08:25:14.149592 :CDAAA91C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24768 pso_num=29 pso_serial#=81 2025-09-15 08:25:14.149773 :CDAAA91D:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=24768 (legacy spawn) 2025-09-15 08:25:14.156214 :CDAAA920:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 08:25:14.156513 :CDAAA92A:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-09-15 08:25:14.157358 :CDAAA92C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-15 16:00:16.979950 :CDCE9D76:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-15 16:00:16.967 2025-09-15 16:00:16.979953 :CDCE9D77:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24856 pso_num=29 pso_serial#=82 2025-09-15 16:00:16.980091 :CDCE9D78:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24856 osp_idx=27 osp_ver=17676 osp_pg=0 (spawn #595013) 2025-09-15 16:00:16.980092 :CDCE9D79:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-15 16:00:16.980092 :CDCE9D7A:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=75 time=2337668283 2025-09-15 16:00:16.980092 :CDCE9D7B:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-15 16:00:16.980093 :CDCE9D7C:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-15 16:00:16.980093 :CDCE9D7D:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-15 16:00:16.980093 :CDCE9D7E:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-15 16:00:16.980094 :CDCE9D7F:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-15 16:00:16.980608 :CDCE9D80:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-15 16:00:16.980649 :CDCE9D86:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-15 16:00:16.984753 :CDCE9DC1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 16:00:16.984803 :CDCE9DC2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 16:00:16.985055 :CDCE9DC3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 16:00:16.985073 :CDCE9DC4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 16:00:16.985291 :CDCE9DC5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 16:00:16.985304 :CDCE9DC6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 16:00:16.985523 :CDCE9DC7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 16:00:16.985535 :CDCE9DC8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 16:00:16.985748 :CDCE9DCB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 16:00:16.985761 :CDCE9DCC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 16:00:16.985979 :CDCE9DD5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-15 16:00:16.986001 :CDCE9DD6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-15 16:00:16.988630 :CDCE9DF3:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-15 22:00:00.507965 :CDEB251C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-15 22:00:00.500 2025-09-15 22:00:00.507966 :CDEB251D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24308 pso_num=29 pso_serial#=83 2025-09-15 22:00:00.508090 :CDEB2523:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24308 osp_idx=27 osp_ver=17677 osp_pg=0 (spawn #595847) 2025-09-15 22:00:00.508090 :CDEB2524:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-15 22:00:00.508091 :CDEB2525:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=76 time=2359251815 2025-09-15 22:00:00.508091 :CDEB2526:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-15 22:00:00.508092 :CDEB2527:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-15 22:00:00.508092 :CDEB2528:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-15 22:00:00.508092 :CDEB2529:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-15 22:00:00.508093 :CDEB252A:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-15 22:00:00.508589 :CDEB252B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.513619 :CDEB254A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.513664 :CDEB254D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-09-15 22:00:00.531392 :CDEB2717:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.531731 :CDEB271F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.531875 :CDEB272A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.531900 :CDEB272E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.532100 :CDEB2747:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.532360 :CDEB274F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.532523 :CDEB2757:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.532682 :CDEB275F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.532858 :CDEB2767:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.533028 :CDEB276F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.533181 :CDEB2777:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.533337 :CDEB277F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.533492 :CDEB2787:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.533651 :CDEB278F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.533811 :CDEB2797:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.533977 :CDEB279F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.534202 :CDEB27A7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.534376 :CDEB27AF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.534526 :CDEB27B7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.534677 :CDEB27BF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.535074 :CDEB27C7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.535248 :CDEB27CF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.535397 :CDEB27D7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.535666 :CDEB27DF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.535911 :CDEB27E7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.536155 :CDEB27EF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.536848 :CDEB27F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:00.563045 :CDEB280A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:01.094489 :CDEB287E:db_trace:ksl2.c@2477:kslwtbctx(): [10005:29:233] KSL WAIT BEG [latch: cache buffers chains] 33766663296/0x7dca66480 150/0x96 0/0x0 wait_id=29 seq_num=30 snap_id=1 2025-09-15 22:00:01.094524 :CDEB287F:db_trace:ksl2.c@2611:kslwtectx(): [10005:29:233] KSL WAIT END [latch: cache buffers chains] 33766663296/0x7dca66480 150/0x96 0/0x0 wait_id=29 seq_num=30 snap_id=1 2025-09-15 22:00:01.094525 :CDEB2880:db_trace:ksl2.c@2619:kslwtectx(): [10005:29:233] KSL WAIT END wait times (usecs) - snap=35, exc=35, tot=35 2025-09-15 22:00:01.609550*:CDEB29C1:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000030183AD0 estart=1757944801 eid=22450333 ctx=0x0000000777968158 cwh=0x000000002B460AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-09-15 22:00:01.609550*:CDEB29C2:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000030183AD0 curCtx=0x000000006032C4B8 pubTabIdxCnt=0 2025-09-15 22:00:01.609550*:CDEB29C3:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000030183AD0 2025-09-15 22:00:01.609550*:CDEB29C6:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000030183AD0 2025-09-15 22:00:01.609550*:CDEB29C7:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000301BAAF8 estart=1757944800 eid=16777591 ctx=0x000000077B54EAC8 cwh=0x000000002B460608 cpu=843750 buffg=49102 interb=196608 r=24 rb=196608 w=0 wb=0 2025-09-15 22:00:01.609550*:CDEB29C9:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000301BAAF8 curCtx=0x0000000060141240 pubTabIdxCnt=0 2025-09-15 22:00:01.609550*:CDEB29CA:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000301BAAF8 2025-09-15 22:00:01.609550*:CDEB29CB:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000301BAAF8 2025-09-15 22:00:01.609550*:CDEB29CF:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000030183AD0 curCtx=0x000000006032C4B8 xsc->flg4=65792 flags=1 2025-09-15 22:00:01.609550*:CDEB29D0:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000030183AD0 2025-09-15 22:00:02.328322*:CDEB2B2F:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000301BAAF8 curCtx=0x0000000060141240 xsc->flg4=65792 flags=2 2025-09-15 22:00:02.328322*:CDEB2B30:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000301BAAF8 2025-09-15 22:00:02.340316 :CDEB2B31:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:02.364124 :CDEB2B4A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:02.366482 :CDEB2B52:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-09-15 22:00:02.366738 :CDEB2B53:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-09-15 22:00:02.367816 :CDEB2B54:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:02.367936 :CDEB2B57:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:02.369005 :CDEB2B72:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:02.371000 :CDEB2B7A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:02.371405 :CDEB2B82:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:02.437703*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-09-15 22:00:02.437703*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-09-15 22:00:02.437703*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-09-15 22:00:02.437703*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-09-15 22:00:02.437703*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-09-15 22:00:02.437703*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-09-15 22:00:02.437703*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-09-15 22:00:02.528652 :CDEB2C01:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:04.426989 :CDEB2DB5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-15 22:00:04.427001 :CDEB2DB6:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0009.000.0001df29 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 24308, J003)