Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250429221649\orcl_j000_11236_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:37668M/63366M, Ph+PgF:45276M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 11236, image: ORACLE.EXE (J000) *** 2025-04-29 22:16:49.911 *** SESSION ID:(201.21997) 2025-04-29 22:16:49.911 *** 2025-04-29 22:16:49.911 Process diagnostic dump for ORACLE.EXE (J000), OS id=11236, pid: 25, proc_ser: 150, sid: 201, sess_ser: 21997 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 11236 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=46 seq_num=47 snap_id=1 wait times: snap=0.378766 sec, exc=0.378766 sec, total=0.378766 sec wait times: max=0.500000 sec, heur=23.396306 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.000013 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=45 seq_num=46 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.000011 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=44 seq_num=45 snap_id=1 wait times: snap=0.501638 sec, exc=0.501638 sec, total=0.501638 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=43 seq_num=44 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.000011 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=42 seq_num=43 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=41 seq_num=42 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.000008 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.499990 sec, exc=0.499990 sec, total=0.499990 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000015 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.499995 sec, exc=0.499995 sec, total=0.499995 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.505112 sec, exc=0.505112 sec, total=0.505112 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=37 seq_num=38 snap_id=1 wait times: snap=0.499990 sec, exc=0.499990 sec, total=0.499990 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=36 seq_num=37 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.000013 sec of elapsed time Sampled Session History of session 201 serial 21997 --------------------------------------------------- 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 --------------------------------------------------- [24 samples, 22:16:26 - 22:16:49] idle wait at each sample [session created at: 22:16:26] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-04-29 22:16:49.911 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 11236, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-04-29 22:13:26.177755 :90886D08: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-04-29 22:13:26.177872 :90886D11: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-04-29 22:13:56.263936 :9088773B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:14:07.687963 :90887A8E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:14:07.674 2025-04-29 22:14:07.687965 :90887A8F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11492 pso_num=25 pso_serial#=132 2025-04-29 22:14:07.688101 :90887A90:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=11492 (legacy spawn) 2025-04-29 22:14:07.694586 :90887A91: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-04-29 22:14:07.694764 :90887A96: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-04-29 22:14:07.695534 :90887A9B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:14:07.704095 :90887A9E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:14:07.690 2025-04-29 22:14:07.704097 :90887A9F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7380 pso_num=25 pso_serial#=133 2025-04-29 22:14:07.704238 :90887AA0:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=7380 (legacy spawn) 2025-04-29 22:14:07.710668 :90887AA1: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-04-29 22:14:07.710825 :90887AAA: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-04-29 22:14:07.711627 :90887AAB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:14:09.437356 :90887B62:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:14:09.428 2025-04-29 22:14:09.437359 :90887B63:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10824 pso_num=25 pso_serial#=134 2025-04-29 22:14:09.437541 :90887B64:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10824 (legacy spawn) 2025-04-29 22:14:09.443905 :90887B65: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-04-29 22:14:09.444078 :90887B6E: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-04-29 22:14:09.444896 :90887B6F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:14:10.817992 :90887BCF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:14:10.804 2025-04-29 22:14:10.817994 :90887BD0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9648 pso_num=25 pso_serial#=135 2025-04-29 22:14:10.818143 :90887BD1:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=9648 (legacy spawn) 2025-04-29 22:14:10.825128 :90887BD2: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-04-29 22:14:10.825322 :90887BD7: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-04-29 22:14:10.826303 :90887BDC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:14:10.835124 :90887BDF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:14:10.819 2025-04-29 22:14:10.835126 :90887BE0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10396 pso_num=25 pso_serial#=136 2025-04-29 22:14:10.835280 :90887BE1:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10396 (legacy spawn) 2025-04-29 22:14:10.841981 :90887BF2: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-04-29 22:14:10.842157 :90887BFB: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-04-29 22:14:10.843046 :90887BFC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:14:18.061282 :90887E54:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:14:18.053 2025-04-29 22:14:18.061284 :90887E55:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10244 pso_num=25 pso_serial#=137 2025-04-29 22:14:18.061427 :90887E56:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10244 (legacy spawn) 2025-04-29 22:14:18.067885 :90887E57: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-04-29 22:14:18.068056 :90887E60: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-04-29 22:14:18.068935 :90887E61:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:14:26.275981 :908880E1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:14:26.270 2025-04-29 22:14:26.275982 :908880E2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8936 pso_num=25 pso_serial#=138 2025-04-29 22:14:26.276120 :908880E3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8936 osp_idx=23 osp_ver=68477 osp_pg=0 (spawn #131813) 2025-04-29 22:14:26.276121 :908880E4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:14:26.276121 :908880E5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=80 time=3235655750 2025-04-29 22:14:26.276122 :908880E6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:14:26.276122 :908880E7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:14:26.276122 :908880E8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:14:26.276123 :908880E9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:14:26.276123 :908880EA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:14:26.276641 :908880EB: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-04-29 22:14:26.277310 :90888100: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-04-29 22:14:26.288604 :9088811C:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-29 22:14:26.289095 :9088811D:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-29 22:14:26.291522 :9088811E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-04-29 22:14:26.291865 :9088811F: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-04-29 22:14:26.291901 :90888122:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-04-29 22:14:26.292768 :90888128: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-04-29 22:14:26.292890 :90888131: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-04-29 22:14:56.405509 :90888B0A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:17.343265 :90889165:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:17.334 2025-04-29 22:15:17.343267 :90889166:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8696 pso_num=25 pso_serial#=139 2025-04-29 22:15:17.343401 :90889167:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=8696 (legacy spawn) 2025-04-29 22:15:17.349882 :90889168: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-04-29 22:15:17.350071 :9088916D: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-04-29 22:15:17.350911 :90889172:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:20.283974 :90889259:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:20.270 2025-04-29 22:15:20.283977 :9088925A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11988 pso_num=25 pso_serial#=140 2025-04-29 22:15:20.284121 :9088925B:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=11988 (legacy spawn) 2025-04-29 22:15:20.290561 :9088925C: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-04-29 22:15:20.290737 :90889261: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-04-29 22:15:20.291549 :90889266:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:20.309589 :90889269:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:20.301 2025-04-29 22:15:20.309592 :9088926A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8892 pso_num=25 pso_serial#=141 2025-04-29 22:15:20.309732 :9088926B:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=8892 (legacy spawn) 2025-04-29 22:15:20.316126 :9088926C: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-04-29 22:15:20.316320 :90889274: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-04-29 22:15:20.317119 :90889276:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:20.324533 :90889279:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:20.317 2025-04-29 22:15:20.324536 :9088927A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10512 pso_num=25 pso_serial#=142 2025-04-29 22:15:20.324665 :9088927B:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10512 (legacy spawn) 2025-04-29 22:15:20.331046 :9088927C: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-04-29 22:15:20.331207 :90889285: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-04-29 22:15:20.332012 :90889286:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:23.415308 :9088939F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:23.402 2025-04-29 22:15:23.415310 :908893A0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11996 pso_num=25 pso_serial#=143 2025-04-29 22:15:23.415450 :908893A1:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=11996 (legacy spawn) 2025-04-29 22:15:23.421836 :908893A2: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-04-29 22:15:23.422009 :908893A7: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-04-29 22:15:23.422821 :908893AC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:23.442143 :908893AF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:23.433 2025-04-29 22:15:23.442145 :908893B0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8848 pso_num=25 pso_serial#=144 2025-04-29 22:15:23.442285 :908893B1:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=8848 (legacy spawn) 2025-04-29 22:15:23.448848 :908893B2: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-04-29 22:15:23.449007 :908893BB: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-04-29 22:15:23.449824 :908893BC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:26.392499 :908894A0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:26.387 2025-04-29 22:15:26.392501 :908894A1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8548 pso_num=25 pso_serial#=145 2025-04-29 22:15:26.392636 :908894A2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8548 osp_idx=23 osp_ver=68484 osp_pg=0 (spawn #131815) 2025-04-29 22:15:26.392637 :908894A3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:15:26.392637 :908894A4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=81 time=3235715875 2025-04-29 22:15:26.392638 :908894A5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:15:26.392638 :908894A6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:15:26.392638 :908894A7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:15:26.392639 :908894A8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:15:26.392639 :908894A9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:15:26.393121 :908894AA: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-04-29 22:15:26.393768 :908894BF: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-04-29 22:15:26.401320 :908894DB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-04-29 22:15:26.401669 :908894DC: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-04-29 22:15:26.401702 :908894DF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-04-29 22:15:26.402477 :90889508: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-04-29 22:15:26.402604 :90889511: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-04-29 22:15:56.500095 :90889E96:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:56.895966 :90889EA4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:56.890 2025-04-29 22:15:56.895968 :90889EA5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10716 pso_num=25 pso_serial#=146 2025-04-29 22:15:56.896107 :90889EA6:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10716 (legacy spawn) 2025-04-29 22:15:56.902724 :90889EA7: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-04-29 22:15:56.902899 :90889EAC: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-04-29 22:15:56.903754 :90889EB1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:15:56.912917 :90889EB4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:15:56.905 2025-04-29 22:15:56.912919 :90889EB5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9492 pso_num=25 pso_serial#=147 2025-04-29 22:15:56.913053 :90889EB6:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=9492 (legacy spawn) 2025-04-29 22:15:56.919555 :90889EB7: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-04-29 22:15:56.919734 :90889EC0: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-04-29 22:15:56.920570 :90889EC1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:16:00.091074 :90889FE5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:16:00.078 2025-04-29 22:16:00.091077 :90889FE6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10268 pso_num=25 pso_serial#=148 2025-04-29 22:16:00.091250 :90889FE7:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=10268 (legacy spawn) 2025-04-29 22:16:00.113592 :90889FF4: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-04-29 22:16:00.113752 :90889FFD: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-04-29 22:16:00.114527 :90889FFE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:16:00.123181 :9088A001:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:16:00.109 2025-04-29 22:16:00.123183 :9088A002:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=580 pso_num=25 pso_serial#=149 2025-04-29 22:16:00.123357 :9088A003:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=580 (legacy spawn) 2025-04-29 22:16:00.129866 :9088A004: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-04-29 22:16:00.130040 :9088A00D: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-04-29 22:16:00.130850 :9088A00E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-04-29 22:16:21.478081 :9088A6A5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 04-29 22:16:21.472 2025-04-29 22:16:21.478082 :9088A6A6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11236 pso_num=25 pso_serial#=150 2025-04-29 22:16:21.478217 :9088A6A7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11236 osp_idx=23 osp_ver=68489 osp_pg=0 (spawn #131817) 2025-04-29 22:16:21.478218 :9088A6A8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-04-29 22:16:21.478218 :9088A6A9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=82 time=3235770953 2025-04-29 22:16:21.478218 :9088A6AA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-04-29 22:16:21.478219 :9088A6AB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-04-29 22:16:21.478219 :9088A6AC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-04-29 22:16:21.478219 :9088A6AD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-04-29 22:16:21.478220 :9088A6AE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-04-29 22:16:21.478694 :9088A6AF: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-04-29 22:16:21.479309 :9088A6C4: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-04-29 22:16:21.484786 :9088A6E0: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-04-29 22:16:21.485762 :9088A6E8: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-04-29 22:16:21.485891 :9088A6F1: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-04-29 22:16:26.488608 :9088A873:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-04-29 22:16:26.488628*:9088A875:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DCBB58 estart=1745936185 eid=16836639 ctx=0x000000077BD98A08 cwh=0x0000000024D802A0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-04-29 22:16:26.488628*:9088A876:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DCBB58 curCtx=0x0000000024D8F300 pubTabIdxCnt=0 2025-04-29 22:16:26.488628*:9088A877:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DCBB58 2025-04-29 22:16:26.488628*:9088A878:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DCBB58 2025-04-29 22:16:26.488628*:9088A879:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DCBB58 curCtx=0x0000000024D8F300 xsc->flg4=65792 flags=2 2025-04-29 22:16:26.488628*:9088A87A:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DCBB58 2025-04-29 22:16:26.489124 :9088A87B: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-04-29 22:16:26.503188 :9088A883:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-04-29 22:16:26.503273 :9088A884:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-04-29 22:16:26.504060 :9088A885:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-04-29 22:16:26.504411 :9088A886: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-04-29 22:16:26.504451 :9088A889:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-04-29 22:16:26.512422 :9088A88F: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-04-29 22:16:26.512485 :9088A892:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:ktcc.c:879 2025-04-29 22:16:26.512519 :9088A893:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:ktcc.c:879 2025-04-29 22:16:26.512887 :9088A899:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-29 22:16:26.513236 :9088A89A:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-04-29 22:16:26.513419 :9088A89B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-04-29 22:16:26.513652 :9088A89C: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-04-29 22:16:26.513678 :9088A89F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-04-29 22:16:26.515327 :9088A8A5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-04-29 22:16:26.515570 :9088A8A6: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-04-29 22:16:26.515600 :9088A8A9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-04-29 22:16:26.516509 :9088A8AF: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-04-29 22:16:26.516616 :9088A8B8: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 11236, J000)