Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250628180740\orcl_w000_9284_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:36383M/63366M, Ph+PgF:42519M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 9284, image: ORACLE.EXE (W000) *** 2025-06-28 18:07:40.436 *** SESSION ID:(209.7607) 2025-06-28 18:07:40.436 *** 2025-06-28 18:07:40.436 Process diagnostic dump for ORACLE.EXE (W000), OS id=9284, pid: 26, proc_ser: 205, sid: 209, sess_ser: 7607 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=157 seq_num=158 snap_id=1 wait times: snap=1.557926 sec, exc=1.557926 sec, total=1.557926 sec wait times: max=5.000000 sec, heur=5 min 26 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.000023 sec since current wait 0: 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.013082 sec, exc=5.013082 sec, total=5.013082 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 1: 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.004645 sec, exc=5.004645 sec, total=5.004645 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=154 seq_num=155 snap_id=1 wait times: snap=5.014735 sec, exc=5.014735 sec, total=5.014735 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 3: 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.004625 sec, exc=5.004625 sec, total=5.004625 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 4: 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.002715 sec, exc=5.002715 sec, total=5.002715 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 5: 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.000194 sec, exc=5.000194 sec, total=5.000194 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=150 seq_num=151 snap_id=1 wait times: snap=5.006370 sec, exc=5.006370 sec, total=5.006370 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=149 seq_num=150 snap_id=1 wait times: snap=5.002333 sec, exc=5.002333 sec, total=5.002333 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000041 sec of elapsed time 8: 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.004659 sec, exc=5.004659 sec, total=5.004659 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000041 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=147 seq_num=148 snap_id=1 wait times: snap=5.004640 sec, exc=5.004640 sec, total=5.004640 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time Sampled Session History of session 209 serial 7607 --------------------------------------------------- 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, 18:05:40 - 18:07:40] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-28 18:07:40.436 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 9284, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-28 15:34:30.462379 :AAD2CFF1:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=62 time=4100613657 2025-06-28 15:34:30.462379 :AAD2CFF2:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 15:34:30.462379 :AAD2CFF3:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 15:34:30.462379 :AAD2CFF4:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 15:34:30.462380 :AAD2CFF5:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 15:34:30.462380 :AAD2CFF6:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 15:34:30.462889 :AAD2CFF7: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 15:34:30.462939 :AAD2CFFF: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 15:44:31.213943 :AAD398A7:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 15:44:31.703122 :AAD3992D:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 15:44:31.698 2025-06-28 15:44:31.703124 :AAD3992E:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=8732 pso_num=26 pso_serial#=193 2025-06-28 15:44:31.703264 :AAD3992F:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=8732 osp_idx=24 osp_ver=526513 osp_pg=0 (spawn #331638) 2025-06-28 15:44:31.703264 :AAD39930: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 15:44:31.703265 :AAD39931:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=63 time=4101214891 2025-06-28 15:44:31.703265 :AAD39932:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 15:44:31.703266 :AAD39933:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 15:44:31.703266 :AAD39934:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 15:44:31.703266 :AAD39935:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 15:44:31.703267 :AAD39936:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 15:44:31.703765 :AAD39937: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 15:44:31.703811 :AAD3993D: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 15:54:32.635207 :AAD46166:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 15:54:32.905489 :AAD461C5:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 15:54:32.901 2025-06-28 15:54:32.905491 :AAD461C6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=16556 pso_num=26 pso_serial#=194 2025-06-28 15:54:32.905630 :AAD461C7:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=16556 osp_idx=24 osp_ver=526514 osp_pg=0 (spawn #331660) 2025-06-28 15:54:32.905631 :AAD461C8: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 15:54:32.905631 :AAD461C9:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=64 time=4101816094 2025-06-28 15:54:32.905631 :AAD461CA:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 15:54:32.905632 :AAD461CB:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 15:54:32.905632 :AAD461CC:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 15:54:32.905632 :AAD461CD:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 15:54:32.905633 :AAD461CE:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 15:54:32.906153 :AAD461CF: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 15:54:32.906207 :AAD461D9: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 16:02:13.117399 :AAD4FDE0: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 16:02:13.119605 :AAD4FDEA: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 16:04:34.170360 :AAD52DB8: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 16:05:04.216369 :AAD53755:db_trace:ksl2.c@2477:kslwtbctx(): [10005:26:209] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=130 seq_num=131 snap_id=1 2025-06-28 16:05:04.216375 :AAD5375A:db_trace:ksl2.c@2611:kslwtectx(): [10005:26:209] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=130 seq_num=131 snap_id=1 2025-06-28 16:05:04.216376 :AAD5375B:db_trace:ksl2.c@2619:kslwtectx(): [10005:26:209] KSL WAIT END wait times (usecs) - snap=9, exc=9, tot=9 2025-06-28 16:05:04.216385 :AAD5375C: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 16:14:35.001086 :AAD5FF1F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 16:14:35.380574 :AAD5FF7E:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 16:14:35.375 2025-06-28 16:14:35.380576 :AAD5FF7F:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=8164 pso_num=26 pso_serial#=195 2025-06-28 16:14:35.380711 :AAD5FF80:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=8164 osp_idx=24 osp_ver=526515 osp_pg=0 (spawn #331709) 2025-06-28 16:14:35.380712 :AAD5FF81: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 16:14:35.380712 :AAD5FF82:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=65 time=4103018563 2025-06-28 16:14:35.380713 :AAD5FF83:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 16:14:35.380713 :AAD5FF84:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 16:14:35.380713 :AAD5FF85:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 16:14:35.380714 :AAD5FF86:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 16:14:35.380714 :AAD5FF87:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 16:14:35.381255 :AAD5FF88: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 16:14:35.381299 :AAD5FF91: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 16:24:36.300865 :AAD6C7C3:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 16:24:36.586692 :AAD6C810:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 16:24:36.582 2025-06-28 16:24:36.586694 :AAD6C811:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=17544 pso_num=26 pso_serial#=196 2025-06-28 16:24:36.586828 :AAD6C812:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=17544 osp_idx=24 osp_ver=526516 osp_pg=0 (spawn #331731) 2025-06-28 16:24:36.586829 :AAD6C813: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 16:24:36.586829 :AAD6C814:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=66 time=4103619782 2025-06-28 16:24:36.586830 :AAD6C815:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 16:24:36.586830 :AAD6C816:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 16:24:36.586830 :AAD6C817:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 16:24:36.586831 :AAD6C818:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 16:24:36.586831 :AAD6C819:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 16:24:36.587328 :AAD6C81A: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 16:24:36.587371 :AAD6C822: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 16:34:37.462370 :AAD792C1:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 16:34:37.748311 :AAD79316:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 16:34:37.743 2025-06-28 16:34:37.748313 :AAD79317:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10840 pso_num=26 pso_serial#=197 2025-06-28 16:34:37.748453 :AAD79318:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10840 osp_idx=24 osp_ver=526517 osp_pg=0 (spawn #331754) 2025-06-28 16:34:37.748453 :AAD79319: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 16:34:37.748453 :AAD7931A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=67 time=4104220938 2025-06-28 16:34:37.748454 :AAD7931B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 16:34:37.748454 :AAD7931C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 16:34:37.748455 :AAD7931D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 16:34:37.748455 :AAD7931E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 16:34:37.748455 :AAD7931F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 16:34:37.748937 :AAD79320: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 16:34:37.748988 :AAD7932A: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 16:44:38.630469 :AAD85B99:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 16:44:38.963196 :AAD85BEC:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 16:44:38.958 2025-06-28 16:44:38.963198 :AAD85BED:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=16132 pso_num=26 pso_serial#=198 2025-06-28 16:44:38.963340 :AAD85BEE:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=16132 osp_idx=24 osp_ver=526518 osp_pg=0 (spawn #331777) 2025-06-28 16:44:38.963341 :AAD85BEF: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 16:44:38.963341 :AAD85BF0:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=68 time=4104822157 2025-06-28 16:44:38.963341 :AAD85BF1:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 16:44:38.963341 :AAD85BF2:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 16:44:38.963342 :AAD85BF3:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 16:44:38.963342 :AAD85BF4:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 16:44:38.963342 :AAD85BF5:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 16:44:38.963822 :AAD85BF6: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 16:44:38.963864 :AAD85BFD: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 16:54:39.902225 :AAD9242D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 16:54:40.328947 :AAD92482:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 16:54:40.324 2025-06-28 16:54:40.328949 :AAD92483:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12152 pso_num=26 pso_serial#=199 2025-06-28 16:54:40.329082 :AAD92484:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12152 osp_idx=24 osp_ver=526519 osp_pg=0 (spawn #331799) 2025-06-28 16:54:40.329083 :AAD92485: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 16:54:40.329083 :AAD92486:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=69 time=4105423516 2025-06-28 16:54:40.329084 :AAD92487:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 16:54:40.329084 :AAD92488:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 16:54:40.329084 :AAD92489:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 16:54:40.329084 :AAD9248A:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 16:54:40.329085 :AAD9248B:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 16:54:40.329580 :AAD9248C: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 16:54:40.329624 :AAD92493: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 17:04:41.282087 :AAD9EF0A:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 17:04:41.521057 :AAD9EF46:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 17:04:41.516 2025-06-28 17:04:41.521060 :AAD9EF47:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10480 pso_num=26 pso_serial#=200 2025-06-28 17:04:41.521191 :AAD9EF48:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10480 osp_idx=24 osp_ver=526520 osp_pg=0 (spawn #331825) 2025-06-28 17:04:41.521192 :AAD9EF49: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 17:04:41.521192 :AAD9EF4A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=70 time=4106024704 2025-06-28 17:04:41.521193 :AAD9EF4B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 17:04:41.521193 :AAD9EF4C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 17:04:41.521193 :AAD9EF4D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 17:04:41.521194 :AAD9EF4E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 17:04:41.521194 :AAD9EF4F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 17:04:41.521682 :AAD9EF50: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 17:04:41.521727 :AAD9EF57: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 17:14:42.354946 :AADAC154:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 17:14:42.734547 :AADAC1AB:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 17:14:42.730 2025-06-28 17:14:42.734549 :AADAC1AC:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9636 pso_num=26 pso_serial#=201 2025-06-28 17:14:42.734685 :AADAC1AD:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9636 osp_idx=24 osp_ver=526521 osp_pg=0 (spawn #331848) 2025-06-28 17:14:42.734685 :AADAC1AE: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 17:14:42.734686 :AADAC1AF:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=71 time=4106625922 2025-06-28 17:14:42.734686 :AADAC1B0:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 17:14:42.734687 :AADAC1B1:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 17:14:42.734688 :AADAC1B2:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 17:14:42.734688 :AADAC1B3:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 17:14:42.734688 :AADAC1B4:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 17:14:42.735268 :AADAC1B5: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 17:14:42.735316 :AADAC1BC: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 17:24:43.632709 :AADB8A5F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 17:24:43.871659 :AADB8A9A:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 17:24:43.867 2025-06-28 17:24:43.871663 :AADB8A9B:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=17756 pso_num=26 pso_serial#=202 2025-06-28 17:24:43.871805 :AADB8A9C:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=17756 osp_idx=24 osp_ver=526522 osp_pg=0 (spawn #331870) 2025-06-28 17:24:43.871806 :AADB8A9D: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 17:24:43.871806 :AADB8A9E:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=72 time=4107227063 2025-06-28 17:24:43.871807 :AADB8A9F:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 17:24:43.871807 :AADB8AA0:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 17:24:43.871807 :AADB8AA1:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 17:24:43.871808 :AADB8AA2:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 17:24:43.871808 :AADB8AA3:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 17:24:43.872287 :AADB8AA4: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 17:24:43.872332 :AADB8AAE: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 17:34:44.647546 :AADC5325:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 17:34:45.074195 :AADC5381:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 17:34:45.069 2025-06-28 17:34:45.074197 :AADC5382:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=2772 pso_num=26 pso_serial#=203 2025-06-28 17:34:45.074340 :AADC5383:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=2772 osp_idx=24 osp_ver=526523 osp_pg=0 (spawn #331893) 2025-06-28 17:34:45.074340 :AADC5384: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 17:34:45.074341 :AADC5385:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=73 time=4107828266 2025-06-28 17:34:45.074342 :AADC5386:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 17:34:45.074342 :AADC5387:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 17:34:45.074342 :AADC5388:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 17:34:45.074343 :AADC5389:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 17:34:45.074343 :AADC538A:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 17:34:45.074849 :AADC538B: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 17:34:45.074895 :AADC5393: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 17:44:45.969423 :AADD1C22:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 17:44:46.286502 :AADD1C77:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 17:44:46.282 2025-06-28 17:44:46.286504 :AADD1C78:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=3280 pso_num=26 pso_serial#=204 2025-06-28 17:44:46.286641 :AADD1C79:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=3280 osp_idx=24 osp_ver=526524 osp_pg=0 (spawn #331916) 2025-06-28 17:44:46.286642 :AADD1C7A: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 17:44:46.286642 :AADD1C7B:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=74 time=4108429469 2025-06-28 17:44:46.286643 :AADD1C7C:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 17:44:46.286643 :AADD1C7D:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 17:44:46.286644 :AADD1C7E:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 17:44:46.286644 :AADD1C7F:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 17:44:46.286644 :AADD1C80:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 17:44:46.287206 :AADD1C81: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 17:44:46.287250 :AADD1C89: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 17:54:47.151754 :AADDE522:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-06-28 17:54:47.422022 :AADDE573:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 06-28 17:54:47.417 2025-06-28 17:54:47.422024 :AADDE574:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9284 pso_num=26 pso_serial#=205 2025-06-28 17:54:47.422166 :AADDE575:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9284 osp_idx=24 osp_ver=526525 osp_pg=0 (spawn #331938) 2025-06-28 17:54:47.422167 :AADDE576: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 17:54:47.422167 :AADDE577:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=75 time=4109030610 2025-06-28 17:54:47.422168 :AADDE578:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-06-28 17:54:47.422168 :AADDE579:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-06-28 17:54:47.422168 :AADDE57A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-06-28 17:54:47.422169 :AADDE57B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-28 17:54:47.422169 :AADDE57C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-28 17:54:47.422665 :AADDE57D: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 17:54:47.422710 :AADDE584: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 18:02:13.825757 :AADE7B93: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 18:04:48.700521 :AADEAFF5: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: 9284, W000)