Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250504060008\orcl_j000_11376_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:37550M/63366M, Ph+PgF:45030M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 11376, image: ORACLE.EXE (J000) *** 2025-05-04 06:00:08.823 *** SESSION ID:(177.25717) 2025-05-04 06:00:08.823 *** 2025-05-04 06:00:08.823 Process diagnostic dump for ORACLE.EXE (J000), OS id=11376, pid: 22, proc_ser: 125, sid: 177, sess_ser: 25717 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 11376 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.160837 sec, exc=0.160837 sec, total=0.160837 sec wait times: max=0.500000 sec, heur=6.665031 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.000010 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 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=10 seq_num=11 snap_id=1 wait times: snap=0.499965 sec, exc=0.499965 sec, total=0.499965 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.510119 sec, exc=0.510119 sec, total=0.510119 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=8 seq_num=9 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.000009 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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.000011 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 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.000011 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.504573 sec, exc=0.504573 sec, total=0.504573 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time Sampled Session History of session 177 serial 25717 --------------------------------------------------- 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 --------------------------------------------------- [7 samples, 06:00:02 - 06:00:08] idle wait at each sample [session created at: 06:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-04 06:00:08.823 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 11376, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-04 05:57:46.318378 :9272502F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:57:46.326911 :92725032:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:57:46.311 2025-05-04 05:57:46.326913 :92725033:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11480 pso_num=22 pso_serial#=107 2025-05-04 05:57:46.327049 :92725034:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11480 (legacy spawn) 2025-05-04 05:57:46.333531 :9272505F: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-04 05:57:46.333694 :92725068: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-04 05:57:46.334505 :92725069:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:57:49.413240 :92725150:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:57:49.400 2025-05-04 05:57:49.413242 :92725151:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8164 pso_num=22 pso_serial#=108 2025-05-04 05:57:49.413378 :92725152:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8164 (legacy spawn) 2025-05-04 05:57:49.419787 :92725153: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-04 05:57:49.419963 :92725158: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-04 05:57:49.420775 :9272515D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:57:49.429302 :92725160:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:57:49.415 2025-05-04 05:57:49.429304 :92725161:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8432 pso_num=22 pso_serial#=109 2025-05-04 05:57:49.429437 :92725162:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8432 (legacy spawn) 2025-05-04 05:57:49.435862 :92725163: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-04 05:57:49.436021 :9272516C: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-04 05:57:49.436794 :9272516D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:57:54.143565 :927252C2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:57:54.135 2025-05-04 05:57:54.143568 :927252C3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10856 pso_num=22 pso_serial#=110 2025-05-04 05:57:54.143722 :927252C4:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10856 (legacy spawn) 2025-05-04 05:57:54.150545 :927252C5: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-04 05:57:54.150708 :927252CD: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-04 05:57:54.151680 :927252CF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:57:54.453161 :92725301:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:57:54.448 2025-05-04 05:57:54.453163 :92725302:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11420 pso_num=22 pso_serial#=111 2025-05-04 05:57:54.453297 :92725303:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11420 osp_idx=0 osp_ver=152091 osp_pg=0 (spawn #146458) 2025-05-04 05:57:54.453298 :92725304: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-04 05:57:54.453298 :92725305:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=35 time=3609051625 2025-05-04 05:57:54.453299 :92725306:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:57:54.453299 :92725307:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:57:54.453299 :92725308:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:57:54.453300 :92725309:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:57:54.453300 :9272530A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:57:54.453777 :9272530B: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-04 05:57:54.454413 :92725320: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-04 05:57:54.461929 :9272533C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-04 05:57:54.462290 :9272533D: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-04 05:57:54.462328 :92725340:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-04 05:57:54.463230 :92725346: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-04 05:57:54.463351 :9272534F: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-04 05:58:24.545653 :92725CD9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:58:25.943543 :92725D7A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:58:25.930 2025-05-04 05:58:25.943545 :92725D7B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11912 pso_num=22 pso_serial#=112 2025-05-04 05:58:25.943684 :92725D7C:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11912 (legacy spawn) 2025-05-04 05:58:25.950218 :92725D88: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-04 05:58:25.950402 :92725D90: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-04 05:58:25.951213 :92725D92:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:58:25.960033 :92725D95:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:58:25.960 2025-05-04 05:58:25.960036 :92725D96:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11800 pso_num=22 pso_serial#=113 2025-05-04 05:58:25.960178 :92725D97:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11800 (legacy spawn) 2025-05-04 05:58:25.966647 :92725D98: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-04 05:58:25.966812 :92725DA1: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-04 05:58:25.967612 :92725DA2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:58:28.155295 :92725E0F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:58:28.146 2025-05-04 05:58:28.155297 :92725E10:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2804 pso_num=22 pso_serial#=114 2025-05-04 05:58:28.155433 :92725E11:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=2804 (legacy spawn) 2025-05-04 05:58:28.161841 :92725E12: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-04 05:58:28.162028 :92725E17: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-04 05:58:28.162813 :92725E1C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:58:46.693111 :927264BF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:58:46.680 2025-05-04 05:58:46.693112 :927264C0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9172 pso_num=22 pso_serial#=115 2025-05-04 05:58:46.693246 :927264C1:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9172 (legacy spawn) 2025-05-04 05:58:46.699720 :927264C2: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-04 05:58:46.700008 :927264C7: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-04 05:58:46.700795 :927264CC:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:58:54.529371 :9272671B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:58:54.523 2025-05-04 05:58:54.529373 :9272671C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11572 pso_num=22 pso_serial#=116 2025-05-04 05:58:54.529515 :9272671D:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11572 osp_idx=0 osp_ver=152096 osp_pg=0 (spawn #146460) 2025-05-04 05:58:54.529516 :9272671E: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-04 05:58:54.529516 :9272671F:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=36 time=3609111687 2025-05-04 05:58:54.529517 :92726720:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:58:54.529517 :92726721:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:58:54.529517 :92726722:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:58:54.529518 :92726723:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:58:54.529518 :92726724:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:58:54.530023 :92726725: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-04 05:58:54.530700 :9272673A: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-04 05:58:54.541738 :92726756:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-04 05:58:54.542251 :92726757:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-04 05:58:54.544583 :92726758:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-04 05:58:54.544914 :92726759: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-04 05:58:54.544949 :9272675C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-04 05:58:54.545833 :92726762: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-04 05:58:54.545971 :9272676B: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-04 05:59:24.640929 :9272710D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:30.919100 :927272FB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:30.906 2025-05-04 05:59:30.919102 :927272FC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10764 pso_num=22 pso_serial#=117 2025-05-04 05:59:30.919234 :927272FD:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10764 (legacy spawn) 2025-05-04 05:59:30.925753 :927272FE: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-04 05:59:30.925918 :92727303: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-04 05:59:30.926732 :92727308:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:30.935601 :9272730B:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:30.921 2025-05-04 05:59:30.935603 :9272730C:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10448 pso_num=22 pso_serial#=118 2025-05-04 05:59:30.935750 :9272730D:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10448 (legacy spawn) 2025-05-04 05:59:30.942182 :9272730E: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-04 05:59:30.942348 :92727317: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-04 05:59:30.943145 :92727318:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:35.514891 :927274D5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:35.500 2025-05-04 05:59:35.514893 :927274D6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8780 pso_num=22 pso_serial#=119 2025-05-04 05:59:35.515032 :927274D7:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8780 (legacy spawn) 2025-05-04 05:59:35.521506 :927274E6: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-04 05:59:35.521694 :927274EF: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-04 05:59:35.522531 :927274F0:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:35.540740 :927274F3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:35.532 2025-05-04 05:59:35.540742 :927274F4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10256 pso_num=22 pso_serial#=120 2025-05-04 05:59:35.540886 :927274F5:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10256 (legacy spawn) 2025-05-04 05:59:35.547395 :927274F6: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-04 05:59:35.547559 :927274FF: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-04 05:59:35.548408 :92727500:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:36.555978 :9272751A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:36.547 2025-05-04 05:59:36.555980 :9272751B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11244 pso_num=22 pso_serial#=121 2025-05-04 05:59:36.556116 :9272751C:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11244 (legacy spawn) 2025-05-04 05:59:36.562596 :9272751D: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-04 05:59:36.562792 :92727522: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-04 05:59:36.563601 :92727527:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:38.714863 :927275F6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:38.713 2025-05-04 05:59:38.714865 :927275F7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10660 pso_num=22 pso_serial#=122 2025-05-04 05:59:38.714998 :927275F8:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=10660 (legacy spawn) 2025-05-04 05:59:38.730876 :927275F9: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-04 05:59:38.731045 :92727602: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-04 05:59:38.731886 :92727603:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:38.740544 :92727606:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:38.729 2025-05-04 05:59:38.740547 :92727607:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8696 pso_num=22 pso_serial#=123 2025-05-04 05:59:38.740677 :92727608:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=8696 (legacy spawn) 2025-05-04 05:59:38.747114 :92727609: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-04 05:59:38.747282 :92727612: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-04 05:59:38.748102 :92727613:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:49.011383 :927278FE:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:49.003 2025-05-04 05:59:49.011385 :927278FF:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11756 pso_num=22 pso_serial#=124 2025-05-04 05:59:49.011529 :92727900:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11756 (legacy spawn) 2025-05-04 05:59:49.017975 :92727901: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-04 05:59:49.018154 :92727906: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-04 05:59:49.018992 :9272790B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-04 05:59:54.617325 :92727AF4:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-04 05:59:54.612 2025-05-04 05:59:54.617327 :92727AF5:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11376 pso_num=22 pso_serial#=125 2025-05-04 05:59:54.617468 :92727AF6:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11376 osp_idx=0 osp_ver=152105 osp_pg=0 (spawn #146462) 2025-05-04 05:59:54.617469 :92727AF7: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-04 05:59:54.617470 :92727AF8:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=37 time=3609171781 2025-05-04 05:59:54.617470 :92727AF9:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:59:54.617470 :92727AFA:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:59:54.617471 :92727AFB:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:59:54.617471 :92727AFC:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:59:54.617472 :92727AFD:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:59:54.617977 :92727AFE: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-04 05:59:54.618614 :92727B13: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-04 05:59:54.626116 :92727B2F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-05-04 05:59:54.626494 :92727B30: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-04 05:59:54.626531 :92727B33:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-05-04 05:59:54.627381 :92727B39: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-04 05:59:54.627498 :92727B42: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-04 06:00:02.028217 :92727F9D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-04 06:00:02.028217*:92727FC2:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000000FCDC718 estart=1746309601 eid=16779778 ctx=0x000000077FD6A000 cwh=0x000000000FCD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-04 06:00:02.028217*:92727FC3:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 pubTabIdxCnt=0 2025-05-04 06:00:02.028217*:92727FC4:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000000FCDC718 2025-05-04 06:00:02.028217*:92727FC5:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000000FCDC718 2025-05-04 06:00:02.028217*:92727FE1:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000000FCDC718 curCtx=0x000000000FCD8938 xsc->flg4=65792 flags=2 2025-05-04 06:00:02.028217*:92727FE2:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000000FCDC718 2025-05-04 06:00:02.035104 :92727FE3: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-04 06:00:02.035170 :92727FE6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-05-04 06:00:02.046441 :92728044: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-04 06:00:02.051426 :92728069: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-04 06:00:02.052208 :92728071: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-04 06:00:02.058050 :92728081:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-04 06:00:02.058205 :92728090:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-04 06:00:02.059014 :92728098: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-04 06:00:02.059210 :927280A0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-05-04 06:00:02.060893 :927280A1: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-04 06:00:02.060948 :927280A4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-04 06:00:02.061055 :927280B1: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-04 06:00:02.153124 :927282EB:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-04 06:00:02.155393 :927282ED: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-04 06:00:02.155436 :927282F0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-05-04 06:00:02.158047 :927282F6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:jslv.c:9203 2025-05-04 06:00:02.161642 :927282F7: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-04 06:00:02.161749 :927282FA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-04 06:00:02.161833 :92728307: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: 11376, J000)