Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250729220006\orcl_j003_1400_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:35910M/63366M, Ph+PgF:41638M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 1400, image: ORACLE.EXE (J003) *** 2025-07-29 22:00:06.350 *** SESSION ID:(233.30523) 2025-07-29 22:00:06.350 *** 2025-07-29 22:00:06.350 Process diagnostic dump for ORACLE.EXE (J003), OS id=1400, pid: 29, proc_ser: 162, sid: 233, sess_ser: 30523 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 1400 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12834, hash value=1772352875 Current Wait Stack: Not in wait; last wait ended 2.497378 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.497404 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.000145 sec, exc=0.000145 sec, total=0.000145 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.063374 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.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.026834 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.000166 sec, exc=0.000166 sec, total=0.000166 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.729159 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.025303 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.000003 sec, exc=0.000003 sec, total=0.000003 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.012905 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.000068 sec, exc=0.000068 sec, total=0.000068 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049985 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.008827 sec, exc=0.008827 sec, total=0.008827 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.008033 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.013302 sec, exc=0.013302 sec, total=0.013302 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.263346 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.005891 sec, exc=0.005891 sec, total=0.005891 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000176 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.000131 sec, exc=0.000131 sec, total=0.000131 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007867 sec of elapsed time Sampled Session History of session 233 serial 30523 --------------------------------------------------- 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, 22:00:02 - 22:00:05] not in wait at each sample [1 sample, 22:00:01] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-29 22:00:06.350 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 1400, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-29 00:05:48.273766 :B8505DCF:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=80 time=2428324158 2025-07-29 00:05:48.273766 :B8505DD0:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 00:05:48.273766 :B8505DD1:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 00:05:48.273767 :B8505DD2:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 00:05:48.273767 :B8505DD3:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 00:05:48.273767 :B8505DD4:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 00:05:48.274335 :B8505DD5: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-29 00:06:18.367649 :B850694D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 01:00:03.117319 :B8549979:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 01:00:03.103 2025-07-29 01:00:03.117321 :B854997A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18704 pso_num=29 pso_serial#=154 2025-07-29 01:00:03.117475 :B854997B:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=18704 (legacy spawn) 2025-07-29 01:00:03.124590 :B854997C: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-29 01:00:03.124771 :B8549985: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-29 01:00:03.125721 :B8549986:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 01:00:03.135216 :B8549989:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 01:00:03.134 2025-07-29 01:00:03.135217 :B854998A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18232 pso_num=29 pso_serial#=155 2025-07-29 01:00:03.135370 :B854998B:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=18232 (legacy spawn) 2025-07-29 01:00:03.151605 :B854998C: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-29 01:00:03.151773 :B8549995: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-29 01:00:03.152713 :B8549996:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 01:00:11.881948 :B8549C14:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 01:00:11.872 2025-07-29 01:00:11.881950 :B8549C15:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=19092 pso_num=29 pso_serial#=156 2025-07-29 01:00:11.882100 :B8549C16:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=19092 (legacy spawn) 2025-07-29 01:00:11.888762 :B8549C17: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-29 01:00:11.888922 :B8549C20: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-29 01:00:11.889758 :B8549C21:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 01:00:27.705868 :B854A18B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 01:00:27.697 2025-07-29 01:00:27.705870 :B854A18C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16832 pso_num=29 pso_serial#=157 2025-07-29 01:00:27.706036 :B854A18D:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=16832 (legacy spawn) 2025-07-29 01:00:27.713324 :B854A18E: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-29 01:00:27.713515 :B854A193: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-29 01:00:27.714422 :B854A198:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 01:00:31.826237 :B854A338:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 01:00:31.821 2025-07-29 01:00:31.826239 :B854A339:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=6464 pso_num=29 pso_serial#=158 2025-07-29 01:00:31.826377 :B854A33A:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=6464 osp_idx=27 osp_ver=15202 osp_pg=0 (spawn #432912) 2025-07-29 01:00:31.826377 :B854A33B: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-29 01:00:31.826378 :B854A33C:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=81 time=2431607720 2025-07-29 01:00:31.826378 :B854A33D:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 01:00:31.826379 :B854A33E:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 01:00:31.826379 :B854A33F:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 01:00:31.826379 :B854A340:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 01:00:31.826380 :B854A341:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 01:00:31.826876 :B854A342: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-29 01:00:31.826932 :B854A348: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-29 01:00:31.831430 :B854A35B: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-29 01:00:31.853847 :B854A363: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-29 01:00:31.869033 :B854A36B: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-29 01:00:31.894913 :B854A373: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-29 01:00:31.898662 :B854A37B: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-29 01:00:31.902360 :B854A383: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-29 01:00:31.907749 :B854A38B: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-29 01:00:31.908794 :B854A393: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-29 01:00:33.070941*:B854A3F9:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000029A623F8 estart=1753722032 eid=16780277 ctx=0x0000000777AAE258 cwh=0x0000000029A50410 cpu=15625 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-07-29 01:00:33.070941*:B854A3FA:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000029A623F8 curCtx=0x000000002B4FF998 pubTabIdxCnt=0 2025-07-29 01:00:33.070941*:B854A3FB:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000029A623F8 2025-07-29 01:00:33.070941*:B854A3FC:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000029A623F8 2025-07-29 01:00:33.102180*:B854A409:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000029A623F8 curCtx=0x000000002B4FF998 xsc->flg4=65792 flags=2 2025-07-29 01:00:33.102180*:B854A40A:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000029A623F8 2025-07-29 01:00:33.128619 :B854A40B: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-29 01:00:33.169128 :B854A413: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-29 01:00:33.169447 :B854A41B: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-29 01:00:33.169722 :B854A423: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-29 01:00:33.169738 :B854A426: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-29 01:00:33.169800 :B854A433: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-29 01:00:33.172489 :B854A440:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 08:23:43.493753 :B8772939:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 08:23:43.486 2025-07-29 08:23:43.493756 :B877293A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18548 pso_num=29 pso_serial#=159 2025-07-29 08:23:43.496161 :B877293B:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=18548 osp_idx=27 osp_ver=15203 osp_pg=0 (spawn #433939) 2025-07-29 08:23:43.496163 :B877293C: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-29 08:23:43.496164 :B877293D:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=82 time=2458199376 2025-07-29 08:23:43.496165 :B877293E:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 08:23:43.496165 :B877293F:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 08:23:43.496166 :B8772940:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 08:23:43.496166 :B8772941:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 08:23:43.496166 :B8772942:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 08:23:43.499062 :B8772943: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-29 08:23:43.499120 :B8772949: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-29 08:23:43.499547 :B877294A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 08:23:45.779812 :B8772A50:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 08:23:45.767 2025-07-29 08:23:45.779814 :B8772A51:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10368 pso_num=29 pso_serial#=160 2025-07-29 08:23:45.779987 :B8772A52:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10368 osp_idx=27 osp_ver=15204 osp_pg=0 (spawn #433941) 2025-07-29 08:23:45.779987 :B8772A53: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-29 08:23:45.779988 :B8772A54:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=83 time=2458201673 2025-07-29 08:23:45.779988 :B8772A55:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 08:23:45.779989 :B8772A56:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 08:23:45.779989 :B8772A57:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 08:23:45.779989 :B8772A58:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 08:23:45.779989 :B8772A59:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 08:23:45.780613 :B8772A5A: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-29 08:23:45.780676 :B8772A60: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-29 08:23:45.781183 :B8772A61:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 16:00:20.801212 :B89ACB98:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 16:00:20.793 2025-07-29 16:00:20.801215 :B89ACB99:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11804 pso_num=29 pso_serial#=161 2025-07-29 16:00:20.801409 :B89ACB9A:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11804 osp_idx=27 osp_ver=15205 osp_pg=0 (spawn #434994) 2025-07-29 16:00:20.801410 :B89ACB9B: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-29 16:00:20.801411 :B89ACB9C:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=84 time=2485596689 2025-07-29 16:00:20.801411 :B89ACB9D:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 16:00:20.801412 :B89ACB9E:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 16:00:20.801412 :B89ACB9F:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 16:00:20.801412 :B89ACBA0:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 16:00:20.801413 :B89ACBA1:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 16:00:20.801917 :B89ACBA2: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-29 16:00:20.801969 :B89ACBA8: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-29 16:00:20.809138 :B89ACBB6: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-29 16:00:20.810209 :B89ACBBE: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-29 16:00:20.810754 :B89ACBC6: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-29 16:00:20.811211 :B89ACBCE: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-29 16:00:20.811638 :B89ACBD6: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-29 16:00:20.814178 :B89ACBDE: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-29 16:00:20.815302 :B89ACBE6: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-29 16:00:20.864566 :B89ACBEE: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-29 16:00:20.865456 :B89ACBF6: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-29 16:00:20.865712 :B89ACBFE: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-29 16:00:20.866000 :B89ACC06: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-29 16:00:20.867813 :B89ACC0E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-07-29 22:00:02.047855 :B8B6A125:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 07-29 22:00:02.036 2025-07-29 22:00:02.047856 :B8B6A126:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=1400 pso_num=29 pso_serial#=162 2025-07-29 22:00:02.047975 :B8B6A12A:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=1400 osp_idx=27 osp_ver=15206 osp_pg=0 (spawn #435825) 2025-07-29 22:00:02.047976 :B8B6A12B: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-29 22:00:02.047976 :B8B6A12C:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=85 time=2507177939 2025-07-29 22:00:02.047977 :B8B6A12D:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-07-29 22:00:02.047977 :B8B6A12E:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-07-29 22:00:02.047978 :B8B6A12F:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-07-29 22:00:02.047978 :B8B6A130:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-29 22:00:02.047978 :B8B6A131:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-29 22:00:02.048534 :B8B6A138: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-29 22:00:02.053547 :B8B6A14F: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-29 22:00:02.053583 :B8B6A152:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-07-29 22:00:02.070084 :B8B6A366: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-29 22:00:02.070277 :B8B6A379: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-29 22:00:02.070449 :B8B6A381: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-29 22:00:02.070608 :B8B6A389: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-29 22:00:02.070777 :B8B6A391: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-29 22:00:02.070947 :B8B6A399: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-29 22:00:02.071120 :B8B6A3A1: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-29 22:00:02.071276 :B8B6A3A9: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-29 22:00:02.071431 :B8B6A3B1: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-29 22:00:02.071585 :B8B6A3B9: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-29 22:00:02.071743 :B8B6A3C1: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-29 22:00:02.071895 :B8B6A3C9: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-29 22:00:02.072045 :B8B6A3D1: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-29 22:00:02.072270 :B8B6A3D9: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-29 22:00:02.072439 :B8B6A3E1: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-29 22:00:02.072591 :B8B6A3E9: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-29 22:00:02.072746 :B8B6A3F1: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-29 22:00:02.073113 :B8B6A403: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-29 22:00:02.073291 :B8B6A40B: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-29 22:00:02.073446 :B8B6A413: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-29 22:00:02.073767 :B8B6A434: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-29 22:00:02.074092 :B8B6A43C: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-29 22:00:02.074342 :B8B6A444: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-29 22:00:02.074989 :B8B6A44C: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-29 22:00:02.075221 :B8B6A454: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-29 22:00:02.078169 :B8B6A45F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-07-29 22:00:02.101937 :B8B6A469: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-29 22:00:03.378499*:B8B6A6E5:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000031233AD0 estart=1753797603 eid=20881244 ctx=0x0000000777968158 cwh=0x000000002B560AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-07-29 22:00:03.378499*:B8B6A6E6:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000031233AD0 curCtx=0x000000005260C4B8 pubTabIdxCnt=0 2025-07-29 22:00:03.378499*:B8B6A6E7:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000031233AD0 2025-07-29 22:00:03.378499*:B8B6A6E8:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000031233AD0 2025-07-29 22:00:03.378499*:B8B6A6E9:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000003126AAF8 estart=1753797601 eid=16777487 ctx=0x000000077B54EAC8 cwh=0x000000002B560608 cpu=1093750 buffg=60111 interb=196608 r=24 rb=196608 w=0 wb=0 2025-07-29 22:00:03.378499*:B8B6A6EA:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000003126AAF8 curCtx=0x0000000052321240 pubTabIdxCnt=0 2025-07-29 22:00:03.378499*:B8B6A6EB:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000003126AAF8 2025-07-29 22:00:03.378499*:B8B6A6EC:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000003126AAF8 2025-07-29 22:00:03.378499*:B8B6A6ED:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000031233AD0 curCtx=0x000000005260C4B8 xsc->flg4=65792 flags=1 2025-07-29 22:00:03.378499*:B8B6A6EE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000031233AD0 2025-07-29 22:00:03.770430 :B8B6A82B:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 8, ext 1, nex 3 2025-07-29 22:00:03.770438 :B8B6A82C:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x0081b05e where: kdiwh22: kdifind 2025-07-29 22:00:03.770438*:B8B6A82D:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000003126AAF8 curCtx=0x0000000052321240 xsc->flg4=65792 flags=2 2025-07-29 22:00:03.770438*:B8B6A82E:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000003126AAF8 2025-07-29 22:00:03.778369 :B8B6A82F: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-29 22:00:03.799024 :B8B6A868: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-29 22:00:03.800917 :B8B6A870:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-07-29 22:00:03.801093 :B8B6A871:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-07-29 22:00:03.801982 :B8B6A872: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-29 22:00:03.802120 :B8B6A875: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-29 22:00:03.803014 :B8B6A887: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-29 22:00:03.804516 :B8B6A88F: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-29 22:00:03.804795 :B8B6A897: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-29 22:00:03.862912*: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-29 22:00:03.862912*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-07-29 22:00:03.862912*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-07-29 22:00:03.862912*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-07-29 22:00:03.862912*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-07-29 22:00:03.862912*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-07-29 22:00:03.862912*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-07-29 22:00:03.935366 :B8B6A921: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-29 22:00:05.860807 :B8B6AB63: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-29 22:00:05.860819 :B8B6AB64:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0008.011.0000d02f ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 1400, J003)