Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250518220156\orcl_w000_12056_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:37368M/63366M, Ph+PgF:44540M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 12056, image: ORACLE.EXE (W000) *** 2025-05-18 22:01:56.849 *** SESSION ID:(209.51493) 2025-05-18 22:01:56.849 *** 2025-05-18 22:01:56.849 Process diagnostic dump for ORACLE.EXE (W000), OS id=12056, pid: 26, proc_ser: 71, sid: 209, sess_ser: 51493 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.308122 sec, exc=0.308122 sec, total=0.308122 sec wait times: max=5.000000 sec, heur=55.387371 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.000026 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=5.004641 sec, exc=5.004641 sec, total=5.004641 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000018 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=5.010191 sec, exc=5.010191 sec, total=5.010191 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=9 seq_num=10 snap_id=1 wait times: snap=5.004185 sec, exc=5.004185 sec, total=5.004185 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=8 seq_num=9 snap_id=1 wait times: snap=5.003211 sec, exc=5.003211 sec, total=5.003211 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=5.013293 sec, exc=5.013293 sec, total=5.013293 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=5.005020 sec, exc=5.005020 sec, total=5.005020 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=5.014723 sec, exc=5.014723 sec, total=5.014723 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=4 seq_num=5 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.000019 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=5.014735 sec, exc=5.014735 sec, total=5.014735 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=5.007224 sec, exc=5.007224 sec, total=5.007224 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 209 serial 51493 --------------------------------------------------- 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 --------------------------------------------------- [56 samples, 22:01:01 - 22:01:56] idle wait at each sample [session created at: 22:01:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-18 22:01:56.849 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 12056, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-18 19:30:41.590125 :98DD64A6:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12824 pso_num=26 pso_serial#=58 2025-05-18 19:30:41.590259 :98DD64A7:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12824 osp_idx=24 osp_ver=286677 osp_pg=0 (spawn #195498) 2025-05-18 19:30:41.590260 :98DD64A8:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 19:30:41.590260 :98DD64A9:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=149 time=572451454 2025-05-18 19:30:41.590260 :98DD64AA:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 19:30:41.590261 :98DD64AB:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 19:30:41.590261 :98DD64AC:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 19:30:41.590262 :98DD64AD:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 19:30:41.590262 :98DD64AE:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 19:30:41.590753 :98DD64AF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 19:30:41.590797 :98DD64B6:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 19:37:19.622380 :98DDE9B1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 19:40:42.903001 :98DE2D4B:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 19:50:43.816701 :98DEF580:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 19:50:44.297209 :98DEF5C9:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 19:50:44.292 2025-05-18 19:50:44.297211 :98DEF5CA:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12628 pso_num=26 pso_serial#=59 2025-05-18 19:50:44.297349 :98DEF5CB:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12628 osp_idx=24 osp_ver=286678 osp_pg=0 (spawn #195543) 2025-05-18 19:50:44.297349 :98DEF5CC:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 19:50:44.297349 :98DEF5CD:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=150 time=573654172 2025-05-18 19:50:44.297350 :98DEF5CE:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 19:50:44.297350 :98DEF5CF:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 19:50:44.297350 :98DEF5D0:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 19:50:44.297351 :98DEF5D1:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 19:50:44.297351 :98DEF5D2:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 19:50:44.297847 :98DEF5D3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 19:50:44.297892 :98DEF5DA:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 20:00:45.305464 :98DFBFE0:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 20:00:45.638210 :98DFC021:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 20:00:45.634 2025-05-18 20:00:45.638212 :98DFC022:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=9724 pso_num=26 pso_serial#=60 2025-05-18 20:00:45.638345 :98DFC023:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=9724 osp_idx=24 osp_ver=286679 osp_pg=0 (spawn #195568) 2025-05-18 20:00:45.638346 :98DFC024:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 20:00:45.638347 :98DFC025:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=151 time=574255516 2025-05-18 20:00:45.638347 :98DFC026:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 20:00:45.638347 :98DFC027:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 20:00:45.638347 :98DFC028:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 20:00:45.638348 :98DFC029:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 20:00:45.638348 :98DFC02A:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 20:00:45.638843 :98DFC02B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 20:00:45.638888 :98DFC032:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 20:10:46.625557 :98E091AB:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 20:10:46.927079 :98E091F1:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 20:10:46.922 2025-05-18 20:10:46.927081 :98E091F2:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14188 pso_num=26 pso_serial#=61 2025-05-18 20:10:46.927224 :98E091F3:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14188 osp_idx=24 osp_ver=286680 osp_pg=0 (spawn #195592) 2025-05-18 20:10:46.927225 :98E091F4:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 20:10:46.927225 :98E091F5:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=152 time=574856797 2025-05-18 20:10:46.927226 :98E091F6:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 20:10:46.927226 :98E091F7:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 20:10:46.927226 :98E091F8:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 20:10:46.927227 :98E091F9:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 20:10:46.927227 :98E091FA:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 20:10:46.927719 :98E091FB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 20:10:46.927762 :98E09203:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 20:20:47.821201 :98E1597F:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 20:20:48.185348 :98E159BB:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 20:20:48.181 2025-05-18 20:20:48.185350 :98E159BC:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13704 pso_num=26 pso_serial#=62 2025-05-18 20:20:48.185489 :98E159BD:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13704 osp_idx=24 osp_ver=286681 osp_pg=0 (spawn #195614) 2025-05-18 20:20:48.185490 :98E159BE:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 20:20:48.185491 :98E159BF:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=153 time=575458063 2025-05-18 20:20:48.185491 :98E159C0:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 20:20:48.185492 :98E159C1:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 20:20:48.185492 :98E159C2:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 20:20:48.185492 :98E159C3:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 20:20:48.185493 :98E159C4:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 20:20:48.185998 :98E159C5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 20:20:48.186044 :98E159CD:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 20:30:49.052681 :98E2222B:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 20:30:49.463662 :98E22272:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 20:30:49.459 2025-05-18 20:30:49.463665 :98E22273:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=2752 pso_num=26 pso_serial#=63 2025-05-18 20:30:49.463799 :98E22274:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=2752 osp_idx=24 osp_ver=286682 osp_pg=0 (spawn #195637) 2025-05-18 20:30:49.463800 :98E22275:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 20:30:49.463800 :98E22276:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=154 time=576059329 2025-05-18 20:30:49.463800 :98E22277:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 20:30:49.463801 :98E22278:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 20:30:49.463801 :98E22279:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 20:30:49.463801 :98E2227A:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 20:30:49.463802 :98E2227B:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 20:30:49.464303 :98E2227C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 20:30:49.464346 :98E22284:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 20:40:50.427164 :98E2E9AA:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 20:40:50.822508 :98E2E9E3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 20:40:50.818 2025-05-18 20:40:50.822510 :98E2E9E4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13588 pso_num=26 pso_serial#=64 2025-05-18 20:40:50.822642 :98E2E9E5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13588 osp_idx=24 osp_ver=286683 osp_pg=0 (spawn #195660) 2025-05-18 20:40:50.822642 :98E2E9E6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 20:40:50.822643 :98E2E9E7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=155 time=576660688 2025-05-18 20:40:50.822643 :98E2E9E8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 20:40:50.822644 :98E2E9E9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 20:40:50.822644 :98E2E9EA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 20:40:50.822645 :98E2E9EB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 20:40:50.822645 :98E2E9EC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 20:40:50.823178 :98E2E9ED:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 20:40:50.823222 :98E2E9F4:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 20:50:51.803236 :98E3B141:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 20:50:52.177493 :98E3B188:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 20:50:52.172 2025-05-18 20:50:52.177495 :98E3B189:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10896 pso_num=26 pso_serial#=65 2025-05-18 20:50:52.177638 :98E3B18A:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10896 osp_idx=24 osp_ver=286684 osp_pg=0 (spawn #195682) 2025-05-18 20:50:52.177639 :98E3B18B:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 20:50:52.177640 :98E3B18C:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=156 time=577262047 2025-05-18 20:50:52.177641 :98E3B18D:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 20:50:52.177641 :98E3B18E:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 20:50:52.177643 :98E3B18F:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 20:50:52.177643 :98E3B190:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 20:50:52.177644 :98E3B191:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 20:50:52.178141 :98E3B192:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 20:50:52.178185 :98E3B19A:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 21:00:53.116461 :98E47A4E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 21:00:53.527389 :98E47A8A:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 21:00:53.522 2025-05-18 21:00:53.527391 :98E47A8B:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12412 pso_num=26 pso_serial#=66 2025-05-18 21:00:53.527542 :98E47A8C:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12412 osp_idx=24 osp_ver=286685 osp_pg=0 (spawn #195707) 2025-05-18 21:00:53.527542 :98E47A8D:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 21:00:53.527543 :98E47A8E:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=157 time=577863391 2025-05-18 21:00:53.527544 :98E47A8F:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 21:00:53.527545 :98E47A90:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 21:00:53.527545 :98E47A91:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 21:00:53.527545 :98E47A92:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 21:00:53.527546 :98E47A93:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 21:00:53.528088 :98E47A94:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 21:00:53.528133 :98E47A9C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 21:10:54.471541 :98E54BA8:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 21:10:54.741810 :98E54C1A:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 21:10:54.737 2025-05-18 21:10:54.741812 :98E54C1B:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14260 pso_num=26 pso_serial#=67 2025-05-18 21:10:54.741949 :98E54C1C:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14260 osp_idx=24 osp_ver=286686 osp_pg=0 (spawn #195731) 2025-05-18 21:10:54.741949 :98E54C1D:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 21:10:54.741950 :98E54C1E:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=158 time=578464610 2025-05-18 21:10:54.741950 :98E54C1F:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 21:10:54.741950 :98E54C20:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 21:10:54.741951 :98E54C21:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 21:10:54.741951 :98E54C22:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 21:10:54.741951 :98E54C23:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 21:10:54.742444 :98E54C24:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 21:10:54.742491 :98E54C2C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 21:20:55.803187 :98E612B0:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 21:20:56.026625 :98E612EC:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 21:20:56.022 2025-05-18 21:20:56.026627 :98E612ED:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=11784 pso_num=26 pso_serial#=68 2025-05-18 21:20:56.026766 :98E612EE:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=11784 osp_idx=24 osp_ver=286687 osp_pg=0 (spawn #195753) 2025-05-18 21:20:56.026766 :98E612EF:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 21:20:56.026767 :98E612F0:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=159 time=579065891 2025-05-18 21:20:56.026767 :98E612F1:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 21:20:56.026767 :98E612F2:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 21:20:56.026768 :98E612F3:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 21:20:56.026768 :98E612F4:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 21:20:56.026769 :98E612F5:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 21:20:56.027275 :98E612F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 21:20:56.027337 :98E612FD:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 21:30:57.093548 :98E6DCAF:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 21:30:57.379472 :98E6DCF3:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 21:30:57.375 2025-05-18 21:30:57.379475 :98E6DCF4:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13308 pso_num=26 pso_serial#=69 2025-05-18 21:30:57.379604 :98E6DCF5:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13308 osp_idx=24 osp_ver=286688 osp_pg=0 (spawn #195776) 2025-05-18 21:30:57.379605 :98E6DCF6:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 21:30:57.379605 :98E6DCF7:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=160 time=579667250 2025-05-18 21:30:57.379606 :98E6DCF8:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 21:30:57.379606 :98E6DCF9:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 21:30:57.379606 :98E6DCFA:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 21:30:57.379607 :98E6DCFB:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 21:30:57.379607 :98E6DCFC:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 21:30:57.380085 :98E6DCFD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 21:30:57.380133 :98E6DD07:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 21:40:58.363954 :98E7A44A:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 21:40:58.759196 :98E7A486:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 21:40:58.754 2025-05-18 21:40:58.759199 :98E7A487:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10896 pso_num=26 pso_serial#=70 2025-05-18 21:40:58.759337 :98E7A488:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10896 osp_idx=24 osp_ver=286689 osp_pg=0 (spawn #195799) 2025-05-18 21:40:58.759337 :98E7A489:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 21:40:58.759338 :98E7A48A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=161 time=580268625 2025-05-18 21:40:58.759338 :98E7A48B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 21:40:58.759339 :98E7A48C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 21:40:58.759339 :98E7A48D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 21:40:58.759339 :98E7A48E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 21:40:58.759340 :98E7A48F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 21:40:58.759826 :98E7A490:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 21:40:58.759872 :98E7A498:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 21:42:20.267873 :98E7BF54:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 21:51:00.157601 :98E86CD9:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 21:51:00.157651 :98E86CDB:db_trace:ksl2.c@2477:kslwtbctx(): [10005:26:209] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-05-18 21:51:00.157754 :98E86CE0:db_trace:ksl2.c@2611:kslwtectx(): [10005:26:209] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=123 seq_num=124 snap_id=1 2025-05-18 21:51:00.157755 :98E86CE1:db_trace:ksl2.c@2619:kslwtectx(): [10005:26:209] KSL WAIT END wait times (usecs) - snap=102, exc=102, tot=102 2025-05-18 22:01:01.042147 :98E93755:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-18 22:01:01.468584 :98E93790:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-18 22:01:01.463 2025-05-18 22:01:01.468586 :98E93791:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12056 pso_num=26 pso_serial#=71 2025-05-18 22:01:01.468724 :98E93792:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12056 osp_idx=24 osp_ver=286690 osp_pg=0 (spawn #195845) 2025-05-18 22:01:01.468725 :98E93793:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 22:01:01.468725 :98E93794:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=162 time=581471344 2025-05-18 22:01:01.468726 :98E93795:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 22:01:01.468726 :98E93796:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 22:01:01.468726 :98E93797:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 22:01:01.468727 :98E93798:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 22:01:01.468727 :98E93799:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 22:01:01.469235 :98E9379A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 22:01:01.469289 :98E937A0:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 26 (osid: 12056, W000)