Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250703220006\orcl_j001_14916_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:37001M/63366M, Ph+PgF:42935M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 14916, image: ORACLE.EXE (J001) *** 2025-07-03 22:00:06.504 *** SESSION ID:(201.7197) 2025-07-03 22:00:06.504 *** 2025-07-03 22:00:06.504 Process diagnostic dump for ORACLE.EXE (J001), OS id=14916, pid: 25, proc_ser: 195, sid: 201, sess_ser: 7197 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 14916 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.491000 sec, exc=0.491000 sec, total=0.491000 sec wait times: max=0.500000 sec, heur=4.391311 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=8 seq_num=9 snap_id=1 wait times: snap=0.510092 sec, exc=0.510092 sec, total=0.510092 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=7 seq_num=8 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.000013 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.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.000007 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499112 sec, exc=0.499112 sec, total=0.499112 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.339093 sec, exc=0.339093 sec, total=0.339093 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000002 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500014 sec, exc=0.500014 sec, total=0.500014 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.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.000007 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.509306 sec, exc=0.509306 sec, total=0.509306 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.042646 sec, exc=0.042646 sec, total=0.042646 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 7197 --------------------------------------------------- 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:02 - 22:00:06] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-03 22:00:06.504 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 14916, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-03 21:47:31.309828 :AD21845A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:47:31.309829 :AD21845B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:47:31.309829 :AD21845C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:47:31.310323 :AD21845D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:48:01.408443 :AD218E73:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:48:31.403256 :AD2197FF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:48:31.392 2025-07-03 21:48:31.403258 :AD219800:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=8552 pso_num=25 pso_serial#=184 2025-07-03 21:48:31.403381 :AD219801:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=8552 osp_idx=23 osp_ver=180836 osp_pg=0 (spawn #349133) 2025-07-03 21:48:31.403382 :AD219802:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:48:31.403382 :AD219803:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=28 time=260087298 2025-07-03 21:48:31.403382 :AD219804:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:48:31.403383 :AD219805:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:48:31.403383 :AD219806:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:48:31.403383 :AD219807:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:48:31.403384 :AD219808:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:48:31.403869 :AD219809:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:48:56.445414 :AD21A071:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 21:49:26.521493 :AD21AA3F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:49:31.500232 :AD21ABBB:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:49:31.489 2025-07-03 21:49:31.500233 :AD21ABBC:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=6728 pso_num=25 pso_serial#=185 2025-07-03 21:49:31.500346 :AD21ABBD:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=6728 osp_idx=23 osp_ver=180837 osp_pg=0 (spawn #349135) 2025-07-03 21:49:31.500347 :AD21ABBE:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:49:31.500347 :AD21ABBF:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=29 time=260147392 2025-07-03 21:49:31.500347 :AD21ABC0:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:49:31.500348 :AD21ABC1:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:49:31.500348 :AD21ABC2:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:49:31.500348 :AD21ABC3:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:49:31.500349 :AD21ABC4:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:49:31.500871 :AD21ABC5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:50:01.573998 :AD21B5A0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:50:31.596342 :AD21BF1C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:50:31.585 2025-07-03 21:50:31.596344 :AD21BF1D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18376 pso_num=25 pso_serial#=186 2025-07-03 21:50:31.596462 :AD21BF1E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18376 osp_idx=23 osp_ver=180838 osp_pg=0 (spawn #349138) 2025-07-03 21:50:31.596463 :AD21BF1F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:50:31.596463 :AD21BF20:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=30 time=260207486 2025-07-03 21:50:31.596463 :AD21BF21:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:50:31.596464 :AD21BF22:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:50:31.596464 :AD21BF23:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:50:31.596464 :AD21BF24:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:50:31.596464 :AD21BF25:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:50:31.596973 :AD21BF26:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:51:01.681402 :AD21C8C8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:51:31.710578 :AD21D278:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:51:31.700 2025-07-03 21:51:31.710581 :AD21D279:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18160 pso_num=25 pso_serial#=187 2025-07-03 21:51:31.710730 :AD21D27A:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18160 osp_idx=23 osp_ver=180839 osp_pg=0 (spawn #349140) 2025-07-03 21:51:31.710731 :AD21D27B:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:51:31.710731 :AD21D27C:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=31 time=260267595 2025-07-03 21:51:31.710732 :AD21D27D:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:51:31.710733 :AD21D27E:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:51:31.710733 :AD21D27F:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:51:31.710734 :AD21D280:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:51:31.710734 :AD21D281:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:51:31.711264 :AD21D282:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:52:01.815316 :AD21DC28:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:52:31.794802 :AD21E5C4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:52:31.783 2025-07-03 21:52:31.794804 :AD21E5C5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15028 pso_num=25 pso_serial#=188 2025-07-03 21:52:31.794935 :AD21E5C6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15028 osp_idx=23 osp_ver=180840 osp_pg=0 (spawn #349142) 2025-07-03 21:52:31.794936 :AD21E5C7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:52:31.794936 :AD21E5C8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=32 time=260327689 2025-07-03 21:52:31.794937 :AD21E5C9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:52:31.794938 :AD21E5CA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:52:31.794938 :AD21E5CB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:52:31.794939 :AD21E5CC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:52:31.794939 :AD21E5CD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:52:31.795444 :AD21E5CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:53:01.886486 :AD21EFB4:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:53:31.873054 :AD21F957:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:53:31.861 2025-07-03 21:53:31.873057 :AD21F958:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17812 pso_num=25 pso_serial#=189 2025-07-03 21:53:31.873168 :AD21F959:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17812 osp_idx=23 osp_ver=180841 osp_pg=0 (spawn #349145) 2025-07-03 21:53:31.873168 :AD21F95A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:53:31.873169 :AD21F95B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=33 time=260387767 2025-07-03 21:53:31.873169 :AD21F95C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:53:31.873170 :AD21F95D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:53:31.873170 :AD21F95E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:53:31.873170 :AD21F95F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:53:31.873171 :AD21F960:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:53:31.873681 :AD21F961:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:54:01.916178 :AD220303:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:54:31.938139 :AD220D15:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:54:31.927 2025-07-03 21:54:31.938141 :AD220D16:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9264 pso_num=25 pso_serial#=190 2025-07-03 21:54:31.938264 :AD220D17:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9264 osp_idx=23 osp_ver=180842 osp_pg=0 (spawn #349147) 2025-07-03 21:54:31.938265 :AD220D18:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:54:31.938265 :AD220D19:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=34 time=260447829 2025-07-03 21:54:31.938266 :AD220D1A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:54:31.938266 :AD220D1B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:54:31.938267 :AD220D1C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:54:31.938267 :AD220D1D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:54:31.938268 :AD220D1E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:54:31.938758 :AD220D1F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:55:02.019052 :AD2217C8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:55:32.029230 :AD222181:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:55:32.018 2025-07-03 21:55:32.029232 :AD222182:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=7924 pso_num=25 pso_serial#=191 2025-07-03 21:55:32.029344 :AD222183:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=7924 osp_idx=23 osp_ver=180843 osp_pg=0 (spawn #349149) 2025-07-03 21:55:32.029345 :AD222184:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:55:32.029345 :AD222185:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=35 time=260507923 2025-07-03 21:55:32.029346 :AD222186:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:55:32.029346 :AD222187:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:55:32.029347 :AD222188:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:55:32.029347 :AD222189:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:55:32.029347 :AD22218A:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:55:32.029859 :AD22218B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:56:02.109780 :AD222B01:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:56:32.119325 :AD223494:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:56:32.108 2025-07-03 21:56:32.119327 :AD223495:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18004 pso_num=25 pso_serial#=192 2025-07-03 21:56:32.119467 :AD223496:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18004 osp_idx=23 osp_ver=180844 osp_pg=0 (spawn #349151) 2025-07-03 21:56:32.119468 :AD223497:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:56:32.119468 :AD223498:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=36 time=260568001 2025-07-03 21:56:32.119469 :AD223499:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:56:32.119469 :AD22349A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:56:32.119469 :AD22349B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:56:32.119470 :AD22349C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:56:32.119470 :AD22349D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:56:32.119940 :AD22349E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:57:02.211447 :AD223E51:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:57:32.209654 :AD2247FD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:57:32.197 2025-07-03 21:57:32.209656 :AD2247FE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=6128 pso_num=25 pso_serial#=193 2025-07-03 21:57:32.209790 :AD2247FF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=6128 osp_idx=23 osp_ver=180845 osp_pg=0 (spawn #349153) 2025-07-03 21:57:32.209791 :AD224800:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:57:32.209791 :AD224801:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=37 time=260628095 2025-07-03 21:57:32.209792 :AD224802:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:57:32.209792 :AD224803:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:57:32.209793 :AD224804:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:57:32.209794 :AD224805:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:57:32.209794 :AD224806:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:57:32.210343 :AD224807:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:58:02.285566 :AD225234:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:58:32.304576 :AD225BE1:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:58:32.293 2025-07-03 21:58:32.304578 :AD225BE2:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=3280 pso_num=25 pso_serial#=194 2025-07-03 21:58:32.304712 :AD225BE3:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=3280 osp_idx=23 osp_ver=180846 osp_pg=0 (spawn #349156) 2025-07-03 21:58:32.304712 :AD225BE4:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:58:32.304713 :AD225BE5:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=38 time=260688189 2025-07-03 21:58:32.304713 :AD225BE6:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:58:32.304714 :AD225BE7:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:58:32.304714 :AD225BE8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:58:32.304715 :AD225BE9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:58:32.304715 :AD225BEA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:58:32.305222 :AD225BEB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 21:58:57.346586 :AD22643C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 21:59:27.423653 :AD226E22:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-03 21:59:32.407573 :AD226F6B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-03 21:59:32.396 2025-07-03 21:59:32.407576 :AD226F6C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14916 pso_num=25 pso_serial#=195 2025-07-03 21:59:32.407690 :AD226F6D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14916 osp_idx=23 osp_ver=180847 osp_pg=0 (spawn #349158) 2025-07-03 21:59:32.407691 :AD226F6E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-07-03 21:59:32.407691 :AD226F6F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=39 time=260748298 2025-07-03 21:59:32.407691 :AD226F70:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-03 21:59:32.407691 :AD226F71:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-03 21:59:32.407692 :AD226F72:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-03 21:59:32.407692 :AD226F73:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-03 21:59:32.407692 :AD226F74:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-03 21:59:32.408207 :AD226F75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.036614 :AD227AD4:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.036614*:AD227AF3:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEB898 estart=1751551201 eid=16783503 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-03 22:00:02.036614*:AD227AF5:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 pubTabIdxCnt=0 2025-07-03 22:00:02.036614*:AD227AF6:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEB898 2025-07-03 22:00:02.036614*:AD227AF7:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEB898 2025-07-03 22:00:02.036614*:AD227B15:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 xsc->flg4=65792 flags=2 2025-07-03 22:00:02.036614*:AD227B16:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEB898 2025-07-03 22:00:02.043487 :AD227B17:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.043539 :AD227B1A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-03 22:00:02.076775 :AD227C53:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-03 22:00:02.077448 :AD227C54:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 9e2d120000000000 2025-07-03 22:00:02.081656 :AD227C55:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.081751 :AD227C65:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.081763 :AD227C69:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-07-03 22:00:02.081769 :AD227C6A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.081798 :AD227C79:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.082614 :AD227C82:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 230271541) 2025-07-03 22:00:02.082617 :AD227C83:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.082646 :AD227C93:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.082657 :AD227C9A:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65561 1) 2025-07-03 22:00:02.082659 :AD227C9B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.082696 :AD227CA7:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.082700 :AD227CB3:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65561) 2025-07-03 22:00:02.082702 :AD227CB4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.082745 :AD227CD5:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.083161 :AD227D4E:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.083175 :AD227D4F:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-03 22:00:02.083962 :AD227D56:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 9f2d120000000000 2025-07-03 22:00:02.084342 :AD227D57:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 230271541) 2025-07-03 22:00:02.084346 :AD227D58:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.084374 :AD227D67:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:02.116237 :AD227D78:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-03 22:00:02.118077 :AD227D79:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.118134 :AD227D7C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-07-03 22:00:02.118289 :AD227D88:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-07-03 22:00:02.161640 :AD227DB0:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-07-03 22:00:04.009935 :AD22822D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 14916, J001)