Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250705220911\orcl_j001_13928_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:37334M/63366M, Ph+PgF:43346M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 13928, image: ORACLE.EXE (J001) *** 2025-07-05 22:09:11.264 *** SESSION ID:(209.24181) 2025-07-05 22:09:11.264 *** 2025-07-05 22:09:11.264 Process diagnostic dump for ORACLE.EXE (J001), OS id=13928, pid: 26, proc_ser: 101, sid: 209, sess_ser: 24181 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 13928 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.120739 sec, exc=0.120739 sec, total=0.120739 sec wait times: max=0.500000 sec, heur=5.129193 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.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 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.000013 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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.000007 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.510729 sec, exc=0.510729 sec, total=0.510729 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 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.000008 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 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.000008 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.510112 sec, exc=0.510112 sec, total=0.510112 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=3 seq_num=4 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.000010 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 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.000012 sec of elapsed time 8: 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.000011 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.487536 sec, exc=0.487536 sec, total=0.487536 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 209 serial 24181 --------------------------------------------------- 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 --------------------------------------------------- [6 samples, 22:09:06 - 22:09:11] idle wait at each sample [session created at: 22:09:06] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-05 22:09:11.264 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 13928, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-05 22:00:40.703839 :AE0785BA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.704272 :AE0785C2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.706795 :AE0785CA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.707981 :AE0785D2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.757758 :AE0785E5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.759227 :AE0785ED:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.760175 :AE0785F5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.760418 :AE0785FD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.760670 :AE078605:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:00:40.762555 :AE07860D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:00:59.431237 :AE078C42:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:00:59.418 2025-07-05 22:00:59.431238 :AE078C43:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=4296 pso_num=26 pso_serial#=93 2025-07-05 22:00:59.431373 :AE078C49:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=4296 osp_idx=24 osp_ver=567468 osp_pg=0 (spawn #355832) 2025-07-05 22:00:59.431374 :AE078C4A:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:00:59.431374 :AE078C4B:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=39 time=433635314 2025-07-05 22:00:59.431374 :AE078C4C:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:00:59.431375 :AE078C4D:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:00:59.431375 :AE078C4E:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:00:59.431376 :AE078C4F:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:00:59.431376 :AE078C50:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:00:59.431919 :AE078C51:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:01:29.509702 :AE079748:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:01:59.500086 :AE07A153:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:01:59.488 2025-07-05 22:01:59.500088 :AE07A154:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12004 pso_num=26 pso_serial#=94 2025-07-05 22:01:59.500202 :AE07A155:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12004 osp_idx=24 osp_ver=567469 osp_pg=0 (spawn #355834) 2025-07-05 22:01:59.500203 :AE07A156:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:01:59.500203 :AE07A157:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=40 time=433695392 2025-07-05 22:01:59.500204 :AE07A158:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:01:59.500204 :AE07A159:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:01:59.500204 :AE07A15A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:01:59.500205 :AE07A15B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:01:59.500205 :AE07A15C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:01:59.500831 :AE07A15D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:02:29.580155 :AE07AB78:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:02:59.602517 :AE07B5AD:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:02:59.590 2025-07-05 22:02:59.602519 :AE07B5AE:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=4640 pso_num=26 pso_serial#=95 2025-07-05 22:02:59.602640 :AE07B5AF:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=4640 osp_idx=24 osp_ver=567470 osp_pg=0 (spawn #355836) 2025-07-05 22:02:59.602641 :AE07B5B0:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:02:59.602641 :AE07B5B1:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=41 time=433755486 2025-07-05 22:02:59.602642 :AE07B5B2:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:02:59.602642 :AE07B5B3:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:02:59.602643 :AE07B5B4:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:02:59.602643 :AE07B5B5:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:02:59.602643 :AE07B5B6:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:02:59.603636 :AE07B5B7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:03:24.609183 :AE07BF54:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05 22:03:54.717945 :AE07C970:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:03:59.666684 :AE07CB53:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:03:59.654 2025-07-05 22:03:59.666686 :AE07CB54:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12568 pso_num=26 pso_serial#=96 2025-07-05 22:03:59.666798 :AE07CB55:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12568 osp_idx=24 osp_ver=567471 osp_pg=0 (spawn #355839) 2025-07-05 22:03:59.666799 :AE07CB56:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:03:59.666800 :AE07CB57:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=42 time=433815548 2025-07-05 22:03:59.666800 :AE07CB58:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:03:59.666801 :AE07CB59:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:03:59.666801 :AE07CB5A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:03:59.666802 :AE07CB5B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:03:59.666802 :AE07CB5C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:03:59.667367 :AE07CB5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:04:29.735806 :AE07D574:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:04:59.784955 :AE07DF8E:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:04:59.772 2025-07-05 22:04:59.784957 :AE07DF8F:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=16340 pso_num=26 pso_serial#=97 2025-07-05 22:04:59.785088 :AE07DF90:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=16340 osp_idx=24 osp_ver=567472 osp_pg=0 (spawn #355842) 2025-07-05 22:04:59.785088 :AE07DF91:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:04:59.785089 :AE07DF92:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=43 time=433875673 2025-07-05 22:04:59.785089 :AE07DF93:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:04:59.785089 :AE07DF94:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:04:59.785090 :AE07DF95:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:04:59.785090 :AE07DF96:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:04:59.785090 :AE07DF97:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:04:59.786115 :AE07DF98:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:05:29.863772 :AE07E9EE:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:05:59.885958 :AE07F926:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:05:59.874 2025-07-05 22:05:59.885960 :AE07F927:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14556 pso_num=26 pso_serial#=98 2025-07-05 22:05:59.886084 :AE07F928:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14556 osp_idx=24 osp_ver=567473 osp_pg=0 (spawn #355844) 2025-07-05 22:05:59.886085 :AE07F929:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:05:59.886085 :AE07F92A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=44 time=433935767 2025-07-05 22:05:59.886086 :AE07F92B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:05:59.886086 :AE07F92C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:05:59.886086 :AE07F92D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:05:59.886087 :AE07F92E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:05:59.886087 :AE07F92F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:05:59.886767 :AE07F930:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:06:29.959579 :AE08053C:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:06:59.957899 :AE080F86:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:06:59.946 2025-07-05 22:06:59.957900 :AE080F87:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=4488 pso_num=26 pso_serial#=99 2025-07-05 22:06:59.958021 :AE080F88:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=4488 osp_idx=24 osp_ver=567474 osp_pg=0 (spawn #355847) 2025-07-05 22:06:59.958021 :AE080F89:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:06:59.958022 :AE080F8A:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=45 time=433995845 2025-07-05 22:06:59.958022 :AE080F8B:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:06:59.958023 :AE080F8C:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:06:59.958023 :AE080F8D:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:06:59.958023 :AE080F8E:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:06:59.958024 :AE080F8F:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:06:59.958598 :AE080F90:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:07:30.057475 :AE086A89:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:08:00.003743 :AE0874A8:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:07:59.993 2025-07-05 22:08:00.003745 :AE0874A9:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=6600 pso_num=26 pso_serial#=100 2025-07-05 22:08:00.003876 :AE0874AA:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=6600 osp_idx=24 osp_ver=567475 osp_pg=0 (spawn #355854) 2025-07-05 22:08:00.003876 :AE0874AB:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:08:00.003877 :AE0874AC:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=46 time=434055892 2025-07-05 22:08:00.003878 :AE0874AD:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:08:00.003878 :AE0874AE:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:08:00.003879 :AE0874AF:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:08:00.003879 :AE0874B0:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:08:00.003879 :AE0874B1:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:08:00.004420 :AE0874B2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:08:30.089890 :AE087EAB:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-07-05 22:09:00.098723 :AE0888D1:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 07-05 22:09:00.087 2025-07-05 22:09:00.098725 :AE0888D2:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13928 pso_num=26 pso_serial#=101 2025-07-05 22:09:00.098862 :AE0888D3:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13928 osp_idx=24 osp_ver=567476 osp_pg=0 (spawn #355856) 2025-07-05 22:09:00.098863 :AE0888D4:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-05 22:09:00.098863 :AE0888D5:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=47 time=434115986 2025-07-05 22:09:00.098864 :AE0888D6:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-07-05 22:09:00.098864 :AE0888D7:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-07-05 22:09:00.098864 :AE0888D8:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-07-05 22:09:00.098865 :AE0888D9:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-05 22:09:00.098865 :AE0888DA:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-05 22:09:00.099357 :AE0888DB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-05 22:09:04.367389 :AE088B69:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05 22:09:04.472886 :AE088EE1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05 22:09:04.472886*:AE088EF0:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000027ADC718 estart=1751724544 eid=16783634 ctx=0x000000077FD6A000 cwh=0x0000000027AD0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-05 22:09:04.472886*:AE088EF1:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000027ADC718 curCtx=0x0000000027AD8938 pubTabIdxCnt=0 2025-07-05 22:09:04.472886*:AE088EF2:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000027ADC718 2025-07-05 22:09:04.472886*:AE088EF3:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000027ADC718 2025-07-05 22:09:04.472886*:AE088EF4:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000027ADC718 curCtx=0x0000000027AD8938 xsc->flg4=65792 flags=2 2025-07-05 22:09:04.472886*:AE088EF5:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000027ADC718 2025-07-05 22:09:04.478084 :AE088F00:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:04.478124 :AE088F03:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:jslv.c:9203 2025-07-05 22:09:04.487750 :AE088F13:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:04.601375 :AE088F1B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:04.735836 :AE088F2E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:04.866124 :AE088F42:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:05.982457 :AE088FD4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:05.983507 :AE088FDC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:05.985215 :AE088FE4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:05.988458 :AE088FEC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:05.991755 :AE088FF4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.006308 :AE088FFC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.006943 :AE089004:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.007567 :AE08900C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.007909*:AE08901E:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DB927B8 estart=1751724546 eid=16788119 ctx=0x000000077F821100 cwh=0x000000002DB91330 cpu=0 buffg=3 interb=0 r=0 rb=0 w=0 wb=0 2025-07-05 22:09:06.007909*:AE08901F:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DB927B8 curCtx=0x000000002DCFFF40 pubTabIdxCnt=0 2025-07-05 22:09:06.007909*:AE089020:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DB927B8 2025-07-05 22:09:06.007909*:AE089021:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DB927B8 2025-07-05 22:09:06.007909*:AE089022:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB927B8 curCtx=0x000000002DCFFF40 xsc->flg4=65792 flags=2 2025-07-05 22:09:06.007909*:AE089023:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB927B8 2025-07-05 22:09:06.008131 :AE089024:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.010709 :AE08902C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.011690 :AE089034:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-07-05 22:09:06.012478 :AE089035:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-07-05 22:09:06.013242 :AE089036:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-07-05 22:09:06.013652 :AE089037:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-07-05 22:09:06.013659 :AE089038:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-07-05 22:09:06.014245 :AE089039:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-07-05 22:09:06.014741 :AE08903A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-07-05 22:09:06.015105 :AE08903B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-07-05 22:09:06.016169 :AE08903C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-07-05 22:09:06.070912 :AE08903D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.070956 :AE089040:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-07-05 22:09:06.071912 :AE089046:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.072802 :AE08904E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-07-05 22:09:06.073271 :AE08904F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.074312 :AE089057:db_trace:ktu.c@4871:ktuaex1r(): [10442:26:209] Extension usn 9, ext 2, nex 3 2025-07-05 22:09:06.074318 :AE089058:db_trace:ktusm.c@2117:ktusmasp(): [10445:26:209] des1:tsn:3 rdba:0x00400b81 where: kddwh01: kdddel 2025-07-05 22:09:06.092827 :AE089059:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.092876 :AE08905C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-07-05 22:09:06.093681 :AE089062:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.094580 :AE08906A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-07-05 22:09:06.095032 :AE08906B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.115215 :AE089073:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.115265 :AE089076:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-07-05 22:09:06.116095 :AE08907C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.116921 :AE089084:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-07-05 22:09:06.117458 :AE089085:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.136392 :AE08908D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.136441 :AE089090:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-07-05 22:09:06.137408 :AE089096:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.137901 :AE08909E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.138254 :AE0890A6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.138438 :AE0890AE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.138582 :AE0890B8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.138722 :AE0890C0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:jslv.c:9203 2025-07-05 22:09:06.142651 :AE0890C1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.142728 :AE0890C4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-05 22:09:06.142837 :AE0890D1:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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 26 (osid: 13928, J001)