Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250508220004\orcl_j003_12708_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:37530M/63366M, Ph+PgF:44934M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 12708, image: ORACLE.EXE (J003) *** 2025-05-08 22:00:04.895 *** SESSION ID:(233.21057) 2025-05-08 22:00:04.895 *** 2025-05-08 22:00:04.895 Process diagnostic dump for ORACLE.EXE (J003), OS id=12708, pid: 29, proc_ser: 51, sid: 233, sess_ser: 21057 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12708 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12396, hash value=93387000 Current Wait Stack: Not in wait; last wait ended 2.151223 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.151248 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=41 seq_num=42 snap_id=1 wait times: snap=0.000164 sec, exc=0.000164 sec, total=0.000164 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.067690 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000008 sec, exc=0.000008 sec, total=0.000008 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.029101 sec of elapsed time 2: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x3, filetype=0x2 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000161 sec, exc=0.000161 sec, total=0.000161 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.728895 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=38 seq_num=39 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.025193 sec of elapsed time 4: 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.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.013110 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000112 sec, exc=0.000112 sec, total=0.000112 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049164 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.005391 sec, exc=0.005391 sec, total=0.005391 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007848 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.000072 sec, exc=0.000072 sec, total=0.000072 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.264272 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.003327 sec, exc=0.003327 sec, total=0.003327 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000177 sec of elapsed time 9: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.000118 sec, exc=0.000118 sec, total=0.000118 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.008077 sec of elapsed time Sampled Session History of session 233 serial 21057 --------------------------------------------------- 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: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:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-08 22:00:04.895 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 12708, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-08 01:00:36.418407 :94205053:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-08 01:00:36.418407 :94205054:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-08 01:00:36.418407 :94205055:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-08 01:00:36.418408 :94205056:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-08 01:00:36.418408 :94205057:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-08 01:00:36.418914 :94205058: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-05-08 01:00:36.418956 :9420505E: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-05-08 01:00:36.426155 :9420506C: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-05-08 01:00:36.427213 :94205074: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-05-08 01:00:36.427688 :9420507C: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-05-08 01:00:36.428117 :94205084: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-05-08 01:00:36.428538 :9420508C: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-05-08 01:00:36.431264 :94205094: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-05-08 01:00:36.432342 :9420509C: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-05-08 01:00:36.481092 :942050A4: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-05-08 01:00:36.481981 :942050AC: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-05-08 01:00:36.482217 :942050B4: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-05-08 01:00:36.482463 :942050BC: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-05-08 01:00:36.484255 :942050C4:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-08 01:02:35.364973 :942078A0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-08 01:02:35.353 2025-05-08 01:02:35.364974 :942078A1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12576 pso_num=29 pso_serial#=46 2025-05-08 01:02:35.365111 :942078A2:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12576 osp_idx=27 osp_ver=10500 osp_pg=0 (spawn #159331) 2025-05-08 01:02:35.365112 :942078A3:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-08 01:02:35.365112 :942078A4:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=159 time=3936932531 2025-05-08 01:02:35.365113 :942078A5:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-08 01:02:35.365113 :942078A6:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-08 01:02:35.365113 :942078A7:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-08 01:02:35.365114 :942078A8:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-08 01:02:35.365114 :942078A9:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-08 01:02:35.365647 :942078AA: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-05-08 01:02:35.365693 :942078B0: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-05-08 01:02:35.374250 :942078C5:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-08 01:12:36.741526 :94214A22:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-08 01:12:36.729 2025-05-08 01:12:36.741528 :94214A23:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13092 pso_num=29 pso_serial#=47 2025-05-08 01:12:36.741663 :94214A24:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13092 osp_idx=27 osp_ver=10501 osp_pg=0 (spawn #159354) 2025-05-08 01:12:36.741664 :94214A25:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-08 01:12:36.741665 :94214A26:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=160 time=3937533906 2025-05-08 01:12:36.741665 :94214A27:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-08 01:12:36.741666 :94214A28:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-08 01:12:36.741666 :94214A29:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-08 01:12:36.741666 :94214A2A:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-08 01:12:36.741667 :94214A2B:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-08 01:12:36.742179 :94214A2C: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-05-08 01:12:36.742222 :94214A32: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-05-08 01:12:36.746325 :94214A4B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:12:36.746369 :94214A4C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:12:36.746628 :94214A4D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:12:36.746644 :94214A4E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:12:36.746858 :94214A4F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:12:36.746872 :94214A50:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:12:36.747076 :94214A51:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:12:36.747089 :94214A52:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:12:36.747290 :94214A53:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:12:36.747304 :94214A54:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:12:36.747508 :94214A55:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:12:36.747521 :94214A56:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:12:36.749923 :94214A57:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-08 01:42:40.988516 :9423A4E7:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-08 01:42:40.976 2025-05-08 01:42:40.988518 :9423A4E8:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10564 pso_num=29 pso_serial#=48 2025-05-08 01:42:40.988649 :9423A4E9:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10564 osp_idx=27 osp_ver=10502 osp_pg=0 (spawn #159422) 2025-05-08 01:42:40.988650 :9423A4EA:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-08 01:42:40.988651 :9423A4EB:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=161 time=3939338140 2025-05-08 01:42:40.988651 :9423A4EC:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-08 01:42:40.988652 :9423A4ED:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-08 01:42:40.988652 :9423A4EE:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-08 01:42:40.988652 :9423A4EF:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-08 01:42:40.988653 :9423A4F0:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-08 01:42:40.989185 :9423A4F1: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-05-08 01:42:40.989240 :9423A4F7: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-05-08 01:42:40.993355 :9423A520:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:42:40.993411 :9423A521:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:42:40.993705 :9423A522:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:42:40.993721 :9423A523:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:42:40.993943 :9423A524:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:42:40.993957 :9423A525:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:42:40.994169 :9423A526:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:42:40.994183 :9423A527:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:42:40.994396 :9423A528:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:42:40.994409 :9423A529:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:42:40.994619 :9423A52A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-08 01:42:40.994633 :9423A52B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-08 01:42:40.996961 :9423A52C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-08 20:00:06.083105 :947966B7:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-08 20:00:06.081 2025-05-08 20:00:06.083107 :947966B8:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12156 pso_num=29 pso_serial#=49 2025-05-08 20:00:06.083252 :947966B9:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12156 osp_idx=27 osp_ver=10503 osp_pg=0 (spawn #161998) 2025-05-08 20:00:06.083253 :947966BA:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-08 20:00:06.083253 :947966BB:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=162 time=4005183234 2025-05-08 20:00:06.083254 :947966BC:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-08 20:00:06.083254 :947966BD:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-08 20:00:06.083255 :947966BE:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-08 20:00:06.083255 :947966BF:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-08 20:00:06.083255 :947966C0:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-08 20:00:06.083776 :947966C1: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-05-08 20:00:06.083822 :947966C8: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-05-08 20:00:06.092114 :947966EC:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-08 21:00:14.108259 :947E2878:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-08 21:00:14.106 2025-05-08 21:00:14.108260 :947E2879:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12584 pso_num=29 pso_serial#=50 2025-05-08 21:00:14.108392 :947E287A:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12584 osp_idx=27 osp_ver=10504 osp_pg=0 (spawn #162139) 2025-05-08 21:00:14.108393 :947E287B:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-08 21:00:14.108393 :947E287C:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=163 time=4008791265 2025-05-08 21:00:14.108393 :947E287D:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-08 21:00:14.108394 :947E287E:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-08 21:00:14.108394 :947E287F:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-08 21:00:14.108394 :947E2880:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-08 21:00:14.108394 :947E2881:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-08 21:00:14.108896 :947E2882: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-05-08 21:00:14.108936 :947E2889: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-05-08 21:00:14.117522 :947E28AD:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-08 22:00:00.957130 :9482E54D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-08 22:00:00.951 2025-05-08 22:00:00.957131 :9482E54E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12708 pso_num=29 pso_serial#=51 2025-05-08 22:00:00.957256 :9482E54F:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12708 osp_idx=27 osp_ver=10505 osp_pg=0 (spawn #162280) 2025-05-08 22:00:00.957257 :9482E550:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-08 22:00:00.957258 :9482E551:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=164 time=4012378125 2025-05-08 22:00:00.957258 :9482E552:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-08 22:00:00.957259 :9482E553:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-08 22:00:00.957259 :9482E554:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-08 22:00:00.957260 :9482E555:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-08 22:00:00.957260 :9482E556:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-08 22:00:00.957825 :9482E557: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-05-08 22:00:00.962793 :9482E576: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-05-08 22:00:00.962836 :9482E579:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-08 22:00:00.981027 :9482E75B: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-05-08 22:00:00.981335 :9482E763: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-05-08 22:00:00.981500 :9482E76B: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-05-08 22:00:00.981691 :9482E773: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-05-08 22:00:00.981857 :9482E77B: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-05-08 22:00:00.982010 :9482E783: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-05-08 22:00:00.982160 :9482E78B: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-05-08 22:00:00.982320 :9482E793: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-05-08 22:00:00.982475 :9482E79B: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-05-08 22:00:00.982628 :9482E7A3: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-05-08 22:00:00.982774 :9482E7AB: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-05-08 22:00:00.982925 :9482E7B3: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-05-08 22:00:00.983079 :9482E7BB: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-05-08 22:00:00.983228 :9482E7C3: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-05-08 22:00:00.983377 :9482E7CB: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-05-08 22:00:00.983543 :9482E7D3: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-05-08 22:00:00.983711 :9482E7DB: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-05-08 22:00:00.983877 :9482E7E3: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-05-08 22:00:00.984066 :9482E7EB: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-05-08 22:00:00.984556 :9482E7F3: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-05-08 22:00:00.984734 :9482E7FB: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-05-08 22:00:00.984898 :9482E803: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-05-08 22:00:00.985161 :9482E80B: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-05-08 22:00:00.985412 :9482E813: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-05-08 22:00:00.985648 :9482E81B: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-05-08 22:00:00.986260 :9482E823: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-05-08 22:00:01.012119 :9482E82B: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-05-08 22:00:02.253704*:9482EA4B:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000031533AD0 estart=1746712802 eid=18191317 ctx=0x0000000777968158 cwh=0x0000000029C90AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-05-08 22:00:02.253704*:9482EA4C:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000031533AD0 curCtx=0x000000003A4DC4B8 pubTabIdxCnt=0 2025-05-08 22:00:02.253704*:9482EA4D:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000031533AD0 2025-05-08 22:00:02.253704*:9482EA4E:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000031533AD0 2025-05-08 22:00:02.253704*:9482EA4F:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000003156AAF8 estart=1746712800 eid=16777309 ctx=0x000000077B54EAC8 cwh=0x0000000029C90608 cpu=1062500 buffg=59485 interb=204800 r=25 rb=204800 w=0 wb=0 2025-05-08 22:00:02.253704*:9482EA50:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000003156AAF8 curCtx=0x00000000345B1240 pubTabIdxCnt=0 2025-05-08 22:00:02.253704*:9482EA51:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000003156AAF8 2025-05-08 22:00:02.253704*:9482EA52:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000003156AAF8 2025-05-08 22:00:02.253704*:9482EA54:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000031533AD0 curCtx=0x000000003A4DC4B8 xsc->flg4=65792 flags=1 2025-05-08 22:00:02.253704*:9482EA55:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000031533AD0 2025-05-08 22:00:02.657230 :9482EA70:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 6, ext 1, nex 2 2025-05-08 22:00:02.657239 :9482EA71:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x008191c3 where: kdiwh22: kdifind 2025-05-08 22:00:02.659972*:9482EA72:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000003156AAF8 curCtx=0x00000000345B1240 xsc->flg4=65792 flags=2 2025-05-08 22:00:02.659972*:9482EA73:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000003156AAF8 2025-05-08 22:00:02.665846 :9482EA74: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-05-08 22:00:02.688439 :9482EA94: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-05-08 22:00:02.690813 :9482EAA4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-05-08 22:00:02.691073 :9482EAA5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-05-08 22:00:02.692253 :9482EAAE: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-05-08 22:00:02.692375 :9482EAB6: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-05-08 22:00:02.693386 :9482EAC1: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-05-08 22:00:02.693441 :9482EAC3: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-05-08 22:00:02.695300 :9482EADD: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-05-08 22:00:02.695633 :9482EAE5: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-05-08 22:00:02.753704*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-05-08 22:00:02.753704*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-08 22:00:02.753704*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-08 22:00:02.769335*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-08 22:00:02.769335*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-08 22:00:02.769335*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-08 22:00:02.769335*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-08 22:00:02.843857 :9482EBC3: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-05-08 22:00:04.716530 :9482ED67: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-05-08 22:00:04.716542 :9482ED68:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0008.001.0000c8fa ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 12708, J003)