Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250521220008\orcl_w000_12904_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:37320M/63366M, Ph+PgF:44397M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 12904, image: ORACLE.EXE (W000) *** 2025-05-21 22:00:08.590 *** SESSION ID:(177.55719) 2025-05-21 22:00:08.590 *** 2025-05-21 22:00:08.590 Process diagnostic dump for ORACLE.EXE (W000), OS id=12904, pid: 22, proc_ser: 114, sid: 177, sess_ser: 55719 ------------------------------------------------------------------------------- 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=4.755650 sec, exc=4.755650 sec, total=4.755650 sec wait times: max=5.000000 sec, heur=9 min 20 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.000016 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=111 seq_num=112 snap_id=1 wait times: snap=5.004642 sec, exc=5.004642 sec, total=5.004642 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 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=5.007247 sec, exc=5.007247 sec, total=5.007247 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 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.008672 sec, exc=5.008672 sec, total=5.008672 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 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.004701 sec, exc=5.004701 sec, total=5.004701 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 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.014748 sec, exc=5.014748 sec, total=5.014748 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=106 seq_num=107 snap_id=1 wait times: snap=5.004623 sec, exc=5.004623 sec, total=5.004623 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 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.004625 sec, exc=5.004625 sec, total=5.004625 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 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.014712 sec, exc=5.014712 sec, total=5.014712 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 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.008313 sec, exc=5.008313 sec, total=5.008313 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 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.013687 sec, exc=5.013687 sec, total=5.013687 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time Sampled Session History of session 177 serial 55719 --------------------------------------------------- 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, 21:58:08 - 22:00:08] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-21 22:00:08.590 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 12904, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-21 19:30:28.503225 :9A304F08:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 19:30:28.820410 :9A304F71:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 19:30:28.815 2025-05-21 19:30:28.820412 :9A304F72:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12032 pso_num=22 pso_serial#=101 2025-05-21 19:30:28.820544 :9A304F73:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12032 osp_idx=0 osp_ver=220931 osp_pg=0 (spawn #205496) 2025-05-21 19:30:28.820545 :9A304F74: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-21 19:30:28.820545 :9A304F75:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=19 time=831638688 2025-05-21 19:30:28.820546 :9A304F76:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 19:30:28.820546 :9A304F77:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 19:30:28.820547 :9A304F78:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 19:30:28.820547 :9A304F79:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 19:30:28.820548 :9A304F7A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 19:30:28.821045 :9A304F7B: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-21 19:30:28.821093 :9A304F83: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-21 19:40:29.800737 :9A310F9D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 19:40:30.180447 :9A31101A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 19:40:30.176 2025-05-21 19:40:30.180449 :9A31101B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13020 pso_num=22 pso_serial#=102 2025-05-21 19:40:30.180591 :9A31101C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13020 osp_idx=0 osp_ver=220932 osp_pg=0 (spawn #205517) 2025-05-21 19:40:30.180592 :9A31101D: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-21 19:40:30.180592 :9A31101E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=20 time=832240047 2025-05-21 19:40:30.180593 :9A31101F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 19:40:30.180593 :9A311020:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 19:40:30.180593 :9A311021:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 19:40:30.180594 :9A311022:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 19:40:30.180594 :9A311023:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 19:40:30.181113 :9A311024: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-21 19:40:30.181162 :9A31102C: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-21 19:50:31.185553 :9A31D08B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 19:50:31.472222 :9A31D0F4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 19:50:31.466 2025-05-21 19:50:31.472224 :9A31D0F5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10624 pso_num=22 pso_serial#=103 2025-05-21 19:50:31.472381 :9A31D0F6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10624 osp_idx=0 osp_ver=220933 osp_pg=0 (spawn #205540) 2025-05-21 19:50:31.472382 :9A31D0F7: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-21 19:50:31.472382 :9A31D0F8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=21 time=832841344 2025-05-21 19:50:31.472383 :9A31D0F9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 19:50:31.472383 :9A31D0FA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 19:50:31.472384 :9A31D0FB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 19:50:31.472384 :9A31D0FC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 19:50:31.472384 :9A31D0FD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 19:50:31.472972 :9A31D0FE: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-21 19:50:31.473043 :9A31D108: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-21 20:00:32.489931 :9A329317:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 20:00:32.916485 :9A329386:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 20:00:32.912 2025-05-21 20:00:32.916487 :9A329387:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11216 pso_num=22 pso_serial#=104 2025-05-21 20:00:32.916617 :9A329388:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11216 osp_idx=0 osp_ver=220934 osp_pg=0 (spawn #205564) 2025-05-21 20:00:32.916618 :9A329389: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-21 20:00:32.916619 :9A32938A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=22 time=833442782 2025-05-21 20:00:32.916619 :9A32938B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 20:00:32.916619 :9A32938C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 20:00:32.916620 :9A32938D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 20:00:32.916620 :9A32938E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 20:00:32.916621 :9A32938F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 20:00:32.917109 :9A329390: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-21 20:00:32.917157 :9A32939A: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-21 20:10:33.785315 :9A335BF0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 20:10:34.190761 :9A335C60:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 20:10:34.185 2025-05-21 20:10:34.190763 :9A335C61:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11092 pso_num=22 pso_serial#=105 2025-05-21 20:10:34.190896 :9A335C62:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11092 osp_idx=0 osp_ver=220935 osp_pg=0 (spawn #205588) 2025-05-21 20:10:34.190897 :9A335C63: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-21 20:10:34.190897 :9A335C64:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=23 time=834044063 2025-05-21 20:10:34.190897 :9A335C65:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 20:10:34.190898 :9A335C66:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 20:10:34.190898 :9A335C67:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 20:10:34.190899 :9A335C68:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 20:10:34.190899 :9A335C69:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 20:10:34.191430 :9A335C6A: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-21 20:10:34.191477 :9A335C72: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-21 20:20:35.230108 :9A3420EA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 20:20:35.516098 :9A34215F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 20:20:35.511 2025-05-21 20:20:35.516100 :9A342160:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12976 pso_num=22 pso_serial#=106 2025-05-21 20:20:35.516237 :9A342161:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12976 osp_idx=0 osp_ver=220936 osp_pg=0 (spawn #205611) 2025-05-21 20:20:35.516238 :9A342162: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-21 20:20:35.516239 :9A342163:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=24 time=834645391 2025-05-21 20:20:35.516239 :9A342164:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 20:20:35.516239 :9A342165:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 20:20:35.516239 :9A342166:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 20:20:35.516240 :9A342167:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 20:20:35.516240 :9A342168:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 20:20:35.516735 :9A342169: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-21 20:20:35.516789 :9A342170: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-21 20:30:36.592161 :9A34E395:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 20:30:36.893688 :9A34E40D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 20:30:36.889 2025-05-21 20:30:36.893690 :9A34E40E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13672 pso_num=22 pso_serial#=107 2025-05-21 20:30:36.893826 :9A34E40F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13672 osp_idx=0 osp_ver=220937 osp_pg=0 (spawn #205633) 2025-05-21 20:30:36.893827 :9A34E410: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-21 20:30:36.893827 :9A34E411:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=25 time=835246766 2025-05-21 20:30:36.893827 :9A34E412:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 20:30:36.893828 :9A34E413:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 20:30:36.893828 :9A34E414:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 20:30:36.893828 :9A34E415:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 20:30:36.893829 :9A34E416:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 20:30:36.894320 :9A34E417: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-21 20:30:36.894364 :9A34E420: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-21 20:40:37.832103 :9A35A638:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 20:40:38.290173 :9A35A6A4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 20:40:38.285 2025-05-21 20:40:38.290175 :9A35A6A5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9064 pso_num=22 pso_serial#=108 2025-05-21 20:40:38.290313 :9A35A6A6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9064 osp_idx=0 osp_ver=220938 osp_pg=0 (spawn #205656) 2025-05-21 20:40:38.290313 :9A35A6A7: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-21 20:40:38.290314 :9A35A6A8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=26 time=835848157 2025-05-21 20:40:38.290314 :9A35A6A9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 20:40:38.290314 :9A35A6AA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 20:40:38.290315 :9A35A6AB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 20:40:38.290315 :9A35A6AC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 20:40:38.290315 :9A35A6AD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 20:40:38.290825 :9A35A6AE: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-21 20:40:38.290870 :9A35A6B6: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-21 20:50:39.306368 :9A36687F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 20:50:39.560979 :9A3668ED:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 20:50:39.556 2025-05-21 20:50:39.560982 :9A3668EE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11368 pso_num=22 pso_serial#=109 2025-05-21 20:50:39.561116 :9A3668EF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11368 osp_idx=0 osp_ver=220939 osp_pg=0 (spawn #205679) 2025-05-21 20:50:39.561117 :9A3668F0: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-21 20:50:39.561117 :9A3668F1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=27 time=836449438 2025-05-21 20:50:39.561117 :9A3668F2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 20:50:39.561118 :9A3668F3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 20:50:39.561118 :9A3668F4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 20:50:39.561118 :9A3668F5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 20:50:39.561118 :9A3668F6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 20:50:39.561608 :9A3668F7: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-21 20:50:39.561653 :9A366900: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-21 20:51:25.213528 :9A3677B9: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-21 21:00:40.918209 :9A372B9D: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-21 21:01:10.983600 :9A37361C:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=129 seq_num=130 snap_id=1 2025-05-21 21:01:10.983634 :9A373629:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=129 seq_num=130 snap_id=1 2025-05-21 21:01:10.983637 :9A37362A:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=32, exc=32, tot=32 2025-05-21 21:10:41.930418 :9A37F7EA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 21:10:42.263056 :9A37F88F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 21:10:42.259 2025-05-21 21:10:42.263058 :9A37F890:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13148 pso_num=22 pso_serial#=110 2025-05-21 21:10:42.263192 :9A37F891:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13148 osp_idx=0 osp_ver=220940 osp_pg=0 (spawn #205726) 2025-05-21 21:10:42.263193 :9A37F892: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-21 21:10:42.263193 :9A37F893:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=28 time=837652141 2025-05-21 21:10:42.263194 :9A37F894:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 21:10:42.263194 :9A37F895:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 21:10:42.263194 :9A37F896:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 21:10:42.263195 :9A37F897:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 21:10:42.263195 :9A37F898:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 21:10:42.263689 :9A37F899: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-21 21:10:42.263731 :9A37F8A1: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-21 21:20:43.247455 :9A38B97C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 21:20:43.580380 :9A38BA19:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 21:20:43.575 2025-05-21 21:20:43.580382 :9A38BA1A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13656 pso_num=22 pso_serial#=111 2025-05-21 21:20:43.580523 :9A38BA1B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13656 osp_idx=0 osp_ver=220941 osp_pg=0 (spawn #205749) 2025-05-21 21:20:43.580523 :9A38BA1C: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-21 21:20:43.580524 :9A38BA1D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=29 time=838253454 2025-05-21 21:20:43.580524 :9A38BA1E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 21:20:43.580525 :9A38BA1F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 21:20:43.580525 :9A38BA20:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 21:20:43.580525 :9A38BA21:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 21:20:43.580526 :9A38BA22:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 21:20:43.581034 :9A38BA23: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-21 21:20:43.581082 :9A38BA2B: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-21 21:30:44.598968 :9A397B73:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 21:30:45.009823 :9A397BDB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 21:30:45.005 2025-05-21 21:30:45.009824 :9A397BDC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12832 pso_num=22 pso_serial#=112 2025-05-21 21:30:45.009954 :9A397BDD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12832 osp_idx=0 osp_ver=220942 osp_pg=0 (spawn #205771) 2025-05-21 21:30:45.009955 :9A397BDE: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-21 21:30:45.009955 :9A397BDF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=30 time=838854875 2025-05-21 21:30:45.009956 :9A397BE0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 21:30:45.009956 :9A397BE1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 21:30:45.009956 :9A397BE2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 21:30:45.009957 :9A397BE3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 21:30:45.009957 :9A397BE4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 21:30:45.010448 :9A397BE5: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-21 21:30:45.010494 :9A397BEF: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-21 21:40:45.883551 :9A3A3CFF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 21:40:46.383534 :9A3A3D94:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 21:40:46.378 2025-05-21 21:40:46.383536 :9A3A3D95:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11688 pso_num=22 pso_serial#=113 2025-05-21 21:40:46.383687 :9A3A3D96:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11688 osp_idx=0 osp_ver=220943 osp_pg=0 (spawn #205794) 2025-05-21 21:40:46.383688 :9A3A3D97: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-21 21:40:46.383688 :9A3A3D98:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=31 time=839456250 2025-05-21 21:40:46.383688 :9A3A3D99:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 21:40:46.383689 :9A3A3D9A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 21:40:46.383689 :9A3A3D9B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 21:40:46.383690 :9A3A3D9C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 21:40:46.383690 :9A3A3D9D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 21:40:46.384235 :9A3A3D9E: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-21 21:40:46.384281 :9A3A3DA5: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-21 21:50:47.346071 :9A3AFEDC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-21 21:50:47.928871 :9A3AFF5A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-21 21:50:47.924 2025-05-21 21:50:47.928873 :9A3AFF5B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12904 pso_num=22 pso_serial#=114 2025-05-21 21:50:47.929017 :9A3AFF5C:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12904 osp_idx=0 osp_ver=220944 osp_pg=0 (spawn #205817) 2025-05-21 21:50:47.929018 :9A3AFF5D: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-21 21:50:47.929018 :9A3AFF5E:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=32 time=840057797 2025-05-21 21:50:47.929019 :9A3AFF5F:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-21 21:50:47.929019 :9A3AFF60:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-21 21:50:47.929020 :9A3AFF61:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-21 21:50:47.929020 :9A3AFF62:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-21 21:50:47.929020 :9A3AFF63:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-21 21:50:47.929522 :9A3AFF64: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-21 21:50:47.929571 :9A3AFF6C: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 12904, W000)