Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250730220008\orcl_j001_4196_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:35897M/63366M, Ph+PgF:41601M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 4196, image: ORACLE.EXE (J001) *** 2025-07-30 22:00:08.232 *** SESSION ID:(201.32073) 2025-07-30 22:00:08.232 *** 2025-07-30 22:00:08.232 Process diagnostic dump for ORACLE.EXE (J001), OS id=4196, pid: 25, proc_ser: 126, sid: 201, sess_ser: 32073 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 4196 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=0.210445 sec, exc=0.210445 sec, total=0.210445 sec wait times: max=0.500000 sec, heur=7.809233 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000010 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 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.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.510098 sec, exc=0.510098 sec, total=0.510098 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=13 seq_num=14 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.499954 sec, exc=0.499954 sec, total=0.499954 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000019 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.500026 sec, exc=0.500026 sec, total=0.500026 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 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.000011 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.509322 sec, exc=0.509322 sec, total=0.509322 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.078899 sec, exc=0.078899 sec, total=0.078899 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.500012 sec, exc=0.500012 sec, total=0.500012 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time Sampled Session History of session 201 serial 32073 --------------------------------------------------- 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 --------------------------------------------------- [8 samples, 22:00:00 - 22:00:08] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-30 22:00:08.232 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 4196, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-30 21:46:39.263493 :B9295DE9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:46:39.263494 :B9295DEA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:46:39.263494 :B9295DEB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:46:39.263494 :B9295DEC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:46:39.264042 :B9295DED: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-30 21:47:09.333788 :B929678D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:47:39.318053 :B9297193:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:47:39.307 2025-07-30 21:47:39.318056 :B9297194:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19132 pso_num=25 pso_serial#=114 2025-07-30 21:47:39.318193 :B9297195:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19132 osp_idx=23 osp_ver=222076 osp_pg=0 (spawn #439129) 2025-07-30 21:47:39.318194 :B9297196: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-30 21:47:39.318194 :B9297197:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=133 time=2592835204 2025-07-30 21:47:39.318195 :B9297198:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:47:39.318195 :B9297199:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:47:39.318197 :B929719A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:47:39.318197 :B929719B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:47:39.318197 :B929719C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:47:39.318684 :B929719D: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-30 21:48:04.332974 :B9297A91: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-30 21:48:34.425561 :B9298453:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:48:39.375438 :B92985E4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:48:39.364 2025-07-30 21:48:39.375440 :B92985E5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14016 pso_num=25 pso_serial#=115 2025-07-30 21:48:39.375568 :B92985E6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14016 osp_idx=23 osp_ver=222077 osp_pg=0 (spawn #439131) 2025-07-30 21:48:39.375569 :B92985E7: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-30 21:48:39.375569 :B92985E8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=134 time=2592895267 2025-07-30 21:48:39.375570 :B92985E9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:48:39.375570 :B92985EA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:48:39.375571 :B92985EB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:48:39.375571 :B92985EC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:48:39.375571 :B92985ED:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:48:39.376062 :B92985EE: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-30 21:49:09.422849 :B9298FCC:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:49:39.434878 :B929998D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:49:39.423 2025-07-30 21:49:39.434880 :B929998E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19892 pso_num=25 pso_serial#=116 2025-07-30 21:49:39.435003 :B929998F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19892 osp_idx=23 osp_ver=222078 osp_pg=0 (spawn #439133) 2025-07-30 21:49:39.435004 :B9299990: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-30 21:49:39.435004 :B9299991:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=135 time=2592955329 2025-07-30 21:49:39.435005 :B9299992:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:49:39.435005 :B9299993:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:49:39.435005 :B9299994:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:49:39.435006 :B9299995:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:49:39.435006 :B9299996:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:49:39.435488 :B9299997: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-30 21:50:09.491349 :B929A393:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:50:39.510919 :B929AD53:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:50:39.500 2025-07-30 21:50:39.510921 :B929AD54:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=1020 pso_num=25 pso_serial#=117 2025-07-30 21:50:39.511046 :B929AD55:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=1020 osp_idx=23 osp_ver=222079 osp_pg=0 (spawn #439135) 2025-07-30 21:50:39.511047 :B929AD56: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-30 21:50:39.511047 :B929AD57:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=136 time=2593015392 2025-07-30 21:50:39.511048 :B929AD58:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:50:39.511048 :B929AD59:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:50:39.511049 :B929AD5A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:50:39.511049 :B929AD5B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:50:39.511050 :B929AD5C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:50:39.511521 :B929AD5D: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-30 21:51:09.581544 :B929B784:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:51:39.582098 :B929C183:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:51:39.575 2025-07-30 21:51:39.582100 :B929C184:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18392 pso_num=25 pso_serial#=118 2025-07-30 21:51:39.582223 :B929C185:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18392 osp_idx=23 osp_ver=222080 osp_pg=0 (spawn #439138) 2025-07-30 21:51:39.582224 :B929C186: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-30 21:51:39.582224 :B929C187:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=137 time=2593075470 2025-07-30 21:51:39.582224 :B929C188:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:51:39.582225 :B929C189:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:51:39.582225 :B929C18A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:51:39.582225 :B929C18B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:51:39.582226 :B929C18C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:51:39.582719 :B929C18D: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-30 21:52:09.660297 :B929CB8C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:52:39.668576 :B929D580:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:52:39.657 2025-07-30 21:52:39.668578 :B929D581:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19644 pso_num=25 pso_serial#=119 2025-07-30 21:52:39.668707 :B929D582:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19644 osp_idx=23 osp_ver=222081 osp_pg=0 (spawn #439140) 2025-07-30 21:52:39.668708 :B929D583: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-30 21:52:39.668708 :B929D584:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=138 time=2593135564 2025-07-30 21:52:39.668709 :B929D585:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:52:39.668709 :B929D586:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:52:39.668709 :B929D587:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:52:39.668710 :B929D588:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:52:39.668710 :B929D589:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:52:39.669186 :B929D58A: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-30 21:53:09.701025 :B929E029:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:53:39.741448 :B929EA41:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:53:39.729 2025-07-30 21:53:39.741450 :B929EA42:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19608 pso_num=25 pso_serial#=120 2025-07-30 21:53:39.741572 :B929EA43:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19608 osp_idx=23 osp_ver=222082 osp_pg=0 (spawn #439143) 2025-07-30 21:53:39.741573 :B929EA44: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-30 21:53:39.741573 :B929EA45:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=139 time=2593195626 2025-07-30 21:53:39.741574 :B929EA46:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:53:39.741574 :B929EA47:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:53:39.741574 :B929EA48:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:53:39.741575 :B929EA49:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:53:39.741575 :B929EA4A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:53:39.742080 :B929EA4B: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-30 21:54:09.804410 :B929F477:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:54:39.832726 :B929FE60:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:54:39.821 2025-07-30 21:54:39.832728 :B929FE61:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18360 pso_num=25 pso_serial#=121 2025-07-30 21:54:39.832849 :B929FE62:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18360 osp_idx=23 osp_ver=222083 osp_pg=0 (spawn #439145) 2025-07-30 21:54:39.832849 :B929FE63: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-30 21:54:39.832850 :B929FE64:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=140 time=2593255720 2025-07-30 21:54:39.832850 :B929FE65:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:54:39.832851 :B929FE66:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:54:39.832851 :B929FE67:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:54:39.832852 :B929FE68:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:54:39.832852 :B929FE69:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:54:39.833335 :B929FE6A: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-30 21:55:09.925431 :B92A0842:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:55:39.912913 :B92A1213:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:55:39.901 2025-07-30 21:55:39.912914 :B92A1214:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=6744 pso_num=25 pso_serial#=122 2025-07-30 21:55:39.913051 :B92A1215:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=6744 osp_idx=23 osp_ver=222084 osp_pg=0 (spawn #439147) 2025-07-30 21:55:39.913052 :B92A1216: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-30 21:55:39.913053 :B92A1217:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=141 time=2593315798 2025-07-30 21:55:39.913053 :B92A1218:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:55:39.913053 :B92A1219:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:55:39.913054 :B92A121A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:55:39.913054 :B92A121B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:55:39.913055 :B92A121C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:55:39.913580 :B92A121D: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-30 21:56:09.997228 :B92A1C3C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:56:39.999859 :B92A266C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:56:39.989 2025-07-30 21:56:39.999862 :B92A266D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19228 pso_num=25 pso_serial#=123 2025-07-30 21:56:39.999994 :B92A266E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19228 osp_idx=23 osp_ver=222085 osp_pg=0 (spawn #439150) 2025-07-30 21:56:39.999995 :B92A266F: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-30 21:56:39.999995 :B92A2670:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=142 time=2593375892 2025-07-30 21:56:39.999995 :B92A2671:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:56:39.999996 :B92A2672:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:56:39.999996 :B92A2673:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:56:39.999997 :B92A2674:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:56:39.999997 :B92A2675:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:56:40.000472 :B92A2676: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-30 21:57:10.055090 :B92A3058:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:57:40.105754 :B92A3AE3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:57:40.095 2025-07-30 21:57:40.105756 :B92A3AE4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=20172 pso_num=25 pso_serial#=124 2025-07-30 21:57:40.105878 :B92A3AE5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=20172 osp_idx=23 osp_ver=222086 osp_pg=0 (spawn #439152) 2025-07-30 21:57:40.105879 :B92A3AE6: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-30 21:57:40.105880 :B92A3AE7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=143 time=2593436001 2025-07-30 21:57:40.105880 :B92A3AE8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:57:40.105881 :B92A3AE9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:57:40.105881 :B92A3AEA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:57:40.105881 :B92A3AEB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:57:40.105882 :B92A3AEC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:57:40.106370 :B92A3AED: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-30 21:58:05.129540 :B92A443C: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-30 21:58:35.222254 :B92A4DF3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:58:40.206313 :B92A4F7C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:58:40.194 2025-07-30 21:58:40.206315 :B92A4F7D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19900 pso_num=25 pso_serial#=125 2025-07-30 21:58:40.206446 :B92A4F7E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19900 osp_idx=23 osp_ver=222087 osp_pg=0 (spawn #439154) 2025-07-30 21:58:40.206447 :B92A4F7F: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-30 21:58:40.206447 :B92A4F80:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=144 time=2593496095 2025-07-30 21:58:40.206448 :B92A4F81:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:58:40.206448 :B92A4F82:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:58:40.206449 :B92A4F83:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:58:40.206450 :B92A4F84:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:58:40.206450 :B92A4F85:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:58:40.207003 :B92A4F86: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-30 21:59:10.316146 :B92A593E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-30 21:59:40.288178 :B92A6312:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-30 21:59:40.277 2025-07-30 21:59:40.288180 :B92A6313:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4196 pso_num=25 pso_serial#=126 2025-07-30 21:59:40.288366 :B92A6314:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4196 osp_idx=23 osp_ver=222088 osp_pg=0 (spawn #439156) 2025-07-30 21:59:40.288366 :B92A6315: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-30 21:59:40.288367 :B92A6316:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=145 time=2593556173 2025-07-30 21:59:40.288367 :B92A6317:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-30 21:59:40.288368 :B92A6318:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-30 21:59:40.288368 :B92A6319:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-30 21:59:40.288368 :B92A631A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-30 21:59:40.288368 :B92A631B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-30 21:59:40.288871 :B92A631C: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-30 22:00:00.296486 :B92A6B5C: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-30 22:00:00.296486*:B92A6B7F:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEC718 estart=1753883999 eid=16785164 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-30 22:00:00.296486*:B92A6B80:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 pubTabIdxCnt=0 2025-07-30 22:00:00.296486*:B92A6B81:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEC718 2025-07-30 22:00:00.296486*:B92A6B82:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEC718 2025-07-30 22:00:00.296486*:B92A6B88:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 xsc->flg4=65792 flags=2 2025-07-30 22:00:00.296486*:B92A6B89:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEC718 2025-07-30 22:00:00.303272 :B92A6B9F: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-30 22:00:00.303325 :B92A6BA2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-30 22:00:00.315100 :B92A6C02: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-30 22:00:00.320393 :B92A6D43: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-30 22:00:00.321136 :B92A6D55: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-30 22:00:00.326965 :B92A6D65: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-07-30 22:00:00.327124 :B92A6D74: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-07-30 22:00:00.327932 :B92A6D7D: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-30 22:00:00.328124 :B92A6D85:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-30 22:00:00.329339 :B92A6D89: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-30 22:00:00.329428 :B92A6D9F: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-30 22:00:00.421326 :B92A6E44: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-30 22:00:00.423445 :B92A6E49: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-30 22:00:00.423481 :B92A6E4C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-30 22:00:00.425951 :B92A6E52:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-30 22:00:00.429368 :B92A6E53: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-30 22:00:00.429443 :B92A6E56: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-30 22:00:00.429523 :B92A6E63: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-30 22:00:04.008998 :B92A738D: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 4196, J001)