Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250728220010\orcl_j001_18716_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:35940M/63366M, Ph+PgF:41689M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 18716, image: ORACLE.EXE (J001) *** 2025-07-28 22:00:10.267 *** SESSION ID:(201.28029) 2025-07-28 22:00:10.267 *** 2025-07-28 22:00:10.267 Process diagnostic dump for ORACLE.EXE (J001), OS id=18716, pid: 25, proc_ser: 192, sid: 201, sess_ser: 28029 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 18716 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.255266 sec, exc=0.255266 sec, total=0.255266 sec wait times: max=0.500000 sec, heur=8.105744 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000008 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.499987 sec, exc=0.499987 sec, total=0.499987 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.500008 sec, exc=0.500008 sec, total=0.500008 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.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 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.499976 sec, exc=0.499976 sec, total=0.499976 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 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.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.000016 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.500119 sec, exc=0.500119 sec, total=0.500119 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 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.500009 sec, exc=0.500009 sec, total=0.500009 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 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.499992 sec, exc=0.499992 sec, total=0.499992 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 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.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.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.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.000012 sec of elapsed time Sampled Session History of session 201 serial 28029 --------------------------------------------------- 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 --------------------------------------------------- [9 samples, 22:00:02 - 22:00:10] 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-28 22:00:10.267 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 18716, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-28 21:48:36.895514 :B84572AD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14064 pso_num=25 pso_serial#=181 2025-07-28 21:48:36.895643 :B84572AE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14064 osp_idx=23 osp_ver=220103 osp_pg=0 (spawn #432464) 2025-07-28 21:48:36.895644 :B84572AF: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-28 21:48:36.895644 :B84572B0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=12 time=2420092783 2025-07-28 21:48:36.895645 :B84572B1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:48:36.895645 :B84572B2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:48:36.895645 :B84572B3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:48:36.895645 :B84572B4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:48:36.895646 :B84572B5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:48:36.896120 :B84572B6: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-28 21:49:06.957038 :B8457CBA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:49:36.972754 :B84586B7:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:49:36.962 2025-07-28 21:49:36.972756 :B84586B8:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=13808 pso_num=25 pso_serial#=182 2025-07-28 21:49:36.972898 :B84586B9:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=13808 osp_idx=23 osp_ver=220104 osp_pg=0 (spawn #432466) 2025-07-28 21:49:36.972898 :B84586BA: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-28 21:49:36.972899 :B84586BB:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=13 time=2420152861 2025-07-28 21:49:36.972899 :B84586BC:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:49:36.972899 :B84586BD:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:49:36.972900 :B84586BE:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:49:36.972900 :B84586BF:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:49:36.972901 :B84586C0:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:49:36.973400 :B84586C1: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-28 21:50:07.034028 :B845909F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:50:37.044511 :B8459AB0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:50:37.033 2025-07-28 21:50:37.044513 :B8459AB1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17772 pso_num=25 pso_serial#=183 2025-07-28 21:50:37.044629 :B8459AB2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17772 osp_idx=23 osp_ver=220105 osp_pg=0 (spawn #432469) 2025-07-28 21:50:37.044630 :B8459AB3: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-28 21:50:37.044630 :B8459AB4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=14 time=2420212939 2025-07-28 21:50:37.044631 :B8459AB5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:50:37.044631 :B8459AB6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:50:37.044631 :B8459AB7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:50:37.044632 :B8459AB8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:50:37.044632 :B8459AB9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:50:37.045201 :B8459ABA: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-28 21:51:07.114092 :B845A464:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:51:37.119063 :B845AE32:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:51:37.108 2025-07-28 21:51:37.119065 :B845AE33:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17112 pso_num=25 pso_serial#=184 2025-07-28 21:51:37.119199 :B845AE34:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17112 osp_idx=23 osp_ver=220106 osp_pg=0 (spawn #432471) 2025-07-28 21:51:37.119200 :B845AE35: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-28 21:51:37.119201 :B845AE36:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=15 time=2420273001 2025-07-28 21:51:37.119201 :B845AE37:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:51:37.119201 :B845AE38:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:51:37.119202 :B845AE39:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:51:37.119202 :B845AE3A:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:51:37.119203 :B845AE3B:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:51:37.119730 :B845AE3C: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-28 21:52:07.179033 :B845B7DE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:52:37.219754 :B845C195:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:52:37.209 2025-07-28 21:52:37.219757 :B845C196:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17200 pso_num=25 pso_serial#=185 2025-07-28 21:52:37.219904 :B845C197:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17200 osp_idx=23 osp_ver=220107 osp_pg=0 (spawn #432473) 2025-07-28 21:52:37.219904 :B845C198: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-28 21:52:37.219905 :B845C199:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=16 time=2420333111 2025-07-28 21:52:37.219905 :B845C19A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:52:37.219906 :B845C19B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:52:37.219906 :B845C19C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:52:37.219906 :B845C19D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:52:37.219906 :B845C19E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:52:37.220392 :B845C19F: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-28 21:53:07.270777 :B845CB40:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:53:37.308374 :B845D526:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:53:37.297 2025-07-28 21:53:37.308377 :B845D527:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16084 pso_num=25 pso_serial#=186 2025-07-28 21:53:37.308512 :B845D528:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16084 osp_idx=23 osp_ver=220108 osp_pg=0 (spawn #432475) 2025-07-28 21:53:37.308512 :B845D529: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-28 21:53:37.308513 :B845D52A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=17 time=2420393189 2025-07-28 21:53:37.308513 :B845D52B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:53:37.308514 :B845D52C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:53:37.308514 :B845D52D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:53:37.308514 :B845D52E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:53:37.308515 :B845D52F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:53:37.308976 :B845D530: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-28 21:54:02.354703 :B845DD36: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-28 21:54:32.422846 :B845E714:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:54:37.407357 :B845E90B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:54:37.396 2025-07-28 21:54:37.407359 :B845E90C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19080 pso_num=25 pso_serial#=187 2025-07-28 21:54:37.407499 :B845E90D:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19080 osp_idx=23 osp_ver=220109 osp_pg=0 (spawn #432477) 2025-07-28 21:54:37.407500 :B845E90E: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-28 21:54:37.407500 :B845E90F:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=18 time=2420453298 2025-07-28 21:54:37.407500 :B845E910:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:54:37.407501 :B845E911:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:54:37.407502 :B845E912:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:54:37.407503 :B845E913:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:54:37.407503 :B845E914:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:54:37.407994 :B845E915: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-28 21:55:07.473625 :B845F3E7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:55:37.464690 :B845FD7C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:55:37.454 2025-07-28 21:55:37.464692 :B845FD7D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18400 pso_num=25 pso_serial#=188 2025-07-28 21:55:37.464825 :B845FD7E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18400 osp_idx=23 osp_ver=220110 osp_pg=0 (spawn #432479) 2025-07-28 21:55:37.464826 :B845FD7F: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-28 21:55:37.464826 :B845FD80:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=19 time=2420513345 2025-07-28 21:55:37.464826 :B845FD81:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:55:37.464827 :B845FD82:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:55:37.464828 :B845FD83:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:55:37.464828 :B845FD84:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:55:37.464828 :B845FD85:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:55:37.465300 :B845FD86: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-28 21:56:07.541292 :B846072E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:56:37.561900 :B84610D5:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:56:37.551 2025-07-28 21:56:37.561903 :B84610D6:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18180 pso_num=25 pso_serial#=189 2025-07-28 21:56:37.562042 :B84610D7:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18180 osp_idx=23 osp_ver=220111 osp_pg=0 (spawn #432481) 2025-07-28 21:56:37.562043 :B84610D8: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-28 21:56:37.562044 :B84610D9:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=20 time=2420573454 2025-07-28 21:56:37.562044 :B84610DA:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:56:37.562045 :B84610DB:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:56:37.562045 :B84610DC:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:56:37.562046 :B84610DD:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:56:37.562046 :B84610DE:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:56:37.562563 :B84610DF: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-28 21:57:07.661194 :B8461A78:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:57:37.643795 :B8462479:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:57:37.631 2025-07-28 21:57:37.643797 :B846247A:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18524 pso_num=25 pso_serial#=190 2025-07-28 21:57:37.643911 :B846247B:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18524 osp_idx=23 osp_ver=220112 osp_pg=0 (spawn #432484) 2025-07-28 21:57:37.643912 :B846247C: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-28 21:57:37.643912 :B846247D:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=21 time=2420633533 2025-07-28 21:57:37.643913 :B846247E:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:57:37.643913 :B846247F:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:57:37.643914 :B8462480:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:57:37.643914 :B8462481:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:57:37.643914 :B8462482:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:57:37.644452 :B8462483: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-28 21:58:07.722675 :B8462EBF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:58:37.725344 :B8463870:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:58:37.714 2025-07-28 21:58:37.725345 :B8463871:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9252 pso_num=25 pso_serial#=191 2025-07-28 21:58:37.725477 :B8463872:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=9252 osp_idx=23 osp_ver=220113 osp_pg=0 (spawn #432486) 2025-07-28 21:58:37.725477 :B8463873: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-28 21:58:37.725478 :B8463874:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=22 time=2420693611 2025-07-28 21:58:37.725478 :B8463875:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:58:37.725479 :B8463876:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:58:37.725479 :B8463877:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:58:37.725479 :B8463878:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:58:37.725480 :B8463879:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:58:37.725969 :B846387A: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-28 21:59:07.775787 :B84642D7:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-28 21:59:37.793900 :B8464CBC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-28 21:59:37.782 2025-07-28 21:59:37.793902 :B8464CBD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18716 pso_num=25 pso_serial#=192 2025-07-28 21:59:37.794030 :B8464CBE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18716 osp_idx=23 osp_ver=220114 osp_pg=0 (spawn #432488) 2025-07-28 21:59:37.794031 :B8464CBF: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-28 21:59:37.794032 :B8464CC0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=23 time=2420753689 2025-07-28 21:59:37.794032 :B8464CC1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-28 21:59:37.794032 :B8464CC2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-28 21:59:37.794033 :B8464CC3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-28 21:59:37.794033 :B8464CC4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-28 21:59:37.794033 :B8464CC5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-28 21:59:37.794491 :B8464CC6: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-28 22:00:02.032645 :B84656A8: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-28 22:00:02.032645*:B84656B6:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEB898 estart=1753711201 eid=16785045 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-28 22:00:02.032645*:B84656B7:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 pubTabIdxCnt=0 2025-07-28 22:00:02.032645*:B84656B8:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEB898 2025-07-28 22:00:02.032645*:B84656B9:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEB898 2025-07-28 22:00:02.032645*:B84656BA:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 xsc->flg4=65792 flags=2 2025-07-28 22:00:02.032645*:B84656BB:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEB898 2025-07-28 22:00:02.038494 :B84656C6: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-28 22:00:02.038540 :B84656CB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-28 22:00:02.055272 :B846574B:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-28 22:00:02.055866 :B846574C:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 765f120000000000 2025-07-28 22:00:02.057552 :B8465777: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-28 22:00:02.057678 :B8465784: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-28 22:00:02.057689 :B846578A: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-28 22:00:02.057695 :B846578C: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-28 22:00:02.057718 :B8465797: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-28 22:00:02.058466 :B84657BC:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 232757780) 2025-07-28 22:00:02.058474 :B84657BD: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-28 22:00:02.058512 :B84657C6: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-28 22:00:02.058522 :B84657CF: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-28 22:00:02.058525 :B84657D2: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-28 22:00:02.058566 :B84657DD: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-28 22:00:02.058569 :B84657E4: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-28 22:00:02.058572 :B84657EA: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-28 22:00:02.058638 :B8465809: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-28 22:00:02.059306 :B84658B0: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-28 22:00:02.059323 :B84658B1:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-07-28 22:00:02.060158 :B84658B8:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 775f120000000000 2025-07-28 22:00:02.060530 :B84658B9:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 232757780) 2025-07-28 22:00:02.060538 :B84658BA: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-28 22:00:02.060574 :B84658C3: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-28 22:00:02.069544 :B846598B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-28 22:00:02.071446 :B846598C: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-28 22:00:02.071544 :B846598F: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-28 22:00:02.071741 :B846599C: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-28 22:00:02.157703 :B84659B5: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-28 22:00:02.159890 :B84659B6: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-28 22:00:02.159933 :B84659B9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-28 22:00:02.162611 :B84659BF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-28 22:00:02.166131 :B84659C0: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-28 22:00:02.166224 :B84659C3: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-28 22:00:02.166309 :B84659D0: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-28 22:00:04.017962 :B8465DC3: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: 18716, J001)