Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250601180746\orcl_w000_13080_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:37179M/63366M, Ph+PgF:44062M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 13080, image: ORACLE.EXE (W000) *** 2025-06-01 18:07:46.714 *** SESSION ID:(177.17267) 2025-06-01 18:07:46.714 *** 2025-06-01 18:07:46.714 Process diagnostic dump for ORACLE.EXE (W000), OS id=13080, pid: 22, proc_ser: 246, sid: 177, sess_ser: 17267 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=1.433390 sec, exc=1.433390 sec, total=1.433390 sec wait times: max=5.000000 sec, heur=2 min 11 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.000026 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.002129 sec, exc=5.002129 sec, total=5.002129 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.001419 sec, exc=5.001419 sec, total=5.001419 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=24 seq_num=25 snap_id=1 wait times: snap=5.014165 sec, exc=5.014165 sec, total=5.014165 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.000566 sec, exc=5.000566 sec, total=5.000566 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.004628 sec, exc=5.004628 sec, total=5.004628 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.010794 sec, exc=5.010794 sec, total=5.010794 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.014744 sec, exc=5.014744 sec, total=5.014744 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.015222 sec, exc=5.015222 sec, total=5.015222 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=5.003231 sec, exc=5.003231 sec, total=5.003231 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=5.014498 sec, exc=5.014498 sec, total=5.014498 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 177 serial 17267 --------------------------------------------------- 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:05:46 - 18:07:46] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-01 18:07:46.714 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 13080, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-01 15:25:13.408804 :9EECD574: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-06-01 15:30:01.881196 :9EED32B1: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-06-01 15:35:14.693698 :9EED9879: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-06-01 15:45:15.529278 :9EEE5B22:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 15:45:15.908890 :9EEE5B75:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 15:45:15.903 2025-06-01 15:45:15.908892 :9EEE5B76:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14596 pso_num=22 pso_serial#=233 2025-06-01 15:45:15.909025 :9EEE5B77:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14596 osp_idx=0 osp_ver=254285 osp_pg=0 (spawn #241619) 2025-06-01 15:45:15.909026 :9EEE5B78:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 15:45:15.909026 :9EEE5B79:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=179 time=1768474563 2025-06-01 15:45:15.909026 :9EEE5B7A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 15:45:15.909027 :9EEE5B7B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 15:45:15.909028 :9EEE5B7C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 15:45:15.909028 :9EEE5B7D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 15:45:15.909028 :9EEE5B7E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 15:45:15.909524 :9EEE5B7F: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-06-01 15:45:15.909568 :9EEE5B87: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-06-01 15:55:16.770060 :9EEF1E2B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 15:55:17.118621 :9EEF1E6B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 15:55:17.114 2025-06-01 15:55:17.118623 :9EEF1E6C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12380 pso_num=22 pso_serial#=234 2025-06-01 15:55:17.118762 :9EEF1E6D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12380 osp_idx=0 osp_ver=254286 osp_pg=0 (spawn #241642) 2025-06-01 15:55:17.118763 :9EEF1E6E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 15:55:17.118763 :9EEF1E6F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=180 time=1769075766 2025-06-01 15:55:17.118764 :9EEF1E70:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 15:55:17.118764 :9EEF1E71:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 15:55:17.118764 :9EEF1E72:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 15:55:17.118765 :9EEF1E73:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 15:55:17.118765 :9EEF1E74:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 15:55:17.119276 :9EEF1E75: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-06-01 15:55:17.119318 :9EEF1E7C: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-06-01 16:05:18.039422 :9EEFE30D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 16:05:18.497367 :9EEFE357:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 16:05:18.492 2025-06-01 16:05:18.497368 :9EEFE358:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13024 pso_num=22 pso_serial#=235 2025-06-01 16:05:18.497523 :9EEFE359:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13024 osp_idx=0 osp_ver=254287 osp_pg=0 (spawn #241668) 2025-06-01 16:05:18.497524 :9EEFE35A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 16:05:18.497524 :9EEFE35B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=181 time=1769677141 2025-06-01 16:05:18.497525 :9EEFE35C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 16:05:18.497525 :9EEFE35D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 16:05:18.497526 :9EEFE35E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 16:05:18.497526 :9EEFE35F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 16:05:18.497527 :9EEFE360:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 16:05:18.498055 :9EEFE361: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-06-01 16:05:18.498102 :9EEFE368: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-06-01 16:15:19.327949 :9EF0B195:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 16:15:19.895170 :9EF0B1DA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 16:15:19.890 2025-06-01 16:15:19.895172 :9EF0B1DB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=1112 pso_num=22 pso_serial#=236 2025-06-01 16:15:19.895315 :9EF0B1DC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=1112 osp_idx=0 osp_ver=254288 osp_pg=0 (spawn #241691) 2025-06-01 16:15:19.895316 :9EF0B1DD:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 16:15:19.895316 :9EF0B1DE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=182 time=1770278547 2025-06-01 16:15:19.895317 :9EF0B1DF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 16:15:19.895317 :9EF0B1E0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 16:15:19.895318 :9EF0B1E1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 16:15:19.895318 :9EF0B1E2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 16:15:19.895318 :9EF0B1E3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 16:15:19.895809 :9EF0B1E4: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-06-01 16:15:19.895858 :9EF0B1EC: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-06-01 16:25:20.766309 :9EF17785:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 16:25:21.302167 :9EF177D2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 16:25:21.297 2025-06-01 16:25:21.302168 :9EF177D3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15200 pso_num=22 pso_serial#=237 2025-06-01 16:25:21.302304 :9EF177D4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15200 osp_idx=0 osp_ver=254289 osp_pg=0 (spawn #241714) 2025-06-01 16:25:21.302305 :9EF177D5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 16:25:21.302306 :9EF177D6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=183 time=1770879954 2025-06-01 16:25:21.302306 :9EF177D7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 16:25:21.302306 :9EF177D8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 16:25:21.302307 :9EF177D9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 16:25:21.302307 :9EF177DA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 16:25:21.302307 :9EF177DB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 16:25:21.302802 :9EF177DC: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-06-01 16:25:21.302843 :9EF177E4: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-06-01 16:35:22.248691 :9EF23DC9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 16:35:22.706674 :9EF23E17:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 16:35:22.701 2025-06-01 16:35:22.706676 :9EF23E18:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9008 pso_num=22 pso_serial#=238 2025-06-01 16:35:22.706815 :9EF23E19:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9008 osp_idx=0 osp_ver=254290 osp_pg=0 (spawn #241736) 2025-06-01 16:35:22.706816 :9EF23E1A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 16:35:22.706816 :9EF23E1B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=184 time=1771481360 2025-06-01 16:35:22.706816 :9EF23E1C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 16:35:22.706817 :9EF23E1D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 16:35:22.706817 :9EF23E1E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 16:35:22.706817 :9EF23E1F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 16:35:22.706818 :9EF23E20:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 16:35:22.707311 :9EF23E21: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-06-01 16:35:22.707361 :9EF23E2B: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-06-01 16:45:23.644458 :9EF304AD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 16:45:24.211805 :9EF304F2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 16:45:24.207 2025-06-01 16:45:24.211807 :9EF304F3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7736 pso_num=22 pso_serial#=239 2025-06-01 16:45:24.211943 :9EF304F4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7736 osp_idx=0 osp_ver=254291 osp_pg=0 (spawn #241759) 2025-06-01 16:45:24.211944 :9EF304F5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 16:45:24.211944 :9EF304F6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=185 time=1772082860 2025-06-01 16:45:24.211944 :9EF304F7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 16:45:24.211945 :9EF304F8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 16:45:24.211945 :9EF304F9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 16:45:24.211945 :9EF304FA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 16:45:24.211946 :9EF304FB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 16:45:24.212449 :9EF304FC: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-06-01 16:45:24.212495 :9EF30503: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-06-01 16:55:25.162335 :9EF3CB7F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 16:55:25.714200 :9EF3CBC4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 16:55:25.709 2025-06-01 16:55:25.714202 :9EF3CBC5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14864 pso_num=22 pso_serial#=240 2025-06-01 16:55:25.714347 :9EF3CBC6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14864 osp_idx=0 osp_ver=254292 osp_pg=0 (spawn #241782) 2025-06-01 16:55:25.714348 :9EF3CBC7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 16:55:25.714348 :9EF3CBC8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=186 time=1772684360 2025-06-01 16:55:25.714349 :9EF3CBC9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 16:55:25.714349 :9EF3CBCA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 16:55:25.714349 :9EF3CBCB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 16:55:25.714350 :9EF3CBCC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 16:55:25.714350 :9EF3CBCD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 16:55:25.714846 :9EF3CBCE: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-06-01 16:55:25.714890 :9EF3CBD6: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-06-01 17:05:26.670157 :9EF492E4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 17:05:27.096783 :9EF49324:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 17:05:27.092 2025-06-01 17:05:27.096785 :9EF49325:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14116 pso_num=22 pso_serial#=241 2025-06-01 17:05:27.096927 :9EF49326:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14116 osp_idx=0 osp_ver=254293 osp_pg=0 (spawn #241807) 2025-06-01 17:05:27.096928 :9EF49327:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 17:05:27.096928 :9EF49328:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=187 time=1773285750 2025-06-01 17:05:27.096929 :9EF49329:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 17:05:27.096929 :9EF4932A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 17:05:27.096929 :9EF4932B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 17:05:27.096930 :9EF4932C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 17:05:27.096930 :9EF4932D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 17:05:27.097448 :9EF4932E: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-06-01 17:05:27.097494 :9EF49335: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-06-01 17:15:28.046019 :9EF56137:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 17:15:28.451572 :9EF5617D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 17:15:28.446 2025-06-01 17:15:28.451574 :9EF5617E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13904 pso_num=22 pso_serial#=242 2025-06-01 17:15:28.451713 :9EF5617F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13904 osp_idx=0 osp_ver=254294 osp_pg=0 (spawn #241830) 2025-06-01 17:15:28.451714 :9EF56180:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 17:15:28.451714 :9EF56181:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=188 time=1773887094 2025-06-01 17:15:28.451715 :9EF56182:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 17:15:28.451715 :9EF56183:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 17:15:28.451715 :9EF56184:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 17:15:28.451715 :9EF56185:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 17:15:28.451716 :9EF56186:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 17:15:28.452220 :9EF56187: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-06-01 17:15:28.452266 :9EF56191: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-06-01 17:25:29.367958 :9EF62A09:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 17:25:29.904091 :9EF62A52:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 17:25:29.899 2025-06-01 17:25:29.904092 :9EF62A53:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10564 pso_num=22 pso_serial#=243 2025-06-01 17:25:29.904241 :9EF62A54:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10564 osp_idx=0 osp_ver=254295 osp_pg=0 (spawn #241853) 2025-06-01 17:25:29.904242 :9EF62A55:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 17:25:29.904242 :9EF62A56:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=189 time=1774488547 2025-06-01 17:25:29.904243 :9EF62A57:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 17:25:29.904243 :9EF62A58:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 17:25:29.904243 :9EF62A59:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 17:25:29.904243 :9EF62A5A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 17:25:29.904244 :9EF62A5B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 17:25:29.904766 :9EF62A5C: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-06-01 17:25:29.904810 :9EF62A66: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-06-01 17:33:30.900177 :9EF6C95A: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-06-01 17:35:31.183260 :9EF6F165: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-06-01 17:45:32.167251 :9EF7B9DF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 17:45:32.499844 :9EF7BA1A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 17:45:32.495 2025-06-01 17:45:32.499846 :9EF7BA1B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15120 pso_num=22 pso_serial#=244 2025-06-01 17:45:32.499995 :9EF7BA1C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15120 osp_idx=0 osp_ver=254296 osp_pg=0 (spawn #241897) 2025-06-01 17:45:32.499995 :9EF7BA1D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 17:45:32.499996 :9EF7BA1E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=190 time=1775691141 2025-06-01 17:45:32.499996 :9EF7BA1F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 17:45:32.499997 :9EF7BA20:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 17:45:32.499997 :9EF7BA21:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 17:45:32.499998 :9EF7BA22:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 17:45:32.499998 :9EF7BA23:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 17:45:32.500513 :9EF7BA24: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-06-01 17:45:32.500561 :9EF7BA2A: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-06-01 17:55:33.435747 :9EF88056:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 17:55:33.784245 :9EF880C3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 17:55:33.779 2025-06-01 17:55:33.784248 :9EF880C4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14136 pso_num=22 pso_serial#=245 2025-06-01 17:55:33.784385 :9EF880C5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14136 osp_idx=0 osp_ver=254297 osp_pg=0 (spawn #241920) 2025-06-01 17:55:33.784385 :9EF880C6:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 17:55:33.784385 :9EF880C7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=191 time=1776292438 2025-06-01 17:55:33.784386 :9EF880C8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 17:55:33.784386 :9EF880C9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 17:55:33.784386 :9EF880CA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 17:55:33.784387 :9EF880CB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 17:55:33.784387 :9EF880CC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 17:55:33.784887 :9EF880CD: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-06-01 17:55:33.784936 :9EF880D4: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-06-01 18:05:34.756850 :9EF94AC7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-01 18:05:35.074111 :9EF94B24:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-01 18:05:35.069 2025-06-01 18:05:35.074114 :9EF94B25:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13080 pso_num=22 pso_serial#=246 2025-06-01 18:05:35.074271 :9EF94B26:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13080 osp_idx=0 osp_ver=254298 osp_pg=0 (spawn #241945) 2025-06-01 18:05:35.074272 :9EF94B27:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-01 18:05:35.074272 :9EF94B28:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=192 time=1776893719 2025-06-01 18:05:35.074273 :9EF94B29:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-01 18:05:35.074273 :9EF94B2A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-01 18:05:35.074274 :9EF94B2B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-01 18:05:35.074274 :9EF94B2C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-01 18:05:35.074274 :9EF94B2D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-01 18:05:35.074790 :9EF94B2E: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-06-01 18:05:35.074834 :9EF94B36: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: 13080, W000)