Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250705100739\orcl_w000_18196_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:37513M/63366M, Ph+PgF:43418M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 18196, image: ORACLE.EXE (W000) *** 2025-07-05 10:07:39.848 *** SESSION ID:(201.11299) 2025-07-05 10:07:39.848 *** 2025-07-05 10:07:39.848 Process diagnostic dump for ORACLE.EXE (W000), OS id=18196, pid: 25, proc_ser: 157, sid: 201, sess_ser: 11299 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=3.819394 sec, exc=3.819394 sec, total=3.819394 sec wait times: max=5.000000 sec, heur=2 min 39 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=31 seq_num=32 snap_id=1 wait times: snap=5.001447 sec, exc=5.001447 sec, total=5.001447 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 1: 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.000370 sec, exc=5.000370 sec, total=5.000370 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.008608 sec, exc=5.008608 sec, total=5.008608 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=28 seq_num=29 snap_id=1 wait times: snap=5.004652 sec, exc=5.004652 sec, total=5.004652 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=5.014749 sec, exc=5.014749 sec, total=5.014749 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=26 seq_num=27 snap_id=1 wait times: snap=5.010165 sec, exc=5.010165 sec, total=5.010165 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000018 sec of elapsed time 6: 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.009725 sec, exc=5.009725 sec, total=5.009725 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 7: 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.003237 sec, exc=5.003237 sec, total=5.003237 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000018 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.000374 sec, exc=5.000374 sec, total=5.000374 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.007580 sec, exc=5.007580 sec, total=5.007580 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 201 serial 11299 --------------------------------------------------- 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:05:39 - 10:07:39] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-05 10:07:39.848 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 18196, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-05 06:34:33.065428 :ADBC45F7: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-07-05 06:44:33.857964 :ADBD144D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 06:44:34.222106 :ADBD149F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 06:44:34.217 2025-07-05 06:44:34.222108 :ADBD14A0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15496 pso_num=25 pso_serial#=145 2025-07-05 06:44:34.222248 :ADBD14A1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15496 osp_idx=23 osp_ver=182837 osp_pg=0 (spawn #353714) 2025-07-05 06:44:34.222249 :ADBD14A2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 06:44:34.222249 :ADBD14A3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=97 time=378650111 2025-07-05 06:44:34.222249 :ADBD14A4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 06:44:34.222250 :ADBD14A5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 06:44:34.222250 :ADBD14A6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 06:44:34.222250 :ADBD14A7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 06:44:34.222251 :ADBD14A8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 06:44:34.222794 :ADBD14A9: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-07-05 06:44:34.222841 :ADBD14B1: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-07-05 06:54:35.032957 :ADBDE2A4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 06:54:35.350330 :ADBDE2FB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 06:54:35.345 2025-07-05 06:54:35.350332 :ADBDE2FC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7880 pso_num=25 pso_serial#=146 2025-07-05 06:54:35.350465 :ADBDE2FD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7880 osp_idx=23 osp_ver=182838 osp_pg=0 (spawn #353737) 2025-07-05 06:54:35.350465 :ADBDE2FE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 06:54:35.350466 :ADBDE2FF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=98 time=379251251 2025-07-05 06:54:35.350466 :ADBDE300:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 06:54:35.350466 :ADBDE301:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 06:54:35.350466 :ADBDE302:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 06:54:35.350467 :ADBDE303:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 06:54:35.350467 :ADBDE304:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 06:54:35.351005 :ADBDE305: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-07-05 06:54:35.351054 :ADBDE30D: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-07-05 07:00:30.709409 :ADBE5DE9: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-07-05 07:04:36.572002 :ADBEB699: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-07-05 07:14:37.458074 :ADBF89D1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 07:14:37.806343 :ADBF8A36:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 07:14:37.801 2025-07-05 07:14:37.806345 :ADBF8A37:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11772 pso_num=25 pso_serial#=147 2025-07-05 07:14:37.806483 :ADBF8A38:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11772 osp_idx=23 osp_ver=182839 osp_pg=0 (spawn #353784) 2025-07-05 07:14:37.806484 :ADBF8A39:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 07:14:37.806484 :ADBF8A3A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=99 time=380453704 2025-07-05 07:14:37.806484 :ADBF8A3B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 07:14:37.806485 :ADBF8A3C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 07:14:37.806485 :ADBF8A3D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 07:14:37.806485 :ADBF8A3E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 07:14:37.806485 :ADBF8A3F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 07:14:37.807051 :ADBF8A40: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-07-05 07:14:37.807105 :ADBF8A4A: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-07-05 07:24:38.602581 :ADC057F6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 07:24:38.967007 :ADC05850:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 07:24:38.962 2025-07-05 07:24:38.967010 :ADC05851:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11256 pso_num=25 pso_serial#=148 2025-07-05 07:24:38.967140 :ADC05852:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11256 osp_idx=23 osp_ver=182840 osp_pg=0 (spawn #353807) 2025-07-05 07:24:38.967141 :ADC05853:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 07:24:38.967142 :ADC05854:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=100 time=381054861 2025-07-05 07:24:38.967142 :ADC05855:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 07:24:38.967142 :ADC05856:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 07:24:38.967143 :ADC05857:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 07:24:38.967143 :ADC05858:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 07:24:38.967143 :ADC05859:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 07:24:38.967706 :ADC0585A: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-07-05 07:24:38.967749 :ADC05862: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-07-05 07:34:39.894667 :ADC1245E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 07:34:40.397770 :ADC124E0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 07:34:40.392 2025-07-05 07:34:40.397772 :ADC124E1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18420 pso_num=25 pso_serial#=149 2025-07-05 07:34:40.397891 :ADC124E2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18420 osp_idx=23 osp_ver=182841 osp_pg=0 (spawn #353830) 2025-07-05 07:34:40.397892 :ADC124E3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 07:34:40.397892 :ADC124E4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=101 time=381656298 2025-07-05 07:34:40.397893 :ADC124E5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 07:34:40.397893 :ADC124E6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 07:34:40.397894 :ADC124E7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 07:34:40.397894 :ADC124E8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 07:34:40.397894 :ADC124E9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 07:34:40.398359 :ADC124EA: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-07-05 07:34:40.398408 :ADC124F1: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-07-05 07:44:41.382624 :ADC1F14A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 07:44:41.965811 :ADC1F1DC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 07:44:41.967 2025-07-05 07:44:41.965813 :ADC1F1DD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7460 pso_num=25 pso_serial#=150 2025-07-05 07:44:41.965944 :ADC1F1DE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7460 osp_idx=23 osp_ver=182842 osp_pg=0 (spawn #353853) 2025-07-05 07:44:41.965945 :ADC1F1DF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 07:44:41.965945 :ADC1F1E0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=102 time=382257704 2025-07-05 07:44:41.965945 :ADC1F1E1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 07:44:41.965946 :ADC1F1E2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 07:44:41.965946 :ADC1F1E3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 07:44:41.965946 :ADC1F1E4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 07:44:41.965947 :ADC1F1E5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 07:44:41.966494 :ADC1F1E6: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-07-05 07:44:41.966541 :ADC1F1F0: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-07-05 07:54:43.349516 :ADC2BE4A: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-07-05 08:04:44.966255 :ADC38BFA: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-07-05 08:14:46.403246 :ADC45DF1: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-07-05 08:24:47.918100 :ADC52C90: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-07-05 08:34:49.386433 :ADC6043C: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-07-05 08:44:50.969112 :ADC6D0E2: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-07-05 08:54:51.815223 :ADC79CD8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 08:54:52.308364 :ADC79D08:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 08:54:52.300 2025-07-05 08:54:52.308366 :ADC79D09:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16692 pso_num=25 pso_serial#=151 2025-07-05 08:54:52.308488 :ADC79D0A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16692 osp_idx=23 osp_ver=182843 osp_pg=0 (spawn #354010) 2025-07-05 08:54:52.308488 :ADC79D0B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 08:54:52.308489 :ADC79D0C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=103 time=386468204 2025-07-05 08:54:52.308489 :ADC79D0D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 08:54:52.308489 :ADC79D0E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 08:54:52.308489 :ADC79D0F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 08:54:52.308490 :ADC79D10:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 08:54:52.308490 :ADC79D11:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 08:54:52.308957 :ADC79D12: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-07-05 08:54:52.309005 :ADC79D18: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-07-05 09:00:38.710816 :ADC8148F: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-07-05 09:04:53.630590 :ADC86E55: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-07-05 09:04:53.630640 :ADC86E56:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-07-05 09:04:53.630643 :ADC86E57:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-07-05 09:04:53.630644 :ADC86E58:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=3, exc=3, tot=3 2025-07-05 09:04:53.631046 :ADC86E5D: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-07-05 09:14:54.605567 :ADC9460B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 09:14:54.938521 :ADC9465C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 09:14:54.933 2025-07-05 09:14:54.938523 :ADC9465D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12272 pso_num=25 pso_serial#=152 2025-07-05 09:14:54.938664 :ADC9465E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12272 osp_idx=23 osp_ver=182844 osp_pg=0 (spawn #354057) 2025-07-05 09:14:54.938665 :ADC9465F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 09:14:54.938666 :ADC94660:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=104 time=387670829 2025-07-05 09:14:54.938666 :ADC94661:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 09:14:54.938666 :ADC94662:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 09:14:54.938667 :ADC94663:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 09:14:54.938667 :ADC94664:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 09:14:54.938668 :ADC94665:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 09:14:54.939256 :ADC94666: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-07-05 09:14:54.939313 :ADC94670: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-07-05 09:24:55.771104 :ADCA14B3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 09:24:56.135439 :ADCA14F0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 09:24:56.130 2025-07-05 09:24:56.135441 :ADCA14F1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17064 pso_num=25 pso_serial#=153 2025-07-05 09:24:56.135576 :ADCA14F2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17064 osp_idx=23 osp_ver=182845 osp_pg=0 (spawn #354080) 2025-07-05 09:24:56.135577 :ADCA14F3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 09:24:56.135577 :ADCA14F4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=105 time=388272033 2025-07-05 09:24:56.135577 :ADCA14F5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 09:24:56.135578 :ADCA14F6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 09:24:56.135578 :ADCA14F7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 09:24:56.135578 :ADCA14F8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 09:24:56.135579 :ADCA14F9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 09:24:56.136151 :ADCA14FA: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-07-05 09:24:56.136196 :ADCA1502: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-07-05 09:34:56.989047 :ADCAE4A5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 09:34:57.244181 :ADCAE4D6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 09:34:57.239 2025-07-05 09:34:57.244183 :ADCAE4D7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16572 pso_num=25 pso_serial#=154 2025-07-05 09:34:57.244325 :ADCAE4D8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16572 osp_idx=23 osp_ver=182846 osp_pg=0 (spawn #354103) 2025-07-05 09:34:57.244325 :ADCAE4D9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 09:34:57.244326 :ADCAE4DA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=106 time=388873142 2025-07-05 09:34:57.244326 :ADCAE4DB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 09:34:57.244327 :ADCAE4DC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 09:34:57.244327 :ADCAE4DD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 09:34:57.244327 :ADCAE4DE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 09:34:57.244328 :ADCAE4DF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 09:34:57.244896 :ADCAE4E0: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-07-05 09:34:57.244947 :ADCAE4E6: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-07-05 09:44:58.018235 :ADCBB391:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 09:44:58.429967 :ADCBB3B6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 09:44:58.424 2025-07-05 09:44:58.429970 :ADCBB3B7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15440 pso_num=25 pso_serial#=155 2025-07-05 09:44:58.430110 :ADCBB3B8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15440 osp_idx=23 osp_ver=182847 osp_pg=0 (spawn #354126) 2025-07-05 09:44:58.430111 :ADCBB3B9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 09:44:58.430112 :ADCBB3BA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=107 time=389474329 2025-07-05 09:44:58.430112 :ADCBB3BB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 09:44:58.430112 :ADCBB3BC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 09:44:58.430114 :ADCBB3BD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 09:44:58.430115 :ADCBB3BE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 09:44:58.430115 :ADCBB3BF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 09:44:58.430732 :ADCBB3C0: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-07-05 09:44:58.430776 :ADCBB3C7: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-07-05 09:54:59.319132 :ADCC832F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 09:54:59.620997 :ADCC8354:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 09:54:59.616 2025-07-05 09:54:59.620999 :ADCC8355:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12040 pso_num=25 pso_serial#=156 2025-07-05 09:54:59.621139 :ADCC8356:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12040 osp_idx=23 osp_ver=182848 osp_pg=0 (spawn #354149) 2025-07-05 09:54:59.621139 :ADCC8357:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 09:54:59.621140 :ADCC8358:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=108 time=390075517 2025-07-05 09:54:59.621140 :ADCC8359:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 09:54:59.621141 :ADCC835A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 09:54:59.621141 :ADCC835B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 09:54:59.621141 :ADCC835C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 09:54:59.621141 :ADCC835D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 09:54:59.621759 :ADCC835E: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-07-05 09:54:59.621806 :ADCC8366: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-07-05 10:05:00.529458 :ADCD546B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-05 10:05:00.816098 :ADCD5493:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-05 10:05:00.811 2025-07-05 10:05:00.816100 :ADCD5494:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18196 pso_num=25 pso_serial#=157 2025-07-05 10:05:00.816246 :ADCD5495:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18196 osp_idx=23 osp_ver=182849 osp_pg=0 (spawn #354175) 2025-07-05 10:05:00.816247 :ADCD5496:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 10:05:00.816247 :ADCD5497:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=109 time=390676704 2025-07-05 10:05:00.816248 :ADCD5498:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 10:05:00.816248 :ADCD5499:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 10:05:00.816249 :ADCD549A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 10:05:00.816249 :ADCD549B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 10:05:00.816249 :ADCD549C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 10:05:00.816982 :ADCD549D: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-07-05 10:05:00.817028 :ADCD54A5: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: 18196, W000)