Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250616220008\orcl_j003_14208_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:36562M/63366M, Ph+PgF:42969M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 14208, image: ORACLE.EXE (J003) *** 2025-06-16 22:00:08.163 *** SESSION ID:(233.25859) 2025-06-16 22:00:08.163 *** 2025-06-16 22:00:08.163 Process diagnostic dump for ORACLE.EXE (J003), OS id=14208, pid: 29, proc_ser: 143, sid: 233, sess_ser: 25859 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 14208 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12609, hash value=2863053659 Current Wait Stack: Not in wait; last wait ended 1.446716 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 1.446752 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=140 seq_num=141 snap_id=1 wait times: snap=0.000295 sec, exc=0.000295 sec, total=0.000295 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000008 sec of elapsed time 1: waited for 'log file sequential read' log#=0x286d, block#=0x0, blocks=0x0 wait_id=139 seq_num=140 snap_id=1 wait times: snap=0.000008 sec, exc=0.000008 sec, total=0.000008 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.078799 sec of elapsed time 2: waited for 'log file sequential read' log#=0x286d, block#=0x0, blocks=0x0 wait_id=138 seq_num=139 snap_id=1 wait times: snap=0.000032 sec, exc=0.000032 sec, total=0.000032 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.458878 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x2800, blocks=0x800 wait_id=137 seq_num=138 snap_id=1 wait times: snap=0.000259 sec, exc=0.000259 sec, total=0.000259 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000103 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0x2000, blocks=0x800 wait_id=136 seq_num=137 snap_id=1 wait times: snap=0.000261 sec, exc=0.000261 sec, total=0.000261 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.020188 sec of elapsed time 5: waited for 'log file sequential read' log#=0x286d, block#=0x800, blocks=0x800 wait_id=135 seq_num=136 snap_id=1 wait times: snap=0.000190 sec, exc=0.000190 sec, total=0.000190 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002457 sec of elapsed time 6: waited for 'log file sequential read' log#=0x286d, block#=0x0, blocks=0x0 wait_id=134 seq_num=135 snap_id=1 wait times: snap=0.000002 sec, exc=0.000002 sec, total=0.000002 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000117 sec of elapsed time 7: waited for 'log file sequential read' log#=0x286d, block#=0x2, blocks=0x7fe wait_id=133 seq_num=134 snap_id=1 wait times: snap=0.000187 sec, exc=0.000187 sec, total=0.000187 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000145 sec of elapsed time 8: waited for 'log file sequential read' log#=0x0, block#=0x1, blocks=0x1 wait_id=132 seq_num=133 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.000003 sec of elapsed time 9: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x0, filetype=0x3 wait_id=131 seq_num=132 snap_id=1 wait times: snap=0.000198 sec, exc=0.000198 sec, total=0.000198 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000120 sec of elapsed time Sampled Session History of session 233 serial 25859 --------------------------------------------------- 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 --------------------------------------------------- [7 samples, 22:00:01 - 22:00:07] not in wait at each sample [1 sample, 22:00:00] idle wait at each sample [session created at: 22:00:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-16 22:00:08.163 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 14208, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-16 01:49:47.963598 :A54290C7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-16 01:49:47.963813 :A54290C8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-16 01:49:47.963827 :A54290C9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-16 01:49:47.964042 :A54290CA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-16 01:49:47.964055 :A54290CB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-16 01:49:47.964266 :A54290CC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-16 01:49:47.964279 :A54290CD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-16 01:49:47.966603 :A54290CE:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 04:00:04.116467 :A54CB4DE:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 04:00:04.114 2025-06-16 04:00:04.116468 :A54CB4DF:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12524 pso_num=29 pso_serial#=135 2025-06-16 04:00:04.116598 :A54CB4E0:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12524 osp_idx=27 osp_ver=12884 osp_pg=0 (spawn #289995) 2025-06-16 04:00:04.116599 :A54CB4E1:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 04:00:04.116599 :A54CB4E2:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=14 time=3022147297 2025-06-16 04:00:04.116599 :A54CB4E3:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 04:00:04.116600 :A54CB4E4:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 04:00:04.116600 :A54CB4E5:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 04:00:04.116600 :A54CB4E6:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 04:00:04.116601 :A54CB4E7:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 04:00:04.117097 :A54CB4E8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 04:00:04.117146 :A54CB4EE:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-16 04:00:04.125265 :A54CB50F:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 05:00:11.379647 :A55167A1:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 05:00:11.377 2025-06-16 05:00:11.379648 :A55167A2:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=17156 pso_num=29 pso_serial#=136 2025-06-16 05:00:11.379786 :A55167A3:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=17156 osp_idx=27 osp_ver=12885 osp_pg=0 (spawn #290137) 2025-06-16 05:00:11.379787 :A55167A4:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 05:00:11.379787 :A55167A5:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=15 time=3025754563 2025-06-16 05:00:11.379788 :A55167A6:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 05:00:11.379788 :A55167A7:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 05:00:11.379788 :A55167A8:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 05:00:11.379789 :A55167A9:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 05:00:11.379789 :A55167AA:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 05:00:11.380280 :A55167AB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 05:00:11.380324 :A55167B1:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-16 05:00:11.388374 :A55167C3:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 06:00:18.231501 :A5562334:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 06:00:18.229 2025-06-16 06:00:18.231502 :A5562335:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13676 pso_num=29 pso_serial#=137 2025-06-16 06:00:18.231642 :A5562336:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13676 osp_idx=27 osp_ver=12886 osp_pg=0 (spawn #290275) 2025-06-16 06:00:18.231643 :A5562337:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 06:00:18.231643 :A5562338:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=16 time=3029361407 2025-06-16 06:00:18.231644 :A5562339:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 06:00:18.231644 :A556233A:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 06:00:18.231645 :A556233B:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 06:00:18.231645 :A556233C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 06:00:18.231646 :A556233D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 06:00:18.232163 :A556233E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 06:00:18.232211 :A5562344:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-16 06:00:18.240234 :A5562356:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 07:00:25.472442 :A55AE31B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 07:00:25.470 2025-06-16 07:00:25.472444 :A55AE31C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16908 pso_num=29 pso_serial#=138 2025-06-16 07:00:25.472582 :A55AE31D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=16908 osp_idx=27 osp_ver=12887 osp_pg=0 (spawn #290415) 2025-06-16 07:00:25.472582 :A55AE31E:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 07:00:25.472582 :A55AE31F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=17 time=3032968657 2025-06-16 07:00:25.472583 :A55AE320:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 07:00:25.472583 :A55AE321:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 07:00:25.472584 :A55AE322:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 07:00:25.472584 :A55AE323:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 07:00:25.472584 :A55AE324:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 07:00:25.473084 :A55AE325:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 07:00:25.473124 :A55AE32B:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-16 07:00:25.481375 :A55AE33D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 08:00:33.131438 :A55F9F5C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 08:00:33.129 2025-06-16 08:00:33.131439 :A55F9F5D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16152 pso_num=29 pso_serial#=139 2025-06-16 08:00:33.131580 :A55F9F5E:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=16152 osp_idx=27 osp_ver=12888 osp_pg=0 (spawn #290554) 2025-06-16 08:00:33.131581 :A55F9F5F:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 08:00:33.131581 :A55F9F60:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=18 time=3036576313 2025-06-16 08:00:33.131581 :A55F9F61:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 08:00:33.131582 :A55F9F62:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 08:00:33.131582 :A55F9F63:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 08:00:33.131583 :A55F9F64:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 08:00:33.131583 :A55F9F65:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 08:00:33.132080 :A55F9F66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 08:00:33.132119 :A55F9F6C:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-16 08:00:33.140321 :A55F9F7E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 09:00:40.421071 :A564599A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 09:00:40.421 2025-06-16 09:00:40.421072 :A564599B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16688 pso_num=29 pso_serial#=140 2025-06-16 09:00:40.421209 :A564599C:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=16688 osp_idx=27 osp_ver=12889 osp_pg=0 (spawn #290692) 2025-06-16 09:00:40.421210 :A564599D:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 09:00:40.421211 :A564599E:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=19 time=3040183594 2025-06-16 09:00:40.421211 :A564599F:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 09:00:40.421211 :A56459A0:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 09:00:40.421212 :A56459A1:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 09:00:40.421212 :A56459A2:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 09:00:40.421212 :A56459A3:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 09:00:40.421691 :A56459A4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 09:00:40.421728 :A56459AA:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-16 09:00:40.429742 :A56459CC:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 10:00:47.614182 :A56915D4:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 10:00:47.612 2025-06-16 10:00:47.614183 :A56915D5:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15916 pso_num=29 pso_serial#=141 2025-06-16 10:00:47.614318 :A56915D6:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=15916 osp_idx=27 osp_ver=12890 osp_pg=0 (spawn #290831) 2025-06-16 10:00:47.614318 :A56915D7:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 10:00:47.614319 :A56915D8:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=20 time=3043790797 2025-06-16 10:00:47.614319 :A56915D9:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 10:00:47.614320 :A56915DA:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 10:00:47.614320 :A56915DB:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 10:00:47.614320 :A56915DC:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 10:00:47.614320 :A56915DD:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 10:00:47.614850 :A56915DE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 10:00:47.614895 :A56915E4:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-16 10:00:47.622891 :A5691606:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 11:00:54.768515 :A56DD133:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 11:00:54.765 2025-06-16 11:00:54.768516 :A56DD134:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14440 pso_num=29 pso_serial#=142 2025-06-16 11:00:54.768648 :A56DD135:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14440 osp_idx=27 osp_ver=12891 osp_pg=0 (spawn #290969) 2025-06-16 11:00:54.768649 :A56DD136:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 11:00:54.768649 :A56DD137:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=21 time=3047397938 2025-06-16 11:00:54.768650 :A56DD138:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 11:00:54.768650 :A56DD139:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 11:00:54.768650 :A56DD13A:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 11:00:54.768651 :A56DD13B:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 11:00:54.768652 :A56DD13C:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 11:00:54.769153 :A56DD13D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 11:00:54.769198 :A56DD143:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-16 11:00:54.777589 :A56DD155:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-16 22:00:01.012285 :A5A177F2:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-16 22:00:01.004 2025-06-16 22:00:01.012286 :A5A177F3:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14208 pso_num=29 pso_serial#=143 2025-06-16 22:00:01.012402 :A5A177F9:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14208 osp_idx=27 osp_ver=12892 osp_pg=0 (spawn #292494) 2025-06-16 22:00:01.012403 :A5A177FA:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-16 22:00:01.012403 :A5A177FB:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=22 time=3086944204 2025-06-16 22:00:01.012403 :A5A177FC:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-16 22:00:01.012404 :A5A177FD:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-16 22:00:01.012404 :A5A177FE:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-16 22:00:01.012404 :A5A177FF:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-16 22:00:01.012405 :A5A17800:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-16 22:00:01.012961 :A5A17809:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.017953 :A5A17821:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.017978 :A5A17822:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-06-16 22:00:01.035827 :A5A17A25:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.036171 :A5A17A2D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.036355 :A5A17A35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.036528 :A5A17A3D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.036692 :A5A17A45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.036862 :A5A17A4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.037036 :A5A17A55:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.037202 :A5A17A5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.037373 :A5A17A65:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.037531 :A5A17A6D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.037683 :A5A17A75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.037838 :A5A17A7D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.037992 :A5A17A85:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.038155 :A5A17A8D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.038317 :A5A17A95:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.038479 :A5A17A9D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.038633 :A5A17AA5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.038798 :A5A17AAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.038948 :A5A17AB5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.039107 :A5A17ABD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.039256 :A5A17AC5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.039503 :A5A17ACD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.039675 :A5A17AD5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.039846 :A5A17ADD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.040492 :A5A17AE5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:01.068234 :A5A17AFF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:02.176544*:A5A17CDA:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC03AD0 estart=1750082402 eid=19503896 ctx=0x0000000777968158 cwh=0x0000000045CA0158 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-06-16 22:00:02.176544*:A5A17CDB:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC03AD0 curCtx=0x0000000045BA1BF8 pubTabIdxCnt=0 2025-06-16 22:00:02.176544*:A5A17CDC:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC03AD0 2025-06-16 22:00:02.176544*:A5A17CDD:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC03AD0 2025-06-16 22:00:02.176544*:A5A17CDE:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC7B6F0 estart=1750082401 eid=16777396 ctx=0x000000077B54EAC8 cwh=0x000000002DC70068 cpu=937500 buffg=52244 interb=196608 r=24 rb=196608 w=0 wb=0 2025-06-16 22:00:02.176544*:A5A17CDF:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC7B6F0 curCtx=0x0000000045B97FD8 pubTabIdxCnt=0 2025-06-16 22:00:02.176544*:A5A17CE0:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC7B6F0 2025-06-16 22:00:02.176544*:A5A17CE1:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC7B6F0 2025-06-16 22:00:02.176544*:A5A17CE2:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC03AD0 curCtx=0x0000000045BA1BF8 xsc->flg4=65792 flags=1 2025-06-16 22:00:02.176544*:A5A17CE3:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC03AD0 2025-06-16 22:00:02.738770*:A5A17E1B:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC7B6F0 curCtx=0x0000000045B97FD8 xsc->flg4=65792 flags=2 2025-06-16 22:00:02.738770*:A5A17E1C:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC7B6F0 2025-06-16 22:00:02.744564 :A5A17E1D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:02.766710 :A5A17E2E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:02.768967 :A5A17E36:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-06-16 22:00:02.769215 :A5A17E37:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-06-16 22:00:02.770286 :A5A17E38:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:02.770389 :A5A17E3B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:02.771337 :A5A17E4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:02.773112 :A5A17E55:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:02.773441 :A5A17E5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:02.832520*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-06-16 22:00:02.832520*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-06-16 22:00:02.832520*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-06-16 22:00:02.848146*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-06-16 22:00:02.848146*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-06-16 22:00:02.848146*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-06-16 22:00:02.848146*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-06-16 22:00:02.923873 :A5A17F25:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:04.829205 :A5A1806F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:04.829220 :A5A18070:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0009.018.0001cd6f 2025-06-16 22:00:07.172554 :A5A181F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:07.174010 :A5A181F8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:07.184855 :A5A18200:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-16 22:00:07.210215 :A5A18227:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 14208, J003)