Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250912220005\orcl_j003_24320_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:34824M/63366M, Ph+PgF:39475M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 24320, image: ORACLE.EXE (J003) *** 2025-09-12 22:00:05.378 *** SESSION ID:(233.35067) 2025-09-12 22:00:05.378 *** 2025-09-12 22:00:05.378 Process diagnostic dump for ORACLE.EXE (J003), OS id=24320, pid: 29, proc_ser: 116, sid: 233, sess_ser: 35067 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 24320 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_13065, hash value=2270308170 Current Wait Stack: Not in wait; last wait ended 2.482226 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.482251 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000174 sec, exc=0.000174 sec, total=0.000174 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.063340 sec of elapsed time 1: 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.000005 sec, exc=0.000005 sec, total=0.000005 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.751242 sec of elapsed time 2: 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.000008 sec, exc=0.000008 sec, total=0.000008 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.025983 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=36 seq_num=37 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.013166 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=35 seq_num=36 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.053907 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.007061 sec, exc=0.007061 sec, total=0.007061 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007959 sec of elapsed time 6: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=33 seq_num=34 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.262802 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.004230 sec, exc=0.004230 sec, total=0.004230 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000168 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=31 seq_num=32 snap_id=1 wait times: snap=0.000117 sec, exc=0.000117 sec, total=0.000117 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.008062 sec of elapsed time 9: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=30 seq_num=31 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.000061 sec of elapsed time Sampled Session History of session 233 serial 35067 --------------------------------------------------- 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:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-12 22:00:05.378 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 24320, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-12 00:06:12.317333 :CC2E37E5:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=24992 (legacy spawn) 2025-09-12 00:06:12.323908 :CC2E37E6: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-12 00:06:12.324075 :CC2E37EF: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-12 00:06:12.324860 :CC2E37F0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 00:19:17.487230 :CC2F3A7E:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 00:19:17.474 2025-09-12 00:19:17.487233 :CC2F3A7F:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=23640 pso_num=29 pso_serial#=108 2025-09-12 00:19:17.487383 :CC2F3A80:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=23640 osp_idx=27 osp_ver=17447 osp_pg=0 (spawn #582828) 2025-09-12 00:19:17.487384 :CC2F3A81: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-12 00:19:17.487385 :CC2F3A82:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=242 time=2022008783 2025-09-12 00:19:17.487385 :CC2F3A83:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-12 00:19:17.487385 :CC2F3A84:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-12 00:19:17.487386 :CC2F3A85:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-12 00:19:17.487386 :CC2F3A86:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-12 00:19:17.487386 :CC2F3A87:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-12 00:19:17.487939 :CC2F3A88: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-12 00:19:17.487980 :CC2F3A8E: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-12 00:19:17.492279 :CC2F3AA7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-12 00:19:17.492325 :CC2F3AA8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-12 00:19:17.492581 :CC2F3AA9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-12 00:19:17.492596 :CC2F3AAA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-12 00:19:17.492810 :CC2F3AAB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-12 00:19:17.492822 :CC2F3AAC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-12 00:19:17.493045 :CC2F3AAD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-12 00:19:17.493066 :CC2F3AAE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-12 00:19:17.493341 :CC2F3AAF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-12 00:19:17.493354 :CC2F3AB0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-12 00:19:17.493569 :CC2F3AB1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-12 00:19:17.493582 :CC2F3AB2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-12 00:19:17.496088 :CC2F3AB3:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 01:00:07.487758 :CC3258FD:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 01:00:07.479 2025-09-12 01:00:07.487761 :CC3258FE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=25108 pso_num=29 pso_serial#=109 2025-09-12 01:00:07.487899 :CC3258FF:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=25108 (legacy spawn) 2025-09-12 01:00:07.494354 :CC325900: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-12 01:00:07.494528 :CC325909: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-12 01:00:07.495344 :CC32590A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 01:00:07.504176 :CC32590D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 01:00:07.495 2025-09-12 01:00:07.504178 :CC32590E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7692 pso_num=29 pso_serial#=110 2025-09-12 01:00:07.504324 :CC32590F:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=7692 (legacy spawn) 2025-09-12 01:00:07.510861 :CC325910: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-12 01:00:07.511034 :CC325918: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-12 01:00:07.511845 :CC325919:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 01:00:10.768977 :CC3259F4:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 01:00:10.755 2025-09-12 01:00:10.768983 :CC3259F5:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24372 pso_num=29 pso_serial#=111 2025-09-12 01:00:10.769130 :CC3259F6:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=24372 (legacy spawn) 2025-09-12 01:00:10.775884 :CC325A04: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-12 01:00:10.776056 :CC325A09: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-12 01:00:10.776880 :CC325A0E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 01:00:10.785896 :CC325A11:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 01:00:10.771 2025-09-12 01:00:10.785898 :CC325A12:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=21932 pso_num=29 pso_serial#=112 2025-09-12 01:00:10.786037 :CC325A13:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=21932 (legacy spawn) 2025-09-12 01:00:10.792883 :CC325A14: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-12 01:00:10.793092 :CC325A1B: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-12 01:00:10.794006 :CC325A1E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 01:00:22.139264 :CC325D66:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 01:00:22.134 2025-09-12 01:00:22.139265 :CC325D67:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=25140 pso_num=29 pso_serial#=113 2025-09-12 01:00:22.139404 :CC325D68:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=25140 osp_idx=27 osp_ver=17452 osp_pg=0 (spawn #582922) 2025-09-12 01:00:22.139405 :CC325D69: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-12 01:00:22.139405 :CC325D6A:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=243 time=2024473440 2025-09-12 01:00:22.139406 :CC325D6B:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-12 01:00:22.139406 :CC325D6C:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-12 01:00:22.139406 :CC325D6D:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-12 01:00:22.139407 :CC325D6E:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-12 01:00:22.139407 :CC325D6F:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-12 01:00:22.139898 :CC325D70: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-12 01:00:22.139945 :CC325D76: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-12 01:00:22.144381 :CC325D89: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-12 01:00:22.170714 :CC325D91:db_trace:ksb.c@6610:ksbcic_int(): [10254:29:233] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 4286507122 8460176) 2025-09-12 01:00:22.170721 :CC325D92:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-12 01:00:22.170775 :CC325D9A:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-12 01:00:22.170815 :CC325DAA: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-12 01:00:22.186730 :CC325DB2: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-12 01:00:22.219688 :CC325DBA: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-12 01:00:22.223365 :CC325DC2: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-12 01:00:22.227053 :CC325DCA: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-12 01:00:22.231443 :CC325DD2: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-12 01:00:22.232637 :CC325DDA: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-12 01:00:23.459886 :CC325E71: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-12 01:00:23.508128 :CC325E79: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-12 01:00:23.508433 :CC325E81: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-12 01:00:23.508704 :CC325E89: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-12 01:00:23.508719 :CC325E8C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-12 01:00:23.508782 :CC325E9A: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-12 01:00:23.511609 :CC325EA6:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 01:00:25.182358 :CC325F70:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 01:00:25.170 2025-09-12 01:00:25.182360 :CC325F71:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24904 pso_num=29 pso_serial#=114 2025-09-12 01:00:25.182501 :CC325F72:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=24904 (legacy spawn) 2025-09-12 01:00:25.189369 :CC325F73: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-12 01:00:25.189559 :CC325F78: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-12 01:00:25.190491 :CC325F7D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 16:00:10.844353 :CC787490:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 16:00:10.839 2025-09-12 16:00:10.844356 :CC787491:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=23380 pso_num=29 pso_serial#=115 2025-09-12 16:00:10.844488 :CC787492:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=23380 osp_idx=27 osp_ver=17454 osp_pg=0 (spawn #585003) 2025-09-12 16:00:10.844488 :CC787493: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-12 16:00:10.844489 :CC787494:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=244 time=2078462127 2025-09-12 16:00:10.844489 :CC787495:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-12 16:00:10.844489 :CC787496:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-12 16:00:10.844490 :CC787497:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-12 16:00:10.844490 :CC787498:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-12 16:00:10.844490 :CC787499:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-12 16:00:10.844993 :CC78749A: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-12 16:00:10.845037 :CC7874A0: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-12 16:00:10.852865 :CC7874AE: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-12 16:00:10.853934 :CC7874B6: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-12 16:00:10.854479 :CC7874BE: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-12 16:00:10.855054 :CC7874C6: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-12 16:00:10.855501 :CC7874CE: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-12 16:00:10.857957 :CC7874D6: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-12 16:00:10.859080 :CC7874DE: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-12 16:00:10.910279 :CC7874E6: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-12 16:00:10.911194 :CC7874EE: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-12 16:00:10.911424 :CC7874F6: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-12 16:00:10.911637 :CC7874FE: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-12 16:00:10.913442 :CC787506:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-12 22:00:01.098698 :CC949FB4:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-12 22:00:01.087 2025-09-12 22:00:01.098699 :CC949FB5:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24320 pso_num=29 pso_serial#=116 2025-09-12 22:00:01.098833 :CC949FB6:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24320 osp_idx=27 osp_ver=17455 osp_pg=0 (spawn #585833) 2025-09-12 22:00:01.098834 :CC949FB7: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-12 22:00:01.098834 :CC949FB8:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=245 time=2100052393 2025-09-12 22:00:01.098835 :CC949FB9:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-12 22:00:01.098835 :CC949FBA:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-12 22:00:01.098836 :CC949FBB:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-12 22:00:01.098836 :CC949FBC:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-12 22:00:01.098837 :CC949FBD:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-12 22:00:01.099328 :CC949FBE: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-12 22:00:01.104244 :CC949FD3: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-12 22:00:01.104280 :CC949FD6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-09-12 22:00:01.122229 :CC94A1EB: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-12 22:00:01.122413 :CC94A1F3: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-12 22:00:01.122585 :CC94A1FB: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-12 22:00:01.122730 :CC94A20F: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-12 22:00:01.122754 :CC94A211: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-12 22:00:01.122910 :CC94A225: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-12 22:00:01.123079 :CC94A22D: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-12 22:00:01.123250 :CC94A235: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-12 22:00:01.123403 :CC94A23D: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-12 22:00:01.123553 :CC94A245: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-12 22:00:01.123711 :CC94A24D: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-12 22:00:01.123871 :CC94A255: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-12 22:00:01.124022 :CC94A25D: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-12 22:00:01.124171 :CC94A265: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-12 22:00:01.124400 :CC94A26D: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-12 22:00:01.124576 :CC94A275: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-12 22:00:01.124726 :CC94A27D: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-12 22:00:01.124886 :CC94A285: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-12 22:00:01.125249 :CC94A28D: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-12 22:00:01.125431 :CC94A295: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-12 22:00:01.125587 :CC94A29D: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-12 22:00:01.125960 :CC94A2A5: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-12 22:00:01.126237 :CC94A2AD: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-12 22:00:01.126496 :CC94A2B5: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-12 22:00:01.127133 :CC94A2BD: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-12 22:00:01.153940 :CC94A2C5: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-12 22:00:02.274436*:CC94A4F4:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000318F3AD0 estart=1757685602 eid=22285053 ctx=0x0000000777968158 cwh=0x000000002B460AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-09-12 22:00:02.274436*:CC94A4F5:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000318F3AD0 curCtx=0x000000005F35C4B8 pubTabIdxCnt=0 2025-09-12 22:00:02.274436*:CC94A4F6:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000318F3AD0 2025-09-12 22:00:02.274436*:CC94A4F7:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000318F3AD0 2025-09-12 22:00:02.274436*:CC94A4F8:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000003192AAF8 estart=1757685601 eid=16777580 ctx=0x000000077B54EAC8 cwh=0x000000002B460608 cpu=953125 buffg=52093 interb=196608 r=24 rb=196608 w=0 wb=0 2025-09-12 22:00:02.274436*:CC94A4F9:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000003192AAF8 curCtx=0x000000005F171240 pubTabIdxCnt=0 2025-09-12 22:00:02.274436*:CC94A4FA:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000003192AAF8 2025-09-12 22:00:02.274436*:CC94A4FB:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000003192AAF8 2025-09-12 22:00:02.274436*:CC94A4FC:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000318F3AD0 curCtx=0x000000005F35C4B8 xsc->flg4=65792 flags=1 2025-09-12 22:00:02.274436*:CC94A4FD:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000318F3AD0 2025-09-12 22:00:02.815800*:CC94A588:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000003192AAF8 curCtx=0x000000005F171240 xsc->flg4=65792 flags=2 2025-09-12 22:00:02.815800*:CC94A589:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000003192AAF8 2025-09-12 22:00:02.826100 :CC94A58A: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-12 22:00:02.846869 :CC94A592: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-12 22:00:02.849220 :CC94A59A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-09-12 22:00:02.849430 :CC94A59B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-09-12 22:00:02.850381 :CC94A59C: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-12 22:00:02.850465 :CC94A59F: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-12 22:00:02.851308 :CC94A5B1: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-12 22:00:02.852785 :CC94A5B9: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-12 22:00:02.853098 :CC94A5C1: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-12 22:00:02.909576*: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-12 22:00:02.909576*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-09-12 22:00:02.909576*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-09-12 22:00:02.909576*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-09-12 22:00:02.909576*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-09-12 22:00:02.909576*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-09-12 22:00:02.909576*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-09-12 22:00:02.985204 :CC94A668: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-12 22:00:04.873872 :CC94A852: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-12 22:00:04.873889 :CC94A853:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0007.007.0000cc66 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 24320, J003)