Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250525180457\orcl_j000_13376_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:37319M/63366M, Ph+PgF:44369M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 13376, image: ORACLE.EXE (J000) *** 2025-05-25 18:04:57.495 *** SESSION ID:(201.3089) 2025-05-25 18:04:57.495 *** 2025-05-25 18:04:57.495 Process diagnostic dump for ORACLE.EXE (J000), OS id=13376, pid: 25, proc_ser: 188, sid: 201, sess_ser: 3089 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 13376 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12494, hash value=886562297 Current Wait Stack: Not in wait; last wait ended 2.229582 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.229607 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000157 sec, exc=0.000157 sec, total=0.000157 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.053752 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000009 sec, exc=0.000009 sec, total=0.000009 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.040709 sec of elapsed time 2: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x3, filetype=0x2 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.000154 sec, exc=0.000154 sec, total=0.000154 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.712297 sec of elapsed time 3: 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.025020 sec of elapsed time 4: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.012674 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.000115 sec, exc=0.000115 sec, total=0.000115 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049264 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.000113 sec, exc=0.000113 sec, total=0.000113 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007771 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.000121 sec, exc=0.000121 sec, total=0.000121 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.261893 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.002495 sec, exc=0.002495 sec, total=0.002495 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000167 sec of elapsed time 9: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=31 seq_num=32 snap_id=1 wait times: snap=0.000121 sec, exc=0.000121 sec, total=0.000121 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.008013 sec of elapsed time Sampled Session History of session 201 serial 3089 --------------------------------------------------- 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 --------------------------------------------------- [4 samples, 18:04:53 - 18:04:56] not in wait at each sample [1 sample, 18:04:52] idle wait at each sample [session created at: 18:04:53] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-25 18:04:57.495 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 13376, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-25 18:02:20.189322 :9BE72729:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:02:20.189453 :9BE72732:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:02:50.280350 :9BE730FB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:03:12.847348 :9BE737E6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:03:12.839 2025-05-25 18:03:12.847352 :9BE737E7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14680 pso_num=25 pso_serial#=178 2025-05-25 18:03:12.847489 :9BE737E8:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=14680 (legacy spawn) 2025-05-25 18:03:12.854017 :9BE737E9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:03:12.854197 :9BE737F1:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:03:12.855112 :9BE737F3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:03:13.298948 :9BE73828:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:03:13.292 2025-05-25 18:03:13.298950 :9BE73829:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13724 pso_num=25 pso_serial#=179 2025-05-25 18:03:13.299089 :9BE7382A:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=13724 (legacy spawn) 2025-05-25 18:03:13.305546 :9BE7382B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:03:13.305721 :9BE73830:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:03:13.306511 :9BE73835:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:03:20.233498 :9BE73AC2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:03:20.228 2025-05-25 18:03:20.233500 :9BE73AC3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12992 pso_num=25 pso_serial#=180 2025-05-25 18:03:20.233645 :9BE73AC4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12992 osp_idx=23 osp_ver=118754 osp_pg=0 (spawn #218613) 2025-05-25 18:03:20.233646 :9BE73AC5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 18:03:20.233646 :9BE73AC6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=82 time=1171972485 2025-05-25 18:03:20.233647 :9BE73AC7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 18:03:20.233647 :9BE73AC8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 18:03:20.233647 :9BE73AC9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 18:03:20.233648 :9BE73ACA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 18:03:20.233648 :9BE73ACB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 18:03:20.234146 :9BE73ACC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 18:03:20.234813 :9BE73AE1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:03:20.242371 :9BE73AFE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:03:20.242735 :9BE73AFF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:03:20.242771 :9BE73B02:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:03:20.243638 :9BE73B08:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:03:20.243757 :9BE73B11:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:03:50.353012 :9BE744BC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:03:58.663011 :9BE74726:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:03:58.649 2025-05-25 18:03:58.663013 :9BE74727:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14360 pso_num=25 pso_serial#=181 2025-05-25 18:03:58.663152 :9BE74728:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=14360 (legacy spawn) 2025-05-25 18:03:58.669621 :9BE74729:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:03:58.669792 :9BE7472E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:03:58.670592 :9BE74733:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:03:58.679320 :9BE74736:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:03:58.665 2025-05-25 18:03:58.679322 :9BE74737:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15228 pso_num=25 pso_serial#=182 2025-05-25 18:03:58.679463 :9BE74738:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15228 (legacy spawn) 2025-05-25 18:03:58.685901 :9BE74739:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:03:58.686061 :9BE74742:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:03:58.686864 :9BE74743:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:04:01.865592 :9BE74866:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:04:01.852 2025-05-25 18:04:01.865594 :9BE74867:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15084 pso_num=25 pso_serial#=183 2025-05-25 18:04:01.865730 :9BE74868:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15084 (legacy spawn) 2025-05-25 18:04:01.872127 :9BE74869:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:01.872157 :9BE7486C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:01.872305 :9BE7486F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:04:01.873124 :9BE74880:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:04:01.881640 :9BE74883:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:04:01.868 2025-05-25 18:04:01.881642 :9BE74884:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15160 pso_num=25 pso_serial#=184 2025-05-25 18:04:01.881787 :9BE74885:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15160 (legacy spawn) 2025-05-25 18:04:01.888283 :9BE74886:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:01.888446 :9BE7488F:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:04:01.889241 :9BE74890:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:04:15.034942 :9BE74C80:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:04:15.026 2025-05-25 18:04:15.034944 :9BE74C81:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15068 pso_num=25 pso_serial#=185 2025-05-25 18:04:15.035084 :9BE74C82:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15068 (legacy spawn) 2025-05-25 18:04:15.041596 :9BE74C83:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:15.041770 :9BE74C8C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:04:15.042596 :9BE74C8D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:04:20.339208 :9BE74E82:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:04:20.333 2025-05-25 18:04:20.339210 :9BE74E83:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14844 pso_num=25 pso_serial#=186 2025-05-25 18:04:20.339345 :9BE74E84:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14844 osp_idx=23 osp_ver=118760 osp_pg=0 (spawn #218615) 2025-05-25 18:04:20.339345 :9BE74E85:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 18:04:20.339346 :9BE74E86:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=83 time=1172032594 2025-05-25 18:04:20.339346 :9BE74E87:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 18:04:20.339346 :9BE74E88:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 18:04:20.339346 :9BE74E89:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 18:04:20.339347 :9BE74E8A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 18:04:20.339347 :9BE74E8B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 18:04:20.339841 :9BE74E8C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.340477 :9BE74EA1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.355084 :9BE74EBD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:20.355171 :9BE74EBE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:20.375713 :9BE74EBF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:20.375793 :9BE74EC0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:20.376106 :9BE74EC1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:20.376146 :9BE74EC2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:20.376202 :9BE74EC3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:20.376560 :9BE74EC4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.376599 :9BE74EC7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:20.387731 :9BE74ECD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.387802 :9BE74ED0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-25 18:04:20.387841 :9BE74ED1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-25 18:04:20.389804 :9BE74ED7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:20.389850 :9BE74ED8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:20.390331 :9BE74ED9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:20.390570 :9BE74EDA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.390605 :9BE74EDD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:20.395848 :9BE74EE3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.395920 :9BE74EE6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-05-25 18:04:20.395960 :9BE74EE7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-05-25 18:04:20.396297 :9BE74EED:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-25 18:04:20.396637 :9BE74EEE:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-25 18:04:20.396821 :9BE74EEF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:20.397081 :9BE74EF0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.397107 :9BE74EF3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:20.398752 :9BE74EF9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:20.398984 :9BE74EFA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.399014 :9BE74EFD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:20.399907 :9BE74F03:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:20.400016 :9BE74F0C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 18:04:50.470949 :9BE75BC3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:04:53.375673 :9BE75CB4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:04:53.370 2025-05-25 18:04:53.375675 :9BE75CB5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12436 pso_num=25 pso_serial#=187 2025-05-25 18:04:53.375808 :9BE75CB6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12436 osp_idx=23 osp_ver=118761 osp_pg=0 (spawn #218617) 2025-05-25 18:04:53.375809 :9BE75CB7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 18:04:53.375809 :9BE75CB8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=84 time=1172065625 2025-05-25 18:04:53.375809 :9BE75CB9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 18:04:53.375810 :9BE75CBA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 18:04:53.375810 :9BE75CBB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 18:04:53.375810 :9BE75CBC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 18:04:53.375810 :9BE75CBD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 18:04:53.376308 :9BE75CBE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.376353 :9BE75CC4:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 18:04:53.380470 :9BE75CDB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-25 18:04:53.380514 :9BE75CDC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-25 18:04:53.380809 :9BE75CDD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-25 18:04:53.380835 :9BE75CDE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-25 18:04:53.381082 :9BE75CDF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-25 18:04:53.381096 :9BE75CE0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-25 18:04:53.381313 :9BE75CE1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-25 18:04:53.381326 :9BE75CE2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-25 18:04:53.381541 :9BE75CE3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-25 18:04:53.381555 :9BE75CE4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-25 18:04:53.381769 :9BE75CE5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-05-25 18:04:53.381782 :9BE75CE6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-05-25 18:04:53.384205 :9BE75D0B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-25 18:04:53.475626 :9BE75E12:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-25 18:04:53.464 2025-05-25 18:04:53.475629 :9BE75E13:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13376 pso_num=25 pso_serial#=188 2025-05-25 18:04:53.475916 :9BE75E14:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13376 osp_idx=23 osp_ver=118762 osp_pg=0 (spawn #218620) 2025-05-25 18:04:53.475917 :9BE75E15:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 18:04:53.475917 :9BE75E16:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=85 time=1172065719 2025-05-25 18:04:53.475918 :9BE75E17:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 18:04:53.475918 :9BE75E18:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 18:04:53.475918 :9BE75E19:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 18:04:53.475919 :9BE75E1A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 18:04:53.475919 :9BE75E1B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 18:04:53.476668 :9BE75E1C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.481761 :9BE75E3B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.481811 :9BE75E3E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-25 18:04:53.498820 :9BE75E54:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.499027 :9BE75E5C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.499357 :9BE75E64:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.499622 :9BE75E6C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.499919 :9BE75E74:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.500077 :9BE75E7C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.500222 :9BE75E84:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:53.518297 :9BE75E8C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:55.182559 :9BE75FBD:db_trace:ktu.c@4871:ktuaex1r(): [10442:25:201] Extension usn 9, ext 2, nex 5 2025-05-25 18:04:55.182566 :9BE75FBE:db_trace:ktusm.c@2117:ktusmasp(): [10445:25:201] des1:tsn:1 rdba:0x00800356 where: kduwh01: kdusru 2025-05-25 18:04:55.196688 :9BE75FD0:db_trace:ktu.c@4871:ktuaex1r(): [10442:25:201] Extension usn 9, ext 3, nex 6 2025-05-25 18:04:55.196696 :9BE75FD1:db_trace:ktusm.c@2117:ktusmasp(): [10445:25:201] des1:tsn:1 rdba:0x0081b058 where: kdiwh22: kdifind 2025-05-25 18:04:55.199152 :9BE75FD2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:55.219478 :9BE75FF4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:55.221374 :9BE75FFC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-25 18:04:55.221638 :9BE75FFD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-25 18:04:55.222545 :9BE75FFE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:55.222640 :9BE76001:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:55.223502 :9BE76013:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:55.224981 :9BE7601B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:55.225257 :9BE76023:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:55.277480*: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-25 18:04:55.277480*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-25 18:04:55.277480*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-25 18:04:55.277480*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-25 18:04:55.277480*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-25 18:04:55.277480*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-25 18:04:55.277480*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-25 18:04:55.344571 :9BE760CC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:57.226231 :9BE761A9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 18:04:57.226245 :9BE761AA:db_trace:ktur.c@3079:ktuabt(): [10444:25:201] ABORT TRANSACTION - xid: 0x000a.003.0016ac7f ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 13376, J000)