Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250712141017\orcl_w000_4556_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:36415M/63366M, Ph+PgF:42493M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 4556, image: ORACLE.EXE (W000) *** 2025-07-12 14:10:18.028 *** SESSION ID:(193.49039) 2025-07-12 14:10:18.028 *** 2025-07-12 14:10:18.028 Process diagnostic dump for ORACLE.EXE (W000), OS id=4556, pid: 24, proc_ser: 198, sid: 193, sess_ser: 49039 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=155 seq_num=156 snap_id=1 wait times: snap=3.686537 sec, exc=3.686537 sec, total=3.686537 sec wait times: max=5.000000 sec, heur=7 min 33 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.000019 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=154 seq_num=155 snap_id=1 wait times: snap=5.002734 sec, exc=5.002734 sec, total=5.002734 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=153 seq_num=154 snap_id=1 wait times: snap=5.004627 sec, exc=5.004627 sec, total=5.004627 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=152 seq_num=153 snap_id=1 wait times: snap=5.014730 sec, exc=5.014730 sec, total=5.014730 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=151 seq_num=152 snap_id=1 wait times: snap=5.010148 sec, exc=5.010148 sec, total=5.010148 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=150 seq_num=151 snap_id=1 wait times: snap=5.014740 sec, exc=5.014740 sec, total=5.014740 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=149 seq_num=150 snap_id=1 wait times: snap=5.008331 sec, exc=5.008331 sec, total=5.008331 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=148 seq_num=149 snap_id=1 wait times: snap=5.012371 sec, exc=5.012371 sec, total=5.012371 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=147 seq_num=148 snap_id=1 wait times: snap=5.008346 sec, exc=5.008346 sec, total=5.008346 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=146 seq_num=147 snap_id=1 wait times: snap=5.014746 sec, exc=5.014746 sec, total=5.014746 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=145 seq_num=146 snap_id=1 wait times: snap=5.004625 sec, exc=5.004625 sec, total=5.004625 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time Sampled Session History of session 193 serial 49039 --------------------------------------------------- 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:08:18 - 14:10:18] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-12 14:10:18.028 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 4556, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-12 11:37:13.748273 :B0F89129:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-07-12 11:37:13.749085 :B0F8912E:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 11:37:14.065105 :B0F891CF:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 11:37:14.060 2025-07-12 11:37:14.065107 :B0F891D0:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14524 pso_num=24 pso_serial#=185 2025-07-12 11:37:14.065243 :B0F891D1:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=14524 osp_idx=22 osp_ver=561195 osp_pg=0 (spawn #377721) 2025-07-12 11:37:14.065244 :B0F891D2:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 11:37:14.065244 :B0F891D3:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=113 time=1001009954 2025-07-12 11:37:14.065244 :B0F891D4:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 11:37:14.065245 :B0F891D5:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 11:37:14.065245 :B0F891D6:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 11:37:14.065245 :B0F891D7:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 11:37:14.065245 :B0F891D8:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 11:37:14.065738 :B0F891D9: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-07-12 11:37:14.065782 :B0F891E1: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-07-12 11:47:15.022211 :B0F9570A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 11:47:15.240325 :B0F9577E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 11:47:15.235 2025-07-12 11:47:15.240327 :B0F9577F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15704 pso_num=24 pso_serial#=186 2025-07-12 11:47:15.240465 :B0F95780:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15704 osp_idx=22 osp_ver=561196 osp_pg=0 (spawn #377744) 2025-07-12 11:47:15.240466 :B0F95781:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 11:47:15.240467 :B0F95782:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=114 time=1001611142 2025-07-12 11:47:15.240467 :B0F95783:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 11:47:15.240467 :B0F95784:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 11:47:15.240468 :B0F95785:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 11:47:15.240468 :B0F95786:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 11:47:15.240468 :B0F95787:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 11:47:15.240977 :B0F95788: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-07-12 11:47:15.241021 :B0F9578F: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-07-12 11:57:16.204897 :B0FA1CD1:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 11:57:16.615999 :B0FA1D3E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 11:57:16.611 2025-07-12 11:57:16.616001 :B0FA1D3F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=16116 pso_num=24 pso_serial#=187 2025-07-12 11:57:16.616147 :B0FA1D40:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=16116 osp_idx=22 osp_ver=561197 osp_pg=0 (spawn #377767) 2025-07-12 11:57:16.616148 :B0FA1D41:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 11:57:16.616149 :B0FA1D42:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=115 time=1002212517 2025-07-12 11:57:16.616151 :B0FA1D43:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 11:57:16.616151 :B0FA1D44:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 11:57:16.616151 :B0FA1D45:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 11:57:16.616151 :B0FA1D46:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 11:57:16.616152 :B0FA1D47:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 11:57:16.616662 :B0FA1D48: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-07-12 11:57:16.616710 :B0FA1D4E: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-07-12 12:00:09.213519 :B0FA55D8: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-07-12 12:07:17.877397 :B0FAEB4E: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-07-12 12:17:18.743479 :B0FBB24C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 12:17:19.201252 :B0FBB2A1:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 12:17:19.196 2025-07-12 12:17:19.201254 :B0FBB2A2:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15912 pso_num=24 pso_serial#=188 2025-07-12 12:17:19.201395 :B0FBB2A3:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15912 osp_idx=22 osp_ver=561198 osp_pg=0 (spawn #377814) 2025-07-12 12:17:19.201395 :B0FBB2A4:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 12:17:19.201396 :B0FBB2A5:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=116 time=1003415095 2025-07-12 12:17:19.201396 :B0FBB2A6:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 12:17:19.201396 :B0FBB2A7:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 12:17:19.201397 :B0FBB2A8:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 12:17:19.201397 :B0FBB2A9:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 12:17:19.201397 :B0FBB2AA:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 12:17:19.201899 :B0FBB2AB: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-07-12 12:17:19.201944 :B0FBB2B3: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-07-12 12:27:20.179402 :B0FC7DC6:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 12:27:20.590406 :B0FC7E13:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 12:27:20.585 2025-07-12 12:27:20.590408 :B0FC7E14:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=16120 pso_num=24 pso_serial#=189 2025-07-12 12:27:20.590545 :B0FC7E15:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=16120 osp_idx=22 osp_ver=561199 osp_pg=0 (spawn #377837) 2025-07-12 12:27:20.590546 :B0FC7E16:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 12:27:20.590546 :B0FC7E17:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=117 time=1004016486 2025-07-12 12:27:20.590546 :B0FC7E18:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 12:27:20.590547 :B0FC7E19:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 12:27:20.590547 :B0FC7E1A:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 12:27:20.590547 :B0FC7E1B:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 12:27:20.590548 :B0FC7E1C:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 12:27:20.591087 :B0FC7E1D: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-07-12 12:27:20.591132 :B0FC7E24: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-07-12 12:37:21.410469 :B0FD4498:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 12:37:21.977903 :B0FD44FF:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 12:37:21.972 2025-07-12 12:37:21.977905 :B0FD4500:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10888 pso_num=24 pso_serial#=190 2025-07-12 12:37:21.978049 :B0FD4501:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=10888 osp_idx=22 osp_ver=561200 osp_pg=0 (spawn #377859) 2025-07-12 12:37:21.978050 :B0FD4502:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 12:37:21.978050 :B0FD4503:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=118 time=1004617876 2025-07-12 12:37:21.978051 :B0FD4504:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 12:37:21.978051 :B0FD4505:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 12:37:21.978052 :B0FD4506:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 12:37:21.978052 :B0FD4507:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 12:37:21.978052 :B0FD4508:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 12:37:21.978584 :B0FD4509: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-07-12 12:37:21.978627 :B0FD4511: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-07-12 12:47:22.774860 :B0FE0B8D:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 12:47:23.357794 :B0FE0BEC:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 12:47:23.353 2025-07-12 12:47:23.357796 :B0FE0BED:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=6844 pso_num=24 pso_serial#=191 2025-07-12 12:47:23.357934 :B0FE0BEE:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=6844 osp_idx=22 osp_ver=561201 osp_pg=0 (spawn #377882) 2025-07-12 12:47:23.357935 :B0FE0BEF:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 12:47:23.357935 :B0FE0BF0:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=119 time=1005219251 2025-07-12 12:47:23.357935 :B0FE0BF1:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 12:47:23.357936 :B0FE0BF2:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 12:47:23.357936 :B0FE0BF3:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 12:47:23.357936 :B0FE0BF4:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 12:47:23.357937 :B0FE0BF5:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 12:47:23.358430 :B0FE0BF6: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-07-12 12:47:23.358478 :B0FE0C00: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-07-12 12:57:24.301254 :B0FED2CE:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 12:57:24.774722 :B0FED331:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 12:57:24.770 2025-07-12 12:57:24.774724 :B0FED332:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9364 pso_num=24 pso_serial#=192 2025-07-12 12:57:24.774863 :B0FED333:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=9364 osp_idx=22 osp_ver=561202 osp_pg=0 (spawn #377905) 2025-07-12 12:57:24.774864 :B0FED334:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 12:57:24.774864 :B0FED335:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=120 time=1005820673 2025-07-12 12:57:24.774865 :B0FED336:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 12:57:24.774865 :B0FED337:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 12:57:24.774865 :B0FED338:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 12:57:24.774866 :B0FED339:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 12:57:24.774866 :B0FED33A:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 12:57:24.775362 :B0FED33B: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-07-12 12:57:24.775410 :B0FED342: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-07-12 13:07:25.634735 :B0FFA3C0:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 13:07:26.077085 :B0FFA41E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 13:07:26.072 2025-07-12 13:07:26.077087 :B0FFA41F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=3264 pso_num=24 pso_serial#=193 2025-07-12 13:07:26.077230 :B0FFA420:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=3264 osp_idx=22 osp_ver=561203 osp_pg=0 (spawn #377930) 2025-07-12 13:07:26.077231 :B0FFA421:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 13:07:26.077231 :B0FFA422:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=121 time=1006421970 2025-07-12 13:07:26.077232 :B0FFA423:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 13:07:26.077232 :B0FFA424:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 13:07:26.077232 :B0FFA425:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 13:07:26.077233 :B0FFA426:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 13:07:26.077233 :B0FFA427:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 13:07:26.077741 :B0FFA428: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-07-12 13:07:26.077783 :B0FFA42F: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-07-12 13:17:26.874656 :B1006D54:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 13:17:27.457561 :B1006DAD:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 13:17:27.453 2025-07-12 13:17:27.457563 :B1006DAE:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=8552 pso_num=24 pso_serial#=194 2025-07-12 13:17:27.457699 :B1006DAF:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=8552 osp_idx=22 osp_ver=561204 osp_pg=0 (spawn #377953) 2025-07-12 13:17:27.457699 :B1006DB0:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 13:17:27.457700 :B1006DB1:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=122 time=1007023345 2025-07-12 13:17:27.457700 :B1006DB2:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 13:17:27.457700 :B1006DB3:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 13:17:27.457701 :B1006DB4:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 13:17:27.457701 :B1006DB5:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 13:17:27.457701 :B1006DB6:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 13:17:27.458192 :B1006DB7: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-07-12 13:17:27.458239 :B1006DBF: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-07-12 13:27:28.398439 :B1013464:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 13:27:28.772557 :B10134CF:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 13:27:28.768 2025-07-12 13:27:28.772559 :B10134D0:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=6356 pso_num=24 pso_serial#=195 2025-07-12 13:27:28.772695 :B10134D1:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=6356 osp_idx=22 osp_ver=561205 osp_pg=0 (spawn #377976) 2025-07-12 13:27:28.772696 :B10134D2:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 13:27:28.772696 :B10134D3:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=123 time=1007624673 2025-07-12 13:27:28.772696 :B10134D4:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 13:27:28.772697 :B10134D5:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 13:27:28.772697 :B10134D6:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 13:27:28.772698 :B10134D7:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 13:27:28.772698 :B10134D8:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 13:27:28.773243 :B10134D9: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-07-12 13:27:28.773289 :B10134E1: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-07-12 13:37:29.679311 :B101FCEF:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 13:37:30.100543 :B101FD4C:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 13:37:30.096 2025-07-12 13:37:30.100545 :B101FD4D:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=18068 pso_num=24 pso_serial#=196 2025-07-12 13:37:30.100688 :B101FD4E:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=18068 osp_idx=22 osp_ver=561206 osp_pg=0 (spawn #377998) 2025-07-12 13:37:30.100689 :B101FD4F:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 13:37:30.100690 :B101FD50:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=124 time=1008226001 2025-07-12 13:37:30.100691 :B101FD51:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 13:37:30.100691 :B101FD52:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 13:37:30.100691 :B101FD53:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 13:37:30.100692 :B101FD54:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 13:37:30.100692 :B101FD55:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 13:37:30.101199 :B101FD56: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-07-12 13:37:30.101246 :B101FD5D: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-07-12 13:47:30.942936 :B102C357:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 13:47:31.447720 :B102C3CD:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 13:47:31.443 2025-07-12 13:47:31.447722 :B102C3CE:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=4196 pso_num=24 pso_serial#=197 2025-07-12 13:47:31.447857 :B102C3CF:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=4196 osp_idx=22 osp_ver=561207 osp_pg=0 (spawn #378021) 2025-07-12 13:47:31.447858 :B102C3D0:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 13:47:31.447858 :B102C3D1:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=125 time=1008827345 2025-07-12 13:47:31.447859 :B102C3D2:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 13:47:31.447859 :B102C3D3:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 13:47:31.447860 :B102C3D4:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 13:47:31.447860 :B102C3D5:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 13:47:31.447860 :B102C3D6:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 13:47:31.448345 :B102C3D7: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-07-12 13:47:31.448391 :B102C3DE: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-07-12 13:57:32.308949 :B1038A73:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-07-12 13:57:32.651827 :B1038AD2:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 07-12 13:57:32.647 2025-07-12 13:57:32.651829 :B1038AD3:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=4556 pso_num=24 pso_serial#=198 2025-07-12 13:57:32.651961 :B1038AD4:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=4556 osp_idx=22 osp_ver=561208 osp_pg=0 (spawn #378044) 2025-07-12 13:57:32.651962 :B1038AD5:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-12 13:57:32.651962 :B1038AD6:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=126 time=1009428548 2025-07-12 13:57:32.651963 :B1038AD7:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-07-12 13:57:32.651963 :B1038AD8:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-07-12 13:57:32.651963 :B1038AD9:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-07-12 13:57:32.651964 :B1038ADA:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-12 13:57:32.651964 :B1038ADB:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-12 13:57:32.652446 :B1038ADC: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-07-12 13:57:32.652492 :B1038AE4: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-07-12 14:02:44.326174 :B103F35A: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-07-12 14:07:34.062630 :B1045A63: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 24 (osid: 4556, W000)