Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250518180124\orcl_w000_11488_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:37394M/63366M, Ph+PgF:44617M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 11488, image: ORACLE.EXE (W000) *** 2025-05-18 18:01:24.870 *** SESSION ID:(177.23811) 2025-05-18 18:01:24.870 *** 2025-05-18 18:01:24.870 Process diagnostic dump for ORACLE.EXE (W000), OS id=11488, pid: 22, proc_ser: 5, sid: 177, sess_ser: 23811 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=1.313416 sec, exc=1.313416 sec, total=1.313416 sec wait times: max=5.000000 sec, heur=56.406196 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=11 seq_num=12 snap_id=1 wait times: snap=5.014730 sec, exc=5.014730 sec, total=5.014730 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=5.010153 sec, exc=5.010153 sec, total=5.010153 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=5.001700 sec, exc=5.001700 sec, total=5.001700 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=5.001366 sec, exc=5.001366 sec, total=5.001366 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=7 seq_num=8 snap_id=1 wait times: snap=5.013925 sec, exc=5.013925 sec, total=5.013925 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=5.007837 sec, exc=5.007837 sec, total=5.007837 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=5.014732 sec, exc=5.014732 sec, total=5.014732 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=5.004599 sec, exc=5.004599 sec, total=5.004599 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=3 seq_num=4 snap_id=1 wait times: snap=5.014743 sec, exc=5.014743 sec, total=5.014743 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=5.015250 sec, exc=5.015250 sec, total=5.015250 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time Sampled Session History of session 177 serial 23811 --------------------------------------------------- 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 --------------------------------------------------- [57 samples, 18:00:28 - 18:01:24] idle wait at each sample [session created at: 18:00:28] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-18 18:01:24.870 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 11488, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-18 16:38:18.934165 :98CFC249:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 16:38:18.934166 :98CFC24A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=163 time=562108797 2025-05-18 16:38:18.934166 :98CFC24B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 16:38:18.934167 :98CFC24C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 16:38:18.934167 :98CFC24D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 16:38:18.934167 :98CFC24E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 16:38:18.934168 :98CFC24F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 16:38:18.934652 :98CFC250: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-05-18 16:38:18.935339 :98CFC265: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-05-18 16:38:18.940834 :98CFC281: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-05-18 16:38:18.941781 :98CFC289: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-05-18 16:38:18.941901 :98CFC292: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-05-18 16:38:23.944776 :98CFC415:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 16:38:54.050805 :98CFCDD1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:38:57.766356 :98CFCF0E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:38:57.758 2025-05-18 16:38:57.766359 :98CFCF0F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12492 pso_num=22 pso_serial#=244 2025-05-18 16:38:57.766498 :98CFCF10:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12492 (legacy spawn) 2025-05-18 16:38:57.772996 :98CFCF11: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-05-18 16:38:57.773167 :98CFCF16: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-05-18 16:38:57.773979 :98CFCF1B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:39:02.447787 :98CFD05B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:39:02.439 2025-05-18 16:39:02.447788 :98CFD05C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13204 pso_num=22 pso_serial#=245 2025-05-18 16:39:02.447931 :98CFD05D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13204 (legacy spawn) 2025-05-18 16:39:02.454419 :98CFD05E: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-05-18 16:39:02.454596 :98CFD063: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-05-18 16:39:02.455386 :98CFD068:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:39:08.328094 :98CFD255:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:39:08.325 2025-05-18 16:39:08.328097 :98CFD256:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13828 pso_num=22 pso_serial#=246 2025-05-18 16:39:08.328237 :98CFD257:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13828 (legacy spawn) 2025-05-18 16:39:08.335002 :98CFD258: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-05-18 16:39:08.335187 :98CFD25D: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-05-18 16:39:08.336139 :98CFD262:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:39:08.345355 :98CFD265:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:39:08.341 2025-05-18 16:39:08.345357 :98CFD266:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9052 pso_num=22 pso_serial#=247 2025-05-18 16:39:08.345509 :98CFD267:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9052 (legacy spawn) 2025-05-18 16:39:08.352112 :98CFD268: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-05-18 16:39:08.352294 :98CFD271: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-05-18 16:39:08.353197 :98CFD272:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:39:11.526203 :98CFD36E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:39:11.513 2025-05-18 16:39:11.526205 :98CFD36F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13980 pso_num=22 pso_serial#=248 2025-05-18 16:39:11.526335 :98CFD370:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13980 (legacy spawn) 2025-05-18 16:39:11.532809 :98CFD371: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-05-18 16:39:11.532982 :98CFD376: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-05-18 16:39:11.533782 :98CFD37B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:39:11.542495 :98CFD37E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:39:11.528 2025-05-18 16:39:11.542496 :98CFD37F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14156 pso_num=22 pso_serial#=249 2025-05-18 16:39:11.542641 :98CFD380:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14156 (legacy spawn) 2025-05-18 16:39:11.549165 :98CFD381: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-05-18 16:39:11.549336 :98CFD38A: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-05-18 16:39:11.550137 :98CFD38B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:39:24.047049 :98CFD7A0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:39:24.041 2025-05-18 16:39:24.047051 :98CFD7A1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9552 pso_num=22 pso_serial#=250 2025-05-18 16:39:24.047186 :98CFD7A2:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9552 osp_idx=0 osp_ver=207310 osp_pg=0 (spawn #195098) 2025-05-18 16:39:24.047187 :98CFD7A3:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 16:39:24.047188 :98CFD7A4:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=164 time=562173922 2025-05-18 16:39:24.047188 :98CFD7A5:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 16:39:24.047188 :98CFD7A6:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 16:39:24.047189 :98CFD7A7:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 16:39:24.047191 :98CFD7A8:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 16:39:24.047191 :98CFD7A9:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 16:39:24.047661 :98CFD7AA: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-05-18 16:39:24.048297 :98CFD7BF: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-05-18 16:39:24.055829 :98CFD7DB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-18 16:39:24.056199 :98CFD7DC: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-05-18 16:39:24.056237 :98CFD7DF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-18 16:39:24.057173 :98CFD7F0: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-05-18 16:39:24.057301 :98CFD7F9: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-05-18 16:39:54.138256 :98CFE1B1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:39:59.958496 :98CFE358:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:39:59.950 2025-05-18 16:39:59.958498 :98CFE359:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9756 pso_num=22 pso_serial#=251 2025-05-18 16:39:59.958632 :98CFE35A:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9756 (legacy spawn) 2025-05-18 16:39:59.965101 :98CFE35B: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-05-18 16:39:59.965280 :98CFE360: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-05-18 16:39:59.966104 :98CFE38E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:40:10.840471 :98CFE706:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:40:10.827 2025-05-18 16:40:10.840473 :98CFE707:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13852 pso_num=22 pso_serial#=252 2025-05-18 16:40:10.840604 :98CFE708:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13852 (legacy spawn) 2025-05-18 16:40:10.846976 :98CFE709: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-05-18 16:40:10.847150 :98CFE70E: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-05-18 16:40:10.847942 :98CFE713:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:40:18.179402 :98CFE953:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:40:18.174 2025-05-18 16:40:18.179405 :98CFE954:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13268 pso_num=22 pso_serial#=253 2025-05-18 16:40:18.179577 :98CFE955:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13268 osp_idx=0 osp_ver=207313 osp_pg=0 (spawn #195100) 2025-05-18 16:40:18.179577 :98CFE956:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 16:40:18.179578 :98CFE957:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=165 time=562228047 2025-05-18 16:40:18.179579 :98CFE958:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 16:40:18.179579 :98CFE959:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 16:40:18.179580 :98CFE95A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 16:40:18.179580 :98CFE95B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 16:40:18.179580 :98CFE95C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 16:40:18.180090 :98CFE95D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 16:40:18.180137 :98CFE967:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 16:50:19.118536 :98D0B1B7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 16:50:19.513822 :98D0B1F5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 16:50:19.508 2025-05-18 16:50:19.513824 :98D0B1F6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13124 pso_num=22 pso_serial#=254 2025-05-18 16:50:19.513967 :98D0B1F7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13124 osp_idx=0 osp_ver=207314 osp_pg=0 (spawn #195122) 2025-05-18 16:50:19.513969 :98D0B1F8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 16:50:19.513970 :98D0B1F9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=166 time=562829375 2025-05-18 16:50:19.513971 :98D0B1FA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 16:50:19.513971 :98D0B1FB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 16:50:19.513972 :98D0B1FC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 16:50:19.513972 :98D0B1FD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 16:50:19.513972 :98D0B1FE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 16:50:19.514511 :98D0B1FF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 16:50:19.514559 :98D0B207:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 17:00:20.545053 :98D17B2E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 17:00:20.815425 :98D17B6D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 17:00:20.811 2025-05-18 17:00:20.815427 :98D17B6E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12912 pso_num=22 pso_serial#=255 2025-05-18 17:00:20.815574 :98D17B6F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12912 osp_idx=0 osp_ver=207315 osp_pg=0 (spawn #195147) 2025-05-18 17:00:20.815575 :98D17B70:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 17:00:20.815575 :98D17B71:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=167 time=563430688 2025-05-18 17:00:20.815576 :98D17B72:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 17:00:20.815576 :98D17B73:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 17:00:20.815576 :98D17B74:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 17:00:20.815577 :98D17B75:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 17:00:20.815577 :98D17B76:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 17:00:20.816073 :98D17B77:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 17:00:20.816118 :98D17B80:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 17:10:21.747118 :98D24E13:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 17:10:22.017498 :98D24E51:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 17:10:22.012 2025-05-18 17:10:22.017501 :98D24E52:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8028 pso_num=22 pso_serial#=1 2025-05-18 17:10:22.017639 :98D24E53:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8028 osp_idx=0 osp_ver=207316 osp_pg=0 (spawn #195171) 2025-05-18 17:10:22.017639 :98D24E54:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 17:10:22.017640 :98D24E55:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=168 time=564031891 2025-05-18 17:10:22.017640 :98D24E56:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 17:10:22.017640 :98D24E57:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 17:10:22.017641 :98D24E58:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 17:10:22.017641 :98D24E59:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 17:10:22.017641 :98D24E5A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 17:10:22.018125 :98D24E5B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 17:10:22.018168 :98D24E62:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 17:20:22.974222 :98D316E4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 17:20:23.322722 :98D31728:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 17:20:23.318 2025-05-18 17:20:23.322725 :98D31729:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8444 pso_num=22 pso_serial#=2 2025-05-18 17:20:23.322895 :98D3172A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8444 osp_idx=0 osp_ver=207317 osp_pg=0 (spawn #195193) 2025-05-18 17:20:23.322896 :98D3172B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 17:20:23.322896 :98D3172C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=169 time=564633188 2025-05-18 17:20:23.322897 :98D3172D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 17:20:23.322897 :98D3172E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 17:20:23.322897 :98D3172F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 17:20:23.322898 :98D31730:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 17:20:23.322898 :98D31731:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 17:20:23.323404 :98D31732:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 17:20:23.323454 :98D31739:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 17:30:24.263965 :98D3E0AA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 17:30:24.581059 :98D3E0EF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 17:30:24.576 2025-05-18 17:30:24.581061 :98D3E0F0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11796 pso_num=22 pso_serial#=3 2025-05-18 17:30:24.581201 :98D3E0F1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11796 osp_idx=0 osp_ver=207318 osp_pg=0 (spawn #195218) 2025-05-18 17:30:24.581202 :98D3E0F2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 17:30:24.581202 :98D3E0F3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=170 time=565234454 2025-05-18 17:30:24.581202 :98D3E0F4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 17:30:24.581203 :98D3E0F5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 17:30:24.581203 :98D3E0F6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 17:30:24.581204 :98D3E0F7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 17:30:24.581204 :98D3E0F8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 17:30:24.581703 :98D3E0F9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 17:30:24.581753 :98D3E100:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 17:37:19.026550 :98D46B1A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 17:40:25.900354 :98D4A8E5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 17:50:26.919562 :98D5714D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 17:50:27.189603 :98D571AF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 17:50:27.185 2025-05-18 17:50:27.189606 :98D571B0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=3560 pso_num=22 pso_serial#=4 2025-05-18 17:50:27.189744 :98D571B1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=3560 osp_idx=0 osp_ver=207319 osp_pg=0 (spawn #195260) 2025-05-18 17:50:27.189744 :98D571B2:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 17:50:27.189745 :98D571B3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=171 time=566437063 2025-05-18 17:50:27.189745 :98D571B4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 17:50:27.189746 :98D571B5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 17:50:27.189746 :98D571B6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 17:50:27.189746 :98D571B7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 17:50:27.189746 :98D571B8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 17:50:27.190232 :98D571B9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 17:50:27.190276 :98D571C1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 18:00:28.179212 :98D639BB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-18 18:00:28.465045 :98D63A1F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-18 18:00:28.460 2025-05-18 18:00:28.465047 :98D63A20:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11488 pso_num=22 pso_serial#=5 2025-05-18 18:00:28.465185 :98D63A21:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11488 osp_idx=0 osp_ver=207320 osp_pg=0 (spawn #195285) 2025-05-18 18:00:28.465186 :98D63A22:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 18:00:28.465186 :98D63A23:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=172 time=567038329 2025-05-18 18:00:28.465187 :98D63A24:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 18:00:28.465187 :98D63A25:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 18:00:28.465188 :98D63A26:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 18:00:28.465188 :98D63A27:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 18:00:28.465188 :98D63A28:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 18:00:28.465680 :98D63A29:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 18:00:28.465724 :98D63A32: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: 11488, W000)