Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250906060007\orcl_j003_4160_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:34975M/63366M, Ph+PgF:39773M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 4160, image: ORACLE.EXE (J003) *** 2025-09-06 06:00:07.763 *** SESSION ID:(233.34257) 2025-09-06 06:00:07.763 *** 2025-09-06 06:00:07.763 Process diagnostic dump for ORACLE.EXE (J003), OS id=4160, pid: 29, proc_ser: 223, sid: 233, sess_ser: 34257 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 4160 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_13031, hash value=3848599588 Current Wait Stack: Not in wait; last wait ended 1.099992 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 1.100018 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.000371 sec, exc=0.000371 sec, total=0.000371 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 1: waited for 'log file sequential read' log#=0x2a47, block#=0x0, blocks=0x0 wait_id=141 seq_num=142 snap_id=1 wait times: snap=0.000007 sec, exc=0.000007 sec, total=0.000007 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.069364 sec of elapsed time 2: waited for 'log file sequential read' log#=0x2a47, block#=0x0, blocks=0x0 wait_id=140 seq_num=141 snap_id=1 wait times: snap=0.000020 sec, exc=0.000020 sec, total=0.000020 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.479262 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0xd000, blocks=0x800 wait_id=139 seq_num=140 snap_id=1 wait times: snap=0.000363 sec, exc=0.000363 sec, total=0.000363 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000008 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0xc800, blocks=0x800 wait_id=138 seq_num=139 snap_id=1 wait times: snap=0.000301 sec, exc=0.000301 sec, total=0.000301 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000082 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0xc000, blocks=0x800 wait_id=137 seq_num=138 snap_id=1 wait times: snap=0.000324 sec, exc=0.000324 sec, total=0.000324 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.098261 sec of elapsed time 6: waited for 'log file sequential read' log#=0x2a47, block#=0x800, blocks=0x800 wait_id=136 seq_num=137 snap_id=1 wait times: snap=0.000214 sec, exc=0.000214 sec, total=0.000214 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002918 sec of elapsed time 7: waited for 'log file sequential read' log#=0x2a47, block#=0x0, blocks=0x0 wait_id=135 seq_num=136 snap_id=1 wait times: snap=0.000002 sec, exc=0.000002 sec, total=0.000002 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000150 sec of elapsed time 8: waited for 'log file sequential read' log#=0x2a47, block#=0x2, blocks=0x7fe wait_id=134 seq_num=135 snap_id=1 wait times: snap=0.000216 sec, exc=0.000216 sec, total=0.000216 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000153 sec of elapsed time 9: waited for 'log file sequential read' log#=0x0, block#=0x1, blocks=0x1 wait_id=133 seq_num=134 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.000002 sec of elapsed time Sampled Session History of session 233 serial 34257 --------------------------------------------------- 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 --------------------------------------------------- [8 samples, 06:00:00 - 06:00:07] not in wait at each sample [1 sample, 05:59:59] 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-09-06 06:00:07.763 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 4160, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-06 01:00:00.318690 :C98CDD79:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=21748 osp_idx=27 osp_ver=17046 osp_pg=0 (spawn #562905) 2025-09-06 01:00:00.318691 :C98CDD7A:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-06 01:00:00.318692 :C98CDD7B:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=144 time=1506051627 2025-09-06 01:00:00.318693 :C98CDD7C:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-06 01:00:00.318694 :C98CDD7D:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-06 01:00:00.318694 :C98CDD7E:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-06 01:00:00.318694 :C98CDD7F:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-06 01:00:00.318695 :C98CDD80:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-06 01:00:00.319227 :C98CDD81: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-09-06 01:00:30.392913 :C98CE8A7:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-06 01:02:08.432808 :C98D0B16:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-06 01:02:08.420 2025-09-06 01:02:08.432810 :C98D0B17:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24008 pso_num=29 pso_serial#=218 2025-09-06 01:02:08.433002 :C98D0B18:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24008 osp_idx=27 osp_ver=17047 osp_pg=0 (spawn #562913) 2025-09-06 01:02:08.433004 :C98D0B19:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-06 01:02:08.433005 :C98D0B1A:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=145 time=1506179737 2025-09-06 01:02:08.433005 :C98D0B1B:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-06 01:02:08.433005 :C98D0B1C:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-06 01:02:08.433006 :C98D0B1D:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-06 01:02:08.433006 :C98D0B1E:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-06 01:02:08.433006 :C98D0B1F:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-06 01:02:08.433535 :C98D0B20: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-09-06 01:02:08.433573 :C98D0B26: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-09-06 01:02:08.437473 :C98D0B3E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:02:08.437536 :C98D0B3F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:02:08.437843 :C98D0B40:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:02:08.437861 :C98D0B41:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:02:08.438089 :C98D0B42:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:02:08.438102 :C98D0B43:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:02:08.438317 :C98D0B44:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:02:08.438330 :C98D0B45:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:02:08.438539 :C98D0B46:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:02:08.438553 :C98D0B47:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:02:08.438764 :C98D0B48:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:02:08.438776 :C98D0B49:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:02:08.440974 :C98D0B6C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-06 01:32:12.129972 :C98F70AA:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-06 01:32:12.117 2025-09-06 01:32:12.129974 :C98F70AB:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=21376 pso_num=29 pso_serial#=219 2025-09-06 01:32:12.130126 :C98F70AC:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=21376 osp_idx=27 osp_ver=17048 osp_pg=0 (spawn #562981) 2025-09-06 01:32:12.130127 :C98F70AD:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-06 01:32:12.130128 :C98F70AE:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=146 time=1507983424 2025-09-06 01:32:12.130129 :C98F70AF:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-06 01:32:12.130129 :C98F70B0:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-06 01:32:12.130129 :C98F70B1:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-06 01:32:12.130130 :C98F70B2:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-06 01:32:12.130131 :C98F70B3:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-06 01:32:12.130662 :C98F70B4: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-09-06 01:32:12.130706 :C98F70BA: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-09-06 01:32:12.134807 :C98F70D3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:32:12.134855 :C98F70D4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:32:12.135112 :C98F70D5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:32:12.135132 :C98F70D6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:32:12.135352 :C98F70D7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:32:12.135366 :C98F70D8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:32:12.135571 :C98F70D9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:32:12.135584 :C98F70DA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:32:12.135793 :C98F70DB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:32:12.135806 :C98F70DC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:32:12.136013 :C98F70DD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-09-06 01:32:12.136026 :C98F70DE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-09-06 01:32:12.138482 :C98F70DF:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-06 02:02:15.884340 :C991CDB6:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-06 02:02:15.881 2025-09-06 02:02:15.884342 :C991CDB7:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24200 pso_num=29 pso_serial#=220 2025-09-06 02:02:15.884479 :C991CDB8:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24200 osp_idx=27 osp_ver=17049 osp_pg=0 (spawn #563053) 2025-09-06 02:02:15.884479 :C991CDB9:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-06 02:02:15.884480 :C991CDBA:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=147 time=1509787174 2025-09-06 02:02:15.884481 :C991CDBB:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-06 02:02:15.884481 :C991CDBC:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-06 02:02:15.884482 :C991CDBD:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-06 02:02:15.884482 :C991CDBE:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-06 02:02:15.884482 :C991CDBF:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-06 02:02:15.884994 :C991CDC0: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-09-06 02:02:15.885042 :C991CDC6: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-09-06 02:02:15.894346 :C991CDEE:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-06 03:02:23.045325 :C996862C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-06 03:02:23.041 2025-09-06 03:02:23.045327 :C996862D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=24036 pso_num=29 pso_serial#=221 2025-09-06 03:02:23.045464 :C996862E:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=24036 osp_idx=27 osp_ver=17050 osp_pg=0 (spawn #563192) 2025-09-06 03:02:23.045465 :C996862F:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-06 03:02:23.045465 :C9968630:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=148 time=1513394330 2025-09-06 03:02:23.045466 :C9968631:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-06 03:02:23.045466 :C9968632:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-06 03:02:23.045467 :C9968633:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-06 03:02:23.045467 :C9968634:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-06 03:02:23.045467 :C9968635:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-06 03:02:23.045985 :C9968636: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-09-06 03:02:23.046037 :C996863C: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-09-06 03:02:23.055141 :C9968664:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-06 04:02:30.088209 :C99B31F2:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-06 04:02:30.085 2025-09-06 04:02:30.088211 :C99B31F3:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=22688 pso_num=29 pso_serial#=222 2025-09-06 04:02:30.088357 :C99B31F4:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=22688 osp_idx=27 osp_ver=17051 osp_pg=0 (spawn #563330) 2025-09-06 04:02:30.088358 :C99B31F5:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-06 04:02:30.088359 :C99B31F6:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=149 time=1517001377 2025-09-06 04:02:30.088359 :C99B31F7:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-06 04:02:30.088360 :C99B31F8:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-06 04:02:30.088360 :C99B31F9:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-06 04:02:30.088360 :C99B31FA:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-06 04:02:30.088361 :C99B31FB:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-06 04:02:30.088897 :C99B31FC: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-09-06 04:02:30.088955 :C99B3202: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-09-06 04:02:30.097956 :C99B321A:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-09-06 06:00:00.583969 :C9A45239:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 09-06 06:00:00.577 2025-09-06 06:00:00.583970 :C9A4523A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=4160 pso_num=29 pso_serial#=223 2025-09-06 06:00:00.584174 :C9A45240:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=4160 osp_idx=27 osp_ver=17052 osp_pg=0 (spawn #563602) 2025-09-06 06:00:00.584176 :C9A45241:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-06 06:00:00.584176 :C9A45242:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=150 time=1524051893 2025-09-06 06:00:00.584177 :C9A45243:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-09-06 06:00:00.584177 :C9A45244:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-09-06 06:00:00.584178 :C9A45245:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-09-06 06:00:00.584178 :C9A45246:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-06 06:00:00.584179 :C9A45247:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-06 06:00:00.584727 :C9A45248: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-09-06 06:00:00.589763 :C9A45267:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.589802 :C9A4526A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-09-06 06:00:00.607835 :C9A45442:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.608067 :C9A4544A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.608239 :C9A45452:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.608754 :C9A4545A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.608954 :C9A45462:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.609220 :C9A4546A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.609501 :C9A45472:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.609666 :C9A4547A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.609820 :C9A45482:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.609972 :C9A4548A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.610123 :C9A45492:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.610269 :C9A4549A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.610431 :C9A454A2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.610595 :C9A454AA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.610742 :C9A454B2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.610898 :C9A454BA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.611062 :C9A454C2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.611219 :C9A454CA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.611367 :C9A454D2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.611512 :C9A454DA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.611731 :C9A454E2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.611902 :C9A454EA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.612055 :C9A454F2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.612244 :C9A454FA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.612492 :C9A45502:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.612647 :C9A4550A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.612819 :C9A45512:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:00.639252 :C9A4551A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.280654*:C9A45882:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000031233AD0 estart=1757109602 eid=22080051 ctx=0x0000000777968158 cwh=0x000000005CE90158 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-09-06 06:00:02.280654*:C9A45883:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000031233AD0 curCtx=0x000000005CEBEE70 pubTabIdxCnt=0 2025-09-06 06:00:02.280654*:C9A45884:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000031233AD0 2025-09-06 06:00:02.280654*:C9A45885:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000031233AD0 2025-09-06 06:00:02.280654*:C9A45886:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000312AB6F0 estart=1757109600 eid=16777566 ctx=0x000000077B54EAC8 cwh=0x00000000312A0068 cpu=1453125 buffg=78286 interb=196608 r=24 rb=196608 w=0 wb=0 2025-09-06 06:00:02.280654*:C9A45887:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000312AB6F0 curCtx=0x000000005CD87FD8 pubTabIdxCnt=0 2025-09-06 06:00:02.280654*:C9A45888:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000312AB6F0 2025-09-06 06:00:02.280654*:C9A45889:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000312AB6F0 2025-09-06 06:00:02.280654*:C9A4588B:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000031233AD0 curCtx=0x000000005CEBEE70 xsc->flg4=65792 flags=1 2025-09-06 06:00:02.280654*:C9A4588C:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000031233AD0 2025-09-06 06:00:02.295241 :C9A458B3:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 6, ext 0, nex 2 2025-09-06 06:00:02.295249 :C9A458B4:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x00800356 where: kduwh01: kdusru 2025-09-06 06:00:02.303117 :C9A458C1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.303117*:C9A458C8:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000312AB6F0 curCtx=0x000000005CD87FD8 xsc->flg4=65792 flags=2 2025-09-06 06:00:02.303117*:C9A458C9:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000312AB6F0 2025-09-06 06:00:02.310617 :C9A458CA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.333256 :C9A458DB:db_trace:ktu.c@4871:ktuaex1r(): [10442:29:233] Extension usn 6, ext 1, nex 3 2025-09-06 06:00:02.333265 :C9A458DC:db_trace:ktusm.c@2117:ktusmasp(): [10445:29:233] des1:tsn:1 rdba:0x00800357 where: kduwh01: kdusru 2025-09-06 06:00:02.333466 :C9A458DD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.335615 :C9A458EE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-09-06 06:00:02.335845 :C9A458EF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-09-06 06:00:02.336784 :C9A458FB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.336870 :C9A45902:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.336968 :C9A4590F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.338012 :C9A45930:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.339815 :C9A45940:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.340136 :C9A45948:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:02.405689*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-09-06 06:00:02.405689*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-09-06 06:00:02.405689*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-09-06 06:00:02.452534*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-09-06 06:00:02.452534*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-09-06 06:00:02.452534*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-09-06 06:00:02.452534*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-09-06 06:00:02.507713 :C9A45963:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:04.427625 :C9A45A1F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:04.427635 :C9A45A20:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x000a.009.0017b778 2025-09-06 06:00:07.118919 :C9A45BDF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:07.120285 :C9A45BE7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:07.130905 :C9A45BEF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-06 06:00:07.160225 :C9A45BF7:db_trace:ksl2.c@14083:ksl_update_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: 4160, J003)