Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250426220725\orcl_j000_9560_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:37585M/63366M, Ph+PgF:45261M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 9560, image: ORACLE.EXE (J000) *** 2025-04-26 22:07:25.387 *** SESSION ID:(193.15705) 2025-04-26 22:07:25.387 *** 2025-04-26 22:07:25.387 Process diagnostic dump for ORACLE.EXE (J000), OS id=9560, pid: 24, proc_ser: 142, sid: 193, sess_ser: 15705 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 9560 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12337, hash value=1174702795 Current Wait Stack: Not in wait; last wait ended 0.966643 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.966668 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=189 seq_num=190 snap_id=1 wait times: snap=0.000204 sec, exc=0.000204 sec, total=0.000204 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#=0x2743, block#=0x0, blocks=0x0 wait_id=188 seq_num=189 snap_id=1 wait times: snap=0.000004 sec, exc=0.000004 sec, total=0.000004 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.077226 sec of elapsed time 2: waited for 'log file sequential read' log#=0x2743, block#=0x0, blocks=0x0 wait_id=187 seq_num=188 snap_id=1 wait times: snap=0.000013 sec, exc=0.000013 sec, total=0.000013 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000008 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0xf000, blocks=0x800 wait_id=186 seq_num=187 snap_id=1 wait times: snap=0.000303 sec, exc=0.000303 sec, total=0.000303 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0xe800, blocks=0x800 wait_id=185 seq_num=186 snap_id=1 wait times: snap=0.000337 sec, exc=0.000337 sec, total=0.000337 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0xe000, blocks=0x800 wait_id=184 seq_num=185 snap_id=1 wait times: snap=0.000280 sec, exc=0.000280 sec, total=0.000280 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 6: waited for 'log file sequential read' log#=0x0, block#=0xd800, blocks=0x800 wait_id=183 seq_num=184 snap_id=1 wait times: snap=0.000294 sec, exc=0.000294 sec, total=0.000294 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 7: waited for 'log file sequential read' log#=0x0, block#=0xd000, blocks=0x800 wait_id=182 seq_num=183 snap_id=1 wait times: snap=0.000302 sec, exc=0.000302 sec, total=0.000302 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000092 sec of elapsed time 8: waited for 'log file sequential read' log#=0x0, block#=0xc800, blocks=0x800 wait_id=181 seq_num=182 snap_id=1 wait times: snap=0.000293 sec, exc=0.000293 sec, total=0.000293 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.524919 sec of elapsed time 9: waited for 'log file sequential read' log#=0x2743, block#=0x800, blocks=0x800 wait_id=180 seq_num=181 snap_id=1 wait times: snap=0.000213 sec, exc=0.000213 sec, total=0.000213 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002040 sec of elapsed time Sampled Session History of session 193 serial 15705 --------------------------------------------------- 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 --------------------------------------------------- [6 samples, 22:07:19 - 22:07:24] not in wait at each sample [22 samples, 22:06:56 - 22:07:18] idle wait at each sample [session created at: 22:06:56] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.016000 sec (max dump time=30.000000 sec) *** 2025-04-26 22:07:25.402 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 9560, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-26 22:04:56.525937 :8F2F848A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:04:56.526228 :8F2F848B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:04:56.526263 :8F2F848C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:04:56.526474 :8F2F848D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:04:56.526503 :8F2F848E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:04:56.526595 :8F2F848F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:04:56.526816 :8F2F8490:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:04:56.526852 :8F2F8493:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:04:56.534832 :8F2F8499:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:04:56.534902 :8F2F849C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:ktcc.c:879 2025-04-26 22:04:56.534937 :8F2F849D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:ktcc.c:879 2025-04-26 22:04:56.536691 :8F2F84A3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:04:56.536736 :8F2F84A4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:04:56.540059 :8F2F84A5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:04:56.540321 :8F2F84A6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:04:56.540356 :8F2F84A9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:04:56.545116 :8F2F84AF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:04:56.545190 :8F2F84B2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:ktcc.c:879 2025-04-26 22:04:56.545237 :8F2F84B3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:ktcc.c:879 2025-04-26 22:04:56.545593 :8F2F84B9:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-26 22:04:56.545956 :8F2F84BA:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-26 22:04:56.546086 :8F2F84BB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:04:56.546330 :8F2F84BC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:04:56.546356 :8F2F84BF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:04:56.547935 :8F2F84C5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:04:56.548153 :8F2F84C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:04:56.548181 :8F2F84C9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:04:56.549041 :8F2F84CF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:04:56.549163 :8F2F84D8:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:05:26.631996 :8F2F93C2:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:05:35.271897 :8F2F9669:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:05:35.263 2025-04-26 22:05:35.271899 :8F2F966A:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9092 pso_num=24 pso_serial#=133 2025-04-26 22:05:35.272082 :8F2F966B:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9092 (legacy spawn) 2025-04-26 22:05:35.278420 :8F2F966C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:35.278591 :8F2F9675:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:05:35.279432 :8F2F9690:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:05:35.913042 :8F2F969F:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:05:35.904 2025-04-26 22:05:35.913044 :8F2F96A0:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9044 pso_num=24 pso_serial#=134 2025-04-26 22:05:35.913174 :8F2F96A1:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9044 (legacy spawn) 2025-04-26 22:05:35.919569 :8F2F96A2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:35.919753 :8F2F96A8:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:05:35.920589 :8F2F96AC:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:05:44.580889 :8F2F997E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:05:44.566 2025-04-26 22:05:44.580890 :8F2F997F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10512 pso_num=24 pso_serial#=135 2025-04-26 22:05:44.581029 :8F2F9980:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=10512 (legacy spawn) 2025-04-26 22:05:44.587512 :8F2F9981:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:44.587681 :8F2F9986:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:05:44.588499 :8F2F998B:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:05:44.597093 :8F2F998E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:05:44.582 2025-04-26 22:05:44.597095 :8F2F998F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=7316 pso_num=24 pso_serial#=136 2025-04-26 22:05:44.597238 :8F2F9990:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=7316 (legacy spawn) 2025-04-26 22:05:44.603640 :8F2F9991:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:44.603803 :8F2F999A:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:05:44.604600 :8F2F999B:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:05:47.689085 :8F2F9A97:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:05:47.676 2025-04-26 22:05:47.689087 :8F2F9A98:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=5248 pso_num=24 pso_serial#=137 2025-04-26 22:05:47.689221 :8F2F9A99:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=5248 (legacy spawn) 2025-04-26 22:05:47.695664 :8F2F9A9A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:47.695839 :8F2F9AA3:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:05:47.696629 :8F2F9AA4:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:05:47.705216 :8F2F9AA7:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:05:47.691 2025-04-26 22:05:47.705218 :8F2F9AA8:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9528 pso_num=24 pso_serial#=138 2025-04-26 22:05:47.705356 :8F2F9AA9:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9528 (legacy spawn) 2025-04-26 22:05:47.724492 :8F2F9AAA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:47.724659 :8F2F9AB3:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:05:47.725519 :8F2F9AB4:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:05:56.513316 :8F2F9D8E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:05:56.507 2025-04-26 22:05:56.513317 :8F2F9D8F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=8828 pso_num=24 pso_serial#=139 2025-04-26 22:05:56.513470 :8F2F9D90:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=8828 osp_idx=22 osp_ver=177108 osp_pg=0 (spawn #121613) 2025-04-26 22:05:56.513470 :8F2F9D91:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 22:05:56.513471 :8F2F9D92:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=165 time=2975958312 2025-04-26 22:05:56.513471 :8F2F9D93:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 22:05:56.513471 :8F2F9D94:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 22:05:56.513472 :8F2F9D95:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 22:05:56.513472 :8F2F9D96:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 22:05:56.513472 :8F2F9D97:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 22:05:56.513993 :8F2F9D98:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-26 22:05:56.514641 :8F2F9DAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:56.522303 :8F2F9DCA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:05:56.522685 :8F2F9DCB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:56.522732 :8F2F9DCE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:05:56.523655 :8F2F9DD4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:05:56.523779 :8F2F9DDD:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:06:26.597955 :8F2FA93B:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:06:37.402041 :8F2FAC83:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:06:37.394 2025-04-26 22:06:37.402043 :8F2FAC84:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=6516 pso_num=24 pso_serial#=140 2025-04-26 22:06:37.402189 :8F2FAC85:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=6516 (legacy spawn) 2025-04-26 22:06:37.408765 :8F2FAC86:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:06:37.408798 :8F2FAC89:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:06:37.408945 :8F2FAC8C:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:06:37.409815 :8F2FAC9D:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:06:44.113063 :8F2FAEC2:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:06:44.104 2025-04-26 22:06:44.113065 :8F2FAEC3:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9252 pso_num=24 pso_serial#=141 2025-04-26 22:06:44.113205 :8F2FAEC4:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9252 (legacy spawn) 2025-04-26 22:06:44.119711 :8F2FAEC5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:06:44.119874 :8F2FAECE:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:06:44.120671 :8F2FAECF:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-04-26 22:06:56.602256 :8F2FB2CC:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 04-26 22:06:56.597 2025-04-26 22:06:56.602258 :8F2FB2CD:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9560 pso_num=24 pso_serial#=142 2025-04-26 22:06:56.602391 :8F2FB2CE:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=9560 osp_idx=22 osp_ver=177111 osp_pg=0 (spawn #121615) 2025-04-26 22:06:56.602392 :8F2FB2CF:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-26 22:06:56.602392 :8F2FB2D0:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=166 time=2976018390 2025-04-26 22:06:56.602392 :8F2FB2D1:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-04-26 22:06:56.602393 :8F2FB2D2:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-04-26 22:06:56.602393 :8F2FB2D3:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-04-26 22:06:56.602394 :8F2FB2D4:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-26 22:06:56.602394 :8F2FB2D5:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-26 22:06:56.602880 :8F2FB2D6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-04-26 22:06:56.603518 :8F2FB2EB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:06:56.614490 :8F2FB307:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-26 22:06:56.614951 :8F2FB308:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-26 22:06:56.617329 :8F2FB309:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:06:56.617668 :8F2FB30A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:06:56.617704 :8F2FB30D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:06:56.618564 :8F2FB313:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:06:56.618692 :8F2FB31C:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04-26 22:07:18.622038 :8F2FBBA7:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-26 22:07:18.622038*:8F2FBBA9:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002495C718 estart=1745676438 eid=16779327 ctx=0x000000077FD6A000 cwh=0x0000000024950068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-04-26 22:07:18.622038*:8F2FBBAA:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002495C718 curCtx=0x0000000024958938 pubTabIdxCnt=0 2025-04-26 22:07:18.622038*:8F2FBBAB:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002495C718 2025-04-26 22:07:18.622038*:8F2FBBAC:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002495C718 2025-04-26 22:07:18.622038*:8F2FBBAD:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002495C718 curCtx=0x0000000024958938 xsc->flg4=65792 flags=2 2025-04-26 22:07:18.622038*:8F2FBBAE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002495C718 2025-04-26 22:07:18.623876 :8F2FBBAF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.623907 :8F2FBBB2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-04-26 22:07:18.641885 :8F2FBBF5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.642087 :8F2FBBFD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.642258 :8F2FBC05:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.642411 :8F2FBC0D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.642570 :8F2FBC15:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.642720 :8F2FBC1D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.642864 :8F2FBC25:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.643021 :8F2FBC2D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.643214 :8F2FBC35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.643371 :8F2FBC3D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.643521 :8F2FBC45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.643666 :8F2FBC4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.643806 :8F2FBC55:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.643980 :8F2FBC5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.644126 :8F2FBC65:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.644443 :8F2FBC6D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.644694 :8F2FBC75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:18.662935 :8F2FBC7D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:20.175423*:8F2FBD6C:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026B93AD0 estart=1745676440 eid=17831870 ctx=0x0000000777968158 cwh=0x00000000274B0068 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-04-26 22:07:20.175423*:8F2FBD6D:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026B93AD0 curCtx=0x00000000275719A8 pubTabIdxCnt=0 2025-04-26 22:07:20.175423*:8F2FBD6E:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026B93AD0 2025-04-26 22:07:20.175423*:8F2FBD6F:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026B93AD0 2025-04-26 22:07:20.175423*:8F2FBD70:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BFB820 estart=1745676438 eid=16777285 ctx=0x000000077B54EAC8 cwh=0x0000000024980608 cpu=1328125 buffg=72600 interb=204800 r=25 rb=204800 w=0 wb=0 2025-04-26 22:07:20.175423*:8F2FBD71:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BFB820 curCtx=0x0000000027579FF0 pubTabIdxCnt=0 2025-04-26 22:07:20.175423*:8F2FBD72:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BFB820 2025-04-26 22:07:20.175423*:8F2FBD73:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BFB820 2025-04-26 22:07:20.175423*:8F2FBD74:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026B93AD0 curCtx=0x00000000275719A8 xsc->flg4=65792 flags=1 2025-04-26 22:07:20.175423*:8F2FBD75:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026B93AD0 2025-04-26 22:07:20.316046*:8F2FBDF9:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BFB820 curCtx=0x0000000027579FF0 xsc->flg4=65792 flags=2 2025-04-26 22:07:20.316046*:8F2FBDFA:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BFB820 2025-04-26 22:07:20.319911 :8F2FBDFB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:20.342339 :8F2FBE1D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:20.344629 :8F2FBE25:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-04-26 22:07:20.344858 :8F2FBE26:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-04-26 22:07:20.345855 :8F2FBE27:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:20.345966 :8F2FBE2A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:20.346934 :8F2FBE3C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:20.348913 :8F2FBE4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:20.349246 :8F2FBE58:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:20.394181*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-04-26 22:07:20.394181*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-04-26 22:07:20.394181*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-04-26 22:07:20.409807*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-04-26 22:07:20.409807*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-04-26 22:07:20.409807*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-04-26 22:07:20.409807*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-04-26 22:07:20.480041 :8F2FBEFD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:22.414193 :8F2FBFB8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:22.414208 :8F2FBFB9:db_trace:ktur.c@3079:ktuabt(): [10444:24:193] ABORT TRANSACTION - xid: 0x0005.005.0000bf47 2025-04-26 22:07:24.893004 :8F2FC186:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:24.894564 :8F2FC18E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:24.905224 :8F2FC196:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-04-26 22:07:24.928012 :8F2FC19E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] 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 24 (osid: 9560, J000)