Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250830140346\orcl_w000_20372_bucket.trc Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options Windows NT Version V6.2 CPU : 32 - type 8664, 16 Physical Cores Process Affinity : 0x0x0000000000000000 Memory (Avail/Total): Ph:35116M/63366M, Ph+PgF:40140M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 20372, image: ORACLE.EXE (W000) *** 2025-08-30 14:03:46.291 *** SESSION ID:(201.62723) 2025-08-30 14:03:46.291 *** 2025-08-30 14:03:46.291 Process diagnostic dump for ORACLE.EXE (W000), OS id=20372, pid: 25, proc_ser: 163, sid: 201, sess_ser: 62723 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=90 seq_num=91 snap_id=1 wait times: snap=2.288042 sec, exc=2.288042 sec, total=2.288042 sec wait times: max=5.000000 sec, heur=7 min 27 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.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=89 seq_num=90 snap_id=1 wait times: snap=5.000164 sec, exc=5.000164 sec, total=5.000164 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=88 seq_num=89 snap_id=1 wait times: snap=5.001917 sec, exc=5.001917 sec, total=5.001917 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=87 seq_num=88 snap_id=1 wait times: snap=5.014107 sec, exc=5.014107 sec, total=5.014107 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=86 seq_num=87 snap_id=1 wait times: snap=5.014715 sec, exc=5.014715 sec, total=5.014715 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=85 seq_num=86 snap_id=1 wait times: snap=5.014724 sec, exc=5.014724 sec, total=5.014724 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=84 seq_num=85 snap_id=1 wait times: snap=5.004624 sec, exc=5.004624 sec, total=5.004624 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=83 seq_num=84 snap_id=1 wait times: snap=5.004633 sec, exc=5.004633 sec, total=5.004633 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 7: 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.015260 sec, exc=5.015260 sec, total=5.015260 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 8: 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.003399 sec, exc=5.003399 sec, total=5.003399 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=80 seq_num=81 snap_id=1 wait times: snap=5.002855 sec, exc=5.002855 sec, total=5.002855 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 62723 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [121 samples, 14:01:46 - 14:03:46] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-30 14:03:46.291 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 20372, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-30 11:36:01.255996 :C6A11DEA:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 11:36:01.251 2025-08-30 11:36:01.255998 :C6A11DEB:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20564 pso_num=25 pso_serial#=150 2025-08-30 11:36:01.256139 :C6A11DEC:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20564 osp_idx=23 osp_ver=266482 osp_pg=0 (spawn #541045) 2025-08-30 11:36:01.256139 :C6A11DED:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 11:36:01.256140 :C6A11DEE:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=56 time=939412565 2025-08-30 11:36:01.256140 :C6A11DEF:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 11:36:01.256140 :C6A11DF0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 11:36:01.256141 :C6A11DF1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 11:36:01.256141 :C6A11DF2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 11:36:01.256141 :C6A11DF3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 11:36:01.256653 :C6A11DF4: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-08-30 11:36:01.256698 :C6A11DFB: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-08-30 11:46:02.061109 :C6A1E47E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 11:46:02.362701 :C6A1E4B6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 11:46:02.358 2025-08-30 11:46:02.362705 :C6A1E4B7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20488 pso_num=25 pso_serial#=151 2025-08-30 11:46:02.362848 :C6A1E4B8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20488 osp_idx=23 osp_ver=266483 osp_pg=0 (spawn #541068) 2025-08-30 11:46:02.362848 :C6A1E4B9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 11:46:02.362849 :C6A1E4BA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=57 time=940013674 2025-08-30 11:46:02.362849 :C6A1E4BB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 11:46:02.362850 :C6A1E4BC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 11:46:02.362850 :C6A1E4BD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 11:46:02.362850 :C6A1E4BE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 11:46:02.362851 :C6A1E4BF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 11:46:02.363367 :C6A1E4C0: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-08-30 11:46:02.363419 :C6A1E4C8: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-08-30 11:56:03.119342 :C6A2AB14:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 11:56:03.545863 :C6A2AB57:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 11:56:03.541 2025-08-30 11:56:03.545865 :C6A2AB58:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19000 pso_num=25 pso_serial#=152 2025-08-30 11:56:03.546009 :C6A2AB59:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19000 osp_idx=23 osp_ver=266484 osp_pg=0 (spawn #541090) 2025-08-30 11:56:03.546010 :C6A2AB5A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 11:56:03.546010 :C6A2AB5B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=58 time=940614846 2025-08-30 11:56:03.546011 :C6A2AB5C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 11:56:03.546011 :C6A2AB5D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 11:56:03.546011 :C6A2AB5E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 11:56:03.546012 :C6A2AB5F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 11:56:03.546012 :C6A2AB60:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 11:56:03.546506 :C6A2AB61: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-08-30 11:56:03.546550 :C6A2AB69: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-08-30 12:06:04.392815 :C6A37862:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 12:06:04.835065 :C6A37899:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 12:06:04.830 2025-08-30 12:06:04.835067 :C6A3789A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19912 pso_num=25 pso_serial#=153 2025-08-30 12:06:04.835207 :C6A3789B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19912 osp_idx=23 osp_ver=266485 osp_pg=0 (spawn #541116) 2025-08-30 12:06:04.835208 :C6A3789C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 12:06:04.835208 :C6A3789D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=59 time=941216143 2025-08-30 12:06:04.835208 :C6A3789E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 12:06:04.835208 :C6A3789F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 12:06:04.835209 :C6A378A0:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 12:06:04.835209 :C6A378A1:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 12:06:04.835209 :C6A378A2:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 12:06:04.835704 :C6A378A3: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-08-30 12:06:04.835751 :C6A378AA: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-08-30 12:16:05.715943 :C6A4417C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 12:16:06.080228 :C6A441B2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 12:16:06.075 2025-08-30 12:16:06.080230 :C6A441B3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21264 pso_num=25 pso_serial#=154 2025-08-30 12:16:06.080366 :C6A441B4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21264 osp_idx=23 osp_ver=266486 osp_pg=0 (spawn #541139) 2025-08-30 12:16:06.080367 :C6A441B5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 12:16:06.080367 :C6A441B6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=60 time=941817377 2025-08-30 12:16:06.080368 :C6A441B7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 12:16:06.080368 :C6A441B8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 12:16:06.080368 :C6A441B9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 12:16:06.080369 :C6A441BA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 12:16:06.080369 :C6A441BB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 12:16:06.080873 :C6A441BC: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-08-30 12:16:06.080930 :C6A441C6: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-08-30 12:26:07.021432 :C6A507FA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 12:26:07.229324 :C6A50830:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 12:26:07.224 2025-08-30 12:26:07.229326 :C6A50831:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23536 pso_num=25 pso_serial#=155 2025-08-30 12:26:07.229468 :C6A50832:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23536 osp_idx=23 osp_ver=266487 osp_pg=0 (spawn #541161) 2025-08-30 12:26:07.229469 :C6A50833:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 12:26:07.229469 :C6A50834:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=61 time=942418533 2025-08-30 12:26:07.229470 :C6A50835:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 12:26:07.229470 :C6A50836:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 12:26:07.229471 :C6A50837:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 12:26:07.229471 :C6A50838:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 12:26:07.229471 :C6A50839:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 12:26:07.229975 :C6A5083A: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-08-30 12:26:07.230022 :C6A50841: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-08-30 12:36:07.976442 :C6A5CF76:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 12:36:08.309141 :C6A5CFAF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 12:36:08.304 2025-08-30 12:36:08.309143 :C6A5CFB0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21540 pso_num=25 pso_serial#=156 2025-08-30 12:36:08.309285 :C6A5CFB1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21540 osp_idx=23 osp_ver=266488 osp_pg=0 (spawn #541184) 2025-08-30 12:36:08.309285 :C6A5CFB2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 12:36:08.309286 :C6A5CFB3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=62 time=943019612 2025-08-30 12:36:08.309286 :C6A5CFB4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 12:36:08.309286 :C6A5CFB5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 12:36:08.309287 :C6A5CFB6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 12:36:08.309287 :C6A5CFB7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 12:36:08.309287 :C6A5CFB8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 12:36:08.309792 :C6A5CFB9: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-08-30 12:36:08.309840 :C6A5CFC1: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-08-30 12:36:53.390440 :C6A5DE95:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-08-30 12:36:53.390447 :C6A5DE9A:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-08-30 12:36:53.390449 :C6A5DE9B:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=9, exc=9, tot=9 2025-08-30 12:36:53.390464 :C6A5DEA1: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-08-30 12:46:09.090163 :C6A6977F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 12:46:09.407521 :C6A697E2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 12:46:09.402 2025-08-30 12:46:09.407523 :C6A697E3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=2268 pso_num=25 pso_serial#=157 2025-08-30 12:46:09.407660 :C6A697E4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=2268 osp_idx=23 osp_ver=266489 osp_pg=0 (spawn #541207) 2025-08-30 12:46:09.407661 :C6A697E5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 12:46:09.407661 :C6A697E6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=63 time=943620705 2025-08-30 12:46:09.407662 :C6A697E7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 12:46:09.407662 :C6A697E8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 12:46:09.407663 :C6A697E9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 12:46:09.407663 :C6A697EA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 12:46:09.407663 :C6A697EB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 12:46:09.408148 :C6A697EC: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-08-30 12:46:09.408196 :C6A697F4: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-08-30 12:56:10.215951 :C6A75E9D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 12:56:10.564531 :C6A75ED6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 12:56:10.559 2025-08-30 12:56:10.564534 :C6A75ED7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22716 pso_num=25 pso_serial#=158 2025-08-30 12:56:10.564672 :C6A75ED8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22716 osp_idx=23 osp_ver=266490 osp_pg=0 (spawn #541229) 2025-08-30 12:56:10.564672 :C6A75ED9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 12:56:10.564673 :C6A75EDA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=64 time=944221862 2025-08-30 12:56:10.564673 :C6A75EDB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 12:56:10.564674 :C6A75EDC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 12:56:10.564674 :C6A75EDD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 12:56:10.564674 :C6A75EDE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 12:56:10.564674 :C6A75EDF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 12:56:10.565186 :C6A75EE0: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-08-30 12:56:10.565230 :C6A75EE6: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-08-30 13:00:33.135199 :C6A7B700: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-08-30 13:06:11.843434 :C6A82F06: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-08-30 13:16:12.680691 :C6A8F511:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 13:16:13.060370 :C6A8F549:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 13:16:13.055 2025-08-30 13:16:13.060372 :C6A8F54A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22884 pso_num=25 pso_serial#=159 2025-08-30 13:16:13.060513 :C6A8F54B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22884 osp_idx=23 osp_ver=266491 osp_pg=0 (spawn #541277) 2025-08-30 13:16:13.060514 :C6A8F54C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 13:16:13.060514 :C6A8F54D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=65 time=945424362 2025-08-30 13:16:13.060515 :C6A8F54E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 13:16:13.060516 :C6A8F54F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 13:16:13.060516 :C6A8F550:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 13:16:13.060516 :C6A8F551:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 13:16:13.060517 :C6A8F552:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 13:16:13.061016 :C6A8F553: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-08-30 13:16:13.061059 :C6A8F559: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-08-30 13:26:13.939584 :C6A9BB5F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 13:26:14.288004 :C6A9BB94:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 13:26:14.283 2025-08-30 13:26:14.288006 :C6A9BB95:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23160 pso_num=25 pso_serial#=160 2025-08-30 13:26:14.288144 :C6A9BB96:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23160 osp_idx=23 osp_ver=266492 osp_pg=0 (spawn #541299) 2025-08-30 13:26:14.288145 :C6A9BB97:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 13:26:14.288146 :C6A9BB98:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=66 time=946025596 2025-08-30 13:26:14.288146 :C6A9BB99:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 13:26:14.288146 :C6A9BB9A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 13:26:14.288147 :C6A9BB9B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 13:26:14.288147 :C6A9BB9C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 13:26:14.288147 :C6A9BB9D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 13:26:14.288638 :C6A9BB9E: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-08-30 13:26:14.288683 :C6A9BBA5: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-08-30 13:36:15.222777 :C6AA8301:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 13:36:15.696235 :C6AA8338:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 13:36:15.691 2025-08-30 13:36:15.696237 :C6AA8339:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19156 pso_num=25 pso_serial#=161 2025-08-30 13:36:15.696365 :C6AA833A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19156 osp_idx=23 osp_ver=266493 osp_pg=0 (spawn #541322) 2025-08-30 13:36:15.696366 :C6AA833B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 13:36:15.696367 :C6AA833C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=67 time=946627002 2025-08-30 13:36:15.696367 :C6AA833D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 13:36:15.696367 :C6AA833E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 13:36:15.696368 :C6AA833F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 13:36:15.696368 :C6AA8340:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 13:36:15.696368 :C6AA8341:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 13:36:15.696846 :C6AA8342: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-08-30 13:36:15.697853 :C6AA834C: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-08-30 13:46:16.439550 :C6AB49AA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 13:46:17.022933 :C6AB49E5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 13:46:17.017 2025-08-30 13:46:17.022935 :C6AB49E6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23104 pso_num=25 pso_serial#=162 2025-08-30 13:46:17.023097 :C6AB49E7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23104 osp_idx=23 osp_ver=266494 osp_pg=0 (spawn #541345) 2025-08-30 13:46:17.023098 :C6AB49E8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 13:46:17.023098 :C6AB49E9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=68 time=947228330 2025-08-30 13:46:17.023099 :C6AB49EA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 13:46:17.023099 :C6AB49EB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 13:46:17.023100 :C6AB49EC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 13:46:17.023100 :C6AB49ED:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 13:46:17.023101 :C6AB49EE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 13:46:17.023669 :C6AB49EF: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-08-30 13:46:17.023731 :C6AB49F5: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-08-30 13:56:17.878389 :C6AC11B0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-30 13:56:18.445662 :C6AC11F6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-30 13:56:18.440 2025-08-30 13:56:18.445664 :C6AC11F7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20372 pso_num=25 pso_serial#=163 2025-08-30 13:56:18.445807 :C6AC11F8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20372 osp_idx=23 osp_ver=266495 osp_pg=0 (spawn #541367) 2025-08-30 13:56:18.445808 :C6AC11F9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-30 13:56:18.445808 :C6AC11FA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=69 time=947829752 2025-08-30 13:56:18.445808 :C6AC11FB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-30 13:56:18.445809 :C6AC11FC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-30 13:56:18.445809 :C6AC11FD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-30 13:56:18.445810 :C6AC11FE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-30 13:56:18.445810 :C6AC11FF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-30 13:56:18.446354 :C6AC1200: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-08-30 13:56:18.446400 :C6AC1207: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: 20372, W000)