Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250526081257\orcl_j000_8392_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:37294M/63366M, Ph+PgF:44298M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 8392, image: ORACLE.EXE (J000) *** 2025-05-26 08:12:57.447 *** SESSION ID:(177.22907) 2025-05-26 08:12:57.447 *** 2025-05-26 08:12:57.447 Process diagnostic dump for ORACLE.EXE (J000), OS id=8392, pid: 22, proc_ser: 205, sid: 177, sess_ser: 22907 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 8392 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=0.351196 sec, exc=0.351196 sec, total=0.351196 sec wait times: max=0.500000 sec, heur=14.884045 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.000023 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=0.500171 sec, exc=0.500171 sec, total=0.500171 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=27 seq_num=28 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.000013 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=0.499957 sec, exc=0.499957 sec, total=0.499957 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=0.500025 sec, exc=0.500025 sec, total=0.500025 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=0.500115 sec, exc=0.500115 sec, total=0.500115 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=0.499957 sec, exc=0.499957 sec, total=0.499957 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=0.500029 sec, exc=0.500029 sec, total=0.500029 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=19 seq_num=20 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.000014 sec of elapsed time Sampled Session History of session 177 serial 22907 --------------------------------------------------- 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 --------------------------------------------------- [15 samples, 08:12:42 - 08:12:57] idle wait at each sample [session created at: 08:12:42] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-26 08:12:57.447 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 8392, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-26 08:09:22.248145 :9C28FEEA: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-05-26 08:09:22.248321 :9C28FEF1: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-05-26 08:09:22.249124 :9C28FEF4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:09:22.257795 :9C28FEF7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:09:22.243 2025-05-26 08:09:22.257797 :9C28FEF8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15072 pso_num=22 pso_serial#=185 2025-05-26 08:09:22.257937 :9C28FEF9:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15072 (legacy spawn) 2025-05-26 08:09:22.264375 :9C28FEFA: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-05-26 08:09:22.264539 :9C28FF02: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-05-26 08:09:22.265337 :9C28FF04:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:09:24.496716 :9C28FFC0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:09:24.488 2025-05-26 08:09:24.496718 :9C28FFC1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=3020 pso_num=22 pso_serial#=186 2025-05-26 08:09:24.496853 :9C28FFC2:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=3020 (legacy spawn) 2025-05-26 08:09:24.503201 :9C28FFC3: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-05-26 08:09:24.503388 :9C28FFC8: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-05-26 08:09:24.504185 :9C28FFCD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:09:42.316331 :9C29053C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:09:42.310 2025-05-26 08:09:42.316333 :9C29053D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12372 pso_num=22 pso_serial#=187 2025-05-26 08:09:42.316472 :9C29053E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12372 osp_idx=0 osp_ver=234787 osp_pg=0 (spawn #220568) 2025-05-26 08:09:42.316473 :9C29053F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 08:09:42.316473 :9C290540:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=221 time=1222754563 2025-05-26 08:09:42.316473 :9C290541:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 08:09:42.316474 :9C290542:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 08:09:42.316474 :9C290543:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 08:09:42.316474 :9C290544:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 08:09:42.316475 :9C290545:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 08:09:42.316975 :9C290546: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-05-26 08:09:42.317611 :9C29055B: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-05-26 08:09:42.325121 :9C290577:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-26 08:09:42.325476 :9C290578: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-05-26 08:09:42.325514 :9C29057B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-26 08:09:42.326347 :9C290581: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-05-26 08:09:42.326460 :9C29058A: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-05-26 08:10:12.435341 :9C290F1A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:10:31.743891 :9C29150F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:10:31.729 2025-05-26 08:10:31.743895 :9C291510:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12656 pso_num=22 pso_serial#=188 2025-05-26 08:10:31.744035 :9C291511:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12656 (legacy spawn) 2025-05-26 08:10:31.750503 :9C291512: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-05-26 08:10:31.750679 :9C291517: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-05-26 08:10:31.751472 :9C29151C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:10:31.760033 :9C29151F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:10:31.745 2025-05-26 08:10:31.760035 :9C291520:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12104 pso_num=22 pso_serial#=189 2025-05-26 08:10:31.760170 :9C291521:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=12104 (legacy spawn) 2025-05-26 08:10:31.766636 :9C291522: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-05-26 08:10:31.766804 :9C29152B: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-05-26 08:10:31.767647 :9C29152C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:10:32.675909 :9C291594:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:10:32.661 2025-05-26 08:10:32.675911 :9C291595:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13528 pso_num=22 pso_serial#=190 2025-05-26 08:10:32.676049 :9C291596:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13528 (legacy spawn) 2025-05-26 08:10:32.682538 :9C291597: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-05-26 08:10:32.682702 :9C29159C: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-05-26 08:10:32.683470 :9C2915A1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:10:34.832986 :9C291631:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:10:34.819 2025-05-26 08:10:34.832988 :9C291632:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14492 pso_num=22 pso_serial#=191 2025-05-26 08:10:34.833121 :9C291633:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14492 (legacy spawn) 2025-05-26 08:10:34.839576 :9C29165C: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-05-26 08:10:34.839742 :9C291661: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-05-26 08:10:34.840525 :9C291666:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:10:34.849182 :9C291669:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:10:34.835 2025-05-26 08:10:34.849184 :9C29166A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15108 pso_num=22 pso_serial#=192 2025-05-26 08:10:34.849324 :9C29166B:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15108 (legacy spawn) 2025-05-26 08:10:34.855755 :9C29166C: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-05-26 08:10:34.855923 :9C291675: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-05-26 08:10:34.856717 :9C291676:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:10:42.402498 :9C2918B9:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:10:42.396 2025-05-26 08:10:42.402501 :9C2918BA:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14440 pso_num=22 pso_serial#=193 2025-05-26 08:10:42.402656 :9C2918BB:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14440 osp_idx=0 osp_ver=234793 osp_pg=0 (spawn #220570) 2025-05-26 08:10:42.402657 :9C2918BC:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 08:10:42.402657 :9C2918BD:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=222 time=1222814657 2025-05-26 08:10:42.402657 :9C2918BE:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 08:10:42.402658 :9C2918BF:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 08:10:42.402658 :9C2918C0:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 08:10:42.402658 :9C2918C1:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 08:10:42.402659 :9C2918C2:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 08:10:42.403153 :9C2918C3: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-05-26 08:10:42.403811 :9C2918D8: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-05-26 08:10:42.414787 :9C2918F4:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-26 08:10:42.415269 :9C2918F5:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-26 08:10:42.417550 :9C2918F6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-26 08:10:42.417885 :9C2918F7: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-05-26 08:10:42.417920 :9C2918FA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-26 08:10:42.418863 :9C291900: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-05-26 08:10:42.418995 :9C291909: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-05-26 08:11:12.507229 :9C2922B7:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:11:14.108906 :9C292344:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:11:14.101 2025-05-26 08:11:14.108909 :9C292345:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13268 pso_num=22 pso_serial#=194 2025-05-26 08:11:14.109074 :9C292346:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13268 (legacy spawn) 2025-05-26 08:11:14.115472 :9C292347: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-05-26 08:11:14.115651 :9C29234E: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-05-26 08:11:14.116479 :9C292350:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:11:40.908953 :9C292B64:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:11:40.900 2025-05-26 08:11:40.908954 :9C292B65:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13040 pso_num=22 pso_serial#=195 2025-05-26 08:11:40.909091 :9C292B66:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13040 (legacy spawn) 2025-05-26 08:11:40.915504 :9C292B67: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-05-26 08:11:40.915705 :9C292B6C: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-05-26 08:11:40.916715 :9C292B71:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:11:42.468404 :9C292C12:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:11:42.462 2025-05-26 08:11:42.468406 :9C292C13:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2404 pso_num=22 pso_serial#=196 2025-05-26 08:11:42.468542 :9C292C14:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2404 osp_idx=0 osp_ver=234796 osp_pg=0 (spawn #220572) 2025-05-26 08:11:42.468543 :9C292C15:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 08:11:42.468544 :9C292C16:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=223 time=1222874719 2025-05-26 08:11:42.468544 :9C292C17:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 08:11:42.468544 :9C292C18:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 08:11:42.468545 :9C292C19:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 08:11:42.468545 :9C292C1A:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 08:11:42.468545 :9C292C1B:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 08:11:42.469031 :9C292C1C: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-05-26 08:11:42.469725 :9C292C31: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-05-26 08:11:42.477180 :9C292C4E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-26 08:11:42.477537 :9C292C4F: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-05-26 08:11:42.477576 :9C292C52:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-26 08:11:42.478494 :9C292C58: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-05-26 08:11:42.478637 :9C292C61: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-05-26 08:12:12.578059 :9C293671:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:14.982670 :9C29372C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:14.969 2025-05-26 08:12:14.982672 :9C29372D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13360 pso_num=22 pso_serial#=197 2025-05-26 08:12:14.982808 :9C29372E:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13360 (legacy spawn) 2025-05-26 08:12:14.989254 :9C29372F: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-05-26 08:12:14.989423 :9C293734: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-05-26 08:12:14.990255 :9C293739:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:16.368256 :9C2937A1:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:16.360 2025-05-26 08:12:16.368258 :9C2937A2:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13792 pso_num=22 pso_serial#=198 2025-05-26 08:12:16.368396 :9C2937A3:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13792 (legacy spawn) 2025-05-26 08:12:16.374911 :9C2937A4: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-05-26 08:12:16.375077 :9C2937AA: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-05-26 08:12:16.375917 :9C2937AD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:20.546135 :9C29390F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:20.532 2025-05-26 08:12:20.546137 :9C293910:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14724 pso_num=22 pso_serial#=199 2025-05-26 08:12:20.546282 :9C293911:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14724 (legacy spawn) 2025-05-26 08:12:20.552684 :9C293912: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-05-26 08:12:20.552861 :9C293917: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-05-26 08:12:20.553652 :9C29391C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:20.571723 :9C29391F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:20.563 2025-05-26 08:12:20.571725 :9C293920:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14616 pso_num=22 pso_serial#=200 2025-05-26 08:12:20.571864 :9C293921:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14616 (legacy spawn) 2025-05-26 08:12:20.578324 :9C293922: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-05-26 08:12:20.578516 :9C29392B: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-05-26 08:12:20.579306 :9C29392C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:23.953713 :9C293A1D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:23.940 2025-05-26 08:12:23.953715 :9C293A1E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14968 pso_num=22 pso_serial#=201 2025-05-26 08:12:23.953860 :9C293A1F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14968 (legacy spawn) 2025-05-26 08:12:23.960354 :9C293A20: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-05-26 08:12:23.960529 :9C293A25: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-05-26 08:12:23.961315 :9C293A2A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:23.969967 :9C293A2D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:23.956 2025-05-26 08:12:23.969969 :9C293A2E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11860 pso_num=22 pso_serial#=202 2025-05-26 08:12:23.970099 :9C293A2F:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11860 (legacy spawn) 2025-05-26 08:12:23.976703 :9C293A30: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-05-26 08:12:23.976886 :9C293A39: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-05-26 08:12:23.977685 :9C293A3A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:33.551277 :9C293D31:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:33.543 2025-05-26 08:12:33.551280 :9C293D32:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10376 pso_num=22 pso_serial#=203 2025-05-26 08:12:33.551464 :9C293D33:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10376 (legacy spawn) 2025-05-26 08:12:33.557852 :9C293D34: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-05-26 08:12:33.558051 :9C293D3D: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-05-26 08:12:33.558854 :9C293D3E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:33.567447 :9C293D41:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:33.559 2025-05-26 08:12:33.567449 :9C293D42:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13256 pso_num=22 pso_serial#=204 2025-05-26 08:12:33.567587 :9C293D43:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=13256 (legacy spawn) 2025-05-26 08:12:33.574056 :9C293D44: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-05-26 08:12:33.574210 :9C293D4D: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-05-26 08:12:33.574979 :9C293D4E:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-26 08:12:42.552283 :9C294015:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-26 08:12:42.547 2025-05-26 08:12:42.552286 :9C294016:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8392 pso_num=22 pso_serial#=205 2025-05-26 08:12:42.552424 :9C294017:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8392 osp_idx=0 osp_ver=234805 osp_pg=0 (spawn #220574) 2025-05-26 08:12:42.552427 :9C294018:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-26 08:12:42.552427 :9C294019:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=224 time=1222934813 2025-05-26 08:12:42.552428 :9C29401A:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-26 08:12:42.552428 :9C29401B:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-26 08:12:42.552428 :9C29401C:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-26 08:12:42.552429 :9C29401D:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-26 08:12:42.552429 :9C29401E:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-26 08:12:42.552925 :9C29401F: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-05-26 08:12:42.553600 :9C294034: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-05-26 08:12:42.564906 :9C294050:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-26 08:12:42.565373 :9C294051:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-26 08:12:42.567779 :9C294052:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-26 08:12:42.568124 :9C294053: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-05-26 08:12:42.568159 :9C294056:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-26 08:12:42.569039 :9C29405C: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-05-26 08:12:42.569168 :9C294065: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: 8392, J000)