Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250720100524\orcl_w000_18456_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:36173M/63366M, Ph+PgF:42097M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 18456, image: ORACLE.EXE (W000) *** 2025-07-20 10:05:24.939 *** SESSION ID:(177.26301) 2025-07-20 10:05:24.939 *** 2025-07-20 10:05:24.939 Process diagnostic dump for ORACLE.EXE (W000), OS id=18456, pid: 22, proc_ser: 56, sid: 177, sess_ser: 26301 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=35 seq_num=36 snap_id=1 wait times: snap=2.971125 sec, exc=2.971125 sec, total=2.971125 sec wait times: max=5.000000 sec, heur=2 min 53 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.000020 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=5.001725 sec, exc=5.001725 sec, total=5.001725 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=33 seq_num=34 snap_id=1 wait times: snap=5.001121 sec, exc=5.001121 sec, total=5.001121 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=32 seq_num=33 snap_id=1 wait times: snap=5.000490 sec, exc=5.000490 sec, total=5.000490 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=5.013153 sec, exc=5.013153 sec, total=5.013153 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=5.009893 sec, exc=5.009893 sec, total=5.009893 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=29 seq_num=30 snap_id=1 wait times: snap=5.004627 sec, exc=5.004627 sec, total=5.004627 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=5.009288 sec, exc=5.009288 sec, total=5.009288 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=27 seq_num=28 snap_id=1 wait times: snap=5.010142 sec, exc=5.010142 sec, total=5.010142 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.008308 sec, exc=5.008308 sec, total=5.008308 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.000282 sec, exc=5.000282 sec, total=5.000282 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time Sampled Session History of session 177 serial 26301 --------------------------------------------------- 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, 10:03:24 - 10:05:24] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-20 10:05:24.939 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 18456, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-20 07:42:13.444239 :B476C3E6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9372 pso_num=22 pso_serial#=42 2025-07-20 07:42:13.444380 :B476C3E7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9372 osp_idx=0 osp_ver=424434 osp_pg=0 (spawn #403845) 2025-07-20 07:42:13.444381 :B476C3E8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 07:42:13.444381 :B476C3E9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=59 time=1678109345 2025-07-20 07:42:13.444382 :B476C3EA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 07:42:13.444382 :B476C3EB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 07:42:13.444382 :B476C3EC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 07:42:13.444383 :B476C3ED:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 07:42:13.444383 :B476C3EE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 07:42:13.444880 :B476C3EF: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-07-20 07:42:13.444927 :B476C3F7: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-07-20 07:52:14.388498 :B4778955:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 07:52:14.741936 :B47789B1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 07:52:14.737 2025-07-20 07:52:14.741937 :B47789B2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15012 pso_num=22 pso_serial#=43 2025-07-20 07:52:14.742068 :B47789B3:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15012 osp_idx=0 osp_ver=424435 osp_pg=0 (spawn #403869) 2025-07-20 07:52:14.742068 :B47789B4:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 07:52:14.742069 :B47789B5:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=60 time=1678710642 2025-07-20 07:52:14.742069 :B47789B6:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 07:52:14.742070 :B47789B7:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 07:52:14.742070 :B47789B8:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 07:52:14.742070 :B47789B9:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 07:52:14.742071 :B47789BA:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 07:52:14.742555 :B47789BB: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-07-20 07:52:14.742611 :B47789C2: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-07-20 08:02:15.623037 :B47850D7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 08:02:16.111941 :B4785134:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 08:02:16.107 2025-07-20 08:02:16.111943 :B4785135:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19168 pso_num=22 pso_serial#=44 2025-07-20 08:02:16.112085 :B4785136:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19168 osp_idx=0 osp_ver=424436 osp_pg=0 (spawn #403894) 2025-07-20 08:02:16.112085 :B4785137:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 08:02:16.112086 :B4785138:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=61 time=1679312001 2025-07-20 08:02:16.112086 :B4785139:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 08:02:16.112087 :B478513A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 08:02:16.112087 :B478513B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 08:02:16.112087 :B478513C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 08:02:16.112088 :B478513D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 08:02:16.112608 :B478513E: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-07-20 08:02:16.112656 :B4785146: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-07-20 08:12:17.039470 :B4792042:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 08:12:17.325376 :B479209C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 08:12:17.321 2025-07-20 08:12:17.325378 :B479209D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18552 pso_num=22 pso_serial#=45 2025-07-20 08:12:17.325524 :B479209E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18552 osp_idx=0 osp_ver=424437 osp_pg=0 (spawn #403917) 2025-07-20 08:12:17.325525 :B479209F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 08:12:17.325525 :B47920A0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=62 time=1679913220 2025-07-20 08:12:17.325526 :B47920A1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 08:12:17.325526 :B47920A2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 08:12:17.325526 :B47920A3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 08:12:17.325527 :B47920A4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 08:12:17.325527 :B47920A5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 08:12:17.326032 :B47920A6: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-07-20 08:12:17.326078 :B47920AC: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-07-20 08:22:18.211964 :B47A353C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 08:22:18.560385 :B47A358B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 08:22:18.555 2025-07-20 08:22:18.560387 :B47A358C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=1216 pso_num=22 pso_serial#=46 2025-07-20 08:22:18.560525 :B47A358D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=1216 osp_idx=0 osp_ver=424438 osp_pg=0 (spawn #403945) 2025-07-20 08:22:18.560526 :B47A358E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 08:22:18.560526 :B47A358F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=63 time=1680514454 2025-07-20 08:22:18.560526 :B47A3590:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 08:22:18.560527 :B47A3591:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 08:22:18.560527 :B47A3592:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 08:22:18.560527 :B47A3593:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 08:22:18.560528 :B47A3594:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 08:22:18.561028 :B47A3595: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-07-20 08:22:18.561078 :B47A359C: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-07-20 08:32:19.574370 :B47B20A9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 08:32:19.739895 :B47B20AC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 08:32:19.731 2025-07-20 08:32:19.739898 :B47B20AD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12540 pso_num=22 pso_serial#=47 2025-07-20 08:32:19.740036 :B47B20AE:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12540 (legacy spawn) 2025-07-20 08:32:19.746832 :B47B20AF: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-07-20 08:32:19.746998 :B47B20B4: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-07-20 08:32:19.747961 :B47B20B9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 08:32:19.939190 :B47B2109:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 08:32:19.934 2025-07-20 08:32:19.939192 :B47B210A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19316 pso_num=22 pso_serial#=48 2025-07-20 08:32:19.939329 :B47B210B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19316 osp_idx=0 osp_ver=424440 osp_pg=0 (spawn #403967) 2025-07-20 08:32:19.939330 :B47B210C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 08:32:19.939330 :B47B210D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=64 time=1681115829 2025-07-20 08:32:19.939330 :B47B210E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 08:32:19.939331 :B47B210F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 08:32:19.939331 :B47B2110:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 08:32:19.939331 :B47B2111:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 08:32:19.939332 :B47B2112:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 08:32:19.939845 :B47B2113: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-07-20 08:32:19.939903 :B47B211D: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-07-20 08:42:20.867461 :B47BE9CC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 08:42:21.294016 :B47BEA09:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 08:42:21.289 2025-07-20 08:42:21.294018 :B47BEA0A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=700 pso_num=22 pso_serial#=49 2025-07-20 08:42:21.294157 :B47BEA0B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=700 osp_idx=0 osp_ver=424441 osp_pg=0 (spawn #403990) 2025-07-20 08:42:21.294159 :B47BEA0C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 08:42:21.294159 :B47BEA0D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=65 time=1681717189 2025-07-20 08:42:21.294160 :B47BEA0E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 08:42:21.294160 :B47BEA0F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 08:42:21.294160 :B47BEA10:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 08:42:21.294160 :B47BEA11:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 08:42:21.294161 :B47BEA12:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 08:42:21.294659 :B47BEA13: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-07-20 08:42:21.294705 :B47BEA1A: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-07-20 08:52:22.215357 :B47CB34B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 08:52:22.595097 :B47CB39B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 08:52:22.590 2025-07-20 08:52:22.595100 :B47CB39C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19148 pso_num=22 pso_serial#=50 2025-07-20 08:52:22.595232 :B47CB39D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19148 osp_idx=0 osp_ver=424442 osp_pg=0 (spawn #404013) 2025-07-20 08:52:22.595233 :B47CB39E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 08:52:22.595233 :B47CB39F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=66 time=1682318486 2025-07-20 08:52:22.595233 :B47CB3A0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 08:52:22.595234 :B47CB3A1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 08:52:22.595234 :B47CB3A2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 08:52:22.595234 :B47CB3A3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 08:52:22.595234 :B47CB3A4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 08:52:22.595734 :B47CB3A5: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-07-20 08:52:22.595780 :B47CB3AD: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-07-20 09:02:23.567123 :B47D7EB2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 09:02:23.894326 :B47D7F0E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 09:02:23.889 2025-07-20 09:02:23.894328 :B47D7F0F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13012 pso_num=22 pso_serial#=51 2025-07-20 09:02:23.894465 :B47D7F10:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13012 osp_idx=0 osp_ver=424443 osp_pg=0 (spawn #404038) 2025-07-20 09:02:23.894466 :B47D7F11:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 09:02:23.894467 :B47D7F12:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=67 time=1682919783 2025-07-20 09:02:23.894468 :B47D7F13:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 09:02:23.894468 :B47D7F14:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 09:02:23.894468 :B47D7F15:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 09:02:23.894469 :B47D7F16:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 09:02:23.894469 :B47D7F17:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 09:02:23.895006 :B47D7F18: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-07-20 09:02:23.895050 :B47D7F1E: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-07-20 09:12:24.772459 :B47E50C4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 09:12:25.157000 :B47E511F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 09:12:25.152 2025-07-20 09:12:25.157002 :B47E5120:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6364 pso_num=22 pso_serial#=52 2025-07-20 09:12:25.157144 :B47E5121:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6364 osp_idx=0 osp_ver=424444 osp_pg=0 (spawn #404061) 2025-07-20 09:12:25.157145 :B47E5122:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 09:12:25.157145 :B47E5123:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=68 time=1683521048 2025-07-20 09:12:25.157146 :B47E5124:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 09:12:25.157146 :B47E5125:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 09:12:25.157146 :B47E5126:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 09:12:25.157147 :B47E5127:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 09:12:25.157147 :B47E5128:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 09:12:25.157654 :B47E5129: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-07-20 09:12:25.157699 :B47E5130: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-07-20 09:13:37.277841 :B47E69D1: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-07-20 09:22:26.458365 :B47F1F62: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-07-20 09:32:27.463413 :B47FEDB9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 09:32:27.780692 :B47FEDDE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 09:32:27.775 2025-07-20 09:32:27.780694 :B47FEDDF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18780 pso_num=22 pso_serial#=53 2025-07-20 09:32:27.780843 :B47FEDE0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18780 osp_idx=0 osp_ver=424445 osp_pg=0 (spawn #404105) 2025-07-20 09:32:27.780844 :B47FEDE1:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 09:32:27.780844 :B47FEDE2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=69 time=1684723673 2025-07-20 09:32:27.780845 :B47FEDE3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 09:32:27.780845 :B47FEDE4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 09:32:27.780845 :B47FEDE5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 09:32:27.780846 :B47FEDE6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 09:32:27.780846 :B47FEDE7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 09:32:27.781340 :B47FEDE8: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-07-20 09:32:27.781384 :B47FEDF0: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-07-20 09:42:28.715856 :B480C328:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 09:42:29.126913 :B480C359:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 09:42:29.122 2025-07-20 09:42:29.126915 :B480C35A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19424 pso_num=22 pso_serial#=54 2025-07-20 09:42:29.127060 :B480C35B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19424 osp_idx=0 osp_ver=424446 osp_pg=0 (spawn #404128) 2025-07-20 09:42:29.127061 :B480C35C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 09:42:29.127061 :B480C35D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=70 time=1685325017 2025-07-20 09:42:29.127062 :B480C35E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 09:42:29.127062 :B480C35F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 09:42:29.127062 :B480C360:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 09:42:29.127063 :B480C361:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 09:42:29.127063 :B480C362:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 09:42:29.127568 :B480C363: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-07-20 09:42:29.127615 :B480C369: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-07-20 09:52:30.137797 :B4818C13:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 09:52:30.361103 :B4818C3B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 09:52:30.356 2025-07-20 09:52:30.361105 :B4818C3C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18496 pso_num=22 pso_serial#=55 2025-07-20 09:52:30.361248 :B4818C3D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18496 osp_idx=0 osp_ver=424447 osp_pg=0 (spawn #404151) 2025-07-20 09:52:30.361249 :B4818C3E:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 09:52:30.361250 :B4818C3F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=71 time=1685926251 2025-07-20 09:52:30.361250 :B4818C40:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 09:52:30.361250 :B4818C41:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 09:52:30.361251 :B4818C42:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 09:52:30.361251 :B4818C43:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 09:52:30.361251 :B4818C44:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 09:52:30.361744 :B4818C45: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-07-20 09:52:30.361792 :B4818C4C: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-07-20 10:02:31.281990 :B48256A3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-20 10:02:31.724256 :B48256C8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-20 10:02:31.719 2025-07-20 10:02:31.724258 :B48256C9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18456 pso_num=22 pso_serial#=56 2025-07-20 10:02:31.724393 :B48256CA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18456 osp_idx=0 osp_ver=424448 osp_pg=0 (spawn #404176) 2025-07-20 10:02:31.724394 :B48256CB:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-20 10:02:31.724395 :B48256CC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=72 time=1686527626 2025-07-20 10:02:31.724395 :B48256CD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-20 10:02:31.724395 :B48256CE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-20 10:02:31.724396 :B48256CF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-20 10:02:31.724396 :B48256D0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-20 10:02:31.724397 :B48256D1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-20 10:02:31.724879 :B48256D2: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-07-20 10:02:31.724924 :B48256D8: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: 18456, W000)