Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250816180818\orcl_j000_18656_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:35423M/63366M, Ph+PgF:40727M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 18656, image: ORACLE.EXE (J000) *** 2025-08-16 18:08:18.421 *** SESSION ID:(177.60193) 2025-08-16 18:08:18.421 *** 2025-08-16 18:08:18.421 Process diagnostic dump for ORACLE.EXE (J000), OS id=18656, pid: 22, proc_ser: 64, sid: 177, sess_ser: 60193 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 18656 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12927, hash value=2462714187 Current Wait Stack: Not in wait; last wait ended 1.181332 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 1.181357 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=177 seq_num=178 snap_id=1 wait times: snap=0.000215 sec, exc=0.000215 sec, total=0.000215 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#=0x29ce, block#=0x0, blocks=0x0 wait_id=176 seq_num=177 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.016779 sec of elapsed time 2: waited for 'log file sequential read' log#=0x29ce, block#=0x0, blocks=0x0 wait_id=175 seq_num=176 snap_id=1 wait times: snap=0.000017 sec, exc=0.000017 sec, total=0.000017 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.188203 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x12000, blocks=0x800 wait_id=174 seq_num=175 snap_id=1 wait times: snap=0.000287 sec, exc=0.000287 sec, total=0.000287 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0x11800, blocks=0x800 wait_id=173 seq_num=174 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.000004 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0x11000, blocks=0x800 wait_id=172 seq_num=173 snap_id=1 wait times: snap=0.000335 sec, exc=0.000335 sec, total=0.000335 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000008 sec of elapsed time 6: waited for 'log file sequential read' log#=0x0, block#=0x10800, blocks=0x800 wait_id=171 seq_num=172 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.000039 sec of elapsed time 7: waited for 'log file sequential read' log#=0x0, block#=0x10000, blocks=0x800 wait_id=170 seq_num=171 snap_id=1 wait times: snap=0.000332 sec, exc=0.000332 sec, total=0.000332 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.429323 sec of elapsed time 8: waited for 'log file sequential read' log#=0x29ce, block#=0x800, blocks=0x800 wait_id=169 seq_num=170 snap_id=1 wait times: snap=0.000208 sec, exc=0.000208 sec, total=0.000208 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002717 sec of elapsed time 9: waited for 'log file sequential read' log#=0x29ce, block#=0x0, blocks=0x0 wait_id=168 seq_num=169 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.000139 sec of elapsed time Sampled Session History of session 177 serial 60193 --------------------------------------------------- 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 --------------------------------------------------- [2 samples, 18:08:16 - 18:08:17] not in wait at each sample [1 sample, 18:08:15] waited for 'log buffer space', seq_num: 74 p1: ''=0x0 p2: ''=0x0 p3: ''=0x0 time_waited: 0.999201 sec (sample interval: 0 sec) [5 samples, 18:08:10 - 18:08:14] not in wait at each sample [16 samples, 18:07:54 - 18:08:09] idle wait at each sample [session created at: 18:07:54] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'log buffer space' [1 sample, 18:08:15 ] time_waited: 0.999201 sec (sample interval: 0 sec) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-16 18:08:18.421 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 18656, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-16 18:05:40.760768 :C0980E12:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:05:40.760942 :C0980E1B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:05:40.761791 :C0980E1C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:05:53.877250 :C09817D5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:05:53.871 2025-08-16 18:05:53.877252 :C09817D6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18016 pso_num=22 pso_serial#=51 2025-08-16 18:05:53.877391 :C09817D7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18016 osp_idx=0 osp_ver=522108 osp_pg=0 (spawn #495274) 2025-08-16 18:05:53.877391 :C09817D8:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:05:53.877392 :C09817D9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=239 time=4048223189 2025-08-16 18:05:53.877392 :C09817DA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:05:53.877393 :C09817DB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:05:53.877393 :C09817DC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:05:53.877394 :C09817DD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:05:53.877394 :C09817DE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:05:53.877875 :C09817DF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:05:53.878518 :C09817F4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:05:53.886095 :C0981810:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-16 18:05:53.886464 :C0981811:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:05:53.886504 :C0981814:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-16 18:05:53.887363 :C098181A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:05:53.887474 :C0981823:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:06:23.986522 :C098239B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:06:42.971731 :C0982934:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:06:42.963 2025-08-16 18:06:42.971734 :C0982935:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20260 pso_num=22 pso_serial#=52 2025-08-16 18:06:42.971878 :C0982936:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20260 (legacy spawn) 2025-08-16 18:06:42.978451 :C0982937:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:42.978611 :C098293C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:06:42.979418 :C0982940:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:06:46.427781 :C0982A6A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:06:46.416 2025-08-16 18:06:46.427783 :C0982A6B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21176 pso_num=22 pso_serial#=53 2025-08-16 18:06:46.427914 :C0982A6C:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21176 (legacy spawn) 2025-08-16 18:06:46.434373 :C0982A6D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:46.434546 :C0982A72:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:06:46.435403 :C0982A77:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:06:49.271930 :C0982B66:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:06:49.258 2025-08-16 18:06:49.271932 :C0982B67:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19396 pso_num=22 pso_serial#=54 2025-08-16 18:06:49.272066 :C0982B68:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19396 (legacy spawn) 2025-08-16 18:06:49.278491 :C0982B69:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:49.278666 :C0982B6E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:06:49.279450 :C0982B73:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:06:49.297426 :C0982B76:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:06:49.289 2025-08-16 18:06:49.297429 :C0982B77:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19388 pso_num=22 pso_serial#=55 2025-08-16 18:06:49.297563 :C0982B78:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=19388 (legacy spawn) 2025-08-16 18:06:49.303990 :C0982B79:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:49.304184 :C0982B82:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:06:49.305033 :C0982B83:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:06:52.475506 :C0982C60:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:06:52.461 2025-08-16 18:06:52.475508 :C0982C61:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21948 pso_num=22 pso_serial#=56 2025-08-16 18:06:52.475662 :C0982C62:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21948 (legacy spawn) 2025-08-16 18:06:52.482669 :C0982C63:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:52.482857 :C0982C68:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:06:52.483786 :C0982C6D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:06:52.493164 :C0982C70:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:06:52.492 2025-08-16 18:06:52.493166 :C0982C71:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20944 pso_num=22 pso_serial#=57 2025-08-16 18:06:52.493311 :C0982C72:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20944 (legacy spawn) 2025-08-16 18:06:52.500208 :C0982C73:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:52.500424 :C0982C7B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:06:52.501379 :C0982C7C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:06:53.967433 :C0982D2E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:06:53.961 2025-08-16 18:06:53.967435 :C0982D2F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22224 pso_num=22 pso_serial#=58 2025-08-16 18:06:53.967577 :C0982D30:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22224 osp_idx=0 osp_ver=522115 osp_pg=0 (spawn #495276) 2025-08-16 18:06:53.967578 :C0982D31:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:06:53.967578 :C0982D32:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=240 time=4048283267 2025-08-16 18:06:53.967578 :C0982D33:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:06:53.967579 :C0982D34:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:06:53.967579 :C0982D35:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:06:53.967579 :C0982D36:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:06:53.967580 :C0982D37:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:06:53.968075 :C0982D38:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:06:53.968728 :C0982D4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:53.979775 :C0982D69:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-08-16 18:06:53.980243 :C0982D6A:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-08-16 18:06:53.982559 :C0982D6B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-16 18:06:53.982905 :C0982D6C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:53.982940 :C0982D6F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-16 18:06:53.983881 :C0982D75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:06:53.984004 :C0982D7E:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:07:24.086305 :C09836CC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:07:25.944890 :C0983734:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:07:25.931 2025-08-16 18:07:25.944892 :C0983735:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22216 pso_num=22 pso_serial#=59 2025-08-16 18:07:25.945032 :C0983736:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22216 (legacy spawn) 2025-08-16 18:07:25.951732 :C0983737:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:07:25.951939 :C098373C:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:07:25.952805 :C0983741:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:07:25.962031 :C0983744:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:07:25.947 2025-08-16 18:07:25.962033 :C0983745:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21428 pso_num=22 pso_serial#=60 2025-08-16 18:07:25.962200 :C0983746:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21428 (legacy spawn) 2025-08-16 18:07:25.968822 :C0983747:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:07:25.968996 :C0983750:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:07:25.969819 :C0983751:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:07:29.133898 :C0983864:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:07:29.121 2025-08-16 18:07:29.133900 :C0983865:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20888 pso_num=22 pso_serial#=61 2025-08-16 18:07:29.134035 :C0983866:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20888 (legacy spawn) 2025-08-16 18:07:29.140627 :C098387A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:07:29.140791 :C0983883:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:07:29.141575 :C0983884:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:07:29.150256 :C0983887:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:07:29.136 2025-08-16 18:07:29.150258 :C0983888:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22476 pso_num=22 pso_serial#=62 2025-08-16 18:07:29.150393 :C0983889:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22476 (legacy spawn) 2025-08-16 18:07:29.156913 :C098388A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:07:29.157083 :C0983893:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:07:29.157907 :C0983894:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:07:45.168637 :C0983DB0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:07:45.160 2025-08-16 18:07:45.168639 :C0983DB1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22408 pso_num=22 pso_serial#=63 2025-08-16 18:07:45.168774 :C0983DB2:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22408 (legacy spawn) 2025-08-16 18:07:45.175294 :C0983DB3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:07:45.175495 :C0983DB8:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:07:45.176304 :C0983DBD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-16 18:07:54.055956 :C098409D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-16 18:07:54.050 2025-08-16 18:07:54.055958 :C098409E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=18656 pso_num=22 pso_serial#=64 2025-08-16 18:07:54.056103 :C098409F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=18656 osp_idx=0 osp_ver=522121 osp_pg=0 (spawn #495278) 2025-08-16 18:07:54.056104 :C09840A0:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-16 18:07:54.056104 :C09840A1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=241 time=4048343361 2025-08-16 18:07:54.056105 :C09840A2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-16 18:07:54.056105 :C09840A3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-16 18:07:54.056105 :C09840A4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-16 18:07:54.056106 :C09840A5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-16 18:07:54.056106 :C09840A6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-16 18:07:54.056603 :C09840A7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-16 18:07:54.057253 :C09840BC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:07:54.064827 :C09840D8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-16 18:07:54.065211 :C09840D9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:07:54.065247 :C09840DC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-16 18:07:54.066106 :C09840E2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:07:54.066232 :C09840EB:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-08-16 18:08:10.389430 :C098473D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-16 18:08:10.389430*:C098476F:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1755338890 eid=16786204 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-08-16 18:08:10.389430*:C0984770:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-08-16 18:08:10.389430*:C0984771:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-08-16 18:08:10.389430*:C0984772:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-08-16 18:08:10.389430*:C0984773:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-08-16 18:08:10.389430*:C0984774:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-08-16 18:08:10.395708 :C0984775:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.395749 :C0984778:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-08-16 18:08:10.412493 :C098477E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.412688 :C0984786:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.412847 :C098478E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.413068 :C0984796:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.413227 :C098479E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.413555 :C09847A6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.413801 :C09847AE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.413964 :C09847B6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.414112 :C09847BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.414356 :C09847C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.414630 :C09847CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.414794 :C09847D6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.415172 :C09847DE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.415342 :C09847E6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.415499 :C09847EE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.415660 :C09847F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.415799 :C09847FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.415940 :C0984806:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.416085 :C098480E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:10.434597 :C0984816:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.085136 :C0984997:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.105356 :C09849B9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.107273 :C09849C1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-16 18:08:12.107455 :C09849C2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-16 18:08:12.108341 :C09849C3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.108432 :C09849C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.109377 :C09849D8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.110855 :C09849E0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.111138 :C09849E8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:12.156429*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-08-16 18:08:12.156429*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-08-16 18:08:12.156429*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-08-16 18:08:12.203294*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-08-16 18:08:12.203294*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-08-16 18:08:12.203294*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-08-16 18:08:12.203294*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-08-16 18:08:12.257746 :C0984A67:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:14.158360 :C0984AD5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:14.158371 :C0984AD6:db_trace:ktur.c@3079:ktuabt(): [10444:22:177] ABORT TRANSACTION - xid: 0x000a.01a.00178295 2025-08-16 18:08:17.703221*:C0984CB9:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BDB6F0 estart=1755338897 eid=16777832 ctx=0x000000077F58CBF8 cwh=0x000000000FD00248 cpu=0 buffg=3 interb=0 r=0 rb=0 w=0 wb=0 2025-08-16 18:08:17.703221*:C0984CBA:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BDB6F0 curCtx=0x00000000299FAEA0 pubTabIdxCnt=0 2025-08-16 18:08:17.703221*:C0984CBB:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BDB6F0 2025-08-16 18:08:17.703221*:C0984CBC:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BDB6F0 2025-08-16 18:08:17.703221*:C0984CBD:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BDB6F0 curCtx=0x00000000299FAEA0 xsc->flg4=65792 flags=1 2025-08-16 18:08:17.703221*:C0984CBE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BDB6F0 2025-08-16 18:08:17.708819 :C0984CDE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:17.710474 :C0984CE6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:17.721939 :C0984CEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-16 18:08:17.750732 :C0984CF6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] 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 22 (osid: 18656, J000)