Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250514220007\orcl_w000_9468_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:37384M/63366M, Ph+PgF:44628M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 9468, image: ORACLE.EXE (W000) *** 2025-05-14 22:00:07.465 *** SESSION ID:(201.15805) 2025-05-14 22:00:07.465 *** 2025-05-14 22:00:07.465 Process diagnostic dump for ORACLE.EXE (W000), OS id=9468, pid: 25, proc_ser: 199, sid: 201, sess_ser: 15805 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=148 seq_num=149 snap_id=1 wait times: snap=0.895538 sec, exc=0.895538 sec, total=0.895538 sec wait times: max=5.000000 sec, heur=2 min 26 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.000038 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=147 seq_num=148 snap_id=1 wait times: snap=5.000510 sec, exc=5.000510 sec, total=5.000510 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=146 seq_num=147 snap_id=1 wait times: snap=5.000301 sec, exc=5.000301 sec, total=5.000301 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000038 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=145 seq_num=146 snap_id=1 wait times: snap=5.013588 sec, exc=5.013588 sec, total=5.013588 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000040 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=144 seq_num=145 snap_id=1 wait times: snap=5.010174 sec, exc=5.010174 sec, total=5.010174 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=143 seq_num=144 snap_id=1 wait times: snap=5.009220 sec, exc=5.009220 sec, total=5.009220 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=142 seq_num=143 snap_id=1 wait times: snap=5.004641 sec, exc=5.004641 sec, total=5.004641 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=141 seq_num=142 snap_id=1 wait times: snap=5.007223 sec, exc=5.007223 sec, total=5.007223 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=140 seq_num=141 snap_id=1 wait times: snap=5.001303 sec, exc=5.001303 sec, total=5.001303 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=139 seq_num=140 snap_id=1 wait times: snap=5.012401 sec, exc=5.012401 sec, total=5.012401 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000029 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=138 seq_num=139 snap_id=1 wait times: snap=5.007530 sec, exc=5.007530 sec, total=5.007530 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time Sampled Session History of session 201 serial 15805 --------------------------------------------------- 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:07 - 22:00:07] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-14 22:00:07.465 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 9468, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-14 19:37:47.907848 :9715054B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 19:47:48.803722 :9715C9B3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 19:47:49.303067 :9715CA00:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 19:47:49.298 2025-05-14 19:47:49.303069 :9715CA01:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11808 pso_num=25 pso_serial#=184 2025-05-14 19:47:49.303203 :9715CA02:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11808 osp_idx=23 osp_ver=95298 osp_pg=0 (spawn #182183) 2025-05-14 19:47:49.303204 :9715CA03:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 19:47:49.303205 :9715CA04:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=250 time=227879172 2025-05-14 19:47:49.303205 :9715CA05:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 19:47:49.303206 :9715CA06:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 19:47:49.303206 :9715CA07:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 19:47:49.303206 :9715CA08:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 19:47:49.303206 :9715CA09:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 19:47:49.303688 :9715CA0A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 19:47:49.303731 :9715CA13:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 19:55:07.624043 :971659C5:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 19:57:50.663127 :97168F0D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:07:51.533559 :97175BFE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:07:51.913071 :97175C40:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:07:51.908 2025-05-14 20:07:51.913072 :97175C41:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10372 pso_num=25 pso_serial#=185 2025-05-14 20:07:51.913210 :97175C42:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10372 osp_idx=23 osp_ver=95299 osp_pg=0 (spawn #182230) 2025-05-14 20:07:51.913211 :97175C43:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 20:07:51.913212 :97175C44:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=251 time=229081782 2025-05-14 20:07:51.913212 :97175C45:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 20:07:51.913213 :97175C46:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 20:07:51.913213 :97175C47:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 20:07:51.913214 :97175C48:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 20:07:51.913214 :97175C49:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 20:07:51.913707 :97175C4A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 20:07:51.913751 :97175C52:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:17:52.850332 :9718230A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:17:53.019787 :97182335:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:17:53.006 2025-05-14 20:17:53.019789 :97182336:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13212 pso_num=25 pso_serial#=186 2025-05-14 20:17:53.019922 :97182337:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=13212 (legacy spawn) 2025-05-14 20:17:53.026354 :97182338:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-14 20:17:53.026383 :9718233B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-14 20:17:53.026526 :9718233E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:17:53.027319 :9718234F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:17:53.036004 :97182352:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:17:53.021 2025-05-14 20:17:53.036006 :97182353:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13272 pso_num=25 pso_serial#=187 2025-05-14 20:17:53.036149 :97182354:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=13272 (legacy spawn) 2025-05-14 20:17:53.042635 :97182355:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-14 20:17:53.042796 :9718235E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:17:53.043590 :9718235F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:17:53.292459 :97182396:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:17:53.287 2025-05-14 20:17:53.292461 :97182397:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12352 pso_num=25 pso_serial#=188 2025-05-14 20:17:53.292602 :97182398:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12352 osp_idx=23 osp_ver=95302 osp_pg=0 (spawn #182253) 2025-05-14 20:17:53.292603 :97182399:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 20:17:53.292603 :9718239A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=252 time=229683157 2025-05-14 20:17:53.292603 :9718239B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 20:17:53.292604 :9718239C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 20:17:53.292604 :9718239D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 20:17:53.292604 :9718239E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 20:17:53.292605 :9718239F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 20:17:53.293099 :971823A0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 20:17:53.293145 :971823A8:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:27:54.194846 :9718E854:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:27:54.234211 :9718E857:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:27:54.226 2025-05-14 20:27:54.234213 :9718E858:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=3624 pso_num=25 pso_serial#=189 2025-05-14 20:27:54.234351 :9718E859:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=3624 (legacy spawn) 2025-05-14 20:27:54.240843 :9718E85A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-14 20:27:54.241017 :9718E85F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:27:54.241844 :9718E864:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:27:54.574605 :9718E8CC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:27:54.570 2025-05-14 20:27:54.574608 :9718E8CD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12740 pso_num=25 pso_serial#=190 2025-05-14 20:27:54.574755 :9718E8CE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12740 osp_idx=23 osp_ver=95304 osp_pg=0 (spawn #182276) 2025-05-14 20:27:54.574756 :9718E8CF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 20:27:54.574756 :9718E8D0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=253 time=230284438 2025-05-14 20:27:54.574757 :9718E8D1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 20:27:54.574757 :9718E8D2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 20:27:54.574758 :9718E8D3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 20:27:54.574758 :9718E8D4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 20:27:54.574759 :9718E8D5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 20:27:54.575293 :9718E8D6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 20:27:54.575345 :9718E8DD:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:37:55.610936 :9719AE3E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:37:55.943603 :9719AE9C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:37:55.939 2025-05-14 20:37:55.943605 :9719AE9D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13184 pso_num=25 pso_serial#=191 2025-05-14 20:37:55.943740 :9719AE9E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13184 osp_idx=23 osp_ver=95305 osp_pg=0 (spawn #182298) 2025-05-14 20:37:55.943741 :9719AE9F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 20:37:55.943742 :9719AEA0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=254 time=230885813 2025-05-14 20:37:55.943742 :9719AEA1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 20:37:55.943742 :9719AEA2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 20:37:55.943743 :9719AEA3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 20:37:55.943743 :9719AEA4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 20:37:55.943743 :9719AEA5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 20:37:55.944236 :9719AEA6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 20:37:55.944280 :9719AEAF:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:47:56.930551 :971A73E6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:47:57.247691 :971A7451:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:47:57.243 2025-05-14 20:47:57.247693 :971A7452:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11580 pso_num=25 pso_serial#=192 2025-05-14 20:47:57.247822 :971A7453:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11580 osp_idx=23 osp_ver=95306 osp_pg=0 (spawn #182321) 2025-05-14 20:47:57.247823 :971A7454:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 20:47:57.247823 :971A7455:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=255 time=231487125 2025-05-14 20:47:57.247824 :971A7456:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 20:47:57.247824 :971A7457:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 20:47:57.247824 :971A7458:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 20:47:57.247825 :971A7459:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 20:47:57.247825 :971A745A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 20:47:57.248295 :971A745B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 20:47:57.248382 :971A7465:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 20:57:58.153377 :971B3927:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 20:57:58.486262 :971B395E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 20:57:58.481 2025-05-14 20:57:58.486265 :971B395F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12616 pso_num=25 pso_serial#=193 2025-05-14 20:57:58.486413 :971B3960:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12616 osp_idx=23 osp_ver=95307 osp_pg=0 (spawn #182344) 2025-05-14 20:57:58.486414 :971B3961:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 20:57:58.486414 :971B3962:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=0 time=232088360 2025-05-14 20:57:58.486414 :971B3963:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 20:57:58.486414 :971B3964:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 20:57:58.486414 :971B3965:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 20:57:58.486415 :971B3966:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 20:57:58.486415 :971B3967:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 20:57:58.486911 :971B3968:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 20:57:58.486965 :971B396F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 21:07:59.349065 :971C0928:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 21:07:59.637052 :971C092B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 21:07:59.625 2025-05-14 21:07:59.637054 :971C092C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10992 pso_num=25 pso_serial#=194 2025-05-14 21:07:59.637191 :971C092D:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10992 (legacy spawn) 2025-05-14 21:07:59.657615 :971C092E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-14 21:07:59.657798 :971C0933:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 21:07:59.658651 :971C0938:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 21:07:59.832475 :971C096D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 21:07:59.828 2025-05-14 21:07:59.832477 :971C096E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=5020 pso_num=25 pso_serial#=195 2025-05-14 21:07:59.832609 :971C096F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=5020 osp_idx=23 osp_ver=95309 osp_pg=0 (spawn #182369) 2025-05-14 21:07:59.832610 :971C0970:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 21:07:59.832610 :971C0971:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=1 time=232689704 2025-05-14 21:07:59.832611 :971C0972:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 21:07:59.832611 :971C0973:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 21:07:59.832612 :971C0974:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 21:07:59.832612 :971C0975:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 21:07:59.832612 :971C0976:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 21:07:59.833144 :971C0977:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 21:07:59.833189 :971C0980:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 21:18:00.836182 :971CCFBB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 21:18:01.080398 :971CCFEF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 21:18:01.075 2025-05-14 21:18:01.080400 :971CCFF0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11412 pso_num=25 pso_serial#=196 2025-05-14 21:18:01.080547 :971CCFF1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11412 osp_idx=23 osp_ver=95310 osp_pg=0 (spawn #182392) 2025-05-14 21:18:01.080548 :971CCFF2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 21:18:01.080549 :971CCFF3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=2 time=233290954 2025-05-14 21:18:01.080549 :971CCFF4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 21:18:01.080549 :971CCFF5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 21:18:01.080550 :971CCFF6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 21:18:01.080550 :971CCFF7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 21:18:01.080550 :971CCFF8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 21:18:01.081047 :971CCFF9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 21:18:01.081091 :971CD002:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 21:28:01.991612 :971D9465:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 21:28:02.433785 :971D94AD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 21:28:02.429 2025-05-14 21:28:02.433787 :971D94AE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=5024 pso_num=25 pso_serial#=197 2025-05-14 21:28:02.433923 :971D94AF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=5024 osp_idx=23 osp_ver=95311 osp_pg=0 (spawn #182415) 2025-05-14 21:28:02.433924 :971D94B0:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 21:28:02.433924 :971D94B1:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=3 time=233892297 2025-05-14 21:28:02.433925 :971D94B2:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 21:28:02.433925 :971D94B3:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 21:28:02.433925 :971D94B4:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 21:28:02.433926 :971D94B5:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 21:28:02.433926 :971D94B6:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 21:28:02.434501 :971D94B7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 21:28:02.434546 :971D94BF:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 21:38:03.414640 :971E59DE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 21:38:03.763620 :971E5A21:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 21:38:03.758 2025-05-14 21:38:03.763621 :971E5A22:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7912 pso_num=25 pso_serial#=198 2025-05-14 21:38:03.763771 :971E5A23:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7912 osp_idx=23 osp_ver=95312 osp_pg=0 (spawn #182437) 2025-05-14 21:38:03.763772 :971E5A24:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 21:38:03.763772 :971E5A25:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=4 time=234493625 2025-05-14 21:38:03.763772 :971E5A26:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 21:38:03.763772 :971E5A27:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 21:38:03.763773 :971E5A28:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 21:38:03.763773 :971E5A29:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 21:38:03.763773 :971E5A2A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 21:38:03.764308 :971E5A2B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 21:38:03.764348 :971E5A35:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 21:48:04.720542 :971F1F86:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-14 21:48:05.162682 :971F1FBE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-14 21:48:05.158 2025-05-14 21:48:05.162684 :971F1FBF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9468 pso_num=25 pso_serial#=199 2025-05-14 21:48:05.162817 :971F1FC0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9468 osp_idx=23 osp_ver=95313 osp_pg=0 (spawn #182460) 2025-05-14 21:48:05.162817 :971F1FC1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-14 21:48:05.162817 :971F1FC2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=5 time=235095032 2025-05-14 21:48:05.162817 :971F1FC3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-14 21:48:05.162818 :971F1FC4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-14 21:48:05.162818 :971F1FC5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-14 21:48:05.162819 :971F1FC6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-14 21:48:05.162819 :971F1FC7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-14 21:48:05.163335 :971F1FC8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-14 21:48:05.163385 :971F1FD2:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 21:57:41.040305 :971FDB88:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-14 21:58:06.431369 :971FE47E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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 25 (osid: 9468, W000)