Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250830180411\orcl_w000_22192_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:35116M/63366M, Ph+PgF:40113M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 22192, image: ORACLE.EXE (W000) *** 2025-08-30 18:04:11.280 *** SESSION ID:(193.3703) 2025-08-30 18:04:11.280 *** 2025-08-30 18:04:11.280 Process diagnostic dump for ORACLE.EXE (W000), OS id=22192, pid: 24, proc_ser: 215, sid: 193, sess_ser: 3703 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=89 seq_num=90 snap_id=1 wait times: snap=3.344213 sec, exc=3.344213 sec, total=3.344213 sec wait times: max=5.000000 sec, heur=7 min 23 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.000021 sec since current wait 0: 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.000188 sec, exc=5.000188 sec, total=5.000188 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: 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.015278 sec, exc=5.015278 sec, total=5.015278 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 2: 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.014020 sec, exc=5.014020 sec, total=5.014020 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 3: 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.004663 sec, exc=5.004663 sec, total=5.004663 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=84 seq_num=85 snap_id=1 wait times: snap=5.004611 sec, exc=5.004611 sec, total=5.004611 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 5: 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.007249 sec, exc=5.007249 sec, total=5.007249 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 6: 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.001167 sec, exc=5.001167 sec, total=5.001167 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=81 seq_num=82 snap_id=1 wait times: snap=5.007226 sec, exc=5.007226 sec, total=5.007226 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 8: 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.012197 sec, exc=5.012197 sec, total=5.012197 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=79 seq_num=80 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.000024 sec of elapsed time Sampled Session History of session 193 serial 3703 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [121 samples, 18:02:11 - 18:04:11] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-30 18:04:11.280 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 22192, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-30 15:26:29.218112 :C6B34299:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 15:26:29.218112 :C6B3429A:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 15:26:29.218607 :C6B3429B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 15:26:29.218653 :C6B342A2:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 15:36:30.093974 :C6B40A83:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 15:36:30.426856 :C6B40ADC:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 15:36:30.422 2025-08-30 15:36:30.426858 :C6B40ADD:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=16876 pso_num=24 pso_serial#=202 2025-08-30 15:36:30.426995 :C6B40ADE:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=16876 osp_idx=22 osp_ver=822332 osp_pg=0 (spawn #541601) 2025-08-30 15:36:30.426996 :C6B40ADF:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 15:36:30.426996 :C6B40AE0:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=13 time=953841737 2025-08-30 15:36:30.426997 :C6B40AE1:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 15:36:30.426997 :C6B40AE2:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 15:36:30.426997 :C6B40AE3:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 15:36:30.426998 :C6B40AE4:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 15:36:30.426998 :C6B40AE5:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 15:36:30.427493 :C6B40AE6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 15:36:30.427540 :C6B40AED:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 15:46:31.248105 :C6B4D182:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 15:46:31.580999 :C6B4D1E4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 15:46:31.576 2025-08-30 15:46:31.581001 :C6B4D1E5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=19356 pso_num=24 pso_serial#=203 2025-08-30 15:46:31.581133 :C6B4D1E6:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=19356 osp_idx=22 osp_ver=822333 osp_pg=0 (spawn #541624) 2025-08-30 15:46:31.581134 :C6B4D1E7:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 15:46:31.581134 :C6B4D1E8:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=14 time=954442893 2025-08-30 15:46:31.581135 :C6B4D1E9:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 15:46:31.581135 :C6B4D1EA:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 15:46:31.581135 :C6B4D1EB:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 15:46:31.581136 :C6B4D1EC:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 15:46:31.581136 :C6B4D1ED:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 15:46:31.581638 :C6B4D1EE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 15:46:31.581687 :C6B4D1F6:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 15:56:32.549227 :C6B59857:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 15:56:32.814153 :C6B598C4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 15:56:32.809 2025-08-30 15:56:32.814155 :C6B598C5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=16392 pso_num=24 pso_serial#=204 2025-08-30 15:56:32.814303 :C6B598C6:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=16392 osp_idx=22 osp_ver=822334 osp_pg=0 (spawn #541646) 2025-08-30 15:56:32.814305 :C6B598C7:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 15:56:32.814306 :C6B598C8:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=15 time=955044112 2025-08-30 15:56:32.814306 :C6B598C9:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 15:56:32.814307 :C6B598CA:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 15:56:32.814307 :C6B598CB:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 15:56:32.814307 :C6B598CC:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 15:56:32.814308 :C6B598CD:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 15:56:32.814807 :C6B598CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 15:56:32.814852 :C6B598D5:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 16:06:33.552914 :C6B66855:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 16:06:34.005207 :C6B66895:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 16:06:34.001 2025-08-30 16:06:34.005209 :C6B66896:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=19940 pso_num=24 pso_serial#=205 2025-08-30 16:06:34.005367 :C6B66897:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=19940 osp_idx=22 osp_ver=822335 osp_pg=0 (spawn #541673) 2025-08-30 16:06:34.005368 :C6B66898:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 16:06:34.005369 :C6B66899:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=16 time=955645315 2025-08-30 16:06:34.005369 :C6B6689A:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 16:06:34.005370 :C6B6689B:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 16:06:34.005370 :C6B6689C:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 16:06:34.005371 :C6B6689D:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 16:06:34.005371 :C6B6689E:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 16:06:34.005920 :C6B6689F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 16:06:34.005969 :C6B668A9:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 16:16:34.947151 :C6B7337A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 16:16:35.108154 :C6B733B2:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 16:16:35.103 2025-08-30 16:16:35.108155 :C6B733B3:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22740 pso_num=24 pso_serial#=206 2025-08-30 16:16:35.108290 :C6B733B4:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22740 osp_idx=22 osp_ver=822336 osp_pg=0 (spawn #541696) 2025-08-30 16:16:35.108291 :C6B733B5:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 16:16:35.108291 :C6B733B6:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=17 time=956246408 2025-08-30 16:16:35.108291 :C6B733B7:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 16:16:35.108291 :C6B733B8:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 16:16:35.108292 :C6B733B9:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 16:16:35.108292 :C6B733BA:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 16:16:35.108292 :C6B733BB:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 16:16:35.108775 :C6B733BC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 16:16:35.108819 :C6B733C3:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 16:26:36.021676 :C6B7FC59:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 16:26:36.354617 :C6B7FC9F:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 16:26:36.349 2025-08-30 16:26:36.354619 :C6B7FCA0:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=19848 pso_num=24 pso_serial#=207 2025-08-30 16:26:36.354764 :C6B7FCA1:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=19848 osp_idx=22 osp_ver=822337 osp_pg=0 (spawn #541718) 2025-08-30 16:26:36.354764 :C6B7FCA2:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 16:26:36.354765 :C6B7FCA3:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=18 time=956847658 2025-08-30 16:26:36.354765 :C6B7FCA4:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 16:26:36.354765 :C6B7FCA5:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 16:26:36.354766 :C6B7FCA6:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 16:26:36.354766 :C6B7FCA7:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 16:26:36.354766 :C6B7FCA8:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 16:26:36.355274 :C6B7FCA9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 16:26:36.355323 :C6B7FCB0:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 16:36:37.179502 :C6B8C5AD:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 16:36:37.574902 :C6B8C603:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 16:36:37.570 2025-08-30 16:36:37.574903 :C6B8C604:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=21392 pso_num=24 pso_serial#=208 2025-08-30 16:36:37.575041 :C6B8C605:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=21392 osp_idx=22 osp_ver=822338 osp_pg=0 (spawn #541741) 2025-08-30 16:36:37.575042 :C6B8C606:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 16:36:37.575043 :C6B8C607:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=19 time=957448877 2025-08-30 16:36:37.575043 :C6B8C608:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 16:36:37.575044 :C6B8C609:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 16:36:37.575044 :C6B8C60A:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 16:36:37.575044 :C6B8C60B:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 16:36:37.575045 :C6B8C60C:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 16:36:37.575534 :C6B8C60D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 16:36:37.575579 :C6B8C615:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 16:46:38.333234 :C6B98E29:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 16:46:38.728861 :C6B98E80:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 16:46:38.724 2025-08-30 16:46:38.728864 :C6B98E81:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=16768 pso_num=24 pso_serial#=209 2025-08-30 16:46:38.729009 :C6B98E82:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=16768 osp_idx=22 osp_ver=822339 osp_pg=0 (spawn #541764) 2025-08-30 16:46:38.729010 :C6B98E83:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 16:46:38.729011 :C6B98E84:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=20 time=958050033 2025-08-30 16:46:38.729011 :C6B98E85:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 16:46:38.729011 :C6B98E86:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 16:46:38.729012 :C6B98E87:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 16:46:38.729012 :C6B98E88:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 16:46:38.729012 :C6B98E89:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 16:46:38.729549 :C6B98E8A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 16:46:38.729597 :C6B98E91:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 16:56:39.617593 :C6BA56EC:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 16:56:39.950549 :C6BA573A:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 16:56:39.946 2025-08-30 16:56:39.950551 :C6BA573B:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=23388 pso_num=24 pso_serial#=210 2025-08-30 16:56:39.950679 :C6BA573C:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=23388 osp_idx=22 osp_ver=822340 osp_pg=0 (spawn #541786) 2025-08-30 16:56:39.950679 :C6BA573D:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 16:56:39.950680 :C6BA573E:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=21 time=958651252 2025-08-30 16:56:39.950680 :C6BA573F:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 16:56:39.950681 :C6BA5740:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 16:56:39.950681 :C6BA5741:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 16:56:39.950682 :C6BA5742:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 16:56:39.950682 :C6BA5743:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 16:56:39.951215 :C6BA5744:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 16:56:39.954474 :C6BA574E:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 17:04:56.412930 :C6BAFF01:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 17:06:41.028387 :C6BB2868:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 17:16:41.838539 :C6BBF331:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 17:16:42.249712 :C6BBF36E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 17:16:42.244 2025-08-30 17:16:42.249714 :C6BBF36F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22956 pso_num=24 pso_serial#=211 2025-08-30 17:16:42.249857 :C6BBF370:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22956 osp_idx=22 osp_ver=822341 osp_pg=0 (spawn #541834) 2025-08-30 17:16:42.249857 :C6BBF371:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 17:16:42.249858 :C6BBF372:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=22 time=959853549 2025-08-30 17:16:42.249858 :C6BBF373:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 17:16:42.249859 :C6BBF374:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 17:16:42.249859 :C6BBF375:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 17:16:42.249859 :C6BBF376:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 17:16:42.249860 :C6BBF377:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 17:16:42.250377 :C6BBF378:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 17:16:42.250440 :C6BBF37E:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 17:26:42.992152 :C6BCBC1C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 17:26:43.465708 :C6BCBC53:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 17:26:43.461 2025-08-30 17:26:43.465710 :C6BCBC54:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=4124 pso_num=24 pso_serial#=212 2025-08-30 17:26:43.465848 :C6BCBC55:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=4124 osp_idx=22 osp_ver=822342 osp_pg=0 (spawn #541856) 2025-08-30 17:26:43.465848 :C6BCBC56:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 17:26:43.465849 :C6BCBC57:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=23 time=960454768 2025-08-30 17:26:43.465849 :C6BCBC58:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 17:26:43.465849 :C6BCBC59:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 17:26:43.465850 :C6BCBC5A:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 17:26:43.465850 :C6BCBC5B:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 17:26:43.465851 :C6BCBC5C:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 17:26:43.466347 :C6BCBC5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 17:26:43.466394 :C6BCBC63:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 17:36:44.355114 :C6BD8517:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 17:36:44.735689 :C6BD855B:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 17:36:44.731 2025-08-30 17:36:44.735691 :C6BD855C:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=20784 pso_num=24 pso_serial#=213 2025-08-30 17:36:44.735829 :C6BD855D:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=20784 osp_idx=22 osp_ver=822343 osp_pg=0 (spawn #541879) 2025-08-30 17:36:44.735830 :C6BD855E:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 17:36:44.735830 :C6BD855F:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=24 time=961056033 2025-08-30 17:36:44.735831 :C6BD8560:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 17:36:44.735831 :C6BD8561:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 17:36:44.735832 :C6BD8562:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 17:36:44.735832 :C6BD8563:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 17:36:44.735832 :C6BD8564:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 17:36:44.736343 :C6BD8565:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 17:36:44.736396 :C6BD856C:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 17:46:45.580166 :C6BE4D65:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 17:46:45.944295 :C6BE4D9B:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 17:46:45.940 2025-08-30 17:46:45.944297 :C6BE4D9C:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22880 pso_num=24 pso_serial#=214 2025-08-30 17:46:45.944427 :C6BE4D9D:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22880 osp_idx=22 osp_ver=822344 osp_pg=0 (spawn #541902) 2025-08-30 17:46:45.944428 :C6BE4D9E:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 17:46:45.944428 :C6BE4D9F:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=25 time=961657252 2025-08-30 17:46:45.944429 :C6BE4DA0:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 17:46:45.944429 :C6BE4DA1:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 17:46:45.944429 :C6BE4DA2:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 17:46:45.944430 :C6BE4DA3:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 17:46:45.944430 :C6BE4DA4:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 17:46:45.944981 :C6BE4DA5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 17:46:45.945025 :C6BE4DAD:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-30 17:56:46.790612 :C6BF166A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-08-30 17:56:47.326762 :C6BF16B0:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 08-30 17:56:47.321 2025-08-30 17:56:47.326764 :C6BF16B1:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22192 pso_num=24 pso_serial#=215 2025-08-30 17:56:47.326905 :C6BF16B2:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=22192 osp_idx=22 osp_ver=822345 osp_pg=0 (spawn #541924) 2025-08-30 17:56:47.326905 :C6BF16B3:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 17:56:47.326905 :C6BF16B4:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=26 time=962258627 2025-08-30 17:56:47.326906 :C6BF16B5:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 17:56:47.326906 :C6BF16B6:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 17:56:47.326906 :C6BF16B7:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 17:56:47.326907 :C6BF16B8:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 17:56:47.326907 :C6BF16B9:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 17:56:47.327422 :C6BF16BA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-30 17:56:47.327471 :C6BF16C1:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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 24 (osid: 22192, W000)