Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250601220820\orcl_w000_11580_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:37140M/63366M, Ph+PgF:43995M/72582M 
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 22
Windows thread id: 11580, image: ORACLE.EXE (W000)


*** 2025-06-01 22:08:20.946
*** SESSION ID:(177.17315) 2025-06-01 22:08:20.946
 

*** 2025-06-01 22:08:20.946
Process diagnostic dump for ORACLE.EXE (W000), OS id=11580,
pid: 22, proc_ser: 15, sid: 177, sess_ser: 17315 
-------------------------------------------------------------------------------
current sql: <none>
Current Wait Stack:
 0: waiting for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=27 seq_num=28 snap_id=1
    wait times: snap=3.576289 sec, exc=3.576289 sec, total=3.576289 sec
    wait times: max=5.000000 sec, heur=2 min 13 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.000022 sec since current wait
 0: 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.009807 sec, exc=5.009807 sec, total=5.009807 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000020 sec of elapsed time
 1: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=25 seq_num=26 snap_id=1
    wait times: snap=5.003231 sec, exc=5.003231 sec, total=5.003231 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000026 sec of elapsed time
 2: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=24 seq_num=25 snap_id=1
    wait times: snap=5.000278 sec, exc=5.000278 sec, total=5.000278 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000023 sec of elapsed time
 3: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=23 seq_num=24 snap_id=1
    wait times: snap=5.004838 sec, exc=5.004838 sec, total=5.004838 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000023 sec of elapsed time
 4: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=22 seq_num=23 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.000024 sec of elapsed time
 5: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=21 seq_num=22 snap_id=1
    wait times: snap=5.014734 sec, exc=5.014734 sec, total=5.014734 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000029 sec of elapsed time
 6: 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.004634 sec, exc=5.004634 sec, total=5.004634 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000024 sec of elapsed time
 7: 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.004637 sec, exc=5.004637 sec, total=5.004637 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000018 sec of elapsed time
 8: 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.008314 sec, exc=5.008314 sec, total=5.008314 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000026 sec of elapsed time
 9: 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.012551 sec, exc=5.012551 sec, total=5.012551 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000028 sec of elapsed time
Sampled Session History of session 177 serial 17315
---------------------------------------------------
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:06:20 - 22:08:20]
    idle wait at each sample
-------------------------------------------------------------------------------
Process diagnostic dump actual duration=0.000000 sec
  (max dump time=30.000000 sec)

*** 2025-06-01 22:08:20.946
 
-------------------------------------------------------------------------------
Trace Bucket Dump Begin: default bucket for process 22 (osid: 11580, W000)
TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA
-------------------------------------------------------------------------------
2025-06-01 19:33:37.758994 :9F0035F8:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 19:35:46.742425 :9F0060AD:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 19:45:47.594874 :9F012708:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 19:45:48.083751 :9F012756:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 19:45:48.079
2025-06-01 19:45:48.083753 :9F012757:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13760 pso_num=22 pso_serial#=2
2025-06-01 19:45:48.083897 :9F012758:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13760 osp_idx=0 osp_ver=254309 osp_pg=0 (spawn #242179)
2025-06-01 19:45:48.083898 :9F012759:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 19:45:48.083899 :9F01275A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=201 time=1782906735
2025-06-01 19:45:48.083899 :9F01275B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 19:45:48.083900 :9F01275C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 19:45:48.083900 :9F01275D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 19:45:48.083900 :9F01275E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 19:45:48.083901 :9F01275F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 19:45:48.084397 :9F012760:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 19:45:48.084454 :9F012766:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 19:55:49.106592 :9F01EC13:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 19:55:49.465039 :9F01EC5A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 19:55:49.460
2025-06-01 19:55:49.465041 :9F01EC5B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13976 pso_num=22 pso_serial#=3
2025-06-01 19:55:49.465176 :9F01EC5C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13976 osp_idx=0 osp_ver=254310 osp_pg=0 (spawn #242202)
2025-06-01 19:55:49.465177 :9F01EC5D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 19:55:49.465177 :9F01EC5E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=202 time=1783508110
2025-06-01 19:55:49.465178 :9F01EC5F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 19:55:49.465178 :9F01EC60:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 19:55:49.465179 :9F01EC61:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 19:55:49.465179 :9F01EC62:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 19:55:49.465179 :9F01EC63:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 19:55:49.465673 :9F01EC64:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 19:55:49.465730 :9F01EC6A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 20:05:50.478231 :9F02B38F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 20:05:50.951692 :9F02B3E5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 20:05:50.947
2025-06-01 20:05:50.951694 :9F02B3E6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13916 pso_num=22 pso_serial#=4
2025-06-01 20:05:50.951839 :9F02B3E7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13916 osp_idx=0 osp_ver=254311 osp_pg=0 (spawn #242227)
2025-06-01 20:05:50.951839 :9F02B3E8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 20:05:50.951840 :9F02B3E9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=203 time=1784109594
2025-06-01 20:05:50.951840 :9F02B3EA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 20:05:50.951840 :9F02B3EB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 20:05:50.951841 :9F02B3EC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 20:05:50.951841 :9F02B3ED:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 20:05:50.951841 :9F02B3EE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 20:05:50.952354 :9F02B3EF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 20:05:50.952403 :9F02B3F6:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 20:15:51.869881 :9F03822D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 20:15:52.322044 :9F038276:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 20:15:52.317
2025-06-01 20:15:52.322046 :9F038277:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8784 pso_num=22 pso_serial#=5
2025-06-01 20:15:52.322187 :9F038278:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8784 osp_idx=0 osp_ver=254312 osp_pg=0 (spawn #242250)
2025-06-01 20:15:52.322187 :9F038279:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 20:15:52.322188 :9F03827A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=204 time=1784710969
2025-06-01 20:15:52.322188 :9F03827B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 20:15:52.322189 :9F03827C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 20:15:52.322189 :9F03827D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 20:15:52.322189 :9F03827E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 20:15:52.322190 :9F03827F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 20:15:52.322701 :9F038280:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 20:15:52.322751 :9F038287:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 20:25:53.193929 :9F044738:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 20:25:53.839126 :9F04478E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 20:25:53.834
2025-06-01 20:25:53.839128 :9F04478F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14316 pso_num=22 pso_serial#=6
2025-06-01 20:25:53.839260 :9F044790:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14316 osp_idx=0 osp_ver=254313 osp_pg=0 (spawn #242273)
2025-06-01 20:25:53.839261 :9F044791:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 20:25:53.839261 :9F044792:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=205 time=1785312485
2025-06-01 20:25:53.839261 :9F044793:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 20:25:53.839262 :9F044794:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 20:25:53.839262 :9F044795:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 20:25:53.839262 :9F044796:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 20:25:53.839263 :9F044797:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 20:25:53.839758 :9F044798:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 20:25:53.839811 :9F04479F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 20:35:54.742731 :9F050CD4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 20:35:55.231832 :9F050D2F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 20:35:55.227
2025-06-01 20:35:55.231834 :9F050D30:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10948 pso_num=22 pso_serial#=7
2025-06-01 20:35:55.231978 :9F050D31:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10948 osp_idx=0 osp_ver=254314 osp_pg=0 (spawn #242295)
2025-06-01 20:35:55.231979 :9F050D32:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 20:35:55.231979 :9F050D33:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=206 time=1785913875
2025-06-01 20:35:55.231980 :9F050D34:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 20:35:55.231980 :9F050D35:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 20:35:55.231980 :9F050D36:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 20:35:55.231981 :9F050D37:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 20:35:55.231981 :9F050D38:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 20:35:55.232463 :9F050D39:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 20:35:55.232517 :9F050D3F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 20:45:56.194915 :9F05D144:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 20:45:56.559005 :9F05D190:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 20:45:56.554
2025-06-01 20:45:56.559007 :9F05D191:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15232 pso_num=22 pso_serial#=8
2025-06-01 20:45:56.559143 :9F05D192:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15232 osp_idx=0 osp_ver=254315 osp_pg=0 (spawn #242318)
2025-06-01 20:45:56.559144 :9F05D193:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 20:45:56.559144 :9F05D194:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=207 time=1786515204
2025-06-01 20:45:56.559145 :9F05D195:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 20:45:56.559145 :9F05D196:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 20:45:56.559145 :9F05D197:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 20:45:56.559145 :9F05D198:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 20:45:56.559146 :9F05D199:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 20:45:56.559644 :9F05D19A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 20:45:56.559705 :9F05D1A4:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 20:55:57.458943 :9F0695F4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 20:55:57.963516 :9F06966A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 20:55:57.959
2025-06-01 20:55:57.963518 :9F06966B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10760 pso_num=22 pso_serial#=9
2025-06-01 20:55:57.963651 :9F06966C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10760 osp_idx=0 osp_ver=254316 osp_pg=0 (spawn #242341)
2025-06-01 20:55:57.963652 :9F06966D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 20:55:57.963652 :9F06966E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=208 time=1787116610
2025-06-01 20:55:57.963653 :9F06966F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 20:55:57.963653 :9F069670:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 20:55:57.963653 :9F069671:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 20:55:57.963654 :9F069672:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 20:55:57.963654 :9F069673:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 20:55:57.964140 :9F069674:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 20:55:57.964186 :9F06967C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 21:05:58.847801 :9F07633F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 21:05:59.368662 :9F0763BC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 21:05:59.363
2025-06-01 21:05:59.368664 :9F0763BD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14696 pso_num=22 pso_serial#=10
2025-06-01 21:05:59.368812 :9F0763BE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14696 osp_idx=0 osp_ver=254317 osp_pg=0 (spawn #242366)
2025-06-01 21:05:59.368813 :9F0763BF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 21:05:59.368813 :9F0763C0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=209 time=1787718016
2025-06-01 21:05:59.368814 :9F0763C1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 21:05:59.368814 :9F0763C2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 21:05:59.368815 :9F0763C3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 21:05:59.368815 :9F0763C4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 21:05:59.368815 :9F0763C5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 21:05:59.369388 :9F0763C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 21:05:59.369457 :9F0763D0:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 21:16:00.308485 :9F082B2D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 21:16:00.672512 :9F082B9F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 21:16:00.667
2025-06-01 21:16:00.672515 :9F082BA0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15112 pso_num=22 pso_serial#=11
2025-06-01 21:16:00.672653 :9F082BA1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15112 osp_idx=0 osp_ver=254318 osp_pg=0 (spawn #242389)
2025-06-01 21:16:00.672654 :9F082BA2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 21:16:00.672654 :9F082BA3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=210 time=1788319313
2025-06-01 21:16:00.672655 :9F082BA4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 21:16:00.672655 :9F082BA5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 21:16:00.672655 :9F082BA6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 21:16:00.672656 :9F082BA7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 21:16:00.672656 :9F082BA8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 21:16:00.673192 :9F082BA9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 21:16:00.673236 :9F082BB1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 21:26:01.699469 :9F08F04F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 21:26:02.001051 :9F08F0BA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 21:26:01.996
2025-06-01 21:26:02.001053 :9F08F0BB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11784 pso_num=22 pso_serial#=12
2025-06-01 21:26:02.001194 :9F08F0BC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11784 osp_idx=0 osp_ver=254319 osp_pg=0 (spawn #242412)
2025-06-01 21:26:02.001195 :9F08F0BD:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 21:26:02.001195 :9F08F0BE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=211 time=1788920641
2025-06-01 21:26:02.001195 :9F08F0BF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 21:26:02.001196 :9F08F0C0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 21:26:02.001196 :9F08F0C1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 21:26:02.001197 :9F08F0C2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 21:26:02.001197 :9F08F0C3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 21:26:02.001691 :9F08F0C4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 21:26:02.001737 :9F08F0CC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 21:33:57.526870 :9F098DAB:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 21:36:03.295984 :9F09B77A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 21:46:04.275672 :9F0A7C60:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 21:46:04.608206 :9F0A7CA2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 21:46:04.604
2025-06-01 21:46:04.608208 :9F0A7CA3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7888 pso_num=22 pso_serial#=13
2025-06-01 21:46:04.608343 :9F0A7CA4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7888 osp_idx=0 osp_ver=254320 osp_pg=0 (spawn #242456)
2025-06-01 21:46:04.608344 :9F0A7CA5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 21:46:04.608345 :9F0A7CA6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=212 time=1790123250
2025-06-01 21:46:04.608345 :9F0A7CA7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 21:46:04.608345 :9F0A7CA8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 21:46:04.608346 :9F0A7CA9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 21:46:04.608346 :9F0A7CAA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 21:46:04.608346 :9F0A7CAB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 21:46:04.608873 :9F0A7CAC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 21:46:04.608928 :9F0A7CB6:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 21:56:05.566837 :9F0B41B0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 21:56:05.868289 :9F0B41EF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 21:56:05.863
2025-06-01 21:56:05.868291 :9F0B41F0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14680 pso_num=22 pso_serial#=14
2025-06-01 21:56:05.868425 :9F0B41F1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14680 osp_idx=0 osp_ver=254321 osp_pg=0 (spawn #242479)
2025-06-01 21:56:05.868425 :9F0B41F2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 21:56:05.868426 :9F0B41F3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=213 time=1790724516
2025-06-01 21:56:05.868428 :9F0B41F4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 21:56:05.868428 :9F0B41F5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 21:56:05.868428 :9F0B41F6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 21:56:05.868429 :9F0B41F7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 21:56:05.868429 :9F0B41F8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 21:56:05.868915 :9F0B41F9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 21:56:05.868958 :9F0B4201:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-01 22:06:06.844855 :9F0C1083:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 22:06:07.162069 :9F0C10C4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 22:06:07.157
2025-06-01 22:06:07.162071 :9F0C10C5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11580 pso_num=22 pso_serial#=15
2025-06-01 22:06:07.162207 :9F0C10C6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11580 osp_idx=0 osp_ver=254322 osp_pg=0 (spawn #242504)
2025-06-01 22:06:07.162208 :9F0C10C7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-06-01 22:06:07.162209 :9F0C10C8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=214 time=1791325813
2025-06-01 22:06:07.162209 :9F0C10C9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 22:06:07.162209 :9F0C10CA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 22:06:07.162210 :9F0C10CB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 22:06:07.162210 :9F0C10CC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 22:06:07.162210 :9F0C10CD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 22:06:07.162703 :9F0C10CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name=   type=0
2025-06-01 22:06:07.162746 :9F0C10D5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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 22 (osid: 11580, W000)