Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250709220006\orcl_j000_5196_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:36484M/63366M, Ph+PgF:42569M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 5196, image: ORACLE.EXE (J000) *** 2025-07-09 22:00:06.846 *** SESSION ID:(177.62505) 2025-07-09 22:00:06.846 *** 2025-07-09 22:00:06.846 Process diagnostic dump for ORACLE.EXE (J000), OS id=5196, pid: 22, proc_ser: 12, sid: 177, sess_ser: 62505 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 5196 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12726, hash value=1578450749 Current Wait Stack: Not in wait; last wait ended 0.872739 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.872768 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=141 seq_num=142 snap_id=1 wait times: snap=0.000193 sec, exc=0.000193 sec, total=0.000193 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 1: waited for 'log file sequential read' log#=0x28f3, block#=0x0, blocks=0x0 wait_id=140 seq_num=141 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.039748 sec of elapsed time 2: waited for 'log file sequential read' log#=0x28f3, block#=0x0, blocks=0x0 wait_id=139 seq_num=140 snap_id=1 wait times: snap=0.000021 sec, exc=0.000021 sec, total=0.000021 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.182821 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x6000, blocks=0x800 wait_id=138 seq_num=139 snap_id=1 wait times: snap=0.000289 sec, exc=0.000289 sec, total=0.000289 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0x5800, blocks=0x800 wait_id=137 seq_num=138 snap_id=1 wait times: snap=0.000316 sec, exc=0.000316 sec, total=0.000316 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0x5000, blocks=0x800 wait_id=136 seq_num=137 snap_id=1 wait times: snap=0.000315 sec, exc=0.000315 sec, total=0.000315 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 6: waited for 'log file sequential read' log#=0x0, block#=0x4800, blocks=0x800 wait_id=135 seq_num=136 snap_id=1 wait times: snap=0.000331 sec, exc=0.000331 sec, total=0.000331 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000078 sec of elapsed time 7: waited for 'log file sequential read' log#=0x0, block#=0x4000, blocks=0x800 wait_id=134 seq_num=135 snap_id=1 wait times: snap=0.000402 sec, exc=0.000402 sec, total=0.000402 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.335693 sec of elapsed time 8: waited for 'log file sequential read' log#=0x28f3, block#=0x800, blocks=0x800 wait_id=133 seq_num=134 snap_id=1 wait times: snap=0.000230 sec, exc=0.000230 sec, total=0.000230 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002704 sec of elapsed time 9: waited for 'log file sequential read' log#=0x28f3, block#=0x0, blocks=0x0 wait_id=132 seq_num=133 snap_id=1 wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000130 sec of elapsed time Sampled Session History of session 177 serial 62505 --------------------------------------------------- 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:00 - 22:00:06] not in wait at each sample [1 sample, 21:59:59] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-09 22:00:06.846 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 5196, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-09 21:58:42.001373 :AFD4E6FA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:58:42.017038 :AFD4E6FD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:58:42.011 2025-07-09 21:58:42.017040 :AFD4E6FE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15012 pso_num=22 pso_serial#=4 2025-07-09 21:58:42.017183 :AFD4E6FF:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15012 (legacy spawn) 2025-07-09 21:58:42.023627 :AFD4E700:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:58:42.023789 :AFD4E709:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 21:58:42.024575 :AFD4E70A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:58:44.952998 :AFD4E817:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:58:44.943 2025-07-09 21:58:44.953001 :AFD4E818:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17072 pso_num=22 pso_serial#=5 2025-07-09 21:58:44.953171 :AFD4E819:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=17072 osp_idx=0 osp_ver=384362 osp_pg=0 (spawn #369144) 2025-07-09 21:58:44.953172 :AFD4E81A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-09 21:58:44.953172 :AFD4E81B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=73 time=779100845 2025-07-09 21:58:44.953172 :AFD4E81C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-09 21:58:44.953173 :AFD4E81D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-09 21:58:44.953173 :AFD4E81E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-09 21:58:44.953173 :AFD4E81F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-09 21:58:44.953174 :AFD4E820:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-09 21:58:44.953664 :AFD4E821:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-09 21:58:44.954348 :AFD4E836:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:58:44.968635 :AFD4E852:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-07-09 21:58:44.968719 :AFD4E853:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-07-09 21:58:44.969567 :AFD4E854:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-07-09 21:58:44.969911 :AFD4E855:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:58:44.969950 :AFD4E858:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-07-09 21:58:44.977921 :AFD4E85E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:58:44.977990 :AFD4E861:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:ktcc.c:879 2025-07-09 21:58:44.978034 :AFD4E862:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:ktcc.c:879 2025-07-09 21:58:44.978407 :AFD4E868:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-07-09 21:58:44.978766 :AFD4E869:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-07-09 21:58:44.978963 :AFD4E86A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-07-09 21:58:44.979248 :AFD4E86B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:58:44.979274 :AFD4E86E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-07-09 21:58:44.980828 :AFD4E874:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-07-09 21:58:44.981051 :AFD4E875:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:58:44.981079 :AFD4E878:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-07-09 21:58:44.982065 :AFD4E87E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:58:44.982190 :AFD4E887:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 21:59:15.078366 :AFD4F241:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:59:18.399318 :AFD4F33C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:59:18.385 2025-07-09 21:59:18.399320 :AFD4F33D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6992 pso_num=22 pso_serial#=6 2025-07-09 21:59:18.399452 :AFD4F33E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=6992 (legacy spawn) 2025-07-09 21:59:18.406119 :AFD4F33F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:18.406310 :AFD4F344:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 21:59:18.407264 :AFD4F349:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:59:18.415749 :AFD4F34C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:59:18.400 2025-07-09 21:59:18.415751 :AFD4F34D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15440 pso_num=22 pso_serial#=7 2025-07-09 21:59:18.415937 :AFD4F34E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15440 (legacy spawn) 2025-07-09 21:59:18.422342 :AFD4F34F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:18.422519 :AFD4F358:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 21:59:18.423324 :AFD4F359:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:59:21.596632 :AFD4F44E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:59:21.582 2025-07-09 21:59:21.596635 :AFD4F44F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18176 pso_num=22 pso_serial#=8 2025-07-09 21:59:21.596787 :AFD4F450:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=18176 (legacy spawn) 2025-07-09 21:59:21.603812 :AFD4F451:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:21.604014 :AFD4F45A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 21:59:21.604920 :AFD4F45B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:59:21.614320 :AFD4F45E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:59:21.614 2025-07-09 21:59:21.614322 :AFD4F45F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17604 pso_num=22 pso_serial#=9 2025-07-09 21:59:21.614465 :AFD4F460:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=17604 (legacy spawn) 2025-07-09 21:59:21.621127 :AFD4F461:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:21.621299 :AFD4F46A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 21:59:21.622144 :AFD4F46B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:59:22.496625 :AFD4F4CD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:59:22.489 2025-07-09 21:59:22.496627 :AFD4F4CE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=17868 pso_num=22 pso_serial#=10 2025-07-09 21:59:22.496764 :AFD4F4CF:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=17868 (legacy spawn) 2025-07-09 21:59:22.503132 :AFD4F4D0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:22.503300 :AFD4F4D5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 21:59:22.504107 :AFD4F4DA:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:59:26.538186 :AFD4F638:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:59:26.529 2025-07-09 21:59:26.538188 :AFD4F639:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4152 pso_num=22 pso_serial#=11 2025-07-09 21:59:26.538325 :AFD4F63A:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=4152 (legacy spawn) 2025-07-09 21:59:26.544755 :AFD4F64E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:26.544874 :AFD4F657:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 21:59:26.545653 :AFD4F658:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-07-09 21:59:45.051993 :AFD4FC12:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 07-09 21:59:45.046 2025-07-09 21:59:45.051995 :AFD4FC13:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=5196 pso_num=22 pso_serial#=12 2025-07-09 21:59:45.052131 :AFD4FC14:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=5196 osp_idx=0 osp_ver=384369 osp_pg=0 (spawn #369147) 2025-07-09 21:59:45.052132 :AFD4FC15:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-09 21:59:45.052132 :AFD4FC16:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=74 time=779160939 2025-07-09 21:59:45.052133 :AFD4FC17:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-07-09 21:59:45.052133 :AFD4FC18:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-07-09 21:59:45.052133 :AFD4FC19:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-07-09 21:59:45.052134 :AFD4FC1A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-09 21:59:45.052134 :AFD4FC1B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-09 21:59:45.052632 :AFD4FC1C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-09 21:59:45.053275 :AFD4FC31:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:45.060791 :AFD4FC4D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-07-09 21:59:45.061152 :AFD4FC4E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:45.061188 :AFD4FC51:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-07-09 21:59:45.062028 :AFD4FC57:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 21:59:45.062147 :AFD4FC60:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 22:00:00.061721 :AFD50258:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-09 22:00:00.061721*:AFD50299:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1752069599 eid=16783874 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-09 22:00:00.061721*:AFD5029A:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-07-09 22:00:00.061721*:AFD5029B:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-07-09 22:00:00.061721*:AFD5029C:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-07-09 22:00:00.067861 :AFD502AA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] 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-07-09 22:00:00.067861*:AFD502B1:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-07-09 22:00:00.067861*:AFD502B2:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-07-09 22:00:00.069159 :AFD502B3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.069220 :AFD502B6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-07-09 22:00:00.080939 :AFD50448:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.086859 :AFD50453:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.087605 :AFD5045C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.093495 :AFD50475:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.093649 :AFD50484:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.094380 :AFD5048C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.094586 :AFD50494:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-07-09 22:00:00.096005 :AFD50495:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.096045 :AFD50498:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.096135 :AFD504A5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-07-09 22:00:00.170828 :AFD504B1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-09 22:00:00.172850 :AFD504C4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.172894 :AFD504C7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-07-09 22:00:00.190224 :AFD5053D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.190424 :AFD50545:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.190585 :AFD5054D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.190743 :AFD50555:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.191051 :AFD5055D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.191308 :AFD50565:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.191476 :AFD5056D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.191628 :AFD50575:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.191958 :AFD5057D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.192208 :AFD50585:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.192451 :AFD5058D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.193095 :AFD50595:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.193331 :AFD5059D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.193675 :AFD505A5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.193834 :AFD505AD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.193994 :AFD505B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.194146 :AFD505BD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.194295 :AFD505C5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.194444 :AFD505CD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.194597 :AFD505D5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.194762 :AFD505DD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.194927 :AFD505E5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.195081 :AFD505ED:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.195227 :AFD505F5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.195384 :AFD505FD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.195545 :AFD50605:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.195701 :AFD5060D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.195849 :AFD50615:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:00.222309 :AFD5061D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:01.442695*:AFD50837:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026B43AD0 estart=1752069601 eid=20215494 ctx=0x0000000777968158 cwh=0x0000000026B90AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-07-09 22:00:01.442695*:AFD50838:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026B43AD0 curCtx=0x000000004C98C4B8 pubTabIdxCnt=0 2025-07-09 22:00:01.442695*:AFD50839:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026B43AD0 2025-07-09 22:00:01.442695*:AFD5083A:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026B43AD0 2025-07-09 22:00:01.442695*:AFD5083B:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BBAAF8 estart=1752069599 eid=16777443 ctx=0x000000077B54EAC8 cwh=0x0000000026B90608 cpu=1031250 buffg=57127 interb=196608 r=24 rb=196608 w=0 wb=0 2025-07-09 22:00:01.442695*:AFD5083C:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BBAAF8 curCtx=0x000000004C7A1240 pubTabIdxCnt=0 2025-07-09 22:00:01.442695*:AFD5083D:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BBAAF8 2025-07-09 22:00:01.442695*:AFD5083E:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BBAAF8 2025-07-09 22:00:01.442695*:AFD50843:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026B43AD0 curCtx=0x000000004C98C4B8 xsc->flg4=65792 flags=1 2025-07-09 22:00:01.442695*:AFD50844:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026B43AD0 2025-07-09 22:00:01.895855*:AFD508D2:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BBAAF8 curCtx=0x000000004C7A1240 xsc->flg4=65792 flags=2 2025-07-09 22:00:01.895855*:AFD508D3:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BBAAF8 2025-07-09 22:00:01.897909 :AFD508D4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:01.920112 :AFD5090D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:01.922289 :AFD50915:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-07-09 22:00:01.922505 :AFD50916:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-07-09 22:00:01.923458 :AFD50917:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:01.923556 :AFD5091A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:01.924547 :AFD5092C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:01.926241 :AFD50934:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:01.926546 :AFD5093C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:01.958325*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-07-09 22:00:01.958325*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-07-09 22:00:01.958325*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-07-09 22:00:02.005201*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-07-09 22:00:02.005201*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-07-09 22:00:02.005201*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-07-09 22:00:02.005201*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-07-09 22:00:02.070027 :AFD509C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:03.981082 :AFD50ABB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:03.981095 :AFD50ABC:db_trace:ktur.c@3079:ktuabt(): [10444:22:177] ABORT TRANSACTION - xid: 0x0007.002.0000c6ed 2025-07-09 22:00:06.427876 :AFD50CAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:06.429242 :AFD50CB5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:06.438429 :AFD50CBD:db_trace:ktu.c@4871:ktuaex1r(): [10442:22:177] Extension usn 9, ext 1, nex 3 2025-07-09 22:00:06.438438 :AFD50CBE:db_trace:ktusm.c@2117:ktusmasp(): [10445:22:177] des1:tsn:1 rdba:0x008127be where: kduwh01: kdusru 2025-07-09 22:00:06.440046 :AFD50CBF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-09 22:00:06.466306 :AFD50CC7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] 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 22 (osid: 5196, J000)