Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250503220929\orcl_j001_11512_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:37567M/63366M, Ph+PgF:45090M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 11512, image: ORACLE.EXE (J001) *** 2025-05-03 22:09:29.267 *** SESSION ID:(201.34439) 2025-05-03 22:09:29.267 *** 2025-05-03 22:09:29.267 Process diagnostic dump for ORACLE.EXE (J001), OS id=11512, pid: 25, proc_ser: 103, sid: 201, sess_ser: 34439 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 11512 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.115474 sec, exc=0.115474 sec, total=0.115474 sec wait times: max=0.500000 sec, heur=4.603023 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=8 seq_num=9 snap_id=1 wait times: snap=0.500169 sec, exc=0.500169 sec, total=0.500169 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499995 sec, exc=0.499995 sec, total=0.499995 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=6 seq_num=7 snap_id=1 wait times: snap=0.500111 sec, exc=0.500111 sec, total=0.500111 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.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 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.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.000013 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.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.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.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=0 seq_num=1 snap_id=1 wait times: snap=0.487195 sec, exc=0.487195 sec, total=0.487195 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 201 serial 34439 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [5 samples, 22:09:24 - 22:09:29] idle wait at each sample [session created at: 22:09:24] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-03 22:09:29.267 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 11512, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-03 22:00:04.030620 :924C3D48:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:00:04.030620 :924C3D49:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=47 time=3580381203 2025-05-03 22:00:04.030621 :924C3D4A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:00:04.030621 :924C3D4B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:00:04.030622 :924C3D4C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:00:04.030622 :924C3D4D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:00:04.030622 :924C3D4E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:00:04.031101 :924C3D50: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-05-03 22:00:09.926567 :924C3F99: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-05-03 22:00:39.984915 :924C4B64:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:01:10.016733 :924C5552:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:01:10.005 2025-05-03 22:01:10.016735 :924C5553:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11928 pso_num=25 pso_serial#=95 2025-05-03 22:01:10.016855 :924C5554:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11928 osp_idx=23 osp_ver=74299 osp_pg=0 (spawn #145337) 2025-05-03 22:01:10.016856 :924C5555:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:01:10.016856 :924C5556:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=48 time=3580447171 2025-05-03 22:01:10.016857 :924C5557:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:01:10.016857 :924C5558:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:01:10.016857 :924C5559:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:01:10.016858 :924C555A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:01:10.016858 :924C555B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:01:10.017344 :924C555C: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-05-03 22:01:40.122007 :924C5FF0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:02:10.136094 :924C69FA:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:02:10.125 2025-05-03 22:02:10.136096 :924C69FB:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=2180 pso_num=25 pso_serial#=96 2025-05-03 22:02:10.136235 :924C69FC:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=2180 osp_idx=23 osp_ver=74300 osp_pg=0 (spawn #145339) 2025-05-03 22:02:10.136235 :924C69FD:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:02:10.136235 :924C69FE:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=49 time=3580507296 2025-05-03 22:02:10.136236 :924C69FF:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:02:10.136236 :924C6A00:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:02:10.136236 :924C6A01:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:02:10.136237 :924C6A02:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:02:10.136237 :924C6A03:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:02:10.136720 :924C6A04: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-05-03 22:02:40.218380 :924C7432:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:03:10.248740 :924C7E50:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:03:10.237 2025-05-03 22:03:10.248743 :924C7E51:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11748 pso_num=25 pso_serial#=97 2025-05-03 22:03:10.248872 :924C7E52:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11748 osp_idx=23 osp_ver=74301 osp_pg=0 (spawn #145342) 2025-05-03 22:03:10.248873 :924C7E53:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:03:10.248873 :924C7E54:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=50 time=3580567406 2025-05-03 22:03:10.248874 :924C7E55:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:03:10.248874 :924C7E56:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:03:10.248875 :924C7E57:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:03:10.248875 :924C7E58:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:03:10.248875 :924C7E59:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:03:10.249353 :924C7E5A: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-05-03 22:03:40.314259 :924C8866:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:04:10.337176 :924C926A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:04:10.324 2025-05-03 22:04:10.337177 :924C926B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8548 pso_num=25 pso_serial#=98 2025-05-03 22:04:10.337299 :924C926C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8548 osp_idx=23 osp_ver=74302 osp_pg=0 (spawn #145344) 2025-05-03 22:04:10.337300 :924C926D:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:04:10.337300 :924C926E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=51 time=3580627500 2025-05-03 22:04:10.337301 :924C926F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:04:10.337301 :924C9270:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:04:10.337301 :924C9271:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:04:10.337302 :924C9272:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:04:10.337302 :924C9273:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:04:10.337799 :924C9274: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-05-03 22:04:40.436777 :924C9CE9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:05:05.402170 :924CA571:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:05:05.390 2025-05-03 22:05:05.402172 :924CA572:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10856 pso_num=25 pso_serial#=99 2025-05-03 22:05:05.402308 :924CA573:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10856 osp_idx=23 osp_ver=74303 osp_pg=0 (spawn #145347) 2025-05-03 22:05:05.402309 :924CA574:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:05:05.402310 :924CA575:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=52 time=3580682562 2025-05-03 22:05:05.402310 :924CA576:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:05:05.402310 :924CA577:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:05:05.402311 :924CA578:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:05:05.402311 :924CA579:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:05:05.402311 :924CA57A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:05:05.402792 :924CA57B: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-05-03 22:05:10.406748 :924CA759: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-05-03 22:05:40.493300 :924CB7DD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:06:10.520460 :924CC1C4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:06:10.509 2025-05-03 22:06:10.520462 :924CC1C5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8700 pso_num=25 pso_serial#=100 2025-05-03 22:06:10.520594 :924CC1C6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8700 osp_idx=23 osp_ver=74304 osp_pg=0 (spawn #145349) 2025-05-03 22:06:10.520595 :924CC1C7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:06:10.520595 :924CC1C8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=53 time=3580747687 2025-05-03 22:06:10.520595 :924CC1C9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:06:10.520596 :924CC1CA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:06:10.520596 :924CC1CB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:06:10.520596 :924CC1CC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:06:10.520597 :924CC1CD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:06:10.521089 :924CC1CE: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-05-03 22:06:40.621655 :924CCFB2:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:07:10.608429 :924CD9DE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:07:10.597 2025-05-03 22:07:10.608431 :924CD9DF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11616 pso_num=25 pso_serial#=101 2025-05-03 22:07:10.608561 :924CD9E0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11616 osp_idx=23 osp_ver=74305 osp_pg=0 (spawn #145351) 2025-05-03 22:07:10.608562 :924CD9E1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:07:10.608563 :924CD9E2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=54 time=3580807765 2025-05-03 22:07:10.608563 :924CD9E3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:07:10.608563 :924CD9E4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:07:10.608564 :924CD9E5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:07:10.608564 :924CD9E6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:07:10.608564 :924CD9E7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:07:10.609040 :924CD9E8: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-05-03 22:07:40.705542 :924CE400:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:08:10.717078 :924CEE22:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:08:10.706 2025-05-03 22:08:10.717081 :924CEE23:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8260 pso_num=25 pso_serial#=102 2025-05-03 22:08:10.717206 :924CEE24:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8260 osp_idx=23 osp_ver=74306 osp_pg=0 (spawn #145353) 2025-05-03 22:08:10.717207 :924CEE25:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:08:10.717207 :924CEE26:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=55 time=3580867875 2025-05-03 22:08:10.717207 :924CEE27:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:08:10.717208 :924CEE28:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:08:10.717208 :924CEE29:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:08:10.717208 :924CEE2A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:08:10.717209 :924CEE2B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:08:10.717720 :924CEE2C: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-05-03 22:08:40.822273 :924CF871:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-03 22:09:10.809620 :924D026C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-03 22:09:10.799 2025-05-03 22:09:10.809621 :924D026D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11512 pso_num=25 pso_serial#=103 2025-05-03 22:09:10.809752 :924D026E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11512 osp_idx=23 osp_ver=74307 osp_pg=0 (spawn #145355) 2025-05-03 22:09:10.809753 :924D026F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-03 22:09:10.809753 :924D0270:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=56 time=3580927968 2025-05-03 22:09:10.809754 :924D0271:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-03 22:09:10.809754 :924D0272:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-03 22:09:10.809755 :924D0273:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-03 22:09:10.809755 :924D0274:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-03 22:09:10.809755 :924D0275:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-03 22:09:10.810229 :924D0276: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-05-03 22:09:22.910009 :924D080C: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-05-03 22:09:23.005779 :924D08BB: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-05-03 22:09:23.005779*:924D08CA:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DDC718 estart=1746281362 eid=16779760 ctx=0x000000077FD6A000 cwh=0x0000000024DD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-03 22:09:23.005779*:924D08CB:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 pubTabIdxCnt=0 2025-05-03 22:09:23.005779*:924D08CC:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DDC718 2025-05-03 22:09:23.005779*:924D08CD:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DDC718 2025-05-03 22:09:23.005779*:924D08D0:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 xsc->flg4=65792 flags=2 2025-05-03 22:09:23.005779*:924D08D1:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DDC718 2025-05-03 22:09:23.011016 :924D08DA: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-05-03 22:09:23.011057 :924D08DD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-03 22:09:23.015261 :924D08ED: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-05-03 22:09:23.121724 :924D08F5: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-05-03 22:09:23.249384 :924D092B: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-05-03 22:09:23.375031 :924D0933: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-05-03 22:09:24.497393 :924D0982: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-05-03 22:09:24.498394 :924D098A: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-05-03 22:09:24.500126 :924D0992: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-05-03 22:09:24.501689 :924D099A: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-05-03 22:09:24.504935 :924D09A2: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-05-03 22:09:24.507539 :924D09AA: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-05-03 22:09:24.522366 :924D09B2: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-05-03 22:09:24.523051 :924D09BA: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-05-03 22:09:24.523564 :924D09C2: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-05-03 22:09:24.524074 :924D09CA: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-05-03 22:09:24.526810 :924D09D2: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-05-03 22:09:24.527778 :924D09DA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.528574 :924D09DB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.529355 :924D09DC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.529766 :924D09DD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.529772 :924D09DE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.530309 :924D09DF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.530871 :924D09E0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.531173 :924D09E1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.532270 :924D09E2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.560005 :924D09EF: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-05-03 22:09:24.560057 :924D09F2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.560935 :924D09F8: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-05-03 22:09:24.561855 :924D0A00:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.562271 :924D0A01: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-05-03 22:09:24.580777 :924D0A09: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-05-03 22:09:24.580825 :924D0A0C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.581635 :924D0A12: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-05-03 22:09:24.582449 :924D0A1A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.582860 :924D0A1B: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-05-03 22:09:24.603464 :924D0A23: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-05-03 22:09:24.603514 :924D0A26:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.604311 :924D0A2C: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-05-03 22:09:24.615343 :924D0A34:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.615815 :924D0A35: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-05-03 22:09:24.636536 :924D0A3D: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-05-03 22:09:24.636586 :924D0A40:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.637417 :924D0A46: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-05-03 22:09:24.638363 :924D0A50:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-05-03 22:09:24.638911 :924D0A59:db_trace:ktu.c@4871:ktuaex1r(): [10442:25:201] Extension usn 9, ext 1, nex 3 2025-05-03 22:09:24.638918 :924D0A5A:db_trace:ktusm.c@2117:ktusmasp(): [10445:25:201] des1:tsn:3 rdba:0x00400c01 where: kddwh01: kdddel 2025-05-03 22:09:24.639281 :924D0A5B: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-05-03 22:09:24.661637 :924D0A77: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-05-03 22:09:24.661674 :924D0A78:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-05-03 22:09:24.662465 :924D0A92: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-05-03 22:09:24.662923 :924D0A9A: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-05-03 22:09:24.663285 :924D0AA2: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-05-03 22:09:24.663461 :924D0AAA: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-05-03 22:09:24.663603 :924D0AB2: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-05-03 22:09:24.663745 :924D0ABD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-03 22:09:24.667723 :924D0ACB: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-05-03 22:09:24.667806 :924D0ACE: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-05-03 22:09:24.667883 :924D0ADB: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 11512, J001)