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


*** 2025-08-16 18:08:18.437
*** SESSION ID:(201.12587) 2025-08-16 18:08:18.437
 

*** 2025-08-16 18:08:18.437
Process diagnostic dump for ORACLE.EXE (W000), OS id=19788,
pid: 25, proc_ser: 198, sid: 201, sess_ser: 12587 
-------------------------------------------------------------------------------
current sql: <none>
Current Wait Stack:
 0: waiting for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=62 seq_num=63 snap_id=1
    wait times: snap=1.922827 sec, exc=1.922827 sec, total=1.922827 sec
    wait times: max=5.000000 sec, heur=5 min 7 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.000055 sec since current wait
 0: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=61 seq_num=62 snap_id=1
    wait times: snap=5.014719 sec, exc=5.014719 sec, total=5.014719 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000039 sec of elapsed time
 1: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=60 seq_num=61 snap_id=1
    wait times: snap=5.010135 sec, exc=5.010135 sec, total=5.010135 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000032 sec of elapsed time
 2: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=59 seq_num=60 snap_id=1
    wait times: snap=5.014717 sec, exc=5.014717 sec, total=5.014717 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000032 sec of elapsed time
 3: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=58 seq_num=59 snap_id=1
    wait times: snap=5.014749 sec, exc=5.014749 sec, total=5.014749 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000039 sec of elapsed time
 4: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=57 seq_num=58 snap_id=1
    wait times: snap=5.004553 sec, exc=5.004553 sec, total=5.004553 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000080 sec of elapsed time
 5: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=56 seq_num=57 snap_id=1
    wait times: snap=5.004622 sec, exc=5.004622 sec, total=5.004622 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000033 sec of elapsed time
 6: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=55 seq_num=56 snap_id=1
    wait times: snap=5.014751 sec, exc=5.014751 sec, total=5.014751 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000036 sec of elapsed time
 7: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=54 seq_num=55 snap_id=1
    wait times: snap=5.004618 sec, exc=5.004618 sec, total=5.004618 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000029 sec of elapsed time
 8: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=53 seq_num=54 snap_id=1
    wait times: snap=5.014718 sec, exc=5.014718 sec, total=5.014718 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000041 sec of elapsed time
 9: waited for 'Space Manager: slave idle wait'
    Slave ID=0x0, =0x0, =0x0
    wait_id=52 seq_num=53 snap_id=1
    wait times: snap=5.007228 sec, exc=5.007228 sec, total=5.007228 sec
    wait times: max=5.000000 sec
    wait counts: calls=1 os=1
    occurred after 0.000031 sec of elapsed time
Sampled Session History of session 201 serial 12587
---------------------------------------------------
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,                                            18:06:18 - 18:08:18]
    idle wait at each sample
-------------------------------------------------------------------------------
Process diagnostic dump actual duration=0.000000 sec
  (max dump time=30.000000 sec)

*** 2025-08-16 18:08:18.437
 
-------------------------------------------------------------------------------
Trace Bucket Dump Begin: default bucket for process 25 (osid: 19788, W000)
TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA
-------------------------------------------------------------------------------
2025-08-16 15:42:52.365081 :C08CC04E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 15:42:52.948314 :C08CC07D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 15:42:52.943
2025-08-16 15:42:52.948316 :C08CC07E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20168 pso_num=25 pso_serial#=185
2025-08-16 15:42:52.948467 :C08CC07F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20168 osp_idx=23 osp_ver=243567 osp_pg=0 (spawn #494943)
2025-08-16 15:42:52.948468 :C08CC080:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 15:42:52.948468 :C08CC081:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=23 time=4039642251
2025-08-16 15:42:52.948469 :C08CC082:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 15:42:52.948469 :C08CC083:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 15:42:52.948470 :C08CC084:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 15:42:52.948470 :C08CC085:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 15:42:52.948470 :C08CC086:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 15:42:52.949052 :C08CC087: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-08-16 15:42:52.949100 :C08CC08D: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-08-16 15:52:53.924350 :C08D8C09:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 15:52:54.236067 :C08D8C34:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 15:52:54.231
2025-08-16 15:52:54.236069 :C08D8C35:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14784 pso_num=25 pso_serial#=186
2025-08-16 15:52:54.236238 :C08D8C36:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14784 osp_idx=23 osp_ver=243568 osp_pg=0 (spawn #494965)
2025-08-16 15:52:54.236239 :C08D8C37:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 15:52:54.236239 :C08D8C38:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=24 time=4040243548
2025-08-16 15:52:54.236240 :C08D8C39:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 15:52:54.236241 :C08D8C3A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 15:52:54.236241 :C08D8C3B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 15:52:54.236241 :C08D8C3C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 15:52:54.236241 :C08D8C3D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 15:52:54.236764 :C08D8C3E: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-08-16 15:52:54.236810 :C08D8C45: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-08-16 16:02:55.215191 :C08E5A9E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 16:02:55.641836 :C08E5ACC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 16:02:55.637
2025-08-16 16:02:55.641838 :C08E5ACD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20284 pso_num=25 pso_serial#=187
2025-08-16 16:02:55.641979 :C08E5ACE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20284 osp_idx=23 osp_ver=243569 osp_pg=0 (spawn #494991)
2025-08-16 16:02:55.641980 :C08E5ACF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 16:02:55.641980 :C08E5AD0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=25 time=4040844954
2025-08-16 16:02:55.641980 :C08E5AD1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 16:02:55.641981 :C08E5AD2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 16:02:55.641981 :C08E5AD3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 16:02:55.641981 :C08E5AD4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 16:02:55.641982 :C08E5AD5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 16:02:55.642484 :C08E5AD6: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-08-16 16:02:55.642529 :C08E5ADE: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-08-16 16:07:20.099103 :C08EBA9C: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-08-16 16:12:56.888245 :C08F2FEE: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-08-16 16:22:57.762035 :C08FFA88:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 16:22:58.183065 :C08FFAB8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 16:22:58.178
2025-08-16 16:22:58.183067 :C08FFAB9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14108 pso_num=25 pso_serial#=188
2025-08-16 16:22:58.183202 :C08FFABA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14108 osp_idx=23 osp_ver=243570 osp_pg=0 (spawn #495036)
2025-08-16 16:22:58.183202 :C08FFABB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 16:22:58.183203 :C08FFABC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=26 time=4042047486
2025-08-16 16:22:58.183203 :C08FFABD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 16:22:58.183203 :C08FFABE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 16:22:58.183204 :C08FFABF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 16:22:58.183204 :C08FFAC0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 16:22:58.183204 :C08FFAC1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 16:22:58.183710 :C08FFAC2: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-08-16 16:22:58.183765 :C08FFAC9: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-08-16 16:32:59.121820 :C090C3F3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 16:32:59.485853 :C090C420:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 16:32:59.481
2025-08-16 16:32:59.485855 :C090C421:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22264 pso_num=25 pso_serial#=189
2025-08-16 16:32:59.486041 :C090C422:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22264 osp_idx=23 osp_ver=243571 osp_pg=0 (spawn #495059)
2025-08-16 16:32:59.486041 :C090C423:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 16:32:59.486042 :C090C424:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=27 time=4042648798
2025-08-16 16:32:59.486042 :C090C425:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 16:32:59.486043 :C090C426:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 16:32:59.486043 :C090C427:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 16:32:59.486044 :C090C428:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 16:32:59.486044 :C090C429:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 16:32:59.486534 :C090C42A: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-08-16 16:32:59.486581 :C090C432: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-08-16 16:43:00.337345 :C0918BEF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 16:43:00.670156 :C0918C1E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 16:43:00.665
2025-08-16 16:43:00.670158 :C0918C1F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21676 pso_num=25 pso_serial#=190
2025-08-16 16:43:00.670299 :C0918C20:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21676 osp_idx=23 osp_ver=243572 osp_pg=0 (spawn #495082)
2025-08-16 16:43:00.670299 :C0918C21:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 16:43:00.670300 :C0918C22:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=28 time=4043249970
2025-08-16 16:43:00.670300 :C0918C23:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 16:43:00.670301 :C0918C24:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 16:43:00.670301 :C0918C25:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 16:43:00.670301 :C0918C26:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 16:43:00.670302 :C0918C27:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 16:43:00.670800 :C0918C28: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-08-16 16:43:00.670849 :C0918C32: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-08-16 16:53:01.579208 :C092543C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 16:53:01.997247 :C092546F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 16:53:01.992
2025-08-16 16:53:01.997249 :C0925470:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18624 pso_num=25 pso_serial#=191
2025-08-16 16:53:01.997383 :C0925471:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18624 osp_idx=23 osp_ver=243573 osp_pg=0 (spawn #495104)
2025-08-16 16:53:01.997384 :C0925472:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 16:53:01.997384 :C0925473:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=29 time=4043851298
2025-08-16 16:53:01.997385 :C0925474:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 16:53:01.997385 :C0925475:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 16:53:01.997385 :C0925476:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 16:53:01.997386 :C0925477:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 16:53:01.997386 :C0925478:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 16:53:01.997866 :C0925479: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-08-16 16:53:01.997914 :C0925481: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-08-16 17:03:02.884721 :C0932164:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 17:03:03.149648 :C09321B0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 17:03:03.145
2025-08-16 17:03:03.149650 :C09321B1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21576 pso_num=25 pso_serial#=192
2025-08-16 17:03:03.149796 :C09321B2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21576 osp_idx=23 osp_ver=243574 osp_pg=0 (spawn #495129)
2025-08-16 17:03:03.149797 :C09321B3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 17:03:03.149797 :C09321B4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=30 time=4044452454
2025-08-16 17:03:03.149797 :C09321B5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 17:03:03.149798 :C09321B6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 17:03:03.149798 :C09321B7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 17:03:03.149798 :C09321B8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 17:03:03.149799 :C09321B9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 17:03:03.150274 :C09321BA: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-08-16 17:03:03.150323 :C09321C1: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-08-16 17:13:04.052327 :C093F0EC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 17:13:04.557370 :C093F17E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 17:13:04.552
2025-08-16 17:13:04.557372 :C093F17F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4124 pso_num=25 pso_serial#=193
2025-08-16 17:13:04.557515 :C093F180:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4124 osp_idx=23 osp_ver=243575 osp_pg=0 (spawn #495153)
2025-08-16 17:13:04.557515 :C093F181:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 17:13:04.557515 :C093F182:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=31 time=4045053861
2025-08-16 17:13:04.557516 :C093F183:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 17:13:04.557516 :C093F184:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 17:13:04.557517 :C093F185:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 17:13:04.557517 :C093F186:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 17:13:04.557518 :C093F187:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 17:13:04.558062 :C093F188: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-08-16 17:13:04.558116 :C093F190: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-08-16 17:23:05.523436 :C094B9C6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 17:23:05.856344 :C094B9F7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 17:23:05.851
2025-08-16 17:23:05.856346 :C094B9F8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22016 pso_num=25 pso_serial#=194
2025-08-16 17:23:05.856477 :C094B9F9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22016 osp_idx=23 osp_ver=243576 osp_pg=0 (spawn #495175)
2025-08-16 17:23:05.856478 :C094B9FA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 17:23:05.856478 :C094B9FB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=32 time=4045655158
2025-08-16 17:23:05.856479 :C094B9FC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 17:23:05.856479 :C094B9FD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 17:23:05.856480 :C094B9FE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 17:23:05.856480 :C094B9FF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 17:23:05.856480 :C094BA00:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 17:23:05.856957 :C094BA01: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-08-16 17:23:05.857008 :C094BA0B: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-08-16 17:33:06.717713 :C095823C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 17:33:07.222588 :C09582A1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 17:33:07.217
2025-08-16 17:33:07.222591 :C09582A2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16664 pso_num=25 pso_serial#=195
2025-08-16 17:33:07.222739 :C09582A3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16664 osp_idx=23 osp_ver=243577 osp_pg=0 (spawn #495198)
2025-08-16 17:33:07.222740 :C09582A4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 17:33:07.222741 :C09582A5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=33 time=4046256533
2025-08-16 17:33:07.222741 :C09582A6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 17:33:07.222742 :C09582A7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 17:33:07.222742 :C09582A8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 17:33:07.222742 :C09582A9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 17:33:07.222743 :C09582AA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 17:33:07.223255 :C09582AB: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-08-16 17:33:07.223303 :C09582B1: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-08-16 17:43:08.059438 :C0964B33:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 17:43:08.470365 :C0964B8B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 17:43:08.465
2025-08-16 17:43:08.470367 :C0964B8C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19144 pso_num=25 pso_serial#=196
2025-08-16 17:43:08.470503 :C0964B8D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19144 osp_idx=23 osp_ver=243578 osp_pg=0 (spawn #495221)
2025-08-16 17:43:08.470503 :C0964B8E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 17:43:08.470504 :C0964B8F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=34 time=4046857783
2025-08-16 17:43:08.470504 :C0964B90:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 17:43:08.470505 :C0964B91:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 17:43:08.470505 :C0964B92:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 17:43:08.470505 :C0964B93:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 17:43:08.470506 :C0964B94:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 17:43:08.471002 :C0964B95: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-08-16 17:43:08.471046 :C0964B9C: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-08-16 17:53:09.324567 :C09711BD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 17:53:09.735532 :C09711F9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 17:53:09.730
2025-08-16 17:53:09.735534 :C09711FA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21656 pso_num=25 pso_serial#=197
2025-08-16 17:53:09.735679 :C09711FB:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21656 osp_idx=23 osp_ver=243579 osp_pg=0 (spawn #495243)
2025-08-16 17:53:09.735680 :C09711FC:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 17:53:09.735680 :C09711FD:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=35 time=4047459048
2025-08-16 17:53:09.735681 :C09711FE:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 17:53:09.735681 :C09711FF:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 17:53:09.735681 :C0971200:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 17:53:09.735682 :C0971201:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 17:53:09.735682 :C0971202:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 17:53:09.736175 :C0971203: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-08-16 17:53:09.736221 :C097120A: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-08-16 17:53:24.744004 :C09716CC:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1
2025-08-16 17:53:24.744061 :C09716D1:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1
2025-08-16 17:53:24.744063 :C09716D2:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=55, exc=55, tot=55
2025-08-16 18:03:10.619137 :C097DD2C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted
2025-08-16 18:03:11.046019 :C097DD5C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-16 18:03:11.041
2025-08-16 18:03:11.046022 :C097DD5D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19788 pso_num=25 pso_serial#=198
2025-08-16 18:03:11.046169 :C097DD5E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19788 osp_idx=23 osp_ver=243580 osp_pg=0 (spawn #495268)
2025-08-16 18:03:11.046169 :C097DD5F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A
2025-08-16 18:03:11.046170 :C097DD60:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=36 time=4048060345
2025-08-16 18:03:11.046170 :C097DD61:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs
2025-08-16 18:03:11.046171 :C097DD62:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs
2025-08-16 18:03:11.046171 :C097DD63:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs
2025-08-16 18:03:11.046171 :C097DD64:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs
2025-08-16 18:03:11.046172 :C097DD65:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs
2025-08-16 18:03:11.046690 :C097DD66: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-08-16 18:03:11.046741 :C097DD6D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name=   type=0 fac#=0 facpost=1
-------------------------------------------------------------------------------
Trace Bucket Dump End: default bucket for process 25 (osid: 19788, W000)