Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250701220006\orcl_w000_17432_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:36765M/63366M, Ph+PgF:42770M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 17432, image: ORACLE.EXE (W000) *** 2025-07-01 22:00:07.047 *** SESSION ID:(201.5207) 2025-07-01 22:00:07.047 *** 2025-07-01 22:00:07.047 Process diagnostic dump for ORACLE.EXE (W000), OS id=17432, pid: 25, proc_ser: 243, sid: 201, sess_ser: 5207 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=191 seq_num=192 snap_id=1 wait times: snap=4.262566 sec, exc=4.262566 sec, total=4.262566 sec wait times: max=5.000000 sec, heur=15 min 17 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000032 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=190 seq_num=191 snap_id=1 wait times: snap=5.009607 sec, exc=5.009607 sec, total=5.009607 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=189 seq_num=190 snap_id=1 wait times: snap=5.004640 sec, exc=5.004640 sec, total=5.004640 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=188 seq_num=189 snap_id=1 wait times: snap=5.014728 sec, exc=5.014728 sec, total=5.014728 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=187 seq_num=188 snap_id=1 wait times: snap=5.015234 sec, exc=5.015234 sec, total=5.015234 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=186 seq_num=187 snap_id=1 wait times: snap=5.003339 sec, exc=5.003339 sec, total=5.003339 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=185 seq_num=186 snap_id=1 wait times: snap=5.000237 sec, exc=5.000237 sec, total=5.000237 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=184 seq_num=185 snap_id=1 wait times: snap=5.000607 sec, exc=5.000607 sec, total=5.000607 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=183 seq_num=184 snap_id=1 wait times: snap=5.003014 sec, exc=5.003014 sec, total=5.003014 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=182 seq_num=183 snap_id=1 wait times: snap=5.004611 sec, exc=5.004611 sec, total=5.004611 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=181 seq_num=182 snap_id=1 wait times: snap=5.004644 sec, exc=5.004644 sec, total=5.004644 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 201 serial 5207 --------------------------------------------------- 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 --------------------------------------------------- [121 samples, 21:58:07 - 22:00:07] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-01 22:00:07.047 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 17432, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-01 19:34:04.425194 :AC371F03:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-07-01 19:34:04.426009 :AC371F04:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 19:34:04.502148 :AC371F65:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 19:34:04.497 2025-07-01 19:34:04.502150 :AC371F66:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17364 pso_num=25 pso_serial#=231 2025-07-01 19:34:04.502288 :AC371F67:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17364 osp_idx=23 osp_ver=179863 osp_pg=0 (spawn #342164) 2025-07-01 19:34:04.502288 :AC371F68:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 19:34:04.502289 :AC371F69:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=105 time=79220392 2025-07-01 19:34:04.502289 :AC371F6A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 19:34:04.502290 :AC371F6B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 19:34:04.502290 :AC371F6C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 19:34:04.502290 :AC371F6D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 19:34:04.502291 :AC371F6E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 19:34:04.502796 :AC371F6F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 19:34:04.502839 :AC371F76:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 19:44:05.456317 :AC37E140:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 19:44:05.721144 :AC37E1D6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 19:44:05.716 2025-07-01 19:44:05.721146 :AC37E1D7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15688 pso_num=25 pso_serial#=232 2025-07-01 19:44:05.721283 :AC37E1D8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15688 osp_idx=23 osp_ver=179864 osp_pg=0 (spawn #342188) 2025-07-01 19:44:05.721284 :AC37E1D9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 19:44:05.721285 :AC37E1DA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=106 time=79821611 2025-07-01 19:44:05.721285 :AC37E1DB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 19:44:05.721285 :AC37E1DC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 19:44:05.721286 :AC37E1DD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 19:44:05.721286 :AC37E1DE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 19:44:05.721286 :AC37E1DF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 19:44:05.721774 :AC37E1E0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 19:44:05.721818 :AC37E1E7:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 19:44:49.112132 :AC37EF66:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-01 19:54:06.991697 :AC38A3B9:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-01 19:54:06.991744 :AC38A3C5:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-07-01 19:54:06.991812 :AC38A3CA:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-07-01 19:54:06.991813 :AC38A3CB:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=68, exc=68, tot=68 2025-07-01 20:04:07.841130 :AC39680F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 20:04:08.236285 :AC3968AB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 20:04:08.231 2025-07-01 20:04:08.236287 :AC3968AC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13448 pso_num=25 pso_serial#=233 2025-07-01 20:04:08.236421 :AC3968AD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13448 osp_idx=23 osp_ver=179865 osp_pg=0 (spawn #342235) 2025-07-01 20:04:08.236421 :AC3968AE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 20:04:08.236421 :AC3968AF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=107 time=81024126 2025-07-01 20:04:08.236421 :AC3968B0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 20:04:08.236422 :AC3968B1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 20:04:08.236422 :AC3968B2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 20:04:08.236423 :AC3968B3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 20:04:08.236423 :AC3968B4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 20:04:08.236923 :AC3968B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 20:04:08.236967 :AC3968BD:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 20:14:09.167869 :AC3A3300:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 20:14:09.516403 :AC3A3363:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 20:14:09.511 2025-07-01 20:14:09.516405 :AC3A3364:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4660 pso_num=25 pso_serial#=234 2025-07-01 20:14:09.516545 :AC3A3365:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4660 osp_idx=23 osp_ver=179866 osp_pg=0 (spawn #342256) 2025-07-01 20:14:09.516546 :AC3A3366:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 20:14:09.516546 :AC3A3367:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=108 time=81625408 2025-07-01 20:14:09.516547 :AC3A3368:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 20:14:09.516547 :AC3A3369:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 20:14:09.516548 :AC3A336A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 20:14:09.516548 :AC3A336B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 20:14:09.516548 :AC3A336C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 20:14:09.517042 :AC3A336D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 20:14:09.517091 :AC3A3376:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 20:14:39.566745 :AC3A3C8A:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-07-01 20:14:39.566774 :AC3A3CA3:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=7 seq_num=8 snap_id=1 2025-07-01 20:14:39.566775 :AC3A3CA4:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=27, exc=27, tot=27 2025-07-01 20:15:09.620744 :AC3A467E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 20:15:39.665767 :AC3A4FC8:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=21 seq_num=22 snap_id=1 2025-07-01 20:15:39.665785 :AC3A4FDA:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=21 seq_num=22 snap_id=1 2025-07-01 20:15:39.665786 :AC3A4FDB:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=19, exc=19, tot=19 2025-07-01 20:24:10.410476 :AC3AF6C4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 20:24:10.774650 :AC3AF740:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 20:24:10.770 2025-07-01 20:24:10.774652 :AC3AF741:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13808 pso_num=25 pso_serial#=235 2025-07-01 20:24:10.774789 :AC3AF742:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13808 osp_idx=23 osp_ver=179867 osp_pg=0 (spawn #342279) 2025-07-01 20:24:10.774790 :AC3AF743:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 20:24:10.774791 :AC3AF744:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=109 time=82226673 2025-07-01 20:24:10.774791 :AC3AF745:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 20:24:10.774792 :AC3AF746:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 20:24:10.774792 :AC3AF747:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 20:24:10.774792 :AC3AF748:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 20:24:10.774793 :AC3AF749:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 20:24:10.775376 :AC3AF74A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 20:24:10.775428 :AC3AF751:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 20:34:11.423613 :AC3BB8EF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 20:34:11.944168 :AC3BB96E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 20:34:11.939 2025-07-01 20:34:11.944170 :AC3BB96F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17448 pso_num=25 pso_serial#=236 2025-07-01 20:34:11.944313 :AC3BB970:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17448 osp_idx=23 osp_ver=179868 osp_pg=0 (spawn #342301) 2025-07-01 20:34:11.944314 :AC3BB971:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 20:34:11.944314 :AC3BB972:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=110 time=82827845 2025-07-01 20:34:11.944315 :AC3BB973:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 20:34:11.944315 :AC3BB974:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 20:34:11.944316 :AC3BB975:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 20:34:11.944316 :AC3BB976:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 20:34:11.944316 :AC3BB977:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 20:34:11.944806 :AC3BB978:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 20:34:11.944852 :AC3BB97F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 20:44:12.720528 :AC3C7BF6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 20:44:13.178337 :AC3C7C78:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 20:44:13.174 2025-07-01 20:44:13.178339 :AC3C7C79:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14456 pso_num=25 pso_serial#=237 2025-07-01 20:44:13.178481 :AC3C7C7A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14456 osp_idx=23 osp_ver=179869 osp_pg=0 (spawn #342324) 2025-07-01 20:44:13.178484 :AC3C7C7B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 20:44:13.178484 :AC3C7C7C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=111 time=83429079 2025-07-01 20:44:13.178485 :AC3C7C7D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 20:44:13.178485 :AC3C7C7E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 20:44:13.178486 :AC3C7C7F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 20:44:13.178486 :AC3C7C80:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 20:44:13.178487 :AC3C7C81:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 20:44:13.178975 :AC3C7C82:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 20:44:13.179018 :AC3C7C8A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 20:54:14.018319 :AC3D3DDA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 20:54:14.382654 :AC3D3E53:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 20:54:14.378 2025-07-01 20:54:14.382656 :AC3D3E54:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17040 pso_num=25 pso_serial#=238 2025-07-01 20:54:14.382800 :AC3D3E55:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17040 osp_idx=23 osp_ver=179870 osp_pg=0 (spawn #342347) 2025-07-01 20:54:14.382800 :AC3D3E56:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 20:54:14.382801 :AC3D3E57:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=112 time=84030283 2025-07-01 20:54:14.382802 :AC3D3E58:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 20:54:14.382802 :AC3D3E59:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 20:54:14.382802 :AC3D3E5A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 20:54:14.382803 :AC3D3E5B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 20:54:14.382803 :AC3D3E5C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 20:54:14.383338 :AC3D3E5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 20:54:14.383382 :AC3D3E64:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 21:04:15.286746 :AC3E0237:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 21:04:15.697654 :AC3E02B5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 21:04:15.693 2025-07-01 21:04:15.697656 :AC3E02B6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16488 pso_num=25 pso_serial#=239 2025-07-01 21:04:15.697800 :AC3E02B7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16488 osp_idx=23 osp_ver=179871 osp_pg=0 (spawn #342372) 2025-07-01 21:04:15.697800 :AC3E02B8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 21:04:15.697801 :AC3E02B9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=113 time=84631595 2025-07-01 21:04:15.697801 :AC3E02BA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 21:04:15.697802 :AC3E02BB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 21:04:15.697802 :AC3E02BC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 21:04:15.697802 :AC3E02BD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 21:04:15.697803 :AC3E02BE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 21:04:15.698293 :AC3E02BF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 21:04:15.698339 :AC3E02C8:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 21:14:16.383982 :AC3ECD1D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 21:14:16.904602 :AC3ECD93:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 21:14:16.899 2025-07-01 21:14:16.904604 :AC3ECD94:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16104 pso_num=25 pso_serial#=240 2025-07-01 21:14:16.904753 :AC3ECD95:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16104 osp_idx=23 osp_ver=179872 osp_pg=0 (spawn #342395) 2025-07-01 21:14:16.904754 :AC3ECD96:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 21:14:16.904754 :AC3ECD97:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=114 time=85232798 2025-07-01 21:14:16.904755 :AC3ECD98:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 21:14:16.904755 :AC3ECD99:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 21:14:16.904756 :AC3ECD9A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 21:14:16.904756 :AC3ECD9B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 21:14:16.904757 :AC3ECD9C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 21:14:16.905294 :AC3ECD9D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 21:14:16.905355 :AC3ECDA4:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 21:24:17.781322 :AC3F8E44:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 21:24:18.301657 :AC3F8EBF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 21:24:18.296 2025-07-01 21:24:18.301659 :AC3F8EC0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13512 pso_num=25 pso_serial#=241 2025-07-01 21:24:18.301792 :AC3F8EC1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13512 osp_idx=23 osp_ver=179873 osp_pg=0 (spawn #342418) 2025-07-01 21:24:18.301793 :AC3F8EC2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 21:24:18.301793 :AC3F8EC3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=115 time=85834189 2025-07-01 21:24:18.301793 :AC3F8EC4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 21:24:18.301794 :AC3F8EC5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 21:24:18.301794 :AC3F8EC6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 21:24:18.301795 :AC3F8EC7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 21:24:18.301795 :AC3F8EC8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 21:24:18.302319 :AC3F8EC9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 21:24:18.302367 :AC3F8ED3:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 21:34:19.139939 :AC404FE8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 21:34:19.644653 :AC40504E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 21:34:19.640 2025-07-01 21:34:19.644654 :AC40504F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=1112 pso_num=25 pso_serial#=242 2025-07-01 21:34:19.644787 :AC405050:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=1112 osp_idx=23 osp_ver=179874 osp_pg=0 (spawn #342440) 2025-07-01 21:34:19.644788 :AC405051:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 21:34:19.644788 :AC405052:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=116 time=86435533 2025-07-01 21:34:19.644789 :AC405053:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 21:34:19.644789 :AC405054:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 21:34:19.644789 :AC405055:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 21:34:19.644790 :AC405056:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 21:34:19.644790 :AC405057:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 21:34:19.645285 :AC405058:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 21:34:19.645337 :AC40505F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 21:44:20.508864 :AC411119:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-01 21:44:20.976942 :AC411179:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-01 21:44:20.972 2025-07-01 21:44:20.976944 :AC41117A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17432 pso_num=25 pso_serial#=243 2025-07-01 21:44:20.977084 :AC41117B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17432 osp_idx=23 osp_ver=179875 osp_pg=0 (spawn #342463) 2025-07-01 21:44:20.977084 :AC41117C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-01 21:44:20.977085 :AC41117D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=117 time=87036876 2025-07-01 21:44:20.977085 :AC41117E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-01 21:44:20.977086 :AC41117F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-01 21:44:20.977086 :AC411180:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-01 21:44:20.977086 :AC411181:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-01 21:44:20.977087 :AC411182:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-01 21:44:20.977579 :AC411183:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-01 21:44:20.977626 :AC41118C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-01 21:44:49.844044 :AC411AB9:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-01 21:54:22.289378 :AC41D373:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 17432, W000)