Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250612220009\orcl_j003_13828_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:36688M/63366M, Ph+PgF:43170M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 13828, image: ORACLE.EXE (J003) *** 2025-06-12 22:00:09.110 *** SESSION ID:(233.25289) 2025-06-12 22:00:09.110 *** 2025-06-12 22:00:09.110 Process diagnostic dump for ORACLE.EXE (J003), OS id=13828, pid: 29, proc_ser: 115, sid: 233, sess_ser: 25289 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 13828 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12581, hash value=2067742918 Current Wait Stack: Not in wait; last wait ended 1.349733 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 1.349758 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=142 seq_num=143 snap_id=1 wait times: snap=0.000217 sec, exc=0.000217 sec, total=0.000217 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#=0x2855, block#=0x0, blocks=0x0 wait_id=141 seq_num=142 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.104822 sec of elapsed time 2: waited for 'log file sequential read' log#=0x2855, block#=0x0, blocks=0x0 wait_id=140 seq_num=141 snap_id=1 wait times: snap=0.000019 sec, exc=0.000019 sec, total=0.000019 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.371519 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x3000, blocks=0x800 wait_id=139 seq_num=140 snap_id=1 wait times: snap=0.000297 sec, exc=0.000297 sec, total=0.000297 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0x2800, blocks=0x800 wait_id=138 seq_num=139 snap_id=1 wait times: snap=0.000288 sec, exc=0.000288 sec, total=0.000288 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000094 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0x2000, blocks=0x800 wait_id=137 seq_num=138 snap_id=1 wait times: snap=0.000284 sec, exc=0.000284 sec, total=0.000284 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.123423 sec of elapsed time 6: waited for 'log file sequential read' log#=0x2855, block#=0x800, blocks=0x800 wait_id=136 seq_num=137 snap_id=1 wait times: snap=0.000201 sec, exc=0.000201 sec, total=0.000201 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.001816 sec of elapsed time 7: waited for 'log file sequential read' log#=0x2855, block#=0x0, blocks=0x0 wait_id=135 seq_num=136 snap_id=1 wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000135 sec of elapsed time 8: waited for 'log file sequential read' log#=0x2855, block#=0x2, blocks=0x7fe wait_id=134 seq_num=135 snap_id=1 wait times: snap=0.000201 sec, exc=0.000201 sec, total=0.000201 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000153 sec of elapsed time 9: waited for 'log file sequential read' log#=0x0, block#=0x1, blocks=0x1 wait_id=133 seq_num=134 snap_id=1 wait times: snap=0.000042 sec, exc=0.000042 sec, total=0.000042 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000003 sec of elapsed time Sampled Session History of session 233 serial 25289 --------------------------------------------------- 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 --------------------------------------------------- [7 samples, 22:00:02 - 22:00:08] not in wait at each sample [1 sample, 22:00:01] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-12 22:00:09.110 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 13828, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-12 01:00:01.600733 :A37BBE3F: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-12 01:00:01.600899 :A37BBE46: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-12 01:00:01.601751 :A37BBE49:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 01:00:01.610383 :A37BBE4C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 01:00:01.595 2025-06-12 01:00:01.610386 :A37BBE4D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14080 pso_num=29 pso_serial#=104 2025-06-12 01:00:01.610533 :A37BBE4E:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=14080 (legacy spawn) 2025-06-12 01:00:01.617099 :A37BBE4F: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-12 01:00:01.617264 :A37BBE58: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-12 01:00:01.618069 :A37BBE59:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 01:00:04.706731 :A37BBF43:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 01:00:04.693 2025-06-12 01:00:04.706734 :A37BBF44:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9112 pso_num=29 pso_serial#=105 2025-06-12 01:00:04.706875 :A37BBF45:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9112 (legacy spawn) 2025-06-12 01:00:04.713458 :A37BBF46: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-12 01:00:04.713625 :A37BBF4B: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-12 01:00:04.714461 :A37BBF50:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 01:00:04.723268 :A37BBF53:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 01:00:04.719 2025-06-12 01:00:04.723270 :A37BBF54:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9288 pso_num=29 pso_serial#=106 2025-06-12 01:00:04.723404 :A37BBF55:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9288 (legacy spawn) 2025-06-12 01:00:04.729893 :A37BBF56: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-12 01:00:04.730062 :A37BBF5E: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-12 01:00:04.730876 :A37BBF60:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 01:00:05.693170 :A37BBFE5:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 01:00:05.688 2025-06-12 01:00:05.693172 :A37BBFE6:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16380 pso_num=29 pso_serial#=107 2025-06-12 01:00:05.693314 :A37BBFE7:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=16380 osp_idx=27 osp_ver=12601 osp_pg=0 (spawn #276236) 2025-06-12 01:00:05.693315 :A37BBFE8: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-12 01:00:05.693315 :A37BBFE9:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=169 time=2665748875 2025-06-12 01:00:05.693316 :A37BBFEA:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-12 01:00:05.693316 :A37BBFEB:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-12 01:00:05.693316 :A37BBFEC:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-12 01:00:05.693317 :A37BBFED:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-12 01:00:05.693317 :A37BBFEE:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-12 01:00:05.693806 :A37BBFEF: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-12 01:00:05.693852 :A37BBFF5: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-12 01:00:05.698275 :A37BC008: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-12 01:00:05.721568 :A37BC010: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-12 01:00:05.735698 :A37BC018: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-12 01:00:05.764275 :A37BC020: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-12 01:00:05.768710 :A37BC028: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-12 01:00:05.772550 :A37BC030: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-12 01:00:05.775151 :A37BC038: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-12 01:00:05.776805 :A37BC040: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-12 01:00:05.777887 :A37BC048: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-12 01:00:05.781527 :A37BC050: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-12 01:00:07.036540 :A37BC09B: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-12 01:00:07.068189 :A37BC0A3: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-12 01:00:07.068531 :A37BC0AB: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-12 01:00:07.068861 :A37BC0B3: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-12 01:00:07.068879 :A37BC0B6: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-06-12 01:00:07.068972 :A37BC0C8: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-12 01:00:07.071875 :A37BC0D0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 01:00:09.675549 :A37BC20D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 01:00:09.666 2025-06-12 01:00:09.675551 :A37BC20E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=17288 pso_num=29 pso_serial#=108 2025-06-12 01:00:09.675700 :A37BC20F:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=17288 (legacy spawn) 2025-06-12 01:00:09.682173 :A37BC210: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-12 01:00:09.682355 :A37BC215: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-12 01:00:09.683196 :A37BC21A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 01:00:16.156351 :A37BC533:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 01:00:16.144 2025-06-12 01:00:16.156353 :A37BC534:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13628 pso_num=29 pso_serial#=109 2025-06-12 01:00:16.156494 :A37BC535:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13628 (legacy spawn) 2025-06-12 01:00:16.163094 :A37BC536: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-12 01:00:16.163258 :A37BC53F: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-12 01:00:16.164119 :A37BC540:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 01:00:23.410245 :A37BC7A0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 01:00:23.396 2025-06-12 01:00:23.410247 :A37BC7A1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16520 pso_num=29 pso_serial#=110 2025-06-12 01:00:23.410382 :A37BC7A2:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=16520 (legacy spawn) 2025-06-12 01:00:23.416864 :A37BC7A3: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-12 01:00:23.417030 :A37BC7A8: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-12 01:00:23.417870 :A37BC7AD:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 01:00:23.436924 :A37BC7B0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 01:00:23.428 2025-06-12 01:00:23.436926 :A37BC7B1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15036 pso_num=29 pso_serial#=111 2025-06-12 01:00:23.437064 :A37BC7B2:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=15036 (legacy spawn) 2025-06-12 01:00:23.443595 :A37BC7B3: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-12 01:00:23.443761 :A37BC7BA: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-12 01:00:23.444614 :A37BC7BD:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 18:00:06.484321 :A3CA740D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 18:00:06.482 2025-06-12 18:00:06.484323 :A3CA740E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=17280 pso_num=29 pso_serial#=112 2025-06-12 18:00:06.484466 :A3CA740F:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=17280 osp_idx=27 osp_ver=12606 osp_pg=0 (spawn #278583) 2025-06-12 18:00:06.484467 :A3CA7410: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-12 18:00:06.484468 :A3CA7411:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=170 time=2726949657 2025-06-12 18:00:06.484468 :A3CA7412:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-12 18:00:06.484468 :A3CA7413:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-12 18:00:06.484469 :A3CA7414:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-12 18:00:06.484469 :A3CA7415:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-12 18:00:06.484469 :A3CA7416:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-12 18:00:06.484962 :A3CA7417: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-12 18:00:06.485005 :A3CA741D: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-12 18:00:06.493093 :A3CA743F:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 19:00:13.555288 :A3CF0EC3:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 19:00:13.552 2025-06-12 19:00:13.555289 :A3CF0EC4:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15660 pso_num=29 pso_serial#=113 2025-06-12 19:00:13.555426 :A3CF0EC5:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=15660 osp_idx=27 osp_ver=12607 osp_pg=0 (spawn #278722) 2025-06-12 19:00:13.555427 :A3CF0EC6: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-12 19:00:13.555427 :A3CF0EC7:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=171 time=2730556735 2025-06-12 19:00:13.555428 :A3CF0EC8:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-12 19:00:13.555428 :A3CF0EC9:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-12 19:00:13.555429 :A3CF0ECA:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-12 19:00:13.555429 :A3CF0ECB:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-12 19:00:13.555429 :A3CF0ECC:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-12 19:00:13.555942 :A3CF0ECD: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-12 19:00:13.555986 :A3CF0ED3: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-12 19:00:13.564704 :A3CF0EF5:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 20:00:21.075417 :A3D3A72A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 20:00:21.073 2025-06-12 20:00:21.075418 :A3D3A72B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15524 pso_num=29 pso_serial#=114 2025-06-12 20:00:21.075555 :A3D3A72C:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=15524 osp_idx=27 osp_ver=12608 osp_pg=0 (spawn #278859) 2025-06-12 20:00:21.075556 :A3D3A72D: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-12 20:00:21.075556 :A3D3A72E:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=172 time=2734164250 2025-06-12 20:00:21.075557 :A3D3A72F:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-12 20:00:21.075557 :A3D3A730:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-12 20:00:21.075558 :A3D3A731:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-12 20:00:21.075558 :A3D3A732:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-12 20:00:21.075558 :A3D3A733:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-12 20:00:21.076048 :A3D3A734: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-12 20:00:21.076094 :A3D3A73A: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-12 20:00:21.084345 :A3D3A74C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-12 22:00:02.051608 :A3DCCCCD:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-12 22:00:02.044 2025-06-12 22:00:02.051609 :A3DCCCCE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13828 pso_num=29 pso_serial#=115 2025-06-12 22:00:02.051751 :A3DCCCCF:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13828 osp_idx=27 osp_ver=12609 osp_pg=0 (spawn #279137) 2025-06-12 22:00:02.051752 :A3DCCCD0: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-12 22:00:02.051752 :A3DCCCD1:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=173 time=2741345235 2025-06-12 22:00:02.051752 :A3DCCCD2:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-12 22:00:02.051753 :A3DCCCD3:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-12 22:00:02.051754 :A3DCCCD4:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-12 22:00:02.051754 :A3DCCCD5:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-12 22:00:02.051755 :A3DCCCD6:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-12 22:00:02.052347 :A3DCCCD7: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-12 22:00:02.057658 :A3DCCCFF: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-12 22:00:02.057706 :A3DCCD0A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-06-12 22:00:02.075775 :A3DCCEEC: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-12 22:00:02.076092 :A3DCCEF4: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-12 22:00:02.076279 :A3DCCEFC: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-12 22:00:02.076450 :A3DCCF04: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-12 22:00:02.076624 :A3DCCF0C: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-12 22:00:02.076795 :A3DCCF14: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-12 22:00:02.076962 :A3DCCF1C: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-12 22:00:02.077114 :A3DCCF24: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-12 22:00:02.077277 :A3DCCF2C: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-12 22:00:02.077436 :A3DCCF34: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-12 22:00:02.077592 :A3DCCF3C: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-12 22:00:02.077742 :A3DCCF44: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-12 22:00:02.077895 :A3DCCF4C: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-12 22:00:02.078064 :A3DCCF54: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-12 22:00:02.078229 :A3DCCF5C: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-12 22:00:02.078381 :A3DCCF64: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-12 22:00:02.078541 :A3DCCF6C: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-12 22:00:02.078690 :A3DCCF74: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-12 22:00:02.078840 :A3DCCF7C: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-12 22:00:02.078989 :A3DCCF84: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-12 22:00:02.079147 :A3DCCF8C: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-12 22:00:02.079296 :A3DCCF94: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-12 22:00:02.079446 :A3DCCF9C: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-12 22:00:02.080080 :A3DCCFA4: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-12 22:00:02.107516 :A3DCCFAC: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-12 22:00:03.278823*:A3DCD2FA:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC03AD0 estart=1749736803 eid=19323313 ctx=0x0000000777968158 cwh=0x00000000447D0158 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-06-12 22:00:03.278823*:A3DCD2FB:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC03AD0 curCtx=0x00000000446D1BF8 pubTabIdxCnt=0 2025-06-12 22:00:03.278823*:A3DCD2FC:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC03AD0 2025-06-12 22:00:03.278823*:A3DCD2FD:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC03AD0 2025-06-12 22:00:03.278823*:A3DCD2FE:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC7B6F0 estart=1749736801 eid=16777384 ctx=0x000000077B54EAC8 cwh=0x000000002DC70068 cpu=984375 buffg=55838 interb=196608 r=24 rb=196608 w=0 wb=0 2025-06-12 22:00:03.278823*:A3DCD2FF:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC7B6F0 curCtx=0x00000000444C7FD8 pubTabIdxCnt=0 2025-06-12 22:00:03.278823*:A3DCD300:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC7B6F0 2025-06-12 22:00:03.278823*:A3DCD301:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC7B6F0 2025-06-12 22:00:03.278823*:A3DCD302:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC03AD0 curCtx=0x00000000446D1BF8 xsc->flg4=65792 flags=1 2025-06-12 22:00:03.278823*:A3DCD303:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC03AD0 2025-06-12 22:00:03.747616*:A3DCD398:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC7B6F0 curCtx=0x00000000444C7FD8 xsc->flg4=65792 flags=2 2025-06-12 22:00:03.747616*:A3DCD399:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC7B6F0 2025-06-12 22:00:03.762154 :A3DCD39A: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-12 22:00:03.782161 :A3DCD3C3: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-12 22:00:03.784118 :A3DCD3CB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-06-12 22:00:03.784333 :A3DCD3CC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-06-12 22:00:03.785215 :A3DCD3CD: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-12 22:00:03.785312 :A3DCD3D0: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-12 22:00:03.786151 :A3DCD3E2: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-12 22:00:03.787673 :A3DCD3EA: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-12 22:00:03.787975 :A3DCD3F2: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-12 22:00:03.841327*: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-12 22:00:03.841327*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-06-12 22:00:03.841327*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-06-12 22:00:03.856953*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-06-12 22:00:03.856953*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-06-12 22:00:03.856953*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-06-12 22:00:03.856953*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-06-12 22:00:03.928053 :A3DCD47C: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-12 22:00:05.815402 :A3DCD5B7: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-12 22:00:05.815417 :A3DCD5B8:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0008.00e.0000cc13 2025-06-12 22:00:08.218077 :A3DCD7C7: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-12 22:00:08.219410 :A3DCD7CF: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-12 22:00:08.229785 :A3DCD7D7: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-12 22:00:08.254340 :A3DCD7DF: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: 13828, J003)