Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250626080214\orcl_m002_15096_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:36333M/63366M, Ph+PgF:42475M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 15096, image: ORACLE.EXE (M002) *** 2025-06-26 08:02:14.130 *** SESSION ID:(201.47737) 2025-06-26 08:02:14.130 *** 2025-06-26 08:02:14.130 Process diagnostic dump for ORACLE.EXE (M002), OS id=15096, pid: 25, proc_ser: 63, sid: 201, sess_ser: 47737 ------------------------------------------------------------------------------- current sql: Current Wait Stack: Not in wait; last wait ended 0.000084 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000108 sec since last wait 0: waited for 'db file sequential read' file#=0x2, block#=0x88ca, blocks=0x1 wait_id=1821 seq_num=1822 snap_id=1 wait times: snap=0.001505 sec, exc=0.001505 sec, total=0.001505 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000332 sec of elapsed time 1: waited for 'db file sequential read' file#=0x2, block#=0x7c3a, blocks=0x1 wait_id=1820 seq_num=1821 snap_id=1 wait times: snap=0.005277 sec, exc=0.005277 sec, total=0.005277 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000356 sec of elapsed time 2: waited for 'db file sequential read' file#=0x2, block#=0x883a, blocks=0x1 wait_id=1819 seq_num=1820 snap_id=1 wait times: snap=0.005566 sec, exc=0.005566 sec, total=0.005566 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000378 sec of elapsed time 3: waited for 'db file sequential read' file#=0x2, block#=0x8d4a, blocks=0x1 wait_id=1818 seq_num=1819 snap_id=1 wait times: snap=0.004781 sec, exc=0.004781 sec, total=0.004781 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000373 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0xe972, blocks=0x1 wait_id=1817 seq_num=1818 snap_id=1 wait times: snap=0.005232 sec, exc=0.005232 sec, total=0.005232 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000318 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x893a, blocks=0x1 wait_id=1816 seq_num=1817 snap_id=1 wait times: snap=0.003324 sec, exc=0.003324 sec, total=0.003324 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000165 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x8812, blocks=0x1 wait_id=1815 seq_num=1816 snap_id=1 wait times: snap=0.000861 sec, exc=0.000861 sec, total=0.000861 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000134 sec of elapsed time 7: waited for 'db file sequential read' file#=0x2, block#=0x7c0a, blocks=0x1 wait_id=1814 seq_num=1815 snap_id=1 wait times: snap=0.000133 sec, exc=0.000133 sec, total=0.000133 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000135 sec of elapsed time 8: waited for 'db file sequential read' file#=0x2, block#=0x876a, blocks=0x1 wait_id=1813 seq_num=1814 snap_id=1 wait times: snap=0.000049 sec, exc=0.000049 sec, total=0.000049 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000136 sec of elapsed time 9: waited for 'db file sequential read' file#=0x2, block#=0x8752, blocks=0x1 wait_id=1812 seq_num=1813 snap_id=1 wait times: snap=0.000049 sec, exc=0.000049 sec, total=0.000049 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000143 sec of elapsed time Sampled Session History of session 201 serial 47737 --------------------------------------------------- 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 --------------------------------------------------- [1 sample, 08:02:14] not in wait at each sample [1 sample, 08:02:13] idle wait at each sample [session created at: 08:02:13] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-26 08:02:14.130 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 15096, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-26 07:50:23.624638 :A9CA4456:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:50:23.624638 :A9CA4457:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:50:23.624639 :A9CA4458:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:50:23.624639 :A9CA4459:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:50:23.625146 :A9CA445A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:50:23.625185 :A9CA4460:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-26 07:50:23.629205 :A9CA4494:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-26 07:50:23.629252 :A9CA4495:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-26 07:50:23.629522 :A9CA4496:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-26 07:50:23.629539 :A9CA4497:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-26 07:50:23.629759 :A9CA4498:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-26 07:50:23.629772 :A9CA4499:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-26 07:50:23.629984 :A9CA449A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-26 07:50:23.629997 :A9CA449B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-26 07:50:23.630203 :A9CA449C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-26 07:50:23.630216 :A9CA449D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-26 07:50:23.630426 :A9CA449E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-06-26 07:50:23.630438 :A9CA449F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-06-26 07:50:23.632922 :A9CA44A0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:50:23.640144 :A9CA44CD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:50:23.637 2025-06-26 07:50:23.640146 :A9CA44CE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4288 pso_num=25 pso_serial#=50 2025-06-26 07:50:23.640336 :A9CA44CF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4288 osp_idx=23 osp_ver=169227 osp_pg=0 (spawn #323858) 2025-06-26 07:50:23.640337 :A9CA44D0:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:50:23.640339 :A9CA44D1:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=26 time=3899966829 2025-06-26 07:50:23.640339 :A9CA44D2:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:50:23.640340 :A9CA44D3:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:50:23.640341 :A9CA44D4:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:50:23.640342 :A9CA44D5:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:50:23.640342 :A9CA44D6:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:50:23.640948 :A9CA44D7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:50:53.732664 :A9CA4E84:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:51:23.722481 :A9CA584D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:51:23.711 2025-06-26 07:51:23.722484 :A9CA584E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17352 pso_num=25 pso_serial#=51 2025-06-26 07:51:23.722608 :A9CA584F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17352 osp_idx=23 osp_ver=169228 osp_pg=0 (spawn #323860) 2025-06-26 07:51:23.722609 :A9CA5850:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:51:23.722609 :A9CA5851:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=27 time=3900026907 2025-06-26 07:51:23.722609 :A9CA5852:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:51:23.722610 :A9CA5853:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:51:23.722610 :A9CA5854:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:51:23.722610 :A9CA5855:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:51:23.722611 :A9CA5856:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:51:23.723109 :A9CA5857:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:51:53.817285 :A9CA6270:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:52:23.785540 :A9CA6C1E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:52:23.774 2025-06-26 07:52:23.785542 :A9CA6C1F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15740 pso_num=25 pso_serial#=52 2025-06-26 07:52:23.785682 :A9CA6C20:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15740 osp_idx=23 osp_ver=169229 osp_pg=0 (spawn #323862) 2025-06-26 07:52:23.785683 :A9CA6C21:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:52:23.785684 :A9CA6C22:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=28 time=3900086969 2025-06-26 07:52:23.785684 :A9CA6C23:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:52:23.785685 :A9CA6C24:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:52:23.785685 :A9CA6C25:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:52:23.785685 :A9CA6C26:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:52:23.785686 :A9CA6C27:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:52:23.786161 :A9CA6C28:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:52:48.798627 :A9CA759A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-26 07:53:18.850162 :A9CA7F38:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:53:23.855170 :A9CA80FC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:53:23.844 2025-06-26 07:53:23.855173 :A9CA80FD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12108 pso_num=25 pso_serial#=53 2025-06-26 07:53:23.855307 :A9CA80FE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12108 osp_idx=23 osp_ver=169230 osp_pg=0 (spawn #323864) 2025-06-26 07:53:23.855307 :A9CA80FF:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:53:23.855308 :A9CA8100:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=29 time=3900147032 2025-06-26 07:53:23.855308 :A9CA8101:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:53:23.855309 :A9CA8102:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:53:23.855310 :A9CA8103:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:53:23.855310 :A9CA8104:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:53:23.855310 :A9CA8105:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:53:23.855815 :A9CA8106:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:53:53.949378 :A9CA8AC1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:54:23.966741 :A9CA9497:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:54:23.956 2025-06-26 07:54:23.966743 :A9CA9498:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11308 pso_num=25 pso_serial#=54 2025-06-26 07:54:23.966862 :A9CA9499:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11308 osp_idx=23 osp_ver=169231 osp_pg=0 (spawn #323866) 2025-06-26 07:54:23.966863 :A9CA949A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:54:23.966863 :A9CA949B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=30 time=3900207157 2025-06-26 07:54:23.966864 :A9CA949C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:54:23.966864 :A9CA949D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:54:23.966864 :A9CA949E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:54:23.966865 :A9CA949F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:54:23.966865 :A9CA94A0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:54:23.967337 :A9CA94A1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:54:54.039705 :A9CA9EBB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:55:24.043258 :A9CAA884:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:55:24.032 2025-06-26 07:55:24.043261 :A9CAA885:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17844 pso_num=25 pso_serial#=55 2025-06-26 07:55:24.043397 :A9CAA886:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17844 osp_idx=23 osp_ver=169232 osp_pg=0 (spawn #323868) 2025-06-26 07:55:24.043398 :A9CAA887:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:55:24.043398 :A9CAA888:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=31 time=3900267235 2025-06-26 07:55:24.043399 :A9CAA889:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:55:24.043399 :A9CAA88A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:55:24.043399 :A9CAA88B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:55:24.043400 :A9CAA88C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:55:24.043400 :A9CAA88D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:55:24.043898 :A9CAA88E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:55:54.151085 :A9CAB2C6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:56:24.117809 :A9CABC98:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:56:24.106 2025-06-26 07:56:24.117811 :A9CABC99:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=5876 pso_num=25 pso_serial#=56 2025-06-26 07:56:24.117944 :A9CABC9A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=5876 osp_idx=23 osp_ver=169233 osp_pg=0 (spawn #323870) 2025-06-26 07:56:24.117945 :A9CABC9B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:56:24.117946 :A9CABC9C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=32 time=3900327297 2025-06-26 07:56:24.117946 :A9CABC9D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:56:24.117946 :A9CABC9E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:56:24.117947 :A9CABC9F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:56:24.117947 :A9CABCA0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:56:24.117947 :A9CABCA1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:56:24.118422 :A9CABCA2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:56:54.220928 :A9CAC66D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:57:24.221895 :A9CAD018:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:57:24.211 2025-06-26 07:57:24.221897 :A9CAD019:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9904 pso_num=25 pso_serial#=57 2025-06-26 07:57:24.222030 :A9CAD01A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9904 osp_idx=23 osp_ver=169234 osp_pg=0 (spawn #323872) 2025-06-26 07:57:24.222031 :A9CAD01B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:57:24.222031 :A9CAD01C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=33 time=3900387407 2025-06-26 07:57:24.222032 :A9CAD01D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:57:24.222032 :A9CAD01E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:57:24.222033 :A9CAD01F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:57:24.222033 :A9CAD020:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:57:24.222033 :A9CAD021:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:57:24.222515 :A9CAD022:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:57:54.314089 :A9CADAA6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:58:24.312450 :A9CAE471:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:58:24.301 2025-06-26 07:58:24.312452 :A9CAE472:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17936 pso_num=25 pso_serial#=58 2025-06-26 07:58:24.312573 :A9CAE473:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17936 osp_idx=23 osp_ver=169235 osp_pg=0 (spawn #323875) 2025-06-26 07:58:24.312574 :A9CAE474:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:58:24.312575 :A9CAE475:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=34 time=3900447500 2025-06-26 07:58:24.312575 :A9CAE476:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:58:24.312576 :A9CAE477:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:58:24.312576 :A9CAE478:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:58:24.312577 :A9CAE479:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:58:24.312577 :A9CAE47A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:58:24.313063 :A9CAE47B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:58:54.394788 :A9CAEE57:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 07:59:24.384811 :A9CAF805:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 07:59:24.374 2025-06-26 07:59:24.384813 :A9CAF806:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10376 pso_num=25 pso_serial#=59 2025-06-26 07:59:24.384937 :A9CAF807:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10376 osp_idx=23 osp_ver=169236 osp_pg=0 (spawn #323877) 2025-06-26 07:59:24.384938 :A9CAF808:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 07:59:24.384938 :A9CAF809:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=35 time=3900507563 2025-06-26 07:59:24.384939 :A9CAF80A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 07:59:24.384939 :A9CAF80B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 07:59:24.384940 :A9CAF80C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 07:59:24.384940 :A9CAF80D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 07:59:24.384940 :A9CAF80E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 07:59:24.385412 :A9CAF80F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 07:59:54.491189 :A9CB020C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 08:00:24.447339 :A9CB0C13:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 08:00:24.436 2025-06-26 08:00:24.447341 :A9CB0C14:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9636 pso_num=25 pso_serial#=60 2025-06-26 08:00:24.447471 :A9CB0C15:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9636 osp_idx=23 osp_ver=169237 osp_pg=0 (spawn #323879) 2025-06-26 08:00:24.447471 :A9CB0C16:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 08:00:24.447472 :A9CB0C17:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=36 time=3900567625 2025-06-26 08:00:24.447472 :A9CB0C18:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 08:00:24.447473 :A9CB0C19:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 08:00:24.447473 :A9CB0C1A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 08:00:24.447473 :A9CB0C1B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 08:00:24.447473 :A9CB0C1C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 08:00:24.448020 :A9CB0C1D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 08:00:54.530547 :A9CB188D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 08:01:24.543845 :A9CB2258:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 08:01:24.533 2025-06-26 08:01:24.543847 :A9CB2259:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16852 pso_num=25 pso_serial#=61 2025-06-26 08:01:24.543978 :A9CB225A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16852 osp_idx=23 osp_ver=169238 osp_pg=0 (spawn #323885) 2025-06-26 08:01:24.543979 :A9CB225B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 08:01:24.543979 :A9CB225C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=37 time=3900627735 2025-06-26 08:01:24.543979 :A9CB225D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 08:01:24.543980 :A9CB225E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 08:01:24.543980 :A9CB225F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 08:01:24.543981 :A9CB2260:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 08:01:24.543981 :A9CB2261:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 08:01:24.544513 :A9CB2262:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 08:01:54.618194 :A9CB2C36:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 08:02:10.825377 :A9CB6BF5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 08:02:10.817 2025-06-26 08:02:10.825379 :A9CB6BF6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16368 pso_num=25 pso_serial#=62 2025-06-26 08:02:10.825526 :A9CB6BF7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16368 osp_idx=23 osp_ver=169239 osp_pg=0 (spawn #323887) 2025-06-26 08:02:10.825526 :A9CB6BF8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 08:02:10.825527 :A9CB6BF9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=38 time=3900674016 2025-06-26 08:02:10.825527 :A9CB6BFA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 08:02:10.825528 :A9CB6BFB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 08:02:10.825528 :A9CB6BFC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 08:02:10.825528 :A9CB6BFD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 08:02:10.825529 :A9CB6BFE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 08:02:10.826779 :A9CB6BFF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 08:02:10.826829 :A9CB6C05:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-26 08:02:10.928459 :A9CB700F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-26 08:02:13.089914 :A9CB70D6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-26 08:02:13.083 2025-06-26 08:02:13.089916 :A9CB70D7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15096 pso_num=25 pso_serial#=63 2025-06-26 08:02:13.090044 :A9CB70D8:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15096 osp_idx=23 osp_ver=169240 osp_pg=0 (spawn #323889) 2025-06-26 08:02:13.090045 :A9CB70D9:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-26 08:02:13.090045 :A9CB70DA:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=39 time=3900676282 2025-06-26 08:02:13.090046 :A9CB70DB:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-26 08:02:13.090046 :A9CB70DC:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-26 08:02:13.090047 :A9CB70DD:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-26 08:02:13.090047 :A9CB70DE:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-26 08:02:13.090048 :A9CB70DF:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-26 08:02:13.090552 :A9CB70E0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-26 08:02:13.090594 :A9CB70E6:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 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: 15096, M002)