Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250513080058\orcl_m002_4640_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:37416M/63366M, Ph+PgF:44705M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 4640, image: ORACLE.EXE (M002) *** 2025-05-13 08:00:58.422 *** SESSION ID:(201.12681) 2025-05-13 08:00:58.422 *** 2025-05-13 08:00:58.422 Process diagnostic dump for ORACLE.EXE (M002), OS id=4640, pid: 25, proc_ser: 22, sid: 201, sess_ser: 12681 ------------------------------------------------------------------------------- current sql: Current Wait Stack: Not in wait; last wait ended 0.000126 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000150 sec since last wait 0: waited for 'db file sequential read' file#=0x2, block#=0x7e72, blocks=0x1 wait_id=1767 seq_num=1768 snap_id=1 wait times: snap=0.000131 sec, exc=0.000131 sec, total=0.000131 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000339 sec of elapsed time 1: waited for 'db file sequential read' file#=0x2, block#=0x7e5a, blocks=0x1 wait_id=1766 seq_num=1767 snap_id=1 wait times: snap=0.002286 sec, exc=0.002286 sec, total=0.002286 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000181 sec of elapsed time 2: waited for 'db file sequential read' file#=0x2, block#=0x7e42, blocks=0x1 wait_id=1765 seq_num=1766 snap_id=1 wait times: snap=0.000046 sec, exc=0.000046 sec, total=0.000046 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000256 sec of elapsed time 3: waited for 'db file sequential read' file#=0x2, block#=0xec02, blocks=0x1 wait_id=1764 seq_num=1765 snap_id=1 wait times: snap=0.000048 sec, exc=0.000048 sec, total=0.000048 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000260 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x824a, blocks=0x1 wait_id=1763 seq_num=1764 snap_id=1 wait times: snap=0.000048 sec, exc=0.000048 sec, total=0.000048 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000159 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x105a, blocks=0x1 wait_id=1762 seq_num=1763 snap_id=1 wait times: snap=0.000054 sec, exc=0.000054 sec, total=0.000054 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000151 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x8652, blocks=0x1 wait_id=1761 seq_num=1762 snap_id=1 wait times: snap=0.000045 sec, exc=0.000045 sec, total=0.000045 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000151 sec of elapsed time 7: waited for 'db file sequential read' file#=0x2, block#=0x8642, blocks=0x1 wait_id=1760 seq_num=1761 snap_id=1 wait times: snap=0.000051 sec, exc=0.000051 sec, total=0.000051 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000139 sec of elapsed time 8: waited for 'db file sequential read' file#=0x2, block#=0x8632, blocks=0x1 wait_id=1759 seq_num=1760 snap_id=1 wait times: snap=0.000048 sec, exc=0.000048 sec, total=0.000048 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000140 sec of elapsed time 9: waited for 'db file sequential read' file#=0x2, block#=0x8622, blocks=0x1 wait_id=1758 seq_num=1759 snap_id=1 wait times: snap=0.000048 sec, exc=0.000048 sec, total=0.000048 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000147 sec of elapsed time Sampled Session History of session 201 serial 12681 --------------------------------------------------- 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:00:58] waited for 'db file sequential read', seq_num: 1507 p1: 'file#'=0x2 p2: 'block#'=0x3a8a p3: 'blocks'=0x1 time_waited: >= 0 sec (still in wait) [1 sample, 08:00:57] idle wait at each sample [session created at: 08:00:57] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'db file sequential read' [1 sample, 08:00:58 ] time_waited: >= 0 sec (still in wait) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-13 08:00:58.422 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 4640, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-13 07:49:09.000910 :966F7D5B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:49:09.000910 :966F7D5C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:49:09.000911 :966F7D5D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:49:09.000911 :966F7D5E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:49:09.001384 :966F7D5F: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-05-13 07:49:39.063159 :966F86C1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:50:09.098889 :966F909A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:50:09.087 2025-05-13 07:50:09.098890 :966F909B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10872 pso_num=25 pso_serial#=10 2025-05-13 07:50:09.099020 :966F909C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10872 osp_idx=23 osp_ver=93849 osp_pg=0 (spawn #177187) 2025-05-13 07:50:09.099021 :966F909D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:50:09.099021 :966F909E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=124 time=98418969 2025-05-13 07:50:09.099022 :966F909F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:50:09.099022 :966F90A0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:50:09.099022 :966F90A1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:50:09.099023 :966F90A2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:50:09.099023 :966F90A3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:50:09.099508 :966F90A4: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-05-13 07:50:39.181914 :966F9A5C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:51:09.210305 :966FA400:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:51:09.200 2025-05-13 07:51:09.210307 :966FA401:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12028 pso_num=25 pso_serial#=11 2025-05-13 07:51:09.210444 :966FA402:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12028 osp_idx=23 osp_ver=93850 osp_pg=0 (spawn #177189) 2025-05-13 07:51:09.210445 :966FA403:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:51:09.210445 :966FA404:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=125 time=98479079 2025-05-13 07:51:09.210445 :966FA405:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:51:09.210446 :966FA406:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:51:09.210446 :966FA407:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:51:09.210446 :966FA408:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:51:09.210447 :966FA409:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:51:09.210972 :966FA40A: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-05-13 07:51:39.331527 :966FAE12:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:52:09.323838 :966FB790:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:52:09.313 2025-05-13 07:52:09.323840 :966FB791:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11496 pso_num=25 pso_serial#=12 2025-05-13 07:52:09.323980 :966FB792:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11496 osp_idx=23 osp_ver=93851 osp_pg=0 (spawn #177191) 2025-05-13 07:52:09.323981 :966FB793:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:52:09.323982 :966FB794:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=126 time=98539188 2025-05-13 07:52:09.323982 :966FB795:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:52:09.323982 :966FB796:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:52:09.323983 :966FB797:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:52:09.323983 :966FB798:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:52:09.323983 :966FB799:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:52:09.324467 :966FB79A: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-05-13 07:52:39.384459 :966FC10C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:53:09.452951 :966FCAD8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:53:09.442 2025-05-13 07:53:09.452954 :966FCAD9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8436 pso_num=25 pso_serial#=13 2025-05-13 07:53:09.453087 :966FCADA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8436 osp_idx=23 osp_ver=93852 osp_pg=0 (spawn #177194) 2025-05-13 07:53:09.453087 :966FCADB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:53:09.453088 :966FCADC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=127 time=98599313 2025-05-13 07:53:09.453088 :966FCADD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:53:09.453089 :966FCADE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:53:09.453089 :966FCADF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:53:09.453089 :966FCAE0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:53:09.453089 :966FCAE1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:53:09.453561 :966FCAE2: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-05-13 07:53:39.516409 :966FD58E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:54:09.547382 :966FDF4F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:54:09.536 2025-05-13 07:54:09.547384 :966FDF50:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12524 pso_num=25 pso_serial#=14 2025-05-13 07:54:09.547520 :966FDF51:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12524 osp_idx=23 osp_ver=93853 osp_pg=0 (spawn #177197) 2025-05-13 07:54:09.547521 :966FDF52:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:54:09.547521 :966FDF53:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=128 time=98659407 2025-05-13 07:54:09.547522 :966FDF54:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:54:09.547522 :966FDF55:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:54:09.547522 :966FDF56:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:54:09.547523 :966FDF57:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:54:09.547523 :966FDF58:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:54:09.547995 :966FDF59: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-05-13 07:54:39.641330 :966FE90F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:55:09.615049 :966FF295:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:55:09.604 2025-05-13 07:55:09.615051 :966FF296:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=3736 pso_num=25 pso_serial#=15 2025-05-13 07:55:09.615183 :966FF297:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=3736 osp_idx=23 osp_ver=93854 osp_pg=0 (spawn #177199) 2025-05-13 07:55:09.615184 :966FF298:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:55:09.615184 :966FF299:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=129 time=98719485 2025-05-13 07:55:09.615185 :966FF29A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:55:09.615185 :966FF29B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:55:09.615185 :966FF29C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:55:09.615186 :966FF29D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:55:09.615186 :966FF29E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:55:09.615647 :966FF29F: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-05-13 07:55:39.697296 :966FFC07:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:56:04.694296 :9670044D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:56:04.683 2025-05-13 07:56:04.694298 :9670044E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13304 pso_num=25 pso_serial#=16 2025-05-13 07:56:04.694438 :9670044F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13304 osp_idx=23 osp_ver=93855 osp_pg=0 (spawn #177201) 2025-05-13 07:56:04.694439 :96700450:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:56:04.694439 :96700451:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=130 time=98774563 2025-05-13 07:56:04.694440 :96700452:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:56:04.694440 :96700453:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:56:04.694441 :96700454:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:56:04.694441 :96700455:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:56:04.694442 :96700456:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:56:04.694921 :96700457: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-05-13 07:56:09.700513 :967005F4: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-05-13 07:56:09.700542*:967005F5:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DCBB58 estart=1747094169 eid=16857904 ctx=0x000000077BD98A08 cwh=0x0000000024D801B0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-13 07:56:09.700542*:967005F6:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DCBB58 curCtx=0x0000000024D8F708 pubTabIdxCnt=0 2025-05-13 07:56:09.700542*:967005F7:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DCBB58 2025-05-13 07:56:09.700542*:967005F8:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DCBB58 2025-05-13 07:56:09.700542*:967005F9:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DCBB58 curCtx=0x0000000024D8F708 xsc->flg4=65792 flags=2 2025-05-13 07:56:09.700542*:967005FA:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DCBB58 2025-05-13 07:56:09.701074 :967005FB: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-13 07:56:09.715435 :96700603:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-13 07:56:09.715522 :96700604:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-13 07:56:09.716289 :96700605:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-13 07:56:09.716644 :96700606: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-13 07:56:09.716683 :96700609:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-13 07:56:09.724542 :9670060F: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-13 07:56:09.724614 :96700612:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-13 07:56:09.724652 :96700613:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-13 07:56:09.725009 :96700619:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-13 07:56:09.725357 :9670061A:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-13 07:56:09.725548 :9670061B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-13 07:56:09.725798 :9670061C: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-13 07:56:09.725825 :9670061F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-13 07:56:09.727518 :96700625:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-13 07:56:09.727769 :96700626: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-13 07:56:09.727800 :96700629:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-13 07:56:09.728719 :9670062F: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-13 07:56:09.728838 :96700638: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-13 07:56:39.823391 :96700FA7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:57:09.835747 :96701951:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:57:09.824 2025-05-13 07:57:09.835749 :96701952:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10236 pso_num=25 pso_serial#=17 2025-05-13 07:57:09.835878 :96701953:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10236 osp_idx=23 osp_ver=93856 osp_pg=0 (spawn #177203) 2025-05-13 07:57:09.835879 :96701954:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:57:09.835879 :96701955:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=131 time=98839704 2025-05-13 07:57:09.835880 :96701956:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:57:09.835880 :96701957:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:57:09.835880 :96701958:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:57:09.835880 :96701959:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:57:09.835880 :9670195A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:57:09.836354 :9670195B: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-05-13 07:57:39.887496 :9670231F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:58:09.908587 :96702C93:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:58:09.897 2025-05-13 07:58:09.908589 :96702C94:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12928 pso_num=25 pso_serial#=18 2025-05-13 07:58:09.908729 :96702C95:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12928 osp_idx=23 osp_ver=93857 osp_pg=0 (spawn #177205) 2025-05-13 07:58:09.908730 :96702C96:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:58:09.908730 :96702C97:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=132 time=98899766 2025-05-13 07:58:09.908731 :96702C98:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:58:09.908731 :96702C99:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:58:09.908732 :96702C9A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:58:09.908732 :96702C9B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:58:09.908732 :96702C9C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:58:09.909193 :96702C9D: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-05-13 07:58:39.991928 :96703738:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 07:59:10.018853 :967040F8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 07:59:10.008 2025-05-13 07:59:10.018856 :967040F9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12004 pso_num=25 pso_serial#=19 2025-05-13 07:59:10.018987 :967040FA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12004 osp_idx=23 osp_ver=93858 osp_pg=0 (spawn #177207) 2025-05-13 07:59:10.018987 :967040FB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 07:59:10.018988 :967040FC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=133 time=98959875 2025-05-13 07:59:10.018988 :967040FD:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 07:59:10.018989 :967040FE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 07:59:10.018989 :967040FF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 07:59:10.018989 :96704100:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 07:59:10.018990 :96704101:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 07:59:10.019463 :96704102: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-05-13 07:59:40.140487 :96704A9F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 08:00:10.144524 :96705451:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 08:00:10.134 2025-05-13 08:00:10.144526 :96705452:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13224 pso_num=25 pso_serial#=20 2025-05-13 08:00:10.144659 :96705453:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13224 osp_idx=23 osp_ver=93859 osp_pg=0 (spawn #177209) 2025-05-13 08:00:10.144659 :96705454:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 08:00:10.144660 :96705455:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=134 time=99020016 2025-05-13 08:00:10.144660 :96705456:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 08:00:10.144661 :96705457:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 08:00:10.144661 :96705458:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 08:00:10.144661 :96705459:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 08:00:10.144662 :9670545A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 08:00:10.145132 :9670545B: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-05-13 08:00:40.220621 :96706025:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 08:00:55.204582 :96709F19:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 08:00:55.198 2025-05-13 08:00:55.204583 :96709F1A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13156 pso_num=25 pso_serial#=21 2025-05-13 08:00:55.204752 :96709F23:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13156 osp_idx=23 osp_ver=93860 osp_pg=0 (spawn #177213) 2025-05-13 08:00:55.204752 :96709F24:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 08:00:55.204753 :96709F25:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=135 time=99065063 2025-05-13 08:00:55.204753 :96709F26:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 08:00:55.204753 :96709F27:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 08:00:55.204754 :96709F28:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 08:00:55.204754 :96709F29:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 08:00:55.204754 :96709F2A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 08:00:55.205655 :96709F53: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-05-13 08:00:55.205690 :96709F59: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-05-13 08:00:55.301028 :9670A21B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-13 08:00:57.517723 :9670A33A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-13 08:00:57.511 2025-05-13 08:00:57.517725 :9670A33B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4640 pso_num=25 pso_serial#=22 2025-05-13 08:00:57.517861 :9670A33C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4640 osp_idx=23 osp_ver=93861 osp_pg=0 (spawn #177215) 2025-05-13 08:00:57.517861 :9670A33D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-13 08:00:57.517862 :9670A33E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=136 time=99067391 2025-05-13 08:00:57.517862 :9670A33F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-13 08:00:57.517863 :9670A340:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-13 08:00:57.517863 :9670A341:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-13 08:00:57.517863 :9670A342:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-13 08:00:57.517864 :9670A343:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-13 08:00:57.518369 :9670A344: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-05-13 08:00:57.518412 :9670A34A: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: 4640, M002)