Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250509220008\orcl_w000_11512_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:37482M/63366M, Ph+PgF:44850M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 11512, image: ORACLE.EXE (W000) *** 2025-05-09 22:00:08.712 *** SESSION ID:(177.9991) 2025-05-09 22:00:08.712 *** 2025-05-09 22:00:08.712 Process diagnostic dump for ORACLE.EXE (W000), OS id=11512, pid: 22, proc_ser: 253, sid: 177, sess_ser: 9991 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=97 seq_num=98 snap_id=1 wait times: snap=3.236336 sec, exc=3.236336 sec, total=3.236336 sec wait times: max=5.000000 sec, heur=8 min 3 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.000038 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=96 seq_num=97 snap_id=1 wait times: snap=5.009222 sec, exc=5.009222 sec, total=5.009222 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000035 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=95 seq_num=96 snap_id=1 wait times: snap=5.010108 sec, exc=5.010108 sec, total=5.010108 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000078 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=94 seq_num=95 snap_id=1 wait times: snap=5.009728 sec, exc=5.009728 sec, total=5.009728 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000038 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=93 seq_num=94 snap_id=1 wait times: snap=5.003224 sec, exc=5.003224 sec, total=5.003224 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=92 seq_num=93 snap_id=1 wait times: snap=5.009283 sec, exc=5.009283 sec, total=5.009283 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=91 seq_num=92 snap_id=1 wait times: snap=5.006035 sec, exc=5.006035 sec, total=5.006035 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000034 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=90 seq_num=91 snap_id=1 wait times: snap=5.014731 sec, exc=5.014731 sec, total=5.014731 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=89 seq_num=90 snap_id=1 wait times: snap=5.010142 sec, exc=5.010142 sec, total=5.010142 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 8: 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.009184 sec, exc=5.009184 sec, total=5.009184 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 9: 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.007218 sec, exc=5.007218 sec, total=5.007218 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time Sampled Session History of session 177 serial 9991 --------------------------------------------------- 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, 21:58:08 - 22:00:08] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-09 22:00:08.712 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 11512, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-09 19:21:14.597599 :94E71E53: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-05-09 19:21:44.705511 :94E727BF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 19:21:44.725809 :94E7281F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 19:21:44.721 2025-05-09 19:21:44.725811 :94E72820:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8784 pso_num=22 pso_serial#=240 2025-05-09 19:21:44.725944 :94E72821:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8784 osp_idx=0 osp_ver=173385 osp_pg=0 (spawn #165292) 2025-05-09 19:21:44.725945 :94E72822:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 19:21:44.725945 :94E72823:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=79 time=4089281890 2025-05-09 19:21:44.725945 :94E72824:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 19:21:44.725946 :94E72825:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 19:21:44.725946 :94E72826:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 19:21:44.725946 :94E72827:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 19:21:44.725947 :94E72828:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 19:21:44.726433 :94E72829: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-05-09 19:21:44.726481 :94E72832: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-05-09 19:31:45.717223 :94E7EB0D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 19:31:46.034448 :94E7EB8B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 19:31:46.034 2025-05-09 19:31:46.034450 :94E7EB8C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13148 pso_num=22 pso_serial#=241 2025-05-09 19:31:46.034587 :94E7EB8D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13148 osp_idx=0 osp_ver=173386 osp_pg=0 (spawn #165316) 2025-05-09 19:31:46.034588 :94E7EB8E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 19:31:46.034589 :94E7EB8F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=80 time=4089883203 2025-05-09 19:31:46.034590 :94E7EB90:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 19:31:46.034590 :94E7EB91:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 19:31:46.034591 :94E7EB92:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 19:31:46.034591 :94E7EB93:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 19:31:46.034592 :94E7EB94:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 19:31:46.035091 :94E7EB95: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-05-09 19:31:46.035134 :94E7EB9C: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-05-09 19:35:23.793185 :94E83299: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-05-09 19:41:47.296131 :94E8AF1C: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-05-09 19:51:48.195101 :94E971DB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 19:51:48.527670 :94E97256:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 19:51:48.522 2025-05-09 19:51:48.527673 :94E97257:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10332 pso_num=22 pso_serial#=242 2025-05-09 19:51:48.527857 :94E97258:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10332 osp_idx=0 osp_ver=173387 osp_pg=0 (spawn #165362) 2025-05-09 19:51:48.527858 :94E97259:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 19:51:48.527858 :94E9725A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=81 time=4091085687 2025-05-09 19:51:48.527858 :94E9725B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 19:51:48.527859 :94E9725C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 19:51:48.527859 :94E9725D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 19:51:48.527860 :94E9725E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 19:51:48.527860 :94E9725F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 19:51:48.528349 :94E97260: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-05-09 19:51:48.528398 :94E9726A: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-05-09 20:01:49.382676 :94EA3647:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 20:01:49.741180 :94EA36B1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 20:01:49.736 2025-05-09 20:01:49.741182 :94EA36B2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11688 pso_num=22 pso_serial#=243 2025-05-09 20:01:49.741314 :94EA36B3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11688 osp_idx=0 osp_ver=173388 osp_pg=0 (spawn #165386) 2025-05-09 20:01:49.741315 :94EA36B4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 20:01:49.741315 :94EA36B5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=82 time=4091686906 2025-05-09 20:01:49.741316 :94EA36B6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 20:01:49.741316 :94EA36B7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 20:01:49.741317 :94EA36B8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 20:01:49.741317 :94EA36B9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 20:01:49.741317 :94EA36BA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 20:01:49.741811 :94EA36BB: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-05-09 20:01:49.741856 :94EA36C3: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-05-09 20:11:50.711942 :94EB02A5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 20:11:50.997960 :94EB031E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 20:11:50.993 2025-05-09 20:11:50.997963 :94EB031F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8776 pso_num=22 pso_serial#=244 2025-05-09 20:11:50.998103 :94EB0320:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8776 osp_idx=0 osp_ver=173389 osp_pg=0 (spawn #165410) 2025-05-09 20:11:50.998104 :94EB0321:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 20:11:50.998104 :94EB0322:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=83 time=4092288171 2025-05-09 20:11:50.998104 :94EB0323:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 20:11:50.998105 :94EB0324:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 20:11:50.998105 :94EB0325:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 20:11:50.998106 :94EB0326:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 20:11:50.998106 :94EB0327:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 20:11:50.998606 :94EB0328: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-05-09 20:11:50.998651 :94EB0331: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-05-09 20:21:51.953452 :94EBC50E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 20:21:52.192590 :94EBC551:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 20:21:52.187 2025-05-09 20:21:52.192592 :94EBC552:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12312 pso_num=22 pso_serial#=245 2025-05-09 20:21:52.192730 :94EBC553:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12312 osp_idx=0 osp_ver=173390 osp_pg=0 (spawn #165433) 2025-05-09 20:21:52.192731 :94EBC554:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 20:21:52.192731 :94EBC555:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=84 time=4092889359 2025-05-09 20:21:52.192732 :94EBC556:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 20:21:52.192733 :94EBC557:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 20:21:52.192733 :94EBC558:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 20:21:52.192734 :94EBC559:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 20:21:52.192734 :94EBC55A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 20:21:52.193235 :94EBC55B: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-05-09 20:21:52.193280 :94EBC563: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-05-09 20:31:53.222235 :94EC87AC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 20:31:53.570643 :94EC87F1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 20:31:53.566 2025-05-09 20:31:53.570645 :94EC87F2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12056 pso_num=22 pso_serial#=246 2025-05-09 20:31:53.570776 :94EC87F3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12056 osp_idx=0 osp_ver=173391 osp_pg=0 (spawn #165457) 2025-05-09 20:31:53.570777 :94EC87F4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 20:31:53.570777 :94EC87F5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=85 time=4093490734 2025-05-09 20:31:53.570778 :94EC87F6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 20:31:53.570778 :94EC87F7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 20:31:53.570778 :94EC87F8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 20:31:53.570779 :94EC87F9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 20:31:53.570779 :94EC87FA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 20:31:53.571256 :94EC87FB: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-05-09 20:31:53.571302 :94EC8802: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-05-09 20:41:54.480075 :94ED4A89:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 20:41:54.828752 :94ED4AD7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 20:41:54.824 2025-05-09 20:41:54.828754 :94ED4AD8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12028 pso_num=22 pso_serial#=247 2025-05-09 20:41:54.828894 :94ED4AD9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12028 osp_idx=0 osp_ver=173392 osp_pg=0 (spawn #165480) 2025-05-09 20:41:54.828895 :94ED4ADA:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 20:41:54.828895 :94ED4ADB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=86 time=4094092000 2025-05-09 20:41:54.828895 :94ED4ADC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 20:41:54.828896 :94ED4ADD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 20:41:54.828896 :94ED4ADE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 20:41:54.828896 :94ED4ADF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 20:41:54.828897 :94ED4AE0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 20:41:54.829399 :94ED4AE1: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-05-09 20:41:54.829447 :94ED4AEA: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-05-09 20:51:55.735545 :94EE0E5C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 20:51:56.256514 :94EE0ED9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 20:51:56.251 2025-05-09 20:51:56.256516 :94EE0EDA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12788 pso_num=22 pso_serial#=248 2025-05-09 20:51:56.256671 :94EE0EDB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12788 osp_idx=0 osp_ver=173393 osp_pg=0 (spawn #165503) 2025-05-09 20:51:56.256672 :94EE0EDC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 20:51:56.256672 :94EE0EDD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=87 time=4094693421 2025-05-09 20:51:56.256673 :94EE0EDE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 20:51:56.256673 :94EE0EDF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 20:51:56.256674 :94EE0EE0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 20:51:56.256674 :94EE0EE1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 20:51:56.256674 :94EE0EE2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 20:51:56.257261 :94EE0EE3: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-05-09 20:51:56.257332 :94EE0EED: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-05-09 21:01:57.148454 :94EED228:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 21:01:57.590664 :94EED29C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 21:01:57.585 2025-05-09 21:01:57.590666 :94EED29D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4696 pso_num=22 pso_serial#=249 2025-05-09 21:01:57.590800 :94EED29E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4696 osp_idx=0 osp_ver=173394 osp_pg=0 (spawn #165527) 2025-05-09 21:01:57.590801 :94EED29F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:01:57.590801 :94EED2A0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=88 time=4095294750 2025-05-09 21:01:57.590802 :94EED2A1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:01:57.590802 :94EED2A2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:01:57.590803 :94EED2A3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:01:57.590803 :94EED2A4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:01:57.590804 :94EED2A5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:01:57.591367 :94EED2A6: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-05-09 21:01:57.591414 :94EED2AC: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-05-09 21:11:58.584573 :94EF9D35:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 21:11:58.999528 :94EF9DA0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 21:11:58.994 2025-05-09 21:11:58.999531 :94EF9DA1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12332 pso_num=22 pso_serial#=250 2025-05-09 21:11:58.999667 :94EF9DA2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12332 osp_idx=0 osp_ver=173395 osp_pg=0 (spawn #165551) 2025-05-09 21:11:58.999668 :94EF9DA3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:11:58.999668 :94EF9DA4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=89 time=4095896171 2025-05-09 21:11:58.999668 :94EF9DA5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:11:58.999669 :94EF9DA6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:11:58.999669 :94EF9DA7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:11:58.999670 :94EF9DA8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:11:58.999670 :94EF9DA9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:11:59.000163 :94EF9DAA: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-05-09 21:11:59.000209 :94EF9DB3: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-05-09 21:21:59.916817 :94F05E24:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 21:22:00.405854 :94F05E9A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 21:22:00.401 2025-05-09 21:22:00.405857 :94F05E9B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10200 pso_num=22 pso_serial#=251 2025-05-09 21:22:00.406001 :94F05E9C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10200 osp_idx=0 osp_ver=173396 osp_pg=0 (spawn #165574) 2025-05-09 21:22:00.406002 :94F05E9D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:22:00.406002 :94F05E9E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=90 time=4096497578 2025-05-09 21:22:00.406002 :94F05E9F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:22:00.406003 :94F05EA0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:22:00.406003 :94F05EA1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:22:00.406004 :94F05EA2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:22:00.406004 :94F05EA3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:22:00.406504 :94F05EA4: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-05-09 21:22:00.406552 :94F05EAE: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-05-09 21:32:01.319298 :94F121B3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 21:32:01.886555 :94F12219:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 21:32:01.882 2025-05-09 21:32:01.886557 :94F1221A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8548 pso_num=22 pso_serial#=252 2025-05-09 21:32:01.886695 :94F1221B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8548 osp_idx=0 osp_ver=173397 osp_pg=0 (spawn #165598) 2025-05-09 21:32:01.886696 :94F1221C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:32:01.886696 :94F1221D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=91 time=4097099046 2025-05-09 21:32:01.886697 :94F1221E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:32:01.886697 :94F1221F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:32:01.886697 :94F12220:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:32:01.886698 :94F12221:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:32:01.886698 :94F12222:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:32:01.887198 :94F12223: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-05-09 21:32:01.887247 :94F1222A: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-05-09 21:40:24.385464 :94F1C3A1: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-05-09 21:42:03.369258 :94F1E33F: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-05-09 21:52:04.229872 :94F2A4B8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-09 21:52:04.744694 :94F2A52B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-09 21:52:04.739 2025-05-09 21:52:04.744697 :94F2A52C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11512 pso_num=22 pso_serial#=253 2025-05-09 21:52:04.744836 :94F2A52D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11512 osp_idx=0 osp_ver=173398 osp_pg=0 (spawn #165643) 2025-05-09 21:52:04.744837 :94F2A52E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-09 21:52:04.744837 :94F2A52F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=92 time=4098301906 2025-05-09 21:52:04.744837 :94F2A530:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 21:52:04.744838 :94F2A531:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 21:52:04.744838 :94F2A532:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 21:52:04.744838 :94F2A533:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 21:52:04.744839 :94F2A534:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 21:52:04.745354 :94F2A535: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-05-09 21:52:04.745399 :94F2A53E: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: 11512, W000)