Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250628140711\orcl_w000_15604_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:36368M/63366M, Ph+PgF:42470M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 15604, image: ORACLE.EXE (W000) *** 2025-06-28 14:07:11.748 *** SESSION ID:(209.7561) 2025-06-28 14:07:11.748 *** 2025-06-28 14:07:11.748 Process diagnostic dump for ORACLE.EXE (W000), OS id=15604, pid: 26, proc_ser: 182, sid: 209, sess_ser: 7561 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=158 seq_num=159 snap_id=1 wait times: snap=2.566678 sec, exc=2.566678 sec, total=2.566678 sec wait times: max=5.000000 sec, heur=5 min 4 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.000024 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=157 seq_num=158 snap_id=1 wait times: snap=5.014663 sec, exc=5.014663 sec, total=5.014663 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=156 seq_num=157 snap_id=1 wait times: snap=5.004638 sec, exc=5.004638 sec, total=5.004638 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=155 seq_num=156 snap_id=1 wait times: snap=5.004628 sec, exc=5.004628 sec, total=5.004628 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=154 seq_num=155 snap_id=1 wait times: snap=5.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.000023 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=153 seq_num=154 snap_id=1 wait times: snap=5.003580 sec, exc=5.003580 sec, total=5.003580 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=152 seq_num=153 snap_id=1 wait times: snap=5.000219 sec, exc=5.000219 sec, total=5.000219 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=151 seq_num=152 snap_id=1 wait times: snap=5.008208 sec, exc=5.008208 sec, total=5.008208 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=150 seq_num=151 snap_id=1 wait times: snap=5.014859 sec, exc=5.014859 sec, total=5.014859 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=149 seq_num=150 snap_id=1 wait times: snap=5.014781 sec, exc=5.014781 sec, total=5.014781 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=148 seq_num=149 snap_id=1 wait times: snap=5.004628 sec, exc=5.004628 sec, total=5.004628 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time Sampled Session History of session 209 serial 7561 --------------------------------------------------- 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:05:11 - 14:07:11] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-28 14:07:11.748 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 15604, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-28 11:44:01.750038 :AAC089A4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=7408 pso_num=26 pso_serial#=168 2025-06-28 11:44:01.750186 :AAC089A5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=7408 osp_idx=24 osp_ver=526488 osp_pg=0 (spawn #331082) 2025-06-28 11:44:01.750186 :AAC089A6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 11:44:01.750187 :AAC089A7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=41 time=4086784938 2025-06-28 11:44:01.750187 :AAC089A8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 11:44:01.750187 :AAC089A9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 11:44:01.750188 :AAC089AA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 11:44:01.750188 :AAC089AB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 11:44:01.750188 :AAC089AC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 11:44:01.750697 :AAC089AD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 11:44:01.750741 :AAC089B4:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 11:54:02.698849 :AAC15284:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 11:54:02.984829 :AAC152C1:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 11:54:02.980 2025-06-28 11:54:02.984832 :AAC152C2:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12140 pso_num=26 pso_serial#=169 2025-06-28 11:54:02.984973 :AAC152C3:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12140 osp_idx=24 osp_ver=526489 osp_pg=0 (spawn #331104) 2025-06-28 11:54:02.984974 :AAC152C4:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 11:54:02.984974 :AAC152C5:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=42 time=4087386172 2025-06-28 11:54:02.984975 :AAC152C6:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 11:54:02.984975 :AAC152C7:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 11:54:02.984975 :AAC152C8:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 11:54:02.984976 :AAC152C9:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 11:54:02.984976 :AAC152CA:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 11:54:02.985467 :AAC152CB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 11:54:02.985510 :AAC152D3:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 12:00:34.458140 :AAC1D4D7:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 12:04:04.236368 :AAC21D91:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 12:14:05.114606 :AAC2EEC8:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 12:14:05.509858 :AAC2EF29:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 12:14:05.505 2025-06-28 12:14:05.509860 :AAC2EF2A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=16556 pso_num=26 pso_serial#=170 2025-06-28 12:14:05.509996 :AAC2EF2B:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=16556 osp_idx=24 osp_ver=526490 osp_pg=0 (spawn #331152) 2025-06-28 12:14:05.509997 :AAC2EF2C:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 12:14:05.509997 :AAC2EF2D:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=43 time=4088588704 2025-06-28 12:14:05.509997 :AAC2EF2E:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 12:14:05.509998 :AAC2EF2F:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 12:14:05.509998 :AAC2EF30:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 12:14:05.509998 :AAC2EF31:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 12:14:05.509999 :AAC2EF32:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 12:14:05.510498 :AAC2EF33:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 12:14:05.510553 :AAC2EF3A:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 12:24:06.348726 :AAC3B7D6:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 12:24:06.775322 :AAC3B827:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 12:24:06.770 2025-06-28 12:24:06.775324 :AAC3B828:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=6696 pso_num=26 pso_serial#=171 2025-06-28 12:24:06.775458 :AAC3B829:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=6696 osp_idx=24 osp_ver=526491 osp_pg=0 (spawn #331174) 2025-06-28 12:24:06.775458 :AAC3B82A:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 12:24:06.775458 :AAC3B82B:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=44 time=4089189969 2025-06-28 12:24:06.775458 :AAC3B82C:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 12:24:06.775459 :AAC3B82D:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 12:24:06.775459 :AAC3B82E:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 12:24:06.775459 :AAC3B82F:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 12:24:06.775460 :AAC3B830:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 12:24:06.775946 :AAC3B831:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 12:24:06.775989 :AAC3B839:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 12:34:07.614827 :AAC4827B:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 12:34:07.947710 :AAC482B4:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 12:34:07.942 2025-06-28 12:34:07.947712 :AAC482B5:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10992 pso_num=26 pso_serial#=172 2025-06-28 12:34:07.947850 :AAC482B6:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10992 osp_idx=24 osp_ver=526492 osp_pg=0 (spawn #331197) 2025-06-28 12:34:07.947851 :AAC482B7:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 12:34:07.947851 :AAC482B8:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=45 time=4089791141 2025-06-28 12:34:07.947852 :AAC482B9:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 12:34:07.947852 :AAC482BA:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 12:34:07.947852 :AAC482BB:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 12:34:07.947853 :AAC482BC:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 12:34:07.947855 :AAC482BD:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 12:34:07.948363 :AAC482BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 12:34:07.948407 :AAC482C5:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 12:44:08.794494 :AAC54B77:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 12:44:09.111655 :AAC54BB7:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 12:44:09.106 2025-06-28 12:44:09.111657 :AAC54BB8:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=7180 pso_num=26 pso_serial#=173 2025-06-28 12:44:09.111797 :AAC54BB9:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=7180 osp_idx=24 osp_ver=526493 osp_pg=0 (spawn #331220) 2025-06-28 12:44:09.111798 :AAC54BBA:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 12:44:09.111798 :AAC54BBB:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=46 time=4090392297 2025-06-28 12:44:09.111799 :AAC54BBC:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 12:44:09.111799 :AAC54BBD:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 12:44:09.111800 :AAC54BBE:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 12:44:09.111800 :AAC54BBF:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 12:44:09.111800 :AAC54BC0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 12:44:09.112310 :AAC54BC1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 12:44:09.112357 :AAC54BCB:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 12:54:09.931273 :AAC61377:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 12:54:10.131864 :AAC6139B:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 12:54:10.119 2025-06-28 12:54:10.131866 :AAC6139C:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11660 pso_num=26 pso_serial#=174 2025-06-28 12:54:10.132010 :AAC6139D:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=11660 (legacy spawn) 2025-06-28 12:54:10.138460 :AAC6139E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-28 12:54:10.138635 :AAC613A3:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-28 12:54:10.139452 :AAC613A8:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 12:54:10.148166 :AAC613AB:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 12:54:10.134 2025-06-28 12:54:10.148169 :AAC613AC:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11328 pso_num=26 pso_serial#=175 2025-06-28 12:54:10.148304 :AAC613AD:db_trace:kso.c@4070:ksonfy(): [10420:26:0] kso: new process: pid=11328 (legacy spawn) 2025-06-28 12:54:10.155116 :AAC613AE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-28 12:54:10.155299 :AAC613B7:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-28 12:54:10.156084 :AAC613B8:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 12:54:10.342154 :AAC613F3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 12:54:10.337 2025-06-28 12:54:10.342156 :AAC613F4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=16548 pso_num=26 pso_serial#=176 2025-06-28 12:54:10.342296 :AAC613F5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=16548 osp_idx=24 osp_ver=526496 osp_pg=0 (spawn #331242) 2025-06-28 12:54:10.342297 :AAC613F6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 12:54:10.342297 :AAC613F7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=47 time=4090993532 2025-06-28 12:54:10.342297 :AAC613F8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 12:54:10.342298 :AAC613F9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 12:54:10.342298 :AAC613FA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 12:54:10.342298 :AAC613FB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 12:54:10.342299 :AAC613FC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 12:54:10.342790 :AAC613FD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 12:54:10.342836 :AAC61404:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 13:04:11.310606 :AAC6DF70:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 13:04:11.471805 :AAC6DFA3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 13:04:11.466 2025-06-28 13:04:11.471807 :AAC6DFA4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=17888 pso_num=26 pso_serial#=177 2025-06-28 13:04:11.471944 :AAC6DFA5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=17888 osp_idx=24 osp_ver=526497 osp_pg=0 (spawn #331268) 2025-06-28 13:04:11.471945 :AAC6DFA6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 13:04:11.471945 :AAC6DFA7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=48 time=4091594657 2025-06-28 13:04:11.471946 :AAC6DFA8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 13:04:11.471946 :AAC6DFA9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 13:04:11.471947 :AAC6DFAA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 13:04:11.471947 :AAC6DFAB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 13:04:11.471947 :AAC6DFAC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 13:04:11.472443 :AAC6DFAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 13:04:11.472488 :AAC6DFB5:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 13:14:12.315592 :AAC7AE4E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 13:14:12.695296 :AAC7AEB7:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 13:14:12.690 2025-06-28 13:14:12.695299 :AAC7AEB8:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=17968 pso_num=26 pso_serial#=178 2025-06-28 13:14:12.695432 :AAC7AEB9:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=17968 osp_idx=24 osp_ver=526498 osp_pg=0 (spawn #331291) 2025-06-28 13:14:12.695433 :AAC7AEBA:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 13:14:12.695433 :AAC7AEBB:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=49 time=4092195891 2025-06-28 13:14:12.695433 :AAC7AEBC:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 13:14:12.695434 :AAC7AEBD:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 13:14:12.695434 :AAC7AEBE:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 13:14:12.695435 :AAC7AEBF:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 13:14:12.695435 :AAC7AEC0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 13:14:12.695925 :AAC7AEC1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 13:14:12.695970 :AAC7AEC9:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 13:24:13.570237 :AAC87A30:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 13:24:13.965589 :AAC87A7F:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 13:24:13.960 2025-06-28 13:24:13.965591 :AAC87A80:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=4508 pso_num=26 pso_serial#=179 2025-06-28 13:24:13.965727 :AAC87A81:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=4508 osp_idx=24 osp_ver=526499 osp_pg=0 (spawn #331313) 2025-06-28 13:24:13.965727 :AAC87A82:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 13:24:13.965728 :AAC87A83:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=50 time=4092797157 2025-06-28 13:24:13.965728 :AAC87A84:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 13:24:13.965728 :AAC87A85:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 13:24:13.965729 :AAC87A86:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 13:24:13.965729 :AAC87A87:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 13:24:13.965729 :AAC87A88:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 13:24:13.966208 :AAC87A89:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 13:24:13.966258 :AAC87A8F:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 13:34:14.867879 :AAC9438D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 13:34:15.185262 :AAC943CF:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 13:34:15.181 2025-06-28 13:34:15.185265 :AAC943D0:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=18028 pso_num=26 pso_serial#=180 2025-06-28 13:34:15.185404 :AAC943D1:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=18028 osp_idx=24 osp_ver=526500 osp_pg=0 (spawn #331336) 2025-06-28 13:34:15.185405 :AAC943D2:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 13:34:15.185405 :AAC943D3:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=51 time=4093398375 2025-06-28 13:34:15.185406 :AAC943D4:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 13:34:15.185406 :AAC943D5:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 13:34:15.185407 :AAC943D6:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 13:34:15.185407 :AAC943D7:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 13:34:15.185407 :AAC943D8:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 13:34:15.185898 :AAC943D9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 13:34:15.185951 :AAC943E1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 13:44:16.118920 :AACA0D66:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 13:44:16.436036 :AACA0DA1:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 13:44:16.431 2025-06-28 13:44:16.436038 :AACA0DA2:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11564 pso_num=26 pso_serial#=181 2025-06-28 13:44:16.436169 :AACA0DA3:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11564 osp_idx=24 osp_ver=526501 osp_pg=0 (spawn #331359) 2025-06-28 13:44:16.436169 :AACA0DA4:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 13:44:16.436170 :AACA0DA5:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=52 time=4093999625 2025-06-28 13:44:16.436170 :AACA0DA6:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 13:44:16.436170 :AACA0DA7:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 13:44:16.436171 :AACA0DA8:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 13:44:16.436171 :AACA0DA9:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 13:44:16.436171 :AACA0DAA:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 13:44:16.436706 :AACA0DAB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 13:44:16.436757 :AACA0DB2:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 13:54:17.362614 :AACAD669:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 13:54:17.689971 :AACAD6BE:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 13:54:17.685 2025-06-28 13:54:17.689973 :AACAD6BF:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=15604 pso_num=26 pso_serial#=182 2025-06-28 13:54:17.690109 :AACAD6C0:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=15604 osp_idx=24 osp_ver=526502 osp_pg=0 (spawn #331381) 2025-06-28 13:54:17.690109 :AACAD6C1:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-28 13:54:17.690110 :AACAD6C2:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=53 time=4094600875 2025-06-28 13:54:17.690111 :AACAD6C3:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 13:54:17.690111 :AACAD6C4:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 13:54:17.690111 :AACAD6C5:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 13:54:17.690111 :AACAD6C6:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 13:54:17.690112 :AACAD6C7:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 13:54:17.690650 :AACAD6C8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-28 13:54:17.690695 :AACAD6D0:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 13:54:32.724914 :AACADB76:db_trace:ksl2.c@2477:kslwtbctx(): [10005:26:209] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-06-28 13:54:32.724926 :AACADB78:db_trace:ksl2.c@2611:kslwtectx(): [10005:26:209] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=4 seq_num=5 snap_id=1 2025-06-28 13:54:32.724927 :AACADB7B:db_trace:ksl2.c@2619:kslwtectx(): [10005:26:209] KSL WAIT END wait times (usecs) - snap=12, exc=12, tot=12 2025-06-28 14:02:07.482748 :AACB74EA:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-28 14:04:18.918890 :AACBA190:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 26 (osid: 15604, W000)