Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250826220006\orcl_j001_19388_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:35166M/63366M, Ph+PgF:40208M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 19388, image: ORACLE.EXE (J001) *** 2025-08-26 22:00:07.060 *** SESSION ID:(201.49903) 2025-08-26 22:00:07.060 *** 2025-08-26 22:00:07.060 Process diagnostic dump for ORACLE.EXE (J001), OS id=19388, pid: 25, proc_ser: 93, sid: 201, sess_ser: 49903 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 19388 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.038235 sec, exc=0.038235 sec, total=0.038235 sec wait times: max=0.500000 sec, heur=6.266492 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.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 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.000009 sec of elapsed time 1: 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.000009 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.500015 sec, exc=0.500015 sec, total=0.500015 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=10 seq_num=11 snap_id=1 wait times: snap=0.505099 sec, exc=0.505099 sec, total=0.505099 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=9 seq_num=10 snap_id=1 wait times: snap=0.499988 sec, exc=0.499988 sec, total=0.499988 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499152 sec, exc=0.499152 sec, total=0.499152 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.125854 sec, exc=0.125854 sec, total=0.125854 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.499991 sec, exc=0.499991 sec, total=0.499991 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.502099 sec, exc=0.502099 sec, total=0.502099 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time Sampled Session History of session 201 serial 49903 --------------------------------------------------- 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 --------------------------------------------------- [7 samples, 22:00:00 - 22:00:07] 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-08-26 22:00:07.060 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 19388, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-26 21:47:54.703086 :C50E0FA8:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:47:54.703087 :C50E0FA9:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:47:54.703087 :C50E0FAA:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:47:54.703573 :C50E0FAB: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-08-26 21:48:24.809676 :C50E1905:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:48:54.826482 :C50E2290:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:48:54.815 2025-08-26 21:48:54.826484 :C50E2291:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=12820 pso_num=25 pso_serial#=82 2025-08-26 21:48:54.826602 :C50E2292:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=12820 osp_idx=23 osp_ver=260549 osp_pg=0 (spawn #529135) 2025-08-26 21:48:54.826603 :C50E2293:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:48:54.826603 :C50E2294:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=140 time=630589565 2025-08-26 21:48:54.826604 :C50E2295:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:48:54.826604 :C50E2296:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:48:54.826605 :C50E2297:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:48:54.826605 :C50E2298:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:48:54.826605 :C50E2299:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:48:54.827090 :C50E229A: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-08-26 21:49:24.905753 :C50E2D0E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:49:54.906799 :C50E363C:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:49:54.896 2025-08-26 21:49:54.906802 :C50E363D:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23136 pso_num=25 pso_serial#=83 2025-08-26 21:49:54.906944 :C50E363E:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23136 osp_idx=23 osp_ver=260550 osp_pg=0 (spawn #529137) 2025-08-26 21:49:54.906945 :C50E363F:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:49:54.906945 :C50E3640:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=141 time=630649643 2025-08-26 21:49:54.906946 :C50E3641:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:49:54.906946 :C50E3642:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:49:54.906946 :C50E3643:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:49:54.906947 :C50E3644:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:49:54.906947 :C50E3645:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:49:54.907417 :C50E3646: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-08-26 21:50:24.980585 :C50E3FDD:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:50:55.000692 :C50E492D:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:50:54.989 2025-08-26 21:50:55.000694 :C50E492E:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21000 pso_num=25 pso_serial#=84 2025-08-26 21:50:55.000825 :C50E492F:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21000 osp_idx=23 osp_ver=260551 osp_pg=0 (spawn #529139) 2025-08-26 21:50:55.000825 :C50E4930:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:50:55.000826 :C50E4931:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=142 time=630709737 2025-08-26 21:50:55.000826 :C50E4932:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:50:55.000827 :C50E4933:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:50:55.000827 :C50E4934:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:50:55.000827 :C50E4935:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:50:55.000828 :C50E4936:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:50:55.001307 :C50E4937: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-08-26 21:51:25.069194 :C50E52C3:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:51:55.094060 :C50E5C07:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:51:55.083 2025-08-26 21:51:55.094062 :C50E5C08:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23040 pso_num=25 pso_serial#=85 2025-08-26 21:51:55.094193 :C50E5C09:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23040 osp_idx=23 osp_ver=260552 osp_pg=0 (spawn #529141) 2025-08-26 21:51:55.094193 :C50E5C0A:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:51:55.094194 :C50E5C0B:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=143 time=630769830 2025-08-26 21:51:55.094194 :C50E5C0C:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:51:55.094195 :C50E5C0D:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:51:55.094195 :C50E5C0E:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:51:55.094195 :C50E5C0F:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:51:55.094195 :C50E5C10:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:51:55.094663 :C50E5C11: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-08-26 21:52:25.125913 :C50E6652:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:52:55.183508 :C50E6FA0:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:52:55.171 2025-08-26 21:52:55.183510 :C50E6FA1:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22484 pso_num=25 pso_serial#=86 2025-08-26 21:52:55.183630 :C50E6FA2:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22484 osp_idx=23 osp_ver=260553 osp_pg=0 (spawn #529144) 2025-08-26 21:52:55.183631 :C50E6FA3:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:52:55.183632 :C50E6FA4:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=144 time=630829908 2025-08-26 21:52:55.183632 :C50E6FA5:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:52:55.183633 :C50E6FA6:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:52:55.183633 :C50E6FA7:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:52:55.183633 :C50E6FA8:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:52:55.183634 :C50E6FA9:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:52:55.184118 :C50E6FAA: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-08-26 21:53:25.221014 :C50E791A:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:53:55.247511 :C50E82E3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:53:55.236 2025-08-26 21:53:55.247513 :C50E82E4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21968 pso_num=25 pso_serial#=87 2025-08-26 21:53:55.247645 :C50E82E5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21968 osp_idx=23 osp_ver=260554 osp_pg=0 (spawn #529146) 2025-08-26 21:53:55.247646 :C50E82E6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:53:55.247646 :C50E82E7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=145 time=630889987 2025-08-26 21:53:55.247646 :C50E82E8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:53:55.247647 :C50E82E9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:53:55.247647 :C50E82EA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:53:55.247648 :C50E82EB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:53:55.247648 :C50E82EC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:53:55.248126 :C50E82ED: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-08-26 21:54:25.321115 :C50E8CAB:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:54:55.332650 :C50E960F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:54:55.321 2025-08-26 21:54:55.332652 :C50E9610:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15000 pso_num=25 pso_serial#=88 2025-08-26 21:54:55.332774 :C50E9611:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=15000 osp_idx=23 osp_ver=260555 osp_pg=0 (spawn #529148) 2025-08-26 21:54:55.332775 :C50E9612:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:54:55.332775 :C50E9613:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=146 time=630950065 2025-08-26 21:54:55.332776 :C50E9614:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:54:55.332776 :C50E9615:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:54:55.332777 :C50E9616:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:54:55.332777 :C50E9617:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:54:55.332777 :C50E9618:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:54:55.333293 :C50E9619: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-08-26 21:55:25.421372 :C50E9F59:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:55:40.394521 :C50EA41F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:55:40.383 2025-08-26 21:55:40.394523 :C50EA420:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=23080 pso_num=25 pso_serial#=89 2025-08-26 21:55:40.394658 :C50EA421:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=23080 osp_idx=23 osp_ver=260556 osp_pg=0 (spawn #529150) 2025-08-26 21:55:40.394659 :C50EA422:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:55:40.394659 :C50EA423:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=147 time=630995127 2025-08-26 21:55:40.394660 :C50EA424:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:55:40.394660 :C50EA425:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:55:40.394661 :C50EA426:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:55:40.394661 :C50EA427:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:55:40.394661 :C50EA428:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:55:40.395152 :C50EA429: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-08-26 21:55:55.403601 :C50EA8AF: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-08-26 21:56:25.499690 :C50EB211:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:56:55.494700 :C50EBB80:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:56:55.483 2025-08-26 21:56:55.494702 :C50EBB81:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=22680 pso_num=25 pso_serial#=90 2025-08-26 21:56:55.494837 :C50EBB82:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=22680 osp_idx=23 osp_ver=260557 osp_pg=0 (spawn #529152) 2025-08-26 21:56:55.494838 :C50EBB83:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:56:55.494838 :C50EBB84:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=148 time=631070221 2025-08-26 21:56:55.494839 :C50EBB85:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:56:55.494839 :C50EBB86:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:56:55.494840 :C50EBB87:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:56:55.494840 :C50EBB88:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:56:55.494841 :C50EBB89:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:56:55.495320 :C50EBB8A: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-08-26 21:57:25.578387 :C50EC507:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:57:55.593380 :C50ECE94:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:57:55.582 2025-08-26 21:57:55.593382 :C50ECE95:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21948 pso_num=25 pso_serial#=91 2025-08-26 21:57:55.593519 :C50ECE96:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21948 osp_idx=23 osp_ver=260558 osp_pg=0 (spawn #529154) 2025-08-26 21:57:55.593520 :C50ECE97:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:57:55.593520 :C50ECE98:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=149 time=631130330 2025-08-26 21:57:55.593521 :C50ECE99:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:57:55.593521 :C50ECE9A:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:57:55.593522 :C50ECE9B:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:57:55.593522 :C50ECE9C:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:57:55.593522 :C50ECE9D:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:57:55.594022 :C50ECE9E: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-08-26 21:58:25.666040 :C50ED7D9:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:58:55.703928 :C50EE1AA:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:58:55.692 2025-08-26 21:58:55.703930 :C50EE1AB:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=21492 pso_num=25 pso_serial#=92 2025-08-26 21:58:55.704058 :C50EE1AC:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=21492 osp_idx=23 osp_ver=260559 osp_pg=0 (spawn #529156) 2025-08-26 21:58:55.704059 :C50EE1AD:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:58:55.704060 :C50EE1AE:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=150 time=631190440 2025-08-26 21:58:55.704060 :C50EE1AF:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:58:55.704061 :C50EE1B0:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:58:55.704061 :C50EE1B1:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:58:55.704061 :C50EE1B2:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:58:55.704062 :C50EE1B3:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:58:55.704582 :C50EE1B4: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-08-26 21:59:25.794190 :C50EEC07:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-08-26 21:59:55.784792 :C50EF59E:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 08-26 21:59:55.774 2025-08-26 21:59:55.784793 :C50EF59F:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=19388 pso_num=25 pso_serial#=93 2025-08-26 21:59:55.784913 :C50EF5A0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=19388 osp_idx=23 osp_ver=260560 osp_pg=0 (spawn #529158) 2025-08-26 21:59:55.784913 :C50EF5A1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-26 21:59:55.784914 :C50EF5A2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=151 time=631250518 2025-08-26 21:59:55.784914 :C50EF5A3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-08-26 21:59:55.784915 :C50EF5A4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-08-26 21:59:55.784915 :C50EF5A5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-08-26 21:59:55.784915 :C50EF5A6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-26 21:59:55.784916 :C50EF5A7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-26 21:59:55.785403 :C50EF5A8: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-08-26 22:00:00.772097 :C50EF86D: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-08-26 22:00:00.772097*:C50EF898:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEB898 estart=1756216800 eid=16786827 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-08-26 22:00:00.772097*:C50EF89A:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 pubTabIdxCnt=0 2025-08-26 22:00:00.772097*:C50EF89C:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEB898 2025-08-26 22:00:00.772097*:C50EF89D:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEB898 2025-08-26 22:00:00.772097*:C50EF8AE:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEB898 curCtx=0x0000000026BE7AB8 xsc->flg4=65792 flags=2 2025-08-26 22:00:00.772097*:C50EF8AF:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEB898 2025-08-26 22:00:00.779086 :C50EF8B0: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-08-26 22:00:00.779150 :C50EF8B3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-08-26 22:00:00.784346 :C50EF8E1:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-08-26 22:00:00.784918 :C50EF8E2:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 5099120000000000 2025-08-26 22:00:00.786525 :C50EF8E3: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-08-26 22:00:00.786621 :C50EF8F0: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-08-26 22:00:00.786632 :C50EF8F7:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-08-26 22:00:00.786640 :C50EF8F8: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-08-26 22:00:00.786673 :C50EF905: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-08-26 22:00:00.787477 :C50EF910:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 235639574) 2025-08-26 22:00:00.787483 :C50EF911: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-08-26 22:00:00.787508 :C50EF91C: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-08-26 22:00:00.787518 :C50EF929:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65561 1) 2025-08-26 22:00:00.787521 :C50EF92A: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-08-26 22:00:00.787554 :C50EF936: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-08-26 22:00:00.787558 :C50EF93D:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65561) 2025-08-26 22:00:00.787561 :C50EF942: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-08-26 22:00:00.787607 :C50EF964: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-08-26 22:00:00.788546 :C50EFA37: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-08-26 22:00:00.788561 :C50EFA38:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-08-26 22:00:00.789411 :C50EFA56:db_trace:kcc.c@13684:kccwbp(): [10021:25:201:1] 0115000000000000 0115000000000000 5199120000000000 2025-08-26 22:00:00.789782 :C50EFA6C:db_trace:ksb.c@6610:ksbcic_int(): [10254:25:201] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 235639574) 2025-08-26 22:00:00.789787 :C50EFA6D: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-08-26 22:00:00.789814 :C50EFA78: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-08-26 22:00:00.798550 :C50EFABF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:jslv.c:9203 2025-08-26 22:00:00.800194 :C50EFAD3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-08-26 22:00:00.800233 :C50EFAD5: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-08-26 22:00:00.800273 :C50EFADD: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-08-26 22:00:00.800374 :C50EFAEC: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-08-26 22:00:00.896773 :C50EFBF8: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-08-26 22:00:04.025287 :C50F009F: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: 19388, J001)