Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250825220009\orcl_j000_22312_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:35212M/63366M, Ph+PgF:40315M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 22312, image: ORACLE.EXE (J000) *** 2025-08-25 22:00:09.460 *** SESSION ID:(177.59915) 2025-08-25 22:00:09.460 *** 2025-08-25 22:00:09.460 Process diagnostic dump for ORACLE.EXE (J000), OS id=22312, pid: 22, proc_ser: 244, sid: 177, sess_ser: 59915 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 22312 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.413681 sec, exc=0.413681 sec, total=0.413681 sec wait times: max=0.500000 sec, heur=5.440347 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000008 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.515489 sec, exc=0.515489 sec, total=0.515489 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.510090 sec, exc=0.510090 sec, total=0.510090 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.500020 sec, exc=0.500020 sec, total=0.500020 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499982 sec, exc=0.499982 sec, total=0.499982 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500024 sec, exc=0.500024 sec, total=0.500024 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.510096 sec, exc=0.510096 sec, total=0.510096 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.499965 sec, exc=0.499965 sec, total=0.499965 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000022 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.490911 sec, exc=0.490911 sec, total=0.490911 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000000 sec of elapsed time Sampled Session History of session 177 serial 59915 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [6 samples, 22:00:04 - 22:00:09] idle wait at each sample [session created at: 22:00:04] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-25 22:00:09.460 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 22312, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-25 21:57:18.675243 :C49F6AD3: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-25 21:57:18.675422 :C49F6ADC: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-25 21:57:18.676226 :C49F6ADD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:57:18.685001 :C49F6AE0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:57:18.671 2025-08-25 21:57:18.685002 :C49F6AE1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8552 pso_num=22 pso_serial#=229 2025-08-25 21:57:18.685134 :C49F6AE2:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8552 (legacy spawn) 2025-08-25 21:57:18.691677 :C49F6AE3: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-25 21:57:18.691848 :C49F6AEC: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-25 21:57:18.692691 :C49F6AED:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:57:19.916280 :C49F6B49:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:57:19.905 2025-08-25 21:57:19.916282 :C49F6B4A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21932 pso_num=22 pso_serial#=230 2025-08-25 21:57:19.916414 :C49F6B4B:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21932 (legacy spawn) 2025-08-25 21:57:19.922970 :C49F6B4C: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-25 21:57:19.923141 :C49F6B51: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-25 21:57:19.923932 :C49F6B56:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:57:22.447579 :C49F6C1B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:57:22.434 2025-08-25 21:57:22.447581 :C49F6C1C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14008 pso_num=22 pso_serial#=231 2025-08-25 21:57:22.447711 :C49F6C1D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14008 (legacy spawn) 2025-08-25 21:57:22.454211 :C49F6C1E: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-25 21:57:22.454394 :C49F6C23: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-25 21:57:22.455254 :C49F6C28:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:57:41.237921 :C49F71E9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:57:41.232 2025-08-25 21:57:41.237923 :C49F71EA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22276 pso_num=22 pso_serial#=232 2025-08-25 21:57:41.238066 :C49F71EB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22276 osp_idx=0 osp_ver=549829 osp_pg=0 (spawn #525813) 2025-08-25 21:57:41.238067 :C49F71EC: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-25 21:57:41.238067 :C49F71ED:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=213 time=544715971 2025-08-25 21:57:41.238068 :C49F71EE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-25 21:57:41.238068 :C49F71EF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-25 21:57:41.238069 :C49F71F0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-25 21:57:41.238069 :C49F71F1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-25 21:57:41.238070 :C49F71F2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-25 21:57:41.238575 :C49F71F3: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-25 21:57:41.239284 :C49F7208: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-25 21:57:41.247005 :C49F7224:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-25 21:57:41.247422 :C49F7225: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-25 21:57:41.247471 :C49F7226:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-25 21:57:41.248446 :C49F722E: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-25 21:57:41.248581 :C49F7237: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-25 21:58:11.381595 :C49F7BF7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:58:24.679204 :C49F7FF9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:58:24.666 2025-08-25 21:58:24.679206 :C49F7FFA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21376 pso_num=22 pso_serial#=233 2025-08-25 21:58:24.679346 :C49F7FFB:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21376 (legacy spawn) 2025-08-25 21:58:24.685929 :C49F7FFC: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-25 21:58:24.686102 :C49F8001: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-25 21:58:24.686900 :C49F8006:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:58:28.100102 :C49F80F1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:58:28.091 2025-08-25 21:58:28.100105 :C49F80F2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22140 pso_num=22 pso_serial#=234 2025-08-25 21:58:28.100253 :C49F80F3:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22140 (legacy spawn) 2025-08-25 21:58:28.106920 :C49F80F4: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-25 21:58:28.107109 :C49F80F9: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-25 21:58:28.107924 :C49F80FE:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:58:28.167910 :C49F8101:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:58:28.153 2025-08-25 21:58:28.167912 :C49F8102:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=16248 pso_num=22 pso_serial#=235 2025-08-25 21:58:28.168057 :C49F8103:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=16248 (legacy spawn) 2025-08-25 21:58:28.174942 :C49F8127: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-25 21:58:28.175111 :C49F8130: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-25 21:58:28.175946 :C49F8131:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:58:28.184705 :C49F8134:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:58:28.184 2025-08-25 21:58:28.184707 :C49F8135:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11176 pso_num=22 pso_serial#=236 2025-08-25 21:58:28.184838 :C49F8136:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11176 (legacy spawn) 2025-08-25 21:58:28.191425 :C49F8137: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-25 21:58:28.191593 :C49F8140: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-25 21:58:28.192349 :C49F8141:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:58:31.352362 :C49F823E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:58:31.338 2025-08-25 21:58:31.352364 :C49F823F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21828 pso_num=22 pso_serial#=237 2025-08-25 21:58:31.352499 :C49F8240:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21828 (legacy spawn) 2025-08-25 21:58:31.359312 :C49F8241: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-25 21:58:31.359503 :C49F824A: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-25 21:58:31.360346 :C49F824B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:58:31.369776 :C49F824E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:58:31.370 2025-08-25 21:58:31.369778 :C49F824F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23456 pso_num=22 pso_serial#=238 2025-08-25 21:58:31.369927 :C49F8250:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23456 (legacy spawn) 2025-08-25 21:58:31.376817 :C49F8251: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-25 21:58:31.376987 :C49F825A: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-25 21:58:31.377893 :C49F825B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:58:41.346273 :C49F8555:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:58:41.340 2025-08-25 21:58:41.346274 :C49F8556:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23064 pso_num=22 pso_serial#=239 2025-08-25 21:58:41.346420 :C49F8557:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23064 osp_idx=0 osp_ver=549836 osp_pg=0 (spawn #525815) 2025-08-25 21:58:41.346421 :C49F8558: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-25 21:58:41.346421 :C49F8559:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=214 time=544776080 2025-08-25 21:58:41.346422 :C49F855A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-25 21:58:41.346422 :C49F855B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-25 21:58:41.346422 :C49F855C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-25 21:58:41.346423 :C49F855D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-25 21:58:41.346423 :C49F855E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-25 21:58:41.346937 :C49F855F: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-25 21:58:41.347597 :C49F8574: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-25 21:58:41.358652 :C49F8591:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-08-25 21:58:41.359126 :C49F8592:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-08-25 21:58:41.361439 :C49F8593:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-25 21:58:41.361834 :C49F8594: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-25 21:58:41.361871 :C49F8597:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-25 21:58:41.362783 :C49F859D: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-25 21:58:41.362918 :C49F85A6: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-25 21:59:11.453693 :C49F8F67:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:59:26.868112 :C49F9413:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:59:26.855 2025-08-25 21:59:26.868114 :C49F9414:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22636 pso_num=22 pso_serial#=240 2025-08-25 21:59:26.868247 :C49F9415:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22636 (legacy spawn) 2025-08-25 21:59:26.874723 :C49F9416: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-25 21:59:26.874900 :C49F941B: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-25 21:59:26.875701 :C49F9420:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:59:36.635286 :C49F9735:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:59:36.635 2025-08-25 21:59:36.635289 :C49F9736:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20204 pso_num=22 pso_serial#=241 2025-08-25 21:59:36.635437 :C49F9737:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20204 (legacy spawn) 2025-08-25 21:59:36.642425 :C49F9738: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-25 21:59:36.642613 :C49F9741: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-25 21:59:36.643519 :C49F9742:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:59:40.869163 :C49F9877:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:59:40.855 2025-08-25 21:59:40.869165 :C49F9878:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20684 pso_num=22 pso_serial#=242 2025-08-25 21:59:40.869300 :C49F9879:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20684 (legacy spawn) 2025-08-25 21:59:40.875855 :C49F987A: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-25 21:59:40.876044 :C49F987F: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-25 21:59:40.876829 :C49F9884:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:59:40.885747 :C49F9887:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:59:40.886 2025-08-25 21:59:40.885749 :C49F9888:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=21984 pso_num=22 pso_serial#=243 2025-08-25 21:59:40.885885 :C49F9889:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=21984 (legacy spawn) 2025-08-25 21:59:40.892416 :C49F988A: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-25 21:59:40.892577 :C49F9893: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-25 21:59:40.893386 :C49F9894:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-08-25 21:59:41.438618 :C49F98D4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 08-25 21:59:41.433 2025-08-25 21:59:41.438620 :C49F98D5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22312 pso_num=22 pso_serial#=244 2025-08-25 21:59:41.438779 :C49F98D6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=22312 osp_idx=0 osp_ver=549841 osp_pg=0 (spawn #525819) 2025-08-25 21:59:41.438780 :C49F98D7: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-25 21:59:41.438781 :C49F98D8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=215 time=544836174 2025-08-25 21:59:41.438781 :C49F98D9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-08-25 21:59:41.438782 :C49F98DA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-08-25 21:59:41.438782 :C49F98DB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-08-25 21:59:41.438783 :C49F98DC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-25 21:59:41.438784 :C49F98DD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-25 21:59:41.439289 :C49F98DE: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-25 21:59:41.440031 :C49F98F3: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-25 21:59:41.447871 :C49F990F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-08-25 21:59:41.448320 :C49F9910: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-25 21:59:41.448365 :C49F9913:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-08-25 21:59:41.449223 :C49F9919: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-25 21:59:41.449358 :C49F9922: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-25 22:00:01.461300 :C49FA13B: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-25 22:00:01.461300*:C49FA14B:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1756130400 eid=16786767 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-08-25 22:00:01.461300*:C49FA14C:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-08-25 22:00:01.461300*:C49FA14D:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-08-25 22:00:01.461300*:C49FA14E:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-08-25 22:00:01.461300*:C49FA14F:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-08-25 22:00:01.461300*:C49FA150:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-08-25 22:00:01.466896 :C49FA15B: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-25 22:00:01.466941 :C49FA162:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-08-25 22:00:01.478144 :C49FA1CD: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-25 22:00:01.482881 :C49FA1EA: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-25 22:00:01.483639 :C49FA1FF: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-25 22:00:01.489474 :C49FA221:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-08-25 22:00:01.489635 :C49FA230:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-08-25 22:00:01.490479 :C49FA238: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-25 22:00:01.490715 :C49FA240:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-08-25 22:00:01.492439 :C49FA243: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-25 22:00:01.492482 :C49FA246:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-08-25 22:00:01.492548 :C49FA253: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-25 22:00:01.586082 :C49FA48D: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-25 22:00:01.588229 :C49FA492: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-25 22:00:01.588269 :C49FA495:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-08-25 22:00:01.590763 :C49FA49B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-08-25 22:00:01.594071 :C49FA49C: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-25 22:00:01.594167 :C49FA49F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-08-25 22:00:01.594247 :C49FA4AC: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-25 22:00:04.011957 :C49FA8F6: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-25 22:00:04.011957*:C49FA8FC:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1756130403 eid=16786773 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-08-25 22:00:04.011957*:C49FA8FD:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-08-25 22:00:04.011957*:C49FA8FE:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-08-25 22:00:04.011957*:C49FA8FF:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-08-25 22:00:04.011957*:C49FA900:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-08-25 22:00:04.011957*:C49FA901:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-08-25 22:00:04.014896 :C49FA902: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-25 22:00:04.014941 :C49FA905:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-08-25 22:00:04.022612 :C49FA90B: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-25 22:00:04.023297 :C49FA913: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-25 22:00:04.023977 :C49FA91B: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-25 22:00:04.024169 :C49FA923:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-08-25 22:00:04.025547 :C49FA924: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-25 22:00:04.025584 :C49FA927:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-08-25 22:00:04.025683 :C49FA934: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 22312, J000)