Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250826220004\orcl_w000_6008_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:35194M/63366M, Ph+PgF:40264M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 6008, image: ORACLE.EXE (W000) *** 2025-08-26 22:00:04.821 *** SESSION ID:(177.64429) 2025-08-26 22:00:04.821 *** 2025-08-26 22:00:04.821 Process diagnostic dump for ORACLE.EXE (W000), OS id=6008, pid: 22, proc_ser: 131, sid: 177, sess_ser: 64429 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=181 seq_num=182 snap_id=1 wait times: snap=4.409709 sec, exc=4.409709 sec, total=4.409709 sec wait times: max=5.000000 sec, heur=11 min 30 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.000022 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=180 seq_num=181 snap_id=1 wait times: snap=5.012433 sec, exc=5.012433 sec, total=5.012433 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=179 seq_num=180 snap_id=1 wait times: snap=5.008343 sec, exc=5.008343 sec, total=5.008343 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=178 seq_num=179 snap_id=1 wait times: snap=5.004619 sec, exc=5.004619 sec, total=5.004619 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=177 seq_num=178 snap_id=1 wait times: snap=5.011808 sec, exc=5.011808 sec, total=5.011808 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=176 seq_num=177 snap_id=1 wait times: snap=5.001133 sec, exc=5.001133 sec, total=5.001133 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=175 seq_num=176 snap_id=1 wait times: snap=5.000414 sec, exc=5.000414 sec, total=5.000414 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=174 seq_num=175 snap_id=1 wait times: snap=5.010982 sec, exc=5.010982 sec, total=5.010982 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000038 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=173 seq_num=174 snap_id=1 wait times: snap=5.001760 sec, exc=5.001760 sec, total=5.001760 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=172 seq_num=173 snap_id=1 wait times: snap=5.004611 sec, exc=5.004611 sec, total=5.004611 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=171 seq_num=172 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.000032 sec of elapsed time Sampled Session History of session 177 serial 64429 --------------------------------------------------- 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:04 - 22:00:04] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-26 22:00:04.821 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 6008, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-26 19:14:48.894141 :C50246A9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 19:14:48.894646 :C50246AA: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-08-26 19:14:48.894703 :C50246B1: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-08-26 19:24:49.717337 :C5030B63:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 19:24:50.300160 :C5030BF5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 19:24:50.300 2025-08-26 19:24:50.300163 :C5030BF6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21316 pso_num=22 pso_serial#=118 2025-08-26 19:24:50.300296 :C5030BF7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21316 osp_idx=0 osp_ver=551755 osp_pg=0 (spawn #528803) 2025-08-26 19:24:50.300297 :C5030BF8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 19:24:50.300297 :C5030BF9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=132 time=621945033 2025-08-26 19:24:50.300297 :C5030BFA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 19:24:50.300298 :C5030BFB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 19:24:50.300298 :C5030BFC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 19:24:50.300299 :C5030BFD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 19:24:50.300299 :C5030BFE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 19:24:50.300801 :C5030BFF: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-08-26 19:24:50.300844 :C5030C06: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-08-26 19:34:51.212881 :C503D0F0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 19:34:51.748884 :C503D172:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 19:34:51.743 2025-08-26 19:34:51.748886 :C503D173:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=1388 pso_num=22 pso_serial#=119 2025-08-26 19:34:51.749022 :C503D174:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=1388 osp_idx=0 osp_ver=551756 osp_pg=0 (spawn #528826) 2025-08-26 19:34:51.749022 :C503D175:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 19:34:51.749022 :C503D176:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=133 time=622546487 2025-08-26 19:34:51.749023 :C503D177:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 19:34:51.749023 :C503D178:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 19:34:51.749023 :C503D179:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 19:34:51.749024 :C503D17A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 19:34:51.749024 :C503D17B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 19:34:51.749525 :C503D17C: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-08-26 19:34:51.749575 :C503D186: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-08-26 19:44:52.622192 :C5049662:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 19:44:53.127027 :C50496E9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 19:44:53.122 2025-08-26 19:44:53.127029 :C50496EA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22936 pso_num=22 pso_serial#=120 2025-08-26 19:44:53.127180 :C50496EB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22936 osp_idx=0 osp_ver=551757 osp_pg=0 (spawn #528848) 2025-08-26 19:44:53.127180 :C50496EC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 19:44:53.127180 :C50496ED:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=134 time=623147862 2025-08-26 19:44:53.127181 :C50496EE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 19:44:53.127181 :C50496EF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 19:44:53.127181 :C50496F0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 19:44:53.127181 :C50496F1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 19:44:53.127182 :C50496F2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 19:44:53.127683 :C50496F3: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-08-26 19:44:53.127731 :C50496FC: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-08-26 19:48:33.850017 :C504DE4B: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-08-26 20:04:55.292867 :C50624EF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 20:04:55.734763 :C506253E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 20:04:55.730 2025-08-26 20:04:55.734765 :C506253F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17272 pso_num=22 pso_serial#=121 2025-08-26 20:04:55.734931 :C5062540:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17272 osp_idx=0 osp_ver=551758 osp_pg=0 (spawn #528896) 2025-08-26 20:04:55.734932 :C5062541:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 20:04:55.734932 :C5062542:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=135 time=624350471 2025-08-26 20:04:55.734934 :C5062543:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 20:04:55.734934 :C5062544:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 20:04:55.734935 :C5062545:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 20:04:55.734935 :C5062546:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 20:04:55.734935 :C5062547:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 20:04:55.735465 :C5062548: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-08-26 20:04:55.735510 :C5062551: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-08-26 20:14:56.610749 :C506EF8E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 20:14:56.990369 :C506EFC2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 20:14:56.985 2025-08-26 20:14:56.990371 :C506EFC3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17528 pso_num=22 pso_serial#=122 2025-08-26 20:14:56.990508 :C506EFC4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17528 osp_idx=0 osp_ver=551759 osp_pg=0 (spawn #528918) 2025-08-26 20:14:56.990509 :C506EFC5:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 20:14:56.990509 :C506EFC6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=136 time=624951721 2025-08-26 20:14:56.990510 :C506EFC7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 20:14:56.990510 :C506EFC8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 20:14:56.990511 :C506EFC9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 20:14:56.990511 :C506EFCA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 20:14:56.990512 :C506EFCB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 20:14:56.991016 :C506EFCC: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-08-26 20:14:56.991064 :C506EFD3: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-08-26 20:24:57.949576 :C507B44E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 20:24:58.313580 :C507B496:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 20:24:58.308 2025-08-26 20:24:58.313582 :C507B497:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21748 pso_num=22 pso_serial#=123 2025-08-26 20:24:58.313726 :C507B498:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=21748 osp_idx=0 osp_ver=551760 osp_pg=0 (spawn #528941) 2025-08-26 20:24:58.313727 :C507B499:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 20:24:58.313727 :C507B49A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=137 time=625553049 2025-08-26 20:24:58.313728 :C507B49B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 20:24:58.313728 :C507B49C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 20:24:58.313729 :C507B49D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 20:24:58.313729 :C507B49E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 20:24:58.313729 :C507B49F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 20:24:58.314220 :C507B4A0: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-08-26 20:24:58.314266 :C507B4A8: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-08-26 20:34:59.243497 :C508788E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 20:34:59.633412 :C50878C4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 20:34:59.628 2025-08-26 20:34:59.633415 :C50878C5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22912 pso_num=22 pso_serial#=124 2025-08-26 20:34:59.633593 :C50878C6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22912 osp_idx=0 osp_ver=551761 osp_pg=0 (spawn #528964) 2025-08-26 20:34:59.633594 :C50878C7:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 20:34:59.633594 :C50878C8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=138 time=626154377 2025-08-26 20:34:59.633595 :C50878C9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 20:34:59.633595 :C50878CA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 20:34:59.633596 :C50878CB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 20:34:59.633596 :C50878CC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 20:34:59.633596 :C50878CD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 20:34:59.634107 :C50878CE: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-08-26 20:34:59.634159 :C50878D4: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-08-26 20:45:00.594019 :C5093D46:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 20:45:01.004906 :C5093D90:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 20:45:01.000 2025-08-26 20:45:01.004907 :C5093D91:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19660 pso_num=22 pso_serial#=125 2025-08-26 20:45:01.005043 :C5093D92:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19660 osp_idx=0 osp_ver=551762 osp_pg=0 (spawn #528987) 2025-08-26 20:45:01.005044 :C5093D93:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 20:45:01.005044 :C5093D94:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=139 time=626755737 2025-08-26 20:45:01.005044 :C5093D95:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 20:45:01.005045 :C5093D96:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 20:45:01.005045 :C5093D97:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 20:45:01.005046 :C5093D98:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 20:45:01.005046 :C5093D99:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 20:45:01.005578 :C5093D9A: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-08-26 20:45:01.005620 :C5093DA2: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-08-26 20:55:01.960787 :C50A01F0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 20:55:02.262587 :C50A0240:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 20:55:02.257 2025-08-26 20:55:02.262589 :C50A0241:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23140 pso_num=22 pso_serial#=126 2025-08-26 20:55:02.262730 :C50A0242:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23140 osp_idx=0 osp_ver=551763 osp_pg=0 (spawn #529010) 2025-08-26 20:55:02.262731 :C50A0243:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 20:55:02.262732 :C50A0244:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=140 time=627357002 2025-08-26 20:55:02.262732 :C50A0245:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 20:55:02.262733 :C50A0246:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 20:55:02.262733 :C50A0247:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 20:55:02.262734 :C50A0248:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 20:55:02.262734 :C50A0249:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 20:55:02.263249 :C50A024A: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-08-26 20:55:02.263303 :C50A0250: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-08-26 21:05:03.242204 :C50ACBA0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 21:05:03.606328 :C50ACBEA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 21:05:03.601 2025-08-26 21:05:03.606330 :C50ACBEB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23120 pso_num=22 pso_serial#=127 2025-08-26 21:05:03.606500 :C50ACBEC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23120 osp_idx=0 osp_ver=551764 osp_pg=0 (spawn #529036) 2025-08-26 21:05:03.606501 :C50ACBED:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:05:03.606501 :C50ACBEE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=141 time=627958346 2025-08-26 21:05:03.606501 :C50ACBEF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:05:03.606502 :C50ACBF0:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:05:03.606502 :C50ACBF1:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:05:03.606502 :C50ACBF2:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:05:03.606503 :C50ACBF3:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:05:03.607004 :C50ACBF4: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-08-26 21:05:03.607053 :C50ACBFB: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-08-26 21:15:04.593199 :C50B95CE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 21:15:04.926144 :C50B9622:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 21:15:04.921 2025-08-26 21:15:04.926147 :C50B9623:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22452 pso_num=22 pso_serial#=128 2025-08-26 21:15:04.926294 :C50B9624:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22452 osp_idx=0 osp_ver=551765 osp_pg=0 (spawn #529058) 2025-08-26 21:15:04.926294 :C50B9625:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:15:04.926295 :C50B9626:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=142 time=628559658 2025-08-26 21:15:04.926295 :C50B9627:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:15:04.926295 :C50B9628:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:15:04.926296 :C50B9629:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:15:04.926296 :C50B962A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:15:04.926296 :C50B962B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:15:04.926799 :C50B962C: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-08-26 21:15:04.926844 :C50B9634: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-08-26 21:25:05.772220 :C50C59E2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 21:25:06.058112 :C50C5A2C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 21:25:06.053 2025-08-26 21:25:06.058114 :C50C5A2D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23440 pso_num=22 pso_serial#=129 2025-08-26 21:25:06.058261 :C50C5A2E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23440 osp_idx=0 osp_ver=551766 osp_pg=0 (spawn #529081) 2025-08-26 21:25:06.058262 :C50C5A2F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:25:06.058263 :C50C5A30:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=143 time=629160799 2025-08-26 21:25:06.058263 :C50C5A31:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:25:06.058264 :C50C5A32:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:25:06.058264 :C50C5A33:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:25:06.058264 :C50C5A34:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:25:06.058265 :C50C5A35:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:25:06.058758 :C50C5A36: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-08-26 21:25:06.058802 :C50C5A3D: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-08-26 21:35:07.030960 :C50D1A07:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 21:35:07.379689 :C50D1A5C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 21:35:07.375 2025-08-26 21:35:07.379691 :C50D1A5D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7652 pso_num=22 pso_serial#=130 2025-08-26 21:35:07.379831 :C50D1A5E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7652 osp_idx=0 osp_ver=551767 osp_pg=0 (spawn #529104) 2025-08-26 21:35:07.379831 :C50D1A5F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:35:07.379832 :C50D1A60:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=144 time=629762112 2025-08-26 21:35:07.379832 :C50D1A61:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:35:07.379832 :C50D1A62:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:35:07.379833 :C50D1A63:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:35:07.379833 :C50D1A64:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:35:07.379833 :C50D1A65:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:35:07.380339 :C50D1A66: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-08-26 21:35:07.380382 :C50D1A6C: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-08-26 21:45:08.334315 :C50DDAC5:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-26 21:45:08.651457 :C50DDAFA:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-26 21:45:08.646 2025-08-26 21:45:08.651458 :C50DDAFB:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6008 pso_num=22 pso_serial#=131 2025-08-26 21:45:08.651590 :C50DDAFC:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6008 osp_idx=0 osp_ver=551768 osp_pg=0 (spawn #529126) 2025-08-26 21:45:08.651591 :C50DDAFD:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:45:08.651591 :C50DDAFE:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=145 time=630363393 2025-08-26 21:45:08.651591 :C50DDAFF:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:45:08.651592 :C50DDB00:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:45:08.651592 :C50DDB01:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:45:08.651592 :C50DDB02:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:45:08.651593 :C50DDB03:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:45:08.652080 :C50DDB04: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-08-26 21:45:08.652128 :C50DDB0E: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-08-26 21:48:34.614689 :C50E1BD5: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-08-26 21:55:09.997875 :C50E9A84: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 6008, W000)