Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250831220736\orcl_w000_21040_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:35067M/63366M, Ph+PgF:39991M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 21040, image: ORACLE.EXE (W000) *** 2025-08-31 22:07:36.876 *** SESSION ID:(177.13573) 2025-08-31 22:07:36.876 *** 2025-08-31 22:07:36.876 Process diagnostic dump for ORACLE.EXE (W000), OS id=21040, pid: 22, proc_ser: 43, sid: 177, sess_ser: 13573 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=90 seq_num=91 snap_id=1 wait times: snap=1.282386 sec, exc=1.282386 sec, total=1.282386 sec wait times: max=5.000000 sec, heur=7 min 26 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.000023 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=89 seq_num=90 snap_id=1 wait times: snap=5.010122 sec, exc=5.010122 sec, total=5.010122 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=88 seq_num=89 snap_id=1 wait times: snap=5.004299 sec, exc=5.004299 sec, total=5.004299 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=87 seq_num=88 snap_id=1 wait times: snap=5.003238 sec, exc=5.003238 sec, total=5.003238 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=86 seq_num=87 snap_id=1 wait times: snap=5.003512 sec, exc=5.003512 sec, total=5.003512 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=85 seq_num=86 snap_id=1 wait times: snap=5.004770 sec, exc=5.004770 sec, total=5.004770 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=84 seq_num=85 snap_id=1 wait times: snap=5.014748 sec, exc=5.014748 sec, total=5.014748 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=83 seq_num=84 snap_id=1 wait times: snap=5.010138 sec, exc=5.010138 sec, total=5.010138 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=82 seq_num=83 snap_id=1 wait times: snap=5.014743 sec, exc=5.014743 sec, total=5.014743 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=81 seq_num=82 snap_id=1 wait times: snap=5.015270 sec, exc=5.015270 sec, total=5.015270 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=80 seq_num=81 snap_id=1 wait times: snap=5.003407 sec, exc=5.003407 sec, total=5.003407 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time Sampled Session History of session 177 serial 13573 --------------------------------------------------- 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:05:36 - 22:07:36] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-31 22:07:36.876 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 21040, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-31 19:29:52.376550 :C737F12C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 19:29:52.376550 :C737F12D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 19:29:52.377028 :C737F12E: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-08-31 19:29:52.377080 :C737F138: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-08-31 19:33:14.514434 :C73833C7: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-08-31 19:39:53.532506 :C738B79A: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-08-31 19:39:53.532551 :C738B79B:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-08-31 19:39:53.532580 :C738B7A0:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-08-31 19:39:53.532581 :C738B7A1:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=29, exc=29, tot=29 2025-08-31 19:49:54.367490 :C7397E33:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 19:49:54.762630 :C7397E9C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 19:49:54.758 2025-08-31 19:49:54.762632 :C7397E9D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23392 pso_num=22 pso_serial#=30 2025-08-31 19:49:54.762770 :C7397E9E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23392 osp_idx=0 osp_ver=558042 osp_pg=0 (spawn #545532) 2025-08-31 19:49:54.762771 :C7397E9F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 19:49:54.762771 :C7397EA0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=59 time=1055446065 2025-08-31 19:49:54.762772 :C7397EA1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 19:49:54.762773 :C7397EA2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 19:49:54.762773 :C7397EA3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 19:49:54.762773 :C7397EA4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 19:49:54.762774 :C7397EA5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 19:49:54.763255 :C7397EA6: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-08-31 19:49:54.763297 :C7397EAE: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-08-31 19:59:55.538491 :C73A44F9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 19:59:55.965128 :C73A4551:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 19:59:55.960 2025-08-31 19:59:55.965131 :C73A4552:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22352 pso_num=22 pso_serial#=31 2025-08-31 19:59:55.965272 :C73A4553:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22352 osp_idx=0 osp_ver=558043 osp_pg=0 (spawn #545554) 2025-08-31 19:59:55.965272 :C73A4554:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 19:59:55.965273 :C73A4555:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=60 time=1056047268 2025-08-31 19:59:55.965273 :C73A4556:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 19:59:55.965273 :C73A4557:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 19:59:55.965274 :C73A4558:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 19:59:55.965274 :C73A4559:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 19:59:55.965274 :C73A455A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 19:59:55.965778 :C73A455B: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-08-31 19:59:55.965828 :C73A4565: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-08-31 20:09:56.936275 :C73B1444:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 20:09:57.144199 :C73B149C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 20:09:57.139 2025-08-31 20:09:57.144201 :C73B149D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19224 pso_num=22 pso_serial#=32 2025-08-31 20:09:57.144340 :C73B149E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19224 osp_idx=0 osp_ver=558044 osp_pg=0 (spawn #545580) 2025-08-31 20:09:57.144340 :C73B149F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 20:09:57.144341 :C73B14A0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=61 time=1056648455 2025-08-31 20:09:57.144342 :C73B14A1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 20:09:57.144342 :C73B14A2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 20:09:57.144342 :C73B14A3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 20:09:57.144343 :C73B14A4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 20:09:57.144343 :C73B14A5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 20:09:57.144840 :C73B14A6: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-08-31 20:09:57.144886 :C73B14AE: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-08-31 20:19:58.013950 :C73BDD4C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 20:19:58.022021 :C73BDD4F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 20:19:58.013 2025-08-31 20:19:58.022023 :C73BDD50:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18800 pso_num=22 pso_serial#=33 2025-08-31 20:19:58.022164 :C73BDD51:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=18800 (legacy spawn) 2025-08-31 20:19:58.028681 :C73BDD52:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-31 20:19:58.028858 :C73BDD57:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-08-31 20:19:58.029687 :C73BDD5C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 20:19:58.268696 :C73BDDB4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 20:19:58.263 2025-08-31 20:19:58.268699 :C73BDDB5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21948 pso_num=22 pso_serial#=34 2025-08-31 20:19:58.268843 :C73BDDB6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21948 osp_idx=0 osp_ver=558046 osp_pg=0 (spawn #545603) 2025-08-31 20:19:58.268844 :C73BDDB7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 20:19:58.268844 :C73BDDB8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=62 time=1057249580 2025-08-31 20:19:58.268844 :C73BDDB9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 20:19:58.268845 :C73BDDBA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 20:19:58.268845 :C73BDDBB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 20:19:58.268845 :C73BDDBC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 20:19:58.268846 :C73BDDBD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 20:19:58.269350 :C73BDDBE: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-08-31 20:19:58.269399 :C73BDDC4: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-08-31 20:29:59.099732 :C73CA3F1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 20:29:59.448311 :C73CA43D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 20:29:59.443 2025-08-31 20:29:59.448313 :C73CA43E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20048 pso_num=22 pso_serial#=35 2025-08-31 20:29:59.448448 :C73CA43F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20048 osp_idx=0 osp_ver=558047 osp_pg=0 (spawn #545625) 2025-08-31 20:29:59.448449 :C73CA440:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 20:29:59.448449 :C73CA441:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=63 time=1057850752 2025-08-31 20:29:59.448450 :C73CA442:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 20:29:59.448450 :C73CA443:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 20:29:59.448450 :C73CA444:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 20:29:59.448451 :C73CA445:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 20:29:59.448451 :C73CA446:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 20:29:59.448945 :C73CA447: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-08-31 20:29:59.448990 :C73CA44E: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-08-31 20:40:00.240312 :C73D6AEA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 20:40:00.635739 :C73D6B24:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 20:40:00.630 2025-08-31 20:40:00.635741 :C73D6B25:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23324 pso_num=22 pso_serial#=36 2025-08-31 20:40:00.635879 :C73D6B26:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23324 osp_idx=0 osp_ver=558048 osp_pg=0 (spawn #545648) 2025-08-31 20:40:00.635879 :C73D6B27:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 20:40:00.635880 :C73D6B28:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=64 time=1058451940 2025-08-31 20:40:00.635880 :C73D6B29:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 20:40:00.635880 :C73D6B2A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 20:40:00.635881 :C73D6B2B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 20:40:00.635881 :C73D6B2C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 20:40:00.635881 :C73D6B2D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 20:40:00.636418 :C73D6B2E: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-08-31 20:40:00.636469 :C73D6B38: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-08-31 20:50:01.374090 :C73E3226:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 20:50:01.691439 :C73E325F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 20:50:01.686 2025-08-31 20:50:01.691441 :C73E3260:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23372 pso_num=22 pso_serial#=37 2025-08-31 20:50:01.691582 :C73E3261:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23372 osp_idx=0 osp_ver=558049 osp_pg=0 (spawn #545672) 2025-08-31 20:50:01.691583 :C73E3262:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 20:50:01.691583 :C73E3263:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=65 time=1059053002 2025-08-31 20:50:01.691584 :C73E3264:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 20:50:01.691584 :C73E3265:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 20:50:01.691585 :C73E3266:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 20:50:01.691585 :C73E3267:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 20:50:01.691585 :C73E3268:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 20:50:01.692120 :C73E3269: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-08-31 20:50:01.692167 :C73E3271: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-08-31 21:00:02.539596 :C73EF871:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 21:00:02.819967 :C73EF8AC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 21:00:02.815 2025-08-31 21:00:02.819970 :C73EF8AD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20516 pso_num=22 pso_serial#=38 2025-08-31 21:00:02.820111 :C73EF8AE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20516 osp_idx=0 osp_ver=558050 osp_pg=0 (spawn #545694) 2025-08-31 21:00:02.820112 :C73EF8AF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 21:00:02.820112 :C73EF8B0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=66 time=1059654127 2025-08-31 21:00:02.820113 :C73EF8B1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 21:00:02.820113 :C73EF8B2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 21:00:02.820114 :C73EF8B3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 21:00:02.820114 :C73EF8B4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 21:00:02.820114 :C73EF8B5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 21:00:02.820612 :C73EF8B6: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-08-31 21:00:02.820665 :C73EF8C0: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-08-31 21:10:03.642065 :C73FCB42:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 21:10:03.962481 :C73FCB7B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 21:10:03.954 2025-08-31 21:10:03.962483 :C73FCB7C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23460 pso_num=22 pso_serial#=39 2025-08-31 21:10:03.962613 :C73FCB7D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23460 osp_idx=0 osp_ver=558051 osp_pg=0 (spawn #545720) 2025-08-31 21:10:03.962614 :C73FCB7E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 21:10:03.962614 :C73FCB7F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=67 time=1060255268 2025-08-31 21:10:03.962614 :C73FCB80:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 21:10:03.962615 :C73FCB81:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 21:10:03.962615 :C73FCB82:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 21:10:03.962615 :C73FCB83:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 21:10:03.962616 :C73FCB84:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 21:10:03.963086 :C73FCB85: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-08-31 21:10:03.963895 :C73FCB8D: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-08-31 21:20:04.763467 :C7409234:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 21:20:05.018213 :C7409276:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 21:20:05.014 2025-08-31 21:20:05.018215 :C7409277:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16984 pso_num=22 pso_serial#=40 2025-08-31 21:20:05.018355 :C7409278:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16984 osp_idx=0 osp_ver=558052 osp_pg=0 (spawn #545743) 2025-08-31 21:20:05.018356 :C7409279:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 21:20:05.018356 :C740927A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=68 time=1060856330 2025-08-31 21:20:05.018356 :C740927B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 21:20:05.018357 :C740927C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 21:20:05.018357 :C740927D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 21:20:05.018358 :C740927E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 21:20:05.018358 :C740927F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 21:20:05.018856 :C7409280: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-08-31 21:20:05.018899 :C7409288: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-08-31 21:30:05.820442 :C74159EC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 21:30:06.241592 :C7415A29:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 21:30:06.236 2025-08-31 21:30:06.241594 :C7415A2A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23372 pso_num=22 pso_serial#=41 2025-08-31 21:30:06.241738 :C7415A2B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23372 osp_idx=0 osp_ver=558053 osp_pg=0 (spawn #545765) 2025-08-31 21:30:06.241738 :C7415A2C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 21:30:06.241739 :C7415A2D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=69 time=1061457549 2025-08-31 21:30:06.241739 :C7415A2E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 21:30:06.241739 :C7415A2F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 21:30:06.241740 :C7415A30:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 21:30:06.241740 :C7415A31:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 21:30:06.241740 :C7415A32:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 21:30:06.242236 :C7415A33: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-08-31 21:30:06.242291 :C7415A3C: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-08-31 21:35:22.165447 :C741C375: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-08-31 21:40:07.468685 :C74221AA: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-08-31 21:50:08.290656 :C742E926:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 21:50:08.758638 :C742E961:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 21:50:08.754 2025-08-31 21:50:08.758640 :C742E962:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22252 pso_num=22 pso_serial#=42 2025-08-31 21:50:08.758780 :C742E963:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22252 osp_idx=0 osp_ver=558054 osp_pg=0 (spawn #545810) 2025-08-31 21:50:08.758781 :C742E964:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 21:50:08.758781 :C742E965:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=70 time=1062660065 2025-08-31 21:50:08.758782 :C742E966:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 21:50:08.758782 :C742E967:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 21:50:08.758782 :C742E968:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 21:50:08.758783 :C742E969:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 21:50:08.758783 :C742E96A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 21:50:08.759283 :C742E96B: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-08-31 21:50:08.759332 :C742E972: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-08-31 22:00:09.616456 :C743B129:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-31 22:00:09.949382 :C743B171:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-31 22:00:09.944 2025-08-31 22:00:09.949384 :C743B172:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21040 pso_num=22 pso_serial#=43 2025-08-31 22:00:09.949527 :C743B173:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21040 osp_idx=0 osp_ver=558055 osp_pg=0 (spawn #545834) 2025-08-31 22:00:09.949528 :C743B174:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-31 22:00:09.949528 :C743B175:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=71 time=1063261252 2025-08-31 22:00:09.949529 :C743B176:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-31 22:00:09.949529 :C743B177:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-31 22:00:09.949529 :C743B178:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-31 22:00:09.949530 :C743B179:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-31 22:00:09.949530 :C743B17A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-31 22:00:09.950033 :C743B17B: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-08-31 22:00:09.950078 :C743B182: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: 21040, W000)