Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250510060006\orcl_j003_13116_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:37501M/63366M, Ph+PgF:44880M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 13116, image: ORACLE.EXE (J003) *** 2025-05-10 06:00:06.166 *** SESSION ID:(233.21259) 2025-05-10 06:00:06.166 *** 2025-05-10 06:00:06.166 Process diagnostic dump for ORACLE.EXE (J003), OS id=13116, pid: 29, proc_ser: 152, sid: 233, sess_ser: 21259 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 13116 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12402, hash value=2890698037 Current Wait Stack: Not in wait; last wait ended 2.324287 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.324312 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=43 seq_num=44 snap_id=1 wait times: snap=0.000181 sec, exc=0.000181 sec, total=0.000181 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.067720 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=42 seq_num=43 snap_id=1 wait times: snap=0.000009 sec, exc=0.000009 sec, total=0.000009 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.759423 sec of elapsed time 2: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=41 seq_num=42 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.025032 sec of elapsed time 3: 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.000004 sec, exc=0.000004 sec, total=0.000004 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.013026 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000069 sec, exc=0.000069 sec, total=0.000069 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049606 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.006795 sec, exc=0.006795 sec, total=0.006795 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007881 sec of elapsed time 6: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=37 seq_num=38 snap_id=1 wait times: snap=0.000080 sec, exc=0.000080 sec, total=0.000080 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.264551 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.004775 sec, exc=0.004775 sec, total=0.004775 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000158 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.000065 sec, exc=0.000065 sec, total=0.000065 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007899 sec of elapsed time 9: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.000002 sec, exc=0.000002 sec, total=0.000002 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.000061 sec of elapsed time Sampled Session History of session 233 serial 21259 --------------------------------------------------- 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:02 - 06:00:05] not in wait at each sample [1 sample, 06:00:01] idle wait at each sample [session created at: 06:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-10 06:00:06.166 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 13116, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-10 01:00:24.353953 :9501494F:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-10 01:00:29.859135 :95014B59:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-10 01:00:29.850 2025-05-10 01:00:29.859136 :95014B5A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=8172 pso_num=29 pso_serial#=146 2025-05-10 01:00:29.859278 :95014B5B:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=8172 (legacy spawn) 2025-05-10 01:00:29.865727 :95014B5C:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:29.865905 :95014B61: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-05-10 01:00:29.866725 :95014B66:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-10 01:00:59.721259 :9501565F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-10 01:00:59.715 2025-05-10 01:00:59.721261 :95015660:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7888 pso_num=29 pso_serial#=147 2025-05-10 01:00:59.721396 :95015661:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=7888 osp_idx=27 osp_ver=10601 osp_pg=0 (spawn #166095) 2025-05-10 01:00:59.721397 :95015662: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-10 01:00:59.721397 :95015663:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=195 time=4109636875 2025-05-10 01:00:59.721397 :95015664:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 01:00:59.721398 :95015665:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 01:00:59.721398 :95015666:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 01:00:59.721398 :95015667:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 01:00:59.721399 :95015668:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 01:00:59.721900 :95015669: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-10 01:00:59.721944 :9501566F: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-10 01:00:59.729054 :9501567D:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.730116 :95015685:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.730665 :9501568D:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.731126 :95015695:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.731565 :9501569D:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.734079 :950156A5:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.735180 :950156AD:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.785017 :950156CF:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.785958 :950156D7:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.786206 :950156DF:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.786430 :950156E7:db_trace:ksl2.c@14083:ksl_update_post_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-10 01:00:59.788119 :950156EF:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-10 01:01:13.353720 :95015BD7:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-10 01:01:13.348 2025-05-10 01:01:13.353722 :95015BD8:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10076 pso_num=29 pso_serial#=148 2025-05-10 01:01:13.353852 :95015BD9:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10076 osp_idx=27 osp_ver=10602 osp_pg=0 (spawn #166097) 2025-05-10 01:01:13.353852 :95015BDA: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-10 01:01:13.353853 :95015BDB:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=196 time=4109650515 2025-05-10 01:01:13.353853 :95015BDC:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 01:01:13.353854 :95015BDD:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 01:01:13.353854 :95015BDE:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 01:01:13.353854 :95015BDF:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 01:01:13.353855 :95015BE0:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 01:01:13.354338 :95015BE1: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-10 01:01:13.354385 :95015BE8: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-10 01:01:13.360834 :95015BF4:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-10 01:03:58.764802 :95019279:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-10 01:03:58.752 2025-05-10 01:03:58.764805 :9501927A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=4460 pso_num=29 pso_serial#=149 2025-05-10 01:03:58.764950 :9501927B:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=4460 osp_idx=27 osp_ver=10603 osp_pg=0 (spawn #166106) 2025-05-10 01:03:58.764951 :9501927C: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-10 01:03:58.764951 :9501927D:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=197 time=4109815921 2025-05-10 01:03:58.764952 :9501927E:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 01:03:58.764952 :9501927F:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 01:03:58.764953 :95019280:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 01:03:58.764953 :95019281:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 01:03:58.764953 :95019282:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 01:03:58.765448 :95019283: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-10 01:03:58.765490 :95019289: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-10 01:03:58.773400 :950192AB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-10 01:19:00.900493 :9502C3C5:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-10 01:19:00.888 2025-05-10 01:19:00.900495 :9502C3C6:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12556 pso_num=29 pso_serial#=150 2025-05-10 01:19:00.900627 :9502C3C7:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12556 osp_idx=27 osp_ver=10604 osp_pg=0 (spawn #166140) 2025-05-10 01:19:00.900628 :9502C3C8: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-10 01:19:00.900628 :9502C3C9:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=198 time=4110718062 2025-05-10 01:19:00.900628 :9502C3CA:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 01:19:00.900628 :9502C3CB:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 01:19:00.900628 :9502C3CC:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 01:19:00.900629 :9502C3CD:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 01:19:00.900629 :9502C3CE:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 01:19:00.901235 :9502C3CF: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-10 01:19:00.901278 :9502C3D5: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-10 01:19:00.905347 :9502C3FE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:19:00.905387 :9502C3FF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:19:00.905653 :9502C400:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:19:00.905669 :9502C401:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:19:00.905883 :9502C402:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:19:00.905896 :9502C403:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:19:00.906108 :9502C404:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:19:00.906122 :9502C405:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:19:00.906325 :9502C406:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:19:00.906338 :9502C407:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:19:00.906541 :9502C408:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:19:00.906555 :9502C409:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:19:00.908799 :9502C40A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-10 01:49:05.096926 :95051555:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-10 01:49:05.084 2025-05-10 01:49:05.096928 :95051556:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12500 pso_num=29 pso_serial#=151 2025-05-10 01:49:05.097062 :95051557:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12500 osp_idx=27 osp_ver=10605 osp_pg=0 (spawn #166208) 2025-05-10 01:49:05.097062 :95051558: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-10 01:49:05.097063 :95051559:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=199 time=4112522250 2025-05-10 01:49:05.097063 :9505155A:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 01:49:05.097064 :9505155B:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 01:49:05.097064 :9505155C:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 01:49:05.097065 :9505155D:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 01:49:05.097065 :9505155E:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 01:49:05.097603 :9505155F: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-10 01:49:05.097642 :95051565: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-10 01:49:05.101830 :9505157E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:49:05.101876 :9505157F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:49:05.102210 :95051580:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:49:05.102226 :95051581:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:49:05.102441 :95051582:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:49:05.102455 :95051583:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:49:05.102665 :95051584:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:49:05.102679 :95051585:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:49:05.102897 :95051586:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:49:05.102911 :95051587:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:49:05.103128 :95051588:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-10 01:49:05.103141 :95051589:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-10 01:49:05.105495 :9505158A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-10 06:00:02.058468 :9518995F:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-10 06:00:02.052 2025-05-10 06:00:02.058469 :95189960:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13116 pso_num=29 pso_serial#=152 2025-05-10 06:00:02.058596 :95189961:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13116 osp_idx=27 osp_ver=10606 osp_pg=0 (spawn #166799) 2025-05-10 06:00:02.058597 :95189962: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-10 06:00:02.058598 :95189963:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=200 time=4127579218 2025-05-10 06:00:02.058599 :95189964:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-10 06:00:02.058599 :95189965:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-10 06:00:02.058600 :95189966:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-10 06:00:02.058600 :95189967:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-10 06:00:02.058601 :95189968:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-10 06:00:02.059148 :95189972: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-10 06:00:02.063390 :95189988:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=25 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:02.063512 :9518998B:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=25 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-10 06:00:02.064094 :9518998D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.064147 :95189992:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-10 06:00:02.081468 :95189B6D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.081669 :95189B75:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.081829 :95189B7D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.081999 :95189B85:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.082161 :95189B8D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.082305 :95189B95:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.082448 :95189B9D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.082593 :95189BA5:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.082917 :95189BAD:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.083086 :95189BB5:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.083248 :95189BBD:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.083561 :95189BC5:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.083781 :95189BCD:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.083929 :95189BD5:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.084085 :95189BDD:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.084236 :95189BE5:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.084387 :95189BED:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.084535 :95189BF5:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.084695 :95189BFD:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.084848 :95189C05:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.084998 :95189C0D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.085140 :95189C15:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.085288 :95189C1D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.085438 :95189C25:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.085586 :95189C2D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.085736 :95189C35:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:02.105824 :95189C3D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:03.395952*:95189E74:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000031533AD0 estart=1746828003 eid=18222138 ctx=0x0000000777968158 cwh=0x00000000344D0068 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-05-10 06:00:03.395952*:95189E76:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000031533AD0 curCtx=0x00000000345919A8 pubTabIdxCnt=0 2025-05-10 06:00:03.395952*:95189E77:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000031533AD0 2025-05-10 06:00:03.395952*:95189E7B:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000031533AD0 2025-05-10 06:00:03.395952*:95189E7C:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000315AB820 estart=1746828001 eid=16777311 ctx=0x000000077B54EAC8 cwh=0x0000000029C90608 cpu=1093750 buffg=62062 interb=204800 r=25 rb=204800 w=0 wb=0 2025-05-10 06:00:03.395952*:95189E7D:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000315AB820 curCtx=0x0000000034599FF0 pubTabIdxCnt=0 2025-05-10 06:00:03.395952*:95189E7E:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000315AB820 2025-05-10 06:00:03.395952*:95189E7F:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000315AB820 2025-05-10 06:00:03.395952*:95189E80:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000031533AD0 curCtx=0x00000000345919A8 xsc->flg4=65792 flags=1 2025-05-10 06:00:03.395952*:95189E81:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000031533AD0 2025-05-10 06:00:03.739703*:95189F93:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000315AB820 curCtx=0x0000000034599FF0 xsc->flg4=65792 flags=2 2025-05-10 06:00:03.739703*:95189F94:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000315AB820 2025-05-10 06:00:03.754724 :95189F95:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:03.777195 :95189F9D:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:03.779510 :95189FA5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-05-10 06:00:03.779732 :95189FA6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-05-10 06:00:03.780753 :95189FA7:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:03.780852 :95189FAA:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:03.781777 :95189FBC:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:03.783656 :95189FC4:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:03.783996 :95189FCC:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:03.849079*: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-10 06:00:03.849079*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-10 06:00:03.849079*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-10 06:00:03.880337*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-10 06:00:03.880337*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-10 06:00:03.880337*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-10 06:00:03.880337*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-10 06:00:03.948587 :95189FFC:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:05.858627 :9518A13E:db_trace:ksl2.c@14083:ksl_update_post_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-10 06:00:05.858638 :9518A13F:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0009.005.0001c603 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 13116, J003)