Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250603081945\orcl_w000_10448_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:37028M/63366M, Ph+PgF:43858M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 10448, image: ORACLE.EXE (W000) *** 2025-06-03 08:19:45.773 *** SESSION ID:(201.54419) 2025-06-03 08:19:45.773 *** 2025-06-03 08:19:45.773 Process diagnostic dump for ORACLE.EXE (W000), OS id=10448, pid: 25, proc_ser: 135, sid: 201, sess_ser: 54419 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=232 seq_num=233 snap_id=1 wait times: snap=1.003722 sec, exc=1.003722 sec, total=1.003722 sec wait times: max=5.000000 sec, heur=11 min 54 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.000037 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=231 seq_num=232 snap_id=1 wait times: snap=5.003233 sec, exc=5.003233 sec, total=5.003233 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=230 seq_num=231 snap_id=1 wait times: snap=5.000450 sec, exc=5.000450 sec, total=5.000450 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000039 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=229 seq_num=230 snap_id=1 wait times: snap=5.015451 sec, exc=5.015451 sec, total=5.015451 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=228 seq_num=229 snap_id=1 wait times: snap=5.014701 sec, exc=5.014701 sec, total=5.014701 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=227 seq_num=228 snap_id=1 wait times: snap=5.010163 sec, exc=5.010163 sec, total=5.010163 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000017 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=226 seq_num=227 snap_id=1 wait times: snap=5.011802 sec, exc=5.011802 sec, total=5.011802 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=225 seq_num=226 snap_id=1 wait times: snap=5.001272 sec, exc=5.001272 sec, total=5.001272 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=224 seq_num=225 snap_id=1 wait times: snap=5.000299 sec, exc=5.000299 sec, total=5.000299 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=223 seq_num=224 snap_id=1 wait times: snap=5.014977 sec, exc=5.014977 sec, total=5.014977 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=222 seq_num=223 snap_id=1 wait times: snap=5.001864 sec, exc=5.001864 sec, total=5.001864 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time Sampled Session History of session 201 serial 54419 --------------------------------------------------- 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, 08:17:45 - 08:19:45] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-03 08:19:45.773 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 10448, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-03 05:40:18.382202 :9F9F35ED:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 05:40:18.737251 :9F9F3625:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 05:40:18.737 2025-06-03 05:40:18.737253 :9F9F3626:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12620 pso_num=25 pso_serial#=122 2025-06-03 05:40:18.737412 :9F9F3627:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12620 osp_idx=23 osp_ver=142014 osp_pg=0 (spawn #246888) 2025-06-03 05:40:18.737413 :9F9F3628: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-03 05:40:18.737413 :9F9F3629:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=171 time=1904977391 2025-06-03 05:40:18.737413 :9F9F362A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 05:40:18.737414 :9F9F362B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 05:40:18.737414 :9F9F362C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 05:40:18.737414 :9F9F362D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 05:40:18.737415 :9F9F362E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 05:40:18.737961 :9F9F362F: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-03 05:40:18.738011 :9F9F3636: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-03 05:50:19.695785 :9F9FFEE5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 05:50:19.997399 :9F9FFF21:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 05:50:19.992 2025-06-03 05:50:19.997401 :9F9FFF22:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14916 pso_num=25 pso_serial#=123 2025-06-03 05:50:19.997534 :9F9FFF23:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14916 osp_idx=23 osp_ver=142015 osp_pg=0 (spawn #246911) 2025-06-03 05:50:19.997535 :9F9FFF24: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-03 05:50:19.997535 :9F9FFF25:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=172 time=1905578641 2025-06-03 05:50:19.997536 :9F9FFF26:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 05:50:19.997536 :9F9FFF27:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 05:50:19.997536 :9F9FFF28:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 05:50:19.997537 :9F9FFF29:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 05:50:19.997537 :9F9FFF2A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 05:50:19.998016 :9F9FFF2B: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-03 05:50:19.998060 :9F9FFF34: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-03 06:00:20.926987 :9FA0C652:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 06:00:21.275411 :9FA0C6B3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 06:00:21.270 2025-06-03 06:00:21.275413 :9FA0C6B4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15752 pso_num=25 pso_serial#=124 2025-06-03 06:00:21.275543 :9FA0C6B5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15752 osp_idx=23 osp_ver=142016 osp_pg=0 (spawn #246934) 2025-06-03 06:00:21.275544 :9FA0C6B6: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-03 06:00:21.275544 :9FA0C6B7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=173 time=1906179922 2025-06-03 06:00:21.275545 :9FA0C6B8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 06:00:21.275545 :9FA0C6B9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 06:00:21.275546 :9FA0C6BA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 06:00:21.275546 :9FA0C6BB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 06:00:21.275547 :9FA0C6BC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 06:00:21.276034 :9FA0C6BD: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-03 06:00:21.276081 :9FA0C6C7: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-03 06:07:50.826558 :9FA16258: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-03 06:07:50.828809 :9FA1625A: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-03 06:10:22.465329 :9FA193D6: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-03 06:20:23.345385 :9FA25E05:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 06:20:23.771767 :9FA25E5E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 06:20:23.767 2025-06-03 06:20:23.771769 :9FA25E5F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15020 pso_num=25 pso_serial#=125 2025-06-03 06:20:23.771903 :9FA25E60:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15020 osp_idx=23 osp_ver=142017 osp_pg=0 (spawn #246981) 2025-06-03 06:20:23.771903 :9FA25E61: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-03 06:20:23.771904 :9FA25E62:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=174 time=1907382422 2025-06-03 06:20:23.771904 :9FA25E63:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 06:20:23.771905 :9FA25E64:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 06:20:23.771905 :9FA25E65:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 06:20:23.771905 :9FA25E66:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 06:20:23.771906 :9FA25E67:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 06:20:23.772402 :9FA25E68: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-03 06:20:23.772446 :9FA25E70: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-03 06:30:24.697950 :9FA324DB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 06:30:25.186989 :9FA3251C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 06:30:25.182 2025-06-03 06:30:25.186991 :9FA3251D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14564 pso_num=25 pso_serial#=126 2025-06-03 06:30:25.187127 :9FA3251E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14564 osp_idx=23 osp_ver=142018 osp_pg=0 (spawn #247004) 2025-06-03 06:30:25.187128 :9FA3251F: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-03 06:30:25.187128 :9FA32520:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=175 time=1907983829 2025-06-03 06:30:25.187129 :9FA32521:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 06:30:25.187129 :9FA32522:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 06:30:25.187129 :9FA32523:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 06:30:25.187130 :9FA32524:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 06:30:25.187131 :9FA32525:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 06:30:25.187663 :9FA32526: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-03 06:30:25.187707 :9FA3252E: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-03 06:40:26.069972 :9FA3EDAC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 06:40:26.543379 :9FA3EDE4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 06:40:26.539 2025-06-03 06:40:26.543381 :9FA3EDE5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15460 pso_num=25 pso_serial#=127 2025-06-03 06:40:26.543521 :9FA3EDE6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15460 osp_idx=23 osp_ver=142019 osp_pg=0 (spawn #247026) 2025-06-03 06:40:26.543522 :9FA3EDE7: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-03 06:40:26.543523 :9FA3EDE8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=176 time=1908585188 2025-06-03 06:40:26.543523 :9FA3EDE9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 06:40:26.543524 :9FA3EDEA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 06:40:26.543524 :9FA3EDEB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 06:40:26.543524 :9FA3EDEC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 06:40:26.543525 :9FA3EDED:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 06:40:26.544027 :9FA3EDEE: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-03 06:40:26.544075 :9FA3EDF5: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-03 06:50:27.363936 :9FA4B64A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 06:50:27.915356 :9FA4B69A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 06:50:27.910 2025-06-03 06:50:27.915358 :9FA4B69B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8548 pso_num=25 pso_serial#=128 2025-06-03 06:50:27.915493 :9FA4B69C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8548 osp_idx=23 osp_ver=142020 osp_pg=0 (spawn #247050) 2025-06-03 06:50:27.915493 :9FA4B69D: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-03 06:50:27.915494 :9FA4B69E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=177 time=1909186563 2025-06-03 06:50:27.915494 :9FA4B69F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 06:50:27.915495 :9FA4B6A0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 06:50:27.915495 :9FA4B6A1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 06:50:27.915495 :9FA4B6A2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 06:50:27.915496 :9FA4B6A3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 06:50:27.916040 :9FA4B6A4: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-03 06:50:27.916084 :9FA4B6AC: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-03 07:00:28.748701 :9FA580C2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 07:00:29.315535 :9FA580F8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 07:00:29.311 2025-06-03 07:00:29.315537 :9FA580F9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15184 pso_num=25 pso_serial#=129 2025-06-03 07:00:29.315675 :9FA580FA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15184 osp_idx=23 osp_ver=142021 osp_pg=0 (spawn #247073) 2025-06-03 07:00:29.315675 :9FA580FB: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-03 07:00:29.315676 :9FA580FC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=178 time=1909787969 2025-06-03 07:00:29.315676 :9FA580FD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 07:00:29.315677 :9FA580FE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 07:00:29.315677 :9FA580FF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 07:00:29.315677 :9FA58100:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 07:00:29.315677 :9FA58101:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 07:00:29.316155 :9FA58102: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-03 07:00:29.316204 :9FA58108: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-03 07:10:30.227731 :9FA64F76:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 07:10:30.732517 :9FA64FAD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 07:10:30.728 2025-06-03 07:10:30.732519 :9FA64FAE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14600 pso_num=25 pso_serial#=130 2025-06-03 07:10:30.732666 :9FA64FAF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14600 osp_idx=23 osp_ver=142022 osp_pg=0 (spawn #247098) 2025-06-03 07:10:30.732666 :9FA64FB0: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-03 07:10:30.732667 :9FA64FB1:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=179 time=1910389375 2025-06-03 07:10:30.732667 :9FA64FB2:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 07:10:30.732668 :9FA64FB3:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 07:10:30.732668 :9FA64FB4:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 07:10:30.732668 :9FA64FB5:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 07:10:30.732669 :9FA64FB6:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 07:10:30.733174 :9FA64FB7: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-03 07:10:30.733217 :9FA64FBF: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-03 07:20:31.584250 :9FA7187F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 07:20:32.104590 :9FA718BE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 07:20:32.099 2025-06-03 07:20:32.104592 :9FA718BF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13464 pso_num=25 pso_serial#=131 2025-06-03 07:20:32.104727 :9FA718C0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13464 osp_idx=23 osp_ver=142023 osp_pg=0 (spawn #247121) 2025-06-03 07:20:32.104728 :9FA718C1: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-03 07:20:32.104729 :9FA718C2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=180 time=1910990750 2025-06-03 07:20:32.104729 :9FA718C3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 07:20:32.104729 :9FA718C4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 07:20:32.104730 :9FA718C5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 07:20:32.104730 :9FA718C6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 07:20:32.104730 :9FA718C7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 07:20:32.105223 :9FA718C8: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-03 07:20:32.105269 :9FA718D0: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-03 07:30:33.042680 :9FA7DE6D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 07:30:33.578564 :9FA7DEB2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 07:30:33.574 2025-06-03 07:30:33.578566 :9FA7DEB3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14600 pso_num=25 pso_serial#=132 2025-06-03 07:30:33.578708 :9FA7DEB4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14600 osp_idx=23 osp_ver=142024 osp_pg=0 (spawn #247144) 2025-06-03 07:30:33.578709 :9FA7DEB5: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-03 07:30:33.578709 :9FA7DEB6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=181 time=1911592219 2025-06-03 07:30:33.578710 :9FA7DEB7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 07:30:33.578710 :9FA7DEB8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 07:30:33.578710 :9FA7DEB9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 07:30:33.578711 :9FA7DEBA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 07:30:33.578711 :9FA7DEBB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 07:30:33.579208 :9FA7DEBC: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-03 07:30:33.579252 :9FA7DEC3: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-03 07:40:34.446114 :9FA8A25B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 07:40:34.966445 :9FA8A293:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 07:40:34.962 2025-06-03 07:40:34.966447 :9FA8A294:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14692 pso_num=25 pso_serial#=133 2025-06-03 07:40:34.966590 :9FA8A295:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14692 osp_idx=23 osp_ver=142025 osp_pg=0 (spawn #247166) 2025-06-03 07:40:34.966590 :9FA8A296: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-03 07:40:34.966591 :9FA8A297:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=182 time=1912193610 2025-06-03 07:40:34.966591 :9FA8A298:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 07:40:34.966591 :9FA8A299:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 07:40:34.966592 :9FA8A29A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 07:40:34.966592 :9FA8A29B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 07:40:34.966592 :9FA8A29C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 07:40:34.967093 :9FA8A29D: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-03 07:40:34.967139 :9FA8A2A5: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-03 07:50:36.010695 :9FA96512:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 07:50:36.359776 :9FA96558:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 07:50:36.354 2025-06-03 07:50:36.359779 :9FA96559:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13732 pso_num=25 pso_serial#=134 2025-06-03 07:50:36.359926 :9FA9655A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13732 osp_idx=23 osp_ver=142026 osp_pg=0 (spawn #247189) 2025-06-03 07:50:36.359928 :9FA9655B: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-03 07:50:36.359928 :9FA9655C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=183 time=1912795000 2025-06-03 07:50:36.359929 :9FA9655D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 07:50:36.359929 :9FA9655E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 07:50:36.359930 :9FA9655F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 07:50:36.359930 :9FA96560:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 07:50:36.359931 :9FA96561:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 07:50:36.360548 :9FA96562: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-03 07:50:36.360622 :9FA9656C: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-03 08:00:37.273166 :9FAA2996:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-03 08:00:37.662885 :9FAA29D2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-03 08:00:37.658 2025-06-03 08:00:37.662886 :9FAA29D3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10448 pso_num=25 pso_serial#=135 2025-06-03 08:00:37.663025 :9FAA29D4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10448 osp_idx=23 osp_ver=142027 osp_pg=0 (spawn #247212) 2025-06-03 08:00:37.663026 :9FAA29D5: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-03 08:00:37.663026 :9FAA29D6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=184 time=1913396313 2025-06-03 08:00:37.663026 :9FAA29D7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-03 08:00:37.663027 :9FAA29D8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-03 08:00:37.663027 :9FAA29D9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-03 08:00:37.663027 :9FAA29DA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-03 08:00:37.663028 :9FAA29DB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-03 08:00:37.663518 :9FAA29DC: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-03 08:00:37.663565 :9FAA29E3: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-03 08:07:51.444989 :9FAABEF5: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-03 08:10:38.966880 :9FAAF7B3: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: 10448, W000)