Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250509220008\orcl_j003_8780_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:37482M/63366M, Ph+PgF:44850M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 8780, image: ORACLE.EXE (J003) *** 2025-05-09 22:00:08.744 *** SESSION ID:(233.21109) 2025-05-09 22:00:08.744 *** 2025-05-09 22:00:08.744 Process diagnostic dump for ORACLE.EXE (J003), OS id=8780, pid: 29, proc_ser: 77, sid: 233, sess_ser: 21109 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 8780 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12399, hash value=2228141557 Current Wait Stack: Not in wait; last wait ended 0.947248 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.947274 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=142 seq_num=143 snap_id=1 wait times: snap=0.000171 sec, exc=0.000171 sec, total=0.000171 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 1: waited for 'log file sequential read' log#=0x2791, block#=0x0, blocks=0x0 wait_id=141 seq_num=142 snap_id=1 wait times: snap=0.000004 sec, exc=0.000004 sec, total=0.000004 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.077644 sec of elapsed time 2: waited for 'log file sequential read' log#=0x2791, block#=0x0, blocks=0x0 wait_id=140 seq_num=141 snap_id=1 wait times: snap=0.000018 sec, exc=0.000018 sec, total=0.000018 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.483486 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x3800, blocks=0x800 wait_id=139 seq_num=140 snap_id=1 wait times: snap=0.000313 sec, exc=0.000313 sec, total=0.000313 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.004218 sec of elapsed time 4: waited for 'log file sequential read' log#=0x2791, block#=0x800, blocks=0x800 wait_id=138 seq_num=139 snap_id=1 wait times: snap=0.000206 sec, exc=0.000206 sec, total=0.000206 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002520 sec of elapsed time 5: waited for 'log file sequential read' log#=0x2791, block#=0x0, blocks=0x0 wait_id=137 seq_num=138 snap_id=1 wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000134 sec of elapsed time 6: waited for 'log file sequential read' log#=0x2791, block#=0x2, blocks=0x7fe wait_id=136 seq_num=137 snap_id=1 wait times: snap=0.000195 sec, exc=0.000195 sec, total=0.000195 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000170 sec of elapsed time 7: waited for 'log file sequential read' log#=0x0, block#=0x1, blocks=0x1 wait_id=135 seq_num=136 snap_id=1 wait times: snap=0.000043 sec, exc=0.000043 sec, total=0.000043 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000003 sec of elapsed time 8: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x0, filetype=0x3 wait_id=134 seq_num=135 snap_id=1 wait times: snap=0.000205 sec, exc=0.000205 sec, total=0.000205 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000129 sec of elapsed time 9: waited for 'control file sequential read' file#=0x0, block#=0x20, blocks=0x1 wait_id=133 seq_num=134 snap_id=1 wait times: snap=0.000045 sec, exc=0.000045 sec, total=0.000045 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000007 sec of elapsed time Sampled Session History of session 233 serial 21109 --------------------------------------------------- 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 --------------------------------------------------- [6 samples, 22:00:03 - 22:00:08] not in wait at each sample [1 sample, 22:00:02] waited for 'null event', seq_num: 0 p1: ''=0x0 p2: ''=0x0 p3: ''=0x0 time_waited: 0.000097 sec (sample interval: 0 sec) [1 sample, 22:00:01] idle wait at each sample [session created at: 22:00:02] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'null event' [1 sample, 22:00:02 ] time_waited: 0.000097 sec (sample interval: 0 sec) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-09 22:00:08.744 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 8780, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-09 01:00:47.361554 :94913CEC:db_trace:ksl2.c@14083:ksl_update_post_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-09 01:00:47.361569 :94913CEF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-09 01:00:47.361650 :94913CFE: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-09 01:00:47.365453 :94913D09:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-09 01:15:47.945390 :94926C6A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-09 01:15:47.933 2025-05-09 01:15:47.945392 :94926C6B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11900 pso_num=29 pso_serial#=71 2025-05-09 01:15:47.945524 :94926C6C:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11900 osp_idx=27 osp_ver=10525 osp_pg=0 (spawn #162745) 2025-05-09 01:15:47.945524 :94926C6D: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-09 01:15:47.945524 :94926C6E:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=176 time=4024125109 2025-05-09 01:15:47.945525 :94926C6F:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 01:15:47.945525 :94926C70:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 01:15:47.945525 :94926C71:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 01:15:47.945526 :94926C72:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 01:15:47.945526 :94926C73:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 01:15:47.946055 :94926C74: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-09 01:15:47.946096 :94926C7A: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-09 01:15:47.950198 :94926C93:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:15:47.950244 :94926C94:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:15:47.950498 :94926C95:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:15:47.950514 :94926C96:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:15:47.950731 :94926C97:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:15:47.950745 :94926C98:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:15:47.950958 :94926C99:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:15:47.950970 :94926C9A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:15:47.951174 :94926C9B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:15:47.951189 :94926C9C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:15:47.951392 :94926C9D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:15:47.951404 :94926C9E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:15:47.953881 :94926C9F:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-09 01:45:51.741485 :9494C275:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-09 01:45:51.729 2025-05-09 01:45:51.741487 :9494C276:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12428 pso_num=29 pso_serial#=72 2025-05-09 01:45:51.741633 :9494C277:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12428 osp_idx=27 osp_ver=10526 osp_pg=0 (spawn #162812) 2025-05-09 01:45:51.741634 :9494C278: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-09 01:45:51.741634 :9494C279:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=177 time=4025928906 2025-05-09 01:45:51.741635 :9494C27A:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 01:45:51.741635 :9494C27B:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 01:45:51.741636 :9494C27C:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 01:45:51.741636 :9494C27D:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 01:45:51.741636 :9494C27E:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 01:45:51.742148 :9494C27F: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-09 01:45:51.742189 :9494C285: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-09 01:45:51.746234 :9494C29E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:45:51.746279 :9494C29F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:45:51.746530 :9494C2A0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:45:51.746546 :9494C2A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:45:51.746752 :9494C2A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:45:51.746766 :9494C2A3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:45:51.746973 :9494C2A4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:45:51.746986 :9494C2A5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:45:51.747189 :9494C2A6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:45:51.747201 :9494C2A7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:45:51.747405 :9494C2A8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-09 01:45:51.747420 :9494C2A9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-09 01:45:51.749874 :9494C2AA:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-09 02:00:53.716102 :9495EF43:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-09 02:00:53.714 2025-05-09 02:00:53.716103 :9495EF44:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13244 pso_num=29 pso_serial#=73 2025-05-09 02:00:53.716226 :9495EF45:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13244 osp_idx=27 osp_ver=10527 osp_pg=0 (spawn #162849) 2025-05-09 02:00:53.716227 :9495EF46: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-09 02:00:53.716227 :9495EF47:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=178 time=4026830875 2025-05-09 02:00:53.716228 :9495EF48:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 02:00:53.716228 :9495EF49:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 02:00:53.716229 :9495EF4A:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 02:00:53.716229 :9495EF4B:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 02:00:53.716229 :9495EF4C:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 02:00:53.716804 :9495EF4D: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-09 02:00:53.716857 :9495EF53: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-09 02:00:53.725523 :9495EF78:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-09 08:24:22.524744 :94B416AC:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-09 08:24:22.516 2025-05-09 08:24:22.524747 :94B416AD:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10912 pso_num=29 pso_serial#=74 2025-05-09 08:24:22.525318 :94B416AE:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10912 osp_idx=27 osp_ver=10528 osp_pg=0 (spawn #163750) 2025-05-09 08:24:22.525319 :94B416AF: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-09 08:24:22.525319 :94B416B0:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=179 time=4049839671 2025-05-09 08:24:22.525319 :94B416B1:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 08:24:22.525320 :94B416B2:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 08:24:22.525320 :94B416B3:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 08:24:22.525320 :94B416B4:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 08:24:22.525321 :94B416B5:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 08:24:22.528065 :94B416B6: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-09 08:24:22.528124 :94B416BC: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-09 08:24:22.528530 :94B416BD:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-09 08:24:24.794293 :94B417F9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-09 08:24:24.786 2025-05-09 08:24:24.794295 :94B417FA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11000 pso_num=29 pso_serial#=75 2025-05-09 08:24:24.794491 :94B417FB:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11000 osp_idx=27 osp_ver=10529 osp_pg=0 (spawn #163752) 2025-05-09 08:24:24.794492 :94B417FC: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-09 08:24:24.794492 :94B417FD:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=180 time=4049841953 2025-05-09 08:24:24.794492 :94B417FE:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 08:24:24.794493 :94B417FF:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 08:24:24.794493 :94B41800:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 08:24:24.794493 :94B41801:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 08:24:24.794493 :94B41802:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 08:24:24.795003 :94B41803: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-09 08:24:24.795043 :94B41809: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-09 08:24:24.795405 :94B4180A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-09 08:24:27.754992 :94B41E82:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-09 08:24:27.750 2025-05-09 08:24:27.754994 :94B41E83:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12484 pso_num=29 pso_serial#=76 2025-05-09 08:24:27.755123 :94B41E84:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12484 osp_idx=27 osp_ver=10530 osp_pg=0 (spawn #163753) 2025-05-09 08:24:27.755124 :94B41E85: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-09 08:24:27.755125 :94B41E86:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=181 time=4049844921 2025-05-09 08:24:27.755125 :94B41E87:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 08:24:27.755126 :94B41E88:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 08:24:27.755126 :94B41E89:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 08:24:27.755127 :94B41E8A:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 08:24:27.755127 :94B41E8B:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 08:24:27.755599 :94B41E8C: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-09 08:24:27.755643 :94B41E93: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-09 08:24:27.753837 :94B41EAA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-09 08:24:27.754229 :94B41EBD:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-09 22:00:02.068467 :94F34046:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-09 22:00:02.063 2025-05-09 22:00:02.068469 :94F34047:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=8780 pso_num=29 pso_serial#=77 2025-05-09 22:00:02.068639 :94F3404C:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=8780 osp_idx=27 osp_ver=10531 osp_pg=0 (spawn #165666) 2025-05-09 22:00:02.068640 :94F3404D: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-09 22:00:02.068641 :94F3404E:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=182 time=4098779234 2025-05-09 22:00:02.068641 :94F3404F:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-09 22:00:02.068642 :94F34050:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-09 22:00:02.068642 :94F34051:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-09 22:00:02.068643 :94F34052:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-09 22:00:02.068643 :94F34053:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-09 22:00:02.069162 :94F34059: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-09 22:00:02.074063 :94F34078:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.074103 :94F3407B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-09 22:00:02.092153 :94F34265:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.092410 :94F3426D:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.092584 :94F34275:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.092752 :94F3427D:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.092925 :94F34285:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.093094 :94F3428D:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.093262 :94F34295:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.093431 :94F3429D:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.093586 :94F342A5:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.093738 :94F342AD:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.093896 :94F342B5:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.094073 :94F342BD:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.094220 :94F342C5:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.094392 :94F342CD:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.094551 :94F342D5:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.094707 :94F342DD:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.094872 :94F342E5:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.095215 :94F342ED:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.095445 :94F342F5:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.095604 :94F342FD:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.095897 :94F34305:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.096146 :94F3430D:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.096378 :94F34315:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.097125 :94F3431D:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.097364 :94F34325:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:02.124324 :94F3432D:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:03.187049*:94F3451D:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000031533AD0 estart=1746799203 eid=18204210 ctx=0x0000000777968158 cwh=0x0000000029C90AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-05-09 22:00:03.187049*:94F3451E:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000031533AD0 curCtx=0x000000003A4DC4B8 pubTabIdxCnt=0 2025-05-09 22:00:03.187049*:94F3451F:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000031533AD0 2025-05-09 22:00:03.187049*:94F34520:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000031533AD0 2025-05-09 22:00:03.187049*:94F34521:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000003156AAF8 estart=1746799202 eid=16777310 ctx=0x000000077B54EAC8 cwh=0x0000000029C90608 cpu=859375 buffg=49880 interb=204800 r=25 rb=204800 w=0 wb=0 2025-05-09 22:00:03.187049*:94F34522:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000003156AAF8 curCtx=0x00000000345B1240 pubTabIdxCnt=0 2025-05-09 22:00:03.187049*:94F34523:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000003156AAF8 2025-05-09 22:00:03.187049*:94F34524:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000003156AAF8 2025-05-09 22:00:03.187049*:94F34525:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000031533AD0 curCtx=0x000000003A4DC4B8 xsc->flg4=65792 flags=1 2025-05-09 22:00:03.187049*:94F34526:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000031533AD0 2025-05-09 22:00:03.765197*:94F345ED:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000003156AAF8 curCtx=0x00000000345B1240 xsc->flg4=65792 flags=2 2025-05-09 22:00:03.765197*:94F345EE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000003156AAF8 2025-05-09 22:00:03.778704 :94F345EF:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:03.798581 :94F34617:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:03.800510 :94F3461F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-05-09 22:00:03.800706 :94F34620:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-05-09 22:00:03.801574 :94F34621:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:03.801658 :94F34624:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:03.802470 :94F34636:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:03.803910 :94F3463E:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:03.804187 :94F34646:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:03.858948*: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-09 22:00:03.858948*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-09 22:00:03.858948*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-09 22:00:03.858948*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-09 22:00:03.858948*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-09 22:00:03.858948*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-09 22:00:03.858948*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-09 22:00:03.948104 :94F346E7:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:05.804226 :94F3486D:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:05.804238 :94F3486E:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0007.016.0000c1a7 2025-05-09 22:00:08.246395 :94F34A69:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:08.247719 :94F34A71:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:08.257945 :94F34A79:db_trace:ksl2.c@14083:ksl_update_post_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-09 22:00:08.280551 :94F34A81:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 8780, J003)