Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250603220008\orcl_j003_16144_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:36943M/63366M, Ph+PgF:43648M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 16144, image: ORACLE.EXE (J003) *** 2025-06-03 22:00:08.869 *** SESSION ID:(233.24209) 2025-06-03 22:00:08.869 *** 2025-06-03 22:00:08.869 Process diagnostic dump for ORACLE.EXE (J003), OS id=16144, pid: 29, proc_ser: 88, sid: 233, sess_ser: 24209 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 16144 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12538, hash value=2471208201 Current Wait Stack: Not in wait; last wait ended 0.975850 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.975876 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=133 seq_num=134 snap_id=1 wait times: snap=0.000301 sec, exc=0.000301 sec, total=0.000301 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 1: waited for 'log file sequential read' log#=0x2823, block#=0x0, blocks=0x0 wait_id=132 seq_num=133 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.136350 sec of elapsed time 2: waited for 'log file sequential read' log#=0x2823, block#=0x0, blocks=0x0 wait_id=131 seq_num=132 snap_id=1 wait times: snap=0.000018 sec, exc=0.000018 sec, total=0.000018 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.204614 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x5800, blocks=0x800 wait_id=130 seq_num=131 snap_id=1 wait times: snap=0.000301 sec, exc=0.000301 sec, total=0.000301 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000013 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0x5000, blocks=0x800 wait_id=129 seq_num=130 snap_id=1 wait times: snap=0.001921 sec, exc=0.001921 sec, total=0.001921 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000015 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0x4800, blocks=0x800 wait_id=128 seq_num=129 snap_id=1 wait times: snap=0.004997 sec, exc=0.004997 sec, total=0.004997 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000014 sec of elapsed time 6: waited for 'log file sequential read' log#=0x0, block#=0x4000, blocks=0x800 wait_id=127 seq_num=128 snap_id=1 wait times: snap=0.005226 sec, exc=0.005226 sec, total=0.005226 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000194 sec of elapsed time 7: waited for 'log file sequential read' log#=0x0, block#=0x3800, blocks=0x800 wait_id=126 seq_num=127 snap_id=1 wait times: snap=0.007370 sec, exc=0.007370 sec, total=0.007370 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.205280 sec of elapsed time 8: waited for 'log file sequential read' log#=0x2823, block#=0x800, blocks=0x800 wait_id=125 seq_num=126 snap_id=1 wait times: snap=0.000199 sec, exc=0.000199 sec, total=0.000199 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002113 sec of elapsed time 9: waited for 'log file sequential read' log#=0x2823, block#=0x0, blocks=0x0 wait_id=124 seq_num=125 snap_id=1 wait times: snap=0.000002 sec, exc=0.000002 sec, total=0.000002 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000118 sec of elapsed time Sampled Session History of session 233 serial 24209 --------------------------------------------------- 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 --------------------------------------------------- [1 sample, 22:00:08] not in wait at each sample [1 sample, 22:00:07] waited for 'Disk file operations I/O', seq_num: 65 p1: 'FileOperation'=0x5 p2: 'fileno'=0x0 p3: 'filetype'=0x3 time_waited: 0.001406 sec (sample interval: 0 sec) [4 samples, 22:00:03 - 22:00:06] not in wait at each sample [1 sample, 22:00:02] idle wait at each sample [session created at: 22:00:02] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'Disk file operations I/O' [1 sample, 22:00:07 ] time_waited: 0.001406 sec (sample interval: 0 sec) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-03 22:00:08.869 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 16144, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-03 01:00:51.044793 :9F8964B8:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 01:00:51.045295 :9F8964B9: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-06-03 01:00:51.045347 :9F8964BF: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-06-03 01:00:51.052940 :9F8964CD: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-06-03 01:00:51.054062 :9F8964D5: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-06-03 01:00:51.054689 :9F8964DD: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-06-03 01:00:51.055160 :9F8964E5: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-06-03 01:00:51.055587 :9F8964ED: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-06-03 01:00:51.057998 :9F8964F5: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-06-03 01:00:51.059155 :9F8964FD: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-06-03 01:00:51.108673 :9F896505: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-06-03 01:00:51.109571 :9F89650D: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-06-03 01:00:51.109819 :9F896515: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-06-03 01:00:51.110032 :9F89651D: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-06-03 01:00:51.111693 :9F896525:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-03 01:01:49.789105 :9F897869:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-03 01:01:49.777 2025-06-03 01:01:49.789106 :9F89786A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13000 pso_num=29 pso_serial#=82 2025-06-03 01:01:49.789250 :9F89786B:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13000 osp_idx=27 osp_ver=12066 osp_pg=0 (spawn #246250) 2025-06-03 01:01:49.789251 :9F89786C:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 01:01:49.789251 :9F89786D:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=232 time=1888268422 2025-06-03 01:01:49.789252 :9F89786E:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 01:01:49.789252 :9F89786F:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 01:01:49.789253 :9F897870:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 01:01:49.789253 :9F897871:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 01:01:49.789253 :9F897872:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 01:01:49.789785 :9F897873: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-06-03 01:01:49.789849 :9F897879: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-06-03 01:01:49.798376 :9F89788E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-03 01:11:51.110541 :9F8A4582:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-03 01:11:51.098 2025-06-03 01:11:51.110543 :9F8A4583:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12000 pso_num=29 pso_serial#=83 2025-06-03 01:11:51.110676 :9F8A4584:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12000 osp_idx=27 osp_ver=12067 osp_pg=0 (spawn #246273) 2025-06-03 01:11:51.110676 :9F8A4585:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 01:11:51.110677 :9F8A4586:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=233 time=1888869750 2025-06-03 01:11:51.110677 :9F8A4587:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 01:11:51.110678 :9F8A4588:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 01:11:51.110678 :9F8A4589:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 01:11:51.110678 :9F8A458A:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 01:11:51.110679 :9F8A458B:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 01:11:51.111210 :9F8A458C: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-06-03 01:11:51.111251 :9F8A4592: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-06-03 01:11:51.115414 :9F8A45AB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:11:51.115459 :9F8A45AC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:11:51.115708 :9F8A45AD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:11:51.115724 :9F8A45AE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:11:51.115945 :9F8A45AF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:11:51.115965 :9F8A45B0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:11:51.116246 :9F8A45B1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:11:51.116259 :9F8A45B2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:11:51.116475 :9F8A45B3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:11:51.116488 :9F8A45B4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:11:51.116698 :9F8A45B5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:11:51.116711 :9F8A45B6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:11:51.119077 :9F8A45B7:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-03 01:41:55.040556 :9F8C9CC1:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-03 01:41:55.028 2025-06-03 01:41:55.040559 :9F8C9CC2:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15528 pso_num=29 pso_serial#=84 2025-06-03 01:41:55.040698 :9F8C9CC3:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=15528 osp_idx=27 osp_ver=12068 osp_pg=0 (spawn #246341) 2025-06-03 01:41:55.040698 :9F8C9CC4:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 01:41:55.040699 :9F8C9CC5:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=234 time=1890673688 2025-06-03 01:41:55.040699 :9F8C9CC6:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 01:41:55.040700 :9F8C9CC7:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 01:41:55.040700 :9F8C9CC8:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 01:41:55.040700 :9F8C9CC9:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 01:41:55.040701 :9F8C9CCA:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 01:41:55.041204 :9F8C9CCB: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-06-03 01:41:55.041246 :9F8C9CD1: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-06-03 01:41:55.045341 :9F8C9CFA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:41:55.045384 :9F8C9CFB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:41:55.045641 :9F8C9CFC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:41:55.045658 :9F8C9CFD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:41:55.045865 :9F8C9CFE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:41:55.045878 :9F8C9CFF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:41:55.046079 :9F8C9D00:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:41:55.046092 :9F8C9D01:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:41:55.046297 :9F8C9D02:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:41:55.046310 :9F8C9D03:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:41:55.046507 :9F8C9D04:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-03 01:41:55.046520 :9F8C9D05:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-03 01:41:55.048876 :9F8C9D06:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-03 05:12:23.174913 :9F9D0C6D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-03 05:12:23.166 2025-06-03 05:12:23.174914 :9F9D0C6E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15232 pso_num=29 pso_serial#=85 2025-06-03 05:12:23.175040 :9F9D0C6F:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=15232 (legacy spawn) 2025-06-03 05:12:23.181788 :9F9D0CA4: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-06-03 05:12:23.181920 :9F9D0CB2: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-06-03 05:12:23.182721 :9F9D0CB3:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-03 08:19:42.790967 :9FABE1B7:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-03 08:19:42.787 2025-06-03 08:19:42.790969 :9FABE1B8:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16056 pso_num=29 pso_serial#=86 2025-06-03 08:19:42.793849 :9FABE1B9:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=16056 osp_idx=27 osp_ver=12070 osp_pg=0 (spawn #247259) 2025-06-03 08:19:42.793850 :9FABE1BA:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 08:19:42.793851 :9FABE1BB:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=235 time=1914541407 2025-06-03 08:19:42.793851 :9FABE1BC:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 08:19:42.793851 :9FABE1BD:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 08:19:42.793852 :9FABE1BE:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 08:19:42.793852 :9FABE1BF:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 08:19:42.793852 :9FABE1C0:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 08:19:42.796587 :9FABE1C1: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-06-03 08:19:42.796638 :9FABE1C7: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-06-03 08:19:42.797041 :9FABE1C8:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-03 08:19:44.992963 :9FABE30F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-03 08:19:44.992 2025-06-03 08:19:44.992965 :9FABE310:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10020 pso_num=29 pso_serial#=87 2025-06-03 08:19:44.993106 :9FABE311:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10020 osp_idx=27 osp_ver=12071 osp_pg=0 (spawn #247261) 2025-06-03 08:19:44.993107 :9FABE312:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 08:19:44.993108 :9FABE313:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=236 time=1914543625 2025-06-03 08:19:44.993108 :9FABE314:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 08:19:44.993108 :9FABE315:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 08:19:44.993109 :9FABE316:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 08:19:44.993109 :9FABE317:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 08:19:44.993109 :9FABE318:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 08:19:44.993606 :9FABE319: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-06-03 08:19:44.993648 :9FABE31F: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-06-03 08:19:44.994008 :9FABE320:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-03 22:00:02.045615 :9FEC8180:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-03 22:00:02.039 2025-06-03 22:00:02.045617 :9FEC8181:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16144 pso_num=29 pso_serial#=88 2025-06-03 22:00:02.045753 :9FEC8182:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=16144 osp_idx=27 osp_ver=12072 osp_pg=0 (spawn #249157) 2025-06-03 22:00:02.045754 :9FEC8183:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-03 22:00:02.045754 :9FEC8184:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=237 time=1963760688 2025-06-03 22:00:02.045754 :9FEC8185:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 22:00:02.045755 :9FEC8186:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 22:00:02.045755 :9FEC8187:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 22:00:02.045755 :9FEC8188:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 22:00:02.045756 :9FEC8189:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 22:00:02.046275 :9FEC8192: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-06-03 22:00:02.051302 :9FEC81B9: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-06-03 22:00:02.051331 :9FEC81BC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-06-03 22:00:02.068674 :9FEC823D: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-06-03 22:00:02.068977 :9FEC8245: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-06-03 22:00:02.069273 :9FEC824D: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-06-03 22:00:02.069432 :9FEC8255: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-06-03 22:00:02.069592 :9FEC825D: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-06-03 22:00:02.069747 :9FEC8265: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-06-03 22:00:02.069984 :9FEC826D: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-06-03 22:00:02.070186 :9FEC8275: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-06-03 22:00:02.070352 :9FEC827D: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-06-03 22:00:02.070514 :9FEC8285: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-06-03 22:00:02.070671 :9FEC828D: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-06-03 22:00:02.070822 :9FEC8295: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-06-03 22:00:02.070984 :9FEC829D: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-06-03 22:00:02.071143 :9FEC82A5: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-06-03 22:00:02.071297 :9FEC82AD: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-06-03 22:00:02.071444 :9FEC82B5: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-06-03 22:00:02.071618 :9FEC82BD: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-06-03 22:00:02.071782 :9FEC82C5: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-06-03 22:00:02.071933 :9FEC82CD: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-06-03 22:00:02.072101 :9FEC82D5: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-06-03 22:00:02.072481 :9FEC82DD: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-06-03 22:00:02.072645 :9FEC82E5: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-06-03 22:00:02.072803 :9FEC82ED: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-06-03 22:00:02.073061 :9FEC82F5: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-06-03 22:00:02.073308 :9FEC82FD: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-06-03 22:00:02.073556 :9FEC8305: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-06-03 22:00:02.074059 :9FEC830D: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-06-03 22:00:02.100541 :9FEC8317: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-06-03 22:00:03.773470 :9FEC8784: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-06-03 22:00:03.789898 :9FEC87A4: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-06-03 22:00:03.790700*:9FEC87B4:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC600F8 estart=1748959202 eid=16777367 ctx=0x000000077B2E3E40 cwh=0x0000000029A906F8 cpu=15625 buffg=10 interb=0 r=0 rb=0 w=0 wb=0 2025-06-03 22:00:03.790700*:9FEC87B5:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC600F8 curCtx=0x00000000345D1928 pubTabIdxCnt=0 2025-06-03 22:00:03.790700*:9FEC87B6:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC600F8 2025-06-03 22:00:03.790700*:9FEC87B7:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC600F8 2025-06-03 22:00:03.806317*:9FEC87BC:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC600F8 curCtx=0x00000000345D1928 xsc->flg4=65792 flags=1 2025-06-03 22:00:03.806317*:9FEC87BD:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC600F8 2025-06-03 22:00:03.810032 :9FEC87BE: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-06-03 22:00:03.812003 :9FEC87C6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-06-03 22:00:03.812211 :9FEC87C7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-06-03 22:00:03.813157 :9FEC87C8: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-06-03 22:00:03.813250 :9FEC87CB: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-06-03 22:00:03.814133 :9FEC87DD: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-06-03 22:00:03.815634 :9FEC87E5: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-06-03 22:00:03.815915 :9FEC87ED: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-06-03 22:00:03.868807*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-06-03 22:00:03.868807*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-06-03 22:00:03.868807*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-06-03 22:00:03.868807*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-06-03 22:00:03.868807*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-06-03 22:00:03.868807*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-06-03 22:00:03.868807*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-06-03 22:00:03.947848 :9FEC8894: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-06-03 22:00:05.838866 :9FEC8A06: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-06-03 22:00:05.838882 :9FEC8A07:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0002.007.0000c20f 2025-06-03 22:00:08.360548 :9FEC8BA4: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-06-03 22:00:08.362149 :9FEC8BAC: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-06-03 22:00:08.371898 :9FEC8BB4:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 7, ext 0, nex 2 2025-06-03 22:00:08.371907 :9FEC8BB5:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x00815e07 where: kdiwh22: kdifind 2025-06-03 22:00:08.373959 :9FEC8BB6: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-06-03 22:00:08.399181 :9FEC8BBE: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 16144, J003)