Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250904221956\orcl_m002_22768_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:35062M/63366M, Ph+PgF:39923M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 22768, image: ORACLE.EXE (M002) *** 2025-09-04 22:19:56.165 *** SESSION ID:(233.34021) 2025-09-04 22:19:56.165 *** 2025-09-04 22:19:56.165 Process diagnostic dump for ORACLE.EXE (M002), OS id=22768, pid: 29, proc_ser: 106, sid: 233, sess_ser: 34021 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'db file sequential read' file#=0x2, block#=0xe972, blocks=0x1 wait_id=1761 seq_num=1762 snap_id=1 wait times: snap=0.000015 sec, exc=0.000015 sec, total=0.000015 sec wait times: max=infinite, heur=0.000015 sec wait counts: calls=0 os=0 in_wait=1 iflags=0x5a0 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000346 sec since current wait 0: waited for 'db file sequential read' file#=0x2, block#=0x893a, blocks=0x1 wait_id=1760 seq_num=1761 snap_id=1 wait times: snap=0.003131 sec, exc=0.003131 sec, total=0.003131 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000172 sec of elapsed time 1: waited for 'db file sequential read' file#=0x2, block#=0x8812, blocks=0x1 wait_id=1759 seq_num=1760 snap_id=1 wait times: snap=0.001072 sec, exc=0.001072 sec, total=0.001072 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000138 sec of elapsed time 2: waited for 'db file sequential read' file#=0x2, block#=0x7c0a, blocks=0x1 wait_id=1758 seq_num=1759 snap_id=1 wait times: snap=0.000083 sec, exc=0.000083 sec, total=0.000083 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000144 sec of elapsed time 3: waited for 'db file sequential read' file#=0x2, block#=0x876a, blocks=0x1 wait_id=1757 seq_num=1758 snap_id=1 wait times: snap=0.000051 sec, exc=0.000051 sec, total=0.000051 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000138 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x8752, blocks=0x1 wait_id=1756 seq_num=1757 snap_id=1 wait times: snap=0.000052 sec, exc=0.000052 sec, total=0.000052 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000151 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x7be2, blocks=0x1 wait_id=1755 seq_num=1756 snap_id=1 wait times: snap=0.000114 sec, exc=0.000114 sec, total=0.000114 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000185 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x7bca, blocks=0x1 wait_id=1754 seq_num=1755 snap_id=1 wait times: snap=0.000891 sec, exc=0.000891 sec, total=0.000891 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000176 sec of elapsed time 7: waited for 'db file sequential read' file#=0x2, block#=0x7baa, blocks=0x1 wait_id=1753 seq_num=1754 snap_id=1 wait times: snap=0.000119 sec, exc=0.000119 sec, total=0.000119 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000348 sec of elapsed time 8: waited for 'db file sequential read' file#=0x2, block#=0x7b6a, blocks=0x1 wait_id=1752 seq_num=1753 snap_id=1 wait times: snap=0.005273 sec, exc=0.005273 sec, total=0.005273 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000144 sec of elapsed time 9: waited for 'db file sequential read' file#=0x2, block#=0x7b4a, blocks=0x1 wait_id=1751 seq_num=1752 snap_id=1 wait times: snap=0.000198 sec, exc=0.000198 sec, total=0.000198 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000147 sec of elapsed time Sampled Session History of session 233 serial 34021 --------------------------------------------------- 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 --------------------------------------------------- [1 sample, 22:19:55] waited for 'db file sequential read', seq_num: 1497 p1: 'file#'=0x2 p2: 'block#'=0x4312 p3: 'blocks'=0x1 time_waited: >= 0 sec (still in wait) [1 sample, 22:19:54] idle wait at each sample [session created at: 22:19:55] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'db file sequential read' [1 sample, 22:19:55 ] time_waited: >= 0 sec (still in wait) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-04 22:19:56.165 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 22768, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-04 01:00:27.828116 :C8A8905F:db_trace:kcrfw.c@4522:kcrf_commit_force(): [10021:29:233:13] 0000000000000000 2025-09-04 01:00:27.831181 :C8A89078:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 16:00:14.221826 :C8F017E9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 16:00:14.214 2025-09-04 16:00:14.221829 :C8F017EA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=19064 pso_num=29 pso_serial#=96 2025-09-04 16:00:14.221986 :C8F017EB:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=19064 osp_idx=27 osp_ver=16925 osp_pg=0 (spawn #558317) 2025-09-04 16:00:14.221986 :C8F017EC:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-04 16:00:14.221987 :C8F017ED:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=115 time=1387265502 2025-09-04 16:00:14.221987 :C8F017EE:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-04 16:00:14.221987 :C8F017EF:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-04 16:00:14.221988 :C8F017F0:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-04 16:00:14.221988 :C8F017F1:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-04 16:00:14.221989 :C8F017F2:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-04 16:00:14.222524 :C8F017F3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.222571 :C8F017F9:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-04 16:00:14.230712 :C8F01807:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.231866 :C8F0180F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.232436 :C8F01817:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.232904 :C8F0181F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.233334 :C8F01827:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.235985 :C8F0182F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.237151 :C8F01837:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.289322 :C8F0184B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.290264 :C8F01853:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.290510 :C8F0185B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.290727 :C8F01863:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 16:00:14.292718 :C8F0186B:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:00:02.041864 :C90C615E:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:00:02.035 2025-09-04 22:00:02.041865 :C90C615F:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24232 pso_num=29 pso_serial#=97 2025-09-04 22:00:02.042000 :C90C6164:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24232 osp_idx=27 osp_ver=16926 osp_pg=0 (spawn #559151) 2025-09-04 22:00:02.042001 :C90C6165:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-04 22:00:02.042002 :C90C6166:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=116 time=1408853346 2025-09-04 22:00:02.042002 :C90C6167:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-04 22:00:02.042003 :C90C6168:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-04 22:00:02.042003 :C90C6169:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-04 22:00:02.042004 :C90C616A:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-04 22:00:02.042005 :C90C616B:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-04 22:00:02.042507 :C90C6171:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.047433 :C90C6190:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.047471 :C90C6195:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-09-04 22:00:02.065575 :C90C636C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.065783 :C90C6374:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.065956 :C90C637C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.066111 :C90C6384:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.066275 :C90C638C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.066457 :C90C6394:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.066634 :C90C639C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.066783 :C90C63A4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.066942 :C90C63AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.067093 :C90C63B4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.067254 :C90C63BC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.067400 :C90C63C4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.067591 :C90C63CC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.067863 :C90C63D4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.068036 :C90C63DC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.068196 :C90C63E4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.068356 :C90C63EC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.068507 :C90C63F4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.068673 :C90C63FC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.068885 :C90C6404:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.069049 :C90C640C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.069209 :C90C6414:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.069361 :C90C641C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.069994 :C90C6424:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.070226 :C90C642C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:02.096827 :C90C6434:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:03.473406*:C90C66DA:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000031233AD0 estart=1756994402 eid=22046753 ctx=0x0000000777968158 cwh=0x000000005CE90158 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-09-04 22:00:03.473406*:C90C66DB:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000031233AD0 curCtx=0x000000005CD91BF8 pubTabIdxCnt=0 2025-09-04 22:00:03.473406*:C90C66DC:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000031233AD0 2025-09-04 22:00:03.473406*:C90C66DD:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000031233AD0 2025-09-04 22:00:03.473406*:C90C66DE:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000312AB6F0 estart=1756994401 eid=16777564 ctx=0x000000077B54EAC8 cwh=0x00000000312A0068 cpu=1187500 buffg=65697 interb=196608 r=24 rb=196608 w=0 wb=0 2025-09-04 22:00:03.473406*:C90C66DF:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000312AB6F0 curCtx=0x000000005CD87FD8 pubTabIdxCnt=0 2025-09-04 22:00:03.473406*:C90C66E0:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000312AB6F0 2025-09-04 22:00:03.473406*:C90C66E1:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000312AB6F0 2025-09-04 22:00:03.473406*:C90C66E2:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000031233AD0 curCtx=0x000000005CD91BF8 xsc->flg4=65792 flags=1 2025-09-04 22:00:03.473406*:C90C66E3:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000031233AD0 2025-09-04 22:00:03.754653*:C90C6724:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000312AB6F0 curCtx=0x000000005CD87FD8 xsc->flg4=65792 flags=2 2025-09-04 22:00:03.754653*:C90C6725:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000312AB6F0 2025-09-04 22:00:03.760594 :C90C6726:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:03.783927 :C90C675F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:03.786415 :C90C6767:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-09-04 22:00:03.786681 :C90C6768:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-09-04 22:00:03.787770 :C90C6769:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:03.787898 :C90C676C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:03.789111 :C90C677E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:03.791213 :C90C6786:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:03.791603 :C90C678E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:03.848413*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-09-04 22:00:03.848413*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-09-04 22:00:03.848413*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-09-04 22:00:03.864031*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-09-04 22:00:03.864031*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-09-04 22:00:03.864031*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-09-04 22:00:03.864031*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-09-04 22:00:03.941608 :C90C681A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:05.822464 :C90C6996:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:05.822476 :C90C6997:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0008.007.0000d380 2025-09-04 22:00:08.197839 :C90C6B19:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:08.202217 :C90C6B23:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:08.213170 :C90C6B31:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:08.243384 :C90C6B45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:09.335409 :C90C6C3C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:jslv.c:9203 2025-09-04 22:00:09.347486 :C90C6C3D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:0] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:09.349012 :C90C6C45:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:00:31.560595 :C90C74BD:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:00:31.546 2025-09-04 22:00:31.560597 :C90C74BE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=23876 pso_num=29 pso_serial#=98 2025-09-04 22:00:31.560734 :C90C74BF:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=23876 (legacy spawn) 2025-09-04 22:00:31.568232 :C90C74C0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:31.568396 :C90C74C5:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-09-04 22:00:31.569207 :C90C74CA:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:00:31.577923 :C90C74CD:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:00:31.577 2025-09-04 22:00:31.577925 :C90C74CE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=22880 pso_num=29 pso_serial#=99 2025-09-04 22:00:31.578066 :C90C74CF:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=22880 (legacy spawn) 2025-09-04 22:00:31.584539 :C90C74D0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:31.584703 :C90C74D9:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-09-04 22:00:31.585520 :C90C74DA:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:00:32.057838 :C90C74FB:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:00:32.049 2025-09-04 22:00:32.057841 :C90C74FC:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18748 pso_num=29 pso_serial#=100 2025-09-04 22:00:32.057991 :C90C74FD:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=18748 (legacy spawn) 2025-09-04 22:00:32.064605 :C90C74FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:32.064780 :C90C7507:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-09-04 22:00:32.065596 :C90C7508:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:00:58.128768 :C90C7E54:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:00:58.115 2025-09-04 22:00:58.128770 :C90C7E55:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=21040 pso_num=29 pso_serial#=101 2025-09-04 22:00:58.128908 :C90C7E56:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=21040 osp_idx=27 osp_ver=16930 osp_pg=0 (spawn #559155) 2025-09-04 22:00:58.128908 :C90C7E57:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-04 22:00:58.128909 :C90C7E58:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=117 time=1408909424 2025-09-04 22:00:58.128909 :C90C7E59:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-04 22:00:58.128910 :C90C7E5A:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-04 22:00:58.128910 :C90C7E5B:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-04 22:00:58.128910 :C90C7E5C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-04 22:00:58.128911 :C90C7E5D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-04 22:00:58.129431 :C90C7E5E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.129473 :C90C7E64:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-04 22:00:58.137455 :C90C7E72:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.138606 :C90C7E7A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.139169 :C90C7E82:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.139724 :C90C7E8A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.140175 :C90C7E92:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.142835 :C90C7E9A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.144044 :C90C7EA2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.199660 :C90C7EAA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.200759 :C90C7EB2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.201045 :C90C7EBA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.201280 :C90C7EC2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:00:58.203588 :C90C7ECA:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:19:51.435048 :C90E46CF:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:19:51.426 2025-09-04 22:19:51.435051 :C90E46D0:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=23384 pso_num=29 pso_serial#=102 2025-09-04 22:19:51.435192 :C90E46D1:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=23384 (legacy spawn) 2025-09-04 22:19:51.441826 :C90E46D2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:19:51.442111 :C90E46DB:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-09-04 22:19:51.442932 :C90E46DC:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:19:53.622788 :C90E4A97:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:19:53.608 2025-09-04 22:19:53.622791 :C90E4A98:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=22996 pso_num=29 pso_serial#=103 2025-09-04 22:19:53.622934 :C90E4A99:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=22996 (legacy spawn) 2025-09-04 22:19:53.629446 :C90E4A9C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:19:53.629880 :C90E4AA5:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-09-04 22:19:53.630700 :C90E4AA6:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:19:53.639473 :C90E4AA9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:19:53.639 2025-09-04 22:19:53.639474 :C90E4AAA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=23180 pso_num=29 pso_serial#=104 2025-09-04 22:19:53.639612 :C90E4AAB:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=23180 (legacy spawn) 2025-09-04 22:19:53.646505 :C90E4AAC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-04 22:19:53.646830 :C90E4AB5:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-09-04 22:19:53.647831 :C90E4AB6:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:19:53.900843 :C90E4B69:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:19:53.899 2025-09-04 22:19:53.900845 :C90E4B6A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=19144 pso_num=29 pso_serial#=105 2025-09-04 22:19:53.901006 :C90E4B6B:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=19144 osp_idx=27 osp_ver=16934 osp_pg=0 (spawn #559201) 2025-09-04 22:19:53.901006 :C90E4B6C:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-04 22:19:53.901007 :C90E4B6D:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=118 time=1410045190 2025-09-04 22:19:53.901007 :C90E4B6E:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-04 22:19:53.901007 :C90E4B6F:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-04 22:19:53.901008 :C90E4B70:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-04 22:19:53.901008 :C90E4B71:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-04 22:19:53.901008 :C90E4B72:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-04 22:19:53.902474 :C90E4B73:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-04 22:19:53.902522 :C90E4B79:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-04 22:19:54.013441 :C90E4BAB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-04 22:19:55.218517 :C90E4BE3:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-04 22:19:55.212 2025-09-04 22:19:55.218519 :C90E4BE4:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=22768 pso_num=29 pso_serial#=106 2025-09-04 22:19:55.218650 :C90E4BE5:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=22768 osp_idx=27 osp_ver=16935 osp_pg=0 (spawn #559203) 2025-09-04 22:19:55.218650 :C90E4BE6:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-04 22:19:55.218651 :C90E4BE7:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=119 time=1410046518 2025-09-04 22:19:55.218651 :C90E4BE8:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-04 22:19:55.218652 :C90E4BE9:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-04 22:19:55.218652 :C90E4BEA:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-04 22:19:55.218652 :C90E4BEB:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-04 22:19:55.218653 :C90E4BEC:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-04 22:19:55.219146 :C90E4BED:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-04 22:19:55.219201 :C90E4BF3:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 22768, M002)