Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250511060006\orcl_j003_11572_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:37494M/63366M, Ph+PgF:44863M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 11572, image: ORACLE.EXE (J003) *** 2025-05-11 06:00:06.757 *** SESSION ID:(233.21439) 2025-05-11 06:00:06.757 *** 2025-05-11 06:00:06.757 Process diagnostic dump for ORACLE.EXE (J003), OS id=11572, pid: 29, proc_ser: 242, sid: 233, sess_ser: 21439 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 11572 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12413, hash value=3163975064 Current Wait Stack: Not in wait; last wait ended 2.913947 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.913972 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=41 seq_num=42 snap_id=1 wait times: snap=0.000163 sec, exc=0.000163 sec, total=0.000163 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.067700 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000007 sec, exc=0.000007 sec, total=0.000007 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.029137 sec of elapsed time 2: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x3, filetype=0x2 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000174 sec, exc=0.000174 sec, total=0.000174 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.726045 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.000003 sec, exc=0.000003 sec, total=0.000003 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.025293 sec of elapsed time 4: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=37 seq_num=38 snap_id=1 wait times: snap=0.000005 sec, exc=0.000005 sec, total=0.000005 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.013133 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000064 sec, exc=0.000064 sec, total=0.000064 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049487 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.007597 sec, exc=0.007597 sec, total=0.007597 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007856 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.000073 sec, exc=0.000073 sec, total=0.000073 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.261412 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.008047 sec, exc=0.008047 sec, total=0.008047 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000169 sec of elapsed time 9: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.000117 sec, exc=0.000117 sec, total=0.000117 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007910 sec of elapsed time Sampled Session History of session 233 serial 21439 --------------------------------------------------- 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 --------------------------------------------------- [5 samples, 06:00:02 - 06:00:06] not in wait at each sample [1 sample, 06:00:01] idle wait at each sample [session created at: 06:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-11 06:00:06.757 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 11572, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-11 00:22:06.597150 :956E7DDC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:22:06.597168 :956E7DDD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:22:06.597386 :956E7DDE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:22:06.597399 :956E7DDF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:22:06.597608 :956E7DE0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:22:06.597621 :956E7DE1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:22:06.599865 :956E7DE2:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 00:52:10.473445 :9570C30B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 00:52:10.461 2025-05-11 00:52:10.473447 :9570C30C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13152 pso_num=29 pso_serial#=237 2025-05-11 00:52:10.473578 :9570C30D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13152 osp_idx=27 osp_ver=10691 osp_pg=0 (spawn #169472) 2025-05-11 00:52:10.473579 :9570C30E:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 00:52:10.473579 :9570C30F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=238 time=4195507625 2025-05-11 00:52:10.473580 :9570C310:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 00:52:10.473580 :9570C311:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 00:52:10.473581 :9570C312:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 00:52:10.473581 :9570C313:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 00:52:10.473582 :9570C314:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 00:52:10.474098 :9570C315: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-05-11 00:52:10.474142 :9570C31B: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-05-11 00:52:10.478307 :9570C334:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:52:10.478350 :9570C335:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:52:10.478597 :9570C336:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:52:10.478611 :9570C337:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:52:10.478816 :9570C338:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:52:10.478829 :9570C339:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:52:10.479131 :9570C33A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:52:10.479144 :9570C33B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:52:10.479359 :9570C33C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:52:10.479372 :9570C33D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:52:10.479581 :9570C33E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 00:52:10.479594 :9570C33F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 00:52:10.481851 :9570C340:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 01:00:00.702839 :95715B94:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 01:00:00.696 2025-05-11 01:00:00.702841 :95715B95:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9116 pso_num=29 pso_serial#=238 2025-05-11 01:00:00.702975 :95715B96:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=9116 osp_idx=27 osp_ver=10692 osp_pg=0 (spawn #169491) 2025-05-11 01:00:00.702976 :95715B97:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 01:00:00.702977 :95715B98:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=239 time=4195977875 2025-05-11 01:00:00.702977 :95715B99:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 01:00:00.702978 :95715B9A:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 01:00:00.702978 :95715B9B:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 01:00:00.702979 :95715B9C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 01:00:00.702980 :95715B9D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 01:00:00.703637 :95715B9E: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-05-11 01:00:30.805208 :9571670E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 01:02:11.816085 :957187CB:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 01:02:11.804 2025-05-11 01:02:11.816087 :957187CC:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11468 pso_num=29 pso_serial#=239 2025-05-11 01:02:11.816227 :957187CD:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11468 osp_idx=27 osp_ver=10693 osp_pg=0 (spawn #169499) 2025-05-11 01:02:11.816227 :957187CE:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 01:02:11.816228 :957187CF:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=240 time=4196108968 2025-05-11 01:02:11.816228 :957187D0:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 01:02:11.816229 :957187D1:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 01:02:11.816229 :957187D2:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 01:02:11.816230 :957187D3:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 01:02:11.816230 :957187D4:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 01:02:11.816880 :957187D5: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-05-11 01:02:11.816931 :957187DB: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-05-11 01:02:11.825499 :957187F0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 01:22:14.344483 :957313E8:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 01:22:14.332 2025-05-11 01:22:14.344486 :957313E9:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=6652 pso_num=29 pso_serial#=240 2025-05-11 01:22:14.344622 :957313EA:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=6652 osp_idx=27 osp_ver=10694 osp_pg=0 (spawn #169547) 2025-05-11 01:22:14.344623 :957313EB:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 01:22:14.344623 :957313EC:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=241 time=4197311500 2025-05-11 01:22:14.344624 :957313ED:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 01:22:14.344624 :957313EE:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 01:22:14.344625 :957313EF:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 01:22:14.344625 :957313F0:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 01:22:14.344625 :957313F1:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 01:22:14.345141 :957313F2: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-05-11 01:22:14.345181 :957313F8: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-05-11 01:22:14.349420 :95731421:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:22:14.349461 :95731422:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:22:14.349705 :95731423:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:22:14.349719 :95731424:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:22:14.349947 :95731425:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:22:14.349967 :95731426:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:22:14.350233 :95731427:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:22:14.350245 :95731428:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:22:14.350454 :95731429:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:22:14.350467 :9573142A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:22:14.350675 :9573142B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:22:14.350688 :9573142C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:22:14.352976 :9573142D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 01:52:18.106642 :9575590E:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 01:52:18.094 2025-05-11 01:52:18.106644 :9575590F:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13272 pso_num=29 pso_serial#=241 2025-05-11 01:52:18.106775 :95755910:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13272 osp_idx=27 osp_ver=10695 osp_pg=0 (spawn #169615) 2025-05-11 01:52:18.106776 :95755911:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 01:52:18.106777 :95755912:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=242 time=4199115265 2025-05-11 01:52:18.106777 :95755913:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 01:52:18.106777 :95755914:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 01:52:18.106778 :95755915:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 01:52:18.106778 :95755916:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 01:52:18.106779 :95755917:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 01:52:18.107289 :95755918: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-05-11 01:52:18.107330 :9575591E: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-05-11 01:52:18.111417 :95755937:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:52:18.111462 :95755938:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:52:18.111715 :95755939:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:52:18.111730 :9575593A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:52:18.111947 :9575593B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:52:18.111959 :9575593C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:52:18.112160 :9575593D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:52:18.112172 :9575593E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:52:18.112372 :9575593F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:52:18.112385 :95755940:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:52:18.112587 :95755941:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 01:52:18.112600 :95755942:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 01:52:18.114921 :95755943:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 06:00:02.064925 :958846FD:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 06:00:02.053 2025-05-11 06:00:02.064926 :958846FE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11572 pso_num=29 pso_serial#=242 2025-05-11 06:00:02.065070 :95884707:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11572 osp_idx=27 osp_ver=10696 osp_pg=0 (spawn #170201) 2025-05-11 06:00:02.065071 :95884709:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 06:00:02.065072 :9588470A:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=243 time=4213979218 2025-05-11 06:00:02.065072 :9588470B:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 06:00:02.065073 :9588470C:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 06:00:02.065073 :9588470D:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 06:00:02.065073 :9588470E:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 06:00:02.065074 :9588470F:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 06:00:02.065583 :95884715: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-05-11 06:00:02.070658 :95884734: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-05-11 06:00:02.070698 :95884737:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-11 06:00:02.088663 :958847AB: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-05-11 06:00:02.088878 :958847B3: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-05-11 06:00:02.089037 :958847BB: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-05-11 06:00:02.089185 :958847C3: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-05-11 06:00:02.089339 :958847CB: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-05-11 06:00:02.089490 :958847D3: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-05-11 06:00:02.089640 :958847DB: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-05-11 06:00:02.089796 :958847E3: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-05-11 06:00:02.089943 :958847EB: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-05-11 06:00:02.090151 :958847F3: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-05-11 06:00:02.090333 :958847FB: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-05-11 06:00:02.090481 :95884803: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-05-11 06:00:02.090628 :9588480B: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-05-11 06:00:02.090782 :95884813: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-05-11 06:00:02.090934 :9588481B: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-05-11 06:00:02.091077 :95884823: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-05-11 06:00:02.091239 :9588482B: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-05-11 06:00:02.091385 :95884833: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-05-11 06:00:02.091529 :9588483B: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-05-11 06:00:02.091676 :95884843: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-05-11 06:00:02.091834 :9588484B: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-05-11 06:00:02.091978 :95884853: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-05-11 06:00:02.092130 :9588485B: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-05-11 06:00:02.112119 :9588490B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-05-11 06:00:02.112781 :95884A0D: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-05-11 06:00:03.381045*:95884CD5:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC03AD0 estart=1746914402 eid=18297281 ctx=0x0000000777968158 cwh=0x000000002DC309C8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-05-11 06:00:03.381045*:95884CD6:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC03AD0 curCtx=0x0000000034357918 pubTabIdxCnt=0 2025-05-11 06:00:03.381045*:95884CD8:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC03AD0 2025-05-11 06:00:03.381045*:95884CDB:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC03AD0 2025-05-11 06:00:03.381045*:95884CDC:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DC7B6F0 estart=1746914401 eid=16777316 ctx=0x000000077B54EAC8 cwh=0x000000002DC30518 cpu=1078125 buffg=60932 interb=204800 r=25 rb=204800 w=0 wb=0 2025-05-11 06:00:03.381045*:95884CDE:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DC7B6F0 curCtx=0x00000000326687D0 pubTabIdxCnt=0 2025-05-11 06:00:03.381045*:95884CE0:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DC7B6F0 2025-05-11 06:00:03.381045*:95884CE2:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DC7B6F0 2025-05-11 06:00:03.381045*:95884CEE:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC03AD0 curCtx=0x0000000034357918 xsc->flg4=65792 flags=1 2025-05-11 06:00:03.381045*:95884CEF:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC03AD0 2025-05-11 06:00:03.756044*:95884E18:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DC7B6F0 curCtx=0x00000000326687D0 xsc->flg4=65792 flags=2 2025-05-11 06:00:03.756044*:95884E19:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DC7B6F0 2025-05-11 06:00:03.762576 :95884E1A: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-05-11 06:00:03.786311 :95884E22: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-05-11 06:00:03.788625 :95884E37:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-05-11 06:00:03.788928 :95884E38:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-05-11 06:00:03.789982 :95884E39: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-05-11 06:00:03.790102 :95884E3C: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-05-11 06:00:03.791103 :95884E4E: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-05-11 06:00:03.793014 :95884E56: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-05-11 06:00:03.793368 :95884E5E: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-05-11 06:00:03.849803*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-05-11 06:00:03.849803*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-11 06:00:03.849803*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-11 06:00:03.849803*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-11 06:00:03.849803*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-11 06:00:03.849803*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-11 06:00:03.849803*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-11 06:00:03.932645 :95884E68: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-05-11 06:00:05.822004 :95884F50: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-05-11 06:00:05.822015 :95884F51:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x000a.00b.00168753 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 11572, J003)