Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250703220552\orcl_j001_5964_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:36987M/63366M, Ph+PgF:42946M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 5964, image: ORACLE.EXE (J001) *** 2025-07-03 22:05:52.224 *** SESSION ID:(201.7207) 2025-07-03 22:05:52.224 *** 2025-07-03 22:05:52.224 Process diagnostic dump for ORACLE.EXE (J001), OS id=5964, pid: 25, proc_ser: 200, sid: 201, sess_ser: 7207 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 5964 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.192402 sec, exc=0.192402 sec, total=0.192402 sec wait times: max=0.500000 sec, heur=19.229481 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=37 seq_num=38 snap_id=1 wait times: snap=0.499981 sec, exc=0.499981 sec, total=0.499981 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000016 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=36 seq_num=37 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.000010 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.510059 sec, exc=0.510059 sec, total=0.510059 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.500007 sec, exc=0.500007 sec, total=0.500007 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.499985 sec, exc=0.499985 sec, total=0.499985 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.499989 sec, exc=0.499989 sec, total=0.499989 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=31 seq_num=32 snap_id=1 wait times: snap=0.510103 sec, exc=0.510103 sec, total=0.510103 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=30 seq_num=31 snap_id=1 wait times: snap=0.499999 sec, exc=0.499999 sec, total=0.499999 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=29 seq_num=30 snap_id=1 wait times: snap=0.510143 sec, exc=0.510143 sec, total=0.510143 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=28 seq_num=29 snap_id=1 wait times: snap=0.500014 sec, exc=0.500014 sec, total=0.500014 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000016 sec of elapsed time Sampled Session History of session 201 serial 7207 --------------------------------------------------- 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 --------------------------------------------------- [20 samples, 22:05:32 - 22:05:52] idle wait at each sample [session created at: 22:05:32] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-03 22:05:52.224 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 5964, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-03 21:52:31.794939 :AD21E5CC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:52:31.794939 :AD21E5CD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:52:31.795444 :AD21E5CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:53:01.886486 :AD21EFB4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:53:31.873054 :AD21F957:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:53:31.861 2025-07-03 21:53:31.873057 :AD21F958:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17812 pso_num=25 pso_serial#=189 2025-07-03 21:53:31.873168 :AD21F959:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17812 osp_idx=23 osp_ver=180841 osp_pg=0 (spawn #349145) 2025-07-03 21:53:31.873168 :AD21F95A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:53:31.873169 :AD21F95B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=33 time=260387767 2025-07-03 21:53:31.873169 :AD21F95C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:53:31.873170 :AD21F95D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:53:31.873170 :AD21F95E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:53:31.873170 :AD21F95F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:53:31.873171 :AD21F960:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:53:31.873681 :AD21F961:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:54:01.916178 :AD220303:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:54:31.938139 :AD220D15:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:54:31.927 2025-07-03 21:54:31.938141 :AD220D16:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9264 pso_num=25 pso_serial#=190 2025-07-03 21:54:31.938264 :AD220D17:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9264 osp_idx=23 osp_ver=180842 osp_pg=0 (spawn #349147) 2025-07-03 21:54:31.938265 :AD220D18:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:54:31.938265 :AD220D19:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=34 time=260447829 2025-07-03 21:54:31.938266 :AD220D1A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:54:31.938266 :AD220D1B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:54:31.938267 :AD220D1C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:54:31.938267 :AD220D1D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:54:31.938268 :AD220D1E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:54:31.938758 :AD220D1F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:55:02.019052 :AD2217C8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:55:32.029230 :AD222181:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:55:32.018 2025-07-03 21:55:32.029232 :AD222182:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7924 pso_num=25 pso_serial#=191 2025-07-03 21:55:32.029344 :AD222183:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7924 osp_idx=23 osp_ver=180843 osp_pg=0 (spawn #349149) 2025-07-03 21:55:32.029345 :AD222184:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:55:32.029345 :AD222185:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=35 time=260507923 2025-07-03 21:55:32.029346 :AD222186:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:55:32.029346 :AD222187:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:55:32.029347 :AD222188:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:55:32.029347 :AD222189:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:55:32.029347 :AD22218A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:55:32.029859 :AD22218B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:56:02.109780 :AD222B01:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:56:32.119325 :AD223494:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:56:32.108 2025-07-03 21:56:32.119327 :AD223495:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18004 pso_num=25 pso_serial#=192 2025-07-03 21:56:32.119467 :AD223496:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18004 osp_idx=23 osp_ver=180844 osp_pg=0 (spawn #349151) 2025-07-03 21:56:32.119468 :AD223497:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:56:32.119468 :AD223498:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=36 time=260568001 2025-07-03 21:56:32.119469 :AD223499:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:56:32.119469 :AD22349A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:56:32.119469 :AD22349B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:56:32.119470 :AD22349C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:56:32.119470 :AD22349D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:56:32.119940 :AD22349E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:57:02.211447 :AD223E51:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:57:32.209654 :AD2247FD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:57:32.197 2025-07-03 21:57:32.209656 :AD2247FE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=6128 pso_num=25 pso_serial#=193 2025-07-03 21:57:32.209790 :AD2247FF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=6128 osp_idx=23 osp_ver=180845 osp_pg=0 (spawn #349153) 2025-07-03 21:57:32.209791 :AD224800:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:57:32.209791 :AD224801:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=37 time=260628095 2025-07-03 21:57:32.209792 :AD224802:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:57:32.209792 :AD224803:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:57:32.209793 :AD224804:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:57:32.209794 :AD224805:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:57:32.209794 :AD224806:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:57:32.210343 :AD224807:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:58:02.285566 :AD225234:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:58:32.304576 :AD225BE1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:58:32.293 2025-07-03 21:58:32.304578 :AD225BE2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=3280 pso_num=25 pso_serial#=194 2025-07-03 21:58:32.304712 :AD225BE3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=3280 osp_idx=23 osp_ver=180846 osp_pg=0 (spawn #349156) 2025-07-03 21:58:32.304712 :AD225BE4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:58:32.304713 :AD225BE5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=38 time=260688189 2025-07-03 21:58:32.304713 :AD225BE6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:58:32.304714 :AD225BE7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:58:32.304714 :AD225BE8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:58:32.304715 :AD225BE9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:58:32.304715 :AD225BEA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:58:32.305222 :AD225BEB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:58:57.346586 :AD22643C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 21:59:27.423653 :AD226E22:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:59:32.407573 :AD226F6B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:59:32.396 2025-07-03 21:59:32.407576 :AD226F6C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14916 pso_num=25 pso_serial#=195 2025-07-03 21:59:32.407690 :AD226F6D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14916 osp_idx=23 osp_ver=180847 osp_pg=0 (spawn #349158) 2025-07-03 21:59:32.407691 :AD226F6E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:59:32.407691 :AD226F6F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=39 time=260748298 2025-07-03 21:59:32.407691 :AD226F70:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:59:32.407691 :AD226F71:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:59:32.407692 :AD226F72:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:59:32.407692 :AD226F73:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:59:32.407692 :AD226F74:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:59:32.408207 :AD226F75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.036614 :AD227AD4:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.036614*:AD227AF3:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEB898 estart=1751551201 eid=16783503 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-03 22:00:02.036614*:AD227AF5:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 pubTabIdxCnt=0 2025-07-03 22:00:02.036614*:AD227AF6:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEB898 2025-07-03 22:00:02.036614*:AD227AF7:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEB898 2025-07-03 22:00:02.036614*:AD227B15:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 xsc->flg4=65792 flags=2 2025-07-03 22:00:02.036614*:AD227B16:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEB898 2025-07-03 22:00:02.043487 :AD227B17:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.043539 :AD227B1A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-03 22:00:02.076775 :AD227C53:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-03 22:00:02.077448 :AD227C54:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 9e2d120000000000 2025-07-03 22:00:02.081656 :AD227C55:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.081751 :AD227C65:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.081763 :AD227C69:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-07-03 22:00:02.081769 :AD227C6A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.081798 :AD227C79:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.082614 :AD227C82:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 230271541) 2025-07-03 22:00:02.082617 :AD227C83:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.082646 :AD227C93:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.082657 :AD227C9A:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65561 1) 2025-07-03 22:00:02.082659 :AD227C9B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.082696 :AD227CA7:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.082700 :AD227CB3:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65561) 2025-07-03 22:00:02.082702 :AD227CB4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.082745 :AD227CD5:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.083161 :AD227D4E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.083175 :AD227D4F:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-03 22:00:02.083962 :AD227D56:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 9f2d120000000000 2025-07-03 22:00:02.084342 :AD227D57:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 230271541) 2025-07-03 22:00:02.084346 :AD227D58:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.084374 :AD227D67:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.116237 :AD227D78:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-03 22:00:02.118077 :AD227D79:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.118134 :AD227D7C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.118289 :AD227D88:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-03 22:00:02.161640 :AD227DB0:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:04.009935 :AD22822D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:32.553219 :AD228D8B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:01:02.654097 :AD229922:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 22:01:32.626409 :AD22A2C5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 22:01:32.615 2025-07-03 22:01:32.626411 :AD22A2C6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15600 pso_num=25 pso_serial#=196 2025-07-03 22:01:32.626593 :AD22A2C7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15600 osp_idx=23 osp_ver=180848 osp_pg=0 (spawn #349169) 2025-07-03 22:01:32.626594 :AD22A2C8:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 22:01:32.626594 :AD22A2C9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=40 time=260868517 2025-07-03 22:01:32.626595 :AD22A2CA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 22:01:32.626595 :AD22A2CB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 22:01:32.626596 :AD22A2CC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 22:01:32.626596 :AD22A2CD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 22:01:32.626596 :AD22A2CE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 22:01:32.627093 :AD22A2CF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 22:02:02.733076 :AD22AC2A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 22:02:32.736142 :AD22B5AF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 22:02:32.724 2025-07-03 22:02:32.736144 :AD22B5B0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8860 pso_num=25 pso_serial#=197 2025-07-03 22:02:32.736282 :AD22B5B1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8860 osp_idx=23 osp_ver=180849 osp_pg=0 (spawn #349171) 2025-07-03 22:02:32.736282 :AD22B5B2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 22:02:32.736283 :AD22B5B3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=41 time=260928626 2025-07-03 22:02:32.736283 :AD22B5B4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 22:02:32.736283 :AD22B5B5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 22:02:32.736284 :AD22B5B6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 22:02:32.736284 :AD22B5B7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 22:02:32.736284 :AD22B5B8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 22:02:32.736745 :AD22B5B9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 22:03:02.812789 :AD22BFDA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 22:03:32.813373 :AD22C97C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 22:03:32.802 2025-07-03 22:03:32.813376 :AD22C97D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15528 pso_num=25 pso_serial#=198 2025-07-03 22:03:32.813501 :AD22C97E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15528 osp_idx=23 osp_ver=180850 osp_pg=0 (spawn #349175) 2025-07-03 22:03:32.813502 :AD22C97F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 22:03:32.813502 :AD22C980:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=42 time=260988704 2025-07-03 22:03:32.813502 :AD22C981:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 22:03:32.813503 :AD22C982:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 22:03:32.813503 :AD22C983:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 22:03:32.813503 :AD22C984:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 22:03:32.813504 :AD22C985:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 22:03:32.814053 :AD22C986:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 22:04:02.889802 :AD22D332:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 22:04:32.893228 :AD22DCAF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 22:04:32.882 2025-07-03 22:04:32.893230 :AD22DCB0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15912 pso_num=25 pso_serial#=199 2025-07-03 22:04:32.893369 :AD22DCB1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15912 osp_idx=23 osp_ver=180851 osp_pg=0 (spawn #349177) 2025-07-03 22:04:32.893370 :AD22DCB2:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 22:04:32.893370 :AD22DCB3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=43 time=261048783 2025-07-03 22:04:32.893371 :AD22DCB4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 22:04:32.893371 :AD22DCB5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 22:04:32.893371 :AD22DCB6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 22:04:32.893372 :AD22DCB7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 22:04:32.893372 :AD22DCB8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 22:04:32.893846 :AD22DCB9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 22:05:02.997905 :AD22E766:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 22:05:32.998301 :AD22F445:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 22:05:32.987 2025-07-03 22:05:32.998303 :AD22F446:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=5964 pso_num=25 pso_serial#=200 2025-07-03 22:05:32.998430 :AD22F447:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=5964 osp_idx=23 osp_ver=180852 osp_pg=0 (spawn #349179) 2025-07-03 22:05:32.998431 :AD22F448:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 22:05:32.998431 :AD22F449:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=44 time=261108892 2025-07-03 22:05:32.998432 :AD22F44A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 22:05:32.998432 :AD22F44B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 22:05:32.998432 :AD22F44C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 22:05:32.998433 :AD22F44D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 22:05:32.998433 :AD22F44E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 22:05:32.998948 :AD22F44F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 5964, J001)