Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250625080140\orcl_w000_4540_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:36357M/63366M, Ph+PgF:42538M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 4540, image: ORACLE.EXE (W000) *** 2025-06-25 08:01:40.701 *** SESSION ID:(201.44963) 2025-06-25 08:01:40.701 *** 2025-06-25 08:01:40.701 Process diagnostic dump for ORACLE.EXE (W000), OS id=4540, pid: 25, proc_ser: 243, sid: 201, sess_ser: 44963 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=84 seq_num=85 snap_id=1 wait times: snap=0.990138 sec, exc=0.990138 sec, total=0.990138 sec wait times: max=5.000000 sec, heur=6 min 56 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=83 seq_num=84 snap_id=1 wait times: snap=5.003214 sec, exc=5.003214 sec, total=5.003214 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 1: 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.000274 sec, exc=5.000274 sec, total=5.000274 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=81 seq_num=82 snap_id=1 wait times: snap=5.007227 sec, exc=5.007227 sec, total=5.007227 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 3: 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.007075 sec, exc=5.007075 sec, total=5.007075 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 4: 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.010152 sec, exc=5.010152 sec, total=5.010152 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=78 seq_num=79 snap_id=1 wait times: snap=5.009713 sec, exc=5.009713 sec, total=5.009713 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=77 seq_num=78 snap_id=1 wait times: snap=5.003215 sec, exc=5.003215 sec, total=5.003215 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=76 seq_num=77 snap_id=1 wait times: snap=5.000319 sec, exc=5.000319 sec, total=5.000319 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=75 seq_num=76 snap_id=1 wait times: snap=5.006993 sec, exc=5.006993 sec, total=5.006993 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=74 seq_num=75 snap_id=1 wait times: snap=5.012540 sec, exc=5.012540 sec, total=5.012540 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 201 serial 44963 --------------------------------------------------- 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, 07:59:40 - 08:01:40] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-25 08:01:40.701 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 4540, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-25 05:24:24.290699 :A94D57DE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 05:24:24.291195 :A94D57DF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 05:24:24.291244 :A94D57E6:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 05:34:25.268104 :A94E1F5C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 05:34:25.553988 :A94E1FA8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 05:34:25.549 2025-06-25 05:34:25.553989 :A94E1FA9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10700 pso_num=25 pso_serial#=230 2025-06-25 05:34:25.554132 :A94E1FAA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10700 osp_idx=23 osp_ver=167877 osp_pg=0 (spawn #320215) 2025-06-25 05:34:25.554132 :A94E1FAB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 05:34:25.554133 :A94E1FAC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=225 time=3805408750 2025-06-25 05:34:25.554133 :A94E1FAD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 05:34:25.554134 :A94E1FAE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 05:34:25.554134 :A94E1FAF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 05:34:25.554134 :A94E1FB0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 05:34:25.554135 :A94E1FB1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 05:34:25.554628 :A94E1FB2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 05:34:25.554671 :A94E1FBA:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 05:44:26.368344 :A94EE804:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 05:44:26.935565 :A94EE85A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 05:44:26.930 2025-06-25 05:44:26.935567 :A94EE85B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17392 pso_num=25 pso_serial#=231 2025-06-25 05:44:26.935702 :A94EE85C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17392 osp_idx=23 osp_ver=167878 osp_pg=0 (spawn #320235) 2025-06-25 05:44:26.935702 :A94EE85D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 05:44:26.935703 :A94EE85E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=226 time=3806010125 2025-06-25 05:44:26.935704 :A94EE85F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 05:44:26.935704 :A94EE860:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 05:44:26.935705 :A94EE861:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 05:44:26.935705 :A94EE862:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 05:44:26.935705 :A94EE863:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 05:44:26.936193 :A94EE864:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 05:44:26.936240 :A94EE86B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 05:54:27.782984 :A94FAF78:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 05:54:28.272145 :A94FAFC8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 05:54:28.267 2025-06-25 05:54:28.272147 :A94FAFC9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14600 pso_num=25 pso_serial#=232 2025-06-25 05:54:28.272284 :A94FAFCA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14600 osp_idx=23 osp_ver=167879 osp_pg=0 (spawn #320258) 2025-06-25 05:54:28.272285 :A94FAFCB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 05:54:28.272285 :A94FAFCC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=227 time=3806611469 2025-06-25 05:54:28.272285 :A94FAFCD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 05:54:28.272286 :A94FAFCE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 05:54:28.272286 :A94FAFCF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 05:54:28.272286 :A94FAFD0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 05:54:28.272287 :A94FAFD1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 05:54:28.272783 :A94FAFD2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 05:54:28.272836 :A94FAFD8:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 06:04:29.082826 :A950779A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 06:04:29.603365 :A95077ED:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 06:04:29.598 2025-06-25 06:04:29.603367 :A95077EE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17808 pso_num=25 pso_serial#=233 2025-06-25 06:04:29.603505 :A95077EF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17808 osp_idx=23 osp_ver=167880 osp_pg=0 (spawn #320284) 2025-06-25 06:04:29.603506 :A95077F0:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 06:04:29.603506 :A95077F1:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=228 time=3807212797 2025-06-25 06:04:29.603507 :A95077F2:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 06:04:29.603508 :A95077F3:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 06:04:29.603508 :A95077F4:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 06:04:29.603508 :A95077F5:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 06:04:29.603508 :A95077F6:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 06:04:29.604050 :A95077F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 06:04:29.604096 :A95077FE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 06:14:30.538432 :A95141D3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 06:14:31.022103 :A9514216:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 06:14:31.017 2025-06-25 06:14:31.022105 :A9514217:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14320 pso_num=25 pso_serial#=234 2025-06-25 06:14:31.022246 :A9514218:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14320 osp_idx=23 osp_ver=167881 osp_pg=0 (spawn #320306) 2025-06-25 06:14:31.022247 :A9514219:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 06:14:31.022247 :A951421A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=229 time=3807814219 2025-06-25 06:14:31.022248 :A951421B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 06:14:31.022248 :A951421C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 06:14:31.022248 :A951421D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 06:14:31.022249 :A951421E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 06:14:31.022249 :A951421F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 06:14:31.022760 :A9514220:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 06:14:31.022807 :A9514227:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 06:18:10.679180 :A9518CE5:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 06:24:32.460163 :A95209E8:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 06:34:33.364475 :A952CE79:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 06:34:33.853613 :A952CEBE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 06:34:33.848 2025-06-25 06:34:33.853615 :A952CEBF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18232 pso_num=25 pso_serial#=235 2025-06-25 06:34:33.853753 :A952CEC0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18232 osp_idx=23 osp_ver=167882 osp_pg=0 (spawn #320351) 2025-06-25 06:34:33.853754 :A952CEC1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 06:34:33.853754 :A952CEC2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=230 time=3809017047 2025-06-25 06:34:33.853755 :A952CEC3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 06:34:33.853755 :A952CEC4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 06:34:33.853756 :A952CEC5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 06:34:33.853756 :A952CEC6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 06:34:33.853756 :A952CEC7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 06:34:33.854383 :A952CEC8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 06:34:33.854426 :A952CED1:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 06:44:34.705079 :A9539342:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 06:44:35.173095 :A9539380:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 06:44:35.168 2025-06-25 06:44:35.173097 :A9539381:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14632 pso_num=25 pso_serial#=236 2025-06-25 06:44:35.173241 :A9539382:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14632 osp_idx=23 osp_ver=167883 osp_pg=0 (spawn #320373) 2025-06-25 06:44:35.173242 :A9539383:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 06:44:35.173242 :A9539384:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=231 time=3809618360 2025-06-25 06:44:35.173243 :A9539385:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 06:44:35.173243 :A9539386:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 06:44:35.173244 :A9539387:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 06:44:35.173244 :A9539388:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 06:44:35.173244 :A9539389:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 06:44:35.173774 :A953938A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 06:44:35.173826 :A9539391:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 06:54:36.058218 :A9545BCD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 06:54:36.516057 :A9545C10:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 06:54:36.511 2025-06-25 06:54:36.516059 :A9545C11:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17740 pso_num=25 pso_serial#=237 2025-06-25 06:54:36.516202 :A9545C12:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17740 osp_idx=23 osp_ver=167884 osp_pg=0 (spawn #320396) 2025-06-25 06:54:36.516202 :A9545C13:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 06:54:36.516203 :A9545C14:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=232 time=3810219704 2025-06-25 06:54:36.516203 :A9545C15:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 06:54:36.516203 :A9545C16:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 06:54:36.516204 :A9545C17:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 06:54:36.516204 :A9545C18:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 06:54:36.516204 :A9545C19:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 06:54:36.516689 :A9545C1A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 06:54:36.516735 :A9545C22:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 07:04:37.429585 :A95524E1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 07:04:37.793800 :A9552526:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 07:04:37.788 2025-06-25 07:04:37.793802 :A9552527:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10660 pso_num=25 pso_serial#=238 2025-06-25 07:04:37.793937 :A9552528:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10660 osp_idx=23 osp_ver=167885 osp_pg=0 (spawn #320423) 2025-06-25 07:04:37.793937 :A9552529:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:04:37.793938 :A955252A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=233 time=3810820985 2025-06-25 07:04:37.793938 :A955252B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:04:37.793939 :A955252C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:04:37.793939 :A955252D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:04:37.793940 :A955252E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:04:37.793940 :A955252F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:04:37.794432 :A9552530:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:04:37.794473 :A9552538:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 07:14:38.683051 :A955F5D4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 07:14:39.203466 :A955F648:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 07:14:39.199 2025-06-25 07:14:39.203468 :A955F649:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18212 pso_num=25 pso_serial#=239 2025-06-25 07:14:39.203617 :A955F64A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18212 osp_idx=23 osp_ver=167886 osp_pg=0 (spawn #320445) 2025-06-25 07:14:39.203618 :A955F64B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:14:39.203618 :A955F64C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=234 time=3811422391 2025-06-25 07:14:39.203619 :A955F64D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:14:39.203619 :A955F64E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:14:39.203619 :A955F64F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:14:39.203620 :A955F650:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:14:39.203620 :A955F651:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:14:39.204127 :A955F652:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:14:39.204170 :A955F65A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 07:24:40.030216 :A956BDD9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 07:24:40.456858 :A956BE3D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 07:24:40.452 2025-06-25 07:24:40.456860 :A956BE3E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16908 pso_num=25 pso_serial#=240 2025-06-25 07:24:40.457009 :A956BE3F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16908 osp_idx=23 osp_ver=167887 osp_pg=0 (spawn #320468) 2025-06-25 07:24:40.457010 :A956BE40:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:24:40.457010 :A956BE41:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=235 time=3812023641 2025-06-25 07:24:40.457011 :A956BE42:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:24:40.457011 :A956BE43:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:24:40.457012 :A956BE44:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:24:40.457012 :A956BE45:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:24:40.457013 :A956BE46:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:24:40.457515 :A956BE47:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:24:40.457562 :A956BE4F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 07:34:41.272098 :A9578857:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 07:34:41.677453 :A95788C3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 07:34:41.673 2025-06-25 07:34:41.677455 :A95788C4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=280 pso_num=25 pso_serial#=241 2025-06-25 07:34:41.677593 :A95788C5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=280 osp_idx=23 osp_ver=167888 osp_pg=0 (spawn #320491) 2025-06-25 07:34:41.677594 :A95788C6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:34:41.677594 :A95788C7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=236 time=3812624875 2025-06-25 07:34:41.677595 :A95788C8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:34:41.677595 :A95788C9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:34:41.677596 :A95788CA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:34:41.677596 :A95788CB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:34:41.677596 :A95788CC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:34:41.678088 :A95788CD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:34:41.678135 :A95788D7:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 07:44:42.493473 :A95851B1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 07:44:42.935731 :A95851EC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 07:44:42.930 2025-06-25 07:44:42.935733 :A95851ED:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9744 pso_num=25 pso_serial#=242 2025-06-25 07:44:42.935875 :A95851EE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9744 osp_idx=23 osp_ver=167889 osp_pg=0 (spawn #320513) 2025-06-25 07:44:42.935875 :A95851EF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:44:42.935876 :A95851F0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=237 time=3813226125 2025-06-25 07:44:42.935876 :A95851F1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:44:42.935877 :A95851F2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:44:42.935877 :A95851F3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:44:42.935877 :A95851F4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:44:42.935877 :A95851F5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:44:42.936379 :A95851F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:44:42.936424 :A95851FE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-25 07:54:43.866980 :A959190F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-25 07:54:44.121586 :A9591946:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-25 07:54:44.116 2025-06-25 07:54:44.121588 :A9591947:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4540 pso_num=25 pso_serial#=243 2025-06-25 07:54:44.121730 :A9591948:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4540 osp_idx=23 osp_ver=167890 osp_pg=0 (spawn #320536) 2025-06-25 07:54:44.121730 :A9591949:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:54:44.121731 :A959194A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=238 time=3813827313 2025-06-25 07:54:44.121731 :A959194B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:54:44.121732 :A959194C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:54:44.121732 :A959194D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:54:44.121732 :A959194E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:54:44.121733 :A959194F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:54:44.122230 :A9591950:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:54:44.122272 :A9591957:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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 25 (osid: 4540, W000)