Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250622180943\orcl_w000_16740_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:36377M/63366M, Ph+PgF:42664M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 16740, image: ORACLE.EXE (W000) *** 2025-06-22 18:09:44.068 *** SESSION ID:(201.41017) 2025-06-22 18:09:44.068 *** 2025-06-22 18:09:44.068 Process diagnostic dump for ORACLE.EXE (W000), OS id=16740, pid: 25, proc_ser: 83, sid: 201, sess_ser: 41017 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=4.133073 sec, exc=4.133073 sec, total=4.133073 sec wait times: max=5.000000 sec, heur=2 min 49 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.000021 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=5.010155 sec, exc=5.010155 sec, total=5.010155 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=5.009492 sec, exc=5.009492 sec, total=5.009492 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=5.001237 sec, exc=5.001237 sec, total=5.001237 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.008276 sec, exc=5.008276 sec, total=5.008276 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=5.004334 sec, exc=5.004334 sec, total=5.004334 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=28 seq_num=29 snap_id=1 wait times: snap=5.009221 sec, exc=5.009221 sec, total=5.009221 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=27 seq_num=28 snap_id=1 wait times: snap=5.010130 sec, exc=5.010130 sec, total=5.010130 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.007400 sec, exc=5.007400 sec, total=5.007400 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.003227 sec, exc=5.003227 sec, total=5.003227 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=5.000417 sec, exc=5.000417 sec, total=5.000417 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 201 serial 41017 --------------------------------------------------- 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:07:44 - 18:09:44] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-22 18:09:44.068 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 16740, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-22 15:56:37.722992 :A82ABE83:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 15:56:37.856068 :A82ABEBE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 15:56:37.851 2025-06-22 15:56:37.856070 :A82ABEBF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17192 pso_num=25 pso_serial#=69 2025-06-22 15:56:37.856205 :A82ABEC0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17192 osp_idx=23 osp_ver=165931 osp_pg=0 (spawn #311665) 2025-06-22 15:56:37.856205 :A82ABEC1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 15:56:37.856206 :A82ABEC2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=97 time=3583541047 2025-06-22 15:56:37.856206 :A82ABEC3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 15:56:37.856207 :A82ABEC4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 15:56:37.856207 :A82ABEC5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 15:56:37.856208 :A82ABEC6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 15:56:37.856208 :A82ABEC7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 15:56:37.856756 :A82ABEC8: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-06-22 15:56:37.856802 :A82ABECF: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-06-22 16:06:38.617596 :A82B918A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 16:06:39.216063 :A82B91D1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 16:06:39.211 2025-06-22 16:06:39.216065 :A82B91D2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15480 pso_num=25 pso_serial#=70 2025-06-22 16:06:39.216204 :A82B91D3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15480 osp_idx=23 osp_ver=165932 osp_pg=0 (spawn #311691) 2025-06-22 16:06:39.216205 :A82B91D4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 16:06:39.216205 :A82B91D5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=98 time=3584142407 2025-06-22 16:06:39.216206 :A82B91D6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 16:06:39.216206 :A82B91D7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 16:06:39.216207 :A82B91D8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 16:06:39.216207 :A82B91D9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 16:06:39.216207 :A82B91DA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 16:06:39.216691 :A82B91DB: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-06-22 16:06:39.216734 :A82B91E2: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-06-22 16:16:40.030120 :A82C5A47:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 16:16:40.585951 :A82C5A81:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 16:16:40.581 2025-06-22 16:16:40.585953 :A82C5A82:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14356 pso_num=25 pso_serial#=71 2025-06-22 16:16:40.586095 :A82C5A83:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14356 osp_idx=23 osp_ver=165933 osp_pg=0 (spawn #311714) 2025-06-22 16:16:40.586096 :A82C5A84:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 16:16:40.586096 :A82C5A85:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=99 time=3584743782 2025-06-22 16:16:40.586097 :A82C5A86:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 16:16:40.586097 :A82C5A87:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 16:16:40.586097 :A82C5A88:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 16:16:40.586098 :A82C5A89:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 16:16:40.586098 :A82C5A8A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 16:16:40.586611 :A82C5A8B: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-06-22 16:16:40.586658 :A82C5A92: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-06-22 16:26:41.475689 :A82D260B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 16:26:41.933578 :A82D265F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 16:26:41.928 2025-06-22 16:26:41.933580 :A82D2660:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12372 pso_num=25 pso_serial#=72 2025-06-22 16:26:41.933723 :A82D2661:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12372 osp_idx=23 osp_ver=165934 osp_pg=0 (spawn #311737) 2025-06-22 16:26:41.933725 :A82D2662:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 16:26:41.933726 :A82D2663:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=100 time=3585345125 2025-06-22 16:26:41.933726 :A82D2664:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 16:26:41.933726 :A82D2665:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 16:26:41.933727 :A82D2666:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 16:26:41.933727 :A82D2667:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 16:26:41.933727 :A82D2668:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 16:26:41.934250 :A82D2669: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-06-22 16:26:41.934296 :A82D2671: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-06-22 16:36:42.777713 :A82DEEE9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 16:36:43.197142 :A82DEEED:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 16:36:43.184 2025-06-22 16:36:43.197143 :A82DEEEE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16336 pso_num=25 pso_serial#=73 2025-06-22 16:36:43.197282 :A82DEEEF:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=16336 (legacy spawn) 2025-06-22 16:36:43.204180 :A82DEEF0: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-06-22 16:36:43.204371 :A82DEEF9: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-06-22 16:36:43.205269 :A82DEEFA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 16:36:43.214249 :A82DEEFD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 16:36:43.199 2025-06-22 16:36:43.214251 :A82DEEFE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15520 pso_num=25 pso_serial#=74 2025-06-22 16:36:43.214418 :A82DEEFF:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15520 (legacy spawn) 2025-06-22 16:36:43.221131 :A82DEF00: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-06-22 16:36:43.221302 :A82DEF09: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-06-22 16:36:43.222163 :A82DEF0A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 16:36:43.360314 :A82DEF44:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 16:36:43.356 2025-06-22 16:36:43.360317 :A82DEF45:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13904 pso_num=25 pso_serial#=75 2025-06-22 16:36:43.360457 :A82DEF46:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13904 osp_idx=23 osp_ver=165937 osp_pg=0 (spawn #311759) 2025-06-22 16:36:43.360458 :A82DEF47:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 16:36:43.360458 :A82DEF48:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=101 time=3585946547 2025-06-22 16:36:43.360459 :A82DEF49:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 16:36:43.360459 :A82DEF4A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 16:36:43.360460 :A82DEF4B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 16:36:43.360460 :A82DEF4C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 16:36:43.360460 :A82DEF4D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 16:36:43.360949 :A82DEF4E: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-06-22 16:36:43.360995 :A82DEF56: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-06-22 16:46:44.254690 :A82EB777:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 16:46:44.728207 :A82EB7B4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 16:46:44.723 2025-06-22 16:46:44.728210 :A82EB7B5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17584 pso_num=25 pso_serial#=76 2025-06-22 16:46:44.728345 :A82EB7B6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17584 osp_idx=23 osp_ver=165938 osp_pg=0 (spawn #311782) 2025-06-22 16:46:44.728346 :A82EB7B7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 16:46:44.728346 :A82EB7B8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=102 time=3586547922 2025-06-22 16:46:44.728346 :A82EB7B9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 16:46:44.728347 :A82EB7BA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 16:46:44.728347 :A82EB7BB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 16:46:44.728348 :A82EB7BC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 16:46:44.728348 :A82EB7BD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 16:46:44.728840 :A82EB7BE: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-06-22 16:46:44.728889 :A82EB7C8: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-06-22 16:56:45.490372 :A82F7FA2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 16:56:45.995083 :A82F7FE6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 16:56:45.990 2025-06-22 16:56:45.995086 :A82F7FE7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13628 pso_num=25 pso_serial#=77 2025-06-22 16:56:45.995233 :A82F7FE8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13628 osp_idx=23 osp_ver=165939 osp_pg=0 (spawn #311805) 2025-06-22 16:56:45.995234 :A82F7FE9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 16:56:45.995234 :A82F7FEA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=103 time=3587149188 2025-06-22 16:56:45.995234 :A82F7FEB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 16:56:45.995235 :A82F7FEC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 16:56:45.995235 :A82F7FED:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 16:56:45.995236 :A82F7FEE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 16:56:45.995236 :A82F7FEF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 16:56:45.995731 :A82F7FF0: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-06-22 16:56:45.995774 :A82F7FF8: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-06-22 17:06:46.920070 :A8304FFB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 17:06:47.260572 :A8305037:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 17:06:47.255 2025-06-22 17:06:47.260575 :A8305038:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4696 pso_num=25 pso_serial#=78 2025-06-22 17:06:47.260727 :A8305039:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4696 osp_idx=23 osp_ver=165940 osp_pg=0 (spawn #311830) 2025-06-22 17:06:47.260727 :A830503A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 17:06:47.260728 :A830503B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=104 time=3587750454 2025-06-22 17:06:47.260728 :A830503C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 17:06:47.260729 :A830503D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 17:06:47.260729 :A830503E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 17:06:47.260729 :A830503F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 17:06:47.260730 :A8305040:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 17:06:47.261229 :A8305041: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-06-22 17:06:47.261280 :A8305047: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-06-22 17:13:42.966598 :A830D938: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-06-22 17:16:48.540515 :A831191E: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-06-22 17:18:03.681113 :A8313188:db_trace:ksl2.c@2477:kslwtbctx(): [10005:25:201] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=139 seq_num=140 snap_id=1 2025-06-22 17:18:03.681139 :A8313192:db_trace:ksl2.c@2611:kslwtectx(): [10005:25:201] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=139 seq_num=140 snap_id=1 2025-06-22 17:18:03.681141 :A8313193:db_trace:ksl2.c@2619:kslwtectx(): [10005:25:201] KSL WAIT END wait times (usecs) - snap=26, exc=26, tot=26 2025-06-22 17:26:49.451389 :A831DE50:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 17:26:49.752910 :A831DE89:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 17:26:49.748 2025-06-22 17:26:49.752912 :A831DE8A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14456 pso_num=25 pso_serial#=79 2025-06-22 17:26:49.753053 :A831DE8B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14456 osp_idx=23 osp_ver=165941 osp_pg=0 (spawn #311875) 2025-06-22 17:26:49.753054 :A831DE8C:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 17:26:49.753055 :A831DE8D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=105 time=3588952938 2025-06-22 17:26:49.753055 :A831DE8E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 17:26:49.753056 :A831DE8F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 17:26:49.753056 :A831DE90:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 17:26:49.753057 :A831DE91:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 17:26:49.753057 :A831DE92:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 17:26:49.753551 :A831DE93: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-06-22 17:26:49.753594 :A831DE9A: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-06-22 17:36:50.592717 :A832A4B6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 17:36:51.029281 :A832A4F9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 17:36:51.024 2025-06-22 17:36:51.029283 :A832A4FA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13936 pso_num=25 pso_serial#=80 2025-06-22 17:36:51.029415 :A832A4FB:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13936 osp_idx=23 osp_ver=165942 osp_pg=0 (spawn #311897) 2025-06-22 17:36:51.029416 :A832A4FC:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 17:36:51.029416 :A832A4FD:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=106 time=3589554219 2025-06-22 17:36:51.029417 :A832A4FE:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 17:36:51.029417 :A832A4FF:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 17:36:51.029417 :A832A500:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 17:36:51.029417 :A832A501:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 17:36:51.029418 :A832A502:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 17:36:51.029905 :A832A503: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-06-22 17:36:51.029950 :A832A50A: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-06-22 17:46:51.970841 :A8336A47:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 17:46:52.225633 :A8336A7F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 17:46:52.220 2025-06-22 17:46:52.225635 :A8336A80:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17816 pso_num=25 pso_serial#=81 2025-06-22 17:46:52.225769 :A8336A81:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17816 osp_idx=23 osp_ver=165943 osp_pg=0 (spawn #311920) 2025-06-22 17:46:52.225769 :A8336A82:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 17:46:52.225770 :A8336A83:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=107 time=3590155422 2025-06-22 17:46:52.225770 :A8336A84:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 17:46:52.225770 :A8336A85:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 17:46:52.225771 :A8336A86:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 17:46:52.225772 :A8336A87:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 17:46:52.225772 :A8336A88:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 17:46:52.226285 :A8336A89: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-06-22 17:46:52.226338 :A8336A90: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-06-22 17:56:53.201877 :A83430C3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 17:56:53.456560 :A8343128:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 17:56:53.451 2025-06-22 17:56:53.456562 :A8343129:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18096 pso_num=25 pso_serial#=82 2025-06-22 17:56:53.456699 :A834312A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18096 osp_idx=23 osp_ver=165944 osp_pg=0 (spawn #311943) 2025-06-22 17:56:53.456700 :A834312B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 17:56:53.456700 :A834312C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=108 time=3590756641 2025-06-22 17:56:53.456700 :A834312D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 17:56:53.456701 :A834312E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 17:56:53.456701 :A834312F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 17:56:53.456701 :A8343130:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 17:56:53.456702 :A8343131:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 17:56:53.457208 :A8343132: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-06-22 17:56:53.457255 :A834313A: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-06-22 18:06:54.435221 :A835029E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 18:06:54.680400 :A83502DA:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 18:06:54.680 2025-06-22 18:06:54.680402 :A83502DB:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16740 pso_num=25 pso_serial#=83 2025-06-22 18:06:54.680539 :A83502DC:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16740 osp_idx=23 osp_ver=165945 osp_pg=0 (spawn #311968) 2025-06-22 18:06:54.680540 :A83502DD:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 18:06:54.680541 :A83502DE:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=109 time=3591357875 2025-06-22 18:06:54.680541 :A83502DF:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 18:06:54.680541 :A83502E0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 18:06:54.680542 :A83502E1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 18:06:54.680542 :A83502E2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 18:06:54.680542 :A83502E3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 18:06:54.681051 :A83502E4: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-06-22 18:06:54.681098 :A83502EB: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: 16740, W000)