Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250824140416\orcl_w000_20892_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:35258M/63366M, Ph+PgF:40419M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 20892, image: ORACLE.EXE (W000) *** 2025-08-24 14:04:16.592 *** SESSION ID:(177.48357) 2025-08-24 14:04:16.592 *** 2025-08-24 14:04:16.592 Process diagnostic dump for ORACLE.EXE (W000), OS id=20892, pid: 22, proc_ser: 189, sid: 177, sess_ser: 48357 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=78 seq_num=79 snap_id=1 wait times: snap=1.788324 sec, exc=1.788324 sec, total=1.788324 sec wait times: max=5.000000 sec, heur=6 min 27 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.000054 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=77 seq_num=78 snap_id=1 wait times: snap=5.002456 sec, exc=5.002456 sec, total=5.002456 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000087 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=76 seq_num=77 snap_id=1 wait times: snap=5.014761 sec, exc=5.014761 sec, total=5.014761 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=75 seq_num=76 snap_id=1 wait times: snap=5.004626 sec, exc=5.004626 sec, total=5.004626 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=74 seq_num=75 snap_id=1 wait times: snap=5.014741 sec, exc=5.014741 sec, total=5.014741 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=73 seq_num=74 snap_id=1 wait times: snap=5.007223 sec, exc=5.007223 sec, total=5.007223 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=72 seq_num=73 snap_id=1 wait times: snap=5.013546 sec, exc=5.013546 sec, total=5.013546 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=71 seq_num=72 snap_id=1 wait times: snap=5.015077 sec, exc=5.015077 sec, total=5.015077 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=70 seq_num=71 snap_id=1 wait times: snap=5.009216 sec, exc=5.009216 sec, total=5.009216 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=69 seq_num=70 snap_id=1 wait times: snap=5.004638 sec, exc=5.004638 sec, total=5.004638 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=68 seq_num=69 snap_id=1 wait times: snap=5.004606 sec, exc=5.004606 sec, total=5.004606 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000042 sec of elapsed time Sampled Session History of session 177 serial 48357 --------------------------------------------------- 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, 14:02:16 - 14:04:16] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-24 14:04:16.592 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 20892, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-24 11:27:29.680401 :C3FE6D81:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 11:27:29.680401 :C3FE6D82:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 11:27:29.680880 :C3FE6D83: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-24 11:27:29.680926 :C3FE6D8A: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-24 11:37:30.579427 :C3FF3A24:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 11:37:30.943483 :C3FF3A8A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 11:37:30.939 2025-08-24 11:37:30.943486 :C3FF3A8B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19396 pso_num=22 pso_serial#=176 2025-08-24 11:37:30.943630 :C3FF3A8C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19396 osp_idx=0 osp_ver=544928 osp_pg=0 (spawn #521050) 2025-08-24 11:37:30.943631 :C3FF3A8D: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-24 11:37:30.943632 :C3FF3A8E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=61 time=421152955 2025-08-24 11:37:30.943632 :C3FF3A8F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 11:37:30.943632 :C3FF3A90:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 11:37:30.943633 :C3FF3A91:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 11:37:30.943633 :C3FF3A92:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 11:37:30.943633 :C3FF3A93:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 11:37:30.944146 :C3FF3A94: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-24 11:37:30.944193 :C3FF3A9C: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-24 11:47:31.775872 :C4000677:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 11:47:32.171033 :C40006D7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 11:47:32.166 2025-08-24 11:47:32.171036 :C40006D8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21076 pso_num=22 pso_serial#=177 2025-08-24 11:47:32.171177 :C40006D9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21076 osp_idx=0 osp_ver=544929 osp_pg=0 (spawn #521073) 2025-08-24 11:47:32.171177 :C40006DA: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-24 11:47:32.171178 :C40006DB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=62 time=421754174 2025-08-24 11:47:32.171179 :C40006DC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 11:47:32.171180 :C40006DD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 11:47:32.171180 :C40006DE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 11:47:32.171180 :C40006DF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 11:47:32.171180 :C40006E0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 11:47:32.171692 :C40006E1: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-24 11:47:32.171736 :C40006E8: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-24 11:57:33.140874 :C400D031:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 11:57:33.536553 :C400D095:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 11:57:33.532 2025-08-24 11:57:33.536556 :C400D096:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20940 pso_num=22 pso_serial#=178 2025-08-24 11:57:33.536710 :C400D097:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20940 osp_idx=0 osp_ver=544930 osp_pg=0 (spawn #521096) 2025-08-24 11:57:33.536711 :C400D098: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-24 11:57:33.536712 :C400D099:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=63 time=422355549 2025-08-24 11:57:33.536712 :C400D09A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 11:57:33.536712 :C400D09B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 11:57:33.536713 :C400D09C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 11:57:33.536713 :C400D09D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 11:57:33.536713 :C400D09E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 11:57:33.537261 :C400D09F: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-24 11:57:33.537307 :C400D0A7: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-24 12:07:34.477984 :C401A5E9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 12:07:34.842085 :C401A633:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 12:07:34.837 2025-08-24 12:07:34.842087 :C401A634:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19052 pso_num=22 pso_serial#=179 2025-08-24 12:07:34.842217 :C401A635:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19052 osp_idx=0 osp_ver=544931 osp_pg=0 (spawn #521121) 2025-08-24 12:07:34.842217 :C401A636: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-24 12:07:34.842218 :C401A637:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=64 time=422956846 2025-08-24 12:07:34.842218 :C401A638:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 12:07:34.842219 :C401A639:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 12:07:34.842219 :C401A63A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 12:07:34.842220 :C401A63B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 12:07:34.842220 :C401A63C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 12:07:34.842773 :C401A63D: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-24 12:07:34.842829 :C401A644: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-24 12:17:35.739259 :C40271AB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 12:17:36.082272 :C40271E8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 12:17:36.077 2025-08-24 12:17:36.082274 :C40271E9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20996 pso_num=22 pso_serial#=180 2025-08-24 12:17:36.082412 :C40271EA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20996 osp_idx=0 osp_ver=544932 osp_pg=0 (spawn #521144) 2025-08-24 12:17:36.082412 :C40271EB: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-24 12:17:36.082413 :C40271EC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=65 time=423558096 2025-08-24 12:17:36.082413 :C40271ED:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 12:17:36.082413 :C40271EE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 12:17:36.082414 :C40271EF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 12:17:36.082414 :C40271F0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 12:17:36.082414 :C40271F1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 12:17:36.082911 :C40271F2: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-24 12:17:36.082957 :C40271FC: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-24 12:27:36.959889 :C4034095:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 12:27:37.417691 :C40340DD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 12:27:37.413 2025-08-24 12:27:37.417693 :C40340DE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20856 pso_num=22 pso_serial#=181 2025-08-24 12:27:37.417830 :C40340DF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20856 osp_idx=0 osp_ver=544933 osp_pg=0 (spawn #521167) 2025-08-24 12:27:37.417831 :C40340E0: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-24 12:27:37.417831 :C40340E1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=66 time=424159424 2025-08-24 12:27:37.417832 :C40340E2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 12:27:37.417832 :C40340E3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 12:27:37.417832 :C40340E4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 12:27:37.417833 :C40340E5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 12:27:37.417833 :C40340E6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 12:27:37.418321 :C40340E7: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-24 12:27:37.418364 :C40340EF: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-24 12:37:38.273885 :C4040AC7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 12:37:38.637898 :C4040B02:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 12:37:38.633 2025-08-24 12:37:38.637900 :C4040B03:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17200 pso_num=22 pso_serial#=182 2025-08-24 12:37:38.638039 :C4040B04:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17200 osp_idx=0 osp_ver=544934 osp_pg=0 (spawn #521189) 2025-08-24 12:37:38.638039 :C4040B05: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-24 12:37:38.638039 :C4040B06:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=67 time=424760643 2025-08-24 12:37:38.638040 :C4040B07:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 12:37:38.638041 :C4040B08:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 12:37:38.638041 :C4040B09:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 12:37:38.638041 :C4040B0A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 12:37:38.638042 :C4040B0B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 12:37:38.638538 :C4040B0C: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-24 12:37:38.638594 :C4040B16: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-24 12:47:39.564314 :C404D309:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 12:47:39.897141 :C404D34F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 12:47:39.892 2025-08-24 12:47:39.897143 :C404D350:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21748 pso_num=22 pso_serial#=183 2025-08-24 12:47:39.897283 :C404D351:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21748 osp_idx=0 osp_ver=544935 osp_pg=0 (spawn #521212) 2025-08-24 12:47:39.897284 :C404D352: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-24 12:47:39.897284 :C404D353:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=68 time=425361908 2025-08-24 12:47:39.897285 :C404D354:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 12:47:39.897285 :C404D355:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 12:47:39.897286 :C404D356:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 12:47:39.897286 :C404D357:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 12:47:39.897286 :C404D358:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 12:47:39.897784 :C404D359: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-24 12:47:39.897831 :C404D362: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-24 12:57:40.941384 :C4059B6D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 12:57:41.196049 :C4059BA9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 12:57:41.191 2025-08-24 12:57:41.196051 :C4059BAA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21952 pso_num=22 pso_serial#=184 2025-08-24 12:57:41.196190 :C4059BAB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21952 osp_idx=0 osp_ver=544936 osp_pg=0 (spawn #521235) 2025-08-24 12:57:41.196190 :C4059BAC: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-24 12:57:41.196191 :C4059BAD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=69 time=425963205 2025-08-24 12:57:41.196191 :C4059BAE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 12:57:41.196192 :C4059BAF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 12:57:41.196192 :C4059BB0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 12:57:41.196192 :C4059BB1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 12:57:41.196192 :C4059BB2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 12:57:41.196679 :C4059BB3: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-24 12:57:41.196736 :C4059BB9: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-24 13:03:02.101591 :C4060A27: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-24 13:07:42.607880 :C4066E75: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-24 13:17:43.509065 :C40735C5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 13:17:43.872939 :C40735FF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 13:17:43.868 2025-08-24 13:17:43.872941 :C4073600:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12948 pso_num=22 pso_serial#=185 2025-08-24 13:17:43.873075 :C4073601:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12948 osp_idx=0 osp_ver=544937 osp_pg=0 (spawn #521283) 2025-08-24 13:17:43.873076 :C4073602: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-24 13:17:43.873076 :C4073603:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=70 time=427165877 2025-08-24 13:17:43.873077 :C4073604:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 13:17:43.873077 :C4073605:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 13:17:43.873077 :C4073606:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 13:17:43.873078 :C4073607:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 13:17:43.873078 :C4073608:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 13:17:43.873561 :C4073609: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-24 13:17:43.873610 :C4073612: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-24 13:27:44.742237 :C408011F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 13:27:45.241662 :C4080167:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 13:27:45.237 2025-08-24 13:27:45.241664 :C4080168:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21036 pso_num=22 pso_serial#=186 2025-08-24 13:27:45.241808 :C4080169:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21036 osp_idx=0 osp_ver=544938 osp_pg=0 (spawn #521306) 2025-08-24 13:27:45.241809 :C408016A: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-24 13:27:45.241809 :C408016B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=71 time=427767252 2025-08-24 13:27:45.241810 :C408016C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 13:27:45.241810 :C408016D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 13:27:45.241810 :C408016E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 13:27:45.241811 :C408016F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 13:27:45.241811 :C4080170:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 13:27:45.242312 :C4080171: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-24 13:27:45.242357 :C4080178: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-24 13:37:46.044719 :C408C933:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 13:37:46.487150 :C408C973:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 13:37:46.482 2025-08-24 13:37:46.487151 :C408C974:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20996 pso_num=22 pso_serial#=187 2025-08-24 13:37:46.487290 :C408C975:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20996 osp_idx=0 osp_ver=544939 osp_pg=0 (spawn #521328) 2025-08-24 13:37:46.487291 :C408C976: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-24 13:37:46.487291 :C408C977:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=72 time=428368502 2025-08-24 13:37:46.487292 :C408C978:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 13:37:46.487292 :C408C979:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 13:37:46.487292 :C408C97A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 13:37:46.487293 :C408C97B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 13:37:46.487293 :C408C97C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 13:37:46.487843 :C408C97D: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-24 13:37:46.487901 :C408C987: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-24 13:47:47.400652 :C40991E7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 13:47:47.905639 :C409922D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 13:47:47.901 2025-08-24 13:47:47.905641 :C409922E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4644 pso_num=22 pso_serial#=188 2025-08-24 13:47:47.905780 :C409922F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4644 osp_idx=0 osp_ver=544940 osp_pg=0 (spawn #521351) 2025-08-24 13:47:47.905781 :C4099230: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-24 13:47:47.905781 :C4099231:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=73 time=428969908 2025-08-24 13:47:47.905781 :C4099232:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 13:47:47.905782 :C4099233:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 13:47:47.905782 :C4099234:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 13:47:47.905782 :C4099235:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 13:47:47.905783 :C4099236:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 13:47:47.906299 :C4099237: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-24 13:47:47.906342 :C409923E: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-24 13:57:48.741633 :C40A5A7F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-24 13:57:49.230802 :C40A5AB8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-24 13:57:49.225 2025-08-24 13:57:49.230804 :C40A5AB9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20892 pso_num=22 pso_serial#=189 2025-08-24 13:57:49.230946 :C40A5ABA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=20892 osp_idx=0 osp_ver=544941 osp_pg=0 (spawn #521374) 2025-08-24 13:57:49.230947 :C40A5ABB: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-24 13:57:49.230947 :C40A5ABC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=74 time=429571237 2025-08-24 13:57:49.230948 :C40A5ABD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-24 13:57:49.230948 :C40A5ABE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-24 13:57:49.230948 :C40A5ABF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-24 13:57:49.230949 :C40A5AC0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-24 13:57:49.230949 :C40A5AC1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-24 13:57:49.231446 :C40A5AC2: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-24 13:57:49.231491 :C40A5AC9: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: 20892, W000)