Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250505082112\orcl_w000_10872_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:37546M/63366M, Ph+PgF:45010M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 10872, image: ORACLE.EXE (W000) *** 2025-05-05 08:21:12.822 *** SESSION ID:(201.36745) 2025-05-05 08:21:12.822 *** 2025-05-05 08:21:12.822 Process diagnostic dump for ORACLE.EXE (W000), OS id=10872, pid: 25, proc_ser: 184, sid: 201, sess_ser: 36745 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=44 seq_num=45 snap_id=1 wait times: snap=2.920111 sec, exc=2.920111 sec, total=2.920111 sec wait times: max=5.000000 sec, heur=3 min 38 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.000020 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=43 seq_num=44 snap_id=1 wait times: snap=5.001128 sec, exc=5.001128 sec, total=5.001128 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=42 seq_num=43 snap_id=1 wait times: snap=5.010559 sec, exc=5.010559 sec, total=5.010559 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=41 seq_num=42 snap_id=1 wait times: snap=5.006631 sec, exc=5.006631 sec, total=5.006631 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=40 seq_num=41 snap_id=1 wait times: snap=5.004663 sec, exc=5.004663 sec, total=5.004663 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=39 seq_num=40 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.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=38 seq_num=39 snap_id=1 wait times: snap=5.011842 sec, exc=5.011842 sec, total=5.011842 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=37 seq_num=38 snap_id=1 wait times: snap=5.001134 sec, exc=5.001134 sec, total=5.001134 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=36 seq_num=37 snap_id=1 wait times: snap=5.000451 sec, exc=5.000451 sec, total=5.000451 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=35 seq_num=36 snap_id=1 wait times: snap=5.009567 sec, exc=5.009567 sec, total=5.009567 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=5.010959 sec, exc=5.010959 sec, total=5.010959 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 36745 --------------------------------------------------- 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, 08:19:12 - 08:21:12] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-05 08:21:12.822 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 10872, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-05 05:57:16.354108 :92E4991E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 05:57:16.354109 :92E4991F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 05:57:16.354611 :92E49920: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-05-05 05:57:16.354663 :92E49928: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-05-05 06:07:17.282415 :92E56A3D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 06:07:17.958938 :92E56AA6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 06:07:17.954 2025-05-05 06:07:17.958940 :92E56AA7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11388 pso_num=25 pso_serial#=170 2025-05-05 06:07:17.959081 :92E56AA8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11388 osp_idx=23 osp_ver=75394 osp_pg=0 (spawn #149888) 2025-05-05 06:07:17.959081 :92E56AA9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 06:07:17.959082 :92E56AAA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=249 time=3696015125 2025-05-05 06:07:17.959082 :92E56AAB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 06:07:17.959083 :92E56AAC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 06:07:17.959083 :92E56AAD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 06:07:17.959083 :92E56AAE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 06:07:17.959084 :92E56AAF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 06:07:17.959581 :92E56AB0: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-05-05 06:07:17.959627 :92E56AB8: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-05-05 06:17:18.814588 :92E63029:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 06:17:19.321352 :92E63097:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 06:17:19.316 2025-05-05 06:17:19.321354 :92E63098:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10888 pso_num=25 pso_serial#=171 2025-05-05 06:17:19.321491 :92E63099:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10888 osp_idx=23 osp_ver=75395 osp_pg=0 (spawn #149910) 2025-05-05 06:17:19.321492 :92E6309A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 06:17:19.321492 :92E6309B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=250 time=3696616484 2025-05-05 06:17:19.321493 :92E6309C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 06:17:19.321493 :92E6309D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 06:17:19.321493 :92E6309E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 06:17:19.321494 :92E6309F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 06:17:19.321494 :92E630A0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 06:17:19.321991 :92E630A1: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-05-05 06:17:19.322035 :92E630A8: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-05-05 06:27:20.171582 :92E6F751:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 06:27:20.660521 :92E6F789:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 06:27:20.655 2025-05-05 06:27:20.660523 :92E6F78A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11752 pso_num=25 pso_serial#=172 2025-05-05 06:27:20.660658 :92E6F78B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11752 osp_idx=23 osp_ver=75396 osp_pg=0 (spawn #149933) 2025-05-05 06:27:20.660659 :92E6F78C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 06:27:20.660659 :92E6F78D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=251 time=3697217828 2025-05-05 06:27:20.660660 :92E6F78E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 06:27:20.660660 :92E6F78F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 06:27:20.660661 :92E6F790:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 06:27:20.660661 :92E6F791:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 06:27:20.660661 :92E6F792:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 06:27:20.661143 :92E6F793: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-05-05 06:27:20.661186 :92E6F79B: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-05-05 06:37:21.563483 :92E7BF5F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 06:37:21.896259 :92E7BFB2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 06:37:21.892 2025-05-05 06:37:21.896261 :92E7BFB3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11524 pso_num=25 pso_serial#=173 2025-05-05 06:37:21.896396 :92E7BFB4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11524 osp_idx=23 osp_ver=75397 osp_pg=0 (spawn #149956) 2025-05-05 06:37:21.896397 :92E7BFB5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 06:37:21.896397 :92E7BFB6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=252 time=3697819062 2025-05-05 06:37:21.896398 :92E7BFB7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 06:37:21.896398 :92E7BFB8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 06:37:21.896398 :92E7BFB9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 06:37:21.896399 :92E7BFBA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 06:37:21.896399 :92E7BFBB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 06:37:21.896915 :92E7BFBC: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-05-05 06:37:21.896960 :92E7BFC4: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-05-05 06:47:22.766645 :92E886D5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 06:47:23.029619 :92E886D8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 06:47:23.016 2025-05-05 06:47:23.029620 :92E886D9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9308 pso_num=25 pso_serial#=174 2025-05-05 06:47:23.029761 :92E886DA:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=9308 (legacy spawn) 2025-05-05 06:47:23.049535 :92E886DB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 06:47:23.049713 :92E886E0:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-05-05 06:47:23.050637 :92E886E5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 06:47:23.059781 :92E886E8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 06:47:23.047 2025-05-05 06:47:23.059783 :92E886E9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12084 pso_num=25 pso_serial#=175 2025-05-05 06:47:23.059958 :92E886EA:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=12084 (legacy spawn) 2025-05-05 06:47:23.066637 :92E886EB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 06:47:23.066807 :92E886F4:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-05-05 06:47:23.067654 :92E886F5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 06:47:23.240142 :92E88732:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 06:47:23.235 2025-05-05 06:47:23.240145 :92E88733:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12228 pso_num=25 pso_serial#=176 2025-05-05 06:47:23.240285 :92E88734:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12228 osp_idx=23 osp_ver=75400 osp_pg=0 (spawn #149978) 2025-05-05 06:47:23.240285 :92E88735:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 06:47:23.240286 :92E88736:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=253 time=3698420406 2025-05-05 06:47:23.240286 :92E88737:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 06:47:23.240286 :92E88738:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 06:47:23.240287 :92E88739:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 06:47:23.240287 :92E8873A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 06:47:23.240288 :92E8873B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 06:47:23.240788 :92E8873C: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-05-05 06:47:23.240833 :92E88743: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-05-05 06:57:24.139193 :92E94E2D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 06:57:24.503310 :92E94E6E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 06:57:24.498 2025-05-05 06:57:24.503312 :92E94E6F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10500 pso_num=25 pso_serial#=177 2025-05-05 06:57:24.503457 :92E94E70:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10500 osp_idx=23 osp_ver=75401 osp_pg=0 (spawn #150001) 2025-05-05 06:57:24.503458 :92E94E71:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 06:57:24.503458 :92E94E72:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=254 time=3699021671 2025-05-05 06:57:24.503459 :92E94E73:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 06:57:24.503459 :92E94E74:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 06:57:24.503460 :92E94E75:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 06:57:24.503460 :92E94E76:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 06:57:24.503460 :92E94E77:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 06:57:24.503975 :92E94E78: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-05-05 06:57:24.504033 :92E94E7F: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-05-05 07:07:25.455903 :92EA1EC2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 07:07:25.804256 :92EA1EFF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 07:07:25.799 2025-05-05 07:07:25.804258 :92EA1F00:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9028 pso_num=25 pso_serial#=178 2025-05-05 07:07:25.804401 :92EA1F01:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9028 osp_idx=23 osp_ver=75402 osp_pg=0 (spawn #150029) 2025-05-05 07:07:25.804402 :92EA1F02:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 07:07:25.804402 :92EA1F03:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=255 time=3699622968 2025-05-05 07:07:25.804403 :92EA1F04:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 07:07:25.804404 :92EA1F05:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 07:07:25.804404 :92EA1F06:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 07:07:25.804405 :92EA1F07:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 07:07:25.804405 :92EA1F08:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 07:07:25.804903 :92EA1F09: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-05-05 07:07:25.804952 :92EA1F0F: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-05-05 07:15:57.458819 :92EACB09: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-05-05 07:17:27.055887 :92EAE8FB: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-05-05 07:27:27.986521 :92EBAFE6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 07:27:28.235510 :92EBB01E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 07:27:28.231 2025-05-05 07:27:28.235512 :92EBB01F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9600 pso_num=25 pso_serial#=179 2025-05-05 07:27:28.235644 :92EBB020:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9600 osp_idx=23 osp_ver=75403 osp_pg=0 (spawn #150073) 2025-05-05 07:27:28.235644 :92EBB021:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 07:27:28.235645 :92EBB022:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=0 time=3700825406 2025-05-05 07:27:28.235645 :92EBB023:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 07:27:28.235646 :92EBB024:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 07:27:28.235646 :92EBB025:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 07:27:28.235646 :92EBB026:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 07:27:28.235647 :92EBB027:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 07:27:28.236205 :92EBB028: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-05-05 07:27:28.236252 :92EBB030: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-05-05 07:37:29.149925 :92EC78A6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 07:37:29.545168 :92EC78E2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 07:37:29.541 2025-05-05 07:37:29.545170 :92EC78E3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9116 pso_num=25 pso_serial#=180 2025-05-05 07:37:29.545311 :92EC78E4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9116 osp_idx=23 osp_ver=75404 osp_pg=0 (spawn #150096) 2025-05-05 07:37:29.545312 :92EC78E5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 07:37:29.545312 :92EC78E6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=1 time=3701426718 2025-05-05 07:37:29.545313 :92EC78E7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 07:37:29.545313 :92EC78E8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 07:37:29.545314 :92EC78E9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 07:37:29.545314 :92EC78EA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 07:37:29.545314 :92EC78EB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 07:37:29.545802 :92EC78EC: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-05-05 07:37:29.545848 :92EC78F4: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-05-05 07:47:30.513507 :92ED3FF5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 07:47:30.736756 :92ED403C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 07:47:30.732 2025-05-05 07:47:30.736758 :92ED403D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8048 pso_num=25 pso_serial#=181 2025-05-05 07:47:30.736893 :92ED403E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8048 osp_idx=23 osp_ver=75405 osp_pg=0 (spawn #150118) 2025-05-05 07:47:30.736894 :92ED403F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 07:47:30.736894 :92ED4040:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=2 time=3702027906 2025-05-05 07:47:30.736895 :92ED4041:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 07:47:30.736895 :92ED4042:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 07:47:30.736895 :92ED4043:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 07:47:30.736896 :92ED4044:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 07:47:30.736896 :92ED4045:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 07:47:30.737392 :92ED4046: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-05-05 07:47:30.737435 :92ED404E: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-05-05 07:57:31.607085 :92EE07B7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 07:57:32.033677 :92EE07EE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 07:57:32.029 2025-05-05 07:57:32.033678 :92EE07EF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10368 pso_num=25 pso_serial#=182 2025-05-05 07:57:32.033820 :92EE07F0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10368 osp_idx=23 osp_ver=75406 osp_pg=0 (spawn #150141) 2025-05-05 07:57:32.033820 :92EE07F1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 07:57:32.033821 :92EE07F2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=3 time=3702629203 2025-05-05 07:57:32.033821 :92EE07F3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 07:57:32.033822 :92EE07F4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 07:57:32.033822 :92EE07F5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 07:57:32.033823 :92EE07F6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 07:57:32.033823 :92EE07F7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 07:57:32.034330 :92EE07F8: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-05-05 07:57:32.034377 :92EE0801: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-05-05 08:07:32.943874 :92EED765:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 08:07:33.307806 :92EED7AC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 08:07:33.303 2025-05-05 08:07:33.307808 :92EED7AD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4572 pso_num=25 pso_serial#=183 2025-05-05 08:07:33.307938 :92EED7AE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4572 osp_idx=23 osp_ver=75407 osp_pg=0 (spawn #150169) 2025-05-05 08:07:33.307939 :92EED7AF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 08:07:33.307939 :92EED7B0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=4 time=3703230468 2025-05-05 08:07:33.307939 :92EED7B1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 08:07:33.307940 :92EED7B2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 08:07:33.307940 :92EED7B3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 08:07:33.307940 :92EED7B4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 08:07:33.307940 :92EED7B5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 08:07:33.308467 :92EED7B6: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-05-05 08:07:33.308516 :92EED7BE: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-05-05 08:17:34.192341 :92EFA1A4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-05 08:17:34.618899 :92EFA1DB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-05 08:17:34.614 2025-05-05 08:17:34.618901 :92EFA1DC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10872 pso_num=25 pso_serial#=184 2025-05-05 08:17:34.619041 :92EFA1DD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10872 osp_idx=23 osp_ver=75408 osp_pg=0 (spawn #150191) 2025-05-05 08:17:34.619041 :92EFA1DE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 08:17:34.619041 :92EFA1DF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=5 time=3703831781 2025-05-05 08:17:34.619042 :92EFA1E0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 08:17:34.619042 :92EFA1E1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 08:17:34.619042 :92EFA1E2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 08:17:34.619043 :92EFA1E3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 08:17:34.619043 :92EFA1E4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 08:17:34.619552 :92EFA1E5: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-05-05 08:17:34.619602 :92EFA1EC: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: 10872, W000)