Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250620220005\orcl_j001_16976_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:36446M/63366M, Ph+PgF:42847M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 16976, image: ORACLE.EXE (J001) *** 2025-06-20 22:00:05.276 *** SESSION ID:(193.22455) 2025-06-20 22:00:05.276 *** 2025-06-20 22:00:05.276 Process diagnostic dump for ORACLE.EXE (J001), OS id=16976, pid: 24, proc_ser: 166, sid: 193, sess_ser: 22455 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 16976 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.264033 sec, exc=0.264033 sec, total=0.264033 sec wait times: max=0.500000 sec, heur=4.721543 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=9 seq_num=10 snap_id=1 wait times: snap=0.502079 sec, exc=0.502079 sec, total=0.502079 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499218 sec, exc=0.499218 sec, total=0.499218 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.360131 sec, exc=0.360131 sec, total=0.360131 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.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.000005 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.500017 sec, exc=0.500017 sec, total=0.500017 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.499965 sec, exc=0.499965 sec, total=0.499965 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.501123 sec, exc=0.501123 sec, total=0.501123 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.499986 sec, exc=0.499986 sec, total=0.499986 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 snap_id=1 wait times: snap=0.499203 sec, exc=0.499203 sec, total=0.499203 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.095725 sec, exc=0.095725 sec, total=0.095725 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 193 serial 22455 --------------------------------------------------- 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:00 - 22:00:05] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-20 22:00:05.276 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 16976, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-20 21:47:39.372517 :A763BFB0:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:47:39.372517 :A763BFB1:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:47:39.372518 :A763BFB2:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:47:39.372518 :A763BFB3:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:47:39.372518 :A763BFB4:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:47:39.372984 :A763BFB5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:48:09.448433 :A763C961:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:48:39.462914 :A763D33B:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:48:39.451 2025-06-20 21:48:39.462915 :A763D33C:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=13812 pso_num=24 pso_serial#=155 2025-06-20 21:48:39.463048 :A763D33D:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=13812 osp_idx=22 osp_ver=438519 osp_pg=0 (spawn #305783) 2025-06-20 21:48:39.463049 :A763D33E:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:48:39.463050 :A763D33F:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=212 time=3431862641 2025-06-20 21:48:39.463050 :A763D340:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:48:39.463050 :A763D341:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:48:39.463051 :A763D342:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:48:39.463051 :A763D343:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:48:39.463052 :A763D344:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:48:39.463547 :A763D345:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:49:09.538566 :A763DE46:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:49:39.571749 :A763E827:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:49:39.560 2025-06-20 21:49:39.571751 :A763E828:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=17328 pso_num=24 pso_serial#=156 2025-06-20 21:49:39.571870 :A763E829:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=17328 osp_idx=22 osp_ver=438520 osp_pg=0 (spawn #305786) 2025-06-20 21:49:39.571871 :A763E82A:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:49:39.571871 :A763E82B:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=213 time=3431922750 2025-06-20 21:49:39.571872 :A763E82C:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:49:39.571872 :A763E82D:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:49:39.571873 :A763E82E:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:49:39.571873 :A763E82F:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:49:39.571874 :A763E830:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:49:39.572365 :A763E831:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:50:09.654506 :A763F202:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:50:39.647258 :A763FBB4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:50:39.635 2025-06-20 21:50:39.647260 :A763FBB5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=13928 pso_num=24 pso_serial#=157 2025-06-20 21:50:39.647380 :A763FBB6:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=13928 osp_idx=22 osp_ver=438521 osp_pg=0 (spawn #305788) 2025-06-20 21:50:39.647380 :A763FBB7:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:50:39.647381 :A763FBB8:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=214 time=3431982829 2025-06-20 21:50:39.647382 :A763FBB9:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:50:39.647382 :A763FBBA:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:50:39.647382 :A763FBBB:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:50:39.647383 :A763FBBC:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:50:39.647383 :A763FBBD:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:50:39.647929 :A763FBBE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:51:04.671153 :A76403BA:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 21:51:34.784938 :A7640DB4:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:51:39.737836 :A7640FA7:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:51:39.727 2025-06-20 21:51:39.737838 :A7640FA8:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=18016 pso_num=24 pso_serial#=158 2025-06-20 21:51:39.737958 :A7640FA9:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=18016 osp_idx=22 osp_ver=438522 osp_pg=0 (spawn #305791) 2025-06-20 21:51:39.737959 :A7640FAA:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:51:39.737959 :A7640FAB:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=215 time=3432042922 2025-06-20 21:51:39.737959 :A7640FAC:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:51:39.737960 :A7640FAD:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:51:39.737960 :A7640FAE:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:51:39.737961 :A7640FAF:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:51:39.737961 :A7640FB0:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:51:39.738450 :A7640FB1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:52:09.823638 :A7641A13:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:52:39.848986 :A764240B:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:52:39.837 2025-06-20 21:52:39.848988 :A764240C:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=3624 pso_num=24 pso_serial#=159 2025-06-20 21:52:39.849121 :A764240D:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=3624 osp_idx=22 osp_ver=438523 osp_pg=0 (spawn #305793) 2025-06-20 21:52:39.849122 :A764240E:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:52:39.849123 :A764240F:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=216 time=3432103032 2025-06-20 21:52:39.849123 :A7642410:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:52:39.849124 :A7642411:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:52:39.849124 :A7642412:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:52:39.849125 :A7642413:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:52:39.849126 :A7642414:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:52:39.849615 :A7642415:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:53:09.929145 :A7642DCD:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:53:39.946692 :A7643796:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:53:39.947 2025-06-20 21:53:39.946694 :A7643797:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=9064 pso_num=24 pso_serial#=160 2025-06-20 21:53:39.946839 :A7643798:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=9064 osp_idx=22 osp_ver=438524 osp_pg=0 (spawn #305795) 2025-06-20 21:53:39.946840 :A7643799:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:53:39.946841 :A764379A:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=217 time=3432163125 2025-06-20 21:53:39.946841 :A764379B:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:53:39.946842 :A764379C:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:53:39.946843 :A764379D:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:53:39.946843 :A764379E:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:53:39.946844 :A764379F:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:53:39.947325 :A76437A0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:54:10.034590 :A7644212:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:54:40.054048 :A7644BE4:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:54:40.043 2025-06-20 21:54:40.054050 :A7644BE5:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=15972 pso_num=24 pso_serial#=161 2025-06-20 21:54:40.054174 :A7644BE6:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=15972 osp_idx=22 osp_ver=438525 osp_pg=0 (spawn #305798) 2025-06-20 21:54:40.054175 :A7644BE7:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:54:40.054175 :A7644BE8:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=218 time=3432223235 2025-06-20 21:54:40.054175 :A7644BE9:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:54:40.054176 :A7644BEA:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:54:40.054176 :A7644BEB:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:54:40.054176 :A7644BEC:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:54:40.054177 :A7644BED:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:54:40.054724 :A7644BEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:55:10.147288 :A76455B4:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:55:40.165013 :A7645F7F:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:55:40.154 2025-06-20 21:55:40.165015 :A7645F80:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=17936 pso_num=24 pso_serial#=162 2025-06-20 21:55:40.165132 :A7645F81:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=17936 osp_idx=22 osp_ver=438526 osp_pg=0 (spawn #305800) 2025-06-20 21:55:40.165132 :A7645F82:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:55:40.165133 :A7645F83:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=219 time=3432283344 2025-06-20 21:55:40.165133 :A7645F84:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:55:40.165134 :A7645F85:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:55:40.165134 :A7645F86:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:55:40.165135 :A7645F87:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:55:40.165135 :A7645F88:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:55:40.165609 :A7645F89:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:56:10.229028 :A764694F:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:56:40.252349 :A7647305:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:56:40.241 2025-06-20 21:56:40.252351 :A7647306:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=4200 pso_num=24 pso_serial#=163 2025-06-20 21:56:40.252483 :A7647307:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=4200 osp_idx=22 osp_ver=438527 osp_pg=0 (spawn #305802) 2025-06-20 21:56:40.252484 :A7647308:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:56:40.252484 :A7647309:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=220 time=3432343438 2025-06-20 21:56:40.252484 :A764730A:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:56:40.252485 :A764730B:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:56:40.252485 :A764730C:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:56:40.252485 :A764730D:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:56:40.252485 :A764730E:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:56:40.252961 :A764730F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:57:10.347380 :A7647D51:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:57:40.357805 :A764873A:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:57:40.347 2025-06-20 21:57:40.357807 :A764873B:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=16212 pso_num=24 pso_serial#=164 2025-06-20 21:57:40.357924 :A764873C:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=16212 osp_idx=22 osp_ver=438528 osp_pg=0 (spawn #305804) 2025-06-20 21:57:40.357925 :A764873D:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:57:40.357925 :A764873E:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=221 time=3432403547 2025-06-20 21:57:40.357926 :A764873F:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:57:40.357926 :A7648740:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:57:40.357927 :A7648741:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:57:40.357927 :A7648742:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:57:40.357927 :A7648743:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:57:40.358400 :A7648744:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:58:10.461668 :A7649168:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:58:40.452695 :A7649B3D:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:58:40.441 2025-06-20 21:58:40.452697 :A7649B3E:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=14672 pso_num=24 pso_serial#=165 2025-06-20 21:58:40.452830 :A7649B3F:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=14672 osp_idx=22 osp_ver=438529 osp_pg=0 (spawn #305806) 2025-06-20 21:58:40.452830 :A7649B40:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:58:40.452831 :A7649B41:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=222 time=3432463641 2025-06-20 21:58:40.452831 :A7649B42:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:58:40.452832 :A7649B43:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:58:40.452832 :A7649B44:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:58:40.452832 :A7649B45:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:58:40.452833 :A7649B46:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:58:40.453298 :A7649B47:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 21:59:10.527790 :A764A5D1:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-06-20 21:59:40.524344 :A764AF56:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 06-20 21:59:40.513 2025-06-20 21:59:40.524347 :A764AF57:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=16976 pso_num=24 pso_serial#=166 2025-06-20 21:59:40.524484 :A764AF58:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=16976 osp_idx=22 osp_ver=438530 osp_pg=0 (spawn #305808) 2025-06-20 21:59:40.524485 :A764AF59:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-20 21:59:40.524485 :A764AF5A:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=223 time=3432523704 2025-06-20 21:59:40.524485 :A764AF5B:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-06-20 21:59:40.524486 :A764AF5C:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-06-20 21:59:40.524486 :A764AF5D:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-06-20 21:59:40.524486 :A764AF5E:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-20 21:59:40.524487 :A764AF5F:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-20 21:59:40.524965 :A764AF60:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.539220 :A764B78B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:00.539220*:A764B7B0:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000024D5B898 estart=1750427999 eid=16782700 ctx=0x000000077FD6A000 cwh=0x0000000024D50068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-06-20 22:00:00.539220*:A764B7B3:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000024D5B898 curCtx=0x0000000024D57AB8 pubTabIdxCnt=0 2025-06-20 22:00:00.539220*:A764B7B5:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000024D5B898 2025-06-20 22:00:00.539220*:A764B7B6:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000024D5B898 2025-06-20 22:00:00.539220*:A764B7CC:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000024D5B898 curCtx=0x0000000024D57AB8 xsc->flg4=65792 flags=2 2025-06-20 22:00:00.539220*:A764B7CD:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000024D5B898 2025-06-20 22:00:00.546090 :A764B7CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.546158 :A764B7D1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-06-20 22:00:00.551336 :A764B7FF:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-20 22:00:00.551913 :A764B800:db_trace:kcc.c@13684:kccwbp(): [10021:24:193:1] 0115000000000000 0115000000000000 bc13120000000000 2025-06-20 22:00:00.553615 :A764B801:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.553702 :A764B80E:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:00.553711 :A764B815:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-06-20 22:00:00.553718 :A764B816:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.553748 :A764B823:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:00.554427 :A764B82E:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 228984410) 2025-06-20 22:00:00.554432 :A764B82F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.554456 :A764B83B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:00.554464 :A764B847:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65560 1) 2025-06-20 22:00:00.554467 :A764B848:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.554496 :A764B854:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:00.554499 :A764B85F:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65560) 2025-06-20 22:00:00.554502 :A764B861:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.554551 :A764B882:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:00.555647 :A764B930:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:00.555680 :A764B938:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-06-20 22:00:00.556668 :A764B957:db_trace:kcc.c@13684:kccwbp(): [10021:24:193:1] 0115000000000000 0115000000000000 bd13120000000000 2025-06-20 22:00:00.557079 :A764B96D:db_trace:ksb.c@6610:ksbcic_int(): [10254:24:193] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 228984410) 2025-06-20 22:00:00.557084 :A764B96E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.557111 :A764B979:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:00.565699 :A764B9CA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-06-20 22:00:00.567383 :A764B9DB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.567476 :A764B9E4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:24:193] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-06-20 22:00:00.664035 :A764BB1B:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-20 22:00:04.024587 :A764BFFB:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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 24 (osid: 16976, J001)