Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250608060004\orcl_j003_16008_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:36808M/63366M, Ph+PgF:43428M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 16008, image: ORACLE.EXE (J003) *** 2025-06-08 06:00:04.641 *** SESSION ID:(233.24791) 2025-06-08 06:00:04.641 *** 2025-06-08 06:00:04.641 Process diagnostic dump for ORACLE.EXE (J003), OS id=16008, pid: 29, proc_ser: 124, sid: 233, sess_ser: 24791 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 16008 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12561, hash value=2182766240 Current Wait Stack: Not in wait; last wait ended 2.088164 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.088191 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.000152 sec, exc=0.000152 sec, total=0.000152 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.063296 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.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.040933 sec of elapsed time 2: waited for 'latch: In memory undo latch' address=0x7b9a2b4b8, number=0xf3, tries=0x0 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000027 sec, exc=0.000027 sec, total=0.000027 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000097 sec of elapsed time 3: 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.000158 sec, exc=0.000158 sec, total=0.000158 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.710760 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.025162 sec of elapsed time 5: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.013250 sec of elapsed time 6: 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.000108 sec, exc=0.000108 sec, total=0.000108 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049974 sec of elapsed time 7: 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.007840 sec, exc=0.007840 sec, total=0.007840 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007802 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.000121 sec, exc=0.000121 sec, total=0.000121 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.260023 sec of elapsed time 9: 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.003536 sec, exc=0.003536 sec, total=0.003536 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000169 sec of elapsed time Sampled Session History of session 233 serial 24791 --------------------------------------------------- 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, 06:00:01 - 06:00:04] not in wait at each sample [1 sample, 06:00:00] idle wait at each sample [session created at: 06:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-08 06:00:04.641 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 16008, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-07 22:56:23.396010 :A1B3E6E7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 22:56:23.396212 :A1B3E6E8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 22:56:23.396225 :A1B3E6E9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 22:56:23.396425 :A1B3E6EA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 22:56:23.396438 :A1B3E6EB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 22:56:23.396642 :A1B3E6EC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 22:56:23.396655 :A1B3E6ED:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 22:56:23.399076 :A1B3E6EE:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-07 23:00:25.454738 :A1B4388B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-07 23:00:25.443 2025-06-07 23:00:25.454740 :A1B4388C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15932 pso_num=29 pso_serial#=113 2025-06-07 23:00:25.454873 :A1B4388D:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=15932 osp_idx=27 osp_ver=12352 osp_pg=0 (spawn #262617) 2025-06-07 23:00:25.454874 :A1B4388E:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 23:00:25.454874 :A1B4388F:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=85 time=2312968641 2025-06-07 23:00:25.454874 :A1B43890:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 23:00:25.454875 :A1B43891:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 23:00:25.454875 :A1B43892:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 23:00:25.454875 :A1B43893:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 23:00:25.454876 :A1B43894:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 23:00:25.455362 :A1B43895: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-06-07 23:00:25.455414 :A1B4389B: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-06-07 23:00:25.463313 :A1B438A9: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-06-07 23:00:25.464385 :A1B438B1: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-06-07 23:00:25.465032 :A1B438B9: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-06-07 23:00:25.465516 :A1B438C1: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-06-07 23:00:25.465969 :A1B438C9: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-06-07 23:00:25.468674 :A1B438D1: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-06-07 23:00:25.469862 :A1B438D9: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-06-07 23:00:25.541255 :A1B438E1: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-06-07 23:00:25.542238 :A1B438E9: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-06-07 23:00:25.542484 :A1B438F1: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-06-07 23:00:25.542706 :A1B438F9: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-06-07 23:00:25.544529 :A1B43901:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-07 23:14:04.034071 :A1B55F1B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-07 23:14:04.021 2025-06-07 23:14:04.034073 :A1B55F1C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14052 pso_num=29 pso_serial#=114 2025-06-07 23:14:04.034209 :A1B55F1D:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=14052 (legacy spawn) 2025-06-07 23:14:04.040624 :A1B55F1E: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-06-07 23:14:04.065727 :A1B55F2D: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-06-07 23:14:04.066470 :A1B55F34:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-07 23:26:27.269532 :A1B656D3:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-07 23:26:27.257 2025-06-07 23:26:27.269535 :A1B656D4:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14860 pso_num=29 pso_serial#=115 2025-06-07 23:26:27.269669 :A1B656D5:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14860 osp_idx=27 osp_ver=12354 osp_pg=0 (spawn #262678) 2025-06-07 23:26:27.269669 :A1B656D6:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-07 23:26:27.269669 :A1B656D7:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=86 time=2314530454 2025-06-07 23:26:27.269670 :A1B656D8:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-07 23:26:27.269670 :A1B656D9:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-07 23:26:27.269671 :A1B656DA:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-07 23:26:27.269671 :A1B656DB:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-07 23:26:27.269671 :A1B656DC:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-07 23:26:27.270177 :A1B656DD: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-06-07 23:26:27.270225 :A1B656E3: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-06-07 23:26:27.274315 :A1B6570C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 23:26:27.274368 :A1B6570D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 23:26:27.274621 :A1B6570E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 23:26:27.274637 :A1B6570F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 23:26:27.274863 :A1B65710:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 23:26:27.274876 :A1B65711:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 23:26:27.275088 :A1B65712:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 23:26:27.275102 :A1B65713:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 23:26:27.275306 :A1B65714:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 23:26:27.275318 :A1B65715:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 23:26:27.275516 :A1B65716:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-07 23:26:27.275529 :A1B65717:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-07 23:26:27.277917 :A1B65718:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-07 23:59:01.648407 :A1B8DEC3:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-07 23:59:01.635 2025-06-07 23:59:01.648409 :A1B8DEC4:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15840 pso_num=29 pso_serial#=116 2025-06-07 23:59:01.648558 :A1B8DEC5:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=15840 (legacy spawn) 2025-06-07 23:59:01.662728 :A1B8DEC6: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-06-07 23:59:34.819297 :A1B8EAE4:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-07 23:59:42.667859 :A1B8ED8A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-07 23:59:42.667 2025-06-07 23:59:42.667861 :A1B8ED8B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=5020 pso_num=29 pso_serial#=117 2025-06-07 23:59:42.668001 :A1B8ED8C:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=5020 (legacy spawn) 2025-06-07 23:59:42.682194 :A1B8ED8D: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-06-08 00:00:15.805323 :A1B8FD17:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-08 01:00:04.489962 :A1BDAB5F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-08 01:00:04.475 2025-06-08 01:00:04.489964 :A1BDAB60:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14912 pso_num=29 pso_serial#=118 2025-06-08 01:00:04.490099 :A1BDAB61:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=14912 (legacy spawn) 2025-06-08 01:00:04.496595 :A1BDAB62: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-06-08 01:00:04.496777 :A1BDAB67: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-06-08 01:00:04.497624 :A1BDAB6C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-08 01:00:04.506314 :A1BDAB6F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-08 01:00:04.491 2025-06-08 01:00:04.506316 :A1BDAB70:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15860 pso_num=29 pso_serial#=119 2025-06-08 01:00:04.506466 :A1BDAB71:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=15860 (legacy spawn) 2025-06-08 01:00:04.512978 :A1BDAB72: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-06-08 01:00:04.513144 :A1BDAB7B: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-06-08 01:00:04.513950 :A1BDAB7C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-08 01:00:07.601110 :A1BDAD63:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-08 01:00:07.589 2025-06-08 01:00:07.601113 :A1BDAD64:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9008 pso_num=29 pso_serial#=120 2025-06-08 01:00:07.601254 :A1BDAD65:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=9008 (legacy spawn) 2025-06-08 01:00:07.608068 :A1BDAD66: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-06-08 01:00:07.608238 :A1BDAD6F: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-06-08 01:00:07.609062 :A1BDAD70:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-08 01:00:07.617924 :A1BDAD73:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-08 01:00:07.605 2025-06-08 01:00:07.617926 :A1BDAD74:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13328 pso_num=29 pso_serial#=121 2025-06-08 01:00:07.618087 :A1BDAD75:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13328 (legacy spawn) 2025-06-08 01:00:07.624821 :A1BDAD76: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-06-08 01:00:07.624987 :A1BDAD7E: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-06-08 01:00:07.625964 :A1BDAD80:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-08 01:00:21.895880 :A1BDB1DF:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-08 01:00:21.883 2025-06-08 01:00:21.895882 :A1BDB1E0:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15868 pso_num=29 pso_serial#=122 2025-06-08 01:00:21.896014 :A1BDB1E1:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=15868 (legacy spawn) 2025-06-08 01:00:21.902563 :A1BDB1E2: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-06-08 01:00:21.902755 :A1BDB1E7: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-06-08 01:00:21.903676 :A1BDB1EC:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-08 01:00:21.936470 :A1BDB1EF:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-08 01:00:21.930 2025-06-08 01:00:21.936472 :A1BDB1F0:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13540 pso_num=29 pso_serial#=123 2025-06-08 01:00:21.936617 :A1BDB1F1:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13540 (legacy spawn) 2025-06-08 01:00:21.943634 :A1BDB1F2: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-06-08 01:00:21.943810 :A1BDB1FB: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-06-08 01:00:21.944721 :A1BDB1FC:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-08 06:00:00.777939 :A1D4B5D0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-08 06:00:00.766 2025-06-08 06:00:00.777941 :A1D4B5D1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=16008 pso_num=29 pso_serial#=124 2025-06-08 06:00:00.778089 :A1D4B5E0:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=16008 osp_idx=27 osp_ver=12363 osp_pg=0 (spawn #263590) 2025-06-08 06:00:00.778090 :A1D4B5E1:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-08 06:00:00.778090 :A1D4B5E2:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=87 time=2338143954 2025-06-08 06:00:00.778091 :A1D4B5E3:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-08 06:00:00.778091 :A1D4B5E4:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-08 06:00:00.778092 :A1D4B5E5:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-08 06:00:00.778092 :A1D4B5E6:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-08 06:00:00.778093 :A1D4B5E7:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-08 06:00:00.778648 :A1D4B5E8: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-06-08 06:00:00.783509 :A1D4B5FE: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-06-08 06:00:00.783545 :A1D4B601:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-06-08 06:00:00.801340 :A1D4B80F: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-06-08 06:00:00.801553 :A1D4B817: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-06-08 06:00:00.801822 :A1D4B81F: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-06-08 06:00:00.801993 :A1D4B827: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-06-08 06:00:00.802164 :A1D4B82F: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-06-08 06:00:00.802331 :A1D4B837: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-06-08 06:00:00.802533 :A1D4B83F: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-06-08 06:00:00.802706 :A1D4B847: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-06-08 06:00:00.802869 :A1D4B84F: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-06-08 06:00:00.803020 :A1D4B857: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-06-08 06:00:00.803181 :A1D4B85F: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-06-08 06:00:00.803336 :A1D4B867: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-06-08 06:00:00.803488 :A1D4B86F: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-06-08 06:00:00.803636 :A1D4B877: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-06-08 06:00:00.803814 :A1D4B87F: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-06-08 06:00:00.803977 :A1D4B887: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-06-08 06:00:00.804127 :A1D4B88F: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-06-08 06:00:00.804285 :A1D4B897: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-06-08 06:00:00.804443 :A1D4B89F: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-06-08 06:00:00.804591 :A1D4B8A7: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-06-08 06:00:00.804739 :A1D4B8AF: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-06-08 06:00:00.804909 :A1D4B8B7: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-06-08 06:00:00.805065 :A1D4B8BF: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-06-08 06:00:00.805211 :A1D4B8C7: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-06-08 06:00:00.805849 :A1D4B8CF: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-06-08 06:00:00.806031 :A1D4B8D7: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-06-08 06:00:00.806238 :A1D4B8DF: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-06-08 06:00:00.833092 :A1D4B8E7: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-06-08 06:00:02.459084 :A1D4BBCC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=16 loc='ktm.h LINE:583 ID:ktmpsm' id1=0 id2=0 name= type=0 2025-06-08 06:00:02.459317 :A1D4BBCF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=16 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-06-08 06:00:02.459396 :A1D4BBD1:db_trace:ksl2.c@2477:kslwtbctx(): [10005:29:233] KSL WAIT BEG [latch: In memory undo latch] 33179219128/0x7b9a2b4b8 243/0xf3 0/0x0 wait_id=39 seq_num=40 snap_id=1 2025-06-08 06:00:02.459424 :A1D4BBD4:db_trace:ksl2.c@2611:kslwtectx(): [10005:29:233] KSL WAIT END [latch: In memory undo latch] 33179219128/0x7b9a2b4b8 243/0xf3 0/0x0 wait_id=39 seq_num=40 snap_id=1 2025-06-08 06:00:02.459425 :A1D4BBD5:db_trace:ksl2.c@2619:kslwtectx(): [10005:29:233] KSL WAIT END wait times (usecs) - snap=27, exc=27, tot=27 2025-06-08 06:00:02.481231 :A1D4BBF9: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-06-08 06:00:02.502125 :A1D4BC7A: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-06-08 06:00:02.504079 :A1D4BC82:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-06-08 06:00:02.504273 :A1D4BC83:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-06-08 06:00:02.505136 :A1D4BC84: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-06-08 06:00:02.505222 :A1D4BC87: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-06-08 06:00:02.506030 :A1D4BC99: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-06-08 06:00:02.507545 :A1D4BCA1: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-06-08 06:00:02.507827 :A1D4BCA9: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-06-08 06:00:02.531913*:A1D4BCB1:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000043430230 estart=1749333601 eid=16777804 ctx=0x000000079F4EAD08 cwh=0x000000002DBE0158 cpu=15625 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-06-08 06:00:02.531913*:A1D4BCB2:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000043430230 curCtx=0x0000000043732A50 pubTabIdxCnt=0 2025-06-08 06:00:02.531913*:A1D4BCB3:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000043430230 2025-06-08 06:00:02.531913*:A1D4BCB4:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000043430230 2025-06-08 06:00:02.531913*:A1D4BCBD:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000043430230 curCtx=0x0000000043732A50 xsc->flg4=65792 flags=1 2025-06-08 06:00:02.531913*:A1D4BCBE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000043430230 2025-06-08 06:00:02.563165*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-06-08 06:00:02.563165*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-06-08 06:00:02.563165*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-06-08 06:00:02.563165*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-06-08 06:00:02.563165*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-06-08 06:00:02.563165*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-06-08 06:00:02.563165*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-06-08 06:00:02.640490 :A1D4BCC1: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-06-08 06:00:04.522816 :A1D4BDCA: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-06-08 06:00:04.522828 :A1D4BDCB:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0009.010.0001cbc1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 16008, J003)