Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250528220008\orcl_j001_12276_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:37283M/63366M, Ph+PgF:44240M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 12276, image: ORACLE.EXE (J001) *** 2025-05-28 22:00:08.578 *** SESSION ID:(201.11735) 2025-05-28 22:00:08.578 *** 2025-05-28 22:00:08.578 Process diagnostic dump for ORACLE.EXE (J001), OS id=12276, pid: 25, proc_ser: 19, sid: 201, sess_ser: 11735 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12276 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.338506 sec, exc=0.338506 sec, total=0.338506 sec wait times: max=0.500000 sec, heur=4.336295 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.000008 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.500016 sec, exc=0.500016 sec, total=0.500016 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.500000 sec, exc=0.500000 sec, total=0.500000 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 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 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 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 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.510116 sec, exc=0.510116 sec, total=0.510116 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 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=0 seq_num=1 snap_id=1 wait times: snap=0.487607 sec, exc=0.487607 sec, total=0.487607 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 11735 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [5 samples, 22:00:04 - 22:00:08] idle wait at each sample [session created at: 22:00:04] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-28 22:00:08.578 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 12276, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-28 21:48:39.322645 :9D490455:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13500 pso_num=25 pso_serial#=8 2025-05-28 21:48:39.322773 :9D490456:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13500 osp_idx=23 osp_ver=123540 osp_pg=0 (spawn #229111) 2025-05-28 21:48:39.322773 :9D490457: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-28 21:48:39.322774 :9D490458:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=134 time=1444691563 2025-05-28 21:48:39.322774 :9D490459:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:48:39.322775 :9D49045A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:48:39.322775 :9D49045B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:48:39.322776 :9D49045C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:48:39.322776 :9D49045D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:48:39.323262 :9D49045E: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-28 21:49:09.370290 :9D490DEC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:49:39.393737 :9D49175E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:49:39.383 2025-05-28 21:49:39.393739 :9D49175F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7792 pso_num=25 pso_serial#=9 2025-05-28 21:49:39.393873 :9D491760:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7792 osp_idx=23 osp_ver=123541 osp_pg=0 (spawn #229113) 2025-05-28 21:49:39.393873 :9D491761: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-28 21:49:39.393874 :9D491762:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=135 time=1444751641 2025-05-28 21:49:39.393874 :9D491763:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:49:39.393874 :9D491764:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:49:39.393875 :9D491765:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:49:39.393875 :9D491766:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:49:39.393875 :9D491767:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:49:39.394349 :9D491768: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-28 21:50:09.458397 :9D4920E1:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:50:39.499848 :9D492A54:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:50:39.488 2025-05-28 21:50:39.499850 :9D492A55:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15032 pso_num=25 pso_serial#=10 2025-05-28 21:50:39.499971 :9D492A56:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15032 osp_idx=23 osp_ver=123542 osp_pg=0 (spawn #229115) 2025-05-28 21:50:39.499972 :9D492A57: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-28 21:50:39.499972 :9D492A58:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=136 time=1444811750 2025-05-28 21:50:39.499973 :9D492A59:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:50:39.499973 :9D492A5A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:50:39.499973 :9D492A5B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:50:39.499974 :9D492A5C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:50:39.499974 :9D492A5D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:50:39.500467 :9D492A5E: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-28 21:51:09.544159 :9D4934C9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:51:39.598588 :9D493E79:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:51:39.587 2025-05-28 21:51:39.598590 :9D493E7A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12360 pso_num=25 pso_serial#=11 2025-05-28 21:51:39.598742 :9D493E7B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12360 osp_idx=23 osp_ver=123543 osp_pg=0 (spawn #229117) 2025-05-28 21:51:39.598743 :9D493E7C: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-28 21:51:39.598743 :9D493E7D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=137 time=1444871844 2025-05-28 21:51:39.598743 :9D493E7E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:51:39.598744 :9D493E7F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:51:39.598744 :9D493E80:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:51:39.598745 :9D493E81:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:51:39.598745 :9D493E82:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:51:39.599220 :9D493E83: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-28 21:52:09.676180 :9D49480A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:52:14.670982 :9D494A00:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:52:14.659 2025-05-28 21:52:14.670984 :9D494A01:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=3836 pso_num=25 pso_serial#=12 2025-05-28 21:52:14.671147 :9D494A02:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=3836 osp_idx=23 osp_ver=123544 osp_pg=0 (spawn #229119) 2025-05-28 21:52:14.671148 :9D494A03: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-28 21:52:14.671148 :9D494A04:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=138 time=1444906922 2025-05-28 21:52:14.671148 :9D494A05:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:52:14.671149 :9D494A06:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:52:14.671149 :9D494A07:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:52:14.671150 :9D494A08:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:52:14.671150 :9D494A09:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:52:14.671631 :9D494A0A: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-28 21:52:39.684724 :9D4951DE: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-28 21:53:09.781887 :9D495B4B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:53:39.810627 :9D496502:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:53:39.799 2025-05-28 21:53:39.810629 :9D496503:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10584 pso_num=25 pso_serial#=13 2025-05-28 21:53:39.810768 :9D496504:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10584 osp_idx=23 osp_ver=123545 osp_pg=0 (spawn #229121) 2025-05-28 21:53:39.810769 :9D496505: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-28 21:53:39.810769 :9D496506:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=139 time=1444992063 2025-05-28 21:53:39.810770 :9D496507:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:53:39.810770 :9D496508:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:53:39.810771 :9D496509:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:53:39.810771 :9D49650A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:53:39.810771 :9D49650B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:53:39.811281 :9D49650C: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-28 21:54:09.940309 :9D496F0C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:54:39.907446 :9D49789B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:54:39.896 2025-05-28 21:54:39.907448 :9D49789C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14408 pso_num=25 pso_serial#=14 2025-05-28 21:54:39.907585 :9D49789D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14408 osp_idx=23 osp_ver=123546 osp_pg=0 (spawn #229123) 2025-05-28 21:54:39.907586 :9D49789E: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-28 21:54:39.907586 :9D49789F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=140 time=1445052157 2025-05-28 21:54:39.907586 :9D4978A0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:54:39.907587 :9D4978A1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:54:39.907587 :9D4978A2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:54:39.907588 :9D4978A3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:54:39.907588 :9D4978A4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:54:39.908062 :9D4978A5: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-28 21:55:09.990085 :9D498283:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:55:39.996046 :9D498BC9:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:55:39.985 2025-05-28 21:55:39.996048 :9D498BCA:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12732 pso_num=25 pso_serial#=15 2025-05-28 21:55:39.996180 :9D498BCB:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12732 osp_idx=23 osp_ver=123547 osp_pg=0 (spawn #229127) 2025-05-28 21:55:39.996181 :9D498BCC: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-28 21:55:39.996181 :9D498BCD:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=141 time=1445112250 2025-05-28 21:55:39.996181 :9D498BCE:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:55:39.996182 :9D498BCF:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:55:39.996182 :9D498BD0:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:55:39.996183 :9D498BD1:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:55:39.996183 :9D498BD2:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:55:39.996671 :9D498BD3: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-28 21:56:10.077003 :9D49958B:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:56:40.103577 :9D499F1E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:56:40.092 2025-05-28 21:56:40.103579 :9D499F1F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13640 pso_num=25 pso_serial#=16 2025-05-28 21:56:40.103723 :9D499F20:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13640 osp_idx=23 osp_ver=123548 osp_pg=0 (spawn #229129) 2025-05-28 21:56:40.103723 :9D499F21: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-28 21:56:40.103724 :9D499F22:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=142 time=1445172344 2025-05-28 21:56:40.103724 :9D499F23:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:56:40.103725 :9D499F24:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:56:40.103725 :9D499F25:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:56:40.103726 :9D499F26:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:56:40.103726 :9D499F27:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:56:40.104232 :9D499F28: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-28 21:57:10.182757 :9D49A8BD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:57:40.190605 :9D49B272:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:57:40.179 2025-05-28 21:57:40.190607 :9D49B273:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15312 pso_num=25 pso_serial#=17 2025-05-28 21:57:40.190739 :9D49B274:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15312 osp_idx=23 osp_ver=123549 osp_pg=0 (spawn #229131) 2025-05-28 21:57:40.190740 :9D49B275: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-28 21:57:40.190740 :9D49B276:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=143 time=1445232438 2025-05-28 21:57:40.190741 :9D49B277:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:57:40.190741 :9D49B278:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:57:40.190742 :9D49B279:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:57:40.190742 :9D49B27A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:57:40.190742 :9D49B27B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:57:40.191288 :9D49B27C: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-28 21:58:10.306136 :9D49BBFF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:58:40.285323 :9D49C52A:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:58:40.274 2025-05-28 21:58:40.285324 :9D49C52B:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=11732 pso_num=25 pso_serial#=18 2025-05-28 21:58:40.285465 :9D49C52C:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=11732 osp_idx=23 osp_ver=123550 osp_pg=0 (spawn #229133) 2025-05-28 21:58:40.285465 :9D49C52D: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-28 21:58:40.285466 :9D49C52E:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=144 time=1445292532 2025-05-28 21:58:40.285466 :9D49C52F:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:58:40.285466 :9D49C530:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:58:40.285467 :9D49C531:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:58:40.285467 :9D49C532:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:58:40.285467 :9D49C533:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:58:40.285948 :9D49C534: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-28 21:59:10.374570 :9D49CEC3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-05-28 21:59:40.355662 :9D49D89F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 05-28 21:59:40.344 2025-05-28 21:59:40.355664 :9D49D8A0:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12276 pso_num=25 pso_serial#=19 2025-05-28 21:59:40.355807 :9D49D8A1:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12276 osp_idx=23 osp_ver=123551 osp_pg=0 (spawn #229135) 2025-05-28 21:59:40.355808 :9D49D8A2: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-28 21:59:40.355808 :9D49D8A3:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=145 time=1445352610 2025-05-28 21:59:40.355808 :9D49D8A4:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-05-28 21:59:40.355809 :9D49D8A5:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-05-28 21:59:40.355809 :9D49D8A6:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-05-28 21:59:40.355809 :9D49D8A7:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-28 21:59:40.355810 :9D49D8A8:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-28 21:59:40.356295 :9D49D8A9: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-28 22:00:00.398060 :9D49E08F: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-28 22:00:00.398060*:9D49E09E:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DDC718 estart=1748440799 eid=16781289 ctx=0x000000077FD6A000 cwh=0x0000000024DD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-28 22:00:00.398060*:9D49E09F:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 pubTabIdxCnt=0 2025-05-28 22:00:00.398060*:9D49E0A0:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DDC718 2025-05-28 22:00:00.398060*:9D49E0A1:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DDC718 2025-05-28 22:00:00.398060*:9D49E0A4:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 xsc->flg4=65792 flags=2 2025-05-28 22:00:00.398060*:9D49E0A5:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DDC718 2025-05-28 22:00:00.403781 :9D49E0C7: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-28 22:00:00.403826 :9D49E0CA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-28 22:00:00.413879 :9D49E10B: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-28 22:00:00.415967 :9D49E13B: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-28 22:00:00.421191 :9D49E158: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-28 22:00:00.422049 :9D49E197: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-28 22:00:00.428064 :9D49E2DE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-28 22:00:00.428217 :9D49E2ED:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-28 22:00:00.429016 :9D49E2F5: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-28 22:00:00.429206 :9D49E2FD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-28 22:00:00.430865 :9D49E2FE: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-28 22:00:00.430918 :9D49E301: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-28 22:00:00.431017 :9D49E30E: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-05-28 22:00:00.522767 :9D49E402: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-28 22:00:00.524837 :9D49E404: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-28 22:00:00.524873 :9D49E407:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-28 22:00:00.527344 :9D49E40D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-28 22:00:00.531078 :9D49E40E: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-28 22:00:00.531156 :9D49E411: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-28 22:00:00.531247 :9D49E41E: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-05-28 22:00:04.006381 :9D49E8D8: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-28 22:00:04.006381*:9D49E8E0:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024DDC718 estart=1748440803 eid=16781295 ctx=0x000000077FD6A000 cwh=0x0000000024DD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-28 22:00:04.006381*:9D49E8E1:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 pubTabIdxCnt=0 2025-05-28 22:00:04.006381*:9D49E8E2:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024DDC718 2025-05-28 22:00:04.006381*:9D49E8E3:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024DDC718 2025-05-28 22:00:04.006381*:9D49E8E4:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024DDC718 curCtx=0x0000000024DD8938 xsc->flg4=65792 flags=2 2025-05-28 22:00:04.006381*:9D49E8E5:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024DDC718 2025-05-28 22:00:04.008609 :9D49E8E6: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-28 22:00:04.008653 :9D49E8E9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-05-28 22:00:04.015278 :9D49E8EF: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-28 22:00:04.016003 :9D49E8F7: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-28 22:00:04.016765 :9D49E8FF: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-28 22:00:04.016953 :9D49E907:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-05-28 22:00:04.250013 :9D49E928:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=24 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-28 22:00:04.250390 :9D49E92C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=24 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-05-28 22:00:04.251209 :9D49E93D: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-28 22:00:04.251252 :9D49E940: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-28 22:00:04.251315 :9D49E94D: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: 12276, J001)