Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250905220008\orcl_j000_16340_bucket.trc Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options Windows NT Version V6.2 CPU : 32 - type 8664, 16 Physical Cores Process Affinity : 0x0x0000000000000000 Memory (Avail/Total): Ph:35022M/63366M, Ph+PgF:39869M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 16340, image: ORACLE.EXE (J000) *** 2025-09-05 22:00:08.562 *** SESSION ID:(193.62431) 2025-09-05 22:00:08.562 *** 2025-09-05 22:00:08.562 Process diagnostic dump for ORACLE.EXE (J000), OS id=16340, pid: 24, proc_ser: 224, sid: 193, sess_ser: 62431 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 16340 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.052608 sec, exc=0.052608 sec, total=0.052608 sec wait times: max=0.500000 sec, heur=4.541220 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.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.500002 sec, exc=0.500002 sec, total=0.500002 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 3: 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.000008 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499992 sec, exc=0.499992 sec, total=0.499992 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.502086 sec, exc=0.502086 sec, total=0.502086 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.499975 sec, exc=0.499975 sec, total=0.499975 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 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.000011 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.486450 sec, exc=0.486450 sec, total=0.486450 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 193 serial 62431 --------------------------------------------------- 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 --------------------------------------------------- [5 samples, 22:00:04 - 22:00:08] 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-09-05 22:00:08.562 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 16340, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-05 21:57:30.089282 :C97DE042:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 21:57:30.089282 :C97DE043:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 21:57:30.089282 :C97DE044:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 21:57:30.089283 :C97DE045:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 21:57:30.089814 :C97DE046:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-05 21:57:30.090457 :C97DE05B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:57:30.098053 :C97DE077:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-09-05 21:57:30.098447 :C97DE078:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:57:30.098483 :C97DE07B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-09-05 21:57:30.099364 :C97DE081:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:57:30.099489 :C97DE08A:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:58:00.172642 :C97DEA43:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:58:01.904531 :C97DEAAF:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:58:01.892 2025-09-05 21:58:01.904533 :C97DEAB0:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=6376 pso_num=24 pso_serial#=211 2025-09-05 21:58:01.904671 :C97DEAB1:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=6376 (legacy spawn) 2025-09-05 21:58:01.911159 :C97DEAB2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:01.911333 :C97DEAB7:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:58:01.912128 :C97DEABC:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:58:06.435190 :C97DEC48:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:58:06.426 2025-09-05 21:58:06.435192 :C97DEC49:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22808 pso_num=24 pso_serial#=212 2025-09-05 21:58:06.435330 :C97DEC4A:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=22808 (legacy spawn) 2025-09-05 21:58:06.441721 :C97DEC4B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:06.441893 :C97DEC54:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:58:06.442722 :C97DEC55:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:58:10.498539 :C97DEDA4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:58:10.490 2025-09-05 21:58:10.498542 :C97DEDA5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=24192 pso_num=24 pso_serial#=213 2025-09-05 21:58:10.498679 :C97DEDA6:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=24192 (legacy spawn) 2025-09-05 21:58:10.505151 :C97DEDA7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:10.505328 :C97DEDAC:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:58:10.506198 :C97DEDB1:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:58:10.514862 :C97DEDB4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:58:10.505 2025-09-05 21:58:10.514864 :C97DEDB5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=23380 pso_num=24 pso_serial#=214 2025-09-05 21:58:10.515003 :C97DEDB6:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=23380 (legacy spawn) 2025-09-05 21:58:10.521446 :C97DEDB7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:10.521618 :C97DEDC0:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:58:10.522480 :C97DEDC1:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:58:13.783934 :C97DEEAD:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:58:13.771 2025-09-05 21:58:13.783936 :C97DEEAE:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=24400 pso_num=24 pso_serial#=215 2025-09-05 21:58:13.784132 :C97DEEAF:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=24400 (legacy spawn) 2025-09-05 21:58:13.790635 :C97DEEB0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:13.790815 :C97DEEB5:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:58:13.791593 :C97DEEBA:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:58:13.809462 :C97DEEBD:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:58:13.802 2025-09-05 21:58:13.809464 :C97DEEBE:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=23908 pso_num=24 pso_serial#=216 2025-09-05 21:58:13.809602 :C97DEEBF:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=23908 (legacy spawn) 2025-09-05 21:58:13.816118 :C97DEEC0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:13.816284 :C97DEEC9:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:58:13.817099 :C97DEECA:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:58:30.158748 :C97DF3FB:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:58:30.153 2025-09-05 21:58:30.158750 :C97DF3FC:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=23376 pso_num=24 pso_serial#=217 2025-09-05 21:58:30.158885 :C97DF3FD:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=23376 osp_idx=22 osp_ver=848191 osp_pg=0 (spawn #562476) 2025-09-05 21:58:30.158885 :C97DF3FE:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 21:58:30.158885 :C97DF3FF:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=210 time=1495161455 2025-09-05 21:58:30.158886 :C97DF400:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 21:58:30.158886 :C97DF401:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 21:58:30.158886 :C97DF402:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 21:58:30.158887 :C97DF403:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 21:58:30.158887 :C97DF404:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 21:58:30.159383 :C97DF405:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-05 21:58:30.160003 :C97DF41A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:30.174397 :C97DF436:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-09-05 21:58:30.174485 :C97DF437:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-09-05 21:58:30.175283 :C97DF438:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-09-05 21:58:30.175635 :C97DF439:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:30.175673 :C97DF43C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-09-05 21:58:30.183633 :C97DF442:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:30.183701 :C97DF445:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:ktcc.c:879 2025-09-05 21:58:30.183737 :C97DF446:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:ktcc.c:879 2025-09-05 21:58:30.184097 :C97DF44C:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-09-05 21:58:30.184437 :C97DF44D:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-09-05 21:58:30.184617 :C97DF44E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-09-05 21:58:30.184919 :C97DF44F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:30.184945 :C97DF452:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-09-05 21:58:30.186551 :C97DF458:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-09-05 21:58:30.186804 :C97DF459:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:30.186837 :C97DF45C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-09-05 21:58:30.187738 :C97DF462:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:58:30.187865 :C97DF46B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:59:00.241091 :C97DFE2D:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:59:04.075576 :C97DFF4D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:59:04.063 2025-09-05 21:59:04.075578 :C97DFF4E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22588 pso_num=24 pso_serial#=218 2025-09-05 21:59:04.075716 :C97DFF4F:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=22588 (legacy spawn) 2025-09-05 21:59:04.082216 :C97DFF50:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:04.082410 :C97DFF55:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:59:04.083233 :C97DFF5A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:59:14.427196 :C97E029A:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:59:14.418 2025-09-05 21:59:14.427198 :C97E029B:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=23364 pso_num=24 pso_serial#=219 2025-09-05 21:59:14.427335 :C97E029C:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=23364 (legacy spawn) 2025-09-05 21:59:14.433871 :C97E029D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:14.434043 :C97E02A2:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:59:14.434874 :C97E02A7:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:59:23.292907 :C97E0569:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:59:23.278 2025-09-05 21:59:23.292909 :C97E056A:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=18680 pso_num=24 pso_serial#=220 2025-09-05 21:59:23.293047 :C97E056B:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=18680 (legacy spawn) 2025-09-05 21:59:23.299525 :C97E056C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:23.299694 :C97E0571:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:59:23.300500 :C97E0576:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:59:23.309153 :C97E0579:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:59:23.294 2025-09-05 21:59:23.309155 :C97E057A:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=24360 pso_num=24 pso_serial#=221 2025-09-05 21:59:23.309322 :C97E057B:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=24360 (legacy spawn) 2025-09-05 21:59:23.315787 :C97E057C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:23.315954 :C97E0585:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:59:23.316770 :C97E0586:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:59:26.401519 :C97E0687:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:59:26.389 2025-09-05 21:59:26.401520 :C97E0688:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=22912 pso_num=24 pso_serial#=222 2025-09-05 21:59:26.401659 :C97E0689:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=22912 (legacy spawn) 2025-09-05 21:59:26.408201 :C97E068A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:26.408370 :C97E068F:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:59:26.409190 :C97E0694:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:59:26.417908 :C97E0697:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:59:26.405 2025-09-05 21:59:26.417910 :C97E0698:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=18748 pso_num=24 pso_serial#=223 2025-09-05 21:59:26.418044 :C97E0699:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=18748 (legacy spawn) 2025-09-05 21:59:26.424533 :C97E069A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:26.424695 :C97E06A3:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 21:59:26.425507 :C97E06A4:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-09-05 21:59:30.235365 :C97E07D8:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 09-05 21:59:30.229 2025-09-05 21:59:30.235368 :C97E07D9:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=16340 pso_num=24 pso_serial#=224 2025-09-05 21:59:30.235507 :C97E07DA:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=16340 osp_idx=22 osp_ver=848198 osp_pg=0 (spawn #562478) 2025-09-05 21:59:30.235508 :C97E07DB:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-05 21:59:30.235508 :C97E07DC:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=211 time=1495221533 2025-09-05 21:59:30.235508 :C97E07DD:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-09-05 21:59:30.235509 :C97E07DE:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-09-05 21:59:30.235509 :C97E07DF:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-09-05 21:59:30.235509 :C97E07E0:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-05 21:59:30.235510 :C97E07E1:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-05 21:59:30.235991 :C97E07E2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-05 21:59:30.236638 :C97E07F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:30.244245 :C97E0813:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-09-05 21:59:30.244597 :C97E0814:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:30.244631 :C97E0817:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-09-05 21:59:30.245557 :C97E081D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 21:59:30.245692 :C97E0826:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 22:00:00.278200 :C97E12FD:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-05 22:00:00.278200*:C97E130F:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024D5C718 estart=1757080799 eid=16787435 ctx=0x000000077FD6A000 cwh=0x0000000024D50068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-09-05 22:00:00.278200*:C97E1310:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024D5C718 curCtx=0x0000000024D58938 pubTabIdxCnt=0 2025-09-05 22:00:00.278200*:C97E1311:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024D5C718 2025-09-05 22:00:00.278200*:C97E1312:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024D5C718 2025-09-05 22:00:00.278200*:C97E1313:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024D5C718 curCtx=0x0000000024D58938 xsc->flg4=65792 flags=2 2025-09-05 22:00:00.278200*:C97E1314:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024D5C718 2025-09-05 22:00:00.283790 :C97E131F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.283832 :C97E1323:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-09-05 22:00:00.294815 :C97E14AE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.295294 :C97E14C0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.300286 :C97E14F7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.300703 :C97E150D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.301043 :C97E151C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.306862 :C97E156C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.307019 :C97E1583:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.307808 :C97E15B3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-09-05 22:00:00.309183 :C97E15F4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.309224 :C97E15F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.309258 :C97E15FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.309375 :C97E160E:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 22:00:00.402794 :C97E1650:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-05 22:00:00.404921 :C97E1654:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.404963 :C97E1657:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-09-05 22:00:00.407307 :C97E165D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-09-05 22:00:00.410696 :C97E165E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.410774 :C97E1661:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-09-05 22:00:00.410866 :C97E166E:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-09-05 22:00:04.013631 :C97E1B2C:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-05 22:00:04.013631*:C97E1B2F:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024D5C718 estart=1757080803 eid=16787441 ctx=0x000000077FD6A000 cwh=0x0000000024D50068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-09-05 22:00:04.013631*:C97E1B30:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024D5C718 curCtx=0x0000000024D58938 pubTabIdxCnt=0 2025-09-05 22:00:04.013631*:C97E1B31:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024D5C718 2025-09-05 22:00:04.013631*:C97E1B32:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024D5C718 2025-09-05 22:00:04.013631*:C97E1B33:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024D5C718 curCtx=0x0000000024D58938 xsc->flg4=65792 flags=2 2025-09-05 22:00:04.013631*:C97E1B34:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024D5C718 2025-09-05 22:00:04.015785 :C97E1B35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:04.015823 :C97E1B38:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-09-05 22:00:04.022382 :C97E1B3E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:04.023210 :C97E1B46:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:04.023988 :C97E1B4E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:04.024187 :C97E1B56:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-09-05 22:00:04.025566 :C97E1B57:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-05 22:00:04.025605 :C97E1B5A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-09-05 22:00:04.025675 :C97E1B67:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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 24 (osid: 16340, J000)