Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250629221114\orcl_w000_9288_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:36546M/63366M, Ph+PgF:42663M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 9288, image: ORACLE.EXE (W000) *** 2025-06-29 22:11:14.827 *** SESSION ID:(201.62289) 2025-06-29 22:11:14.827 *** 2025-06-29 22:11:14.827 Process diagnostic dump for ORACLE.EXE (W000), OS id=9288, pid: 25, proc_ser: 161, sid: 201, sess_ser: 62289 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.755165 sec, exc=0.755165 sec, total=0.755165 sec wait times: max=5.000000 sec, heur=2 min 55 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.000021 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=35 seq_num=36 snap_id=1 wait times: snap=5.007045 sec, exc=5.007045 sec, total=5.007045 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=5.009871 sec, exc=5.009871 sec, total=5.009871 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=5.004632 sec, exc=5.004632 sec, total=5.004632 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=5.004638 sec, exc=5.004638 sec, total=5.004638 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=5.004621 sec, exc=5.004621 sec, total=5.004621 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.009217 sec, exc=5.009217 sec, total=5.009217 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.005147 sec, exc=5.005147 sec, total=5.005147 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=5.010651 sec, exc=5.010651 sec, total=5.010651 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=5.004349 sec, exc=5.004349 sec, total=5.004349 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.014722 sec, exc=5.014722 sec, total=5.014722 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time Sampled Session History of session 201 serial 62289 --------------------------------------------------- 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, 22:09:14 - 22:11:14] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-29 22:11:14.827 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 9288, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-29 19:58:02.518636 :AB58F2A6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 19:58:02.820417 :AB58F31B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 19:58:02.815 2025-06-29 19:58:02.820419 :AB58F31C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16844 pso_num=25 pso_serial#=147 2025-06-29 19:58:02.820557 :AB58F31D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16844 osp_idx=23 osp_ver=175954 osp_pg=0 (spawn #335552) 2025-06-29 19:58:02.820558 :AB58F31E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 19:58:02.820558 :AB58F31F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=232 time=4202826016 2025-06-29 19:58:02.820559 :AB58F320:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 19:58:02.820559 :AB58F321:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 19:58:02.820559 :AB58F322:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 19:58:02.820560 :AB58F323:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 19:58:02.820560 :AB58F324:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 19:58:02.821061 :AB58F325: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-06-29 19:58:02.821104 :AB58F32C: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-06-29 20:08:03.649588 :AB59C044:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 20:08:04.076125 :AB59C0A1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 20:08:04.071 2025-06-29 20:08:04.076127 :AB59C0A2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13400 pso_num=25 pso_serial#=148 2025-06-29 20:08:04.076269 :AB59C0A3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13400 osp_idx=23 osp_ver=175955 osp_pg=0 (spawn #335578) 2025-06-29 20:08:04.076270 :AB59C0A4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 20:08:04.076270 :AB59C0A5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=233 time=4203427266 2025-06-29 20:08:04.076270 :AB59C0A6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 20:08:04.076271 :AB59C0A7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 20:08:04.076271 :AB59C0A8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 20:08:04.076272 :AB59C0A9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 20:08:04.076272 :AB59C0AA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 20:08:04.076787 :AB59C0AB: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-06-29 20:08:04.076834 :AB59C0B3: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-06-29 20:18:04.967444 :AB5A8867:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 20:18:05.331567 :AB5A88C2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 20:18:05.326 2025-06-29 20:18:05.331569 :AB5A88C3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16164 pso_num=25 pso_serial#=149 2025-06-29 20:18:05.331703 :AB5A88C4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16164 osp_idx=23 osp_ver=175956 osp_pg=0 (spawn #335601) 2025-06-29 20:18:05.331703 :AB5A88C5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 20:18:05.331704 :AB5A88C6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=234 time=4204028516 2025-06-29 20:18:05.331704 :AB5A88C7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 20:18:05.331704 :AB5A88C8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 20:18:05.331705 :AB5A88C9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 20:18:05.331705 :AB5A88CA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 20:18:05.331706 :AB5A88CB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 20:18:05.332194 :AB5A88CC: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-06-29 20:18:05.332243 :AB5A88D3: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-06-29 20:28:06.288964 :AB5B4C86:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 20:28:06.637415 :AB5B4CE5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 20:28:06.633 2025-06-29 20:28:06.637417 :AB5B4CE6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14232 pso_num=25 pso_serial#=150 2025-06-29 20:28:06.637558 :AB5B4CE7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14232 osp_idx=23 osp_ver=175957 osp_pg=0 (spawn #335623) 2025-06-29 20:28:06.637558 :AB5B4CE8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 20:28:06.637559 :AB5B4CE9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=235 time=4204629829 2025-06-29 20:28:06.637559 :AB5B4CEA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 20:28:06.637559 :AB5B4CEB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 20:28:06.637560 :AB5B4CEC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 20:28:06.637560 :AB5B4CED:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 20:28:06.637560 :AB5B4CEE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 20:28:06.638070 :AB5B4CEF: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-06-29 20:28:06.638114 :AB5B4CF7: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-06-29 20:28:21.649381 :AB5B51AF:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-06-29 20:28:21.649404 :AB5B51C3:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-06-29 20:28:21.649406 :AB5B51C4:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=23, exc=23, tot=23 2025-06-29 20:35:37.748016 :AB5BE061: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-06-29 20:38:07.841121 :AB5C123E: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-06-29 20:48:08.652197 :AB5CD6A0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 20:48:09.016256 :AB5CD703:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 20:48:09.011 2025-06-29 20:48:09.016258 :AB5CD704:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16044 pso_num=25 pso_serial#=151 2025-06-29 20:48:09.016403 :AB5CD705:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16044 osp_idx=23 osp_ver=175958 osp_pg=0 (spawn #335668) 2025-06-29 20:48:09.016404 :AB5CD706:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 20:48:09.016404 :AB5CD707:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=236 time=4205832204 2025-06-29 20:48:09.016404 :AB5CD708:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 20:48:09.016405 :AB5CD709:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 20:48:09.016406 :AB5CD70A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 20:48:09.016407 :AB5CD70B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 20:48:09.016407 :AB5CD70C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 20:48:09.016896 :AB5CD70D: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-06-29 20:48:09.016943 :AB5CD714: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-06-29 20:58:09.866721 :AB5D9D79:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 20:58:10.262109 :AB5D9DD2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 20:58:10.257 2025-06-29 20:58:10.262111 :AB5D9DD3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17956 pso_num=25 pso_serial#=152 2025-06-29 20:58:10.262247 :AB5D9DD4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17956 osp_idx=23 osp_ver=175959 osp_pg=0 (spawn #335690) 2025-06-29 20:58:10.262248 :AB5D9DD5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 20:58:10.262248 :AB5D9DD6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=237 time=4206433454 2025-06-29 20:58:10.262249 :AB5D9DD7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 20:58:10.262249 :AB5D9DD8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 20:58:10.262249 :AB5D9DD9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 20:58:10.262250 :AB5D9DDA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 20:58:10.262251 :AB5D9DDB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 20:58:10.262757 :AB5D9DDC: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-06-29 20:58:10.262802 :AB5D9DE6: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-06-29 21:08:11.154601 :AB5E6E2E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 21:08:11.409336 :AB5E6E8A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 21:08:11.404 2025-06-29 21:08:11.409338 :AB5E6E8B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8628 pso_num=25 pso_serial#=153 2025-06-29 21:08:11.409482 :AB5E6E8C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8628 osp_idx=23 osp_ver=175960 osp_pg=0 (spawn #335716) 2025-06-29 21:08:11.409483 :AB5E6E8D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 21:08:11.409483 :AB5E6E8E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=238 time=4207034594 2025-06-29 21:08:11.409484 :AB5E6E8F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 21:08:11.409484 :AB5E6E90:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 21:08:11.409484 :AB5E6E91:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 21:08:11.409485 :AB5E6E92:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 21:08:11.409485 :AB5E6E93:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 21:08:11.409990 :AB5E6E94: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-06-29 21:08:11.410049 :AB5E6E9B: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-06-29 21:18:12.254706 :AB5F3810:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 21:18:12.627410 :AB5F386D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 21:18:12.622 2025-06-29 21:18:12.627412 :AB5F386E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7216 pso_num=25 pso_serial#=154 2025-06-29 21:18:12.627562 :AB5F386F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7216 osp_idx=23 osp_ver=175961 osp_pg=0 (spawn #335739) 2025-06-29 21:18:12.627562 :AB5F3870:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 21:18:12.627563 :AB5F3871:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=239 time=4207635813 2025-06-29 21:18:12.627563 :AB5F3872:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 21:18:12.627564 :AB5F3873:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 21:18:12.627564 :AB5F3874:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 21:18:12.627564 :AB5F3875:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 21:18:12.627565 :AB5F3876:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 21:18:12.628089 :AB5F3877: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-06-29 21:18:12.628141 :AB5F3880: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-06-29 21:28:13.511112 :AB5FFDD0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 21:28:13.750205 :AB5FFE35:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 21:28:13.746 2025-06-29 21:28:13.750207 :AB5FFE36:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11036 pso_num=25 pso_serial#=155 2025-06-29 21:28:13.750339 :AB5FFE37:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11036 osp_idx=23 osp_ver=175962 osp_pg=0 (spawn #335761) 2025-06-29 21:28:13.750339 :AB5FFE38:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 21:28:13.750340 :AB5FFE39:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=240 time=4208236938 2025-06-29 21:28:13.750340 :AB5FFE3A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 21:28:13.750340 :AB5FFE3B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 21:28:13.750341 :AB5FFE3C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 21:28:13.750341 :AB5FFE3D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 21:28:13.750342 :AB5FFE3E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 21:28:13.750833 :AB5FFE3F: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-06-29 21:28:13.750882 :AB5FFE48: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-06-29 21:38:14.594052 :AB60C5C0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 21:38:14.926798 :AB60C61C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 21:38:14.922 2025-06-29 21:38:14.926800 :AB60C61D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13448 pso_num=25 pso_serial#=156 2025-06-29 21:38:14.926967 :AB60C61E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13448 osp_idx=23 osp_ver=175963 osp_pg=0 (spawn #335784) 2025-06-29 21:38:14.926967 :AB60C61F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 21:38:14.926967 :AB60C620:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=241 time=4208838110 2025-06-29 21:38:14.926968 :AB60C621:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 21:38:14.926969 :AB60C622:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 21:38:14.926969 :AB60C623:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 21:38:14.926969 :AB60C624:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 21:38:14.926969 :AB60C625:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 21:38:14.927480 :AB60C626: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-06-29 21:38:14.927526 :AB60C62D: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-06-29 21:48:15.730321 :AB618CAC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 21:48:16.219513 :AB618D49:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 21:48:16.215 2025-06-29 21:48:16.219515 :AB618D4A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18100 pso_num=25 pso_serial#=157 2025-06-29 21:48:16.219645 :AB618D4B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18100 osp_idx=23 osp_ver=175964 osp_pg=0 (spawn #335807) 2025-06-29 21:48:16.219646 :AB618D4C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 21:48:16.219646 :AB618D4D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=242 time=4209439407 2025-06-29 21:48:16.219647 :AB618D4E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 21:48:16.219647 :AB618D4F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 21:48:16.219647 :AB618D50:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 21:48:16.219648 :AB618D51:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 21:48:16.219648 :AB618D52:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 21:48:16.220187 :AB618D53: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-06-29 21:48:16.220233 :AB618D5A: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-06-29 21:58:17.055134 :AB6253E4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 21:58:17.491808 :AB625476:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 21:58:17.487 2025-06-29 21:58:17.491810 :AB625477:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15576 pso_num=25 pso_serial#=158 2025-06-29 21:58:17.491953 :AB625478:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15576 osp_idx=23 osp_ver=175965 osp_pg=0 (spawn #335829) 2025-06-29 21:58:17.491954 :AB625479:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 21:58:17.491954 :AB62547A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=243 time=4210040688 2025-06-29 21:58:17.491954 :AB62547B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 21:58:17.491955 :AB62547C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 21:58:17.491955 :AB62547D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 21:58:17.491955 :AB62547E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 21:58:17.491956 :AB62547F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 21:58:17.492448 :AB625480: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-06-29 21:58:17.492495 :AB625489: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-06-29 22:08:18.311091 :AB6323F5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 22:08:18.794000 :AB63241F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 22:08:18.780 2025-06-29 22:08:18.794002 :AB632420:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=5276 pso_num=25 pso_serial#=159 2025-06-29 22:08:18.794140 :AB632421:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=5276 (legacy spawn) 2025-06-29 22:08:18.800602 :AB632422:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 22:08:18.800773 :AB632427: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-06-29 22:08:18.801568 :AB63242C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 22:08:18.810239 :AB63242F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 22:08:18.795 2025-06-29 22:08:18.810241 :AB632430:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12424 pso_num=25 pso_serial#=160 2025-06-29 22:08:18.810380 :AB632431:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=12424 (legacy spawn) 2025-06-29 22:08:18.816932 :AB63245A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 22:08:18.817094 :AB632463: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-06-29 22:08:18.817880 :AB632464:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-29 22:08:18.831347 :AB6324B0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-29 22:08:18.827 2025-06-29 22:08:18.831349 :AB6324B1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9288 pso_num=25 pso_serial#=161 2025-06-29 22:08:18.831486 :AB6324B2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9288 osp_idx=23 osp_ver=175968 osp_pg=0 (spawn #335855) 2025-06-29 22:08:18.831487 :AB6324B3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 22:08:18.831488 :AB6324B4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=244 time=4210642016 2025-06-29 22:08:18.831488 :AB6324B5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 22:08:18.831489 :AB6324B6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 22:08:18.831489 :AB6324B7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 22:08:18.831490 :AB6324B8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 22:08:18.831490 :AB6324B9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 22:08:18.831999 :AB6324BA: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-06-29 22:08:18.832041 :AB6324C2: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 9288, W000)