Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250723220008\orcl_j001_4152_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:36038M/63366M, Ph+PgF:41842M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 4152, image: ORACLE.EXE (J001) *** 2025-07-23 22:00:08.183 *** SESSION ID:(201.7885) 2025-07-23 22:00:08.183 *** 2025-07-23 22:00:08.183 Process diagnostic dump for ORACLE.EXE (J001), OS id=4152, pid: 25, proc_ser: 91, sid: 201, sess_ser: 7885 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 4152 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.180734 sec, exc=0.180734 sec, total=0.180734 sec wait times: max=0.500000 sec, heur=4.165880 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=7 seq_num=8 snap_id=1 wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 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.000010 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 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.000006 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500111 sec, exc=0.500111 sec, total=0.500111 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 5: 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.000012 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.500011 sec, exc=0.500011 sec, total=0.500011 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.484966 sec, exc=0.484966 sec, total=0.484966 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 7885 --------------------------------------------------- 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:04 - 22:00:08] idle wait at each sample [session created at: 22:00:04] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-07-23 22:00:08.183 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 4152, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-07-23 21:48:30.748996 :B60EB666:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:48:30.749466 :B60EB667: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-23 21:49:00.861605 :B60EC048:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:49:30.875575 :B60ECA55:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:49:30.864 2025-07-23 21:49:30.875577 :B60ECA56:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19040 pso_num=25 pso_serial#=81 2025-07-23 21:49:30.875714 :B60ECA57:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19040 osp_idx=23 osp_ver=211078 osp_pg=0 (spawn #415792) 2025-07-23 21:49:30.875714 :B60ECA58: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-23 21:49:30.875715 :B60ECA59:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=253 time=1988146767 2025-07-23 21:49:30.875715 :B60ECA5A:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:49:30.875715 :B60ECA5B:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:49:30.875715 :B60ECA5C:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:49:30.875716 :B60ECA5D:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:49:30.875716 :B60ECA5E:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:49:30.876204 :B60ECA5F: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-23 21:50:00.931074 :B60ED4B8:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:50:30.924226 :B60EDE8D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:50:30.913 2025-07-23 21:50:30.924228 :B60EDE8E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16504 pso_num=25 pso_serial#=82 2025-07-23 21:50:30.924364 :B60EDE8F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16504 osp_idx=23 osp_ver=211079 osp_pg=0 (spawn #415794) 2025-07-23 21:50:30.924365 :B60EDE90: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-23 21:50:30.924365 :B60EDE91:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=254 time=1988206814 2025-07-23 21:50:30.924366 :B60EDE92:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:50:30.924366 :B60EDE93:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:50:30.924367 :B60EDE94:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:50:30.924367 :B60EDE95:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:50:30.924368 :B60EDE96:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:50:30.924860 :B60EDE97: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-23 21:51:00.989675 :B60EE865:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:51:31.002455 :B60EF246:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:51:30.989 2025-07-23 21:51:31.002457 :B60EF247:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18780 pso_num=25 pso_serial#=83 2025-07-23 21:51:31.002582 :B60EF248:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18780 osp_idx=23 osp_ver=211080 osp_pg=0 (spawn #415796) 2025-07-23 21:51:31.002583 :B60EF249: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-23 21:51:31.002583 :B60EF24A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=255 time=1988266892 2025-07-23 21:51:31.002583 :B60EF24B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:51:31.002584 :B60EF24C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:51:31.002584 :B60EF24D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:51:31.002585 :B60EF24E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:51:31.002585 :B60EF24F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:51:31.003097 :B60EF250: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-23 21:52:01.104032 :B60EFC4C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:52:31.092531 :B60F0643:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:52:31.081 2025-07-23 21:52:31.092533 :B60F0644:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19004 pso_num=25 pso_serial#=84 2025-07-23 21:52:31.092660 :B60F0645:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19004 osp_idx=23 osp_ver=211081 osp_pg=0 (spawn #415798) 2025-07-23 21:52:31.092661 :B60F0646: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-23 21:52:31.092662 :B60F0647:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=0 time=1988326986 2025-07-23 21:52:31.092662 :B60F0648:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:52:31.092662 :B60F0649:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:52:31.092663 :B60F064A:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:52:31.092663 :B60F064B:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:52:31.092663 :B60F064C:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:52:31.093157 :B60F064D: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-23 21:53:01.177170 :B60F1046:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:53:31.183679 :B60F1A56:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:53:31.173 2025-07-23 21:53:31.183682 :B60F1A57:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17976 pso_num=25 pso_serial#=85 2025-07-23 21:53:31.183820 :B60F1A58:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17976 osp_idx=23 osp_ver=211082 osp_pg=0 (spawn #415801) 2025-07-23 21:53:31.183821 :B60F1A59: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-23 21:53:31.183821 :B60F1A5A:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=1 time=1988387079 2025-07-23 21:53:31.183822 :B60F1A5B:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:53:31.183822 :B60F1A5C:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:53:31.183823 :B60F1A5D:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:53:31.183823 :B60F1A5E:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:53:31.183823 :B60F1A5F:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:53:31.184319 :B60F1A60: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-23 21:53:56.211218 :B60F226B: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-23 21:53:56.211251*:B60F226C:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BDBB58 estart=1753278836 eid=16971472 ctx=0x000000077BD98A08 cwh=0x0000000026B901B0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-23 21:53:56.211251*:B60F226D:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BDBB58 curCtx=0x0000000026B9F708 pubTabIdxCnt=0 2025-07-23 21:53:56.211251*:B60F226E:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BDBB58 2025-07-23 21:53:56.211251*:B60F226F:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BDBB58 2025-07-23 21:53:56.211251*:B60F2270:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BDBB58 curCtx=0x0000000026B9F708 xsc->flg4=65792 flags=2 2025-07-23 21:53:56.211251*:B60F2271:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BDBB58 2025-07-23 21:53:56.211830 :B60F2272: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-23 21:53:56.217213 :B60F227A: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-23 21:53:56.218248 :B60F2282: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-23 21:53:56.218392 :B60F228B: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-23 21:54:26.296680 :B60F2D4F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:54:31.250111 :B60F2EED:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:54:31.238 2025-07-23 21:54:31.250113 :B60F2EEE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=1484 pso_num=25 pso_serial#=86 2025-07-23 21:54:31.250247 :B60F2EEF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=1484 osp_idx=23 osp_ver=211083 osp_pg=0 (spawn #415803) 2025-07-23 21:54:31.250248 :B60F2EF0: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-23 21:54:31.250248 :B60F2EF1:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=2 time=1988447142 2025-07-23 21:54:31.250248 :B60F2EF2:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:54:31.250249 :B60F2EF3:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:54:31.250251 :B60F2EF4:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:54:31.250251 :B60F2EF5:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:54:31.250251 :B60F2EF6:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:54:31.250804 :B60F2EF7: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-23 21:55:01.315166 :B60F39D0:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:55:31.372661 :B60F43BC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:55:31.373 2025-07-23 21:55:31.372663 :B60F43BD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14940 pso_num=25 pso_serial#=87 2025-07-23 21:55:31.372792 :B60F43BE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14940 osp_idx=23 osp_ver=211084 osp_pg=0 (spawn #415805) 2025-07-23 21:55:31.372793 :B60F43BF: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-23 21:55:31.372793 :B60F43C0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=3 time=1988507251 2025-07-23 21:55:31.372793 :B60F43C1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:55:31.372794 :B60F43C2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:55:31.372794 :B60F43C3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:55:31.372794 :B60F43C4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:55:31.372795 :B60F43C5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:55:31.373255 :B60F43C6: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-23 21:56:01.491955 :B60F4DA9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:56:31.469121 :B60F57DD:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:56:31.458 2025-07-23 21:56:31.469123 :B60F57DE:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19268 pso_num=25 pso_serial#=88 2025-07-23 21:56:31.469262 :B60F57DF:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19268 osp_idx=23 osp_ver=211085 osp_pg=0 (spawn #415808) 2025-07-23 21:56:31.469263 :B60F57E0: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-23 21:56:31.469263 :B60F57E1:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=4 time=1988567361 2025-07-23 21:56:31.469264 :B60F57E2:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:56:31.469264 :B60F57E3:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:56:31.469264 :B60F57E4:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:56:31.469265 :B60F57E5:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:56:31.469265 :B60F57E6:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:56:31.469746 :B60F57E7: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-23 21:57:01.538513 :B60F61BA:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:57:31.557495 :B60F6BAC:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:57:31.546 2025-07-23 21:57:31.557497 :B60F6BAD:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18200 pso_num=25 pso_serial#=89 2025-07-23 21:57:31.557617 :B60F6BAE:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=18200 osp_idx=23 osp_ver=211086 osp_pg=0 (spawn #415810) 2025-07-23 21:57:31.557617 :B60F6BAF: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-23 21:57:31.557618 :B60F6BB0:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=5 time=1988627439 2025-07-23 21:57:31.557618 :B60F6BB1:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:57:31.557618 :B60F6BB2:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:57:31.557619 :B60F6BB3:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:57:31.557619 :B60F6BB4:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:57:31.557619 :B60F6BB5:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:57:31.558117 :B60F6BB6: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-23 21:58:01.601658 :B60F75DE:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:58:31.641005 :B60F7FB4:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:58:31.630 2025-07-23 21:58:31.641007 :B60F7FB5:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16392 pso_num=25 pso_serial#=90 2025-07-23 21:58:31.641148 :B60F7FB6:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=16392 osp_idx=23 osp_ver=211087 osp_pg=0 (spawn #415812) 2025-07-23 21:58:31.641149 :B60F7FB7: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-23 21:58:31.641149 :B60F7FB8:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=6 time=1988687533 2025-07-23 21:58:31.641150 :B60F7FB9:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:58:31.641150 :B60F7FBA:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:58:31.641151 :B60F7FBB:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:58:31.641151 :B60F7FBC:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:58:31.641151 :B60F7FBD:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:58:31.641641 :B60F7FBE: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-23 21:59:01.694950 :B60F8982:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-07-23 21:59:31.743618 :B60F9587:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 07-23 21:59:31.733 2025-07-23 21:59:31.743620 :B60F9588:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=4152 pso_num=25 pso_serial#=91 2025-07-23 21:59:31.743771 :B60F9589:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=4152 osp_idx=23 osp_ver=211088 osp_pg=0 (spawn #415814) 2025-07-23 21:59:31.743771 :B60F958A: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-23 21:59:31.743772 :B60F958B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=7 time=1988747626 2025-07-23 21:59:31.743772 :B60F958C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-07-23 21:59:31.743772 :B60F958D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-07-23 21:59:31.743773 :B60F958E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-07-23 21:59:31.743773 :B60F958F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-07-23 21:59:31.743773 :B60F9590:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-07-23 21:59:31.744250 :B60F9591: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-23 22:00:01.777621 :B60FA0EB: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-23 22:00:01.777621*:B60FA113:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEC718 estart=1753279201 eid=16784734 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-23 22:00:01.777621*:B60FA114:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 pubTabIdxCnt=0 2025-07-23 22:00:01.777621*:B60FA115:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEC718 2025-07-23 22:00:01.777621*:B60FA116:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEC718 2025-07-23 22:00:01.777621*:B60FA125:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 xsc->flg4=65792 flags=2 2025-07-23 22:00:01.777621*:B60FA126:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEC718 2025-07-23 22:00:01.784534 :B60FA12E: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-23 22:00:01.784599 :B60FA131:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-23 22:00:01.796600 :B60FA1BE: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-23 22:00:01.802106 :B60FA2EC: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-23 22:00:01.802901 :B60FA2F4: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-23 22:00:01.808681 :B60FA305:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-07-23 22:00:01.808893 :B60FA314:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-07-23 22:00:01.809616 :B60FA33B: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-23 22:00:01.809843 :B60FA343:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-23 22:00:01.811290 :B60FA344: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-23 22:00:01.811329 :B60FA347: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-23 22:00:01.811429 :B60FA354: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-23 22:00:01.901997 :B60FA42B: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-23 22:00:01.904067 :B60FA42E: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-23 22:00:01.904107 :B60FA431:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-23 22:00:01.906539 :B60FA437:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-23 22:00:01.909826 :B60FA438: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-23 22:00:01.909914 :B60FA43B: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-23 22:00:01.910000 :B60FA448: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-23 22:00:04.011631 :B60FA888: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-23 22:00:04.011631*:B60FA88C:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEC718 estart=1753279204 eid=16784739 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-07-23 22:00:04.011631*:B60FA88D:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 pubTabIdxCnt=0 2025-07-23 22:00:04.011631*:B60FA88E:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEC718 2025-07-23 22:00:04.011631*:B60FA88F:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEC718 2025-07-23 22:00:04.011631*:B60FA890:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 xsc->flg4=65792 flags=2 2025-07-23 22:00:04.011631*:B60FA891:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEC718 2025-07-23 22:00:04.013809 :B60FA892: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-23 22:00:04.013847 :B60FA895:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-07-23 22:00:04.021607 :B60FA89B: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-23 22:00:04.022335 :B60FA8A3: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-23 22:00:04.023069 :B60FA8AB: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-23 22:00:04.023312 :B60FA8B3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-07-23 22:00:04.024885 :B60FA8B4: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-23 22:00:04.024936 :B60FA8B7: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-23 22:00:04.025001 :B60FA8C4: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 4152, J001)