Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250622100841\orcl_w000_11796_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:36389M/63366M, Ph+PgF:42669M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 11796, image: ORACLE.EXE (W000) *** 2025-06-22 10:08:41.351 *** SESSION ID:(177.18763) 2025-06-22 10:08:41.351 *** 2025-06-22 10:08:41.351 Process diagnostic dump for ORACLE.EXE (W000), OS id=11796, pid: 22, proc_ser: 75, sid: 177, sess_ser: 18763 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=1.795819 sec, exc=1.795819 sec, total=1.795819 sec wait times: max=5.000000 sec, heur=2 min 47 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.000037 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=5.004632 sec, exc=5.004632 sec, total=5.004632 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 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.000024 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 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=30 seq_num=31 snap_id=1 wait times: snap=5.009507 sec, exc=5.009507 sec, total=5.009507 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.010772 sec, exc=5.010772 sec, total=5.010772 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=28 seq_num=29 snap_id=1 wait times: snap=5.009186 sec, exc=5.009186 sec, total=5.009186 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=27 seq_num=28 snap_id=1 wait times: snap=5.004653 sec, exc=5.004653 sec, total=5.004653 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 7: 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.007238 sec, exc=5.007238 sec, total=5.007238 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.001249 sec, exc=5.001249 sec, total=5.001249 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 9: 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.000577 sec, exc=5.000577 sec, total=5.000577 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time Sampled Session History of session 177 serial 18763 --------------------------------------------------- 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, 10:06:41 - 10:08:41] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-22 10:08:41.351 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 11796, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-22 07:45:36.307870 :A8039A50:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17024 osp_idx=0 osp_ver=338009 osp_pg=0 (spawn #310522) 2025-06-22 07:45:36.307871 :A8039A51: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-22 07:45:36.307871 :A8039A52:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=166 time=3554079500 2025-06-22 07:45:36.307871 :A8039A53:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 07:45:36.307872 :A8039A54:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 07:45:36.307872 :A8039A55:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 07:45:36.307872 :A8039A56:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 07:45:36.307873 :A8039A57:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 07:45:36.308374 :A8039A58: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-22 07:45:36.308420 :A8039A5F: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-22 07:55:37.166707 :A8045DE2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 07:55:37.546496 :A8045E27:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 07:55:37.541 2025-06-22 07:55:37.546498 :A8045E28:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16408 pso_num=22 pso_serial#=63 2025-06-22 07:55:37.546638 :A8045E29:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16408 osp_idx=0 osp_ver=338010 osp_pg=0 (spawn #310545) 2025-06-22 07:55:37.546638 :A8045E2A: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-22 07:55:37.546639 :A8045E2B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=167 time=3554680735 2025-06-22 07:55:37.546639 :A8045E2C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 07:55:37.546639 :A8045E2D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 07:55:37.546639 :A8045E2E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 07:55:37.546640 :A8045E2F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 07:55:37.546640 :A8045E30:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 07:55:37.547142 :A8045E31: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-22 07:55:37.547205 :A8045E37: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-22 07:56:37.611260 :A80471B4:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=13 seq_num=14 snap_id=1 2025-06-22 07:56:37.611282 :A80471B9:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=13 seq_num=14 snap_id=1 2025-06-22 07:56:37.611285 :A80471BA:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=20, exc=20, tot=20 2025-06-22 08:05:38.357520 :A8052A8F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 08:05:38.831146 :A8052AE0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 08:05:38.826 2025-06-22 08:05:38.831148 :A8052AE1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16916 pso_num=22 pso_serial#=64 2025-06-22 08:05:38.831292 :A8052AE2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16916 osp_idx=0 osp_ver=338011 osp_pg=0 (spawn #310570) 2025-06-22 08:05:38.831293 :A8052AE3: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-22 08:05:38.831293 :A8052AE4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=168 time=3555282016 2025-06-22 08:05:38.831294 :A8052AE5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 08:05:38.831294 :A8052AE6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 08:05:38.831294 :A8052AE7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 08:05:38.831295 :A8052AE8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 08:05:38.831295 :A8052AE9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 08:05:38.831817 :A8052AEA: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-22 08:05:38.831868 :A8052AF2: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-22 08:15:39.803569 :A805F2F1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 08:15:40.214461 :A805F349:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 08:15:40.209 2025-06-22 08:15:40.214462 :A805F34A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16776 pso_num=22 pso_serial#=65 2025-06-22 08:15:40.214602 :A805F34B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16776 osp_idx=0 osp_ver=338012 osp_pg=0 (spawn #310593) 2025-06-22 08:15:40.214603 :A805F34C: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-22 08:15:40.214603 :A805F34D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=169 time=3555883407 2025-06-22 08:15:40.214603 :A805F34E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 08:15:40.214604 :A805F34F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 08:15:40.214604 :A805F350:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 08:15:40.214604 :A805F351:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 08:15:40.214605 :A805F352:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 08:15:40.215092 :A805F353: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-22 08:15:40.215149 :A805F359: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-22 08:25:41.021852 :A806B7EC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 08:25:41.432721 :A806B849:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 08:25:41.428 2025-06-22 08:25:41.432723 :A806B84A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17704 pso_num=22 pso_serial#=66 2025-06-22 08:25:41.432854 :A806B84B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17704 osp_idx=0 osp_ver=338013 osp_pg=0 (spawn #310616) 2025-06-22 08:25:41.432855 :A806B84C: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-22 08:25:41.432855 :A806B84D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=170 time=3556484625 2025-06-22 08:25:41.432856 :A806B84E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 08:25:41.432856 :A806B84F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 08:25:41.432856 :A806B850:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 08:25:41.432857 :A806B851:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 08:25:41.432857 :A806B852:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 08:25:41.433391 :A806B853: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-22 08:25:41.433437 :A806B85C: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-22 08:35:42.305727 :A807E94F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 08:35:42.826084 :A807E9A0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 08:35:42.821 2025-06-22 08:35:42.826087 :A807E9A1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16168 pso_num=22 pso_serial#=67 2025-06-22 08:35:42.826224 :A807E9A2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16168 osp_idx=0 osp_ver=338014 osp_pg=0 (spawn #310643) 2025-06-22 08:35:42.826225 :A807E9A3: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-22 08:35:42.826225 :A807E9A4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=171 time=3557086016 2025-06-22 08:35:42.826225 :A807E9A5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 08:35:42.826226 :A807E9A6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 08:35:42.826226 :A807E9A7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 08:35:42.826226 :A807E9A8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 08:35:42.826227 :A807E9A9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 08:35:42.826715 :A807E9AA: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-22 08:35:42.826760 :A807E9B2: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-22 08:45:43.730077 :A808B529:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 08:45:44.266162 :A808B583:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 08:45:44.261 2025-06-22 08:45:44.266164 :A808B584:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9028 pso_num=22 pso_serial#=68 2025-06-22 08:45:44.266306 :A808B585:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9028 osp_idx=0 osp_ver=338015 osp_pg=0 (spawn #310666) 2025-06-22 08:45:44.266307 :A808B586: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-22 08:45:44.266307 :A808B587:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=172 time=3557687454 2025-06-22 08:45:44.266308 :A808B588:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 08:45:44.266308 :A808B589:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 08:45:44.266308 :A808B58A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 08:45:44.266309 :A808B58B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 08:45:44.266309 :A808B58C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 08:45:44.266799 :A808B58D: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-22 08:45:44.266842 :A808B595: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-22 08:55:45.133071 :A8097D98:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 08:55:45.653473 :A8097DF5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 08:55:45.649 2025-06-22 08:55:45.653475 :A8097DF6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17840 pso_num=22 pso_serial#=69 2025-06-22 08:55:45.653609 :A8097DF7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17840 osp_idx=0 osp_ver=338016 osp_pg=0 (spawn #310689) 2025-06-22 08:55:45.653610 :A8097DF8: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-22 08:55:45.653611 :A8097DF9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=173 time=3558288844 2025-06-22 08:55:45.653611 :A8097DFA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 08:55:45.653611 :A8097DFB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 08:55:45.653612 :A8097DFC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 08:55:45.653612 :A8097DFD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 08:55:45.653612 :A8097DFE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 08:55:45.654099 :A8097DFF: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-22 08:55:45.654145 :A8097E06: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-22 09:04:41.163302 :A80A2E8E: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-22 09:05:46.975549 :A80A4AF0: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-22 09:15:47.797620 :A80B1445:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 09:15:48.239698 :A80B148B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 09:15:48.234 2025-06-22 09:15:48.239700 :A80B148C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14672 pso_num=22 pso_serial#=70 2025-06-22 09:15:48.239835 :A80B148D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14672 osp_idx=0 osp_ver=338017 osp_pg=0 (spawn #310736) 2025-06-22 09:15:48.239835 :A80B148E: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-22 09:15:48.239836 :A80B148F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=174 time=3559491422 2025-06-22 09:15:48.239836 :A80B1490:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 09:15:48.239836 :A80B1491:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 09:15:48.239837 :A80B1492:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 09:15:48.239837 :A80B1493:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 09:15:48.239837 :A80B1494:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 09:15:48.240315 :A80B1495: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-22 09:15:48.240359 :A80B149D: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-22 09:25:49.046084 :A80BDA76:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 09:25:49.472701 :A80BDAB0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 09:25:49.468 2025-06-22 09:25:49.472703 :A80BDAB1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16644 pso_num=22 pso_serial#=71 2025-06-22 09:25:49.472841 :A80BDAB2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16644 osp_idx=0 osp_ver=338018 osp_pg=0 (spawn #310759) 2025-06-22 09:25:49.472842 :A80BDAB3: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-22 09:25:49.472842 :A80BDAB4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=175 time=3560092657 2025-06-22 09:25:49.472843 :A80BDAB5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 09:25:49.472843 :A80BDAB6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 09:25:49.472843 :A80BDAB7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 09:25:49.472843 :A80BDAB8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 09:25:49.472843 :A80BDAB9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 09:25:49.473337 :A80BDABA: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-22 09:25:49.473381 :A80BDAC1: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-22 09:35:50.351047 :A80CA0B6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 09:35:50.746570 :A80CA0FE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 09:35:50.742 2025-06-22 09:35:50.746572 :A80CA0FF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16900 pso_num=22 pso_serial#=72 2025-06-22 09:35:50.746708 :A80CA100:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16900 osp_idx=0 osp_ver=338019 osp_pg=0 (spawn #310781) 2025-06-22 09:35:50.746709 :A80CA101: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-22 09:35:50.746709 :A80CA102:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=176 time=3560693938 2025-06-22 09:35:50.746709 :A80CA103:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 09:35:50.746710 :A80CA104:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 09:35:50.746710 :A80CA105:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 09:35:50.746710 :A80CA106:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 09:35:50.746711 :A80CA107:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 09:35:50.747203 :A80CA108: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-22 09:35:50.747248 :A80CA10F: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-22 09:36:05.759120 :A80CA65F:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-06-22 09:36:05.759176 :A80CA665:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-06-22 09:36:05.759178 :A80CA666:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=55, exc=55, tot=55 2025-06-22 09:45:51.569057 :A80D66EF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 09:45:51.901781 :A80D6729:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 09:45:51.897 2025-06-22 09:45:51.901783 :A80D672A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12796 pso_num=22 pso_serial#=73 2025-06-22 09:45:51.901916 :A80D672B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12796 osp_idx=0 osp_ver=338020 osp_pg=0 (spawn #310804) 2025-06-22 09:45:51.901917 :A80D672C: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-22 09:45:51.901917 :A80D672D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=177 time=3561295094 2025-06-22 09:45:51.901918 :A80D672E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 09:45:51.901918 :A80D672F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 09:45:51.901918 :A80D6730:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 09:45:51.901919 :A80D6731:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 09:45:51.901919 :A80D6732:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 09:45:51.902414 :A80D6733: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-22 09:45:51.902463 :A80D673A: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-22 09:55:52.826348 :A80E2C37:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 09:55:53.081027 :A80E2C73:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 09:55:53.077 2025-06-22 09:55:53.081029 :A80E2C74:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15000 pso_num=22 pso_serial#=74 2025-06-22 09:55:53.081162 :A80E2C75:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15000 osp_idx=0 osp_ver=338021 osp_pg=0 (spawn #310827) 2025-06-22 09:55:53.081163 :A80E2C76: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-22 09:55:53.081163 :A80E2C77:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=178 time=3561896266 2025-06-22 09:55:53.081164 :A80E2C78:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 09:55:53.081164 :A80E2C79:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 09:55:53.081164 :A80E2C7A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 09:55:53.081165 :A80E2C7B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 09:55:53.081165 :A80E2C7C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 09:55:53.081643 :A80E2C7D: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-22 09:55:53.081687 :A80E2C85: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-22 10:05:54.005899 :A80EFB5D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-22 10:05:54.338788 :A80EFB98:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-22 10:05:54.334 2025-06-22 10:05:54.338790 :A80EFB99:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11796 pso_num=22 pso_serial#=75 2025-06-22 10:05:54.338929 :A80EFB9A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11796 osp_idx=0 osp_ver=338022 osp_pg=0 (spawn #310852) 2025-06-22 10:05:54.338930 :A80EFB9B: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-22 10:05:54.338930 :A80EFB9C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=179 time=3562497532 2025-06-22 10:05:54.338930 :A80EFB9D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 10:05:54.338931 :A80EFB9E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 10:05:54.338931 :A80EFB9F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 10:05:54.338932 :A80EFBA0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 10:05:54.338934 :A80EFBA1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 10:05:54.339434 :A80EFBA2: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-22 10:05:54.339479 :A80EFBA9: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: 11796, W000)