Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250823140104\orcl_j000_16340_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:35273M/63366M, Ph+PgF:40392M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 16340, image: ORACLE.EXE (J000) *** 2025-08-23 14:01:04.574 *** SESSION ID:(201.35985) 2025-08-23 14:01:04.574 *** 2025-08-23 14:01:04.574 Process diagnostic dump for ORACLE.EXE (J000), OS id=16340, pid: 25, proc_ser: 164, sid: 201, sess_ser: 35985 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 16340 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12962, hash value=1666484586 Current Wait Stack: Not in wait; last wait ended 1.168976 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 1.169003 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=146 seq_num=147 snap_id=1 wait times: snap=0.000323 sec, exc=0.000323 sec, total=0.000323 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#=0x29f8, block#=0x0, blocks=0x0 wait_id=145 seq_num=146 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.132357 sec of elapsed time 2: waited for 'log file sequential read' log#=0x29f8, block#=0x0, blocks=0x0 wait_id=144 seq_num=145 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.018540 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0xc000, blocks=0x800 wait_id=143 seq_num=144 snap_id=1 wait times: snap=0.000328 sec, exc=0.000328 sec, total=0.000328 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0xb800, blocks=0x800 wait_id=142 seq_num=143 snap_id=1 wait times: snap=0.000300 sec, exc=0.000300 sec, total=0.000300 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0xb000, blocks=0x800 wait_id=141 seq_num=142 snap_id=1 wait times: snap=0.000317 sec, exc=0.000317 sec, total=0.000317 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 6: waited for 'log file sequential read' log#=0x0, block#=0xa800, blocks=0x800 wait_id=140 seq_num=141 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.000112 sec of elapsed time 7: waited for 'log file sequential read' log#=0x0, block#=0xa000, blocks=0x800 wait_id=139 seq_num=140 snap_id=1 wait times: snap=0.000325 sec, exc=0.000325 sec, total=0.000325 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.448943 sec of elapsed time 8: waited for 'log file sequential read' log#=0x29f8, block#=0x0, blocks=0x0 wait_id=138 seq_num=139 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.000158 sec of elapsed time 9: waited for 'log file sequential read' log#=0x29f8, block#=0x2, blocks=0x7fe wait_id=137 seq_num=138 snap_id=1 wait times: snap=0.000203 sec, exc=0.000203 sec, total=0.000203 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000161 sec of elapsed time Sampled Session History of session 201 serial 35985 --------------------------------------------------- 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 --------------------------------------------------- [7 samples, 14:00:57 - 14:01:03] not in wait at each sample [1 sample, 14:00:56] idle wait at each sample [session created at: 14:00:57] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-23 14:01:04.574 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 16340, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-23 13:59:52.682741 :C398A51B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 13:59:52.692175 :C398A51E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 13:59:52.692 2025-08-23 13:59:52.692177 :C398A51F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20848 pso_num=25 pso_serial#=156 2025-08-23 13:59:52.692325 :C398A520:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=20848 (legacy spawn) 2025-08-23 13:59:52.699453 :C398A521:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 13:59:52.699633 :C398A529:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-23 13:59:52.700567 :C398A52A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 13:59:56.908155 :C398A63C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 13:59:56.899 2025-08-23 13:59:56.908158 :C398A63D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21952 pso_num=25 pso_serial#=157 2025-08-23 13:59:56.908292 :C398A63E:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=21952 (legacy spawn) 2025-08-23 13:59:56.914778 :C398A63F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 13:59:56.914944 :C398A648:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-23 13:59:56.915812 :C398A649:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 13:59:58.623835 :C398A743:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 13:59:58.618 2025-08-23 13:59:58.623837 :C398A744:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21756 pso_num=25 pso_serial#=158 2025-08-23 13:59:58.623979 :C398A745:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21756 osp_idx=23 osp_ver=254250 osp_pg=0 (spawn #518040) 2025-08-23 13:59:58.623980 :C398A746:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-23 13:59:58.623980 :C398A747:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=72 time=343300627 2025-08-23 13:59:58.623981 :C398A748:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-23 13:59:58.623981 :C398A749:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-23 13:59:58.623982 :C398A74A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-23 13:59:58.623982 :C398A74B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-23 13:59:58.623982 :C398A74C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-23 13:59:58.624471 :C398A74D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-23 13:59:58.625104 :C398A762:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 13:59:58.632726 :C398A77E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-08-23 13:59:58.633087 :C398A77F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 13:59:58.633121 :C398A782:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-08-23 13:59:58.633960 :C398A788:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 13:59:58.634075 :C398A791:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-23 14:00:28.711183 :C398B0F8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 14:00:29.021047 :C398B0FC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 14:00:29.008 2025-08-23 14:00:29.021049 :C398B0FD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19516 pso_num=25 pso_serial#=159 2025-08-23 14:00:29.021189 :C398B0FE:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=19516 (legacy spawn) 2025-08-23 14:00:29.027741 :C398B0FF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:29.027922 :C398B108:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-23 14:00:29.028758 :C398B109:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 14:00:29.037472 :C398B10C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 14:00:29.024 2025-08-23 14:00:29.037474 :C398B10D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17460 pso_num=25 pso_serial#=160 2025-08-23 14:00:29.037610 :C398B10E:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=17460 (legacy spawn) 2025-08-23 14:00:29.044032 :C398B10F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:29.044198 :C398B118:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-23 14:00:29.045009 :C398B119:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 14:00:30.908634 :C398B1B6:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 14:00:30.899 2025-08-23 14:00:30.908636 :C398B1B7:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15732 pso_num=25 pso_serial#=161 2025-08-23 14:00:30.908780 :C398B1B8:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15732 (legacy spawn) 2025-08-23 14:00:30.915793 :C398B1B9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:30.915982 :C398B1BE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-23 14:00:30.916914 :C398B1C3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 14:00:57.335722 :C398B9AB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 14:00:57.330 2025-08-23 14:00:57.335724 :C398B9AC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21280 pso_num=25 pso_serial#=162 2025-08-23 14:00:57.335863 :C398B9AD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21280 osp_idx=23 osp_ver=254254 osp_pg=0 (spawn #518042) 2025-08-23 14:00:57.335863 :C398B9AE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-23 14:00:57.335864 :C398B9AF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=73 time=343359346 2025-08-23 14:00:57.335865 :C398B9B0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-23 14:00:57.335865 :C398B9B1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-23 14:00:57.335865 :C398B9B2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-23 14:00:57.335866 :C398B9B3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-23 14:00:57.335866 :C398B9B4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-23 14:00:57.336375 :C398B9B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.336421 :C398B9BB:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-08-23 14:00:57.340611 :C398B9CE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-08-23 14:00:57.340657 :C398B9CF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-08-23 14:00:57.341004 :C398B9D0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-08-23 14:00:57.341022 :C398B9D1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-08-23 14:00:57.341242 :C398B9D2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-08-23 14:00:57.341256 :C398B9D4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-08-23 14:00:57.341474 :C398B9DE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-08-23 14:00:57.341487 :C398B9DF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-08-23 14:00:57.341702 :C398B9E0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-08-23 14:00:57.341715 :C398B9E1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-08-23 14:00:57.341997 :C398B9ED:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=18 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-08-23 14:00:57.342008 :C398B9EE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-08-23 14:00:57.342023 :C398B9F0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-08-23 14:00:57.344541 :C398BA01:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 14:00:57.354277 :C398BA37:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 14:00:57.346 2025-08-23 14:00:57.354278 :C398BA38:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21652 pso_num=25 pso_serial#=163 2025-08-23 14:00:57.354437 :C398BA39:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21652 osp_idx=23 osp_ver=254255 osp_pg=0 (spawn #518045) 2025-08-23 14:00:57.354438 :C398BA3A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-23 14:00:57.354438 :C398BA3B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=74 time=343359362 2025-08-23 14:00:57.354439 :C398BA3C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-23 14:00:57.354440 :C398BA3D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-23 14:00:57.354440 :C398BA3E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-23 14:00:57.354441 :C398BA3F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-23 14:00:57.354441 :C398BA40:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-23 14:00:57.355049 :C398BA41:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.355101 :C398BA47:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-08-23 14:00:57.363515 :C398BA59:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-23 14:00:57.444026 :C398BB70:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-23 14:00:57.439 2025-08-23 14:00:57.444028 :C398BB71:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16340 pso_num=25 pso_serial#=164 2025-08-23 14:00:57.444336 :C398BB72:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16340 osp_idx=23 osp_ver=254256 osp_pg=0 (spawn #518046) 2025-08-23 14:00:57.444338 :C398BB73:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-23 14:00:57.444339 :C398BB74:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=75 time=343359440 2025-08-23 14:00:57.444341 :C398BB75:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-23 14:00:57.444341 :C398BB76:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-23 14:00:57.444343 :C398BB77:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-23 14:00:57.444343 :C398BB78:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-23 14:00:57.444344 :C398BB79:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-23 14:00:57.445539 :C398BB7A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.451318 :C398BB99:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.451375 :C398BB9C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-08-23 14:00:57.468946 :C398BBB2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.469313 :C398BBBA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.469480 :C398BBC2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.469633 :C398BBCA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.469805 :C398BBD2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.469958 :C398BBDA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.470111 :C398BBE2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.470258 :C398BBEA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.470418 :C398BBF2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.470589 :C398BBFA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.470730 :C398BC02:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.470869 :C398BC0A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.471009 :C398BC12:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.471163 :C398BC1A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.471313 :C398BC22:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.471452 :C398BC2A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.471663 :C398BC32:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.471800 :C398BC3A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.472119 :C398BC42:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.472361 :C398BC4A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.472516 :C398BC52:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.472665 :C398BC5A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.472806 :C398BC62:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.472946 :C398BC6A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.473101 :C398BC72:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.473291 :C398BC7C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.473435 :C398BC84:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.473579 :C398BC8C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.473733 :C398BC94:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.473880 :C398BC9C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.474026 :C398BCA4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.474173 :C398BCAC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.474319 :C398BCB4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.474465 :C398BCBC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.474616 :C398BCC6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.474760 :C398BCCE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.474901 :C398BCD6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.475038 :C398BCDE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.475183 :C398BCE6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.475330 :C398BCEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.475474 :C398BCF6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.475617 :C398BCFE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.475765 :C398BD06:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.475903 :C398BD0E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.476046 :C398BD16:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:57.493563 :C398BD1E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:58.621295*:C398BE13:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000292C3AD0 estart=1755928858 eid=21650163 ctx=0x0000000777968158 cwh=0x000000002B480068 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-08-23 14:00:58.621295*:C398BE14:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000292C3AD0 curCtx=0x000000002B5419A8 pubTabIdxCnt=0 2025-08-23 14:00:58.621295*:C398BE15:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000292C3AD0 2025-08-23 14:00:58.621295*:C398BE16:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000292C3AD0 2025-08-23 14:00:58.621295*:C398BE17:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002934B820 estart=1755928857 eid=16777538 ctx=0x000000077B54EAC8 cwh=0x0000000024B00608 cpu=937500 buffg=52468 interb=196608 r=24 rb=196608 w=0 wb=0 2025-08-23 14:00:58.621295*:C398BE18:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002934B820 curCtx=0x000000002B549FF0 pubTabIdxCnt=0 2025-08-23 14:00:58.621295*:C398BE19:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002934B820 2025-08-23 14:00:58.621295*:C398BE1A:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002934B820 2025-08-23 14:00:58.621295*:C398BE1B:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000292C3AD0 curCtx=0x000000002B5419A8 xsc->flg4=65792 flags=1 2025-08-23 14:00:58.621295*:C398BE1C:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000292C3AD0 2025-08-23 14:00:59.176118 :C398C0D0:db_trace:ktu.c@4871:ktuaex1r(): [10442:25:201] Extension usn 8, ext 1, nex 2 2025-08-23 14:00:59.176127 :C398C0D1:db_trace:ktusm.c@2117:ktusmasp(): [10445:25:201] des1:tsn:1 rdba:0x008191c2 where: kdiwh22: kdifind 2025-08-23 14:00:59.176127*:C398C0D2:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002934B820 curCtx=0x000000002B549FF0 xsc->flg4=65792 flags=2 2025-08-23 14:00:59.176127*:C398C0D3:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002934B820 2025-08-23 14:00:59.179489 :C398C0D4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:59.201876 :C398C0F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:59.204013 :C398C0FE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-08-23 14:00:59.204254 :C398C0FF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-08-23 14:00:59.205276 :C398C100:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:59.205382 :C398C103:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:59.206317 :C398C115:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:59.207972 :C398C11D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:59.208344 :C398C125:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:00:59.261932*: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-23 14:00:59.261932*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-08-23 14:00:59.261932*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-08-23 14:00:59.261932*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-08-23 14:00:59.261932*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-08-23 14:00:59.261932*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-08-23 14:00:59.261932*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-08-23 14:00:59.347190 :C398C18A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:01:01.217879 :C398C235:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:01:01.217894 :C398C236:db_trace:ktur.c@3079:ktuabt(): [10444:25:201] ABORT TRANSACTION - xid: 0x000a.01f.00179441 2025-08-23 14:01:03.858731 :C398C3F2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:01:03.860172 :C398C3FA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:01:03.870931 :C398C402:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-23 14:01:03.899637 :C398C40A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] 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 25 (osid: 16340, J000)