Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250613220008\orcl_w000_12356_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:36709M/63366M, Ph+PgF:43199M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 12356, image: ORACLE.EXE (W000) *** 2025-06-13 22:00:08.254 *** SESSION ID:(177.1301) 2025-06-13 22:00:08.254 *** 2025-06-13 22:00:08.254 Process diagnostic dump for ORACLE.EXE (W000), OS id=12356, pid: 22, proc_ser: 154, sid: 177, sess_ser: 1301 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=111 seq_num=112 snap_id=1 wait times: snap=3.892962 sec, exc=3.892962 sec, total=3.892962 sec wait times: max=5.000000 sec, heur=9 min 14 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=110 seq_num=111 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.000025 sec of elapsed time 1: 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.014728 sec, exc=5.014728 sec, total=5.014728 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 2: 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.008335 sec, exc=5.008335 sec, total=5.008335 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=107 seq_num=108 snap_id=1 wait times: snap=5.000339 sec, exc=5.000339 sec, total=5.000339 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 4: 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.000017 sec, exc=5.000017 sec, total=5.000017 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 5: 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.001417 sec, exc=5.001417 sec, total=5.001417 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=104 seq_num=105 snap_id=1 wait times: snap=5.004712 sec, exc=5.004712 sec, total=5.004712 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=103 seq_num=104 snap_id=1 wait times: snap=5.014742 sec, exc=5.014742 sec, total=5.014742 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 8: 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.007246 sec, exc=5.007246 sec, total=5.007246 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=101 seq_num=102 snap_id=1 wait times: snap=5.001288 sec, exc=5.001288 sec, total=5.001288 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 177 serial 1301 --------------------------------------------------- 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-06-13 22:00:08.254 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 12356, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-13 19:59:45.598320 :A442A6E3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14664 pso_num=22 pso_serial#=139 2025-06-13 19:59:45.598457 :A442A6E4:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14664 (legacy spawn) 2025-06-13 19:59:45.604965 :A442A6E5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 19:59:45.604994 :A442A6E8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 19:59:45.605151 :A442A6EF:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 19:59:45.605984 :A442A6FC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 19:59:48.188991 :A442A7A2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 19:59:48.181 2025-06-13 19:59:48.188993 :A442A7A3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10388 pso_num=22 pso_serial#=140 2025-06-13 19:59:48.189128 :A442A7A4:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10388 (legacy spawn) 2025-06-13 19:59:48.195534 :A442A7A5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 19:59:48.195715 :A442A7AA:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 19:59:48.196521 :A442A7AF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 19:59:48.205185 :A442A7B2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 19:59:48.197 2025-06-13 19:59:48.205187 :A442A7B3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13028 pso_num=22 pso_serial#=141 2025-06-13 19:59:48.205320 :A442A7B4:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13028 (legacy spawn) 2025-06-13 19:59:48.211737 :A442A7B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 19:59:48.211902 :A442A7BE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 19:59:48.212754 :A442A7BF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 19:59:55.113191 :A442A9D6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 19:59:55.107 2025-06-13 19:59:55.113193 :A442A9D7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14320 pso_num=22 pso_serial#=142 2025-06-13 19:59:55.113328 :A442A9D8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14320 osp_idx=0 osp_ver=302899 osp_pg=0 (spawn #282192) 2025-06-13 19:59:55.113329 :A442A9D9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 19:59:55.113329 :A442A9DA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=204 time=2820538297 2025-06-13 19:59:55.113330 :A442A9DB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 19:59:55.113330 :A442A9DC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 19:59:55.113330 :A442A9DD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 19:59:55.113330 :A442A9DE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 19:59:55.113330 :A442A9DF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 19:59:55.113807 :A442A9E0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-13 19:59:55.114446 :A442A9F5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 19:59:55.121932 :A442AA12:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-06-13 19:59:55.122307 :A442AA13:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 19:59:55.122345 :A442AA16:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-06-13 19:59:55.123266 :A442AA1C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 19:59:55.123395 :A442AA25:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 20:00:25.181263 :A442B4F1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 20:00:33.150156 :A442B751:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 20:00:33.142 2025-06-13 20:00:33.150158 :A442B752:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15036 pso_num=22 pso_serial#=143 2025-06-13 20:00:33.150290 :A442B753:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15036 (legacy spawn) 2025-06-13 20:00:33.156730 :A442B754:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-13 20:00:33.156904 :A442B759:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-06-13 20:00:33.157721 :A442B75E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 20:00:40.428061 :A442B9C9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 20:00:40.422 2025-06-13 20:00:40.428063 :A442B9CA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15952 pso_num=22 pso_serial#=144 2025-06-13 20:00:40.428209 :A442B9CB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15952 osp_idx=0 osp_ver=302901 osp_pg=0 (spawn #282196) 2025-06-13 20:00:40.428210 :A442B9CC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 20:00:40.428210 :A442B9CD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=205 time=2820583625 2025-06-13 20:00:40.428211 :A442B9CE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 20:00:40.428211 :A442B9CF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 20:00:40.428211 :A442B9D0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 20:00:40.428212 :A442B9D1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 20:00:40.428212 :A442B9D2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 20:00:40.428737 :A442B9D3: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-06-13 20:00:40.428786 :A442B9DA: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-06-13 20:10:41.281154 :A44385D4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 20:10:41.660940 :A4438610:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 20:10:41.656 2025-06-13 20:10:41.660942 :A4438611:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12736 pso_num=22 pso_serial#=145 2025-06-13 20:10:41.661119 :A4438612:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12736 osp_idx=0 osp_ver=302902 osp_pg=0 (spawn #282219) 2025-06-13 20:10:41.661120 :A4438613:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 20:10:41.661121 :A4438614:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=206 time=2821184844 2025-06-13 20:10:41.661121 :A4438615:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 20:10:41.661122 :A4438616:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 20:10:41.661122 :A4438617:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 20:10:41.661122 :A4438618:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 20:10:41.661123 :A4438619:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 20:10:41.661658 :A443861A: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-06-13 20:10:41.661703 :A4438622: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-06-13 20:20:42.454729 :A444483F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 20:20:42.881322 :A444489F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 20:20:42.876 2025-06-13 20:20:42.881324 :A44448A0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16012 pso_num=22 pso_serial#=146 2025-06-13 20:20:42.881458 :A44448A1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16012 osp_idx=0 osp_ver=302903 osp_pg=0 (spawn #282242) 2025-06-13 20:20:42.881458 :A44448A2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 20:20:42.881459 :A44448A3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=207 time=2821786079 2025-06-13 20:20:42.881459 :A44448A4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 20:20:42.881460 :A44448A5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 20:20:42.881460 :A44448A6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 20:20:42.881460 :A44448A7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 20:20:42.881460 :A44448A8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 20:20:42.881937 :A44448A9: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-06-13 20:20:42.881985 :A44448B2: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-06-13 20:30:43.610231 :A4450C1C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 20:30:44.109549 :A4450C9B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 20:30:44.104 2025-06-13 20:30:44.109551 :A4450C9C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16512 pso_num=22 pso_serial#=147 2025-06-13 20:30:44.109693 :A4450C9D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16512 osp_idx=0 osp_ver=302904 osp_pg=0 (spawn #282265) 2025-06-13 20:30:44.109694 :A4450C9E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 20:30:44.109694 :A4450C9F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=208 time=2822387297 2025-06-13 20:30:44.109694 :A4450CA0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 20:30:44.109695 :A4450CA1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 20:30:44.109695 :A4450CA2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 20:30:44.109696 :A4450CA3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 20:30:44.109696 :A4450CA4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 20:30:44.110195 :A4450CA5: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-06-13 20:30:44.110244 :A4450CAC: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-06-13 20:40:44.875603 :A445CEC6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 20:40:45.380419 :A445CF1E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 20:40:45.375 2025-06-13 20:40:45.380421 :A445CF1F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15736 pso_num=22 pso_serial#=148 2025-06-13 20:40:45.380553 :A445CF20:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15736 osp_idx=0 osp_ver=302905 osp_pg=0 (spawn #282287) 2025-06-13 20:40:45.380553 :A445CF21:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 20:40:45.380554 :A445CF22:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=209 time=2822988563 2025-06-13 20:40:45.380554 :A445CF23:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 20:40:45.380554 :A445CF24:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 20:40:45.380554 :A445CF25:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 20:40:45.380555 :A445CF26:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 20:40:45.380555 :A445CF27:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 20:40:45.381035 :A445CF28: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-06-13 20:40:45.381085 :A445CF30: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-06-13 20:41:00.050666 :A445D3FC: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-06-13 20:50:46.636261 :A446921E: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-06-13 21:00:47.398506 :A4475668:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 21:00:47.809229 :A44756B7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 21:00:47.805 2025-06-13 21:00:47.809231 :A44756B8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15768 pso_num=22 pso_serial#=149 2025-06-13 21:00:47.809365 :A44756B9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15768 osp_idx=0 osp_ver=302906 osp_pg=0 (spawn #282334) 2025-06-13 21:00:47.809365 :A44756BA:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:00:47.809366 :A44756BB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=210 time=2824191000 2025-06-13 21:00:47.809366 :A44756BC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:00:47.809367 :A44756BD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:00:47.809367 :A44756BE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:00:47.809368 :A44756BF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:00:47.809368 :A44756C0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:00:47.809856 :A44756C1: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-06-13 21:00:47.809901 :A44756C8: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-06-13 21:10:48.617091 :A4481F29:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 21:10:49.012495 :A4481F62:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 21:10:49.007 2025-06-13 21:10:49.012497 :A4481F63:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11536 pso_num=22 pso_serial#=150 2025-06-13 21:10:49.012636 :A4481F64:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11536 osp_idx=0 osp_ver=302907 osp_pg=0 (spawn #282357) 2025-06-13 21:10:49.012637 :A4481F65:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:10:49.012637 :A4481F66:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=211 time=2824792204 2025-06-13 21:10:49.012637 :A4481F67:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:10:49.012638 :A4481F68:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:10:49.012638 :A4481F69:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:10:49.012638 :A4481F6A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:10:49.012639 :A4481F6B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:10:49.013128 :A4481F6C: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-06-13 21:10:49.013170 :A4481F74: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-06-13 21:20:49.884820 :A448E40D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 21:20:50.233101 :A448E449:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 21:20:50.228 2025-06-13 21:20:50.233103 :A448E44A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17380 pso_num=22 pso_serial#=151 2025-06-13 21:20:50.233249 :A448E44B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17380 osp_idx=0 osp_ver=302908 osp_pg=0 (spawn #282380) 2025-06-13 21:20:50.233249 :A448E44C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:20:50.233250 :A448E44D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=212 time=2825393422 2025-06-13 21:20:50.233250 :A448E44E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:20:50.233251 :A448E44F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:20:50.233251 :A448E450:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:20:50.233252 :A448E451:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:20:50.233252 :A448E452:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:20:50.233755 :A448E453: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-06-13 21:20:50.233802 :A448E45B: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-06-13 21:30:50.973809 :A449A6E8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 21:30:51.369161 :A449A730:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 21:30:51.364 2025-06-13 21:30:51.369163 :A449A731:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16880 pso_num=22 pso_serial#=152 2025-06-13 21:30:51.369298 :A449A732:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16880 osp_idx=0 osp_ver=302909 osp_pg=0 (spawn #282403) 2025-06-13 21:30:51.369298 :A449A733:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:30:51.369299 :A449A734:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=213 time=2825994563 2025-06-13 21:30:51.369299 :A449A735:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:30:51.369299 :A449A736:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:30:51.369300 :A449A737:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:30:51.369300 :A449A738:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:30:51.369300 :A449A739:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:30:51.369832 :A449A73A: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-06-13 21:30:51.369878 :A449A743: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-06-13 21:40:52.122937 :A44A69C0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 21:40:52.408875 :A44A69F9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 21:40:52.403 2025-06-13 21:40:52.408877 :A44A69FA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16660 pso_num=22 pso_serial#=153 2025-06-13 21:40:52.409013 :A44A69FB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=16660 osp_idx=0 osp_ver=302910 osp_pg=0 (spawn #282425) 2025-06-13 21:40:52.409014 :A44A69FC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:40:52.409014 :A44A69FD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=214 time=2826595594 2025-06-13 21:40:52.409015 :A44A69FE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:40:52.409015 :A44A69FF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:40:52.409015 :A44A6A00:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:40:52.409016 :A44A6A01:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:40:52.409016 :A44A6A02:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:40:52.409511 :A44A6A03: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-06-13 21:40:52.409557 :A44A6A0D: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-06-13 21:50:53.306458 :A44B2C2A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-06-13 21:50:53.561211 :A44B2C6E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 06-13 21:50:53.557 2025-06-13 21:50:53.561213 :A44B2C6F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12356 pso_num=22 pso_serial#=154 2025-06-13 21:50:53.561351 :A44B2C70:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12356 osp_idx=0 osp_ver=302911 osp_pg=0 (spawn #282448) 2025-06-13 21:50:53.561352 :A44B2C71:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-13 21:50:53.561353 :A44B2C72:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=215 time=2827196750 2025-06-13 21:50:53.561353 :A44B2C73:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-06-13 21:50:53.561354 :A44B2C74:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-06-13 21:50:53.561354 :A44B2C75:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-06-13 21:50:53.561354 :A44B2C76:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-13 21:50:53.561355 :A44B2C77:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-13 21:50:53.561853 :A44B2C78: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-06-13 21:50:53.561900 :A44B2C82: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: 12356, W000)