Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250722220008\orcl_j003_16236_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:36069M/63366M, Ph+PgF:41887M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 16236, image: ORACLE.EXE (J003) *** 2025-07-22 22:00:08.207 *** SESSION ID:(233.29805) 2025-07-22 22:00:08.207 *** 2025-07-22 22:00:08.207 Process diagnostic dump for ORACLE.EXE (J003), OS id=16236, pid: 29, proc_ser: 60, sid: 233, sess_ser: 29805 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 16236 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12797, hash value=841864104 Current Wait Stack: Not in wait; last wait ended 1.400951 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 1.400977 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=133 seq_num=134 snap_id=1 wait times: snap=0.000205 sec, exc=0.000205 sec, total=0.000205 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 1: waited for 'log file sequential read' log#=0x293d, block#=0x0, blocks=0x0 wait_id=132 seq_num=133 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.004654 sec of elapsed time 2: waited for 'log file sequential read' log#=0x293d, block#=0x0, blocks=0x0 wait_id=131 seq_num=132 snap_id=1 wait times: snap=0.000012 sec, exc=0.000012 sec, total=0.000012 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=130 seq_num=131 snap_id=1 wait times: snap=0.000289 sec, exc=0.000289 sec, total=0.000289 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0xe800, blocks=0x800 wait_id=129 seq_num=130 snap_id=1 wait times: snap=0.000295 sec, exc=0.000295 sec, total=0.000295 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=128 seq_num=129 snap_id=1 wait times: snap=0.000301 sec, exc=0.000301 sec, total=0.000301 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000003 sec of elapsed time 6: waited for 'log file sequential read' log#=0x0, block#=0xd800, blocks=0x800 wait_id=127 seq_num=128 snap_id=1 wait times: snap=0.000321 sec, exc=0.000321 sec, total=0.000321 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000007 sec of elapsed time 7: waited for 'log file sequential read' log#=0x0, block#=0xd000, blocks=0x800 wait_id=126 seq_num=127 snap_id=1 wait times: snap=0.000314 sec, exc=0.000314 sec, total=0.000314 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000024 sec of elapsed time 8: waited for 'log file sequential read' log#=0x0, block#=0xc800, blocks=0x800 wait_id=125 seq_num=126 snap_id=1 wait times: snap=0.000364 sec, exc=0.000364 sec, total=0.000364 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.577134 sec of elapsed time 9: waited for 'log file sequential read' log#=0x293d, block#=0x800, blocks=0x800 wait_id=124 seq_num=125 snap_id=1 wait times: snap=0.000215 sec, exc=0.000215 sec, total=0.000215 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002579 sec of elapsed time Sampled Session History of session 233 serial 29805 --------------------------------------------------- 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 --------------------------------------------------- [2 samples, 22:00:07 - 22:00:08] not in wait at each sample [1 sample, 22:00:06] waited for 'Disk file operations I/O', seq_num: 65 p1: 'FileOperation'=0x5 p2: 'fileno'=0x0 p3: 'filetype'=0x3 time_waited: 0.000265 sec (sample interval: 0 sec) [4 samples, 22:00:01 - 22:00:04] not in wait at each sample [1 sample, 22:00:00] idle wait at each sample [session created at: 22:00:01] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'Disk file operations I/O' [1 sample, 22:00:06 ] time_waited: 0.000265 sec (sample interval: 0 sec) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-22 22:00:08.207 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 16236, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-22 01:00:05.740658*:B53AFDED:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB28A28 curCtx=0x000000002DB9AE68 xsc->flg4=65792 flags=1 2025-07-22 01:00:05.740658*:B53AFDEE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB28A28 2025-07-22 01:00:05.740658*:B53AFDEF:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB266F8 curCtx=0x000000002DB9CD70 xsc->flg4=65792 flags=2 2025-07-22 01:00:05.740658*:B53AFDF0:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB266F8 2025-07-22 01:00:05.816338 :B53AFDFC: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-07-22 01:00:05.854074 :B53AFE04: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-07-22 01:00:05.854408 :B53AFE0C: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-07-22 01:00:05.854694 :B53AFE14: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-07-22 01:00:05.854711 :B53AFE17:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-22 01:00:05.854771 :B53AFE23: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-07-22 01:00:05.857918 :B53AFE31:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 01:00:15.260648 :B53B0193:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 01:00:15.250 2025-07-22 01:00:15.260650 :B53B0194:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=17516 pso_num=29 pso_serial#=50 2025-07-22 01:00:15.260787 :B53B0195:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=17516 (legacy spawn) 2025-07-22 01:00:15.267294 :B53B0196: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-07-22 01:00:15.267481 :B53B019B: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-07-22 01:00:15.268275 :B53B01A0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 01:00:17.747254 :B53B0379:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 01:00:17.735 2025-07-22 01:00:17.747256 :B53B037A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7532 pso_num=29 pso_serial#=51 2025-07-22 01:00:17.747392 :B53B037B:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=7532 (legacy spawn) 2025-07-22 01:00:17.753825 :B53B037C: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-07-22 01:00:17.753993 :B53B0385: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-07-22 01:00:17.754777 :B53B0386:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 01:00:25.691261 :B53B05CE:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 01:00:25.677 2025-07-22 01:00:25.691263 :B53B05CF:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14024 pso_num=29 pso_serial#=52 2025-07-22 01:00:25.691398 :B53B05D0:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=14024 (legacy spawn) 2025-07-22 01:00:25.697859 :B53B05D1: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-07-22 01:00:25.698036 :B53B05D7: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-07-22 01:00:25.698869 :B53B05DB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 01:00:25.716974 :B53B05DE:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 01:00:25.708 2025-07-22 01:00:25.716976 :B53B05DF:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=17772 pso_num=29 pso_serial#=53 2025-07-22 01:00:25.717115 :B53B05E0:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=17772 (legacy spawn) 2025-07-22 01:00:25.723607 :B53B05E1: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-07-22 01:00:25.723778 :B53B05E9: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-07-22 01:00:25.724567 :B53B05EB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 01:00:28.511286 :B53B06E9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 01:00:28.506 2025-07-22 01:00:28.511289 :B53B06EA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18920 pso_num=29 pso_serial#=54 2025-07-22 01:00:28.511429 :B53B06EB:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=18920 osp_idx=27 osp_ver=14843 osp_pg=0 (spawn #409584) 2025-07-22 01:00:28.511430 :B53B06EC:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-22 01:00:28.511430 :B53B06ED:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=4 time=1826804408 2025-07-22 01:00:28.511430 :B53B06EE:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-22 01:00:28.511431 :B53B06EF:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-22 01:00:28.511431 :B53B06F0:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-22 01:00:28.511431 :B53B06F1:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-22 01:00:28.511432 :B53B06F2:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-22 01:00:28.511928 :B53B06F3: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-07-22 01:00:28.511973 :B53B06F9: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-07-22 01:00:28.516239 :B53B0707:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-07-22 01:00:28.516281 :B53B0708:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-07-22 01:00:28.516537 :B53B0709:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-07-22 01:00:28.516552 :B53B070A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-07-22 01:00:28.516759 :B53B070B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-07-22 01:00:28.516771 :B53B070C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-07-22 01:00:28.517045 :B53B070D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-07-22 01:00:28.517059 :B53B070E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-07-22 01:00:28.517271 :B53B070F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-07-22 01:00:28.517284 :B53B0710:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-07-22 01:00:28.517498 :B53B0711:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-07-22 01:00:28.517511 :B53B0712:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-07-22 01:00:28.519852 :B53B0713:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 01:00:28.990139 :B53B0738:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 01:00:28.977 2025-07-22 01:00:28.990141 :B53B0739:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18608 pso_num=29 pso_serial#=55 2025-07-22 01:00:28.990283 :B53B073A:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=18608 (legacy spawn) 2025-07-22 01:00:28.996822 :B53B073B: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-07-22 01:00:28.996997 :B53B0741: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-07-22 01:00:28.997789 :B53B0745:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 01:00:29.006378 :B53B0748:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 01:00:28.993 2025-07-22 01:00:29.006380 :B53B0749:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7184 pso_num=29 pso_serial#=56 2025-07-22 01:00:29.006514 :B53B074A:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=7184 (legacy spawn) 2025-07-22 01:00:29.013054 :B53B0756: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-07-22 01:00:29.013212 :B53B075F: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-07-22 01:00:29.013993 :B53B0760:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 16:00:01.580894 :B5826090:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 16:00:01.568 2025-07-22 16:00:01.580896 :B5826091:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=19108 pso_num=29 pso_serial#=57 2025-07-22 16:00:01.581031 :B5826092:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=19108 (legacy spawn) 2025-07-22 16:00:01.587500 :B5826093: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-07-22 16:00:01.587812 :B5826099: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-07-22 16:00:01.588601 :B582609D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 16:00:01.597155 :B58260A0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 16:00:01.583 2025-07-22 16:00:01.597157 :B58260A1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=2860 pso_num=29 pso_serial#=58 2025-07-22 16:00:01.597290 :B58260A2:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=2860 (legacy spawn) 2025-07-22 16:00:01.603889 :B58260A3: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-07-22 16:00:01.604052 :B58260AC: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-07-22 16:00:01.604858 :B58260AD:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 16:00:02.768051 :B5826193:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 16:00:02.765 2025-07-22 16:00:02.768053 :B5826194:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=17796 pso_num=29 pso_serial#=59 2025-07-22 16:00:02.768184 :B5826195:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=17796 osp_idx=27 osp_ver=14848 osp_pg=0 (spawn #411652) 2025-07-22 16:00:02.768184 :B5826196:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-22 16:00:02.768185 :B5826197:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=5 time=1880778642 2025-07-22 16:00:02.768185 :B5826198:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-22 16:00:02.768185 :B5826199:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-22 16:00:02.768186 :B582619A:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-22 16:00:02.768186 :B582619B:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-22 16:00:02.768186 :B582619C:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-22 16:00:02.768683 :B582619D: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-07-22 16:00:02.768739 :B58261A3: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-07-22 16:00:02.775907 :B58261B1: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-07-22 16:00:02.777044 :B58261B9: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-07-22 16:00:02.777626 :B58261C1: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-07-22 16:00:02.778092 :B58261C9: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-07-22 16:00:02.778526 :B58261D1: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-07-22 16:00:02.781030 :B58261D9: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-07-22 16:00:02.782146 :B58261E1: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-07-22 16:00:02.832097 :B58261E9: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-07-22 16:00:02.832972 :B58261F1: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-07-22 16:00:02.833198 :B58261F9: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-07-22 16:00:02.833406 :B5826201: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-07-22 16:00:02.835291 :B5826209:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-22 22:00:01.073665 :B59EA16C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-22 22:00:01.067 2025-07-22 22:00:01.073666 :B59EA16D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16236 pso_num=29 pso_serial#=60 2025-07-22 22:00:01.073788 :B59EA173:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=16236 osp_idx=27 osp_ver=14849 osp_pg=0 (spawn #412485) 2025-07-22 22:00:01.073789 :B59EA174:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-22 22:00:01.073789 :B59EA175:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=6 time=1902376970 2025-07-22 22:00:01.073790 :B59EA176:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-22 22:00:01.073790 :B59EA177:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-22 22:00:01.073791 :B59EA178:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-22 22:00:01.073791 :B59EA179:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-22 22:00:01.073792 :B59EA17A:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-22 22:00:01.074346 :B59EA183: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-07-22 22:00:01.079375 :B59EA19D: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-07-22 22:00:01.079399 :B59EA1A4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-07-22 22:00:01.097139 :B59EA362: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-07-22 22:00:01.097424 :B59EA36A: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-07-22 22:00:01.097605 :B59EA372: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-07-22 22:00:01.097775 :B59EA37A: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-07-22 22:00:01.097943 :B59EA382: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-07-22 22:00:01.098106 :B59EA38A: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-07-22 22:00:01.098262 :B59EA392: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-07-22 22:00:01.098419 :B59EA39A: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-07-22 22:00:01.098574 :B59EA3A2: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-07-22 22:00:01.098722 :B59EA3AA: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-07-22 22:00:01.099174 :B59EA3B2: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-07-22 22:00:01.099513 :B59EA3BA: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-07-22 22:00:01.099730 :B59EA3C2: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-07-22 22:00:01.099901 :B59EA3CA: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-07-22 22:00:01.100068 :B59EA3D2: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-07-22 22:00:01.100234 :B59EA3DA: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-07-22 22:00:01.100387 :B59EA3E2: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-07-22 22:00:01.100564 :B59EA3EA: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-07-22 22:00:01.100731 :B59EA3F2: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-07-22 22:00:01.100892 :B59EA3FA: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-07-22 22:00:01.101050 :B59EA402: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-07-22 22:00:01.101214 :B59EA40A: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-07-22 22:00:01.101380 :B59EA412: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-07-22 22:00:01.101528 :B59EA41A: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-07-22 22:00:01.101680 :B59EA422: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-07-22 22:00:01.128567 :B59EA42A: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-07-22 22:00:02.191829*:B59EA5AD:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000325D3AD0 estart=1753192801 eid=20652514 ctx=0x0000000777968158 cwh=0x00000000500C0158 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-07-22 22:00:02.191829*:B59EA5AE:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000325D3AD0 curCtx=0x000000004FFC1BF8 pubTabIdxCnt=0 2025-07-22 22:00:02.191829*:B59EA5AF:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000325D3AD0 2025-07-22 22:00:02.191829*:B59EA5B0:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000325D3AD0 2025-07-22 22:00:02.191829*:B59EA5B1:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000003264B6F0 estart=1753192801 eid=16777472 ctx=0x000000077B54EAC8 cwh=0x0000000032640068 cpu=859375 buffg=49850 interb=196608 r=24 rb=196608 w=0 wb=0 2025-07-22 22:00:02.191829*:B59EA5B2:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000003264B6F0 curCtx=0x000000004FFB7FD8 pubTabIdxCnt=0 2025-07-22 22:00:02.191829*:B59EA5B3:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000003264B6F0 2025-07-22 22:00:02.191829*:B59EA5B4:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000003264B6F0 2025-07-22 22:00:02.191829*:B59EA5B5:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000325D3AD0 curCtx=0x000000004FFC1BF8 xsc->flg4=65792 flags=1 2025-07-22 22:00:02.191829*:B59EA5B6:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000325D3AD0 2025-07-22 22:00:02.780067*:B59EA6AA:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000003264B6F0 curCtx=0x000000004FFB7FD8 xsc->flg4=65792 flags=2 2025-07-22 22:00:02.780067*:B59EA6AB:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000003264B6F0 2025-07-22 22:00:02.785760 :B59EA6AC: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-07-22 22:00:02.806126 :B59EA6E4: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-07-22 22:00:02.808109 :B59EA6EC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-07-22 22:00:02.808328 :B59EA6ED:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-07-22 22:00:02.809220 :B59EA6EE: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-07-22 22:00:02.809319 :B59EA6F1: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-07-22 22:00:02.810306 :B59EA703: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-07-22 22:00:02.811922 :B59EA70B: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-07-22 22:00:02.812200 :B59EA713: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-07-22 22:00:02.873825*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-07-22 22:00:02.873825*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-07-22 22:00:02.873825*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-07-22 22:00:02.873825*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-07-22 22:00:02.873825*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-07-22 22:00:02.873825*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-07-22 22:00:02.873825*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-07-22 22:00:02.945082 :B59EA769: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-07-22 22:00:04.876070 :B59EA94A: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-07-22 22:00:04.876080 :B59EA94B:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0008.01e.0000cf9e 2025-07-22 22:00:07.262220 :B59EAB06: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-07-22 22:00:07.263624 :B59EAB0E: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-07-22 22:00:07.274056 :B59EAB16: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-07-22 22:00:07.300604 :B59EAB1E: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 16236, J003)