Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250524220216\orcl_w000_12532_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:37287M/63366M, Ph+PgF:44318M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 12532, image: ORACLE.EXE (W000) *** 2025-05-24 22:02:16.568 *** SESSION ID:(201.58029) 2025-05-24 22:02:16.568 *** 2025-05-24 22:02:16.568 Process diagnostic dump for ORACLE.EXE (W000), OS id=12532, pid: 25, proc_ser: 34, sid: 201, sess_ser: 58029 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=3.972856 sec, exc=3.972856 sec, total=3.972856 sec wait times: max=5.000000 sec, heur=1 min 44 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=20 seq_num=21 snap_id=1 wait times: snap=5.015548 sec, exc=5.015548 sec, total=5.015548 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.004625 sec, exc=5.004625 sec, total=5.004625 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=5.014727 sec, exc=5.014727 sec, total=5.014727 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=5.015268 sec, exc=5.015268 sec, total=5.015268 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=5.003386 sec, exc=5.003386 sec, total=5.003386 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=5.014198 sec, exc=5.014198 sec, total=5.014198 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=14 seq_num=15 snap_id=1 wait times: snap=5.009583 sec, exc=5.009583 sec, total=5.009583 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=5.004620 sec, exc=5.004620 sec, total=5.004620 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=5.004608 sec, exc=5.004608 sec, total=5.004608 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=11 seq_num=12 snap_id=1 wait times: snap=5.004607 sec, exc=5.004607 sec, total=5.004607 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time Sampled Session History of session 201 serial 58029 --------------------------------------------------- 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 --------------------------------------------------- [105 samples, 22:00:32 - 22:02:16] idle wait at each sample [session created at: 22:00:32] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-24 22:02:16.568 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 12532, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-24 19:50:14.641024 :9B7EE471:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 19:50:15.024881 :9B7EE4C4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 19:50:15.019 2025-05-24 19:50:15.024883 :9B7EE4C5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12400 pso_num=25 pso_serial#=20 2025-05-24 19:50:15.025022 :9B7EE4C6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12400 osp_idx=23 osp_ver=114259 osp_pg=0 (spawn #215536) 2025-05-24 19:50:15.025023 :9B7EE4C7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 19:50:15.025023 :9B7EE4C8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=161 time=1091987282 2025-05-24 19:50:15.025024 :9B7EE4C9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 19:50:15.025024 :9B7EE4CA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 19:50:15.025024 :9B7EE4CB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 19:50:15.025025 :9B7EE4CC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 19:50:15.025025 :9B7EE4CD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 19:50:15.025537 :9B7EE4CE: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-05-24 19:50:15.025587 :9B7EE4D7: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-05-24 20:00:16.030551 :9B7FA93C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 20:00:16.363295 :9B7FA990:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 20:00:16.358 2025-05-24 20:00:16.363297 :9B7FA991:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9168 pso_num=25 pso_serial#=21 2025-05-24 20:00:16.363431 :9B7FA992:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9168 osp_idx=23 osp_ver=114260 osp_pg=0 (spawn #215559) 2025-05-24 20:00:16.363432 :9B7FA993:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 20:00:16.363432 :9B7FA994:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=162 time=1092588610 2025-05-24 20:00:16.363432 :9B7FA995:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 20:00:16.363433 :9B7FA996:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 20:00:16.363433 :9B7FA997:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 20:00:16.363433 :9B7FA998:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 20:00:16.363434 :9B7FA999:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 20:00:16.363912 :9B7FA99A: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-05-24 20:00:16.363956 :9B7FA9A2: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-05-24 20:06:39.009147 :9B802DF1: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-05-24 20:10:17.608708 :9B80742D: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-05-24 20:10:17.608750 :9B807434: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-05-24 20:10:17.608760 :9B807439: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-05-24 20:10:17.608760 :9B80743A:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=9, exc=9, tot=9 2025-05-24 20:20:18.706050 :9B813A2C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 20:20:19.007455 :9B813A6E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 20:20:19.002 2025-05-24 20:20:19.007457 :9B813A6F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12156 pso_num=25 pso_serial#=22 2025-05-24 20:20:19.007596 :9B813A70:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12156 osp_idx=23 osp_ver=114261 osp_pg=0 (spawn #215606) 2025-05-24 20:20:19.007597 :9B813A71:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 20:20:19.007598 :9B813A72:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=163 time=1093791266 2025-05-24 20:20:19.007598 :9B813A73:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 20:20:19.007599 :9B813A74:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 20:20:19.007599 :9B813A75:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 20:20:19.007599 :9B813A76:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 20:20:19.007600 :9B813A77:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 20:20:19.008102 :9B813A78: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-05-24 20:20:19.008146 :9B813A7F: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-05-24 20:30:19.993977 :9B81FDB2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 20:30:20.279894 :9B81FDFB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 20:30:20.275 2025-05-24 20:30:20.279896 :9B81FDFC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13744 pso_num=25 pso_serial#=23 2025-05-24 20:30:20.280039 :9B81FDFD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13744 osp_idx=23 osp_ver=114262 osp_pg=0 (spawn #215629) 2025-05-24 20:30:20.280040 :9B81FDFE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 20:30:20.280041 :9B81FDFF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=164 time=1094392532 2025-05-24 20:30:20.280041 :9B81FE00:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 20:30:20.280042 :9B81FE01:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 20:30:20.280042 :9B81FE02:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 20:30:20.280043 :9B81FE03:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 20:30:20.280043 :9B81FE04:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 20:30:20.280548 :9B81FE05: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-05-24 20:30:20.280598 :9B81FE0F: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-05-24 20:40:21.268166 :9B82C17B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 20:40:21.491733 :9B82C1C9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 20:40:21.486 2025-05-24 20:40:21.491735 :9B82C1CA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9288 pso_num=25 pso_serial#=24 2025-05-24 20:40:21.491922 :9B82C1CB:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9288 osp_idx=23 osp_ver=114263 osp_pg=0 (spawn #215651) 2025-05-24 20:40:21.491922 :9B82C1CC:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 20:40:21.491922 :9B82C1CD:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=165 time=1094993750 2025-05-24 20:40:21.491923 :9B82C1CE:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 20:40:21.491923 :9B82C1CF:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 20:40:21.491924 :9B82C1D0:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 20:40:21.491924 :9B82C1D1:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 20:40:21.491925 :9B82C1D2:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 20:40:21.492428 :9B82C1D3: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-05-24 20:40:21.492479 :9B82C1DB: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-05-24 20:50:22.405695 :9B838557:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 20:50:22.754152 :9B8385C5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 20:50:22.749 2025-05-24 20:50:22.754154 :9B8385C6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9660 pso_num=25 pso_serial#=25 2025-05-24 20:50:22.754290 :9B8385C7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9660 osp_idx=23 osp_ver=114264 osp_pg=0 (spawn #215674) 2025-05-24 20:50:22.754290 :9B8385C8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 20:50:22.754291 :9B8385C9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=166 time=1095595000 2025-05-24 20:50:22.754291 :9B8385CA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 20:50:22.754292 :9B8385CB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 20:50:22.754292 :9B8385CC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 20:50:22.754293 :9B8385CD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 20:50:22.754293 :9B8385CE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 20:50:22.754792 :9B8385CF: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-05-24 20:50:22.754835 :9B8385D6: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-05-24 21:00:23.742188 :9B844B43:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 21:00:24.028119 :9B844B8A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 21:00:24.023 2025-05-24 21:00:24.028121 :9B844B8B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7276 pso_num=25 pso_serial#=26 2025-05-24 21:00:24.028258 :9B844B8C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7276 osp_idx=23 osp_ver=114265 osp_pg=0 (spawn #215699) 2025-05-24 21:00:24.028259 :9B844B8D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 21:00:24.028259 :9B844B8E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=167 time=1096196282 2025-05-24 21:00:24.028260 :9B844B8F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 21:00:24.028260 :9B844B90:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 21:00:24.028261 :9B844B91:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 21:00:24.028261 :9B844B92:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 21:00:24.028262 :9B844B93:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 21:00:24.028780 :9B844B94: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-05-24 21:00:24.028828 :9B844B9C: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-05-24 21:10:25.027551 :9B851893:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 21:10:25.391633 :9B8518CF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 21:10:25.387 2025-05-24 21:10:25.391635 :9B8518D0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12032 pso_num=25 pso_serial#=27 2025-05-24 21:10:25.391773 :9B8518D1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12032 osp_idx=23 osp_ver=114266 osp_pg=0 (spawn #215720) 2025-05-24 21:10:25.391774 :9B8518D2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 21:10:25.391774 :9B8518D3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=168 time=1096797641 2025-05-24 21:10:25.391774 :9B8518D4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 21:10:25.391775 :9B8518D5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 21:10:25.391775 :9B8518D6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 21:10:25.391775 :9B8518D7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 21:10:25.391775 :9B8518D8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 21:10:25.392269 :9B8518D9: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-05-24 21:10:25.392311 :9B8518E2: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-05-24 21:20:26.373990 :9B85DE0E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 21:20:26.701305 :9B85DE45:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 21:20:26.696 2025-05-24 21:20:26.701307 :9B85DE46:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13148 pso_num=25 pso_serial#=28 2025-05-24 21:20:26.701438 :9B85DE47:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13148 osp_idx=23 osp_ver=114267 osp_pg=0 (spawn #215743) 2025-05-24 21:20:26.701440 :9B85DE48:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 21:20:26.701440 :9B85DE49:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=169 time=1097398954 2025-05-24 21:20:26.701441 :9B85DE4A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 21:20:26.701441 :9B85DE4B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 21:20:26.701442 :9B85DE4C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 21:20:26.701442 :9B85DE4D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 21:20:26.701442 :9B85DE4E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 21:20:26.701932 :9B85DE4F: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-05-24 21:20:26.701980 :9B85DE59: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-05-24 21:30:27.633011 :9B86A3CF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 21:30:27.724178 :9B86A3D2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 21:30:27.711 2025-05-24 21:30:27.724180 :9B86A3D3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13708 pso_num=25 pso_serial#=29 2025-05-24 21:30:27.724320 :9B86A3D4:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=13708 (legacy spawn) 2025-05-24 21:30:27.730755 :9B86A3D5: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-05-24 21:30:27.730929 :9B86A3DD: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-05-24 21:30:27.731779 :9B86A3DE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 21:30:27.740354 :9B86A3E1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 21:30:27.726 2025-05-24 21:30:27.740356 :9B86A3E2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14196 pso_num=25 pso_serial#=30 2025-05-24 21:30:27.740490 :9B86A3E3:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=14196 (legacy spawn) 2025-05-24 21:30:27.746898 :9B86A3E4: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-05-24 21:30:27.747059 :9B86A3ED: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-05-24 21:30:27.747872 :9B86A3EE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 21:30:28.059467 :9B86A428:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 21:30:28.054 2025-05-24 21:30:28.059469 :9B86A429:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9092 pso_num=25 pso_serial#=31 2025-05-24 21:30:28.059606 :9B86A42A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9092 osp_idx=23 osp_ver=114270 osp_pg=0 (spawn #215766) 2025-05-24 21:30:28.059607 :9B86A42B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 21:30:28.059607 :9B86A42C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=170 time=1098000313 2025-05-24 21:30:28.059607 :9B86A42D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 21:30:28.059608 :9B86A42E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 21:30:28.059610 :9B86A42F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 21:30:28.059610 :9B86A430:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 21:30:28.059610 :9B86A431:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 21:30:28.060098 :9B86A432: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-05-24 21:30:28.060142 :9B86A439: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-05-24 21:40:28.966120 :9B876865:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 21:40:29.486400 :9B8768B1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 21:40:29.481 2025-05-24 21:40:29.486402 :9B8768B2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13668 pso_num=25 pso_serial#=32 2025-05-24 21:40:29.486542 :9B8768B3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13668 osp_idx=23 osp_ver=114271 osp_pg=0 (spawn #215788) 2025-05-24 21:40:29.486542 :9B8768B4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 21:40:29.486543 :9B8768B5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=171 time=1098601735 2025-05-24 21:40:29.486543 :9B8768B6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 21:40:29.486543 :9B8768B7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 21:40:29.486544 :9B8768B8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 21:40:29.486544 :9B8768B9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 21:40:29.486544 :9B8768BA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 21:40:29.487065 :9B8768BB: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-05-24 21:40:29.487111 :9B8768C2: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-05-24 21:50:30.409959 :9B882E08:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 21:50:30.919917 :9B882E59:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 21:50:30.915 2025-05-24 21:50:30.919920 :9B882E5A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13512 pso_num=25 pso_serial#=33 2025-05-24 21:50:30.920060 :9B882E5B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13512 osp_idx=23 osp_ver=114272 osp_pg=0 (spawn #215811) 2025-05-24 21:50:30.920061 :9B882E5C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 21:50:30.920062 :9B882E5D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=172 time=1099203172 2025-05-24 21:50:30.920062 :9B882E5E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 21:50:30.920063 :9B882E5F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 21:50:30.920063 :9B882E60:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 21:50:30.920064 :9B882E61:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 21:50:30.920064 :9B882E62:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 21:50:30.920572 :9B882E63: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-05-24 21:50:30.920619 :9B882E6B: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-05-24 22:00:31.868111 :9B88F5AE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-24 22:00:32.419718 :9B88F5F5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-24 22:00:32.414 2025-05-24 22:00:32.419721 :9B88F5F6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12532 pso_num=25 pso_serial#=34 2025-05-24 22:00:32.419855 :9B88F5F7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12532 osp_idx=23 osp_ver=114273 osp_pg=0 (spawn #215836) 2025-05-24 22:00:32.419856 :9B88F5F8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-24 22:00:32.419856 :9B88F5F9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=173 time=1099804672 2025-05-24 22:00:32.419856 :9B88F5FA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-24 22:00:32.419857 :9B88F5FB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-24 22:00:32.419857 :9B88F5FC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-24 22:00:32.419857 :9B88F5FD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-24 22:00:32.419857 :9B88F5FE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-24 22:00:32.420345 :9B88F5FF: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-05-24 22:00:32.420390 :9B88F609: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: 12532, W000)