Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250502221904\orcl_w000_6084_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:37589M/63366M, Ph+PgF:45133M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 6084, image: ORACLE.EXE (W000) *** 2025-05-02 22:19:04.421 *** SESSION ID:(177.20515) 2025-05-02 22:19:04.421 *** 2025-05-02 22:19:04.421 Process diagnostic dump for ORACLE.EXE (W000), OS id=6084, pid: 22, proc_ser: 191, sid: 177, sess_ser: 20515 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=112 seq_num=113 snap_id=1 wait times: snap=1.409609 sec, exc=1.409609 sec, total=1.409609 sec wait times: max=5.000000 sec, heur=1.409609 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.001940 sec since current wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x1, filetype=0x2 wait_id=111 seq_num=112 snap_id=1 wait times: snap=0.000107 sec, exc=0.000107 sec, total=0.000107 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000175 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=110 seq_num=111 snap_id=1 wait times: snap=0.047777 sec, exc=0.047777 sec, total=0.047777 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=109 seq_num=110 snap_id=1 wait times: snap=5.004632 sec, exc=5.004632 sec, total=5.004632 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=108 seq_num=109 snap_id=1 wait times: snap=5.004759 sec, exc=5.004759 sec, total=5.004759 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=107 seq_num=108 snap_id=1 wait times: snap=5.009216 sec, exc=5.009216 sec, total=5.009216 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=106 seq_num=107 snap_id=1 wait times: snap=5.010153 sec, exc=5.010153 sec, total=5.010153 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=105 seq_num=106 snap_id=1 wait times: snap=5.015252 sec, exc=5.015252 sec, total=5.015252 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=104 seq_num=105 snap_id=1 wait times: snap=5.003226 sec, exc=5.003226 sec, total=5.003226 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=103 seq_num=104 snap_id=1 wait times: snap=5.011185 sec, exc=5.011185 sec, total=5.011185 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=102 seq_num=103 snap_id=1 wait times: snap=5.005605 sec, exc=5.005605 sec, total=5.005605 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time Sampled Session History of session 177 serial 20515 --------------------------------------------------- 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, 22:17:04 - 22:19:04] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-02 22:19:04.421 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 6084, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-02 19:49:38.592229 :91CDFB71:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 19:49:38.592280 :91CDFB7B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 19:59:39.567709 :91CEC279:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 19:59:39.832578 :91CEC2B4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 19:59:39.827 2025-05-02 19:59:39.832580 :91CEC2B5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9028 pso_num=22 pso_serial#=177 2025-05-02 19:59:39.832720 :91CEC2B6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9028 osp_idx=0 osp_ver=149862 osp_pg=0 (spawn #141641) 2025-05-02 19:59:39.832720 :91CEC2B7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 19:59:39.832721 :91CEC2B8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=50 time=3486769312 2025-05-02 19:59:39.832721 :91CEC2B9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 19:59:39.832721 :91CEC2BA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 19:59:39.832722 :91CEC2BB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 19:59:39.832722 :91CEC2BC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 19:59:39.832722 :91CEC2BD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 19:59:39.833224 :91CEC2BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 19:59:39.833270 :91CEC2C6:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 20:09:40.677824 :91CF94D8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 20:09:41.088765 :91CF9525:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 20:09:41.084 2025-05-02 20:09:41.088767 :91CF9526:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11348 pso_num=22 pso_serial#=178 2025-05-02 20:09:41.088905 :91CF9527:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11348 osp_idx=0 osp_ver=149863 osp_pg=0 (spawn #141666) 2025-05-02 20:09:41.088905 :91CF9528:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 20:09:41.088906 :91CF9529:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=51 time=3487370578 2025-05-02 20:09:41.088906 :91CF952A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 20:09:41.088906 :91CF952B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 20:09:41.088907 :91CF952C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 20:09:41.088907 :91CF952D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 20:09:41.088908 :91CF952E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 20:09:41.089404 :91CF952F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 20:09:41.089455 :91CF9539:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 20:18:43.570136 :91D0487E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 20:19:42.395190 :91D05D0F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 20:29:43.355747 :91D12472:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 20:29:43.704072 :91D124EC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 20:29:43.699 2025-05-02 20:29:43.704074 :91D124ED:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8760 pso_num=22 pso_serial#=179 2025-05-02 20:29:43.704216 :91D124EE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8760 osp_idx=0 osp_ver=149864 osp_pg=0 (spawn #141713) 2025-05-02 20:29:43.704217 :91D124EF:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 20:29:43.704218 :91D124F0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=52 time=3488573187 2025-05-02 20:29:43.704218 :91D124F1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 20:29:43.704218 :91D124F2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 20:29:43.704219 :91D124F3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 20:29:43.704219 :91D124F4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 20:29:43.704219 :91D124F5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 20:29:43.704719 :91D124F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 20:29:43.704768 :91D124FE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 20:39:44.695716 :91D1EC97:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 20:39:44.997266 :91D1ED1B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 20:39:44.992 2025-05-02 20:39:44.997268 :91D1ED1C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8224 pso_num=22 pso_serial#=180 2025-05-02 20:39:44.997407 :91D1ED1D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8224 osp_idx=0 osp_ver=149865 osp_pg=0 (spawn #141735) 2025-05-02 20:39:44.997408 :91D1ED1E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 20:39:44.997408 :91D1ED1F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=53 time=3489174484 2025-05-02 20:39:44.997409 :91D1ED20:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 20:39:44.997409 :91D1ED21:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 20:39:44.997409 :91D1ED22:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 20:39:44.997410 :91D1ED23:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 20:39:44.997410 :91D1ED24:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 20:39:44.997895 :91D1ED25:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 20:39:44.997944 :91D1ED2C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 20:49:45.937214 :91D2B372:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 20:49:46.332501 :91D2B3B1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 20:49:46.328 2025-05-02 20:49:46.332503 :91D2B3B2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11172 pso_num=22 pso_serial#=181 2025-05-02 20:49:46.332633 :91D2B3B3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11172 osp_idx=0 osp_ver=149866 osp_pg=0 (spawn #141758) 2025-05-02 20:49:46.332634 :91D2B3B4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 20:49:46.332635 :91D2B3B5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=54 time=3489775812 2025-05-02 20:49:46.332635 :91D2B3B6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 20:49:46.332636 :91D2B3B7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 20:49:46.332636 :91D2B3B8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 20:49:46.332636 :91D2B3B9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 20:49:46.332637 :91D2B3BA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 20:49:46.333196 :91D2B3BB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 20:49:46.333240 :91D2B3C1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 20:59:47.272870 :91D37AF1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 20:59:47.652413 :91D37B2B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 20:59:47.648 2025-05-02 20:59:47.652414 :91D37B2C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11284 pso_num=22 pso_serial#=182 2025-05-02 20:59:47.652545 :91D37B2D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11284 osp_idx=0 osp_ver=149867 osp_pg=0 (spawn #141781) 2025-05-02 20:59:47.652546 :91D37B2E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 20:59:47.652547 :91D37B2F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=55 time=3490377140 2025-05-02 20:59:47.652547 :91D37B30:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 20:59:47.652547 :91D37B31:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 20:59:47.652548 :91D37B32:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 20:59:47.652548 :91D37B33:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 20:59:47.652548 :91D37B34:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 20:59:47.653039 :91D37B35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 20:59:47.653083 :91D37B3D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 21:09:48.415389 :91D44A1F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 21:09:48.888670 :91D44A58:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 21:09:48.884 2025-05-02 21:09:48.888672 :91D44A59:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11396 pso_num=22 pso_serial#=183 2025-05-02 21:09:48.888806 :91D44A5A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11396 osp_idx=0 osp_ver=149868 osp_pg=0 (spawn #141806) 2025-05-02 21:09:48.888807 :91D44A5B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 21:09:48.888807 :91D44A5C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=56 time=3490978375 2025-05-02 21:09:48.888808 :91D44A5D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:09:48.888808 :91D44A5E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:09:48.888808 :91D44A5F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:09:48.888808 :91D44A60:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:09:48.888809 :91D44A61:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:09:48.889346 :91D44A62:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 21:09:48.889394 :91D44A6C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 21:19:49.686695 :91D51586:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 21:19:50.201480 :91D515CA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 21:19:50.196 2025-05-02 21:19:50.201481 :91D515CB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11624 pso_num=22 pso_serial#=184 2025-05-02 21:19:50.201617 :91D515CC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11624 osp_idx=0 osp_ver=149869 osp_pg=0 (spawn #141831) 2025-05-02 21:19:50.201618 :91D515CD:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 21:19:50.201618 :91D515CE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=57 time=3491579687 2025-05-02 21:19:50.201619 :91D515CF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:19:50.201619 :91D515D0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:19:50.201619 :91D515D1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:19:50.201620 :91D515D2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:19:50.201620 :91D515D3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:19:50.202089 :91D515D4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 21:19:50.202132 :91D515DC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 21:29:51.051158 :91D5DCA5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 21:29:51.477646 :91D5DCE0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 21:29:51.472 2025-05-02 21:29:51.477648 :91D5DCE1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10224 pso_num=22 pso_serial#=185 2025-05-02 21:29:51.477782 :91D5DCE2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10224 osp_idx=0 osp_ver=149870 osp_pg=0 (spawn #141854) 2025-05-02 21:29:51.477783 :91D5DCE3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 21:29:51.477783 :91D5DCE4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=58 time=3492180953 2025-05-02 21:29:51.477783 :91D5DCE5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:29:51.477784 :91D5DCE6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:29:51.477784 :91D5DCE7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:29:51.477785 :91D5DCE8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:29:51.477785 :91D5DCE9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:29:51.478284 :91D5DCEA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 21:29:51.478328 :91D5DCF2:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 21:39:52.421439 :91D6A40F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 21:39:52.935759 :91D6A457:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 21:39:52.931 2025-05-02 21:39:52.935761 :91D6A458:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10940 pso_num=22 pso_serial#=186 2025-05-02 21:39:52.935896 :91D6A459:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10940 osp_idx=0 osp_ver=149871 osp_pg=0 (spawn #141876) 2025-05-02 21:39:52.935896 :91D6A45A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 21:39:52.935897 :91D6A45B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=59 time=3492782421 2025-05-02 21:39:52.935897 :91D6A45C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:39:52.935898 :91D6A45D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:39:52.935898 :91D6A45E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:39:52.935898 :91D6A45F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:39:52.935899 :91D6A460:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:39:52.936384 :91D6A461:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 21:39:52.936426 :91D6A469:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 21:49:53.796719 :91D76AFF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 21:49:54.379606 :91D76B3A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 21:49:54.375 2025-05-02 21:49:54.379608 :91D76B3B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11960 pso_num=22 pso_serial#=187 2025-05-02 21:49:54.379747 :91D76B3C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11960 osp_idx=0 osp_ver=149872 osp_pg=0 (spawn #141899) 2025-05-02 21:49:54.379747 :91D76B3D:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 21:49:54.379748 :91D76B3E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=60 time=3493383859 2025-05-02 21:49:54.379748 :91D76B3F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:49:54.379749 :91D76B40:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:49:54.379749 :91D76B41:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:49:54.379749 :91D76B42:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:49:54.379750 :91D76B43:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:49:54.380261 :91D76B44:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 21:49:54.380305 :91D76B4C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 21:59:55.229437 :91D83239:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 21:59:55.749722 :91D83280:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 21:59:55.745 2025-05-02 21:59:55.749724 :91D83281:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11956 pso_num=22 pso_serial#=188 2025-05-02 21:59:55.749857 :91D83282:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11956 osp_idx=0 osp_ver=149873 osp_pg=0 (spawn #141922) 2025-05-02 21:59:55.749858 :91D83283:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 21:59:55.749858 :91D83284:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=61 time=3493985234 2025-05-02 21:59:55.749859 :91D83285:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 21:59:55.749859 :91D83286:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 21:59:55.749860 :91D83287:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 21:59:55.749860 :91D83288:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 21:59:55.749860 :91D83289:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 21:59:55.750355 :91D8328A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 21:59:55.750402 :91D83292:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 22:09:56.685739 :91D913A1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 22:09:56.933134 :91D913A4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 22:09:56.919 2025-05-02 22:09:56.933136 :91D913A5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9992 pso_num=22 pso_serial#=189 2025-05-02 22:09:56.933273 :91D913A6:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9992 (legacy spawn) 2025-05-02 22:09:56.939757 :91D913A7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:09:56.939922 :91D913AC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 22:09:56.940770 :91D913B1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 22:09:56.949316 :91D913B4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 22:09:56.935 2025-05-02 22:09:56.949318 :91D913B5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11396 pso_num=22 pso_serial#=190 2025-05-02 22:09:56.949455 :91D913B6:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11396 (legacy spawn) 2025-05-02 22:09:56.955945 :91D913B7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-02 22:09:56.956110 :91D913C0:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 22:09:56.956921 :91D913C1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-02 22:09:57.190137 :91D9140C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-02 22:09:57.185 2025-05-02 22:09:57.190139 :91D9140D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6084 pso_num=22 pso_serial#=191 2025-05-02 22:09:57.190272 :91D9140E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6084 osp_idx=0 osp_ver=149876 osp_pg=0 (spawn #141957) 2025-05-02 22:09:57.190273 :91D9140F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-02 22:09:57.190273 :91D91410:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=62 time=3494586671 2025-05-02 22:09:57.190274 :91D91411:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-02 22:09:57.190274 :91D91412:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-02 22:09:57.190274 :91D91413:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-02 22:09:57.190275 :91D91414:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-02 22:09:57.190275 :91D91415:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-02 22:09:57.190754 :91D91416:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-02 22:09:57.190797 :91D9141C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-02 22:19:03.017076 :91D9D74B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 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 22 (osid: 6084, W000)