Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250505220006\orcl_j000_8872_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:37483M/63366M, Ph+PgF:44967M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 8872, image: ORACLE.EXE (J000) *** 2025-05-05 22:00:06.715 *** SESSION ID:(193.7417) 2025-05-05 22:00:06.715 *** 2025-05-05 22:00:06.715 Process diagnostic dump for ORACLE.EXE (J000), OS id=8872, pid: 24, proc_ser: 228, sid: 193, sess_ser: 7417 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 8872 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.190386 sec, exc=0.190386 sec, total=0.190386 sec wait times: max=0.500000 sec, heur=2.685701 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.000006 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499991 sec, exc=0.499991 sec, total=0.499991 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500005 sec, exc=0.500005 sec, total=0.500005 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 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.000005 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.500004 sec, exc=0.500004 sec, total=0.500004 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=0 seq_num=1 snap_id=1 wait times: snap=0.495285 sec, exc=0.495285 sec, total=0.495285 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 7417 --------------------------------------------------- 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 --------------------------------------------------- [3 samples, 22:00:04 - 22:00:06] 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-05-05 22:00:06.715 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 8872, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-05 21:57:35.386859 :9330BD8E:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=8848 (legacy spawn) 2025-05-05 21:57:35.393264 :9330BD8F: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-05-05 21:57:35.393436 :9330BD94: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-05-05 21:57:35.394230 :9330BD99:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:57:37.019534 :9330BE3A:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:57:37.014 2025-05-05 21:57:37.019535 :9330BE3B:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=6488 pso_num=24 pso_serial#=214 2025-05-05 21:57:37.019672 :9330BE3C:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=6488 osp_idx=22 osp_ver=229968 osp_pg=0 (spawn #152113) 2025-05-05 21:57:37.019673 :9330BE3D:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 21:57:37.019673 :9330BE3E:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=122 time=3753034187 2025-05-05 21:57:37.019674 :9330BE3F:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 21:57:37.019674 :9330BE40:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 21:57:37.019674 :9330BE41:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 21:57:37.019674 :9330BE42:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 21:57:37.019675 :9330BE43:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 21:57:37.020152 :9330BE44: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-05-05 21:57:37.020930 :9330BE59: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-05-05 21:57:37.028324 :9330BE75:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-05-05 21:57:37.028698 :9330BE76: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-05-05 21:57:37.028745 :9330BE79:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-05-05 21:57:37.029688 :9330BE7F: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-05-05 21:57:37.029819 :9330BE88: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-05-05 21:58:07.110871 :9330C89C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:58:09.556601 :9330C96C:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:58:09.548 2025-05-05 21:58:09.556603 :9330C96D:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9076 pso_num=24 pso_serial#=215 2025-05-05 21:58:09.556734 :9330C96E:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=9076 (legacy spawn) 2025-05-05 21:58:09.563115 :9330C96F: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-05-05 21:58:09.563281 :9330C975: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-05-05 21:58:09.564085 :9330C979:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:58:15.616290 :9330CB57:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:58:15.602 2025-05-05 21:58:15.616293 :9330CB58:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=8228 pso_num=24 pso_serial#=216 2025-05-05 21:58:15.616432 :9330CB59:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=8228 (legacy spawn) 2025-05-05 21:58:15.622804 :9330CB5A: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-05-05 21:58:15.622990 :9330CB5F: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-05-05 21:58:15.623790 :9330CB64:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:58:15.641644 :9330CB67:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:58:15.633 2025-05-05 21:58:15.641646 :9330CB68:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11372 pso_num=24 pso_serial#=217 2025-05-05 21:58:15.641786 :9330CB69:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=11372 (legacy spawn) 2025-05-05 21:58:15.648216 :9330CB6A: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-05-05 21:58:15.648375 :9330CB73: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-05-05 21:58:15.649200 :9330CB74:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:58:18.818930 :9330CC66:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:58:18.805 2025-05-05 21:58:18.818933 :9330CC67:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10684 pso_num=24 pso_serial#=218 2025-05-05 21:58:18.819069 :9330CC68:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=10684 (legacy spawn) 2025-05-05 21:58:18.825564 :9330CC69: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-05-05 21:58:18.825728 :9330CC6E: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-05-05 21:58:18.826537 :9330CC73:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:58:18.835054 :9330CC76:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:58:18.821 2025-05-05 21:58:18.835056 :9330CC77:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11012 pso_num=24 pso_serial#=219 2025-05-05 21:58:18.835209 :9330CC78:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=11012 (legacy spawn) 2025-05-05 21:58:18.841774 :9330CC85: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-05-05 21:58:18.841944 :9330CC8E: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-05-05 21:58:18.842814 :9330CC8F:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:58:19.393232 :9330CCC2:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:58:19.385 2025-05-05 21:58:19.393234 :9330CCC3:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10024 pso_num=24 pso_serial#=220 2025-05-05 21:58:19.393387 :9330CCC4:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=10024 (legacy spawn) 2025-05-05 21:58:19.399829 :9330CCC5: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-05-05 21:58:19.399998 :9330CCCE: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-05-05 21:58:19.400890 :9330CCCF:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:58:37.125000 :9330D24E:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:58:37.119 2025-05-05 21:58:37.125002 :9330D24F:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11348 pso_num=24 pso_serial#=221 2025-05-05 21:58:37.125139 :9330D250:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=11348 osp_idx=22 osp_ver=229975 osp_pg=0 (spawn #152115) 2025-05-05 21:58:37.125140 :9330D251:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 21:58:37.125141 :9330D252:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=123 time=3753094296 2025-05-05 21:58:37.125141 :9330D253:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 21:58:37.125141 :9330D254:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 21:58:37.125142 :9330D255:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 21:58:37.125142 :9330D256:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 21:58:37.125143 :9330D257:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 21:58:37.125633 :9330D258: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-05-05 21:58:37.126282 :9330D26D: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-05-05 21:58:37.137192 :9330D289:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-05 21:58:37.137656 :9330D28A:db_trace:kwqid.c@2146:kwqidrdq(): [10960:24:193] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-05 21:58:37.140002 :9330D28B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:psdpgi.c:2235 2025-05-05 21:58:37.140353 :9330D28C: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-05-05 21:58:37.140390 :9330D28F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:psdpgi.c:2235 2025-05-05 21:58:37.141249 :9330D295: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-05-05 21:58:37.141386 :9330D29E: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-05-05 21:59:07.233579 :9330DC5C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:59:17.853014 :9330DF91:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:59:17.843 2025-05-05 21:59:17.853016 :9330DF92:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12244 pso_num=24 pso_serial#=222 2025-05-05 21:59:17.853154 :9330DF93:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12244 (legacy spawn) 2025-05-05 21:59:17.859728 :9330DF94: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-05-05 21:59:17.859904 :9330DF99: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-05-05 21:59:17.860724 :9330DF9E:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:59:21.596052 :9330E0CA:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:59:21.587 2025-05-05 21:59:21.596054 :9330E0CB:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=1112 pso_num=24 pso_serial#=223 2025-05-05 21:59:21.596185 :9330E0CC:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=1112 (legacy spawn) 2025-05-05 21:59:21.602613 :9330E0CD: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-05-05 21:59:21.602776 :9330E0D3: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-05-05 21:59:21.603663 :9330E0D7:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:59:28.516810 :9330E33D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:59:28.502 2025-05-05 21:59:28.516811 :9330E33E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11988 pso_num=24 pso_serial#=224 2025-05-05 21:59:28.516955 :9330E33F:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=11988 (legacy spawn) 2025-05-05 21:59:28.523324 :9330E340: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-05-05 21:59:28.523500 :9330E349: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-05-05 21:59:28.524290 :9330E34A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:59:28.532783 :9330E34D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:59:28.518 2025-05-05 21:59:28.532786 :9330E34E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=4460 pso_num=24 pso_serial#=225 2025-05-05 21:59:28.532922 :9330E34F:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=4460 (legacy spawn) 2025-05-05 21:59:28.539346 :9330E350: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-05-05 21:59:28.539519 :9330E359: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-05-05 21:59:28.540315 :9330E35A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:59:31.811320 :9330E443:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:59:31.809 2025-05-05 21:59:31.811322 :9330E444:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12260 pso_num=24 pso_serial#=226 2025-05-05 21:59:31.811470 :9330E445:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=12260 (legacy spawn) 2025-05-05 21:59:31.818127 :9330E446: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-05-05 21:59:31.818306 :9330E44B: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-05-05 21:59:31.819178 :9330E450:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:59:31.828095 :9330E453:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:59:31.825 2025-05-05 21:59:31.828097 :9330E454:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=6028 pso_num=24 pso_serial#=227 2025-05-05 21:59:31.828235 :9330E455:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=6028 (legacy spawn) 2025-05-05 21:59:31.835028 :9330E456: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-05-05 21:59:31.835220 :9330E45D: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-05-05 21:59:31.836072 :9330E460:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-05 21:59:32.220916 :9330E492:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-05 21:59:32.215 2025-05-05 21:59:32.220918 :9330E493:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=8872 pso_num=24 pso_serial#=228 2025-05-05 21:59:32.221056 :9330E494:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=8872 osp_idx=22 osp_ver=229982 osp_pg=0 (spawn #152118) 2025-05-05 21:59:32.221057 :9330E495:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 21:59:32.221057 :9330E496:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=124 time=3753149390 2025-05-05 21:59:32.221058 :9330E497:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 21:59:32.221058 :9330E498:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 21:59:32.221058 :9330E499:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 21:59:32.221059 :9330E49A:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 21:59:32.221059 :9330E49B:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 21:59:32.221560 :9330E49C: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-05-05 21:59:32.222193 :9330E4B1: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-05-05 21:59:32.227611 :9330E4CD: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-05-05 21:59:32.228563 :9330E4D5: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-05-05 21:59:32.228697 :9330E4DE: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-05-05 21:59:37.232734 :9330E67C: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-05-05 22:00:02.038850 :9330F05A: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-05-05 22:00:02.038850*:9330F06A:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002495C718 estart=1746453601 eid=16779881 ctx=0x000000077FD6A000 cwh=0x0000000024950068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-05 22:00:02.038850*:9330F06D:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002495C718 curCtx=0x0000000024958938 pubTabIdxCnt=0 2025-05-05 22:00:02.038850*:9330F06E:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002495C718 2025-05-05 22:00:02.038850*:9330F071:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002495C718 2025-05-05 22:00:02.043454 :9330F072:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=25 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.043557 :9330F075:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=25 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.043563 :9330F077:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=25 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.043568 :9330F079:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=25 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.043591 :9330F07B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=25 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.043591*:9330F07E:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002495C718 curCtx=0x0000000024958938 xsc->flg4=65792 flags=2 2025-05-05 22:00:02.043591*:9330F07F:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002495C718 2025-05-05 22:00:02.044298 :9330F093: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-05-05 22:00:02.044326 :9330F096:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-05-05 22:00:02.054869 :9330F0E3: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-05-05 22:00:02.055258 :9330F0ED: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-05-05 22:00:02.060355 :9330F113: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-05-05 22:00:02.061085 :9330F125: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-05-05 22:00:02.066977 :9330F286: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-05-05 22:00:02.067129 :9330F295: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-05-05 22:00:02.067959 :9330F29D: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-05-05 22:00:02.068170 :9330F2A5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-05-05 22:00:02.069656 :9330F2A6: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-05-05 22:00:02.069701 :9330F2A9: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-05-05 22:00:02.069804 :9330F2B6: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-05-05 22:00:02.163832 :9330F3B2: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-05-05 22:00:02.166005 :9330F3B5: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-05-05 22:00:02.166050 :9330F3B8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-05-05 22:00:02.168584 :9330F3BE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-05-05 22:00:02.171959 :9330F3BF: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-05-05 22:00:02.172041 :9330F3C2: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-05-05 22:00:02.172121 :9330F3CF: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-05-05 22:00:04.017946 :9330F7F9: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-05-05 22:00:04.017946*:9330F7FB:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002495C718 estart=1746453603 eid=16779887 ctx=0x000000077FD6A000 cwh=0x0000000024950068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-05 22:00:04.017946*:9330F7FC:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002495C718 curCtx=0x0000000024958938 pubTabIdxCnt=0 2025-05-05 22:00:04.017946*:9330F7FD:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002495C718 2025-05-05 22:00:04.017946*:9330F7FE:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002495C718 2025-05-05 22:00:04.017946*:9330F7FF:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002495C718 curCtx=0x0000000024958938 xsc->flg4=65792 flags=2 2025-05-05 22:00:04.017946*:9330F800:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002495C718 2025-05-05 22:00:04.020191 :9330F801: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-05-05 22:00:04.020234 :9330F804:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-05-05 22:00:04.027214 :9330F80A: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-05-05 22:00:04.027924 :9330F812: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-05-05 22:00:04.028634 :9330F81A: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-05-05 22:00:04.028833 :9330F822:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-05-05 22:00:04.030666 :9330F823: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-05-05 22:00:04.030710 :9330F826: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-05-05 22:00:04.030802 :9330F833: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: 8872, J000)