Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250727140655\orcl_j000_19040_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:35998M/63366M, Ph+PgF:41778M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 19040, image: ORACLE.EXE (J000) *** 2025-07-27 14:06:55.843 *** SESSION ID:(201.23513) 2025-07-27 14:06:55.843 *** 2025-07-27 14:06:55.843 Process diagnostic dump for ORACLE.EXE (J000), OS id=19040, pid: 25, proc_ser: 115, sid: 201, sess_ser: 23513 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 19040 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12825, hash value=2751001106 Current Wait Stack: Not in wait; last wait ended 2.222772 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.222797 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000174 sec, exc=0.000174 sec, total=0.000174 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.054778 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000009 sec, exc=0.000009 sec, total=0.000009 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.044098 sec of elapsed time 2: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0x3, filetype=0x2 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.000173 sec, exc=0.000173 sec, total=0.000173 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.714709 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=37 seq_num=38 snap_id=1 wait times: snap=0.000005 sec, exc=0.000005 sec, total=0.000005 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.024979 sec of elapsed time 4: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.012656 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.000121 sec, exc=0.000121 sec, total=0.000121 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049866 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.009683 sec, exc=0.009683 sec, total=0.009683 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007866 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.021137 sec, exc=0.021137 sec, total=0.021137 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.262170 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.003241 sec, exc=0.003241 sec, total=0.003241 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000178 sec of elapsed time 9: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=31 seq_num=32 snap_id=1 wait times: snap=0.000108 sec, exc=0.000108 sec, total=0.000108 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007835 sec of elapsed time Sampled Session History of session 201 serial 23513 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [4 samples, 14:06:52 - 14:06:55] not in wait at each sample [1 sample, 14:06:51] idle wait at each sample [session created at: 14:06:51] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-27 14:06:55.843 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 19040, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-27 14:04:37.612206 :B7AF2BCE: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-07-27 14:04:37.613168 :B7AF2BD3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:04:38.830409 :B7AF2C4B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:04:38.815 2025-07-27 14:04:38.830412 :B7AF2C4C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17572 pso_num=25 pso_serial#=102 2025-07-27 14:04:38.830569 :B7AF2C4D:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=17572 (legacy spawn) 2025-07-27 14:04:38.837571 :B7AF2C4E: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-07-27 14:04:38.837748 :B7AF2C54: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-07-27 14:04:38.838660 :B7AF2C58:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:04:38.848002 :B7AF2C5B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:04:38.847 2025-07-27 14:04:38.848005 :B7AF2C5C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16332 pso_num=25 pso_serial#=103 2025-07-27 14:04:38.848143 :B7AF2C5D:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=16332 (legacy spawn) 2025-07-27 14:04:38.855040 :B7AF2C5E: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-07-27 14:04:38.855219 :B7AF2C67: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-07-27 14:04:38.856165 :B7AF2C68:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:04:58.212445 :B7AF326C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:04:58.206 2025-07-27 14:04:58.212447 :B7AF326D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8552 pso_num=25 pso_serial#=104 2025-07-27 14:04:58.212587 :B7AF326E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8552 osp_idx=23 osp_ver=217986 osp_pg=0 (spawn #428057) 2025-07-27 14:04:58.212588 :B7AF326F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 14:04:58.212589 :B7AF3270:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=141 time=2305874111 2025-07-27 14:04:58.212589 :B7AF3271:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 14:04:58.212590 :B7AF3272:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 14:04:58.212590 :B7AF3273:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 14:04:58.212590 :B7AF3274:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 14:04:58.212590 :B7AF3275:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 14:04:58.213094 :B7AF3276: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-07-27 14:04:58.213757 :B7AF328B: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-07-27 14:04:58.224775 :B7AF32A8:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-07-27 14:04:58.225248 :B7AF32A9:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-07-27 14:04:58.227525 :B7AF32AA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-27 14:04:58.227869 :B7AF32AB: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-07-27 14:04:58.227904 :B7AF32AE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-27 14:04:58.228874 :B7AF32B4: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-07-27 14:04:58.229013 :B7AF32BD: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-07-27 14:05:28.288129 :B7AF3F46:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:05:37.657919 :B7AF471B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:05:37.644 2025-07-27 14:05:37.657921 :B7AF471C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10604 pso_num=25 pso_serial#=105 2025-07-27 14:05:37.658105 :B7AF471D:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10604 (legacy spawn) 2025-07-27 14:05:37.664583 :B7AF471E: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-07-27 14:05:37.664755 :B7AF4723: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-07-27 14:05:37.665569 :B7AF4728:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:05:39.794967 :B7AF47FB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:05:39.786 2025-07-27 14:05:39.794969 :B7AF47FC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14012 pso_num=25 pso_serial#=106 2025-07-27 14:05:39.795107 :B7AF47FD:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=14012 (legacy spawn) 2025-07-27 14:05:39.801680 :B7AF47FE: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-07-27 14:05:39.801844 :B7AF4803: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-07-27 14:05:39.802686 :B7AF4808:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:05:48.111526 :B7AF4A6C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:05:48.108 2025-07-27 14:05:48.111528 :B7AF4A6D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15304 pso_num=25 pso_serial#=107 2025-07-27 14:05:48.111674 :B7AF4A6E:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15304 (legacy spawn) 2025-07-27 14:05:48.118153 :B7AF4A6F: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-07-27 14:05:48.118324 :B7AF4A76: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-07-27 14:05:48.119126 :B7AF4A79:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:05:48.127774 :B7AF4A7C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:05:48.124 2025-07-27 14:05:48.127776 :B7AF4A7D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17272 pso_num=25 pso_serial#=108 2025-07-27 14:05:48.127911 :B7AF4A7E:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=17272 (legacy spawn) 2025-07-27 14:05:48.134431 :B7AF4A7F: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-07-27 14:05:48.134600 :B7AF4A88: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-07-27 14:05:48.135397 :B7AF4A89:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:05:51.295314 :B7AF4B7A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:05:51.282 2025-07-27 14:05:51.295317 :B7AF4B7B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16452 pso_num=25 pso_serial#=109 2025-07-27 14:05:51.295460 :B7AF4B7C:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=16452 (legacy spawn) 2025-07-27 14:05:51.301998 :B7AF4B7D: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-07-27 14:05:51.302170 :B7AF4B83: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-07-27 14:05:51.302993 :B7AF4B87:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:05:51.311666 :B7AF4B8A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:05:51.298 2025-07-27 14:05:51.311668 :B7AF4B8B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=1876 pso_num=25 pso_serial#=110 2025-07-27 14:05:51.311802 :B7AF4B8C:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=1876 (legacy spawn) 2025-07-27 14:05:51.331582 :B7AF4BB5: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-07-27 14:05:51.331753 :B7AF4BBE: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-07-27 14:05:51.332560 :B7AF4BBF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:05:58.261830 :B7AF4DF7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:05:58.255 2025-07-27 14:05:58.261832 :B7AF4DF8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17404 pso_num=25 pso_serial#=111 2025-07-27 14:05:58.261966 :B7AF4DF9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17404 osp_idx=23 osp_ver=217993 osp_pg=0 (spawn #428059) 2025-07-27 14:05:58.261966 :B7AF4DFA:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 14:05:58.261967 :B7AF4DFB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=142 time=2305934158 2025-07-27 14:05:58.261967 :B7AF4DFC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 14:05:58.261968 :B7AF4DFD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 14:05:58.261968 :B7AF4DFE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 14:05:58.261968 :B7AF4DFF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 14:05:58.261969 :B7AF4E00:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 14:05:58.262465 :B7AF4E01: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-07-27 14:05:58.263098 :B7AF4E16: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-07-27 14:05:58.270641 :B7AF4E32:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-27 14:05:58.271046 :B7AF4E33: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-07-27 14:05:58.271080 :B7AF4E36:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-27 14:05:58.272027 :B7AF4E3C: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-07-27 14:05:58.272155 :B7AF4E45: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-07-27 14:06:28.377197 :B7AF58F6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:06:42.212200 :B7AF5D2A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:06:42.203 2025-07-27 14:06:42.212202 :B7AF5D2B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=316 pso_num=25 pso_serial#=112 2025-07-27 14:06:42.212345 :B7AF5D2C:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=316 (legacy spawn) 2025-07-27 14:06:42.219221 :B7AF5D2D: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-07-27 14:06:42.219415 :B7AF5D32: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-07-27 14:06:42.220322 :B7AF5D37:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:06:45.738289 :B7AF5E82:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:06:45.730 2025-07-27 14:06:45.738291 :B7AF5E83:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19080 pso_num=25 pso_serial#=113 2025-07-27 14:06:45.738463 :B7AF5E84:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=19080 (legacy spawn) 2025-07-27 14:06:45.744967 :B7AF5E85: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-07-27 14:06:45.745142 :B7AF5E8A: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-07-27 14:06:45.745953 :B7AF5E8F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:06:51.722362 :B7AF6075:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:06:51.717 2025-07-27 14:06:51.722364 :B7AF6076:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15280 pso_num=25 pso_serial#=114 2025-07-27 14:06:51.722508 :B7AF6077:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15280 osp_idx=23 osp_ver=217996 osp_pg=0 (spawn #428061) 2025-07-27 14:06:51.722509 :B7AF6078:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 14:06:51.722509 :B7AF6079:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=143 time=2305987611 2025-07-27 14:06:51.722509 :B7AF607A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 14:06:51.722510 :B7AF607B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 14:06:51.722510 :B7AF607C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 14:06:51.722511 :B7AF607D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 14:06:51.722511 :B7AF607E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 14:06:51.723014 :B7AF607F: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-07-27 14:06:51.723061 :B7AF6085: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-07-27 14:06:51.727199 :B7AF6097:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-07-27 14:06:51.727253 :B7AF6098:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-07-27 14:06:51.727508 :B7AF6099:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-07-27 14:06:51.727524 :B7AF609A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-07-27 14:06:51.727738 :B7AF609B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-07-27 14:06:51.727752 :B7AF609C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-07-27 14:06:51.727959 :B7AF609D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-07-27 14:06:51.727972 :B7AF609E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-07-27 14:06:51.728175 :B7AF609F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-07-27 14:06:51.728188 :B7AF60A0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-07-27 14:06:51.728389 :B7AF60A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:kelt.c:517 2025-07-27 14:06:51.728403 :B7AF60A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:kelt.c:517 2025-07-27 14:06:51.730953 :B7AF60D0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-27 14:06:51.818861 :B7AF61B2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-27 14:06:51.810 2025-07-27 14:06:51.818863 :B7AF61B3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19040 pso_num=25 pso_serial#=115 2025-07-27 14:06:51.819405 :B7AF61B4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19040 osp_idx=23 osp_ver=217997 osp_pg=0 (spawn #428063) 2025-07-27 14:06:51.819407 :B7AF61B5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-27 14:06:51.819407 :B7AF61B6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=144 time=2305987704 2025-07-27 14:06:51.819407 :B7AF61B7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-27 14:06:51.819408 :B7AF61B8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-27 14:06:51.819409 :B7AF61B9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-27 14:06:51.819409 :B7AF61BA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-27 14:06:51.819410 :B7AF61BB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-27 14:06:51.820254 :B7AF61BC: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-07-27 14:06:51.825325 :B7AF61DB: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-07-27 14:06:51.825366 :B7AF61DE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-27 14:06:51.842449 :B7AF61F4: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-07-27 14:06:51.842717 :B7AF61FC: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-07-27 14:06:51.842887 :B7AF6204: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-07-27 14:06:51.843214 :B7AF620C: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-07-27 14:06:51.843477 :B7AF6214: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-07-27 14:06:51.843763 :B7AF621C: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-07-27 14:06:51.843925 :B7AF6224: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-07-27 14:06:51.844073 :B7AF622C: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-07-27 14:06:51.844225 :B7AF6234: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-07-27 14:06:51.863153 :B7AF623C: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-07-27 14:06:52.998267*:B7AF62C1:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000028C43AD0 estart=1753596411 eid=20819051 ctx=0x0000000777968158 cwh=0x00000000299A0068 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-07-27 14:06:52.998267*:B7AF62C2:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000028C43AD0 curCtx=0x0000000029A619A8 pubTabIdxCnt=0 2025-07-27 14:06:52.998267*:B7AF62C3:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000028C43AD0 2025-07-27 14:06:52.998267*:B7AF62C4:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000028C43AD0 2025-07-27 14:06:52.998267*:B7AF62C5:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000028CBB820 estart=1753596411 eid=16777483 ctx=0x000000077B54EAC8 cwh=0x0000000026B90608 cpu=937500 buffg=52356 interb=196608 r=24 rb=196608 w=0 wb=0 2025-07-27 14:06:52.998267*:B7AF62C6:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000028CBB820 curCtx=0x0000000029A69FF0 pubTabIdxCnt=0 2025-07-27 14:06:52.998267*:B7AF62C7:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000028CBB820 2025-07-27 14:06:52.998267*:B7AF62C8:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000028CBB820 2025-07-27 14:06:52.998267*:B7AF62C9:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000028C43AD0 curCtx=0x0000000029A619A8 xsc->flg4=65792 flags=1 2025-07-27 14:06:52.998267*:B7AF62CA:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000028C43AD0 2025-07-27 14:06:53.545397*:B7AF63CD:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000028CBB820 curCtx=0x0000000029A69FF0 xsc->flg4=65792 flags=2 2025-07-27 14:06:53.545397*:B7AF63CE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000028CBB820 2025-07-27 14:06:53.551062 :B7AF63CF: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-07-27 14:06:53.573717 :B7AF641A: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-07-27 14:06:53.575931 :B7AF6422:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-07-27 14:06:53.576152 :B7AF6423:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-07-27 14:06:53.577146 :B7AF6424: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-07-27 14:06:53.577252 :B7AF6427: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-07-27 14:06:53.578293 :B7AF6439: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-07-27 14:06:53.579984 :B7AF6441: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-07-27 14:06:53.580292 :B7AF6449: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-07-27 14:06:53.623518*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-07-27 14:06:53.623518*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-07-27 14:06:53.623518*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-07-27 14:06:53.639143*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-07-27 14:06:53.639143*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-07-27 14:06:53.639143*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-07-27 14:06:53.639143*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-07-27 14:06:53.711291 :B7AF645D: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-07-27 14:06:55.591166 :B7AF64ED: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-07-27 14:06:55.591182 :B7AF64EE:db_trace:ktur.c@3079:ktuabt(): [10444:25:201] ABORT TRANSACTION - xid: 0x0008.019.0000d00c ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 19040, J000)