Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250426100554\orcl_w000_9676_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:37593M/63366M, Ph+PgF:45279M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 9676, image: ORACLE.EXE (W000) *** 2025-04-26 10:05:54.771 *** SESSION ID:(201.15327) 2025-04-26 10:05:54.771 *** 2025-04-26 10:05:54.771 Process diagnostic dump for ORACLE.EXE (W000), OS id=9676, pid: 25, proc_ser: 12, sid: 201, sess_ser: 15327 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=71 seq_num=72 snap_id=1 wait times: snap=4.416804 sec, exc=4.416804 sec, total=4.416804 sec wait times: max=5.000000 sec, heur=5 min 54 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000021 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=70 seq_num=71 snap_id=1 wait times: snap=5.014165 sec, exc=5.014165 sec, total=5.014165 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=69 seq_num=70 snap_id=1 wait times: snap=5.010156 sec, exc=5.010156 sec, total=5.010156 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=68 seq_num=69 snap_id=1 wait times: snap=5.004217 sec, exc=5.004217 sec, total=5.004217 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=67 seq_num=68 snap_id=1 wait times: snap=5.003223 sec, exc=5.003223 sec, total=5.003223 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=66 seq_num=67 snap_id=1 wait times: snap=5.000361 sec, exc=5.000361 sec, total=5.000361 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000030 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=65 seq_num=66 snap_id=1 wait times: snap=5.007715 sec, exc=5.007715 sec, total=5.007715 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=64 seq_num=65 snap_id=1 wait times: snap=5.004734 sec, exc=5.004734 sec, total=5.004734 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=63 seq_num=64 snap_id=1 wait times: snap=5.010139 sec, exc=5.010139 sec, total=5.010139 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=62 seq_num=63 snap_id=1 wait times: snap=5.014728 sec, exc=5.014728 sec, total=5.014728 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=61 seq_num=62 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.000022 sec of elapsed time Sampled Session History of session 201 serial 15327 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [121 samples, 10:03:54 - 10:05:54] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-26 10:05:54.771 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 9676, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-26 07:19:40.622296 :8EE8EC5D: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-04-26 07:27:20.108654 :8EE98611: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-04-26 07:29:41.817013 :8EE9B657: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-04-26 07:39:42.752769 :8EEA8128:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 07:39:42.960391 :8EEA814A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 07:39:42.955 2025-04-26 07:39:42.960393 :8EEA814B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9656 pso_num=25 pso_serial#=254 2025-04-26 07:39:42.960528 :8EEA814C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9656 osp_idx=23 osp_ver=65278 osp_pg=0 (spawn #119574) 2025-04-26 07:39:42.960529 :8EEA814D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 07:39:42.960529 :8EEA814E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=217 time=2923984750 2025-04-26 07:39:42.960529 :8EEA814F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 07:39:42.960529 :8EEA8150:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 07:39:42.960530 :8EEA8151:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 07:39:42.960530 :8EEA8152:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 07:39:42.960530 :8EEA8153:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 07:39:42.961016 :8EEA8154: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-04-26 07:39:42.961065 :8EEA815D: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-04-26 07:49:43.837076 :8EEB4BC8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 07:49:44.107437 :8EEB4C25:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 07:49:44.102 2025-04-26 07:49:44.107439 :8EEB4C26:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7916 pso_num=25 pso_serial#=255 2025-04-26 07:49:44.107575 :8EEB4C27:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7916 osp_idx=23 osp_ver=65279 osp_pg=0 (spawn #119596) 2025-04-26 07:49:44.107576 :8EEB4C28:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 07:49:44.107576 :8EEB4C29:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=218 time=2924585906 2025-04-26 07:49:44.107577 :8EEB4C2A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 07:49:44.107577 :8EEB4C2B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 07:49:44.107577 :8EEB4C2C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 07:49:44.107578 :8EEB4C2D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 07:49:44.107578 :8EEB4C2E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 07:49:44.108077 :8EEB4C2F: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-04-26 07:49:44.108124 :8EEB4C36: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-04-26 07:59:44.901985 :8EEC1666:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 07:59:45.234736 :8EEC16B3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 07:59:45.229 2025-04-26 07:59:45.234737 :8EEC16B4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10252 pso_num=25 pso_serial#=1 2025-04-26 07:59:45.234872 :8EEC16B5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10252 osp_idx=23 osp_ver=65280 osp_pg=0 (spawn #119619) 2025-04-26 07:59:45.234873 :8EEC16B6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 07:59:45.234873 :8EEC16B7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=219 time=2925187031 2025-04-26 07:59:45.234873 :8EEC16B8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 07:59:45.234874 :8EEC16B9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 07:59:45.234874 :8EEC16BA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 07:59:45.234874 :8EEC16BB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 07:59:45.234874 :8EEC16BC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 07:59:45.235356 :8EEC16BD: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-04-26 07:59:45.235399 :8EEC16C5: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-04-26 08:09:46.172970 :8EECEBC5:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 08:09:46.490639 :8EECEBF4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 08:09:46.485 2025-04-26 08:09:46.490642 :8EECEBF5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7696 pso_num=25 pso_serial#=2 2025-04-26 08:09:46.490792 :8EECEBF6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7696 osp_idx=23 osp_ver=65281 osp_pg=0 (spawn #119647) 2025-04-26 08:09:46.490793 :8EECEBF7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 08:09:46.490794 :8EECEBF8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=220 time=2925788281 2025-04-26 08:09:46.490794 :8EECEBF9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 08:09:46.490795 :8EECEBFA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 08:09:46.490795 :8EECEBFB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 08:09:46.490795 :8EECEBFC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 08:09:46.490796 :8EECEBFD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 08:09:46.491373 :8EECEBFE: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-04-26 08:09:46.491443 :8EECEC08: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-04-26 08:19:47.410676 :8EEDB5E4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 08:19:47.696578 :8EEDB606:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 08:19:47.692 2025-04-26 08:19:47.696580 :8EEDB607:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9796 pso_num=25 pso_serial#=3 2025-04-26 08:19:47.696711 :8EEDB608:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9796 osp_idx=23 osp_ver=65282 osp_pg=0 (spawn #119669) 2025-04-26 08:19:47.696712 :8EEDB609:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 08:19:47.696712 :8EEDB60A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=221 time=2926389500 2025-04-26 08:19:47.696713 :8EEDB60B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 08:19:47.696713 :8EEDB60C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 08:19:47.696714 :8EEDB60D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 08:19:47.696714 :8EEDB60E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 08:19:47.696714 :8EEDB60F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 08:19:47.697247 :8EEDB610: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-04-26 08:19:47.697290 :8EEDB617: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-04-26 08:29:48.559290 :8EEE802B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 08:29:48.798427 :8EEE805A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 08:29:48.794 2025-04-26 08:29:48.798430 :8EEE805B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9736 pso_num=25 pso_serial#=4 2025-04-26 08:29:48.798573 :8EEE805C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9736 osp_idx=23 osp_ver=65283 osp_pg=0 (spawn #119692) 2025-04-26 08:29:48.798574 :8EEE805D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 08:29:48.798575 :8EEE805E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=222 time=2926990593 2025-04-26 08:29:48.798575 :8EEE805F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 08:29:48.798575 :8EEE8060:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 08:29:48.798576 :8EEE8061:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 08:29:48.798576 :8EEE8062:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 08:29:48.798577 :8EEE8063:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 08:29:48.799076 :8EEE8064: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-04-26 08:29:48.799123 :8EEE806B: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-04-26 08:39:49.680241 :8EEF4ADD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 08:39:49.966146 :8EEF4B0E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 08:39:49.961 2025-04-26 08:39:49.966149 :8EEF4B0F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10892 pso_num=25 pso_serial#=5 2025-04-26 08:39:49.966286 :8EEF4B10:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10892 osp_idx=23 osp_ver=65284 osp_pg=0 (spawn #119715) 2025-04-26 08:39:49.966287 :8EEF4B11:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 08:39:49.966288 :8EEF4B12:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=223 time=2927591765 2025-04-26 08:39:49.966288 :8EEF4B13:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 08:39:49.966290 :8EEF4B14:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 08:39:49.966290 :8EEF4B15:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 08:39:49.966291 :8EEF4B16:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 08:39:49.966291 :8EEF4B17:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 08:39:49.966791 :8EEF4B18: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-04-26 08:39:49.966838 :8EEF4B1F: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-04-26 08:49:50.882583 :8EF0165B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 08:49:51.121639 :8EF0168C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 08:49:51.117 2025-04-26 08:49:51.121641 :8EF0168D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10556 pso_num=25 pso_serial#=6 2025-04-26 08:49:51.121776 :8EF0168E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10556 osp_idx=23 osp_ver=65285 osp_pg=0 (spawn #119738) 2025-04-26 08:49:51.121776 :8EF0168F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 08:49:51.121777 :8EF01690:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=224 time=2928192921 2025-04-26 08:49:51.121777 :8EF01691:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 08:49:51.121778 :8EF01692:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 08:49:51.121778 :8EF01693:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 08:49:51.121779 :8EF01694:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 08:49:51.121780 :8EF01695:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 08:49:51.122265 :8EF01696: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-04-26 08:49:51.122307 :8EF0169E: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-04-26 08:59:51.973033 :8EF0E0CF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 08:59:52.368123 :8EF0E0F1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 08:59:52.363 2025-04-26 08:59:52.368125 :8EF0E0F2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9860 pso_num=25 pso_serial#=7 2025-04-26 08:59:52.368260 :8EF0E0F3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9860 osp_idx=23 osp_ver=65286 osp_pg=0 (spawn #119761) 2025-04-26 08:59:52.368261 :8EF0E0F4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 08:59:52.368262 :8EF0E0F5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=225 time=2928794171 2025-04-26 08:59:52.368262 :8EF0E0F6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 08:59:52.368262 :8EF0E0F7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 08:59:52.368263 :8EF0E0F8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 08:59:52.368263 :8EF0E0F9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 08:59:52.368263 :8EF0E0FA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 08:59:52.368742 :8EF0E0FB: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-04-26 08:59:52.368798 :8EF0E105: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-04-26 09:09:53.280547 :8EF1B758:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 09:09:53.597649 :8EF1B788:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 09:09:53.592 2025-04-26 09:09:53.597651 :8EF1B789:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7136 pso_num=25 pso_serial#=8 2025-04-26 09:09:53.597785 :8EF1B78A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7136 osp_idx=23 osp_ver=65287 osp_pg=0 (spawn #119789) 2025-04-26 09:09:53.597785 :8EF1B78B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 09:09:53.597786 :8EF1B78C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=226 time=2929395390 2025-04-26 09:09:53.597786 :8EF1B78D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 09:09:53.597786 :8EF1B78E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 09:09:53.597786 :8EF1B78F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 09:09:53.597787 :8EF1B790:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 09:09:53.597787 :8EF1B791:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 09:09:53.598277 :8EF1B792: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-04-26 09:09:53.598323 :8EF1B799: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-04-26 09:19:54.536817 :8EF2810C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 09:19:54.807089 :8EF2812E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 09:19:54.802 2025-04-26 09:19:54.807091 :8EF2812F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11044 pso_num=25 pso_serial#=9 2025-04-26 09:19:54.807225 :8EF28130:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11044 osp_idx=23 osp_ver=65288 osp_pg=0 (spawn #119811) 2025-04-26 09:19:54.807226 :8EF28131:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 09:19:54.807226 :8EF28132:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=227 time=2929996609 2025-04-26 09:19:54.807227 :8EF28133:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 09:19:54.807227 :8EF28134:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 09:19:54.807227 :8EF28135:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 09:19:54.807228 :8EF28136:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 09:19:54.807228 :8EF28137:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 09:19:54.807766 :8EF28138: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-04-26 09:19:54.807811 :8EF28140: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-04-26 09:27:40.088912 :8EF31D4C: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-04-26 09:29:56.076641 :8EF34B71: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-04-26 09:39:56.914293 :8EF4156E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 09:39:57.293755 :8EF41591:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 09:39:57.289 2025-04-26 09:39:57.293757 :8EF41592:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9788 pso_num=25 pso_serial#=10 2025-04-26 09:39:57.293901 :8EF41593:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9788 osp_idx=23 osp_ver=65289 osp_pg=0 (spawn #119856) 2025-04-26 09:39:57.293903 :8EF41594:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 09:39:57.293904 :8EF41595:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=228 time=2931199093 2025-04-26 09:39:57.293905 :8EF41596:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 09:39:57.293905 :8EF41597:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 09:39:57.293905 :8EF41598:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 09:39:57.293906 :8EF41599:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 09:39:57.293906 :8EF4159A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 09:39:57.294417 :8EF4159B: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-04-26 09:39:57.294463 :8EF415A2: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-04-26 09:49:58.106961 :8EF4DFF3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 09:49:58.565500 :8EF4E020:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 09:49:58.559 2025-04-26 09:49:58.565502 :8EF4E021:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10432 pso_num=25 pso_serial#=11 2025-04-26 09:49:58.565650 :8EF4E022:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10432 osp_idx=23 osp_ver=65290 osp_pg=0 (spawn #119878) 2025-04-26 09:49:58.565651 :8EF4E023:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 09:49:58.565651 :8EF4E024:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=229 time=2931800359 2025-04-26 09:49:58.565652 :8EF4E025:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 09:49:58.565652 :8EF4E026:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 09:49:58.565653 :8EF4E027:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 09:49:58.565653 :8EF4E028:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 09:49:58.565654 :8EF4E029:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 09:49:58.566245 :8EF4E02A: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-04-26 09:49:58.566319 :8EF4E034: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-04-26 09:59:59.440588 :8EF5AA50:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-26 09:59:59.867015 :8EF5AA73:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-26 09:59:59.862 2025-04-26 09:59:59.867016 :8EF5AA74:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9676 pso_num=25 pso_serial#=12 2025-04-26 09:59:59.867152 :8EF5AA75:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9676 osp_idx=23 osp_ver=65291 osp_pg=0 (spawn #119901) 2025-04-26 09:59:59.867153 :8EF5AA76:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 09:59:59.867153 :8EF5AA77:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=230 time=2932401656 2025-04-26 09:59:59.867153 :8EF5AA78:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 09:59:59.867154 :8EF5AA79:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 09:59:59.867154 :8EF5AA7A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 09:59:59.867154 :8EF5AA7B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 09:59:59.867154 :8EF5AA7C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 09:59:59.867640 :8EF5AA7D: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-04-26 09:59:59.867676 :8EF5AA87: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 9676, W000)