Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250622060009\orcl_j001_18280_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:36390M/63366M, Ph+PgF:42659M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 18280, image: ORACLE.EXE (J001) *** 2025-06-22 06:00:10.088 *** SESSION ID:(201.40149) 2025-06-22 06:00:10.088 *** 2025-06-22 06:00:10.088 Process diagnostic dump for ORACLE.EXE (J001), OS id=18280, pid: 25, proc_ser: 174, sid: 201, sess_ser: 40149 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 18280 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.286358 sec, exc=0.286358 sec, total=0.286358 sec wait times: max=0.500000 sec, heur=7.885262 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.000012 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.500005 sec, exc=0.500005 sec, total=0.500005 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=14 seq_num=15 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.000011 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.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.000006 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.499990 sec, exc=0.499990 sec, total=0.499990 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 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.502099 sec, exc=0.502099 sec, total=0.502099 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 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.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 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 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.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.000010 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.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 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.000009 sec of elapsed time Sampled Session History of session 201 serial 40149 --------------------------------------------------- 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, 06:00:02 - 06:00:10] idle wait at each sample [session created at: 06:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-22 06:00:10.088 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 18280, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-22 05:48:34.049991 :A7FA7090:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:48:34.038 2025-06-22 05:48:34.049993 :A7FA7091:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18124 pso_num=25 pso_serial#=162 2025-06-22 05:48:34.050127 :A7FA7092:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18124 osp_idx=23 osp_ver=165514 osp_pg=0 (spawn #310247) 2025-06-22 05:48:34.050127 :A7FA7093:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:48:34.050128 :A7FA7094:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=203 time=3547057235 2025-06-22 05:48:34.050128 :A7FA7095:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:48:34.050129 :A7FA7096:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:48:34.050129 :A7FA7097:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:48:34.050129 :A7FA7098:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:48:34.050130 :A7FA7099:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:48:34.050609 :A7FA709A: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-06-22 05:49:04.135320 :A7FA7A67:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:49:34.153522 :A7FA83E8:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:49:34.142 2025-06-22 05:49:34.153524 :A7FA83E9:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12148 pso_num=25 pso_serial#=163 2025-06-22 05:49:34.153638 :A7FA83EA:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12148 osp_idx=23 osp_ver=165515 osp_pg=0 (spawn #310249) 2025-06-22 05:49:34.153639 :A7FA83EB:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:49:34.153640 :A7FA83EC:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=204 time=3547117344 2025-06-22 05:49:34.153640 :A7FA83ED:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:49:34.153640 :A7FA83EE:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:49:34.153641 :A7FA83EF:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:49:34.153641 :A7FA83F0:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:49:34.153641 :A7FA83F1:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:49:34.154172 :A7FA83F2: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-06-22 05:50:04.233331 :A7FA8DEB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:50:34.232357 :A7FA9793:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:50:34.221 2025-06-22 05:50:34.232359 :A7FA9794:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16844 pso_num=25 pso_serial#=164 2025-06-22 05:50:34.232487 :A7FA9795:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16844 osp_idx=23 osp_ver=165516 osp_pg=0 (spawn #310251) 2025-06-22 05:50:34.232488 :A7FA9796:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:50:34.232489 :A7FA9797:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=205 time=3547177422 2025-06-22 05:50:34.232489 :A7FA9798:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:50:34.232489 :A7FA9799:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:50:34.232490 :A7FA979A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:50:34.232490 :A7FA979B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:50:34.232490 :A7FA979C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:50:34.233004 :A7FA979D: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-06-22 05:51:04.305792 :A7FAA166:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:51:34.298516 :A7FAAB3D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:51:34.287 2025-06-22 05:51:34.298518 :A7FAAB3E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17576 pso_num=25 pso_serial#=165 2025-06-22 05:51:34.298655 :A7FAAB3F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17576 osp_idx=23 osp_ver=165517 osp_pg=0 (spawn #310253) 2025-06-22 05:51:34.298656 :A7FAAB40:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:51:34.298657 :A7FAAB41:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=206 time=3547237485 2025-06-22 05:51:34.298657 :A7FAAB42:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:51:34.298657 :A7FAAB43:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:51:34.298658 :A7FAAB44:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:51:34.298658 :A7FAAB45:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:51:34.298659 :A7FAAB46:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:51:34.299136 :A7FAAB47: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-06-22 05:52:04.375959 :A7FAB4C9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:52:34.370000 :A7FABE5F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:52:34.359 2025-06-22 05:52:34.370002 :A7FABE60:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4800 pso_num=25 pso_serial#=166 2025-06-22 05:52:34.370144 :A7FABE61:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4800 osp_idx=23 osp_ver=165518 osp_pg=0 (spawn #310255) 2025-06-22 05:52:34.370144 :A7FABE62:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:52:34.370145 :A7FABE63:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=207 time=3547297547 2025-06-22 05:52:34.370145 :A7FABE64:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:52:34.370145 :A7FABE65:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:52:34.370146 :A7FABE66:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:52:34.370146 :A7FABE67:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:52:34.370147 :A7FABE68:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:52:34.370633 :A7FABE69: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-06-22 05:53:04.490914 :A7FAC873:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:53:34.485880 :A7FAD23B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:53:34.475 2025-06-22 05:53:34.485882 :A7FAD23C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17968 pso_num=25 pso_serial#=167 2025-06-22 05:53:34.486018 :A7FAD23D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17968 osp_idx=23 osp_ver=165519 osp_pg=0 (spawn #310258) 2025-06-22 05:53:34.486019 :A7FAD23E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:53:34.486019 :A7FAD23F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=208 time=3547357672 2025-06-22 05:53:34.486020 :A7FAD240:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:53:34.486020 :A7FAD241:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:53:34.486021 :A7FAD242:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:53:34.486021 :A7FAD243:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:53:34.486022 :A7FAD244:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:53:34.486484 :A7FAD245: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-06-22 05:53:59.506090 :A7FADA78: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-06-22 05:54:29.582149 :A7FAE487:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:54:34.561480 :A7FAE63B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:54:34.550 2025-06-22 05:54:34.561482 :A7FAE63C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16372 pso_num=25 pso_serial#=168 2025-06-22 05:54:34.561623 :A7FAE63D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16372 osp_idx=23 osp_ver=165520 osp_pg=0 (spawn #310260) 2025-06-22 05:54:34.561624 :A7FAE63E:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:54:34.561625 :A7FAE63F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=209 time=3547417750 2025-06-22 05:54:34.561625 :A7FAE640:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:54:34.561625 :A7FAE641:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:54:34.561626 :A7FAE642:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:54:34.561626 :A7FAE643:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:54:34.561627 :A7FAE644:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:54:34.562110 :A7FAE645: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-06-22 05:55:04.607056 :A7FAF08D:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:55:04.622467 :A7FAF09D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:55:04.623 2025-06-22 05:55:04.622470 :A7FAF09E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13760 pso_num=25 pso_serial#=169 2025-06-22 05:55:04.622611 :A7FAF09F:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=13760 (legacy spawn) 2025-06-22 05:55:04.629051 :A7FAF0A0: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-06-22 05:55:04.629213 :A7FAF0A9: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-06-22 05:55:04.630013 :A7FAF0AA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:55:34.617765 :A7FAFA16:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:55:34.606 2025-06-22 05:55:34.617767 :A7FAFA17:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14012 pso_num=25 pso_serial#=170 2025-06-22 05:55:34.617884 :A7FAFA18:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14012 osp_idx=23 osp_ver=165522 osp_pg=0 (spawn #310263) 2025-06-22 05:55:34.617884 :A7FAFA19:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:55:34.617885 :A7FAFA1A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=210 time=3547477797 2025-06-22 05:55:34.617885 :A7FAFA1B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:55:34.617886 :A7FAFA1C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:55:34.617887 :A7FAFA1D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:55:34.617887 :A7FAFA1E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:55:34.617887 :A7FAFA1F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:55:34.618410 :A7FAFA20: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-06-22 05:56:04.679496 :A7FB0436:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:56:34.700391 :A7FB0DBE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:56:34.689 2025-06-22 05:56:34.700393 :A7FB0DBF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17216 pso_num=25 pso_serial#=171 2025-06-22 05:56:34.700516 :A7FB0DC0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17216 osp_idx=23 osp_ver=165523 osp_pg=0 (spawn #310265) 2025-06-22 05:56:34.700517 :A7FB0DC1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:56:34.700517 :A7FB0DC2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=211 time=3547537891 2025-06-22 05:56:34.700517 :A7FB0DC3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:56:34.700518 :A7FB0DC4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:56:34.700518 :A7FB0DC5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:56:34.700518 :A7FB0DC6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:56:34.700519 :A7FB0DC7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:56:34.701011 :A7FB0DC8: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-06-22 05:57:04.793921 :A7FB1789:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:57:34.766673 :A7FB2120:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:57:34.756 2025-06-22 05:57:34.766675 :A7FB2121:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15256 pso_num=25 pso_serial#=172 2025-06-22 05:57:34.766813 :A7FB2122:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15256 osp_idx=23 osp_ver=165524 osp_pg=0 (spawn #310267) 2025-06-22 05:57:34.766814 :A7FB2123:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:57:34.766814 :A7FB2124:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=212 time=3547597954 2025-06-22 05:57:34.766814 :A7FB2125:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:57:34.766815 :A7FB2126:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:57:34.766815 :A7FB2127:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:57:34.766815 :A7FB2128:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:57:34.766816 :A7FB2129:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:57:34.767306 :A7FB212A: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-06-22 05:58:04.840611 :A7FB2AF6:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:58:34.839098 :A7FB34A4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:58:34.828 2025-06-22 05:58:34.839100 :A7FB34A5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15520 pso_num=25 pso_serial#=173 2025-06-22 05:58:34.839236 :A7FB34A6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15520 osp_idx=23 osp_ver=165525 osp_pg=0 (spawn #310270) 2025-06-22 05:58:34.839237 :A7FB34A7:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:58:34.839237 :A7FB34A8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=213 time=3547658016 2025-06-22 05:58:34.839238 :A7FB34A9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:58:34.839239 :A7FB34AA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:58:34.839239 :A7FB34AB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:58:34.839239 :A7FB34AC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:58:34.839239 :A7FB34AD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:58:34.839731 :A7FB34AE: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-06-22 05:59:04.923637 :A7FB3E81:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-22 05:59:34.924219 :A7FB485E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-22 05:59:34.913 2025-06-22 05:59:34.924221 :A7FB485F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18280 pso_num=25 pso_serial#=174 2025-06-22 05:59:34.924341 :A7FB4860:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18280 osp_idx=23 osp_ver=165526 osp_pg=0 (spawn #310272) 2025-06-22 05:59:34.924342 :A7FB4861:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-22 05:59:34.924342 :A7FB4862:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=214 time=3547718110 2025-06-22 05:59:34.924343 :A7FB4863:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-22 05:59:34.924343 :A7FB4864:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-22 05:59:34.924343 :A7FB4865:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-22 05:59:34.924344 :A7FB4866:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-22 05:59:34.924344 :A7FB4867:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-22 05:59:34.924854 :A7FB4868: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-06-22 06:00:02.178971 :A7FB5387: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-06-22 06:00:02.178971*:A7FB53A6:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEB898 estart=1750543201 eid=16782790 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-06-22 06:00:02.178971*:A7FB53A7:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 pubTabIdxCnt=0 2025-06-22 06:00:02.178971*:A7FB53A8:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEB898 2025-06-22 06:00:02.178971*:A7FB53A9:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEB898 2025-06-22 06:00:02.178971*:A7FB53C8:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 xsc->flg4=65792 flags=2 2025-06-22 06:00:02.178971*:A7FB53C9:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEB898 2025-06-22 06:00:02.185978 :A7FB53CA: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-06-22 06:00:02.186037 :A7FB53CD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-06-22 06:00:02.191419 :A7FB53FB:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-22 06:00:02.192034 :A7FB53FC:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 6216120000000000 2025-06-22 06:00:02.193662 :A7FB53FD: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-06-22 06:00:02.193753 :A7FB540A: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-06-22 06:00:02.193763 :A7FB5411:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-06-22 06:00:02.193769 :A7FB5412: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-06-22 06:00:02.193801 :A7FB541E: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-06-22 06:00:02.194462 :A7FB542A:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 229115289) 2025-06-22 06:00:02.194467 :A7FB542B: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-06-22 06:00:02.194506 :A7FB5434: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-06-22 06:00:02.194515 :A7FB543D:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65561 1) 2025-06-22 06:00:02.194523 :A7FB5444: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-06-22 06:00:02.194560 :A7FB544E: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-06-22 06:00:02.194563 :A7FB5453:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65561) 2025-06-22 06:00:02.194565 :A7FB5458: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-06-22 06:00:02.194638 :A7FB547B: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-06-22 06:00:02.195140 :A7FB54FB: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-06-22 06:00:02.195162 :A7FB5511:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-22 06:00:02.196026 :A7FB5521:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 6316120000000000 2025-06-22 06:00:02.196398 :A7FB5534:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 229115289) 2025-06-22 06:00:02.196406 :A7FB5535: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-06-22 06:00:02.196441 :A7FB5540: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-06-22 06:00:02.204863 :A7FB5599:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-06-22 06:00:02.206790 :A7FB55A2: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-06-22 06:00:02.206857 :A7FB55A5: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-06-22 06:00:02.206921 :A7FB55B2: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-06-22 06:00:02.303857 :A7FB56B4: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: 18280, J001)