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


*** 2025-06-01 08:18:08.390
*** SESSION ID:(177.17149) 2025-06-01 08:18:08.390
 

*** 2025-06-01 08:18:08.390
Process diagnostic dump for ORACLE.EXE (W000), OS id=14864,
pid: 22, proc_ser: 187, sid: 177, sess_ser: 17149 
-------------------------------------------------------------------------------
current sql: <none>
Current Wait Stack:
 0: waiting for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=47 seq_num=48 snap_id=1
    wait times: snap=1.969184 sec, exc=1.969184 sec, total=1.969184 sec
    wait times: max=5.000000 sec, heur=3 min 52 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.000025 sec since current wait
 0: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=46 seq_num=47 snap_id=1
    wait times: snap=5.004606 sec, exc=5.004606 sec, total=5.004606 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000029 sec of elapsed time
 1: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=45 seq_num=46 snap_id=1
    wait times: snap=5.004651 sec, exc=5.004651 sec, total=5.004651 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000023 sec of elapsed time
 2: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=44 seq_num=45 snap_id=1
    wait times: snap=5.003078 sec, exc=5.003078 sec, total=5.003078 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000024 sec of elapsed time
 3: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=43 seq_num=44 snap_id=1
    wait times: snap=5.012926 sec, exc=5.012926 sec, total=5.012926 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=42 seq_num=43 snap_id=1
    wait times: snap=5.014729 sec, exc=5.014729 sec, total=5.014729 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000029 sec of elapsed time
 5: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=41 seq_num=42 snap_id=1
    wait times: snap=5.004649 sec, exc=5.004649 sec, total=5.004649 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000023 sec of elapsed time
 6: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=40 seq_num=41 snap_id=1
    wait times: snap=5.009773 sec, exc=5.009773 sec, total=5.009773 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=39 seq_num=40 snap_id=1
    wait times: snap=5.003239 sec, exc=5.003239 sec, total=5.003239 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000022 sec of elapsed time
 8: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=38 seq_num=39 snap_id=1
    wait times: snap=5.000452 sec, exc=5.000452 sec, total=5.000452 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000027 sec of elapsed time
 9: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=37 seq_num=38 snap_id=1
    wait times: snap=5.013479 sec, exc=5.013479 sec, total=5.013479 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000021 sec of elapsed time
Sampled Session History of session 177 serial 17149
---------------------------------------------------
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:16:08 - 08:18:08]
    idle wait at each sample
-------------------------------------------------------------------------------
Process diagnostic dump actual duration=0.000000 sec
  (max dump time=30.000000 sec)

*** 2025-06-01 08:18:08.390
 
-------------------------------------------------------------------------------
Trace Bucket Dump Begin: default bucket for process 22 (osid: 14864, W000)
TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA
-------------------------------------------------------------------------------
2025-06-01 05:53:57.956716 :9EC02A1A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 05:53:58.259423 :9EC02A54:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 05:53:58.254
2025-06-01 05:53:58.259425 :9EC02A55:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15220 pso_num=22 pso_serial#=174
2025-06-01 05:53:58.259558 :9EC02A56:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15220 osp_idx=0 osp_ver=254226 osp_pg=0 (spawn #240248)
2025-06-01 05:53:58.259559 :9EC02A57: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 05:53:58.259559 :9EC02A58:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=125 time=1732996907
2025-06-01 05:53:58.259560 :9EC02A59:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 05:53:58.259560 :9EC02A5A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 05:53:58.259560 :9EC02A5B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 05:53:58.259561 :9EC02A5C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 05:53:58.259561 :9EC02A5D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 05:53:58.260047 :9EC02A5E: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 05:53:58.260094 :9EC02A66: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 06:03:59.185531 :9EC0F914:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 06:03:59.596451 :9EC0F959:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 06:03:59.592
2025-06-01 06:03:59.596454 :9EC0F95A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15196 pso_num=22 pso_serial#=175
2025-06-01 06:03:59.596588 :9EC0F95B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15196 osp_idx=0 osp_ver=254227 osp_pg=0 (spawn #240279)
2025-06-01 06:03:59.596589 :9EC0F95C: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 06:03:59.596589 :9EC0F95D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=126 time=1733598250
2025-06-01 06:03:59.596590 :9EC0F95E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 06:03:59.596590 :9EC0F95F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 06:03:59.596590 :9EC0F960:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 06:03:59.596591 :9EC0F961:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 06:03:59.596591 :9EC0F962:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 06:03:59.597081 :9EC0F963: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 06:03:59.597127 :9EC0F96A: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 06:14:00.501033 :9EC1C6F9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 06:14:00.818148 :9EC1C733:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 06:14:00.813
2025-06-01 06:14:00.818150 :9EC1C734:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14680 pso_num=22 pso_serial#=176
2025-06-01 06:14:00.818291 :9EC1C735:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14680 osp_idx=0 osp_ver=254228 osp_pg=0 (spawn #240302)
2025-06-01 06:14:00.818292 :9EC1C736: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 06:14:00.818292 :9EC1C737:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=127 time=1734199469
2025-06-01 06:14:00.818292 :9EC1C738:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 06:14:00.818293 :9EC1C739:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 06:14:00.818293 :9EC1C73A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 06:14:00.818293 :9EC1C73B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 06:14:00.818293 :9EC1C73C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 06:14:00.818787 :9EC1C73D: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 06:14:00.818832 :9EC1C745: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 06:15:15.933040 :9EC1E314:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=16 seq_num=17 snap_id=1
2025-06-01 06:15:15.933065 :9EC1E31E:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=16 seq_num=17 snap_id=1
2025-06-01 06:15:15.933067 :9EC1E31F:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=25, exc=25, tot=25
2025-06-01 06:24:01.724620 :9EC28E4E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 06:24:02.041812 :9EC28E93:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 06:24:02.037
2025-06-01 06:24:02.041814 :9EC28E94:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12292 pso_num=22 pso_serial#=177
2025-06-01 06:24:02.041952 :9EC28E95:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12292 osp_idx=0 osp_ver=254229 osp_pg=0 (spawn #240325)
2025-06-01 06:24:02.041953 :9EC28E96: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 06:24:02.041953 :9EC28E97:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=128 time=1734800688
2025-06-01 06:24:02.041954 :9EC28E98:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 06:24:02.041954 :9EC28E99:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 06:24:02.041954 :9EC28E9A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 06:24:02.041954 :9EC28E9B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 06:24:02.041955 :9EC28E9C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 06:24:02.042485 :9EC28E9D: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 06:24:02.042526 :9EC28EA4: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 06:34:03.067691 :9EC352B0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 06:34:03.259963 :9EC352EC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 06:34:03.255
2025-06-01 06:34:03.259966 :9EC352ED:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10456 pso_num=22 pso_serial#=178
2025-06-01 06:34:03.260114 :9EC352EE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10456 osp_idx=0 osp_ver=254230 osp_pg=0 (spawn #240347)
2025-06-01 06:34:03.260115 :9EC352EF: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 06:34:03.260115 :9EC352F0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=129 time=1735401907
2025-06-01 06:34:03.260116 :9EC352F1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 06:34:03.260116 :9EC352F2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 06:34:03.260116 :9EC352F3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 06:34:03.260117 :9EC352F4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 06:34:03.260117 :9EC352F5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 06:34:03.260611 :9EC352F6: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 06:34:03.260656 :9EC352FE: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 06:44:04.184231 :9EC4168C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 06:44:04.564094 :9EC416CF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 06:44:04.559
2025-06-01 06:44:04.564096 :9EC416D0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7880 pso_num=22 pso_serial#=179
2025-06-01 06:44:04.564229 :9EC416D1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7880 osp_idx=0 osp_ver=254231 osp_pg=0 (spawn #240370)
2025-06-01 06:44:04.564230 :9EC416D2: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 06:44:04.564230 :9EC416D3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=130 time=1736003204
2025-06-01 06:44:04.564230 :9EC416D4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 06:44:04.564231 :9EC416D5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 06:44:04.564231 :9EC416D6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 06:44:04.564231 :9EC416D7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 06:44:04.564231 :9EC416D8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 06:44:04.564712 :9EC416D9: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 06:44:04.564756 :9EC416E0: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 06:54:05.476584 :9EC4DB09:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 06:54:05.825162 :9EC4DB43:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 06:54:05.820
2025-06-01 06:54:05.825164 :9EC4DB44:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15012 pso_num=22 pso_serial#=180
2025-06-01 06:54:05.825305 :9EC4DB45:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15012 osp_idx=0 osp_ver=254232 osp_pg=0 (spawn #240394)
2025-06-01 06:54:05.825306 :9EC4DB46: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 06:54:05.825307 :9EC4DB47:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=131 time=1736604469
2025-06-01 06:54:05.825307 :9EC4DB48:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 06:54:05.825308 :9EC4DB49:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 06:54:05.825308 :9EC4DB4A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 06:54:05.825310 :9EC4DB4B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 06:54:05.825310 :9EC4DB4C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 06:54:05.825802 :9EC4DB4D: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 06:54:05.825843 :9EC4DB54: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 07:04:06.747222 :9EC5A090:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 07:04:07.065510 :9EC5A0D4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 07:04:07.060
2025-06-01 07:04:07.065513 :9EC5A0D5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13600 pso_num=22 pso_serial#=181
2025-06-01 07:04:07.065680 :9EC5A0D6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13600 osp_idx=0 osp_ver=254233 osp_pg=0 (spawn #240419)
2025-06-01 07:04:07.065681 :9EC5A0D7: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 07:04:07.065682 :9EC5A0D8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=132 time=1737205719
2025-06-01 07:04:07.065682 :9EC5A0D9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 07:04:07.065683 :9EC5A0DA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 07:04:07.065683 :9EC5A0DB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 07:04:07.065683 :9EC5A0DC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 07:04:07.065684 :9EC5A0DD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 07:04:07.066303 :9EC5A0DE: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 07:04:07.066374 :9EC5A0E8: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 07:14:07.973568 :9EC66CFE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 07:14:08.290747 :9EC66D35:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 07:14:08.286
2025-06-01 07:14:08.290749 :9EC66D36:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14556 pso_num=22 pso_serial#=182
2025-06-01 07:14:08.290886 :9EC66D37:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14556 osp_idx=0 osp_ver=254234 osp_pg=0 (spawn #240442)
2025-06-01 07:14:08.290887 :9EC66D38: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 07:14:08.290887 :9EC66D39:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=133 time=1737806938
2025-06-01 07:14:08.290888 :9EC66D3A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 07:14:08.290888 :9EC66D3B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 07:14:08.290888 :9EC66D3C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 07:14:08.290889 :9EC66D3D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 07:14:08.290889 :9EC66D3E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 07:14:08.291384 :9EC66D3F: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 07:14:08.291428 :9EC66D47: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 07:20:13.019538 :9EC6E41C: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 07:24:09.561251 :9EC73021: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 07:34:10.519684 :9EC7F497:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 07:34:10.899359 :9EC7F4D6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 07:34:10.894
2025-06-01 07:34:10.899361 :9EC7F4D7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14012 pso_num=22 pso_serial#=183
2025-06-01 07:34:10.899499 :9EC7F4D8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14012 osp_idx=0 osp_ver=254235 osp_pg=0 (spawn #240486)
2025-06-01 07:34:10.899499 :9EC7F4D9: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 07:34:10.899500 :9EC7F4DA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=134 time=1739009547
2025-06-01 07:34:10.899501 :9EC7F4DB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 07:34:10.899501 :9EC7F4DC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 07:34:10.899502 :9EC7F4DD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 07:34:10.899502 :9EC7F4DE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 07:34:10.899502 :9EC7F4DF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 07:34:10.899997 :9EC7F4E0: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 07:34:10.900051 :9EC7F4E6: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 07:44:11.828862 :9EC8BA5E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 07:44:12.203137 :9EC8BA9E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 07:44:12.198
2025-06-01 07:44:12.203138 :9EC8BA9F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10584 pso_num=22 pso_serial#=184
2025-06-01 07:44:12.203320 :9EC8BAA0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10584 osp_idx=0 osp_ver=254236 osp_pg=0 (spawn #240509)
2025-06-01 07:44:12.203321 :9EC8BAA1: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 07:44:12.203321 :9EC8BAA2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=135 time=1739610844
2025-06-01 07:44:12.203322 :9EC8BAA3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 07:44:12.203323 :9EC8BAA4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 07:44:12.203323 :9EC8BAA5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 07:44:12.203324 :9EC8BAA6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 07:44:12.203324 :9EC8BAA7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 07:44:12.203869 :9EC8BAA8: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 07:44:12.203916 :9EC8BAAF: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 07:54:13.210337 :9EC980D5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 07:54:13.496461 :9EC9810D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 07:54:13.492
2025-06-01 07:54:13.496463 :9EC9810E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14424 pso_num=22 pso_serial#=185
2025-06-01 07:54:13.496609 :9EC9810F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14424 osp_idx=0 osp_ver=254237 osp_pg=0 (spawn #240532)
2025-06-01 07:54:13.496610 :9EC98110: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 07:54:13.496610 :9EC98111:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=136 time=1740212141
2025-06-01 07:54:13.496611 :9EC98112:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 07:54:13.496611 :9EC98113:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 07:54:13.496611 :9EC98114:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 07:54:13.496612 :9EC98115:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 07:54:13.496612 :9EC98116:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 07:54:13.497110 :9EC98117: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 07:54:13.497154 :9EC9811F: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 08:04:14.464181 :9ECA490A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 08:04:14.797189 :9ECA4950:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 08:04:14.792
2025-06-01 08:04:14.797191 :9ECA4951:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14396 pso_num=22 pso_serial#=186
2025-06-01 08:04:14.797327 :9ECA4952:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14396 osp_idx=0 osp_ver=254238 osp_pg=0 (spawn #240557)
2025-06-01 08:04:14.797328 :9ECA4953: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 08:04:14.797328 :9ECA4954:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=137 time=1740813438
2025-06-01 08:04:14.797328 :9ECA4955:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 08:04:14.797329 :9ECA4956:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 08:04:14.797329 :9ECA4957:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 08:04:14.797330 :9ECA4958:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 08:04:14.797330 :9ECA4959:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 08:04:14.797855 :9ECA495A: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 08:04:14.797911 :9ECA4963: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 08:14:15.675898 :9ECB1880:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted
2025-06-01 08:14:16.118128 :9ECB18E4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 08:14:16.113
2025-06-01 08:14:16.118130 :9ECB18E5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14864 pso_num=22 pso_serial#=187
2025-06-01 08:14:16.118285 :9ECB18E6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14864 osp_idx=0 osp_ver=254239 osp_pg=0 (spawn #240580)
2025-06-01 08:14:16.118286 :9ECB18E7: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 08:14:16.118287 :9ECB18E8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=138 time=1741414766
2025-06-01 08:14:16.118288 :9ECB18E9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs
2025-06-01 08:14:16.118288 :9ECB18EA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs
2025-06-01 08:14:16.118289 :9ECB18EB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs
2025-06-01 08:14:16.118289 :9ECB18EC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-06-01 08:14:16.118290 :9ECB18ED:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-06-01 08:14:16.118836 :9ECB18EE: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 08:14:16.118887 :9ECB18F6: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: 14864, W000)