Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250525220533\orcl_w000_10952_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:37298M/63366M, Ph+PgF:44303M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 26 Windows thread id: 10952, image: ORACLE.EXE (W000) *** 2025-05-25 22:05:33.137 *** SESSION ID:(209.64023) 2025-05-25 22:05:33.137 *** 2025-05-25 22:05:33.137 Process diagnostic dump for ORACLE.EXE (W000), OS id=10952, pid: 26, proc_ser: 15, sid: 209, sess_ser: 64023 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=2.680900 sec, exc=2.680900 sec, total=2.680900 sec wait times: max=5.000000 sec, heur=1 min 47 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.000024 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.011569 sec, exc=5.011569 sec, total=5.011569 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.009212 sec, exc=5.009212 sec, total=5.009212 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.010142 sec, exc=5.010142 sec, total=5.010142 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=5.014761 sec, exc=5.014761 sec, total=5.014761 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=5.004624 sec, exc=5.004624 sec, total=5.004624 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=5.001706 sec, exc=5.001706 sec, total=5.001706 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=5.013906 sec, exc=5.013906 sec, total=5.013906 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=5.013530 sec, exc=5.013530 sec, total=5.013530 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=5.010163 sec, exc=5.010163 sec, total=5.010163 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=5.009227 sec, exc=5.009227 sec, total=5.009227 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 209 serial 64023 --------------------------------------------------- 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 --------------------------------------------------- [108 samples, 22:03:45 - 22:05:33] idle wait at each sample [session created at: 22:03:45] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-25 22:05:33.137 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 26 (osid: 10952, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-25 21:13:38.441808 :9BF628E6:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-25 21:23:39.400188 :9BF6EE07:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:23:40.004947 :9BF6EE97:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:23:39.994 2025-05-25 21:23:40.004949 :9BF6EE98:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12492 pso_num=26 pso_serial#=2 2025-05-25 21:23:40.005083 :9BF6EE99:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12492 osp_idx=24 osp_ver=325637 osp_pg=0 (spawn #219075) 2025-05-25 21:23:40.005084 :9BF6EE9A:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:23:40.005084 :9BF6EE9B:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=126 time=1183992250 2025-05-25 21:23:40.005085 :9BF6EE9C:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:23:40.005085 :9BF6EE9D:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:23:40.005085 :9BF6EE9E:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:23:40.005085 :9BF6EE9F:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:23:40.005086 :9BF6EEA0:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:23:40.005555 :9BF6EEA1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:24:10.077040 :9BF6F82D:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:24:40.102077 :9BF701EE:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:24:40.091 2025-05-25 21:24:40.102079 :9BF701EF:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10320 pso_num=26 pso_serial#=3 2025-05-25 21:24:40.102199 :9BF701F0:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10320 osp_idx=24 osp_ver=325638 osp_pg=0 (spawn #219077) 2025-05-25 21:24:40.102200 :9BF701F1:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:24:40.102200 :9BF701F2:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=127 time=1184052344 2025-05-25 21:24:40.102201 :9BF701F3:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:24:40.102201 :9BF701F4:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:24:40.102201 :9BF701F5:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:24:40.102202 :9BF701F6:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:24:40.102202 :9BF701F7:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:24:40.102697 :9BF701F8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:25:10.190529 :9BF70B8B:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:25:15.155781 :9BF70D63:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:25:15.145 2025-05-25 21:25:15.155784 :9BF70D64:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13504 pso_num=26 pso_serial#=4 2025-05-25 21:25:15.155925 :9BF70D65:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13504 osp_idx=24 osp_ver=325639 osp_pg=0 (spawn #219079) 2025-05-25 21:25:15.155925 :9BF70D66:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:25:15.155926 :9BF70D67:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=128 time=1184087407 2025-05-25 21:25:15.155926 :9BF70D68:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:25:15.155927 :9BF70D69:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:25:15.155927 :9BF70D6A:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:25:15.155927 :9BF70D6B:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:25:15.155928 :9BF70D6C:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:25:15.156418 :9BF70D6D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:25:40.170383 :9BF7158C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 21:26:10.228818 :9BF71F07:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:26:40.263132 :9BF72890:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:26:40.251 2025-05-25 21:26:40.263133 :9BF72891:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14808 pso_num=26 pso_serial#=5 2025-05-25 21:26:40.263272 :9BF72892:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14808 osp_idx=24 osp_ver=325640 osp_pg=0 (spawn #219082) 2025-05-25 21:26:40.263273 :9BF72893:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:26:40.263273 :9BF72894:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=129 time=1184172516 2025-05-25 21:26:40.263273 :9BF72895:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:26:40.263274 :9BF72896:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:26:40.263274 :9BF72897:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:26:40.263274 :9BF72898:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:26:40.263275 :9BF72899:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:26:40.263785 :9BF7289A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:27:10.385186 :9BF73310:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:27:40.381387 :9BF73CAC:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:27:40.370 2025-05-25 21:27:40.381390 :9BF73CAD:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14248 pso_num=26 pso_serial#=6 2025-05-25 21:27:40.381524 :9BF73CAE:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14248 osp_idx=24 osp_ver=325641 osp_pg=0 (spawn #219084) 2025-05-25 21:27:40.381525 :9BF73CAF:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:27:40.381525 :9BF73CB0:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=130 time=1184232625 2025-05-25 21:27:40.381525 :9BF73CB1:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:27:40.381526 :9BF73CB2:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:27:40.381526 :9BF73CB3:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:27:40.381526 :9BF73CB4:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:27:40.381527 :9BF73CB5:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:27:40.382001 :9BF73CB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:28:10.474772 :9BF74629:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:28:40.492762 :9BF74FA0:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:28:40.482 2025-05-25 21:28:40.492764 :9BF74FA1:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14824 pso_num=26 pso_serial#=7 2025-05-25 21:28:40.492897 :9BF74FA2:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14824 osp_idx=24 osp_ver=325642 osp_pg=0 (spawn #219086) 2025-05-25 21:28:40.492897 :9BF74FA3:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:28:40.492898 :9BF74FA4:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=131 time=1184292735 2025-05-25 21:28:40.492898 :9BF74FA5:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:28:40.492899 :9BF74FA6:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:28:40.492899 :9BF74FA7:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:28:40.492899 :9BF74FA8:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:28:40.492900 :9BF74FA9:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:28:40.493397 :9BF74FAA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:29:10.623429 :9BF75984:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:29:40.597864 :9BF76309:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:29:40.586 2025-05-25 21:29:40.597866 :9BF7630A:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14796 pso_num=26 pso_serial#=8 2025-05-25 21:29:40.597986 :9BF7630B:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14796 osp_idx=24 osp_ver=325643 osp_pg=0 (spawn #219088) 2025-05-25 21:29:40.597987 :9BF7630C:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:29:40.597989 :9BF7630D:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=132 time=1184352844 2025-05-25 21:29:40.597989 :9BF7630E:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:29:40.597989 :9BF7630F:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:29:40.597990 :9BF76310:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:29:40.597990 :9BF76311:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:29:40.597990 :9BF76312:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:29:40.598460 :9BF76313:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:30:10.671301 :9BF76D5E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:30:16.336308 :9BF76F6F:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:30:16.326 2025-05-25 21:30:16.336310 :9BF76F70:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13660 pso_num=26 pso_serial#=9 2025-05-25 21:30:16.336476 :9BF76F71:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13660 osp_idx=24 osp_ver=325644 osp_pg=0 (spawn #219090) 2025-05-25 21:30:16.336477 :9BF76F72:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:30:16.336478 :9BF76F73:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=133 time=1184388579 2025-05-25 21:30:16.336478 :9BF76F74:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:30:16.336479 :9BF76F75:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:30:16.336479 :9BF76F76:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:30:16.336480 :9BF76F77:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:30:16.336480 :9BF76F78:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:30:16.336973 :9BF76F7D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:30:40.687463 :9BF77768:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 21:30:40.687494*:9BF77769:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000271DBB58 estart=1748179840 eid=16877837 ctx=0x000000077BD98A08 cwh=0x00000000271901B0 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-25 21:30:40.687494*:9BF7776A:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000271DBB58 curCtx=0x000000002719F708 pubTabIdxCnt=0 2025-05-25 21:30:40.687494*:9BF7776B:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000271DBB58 2025-05-25 21:30:40.687494*:9BF7776C:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000271DBB58 2025-05-25 21:30:40.687494*:9BF7776D:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000271DBB58 curCtx=0x000000002719F708 xsc->flg4=65792 flags=2 2025-05-25 21:30:40.687494*:9BF7776E:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000271DBB58 2025-05-25 21:30:40.688112 :9BF7776F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 21:30:40.699242 :9BF77777:db_trace:kwqid.c@2146:kwqidrdq(): [10960:26:209] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-25 21:30:40.699708 :9BF77778:db_trace:kwqid.c@2146:kwqidrdq(): [10960:26:209] kwqidrdq: Error: 1403 occured in OCI execute 2025-05-25 21:30:40.702093 :9BF77779:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpus:psdpgi.c:2235 2025-05-25 21:30:40.702482 :9BF7777A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 21:30:40.702517 :9BF7777D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:26:209] atxpop:psdpgi.c:2235 2025-05-25 21:30:40.703404 :9BF77783:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-25 21:30:40.703528 :9BF7778C:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] 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-05-25 21:31:10.796595 :9BF780CE:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:31:40.803065 :9BF78A71:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:31:40.792 2025-05-25 21:31:40.803067 :9BF78A72:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=15100 pso_num=26 pso_serial#=10 2025-05-25 21:31:40.803187 :9BF78A73:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=15100 osp_idx=24 osp_ver=325645 osp_pg=0 (spawn #219093) 2025-05-25 21:31:40.803188 :9BF78A74:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:31:40.803188 :9BF78A75:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=134 time=1184473047 2025-05-25 21:31:40.803189 :9BF78A76:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:31:40.803189 :9BF78A77:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:31:40.803190 :9BF78A78:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:31:40.803190 :9BF78A79:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:31:40.803191 :9BF78A7A:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:31:40.803666 :9BF78A7B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:32:10.865939 :9BF7948E:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:32:40.899546 :9BF79E0E:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:32:40.888 2025-05-25 21:32:40.899548 :9BF79E0F:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=13244 pso_num=26 pso_serial#=11 2025-05-25 21:32:40.899679 :9BF79E10:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=13244 osp_idx=24 osp_ver=325646 osp_pg=0 (spawn #219095) 2025-05-25 21:32:40.899679 :9BF79E11:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:32:40.899680 :9BF79E12:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=135 time=1184533141 2025-05-25 21:32:40.899680 :9BF79E13:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:32:40.899680 :9BF79E14:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:32:40.899681 :9BF79E15:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:32:40.899681 :9BF79E16:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:32:40.899681 :9BF79E17:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:32:40.900175 :9BF79E18:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:33:10.984118 :9BF7A7B0:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:33:41.277986 :9BF7B198:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:33:41.273 2025-05-25 21:33:41.277988 :9BF7B199:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14380 pso_num=26 pso_serial#=12 2025-05-25 21:33:41.278129 :9BF7B19A:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14380 osp_idx=24 osp_ver=325647 osp_pg=0 (spawn #219098) 2025-05-25 21:33:41.278130 :9BF7B19B:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:33:41.278130 :9BF7B19C:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=136 time=1184593532 2025-05-25 21:33:41.278130 :9BF7B19D:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:33:41.278130 :9BF7B19E:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:33:41.278131 :9BF7B19F:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:33:41.278131 :9BF7B1A0:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:33:41.278131 :9BF7B1A1:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:33:41.278629 :9BF7B1A2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:33:41.278677 :9BF7B1AA:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 21:43:42.195124 :9BF874E3:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:43:42.746563 :9BF8751D:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:43:42.742 2025-05-25 21:43:42.746565 :9BF8751E:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=14784 pso_num=26 pso_serial#=13 2025-05-25 21:43:42.746699 :9BF8751F:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=14784 osp_idx=24 osp_ver=325648 osp_pg=0 (spawn #219120) 2025-05-25 21:43:42.746700 :9BF87520:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:43:42.746700 :9BF87521:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=137 time=1185195000 2025-05-25 21:43:42.746700 :9BF87522:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:43:42.746701 :9BF87523:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:43:42.746701 :9BF87524:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:43:42.746701 :9BF87525:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:43:42.746702 :9BF87526:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:43:42.747188 :9BF87527:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:43:42.747234 :9BF8752E:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 21:53:43.633547 :9BF93768:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 21:53:44.028831 :9BF937AA:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 21:53:44.024 2025-05-25 21:53:44.028833 :9BF937AB:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=12736 pso_num=26 pso_serial#=14 2025-05-25 21:53:44.028971 :9BF937AC:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=12736 osp_idx=24 osp_ver=325649 osp_pg=0 (spawn #219143) 2025-05-25 21:53:44.028972 :9BF937AD:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 21:53:44.028972 :9BF937AE:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=138 time=1185796282 2025-05-25 21:53:44.028972 :9BF937AF:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 21:53:44.028973 :9BF937B0:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 21:53:44.028974 :9BF937B1:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 21:53:44.028974 :9BF937B2:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 21:53:44.028974 :9BF937B3:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 21:53:44.029491 :9BF937B4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 21:53:44.029538 :9BF937BB:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-25 22:03:44.890062 :9BF9FD68:db_trace:kst.c@698:kstpsodel(): [10280:26:0] kst: process state object about to be deleted 2025-05-25 22:03:45.285413 :9BF9FDA1:db_trace:kst.c@673:kstipg(): [10280:26:0] kst: process state object created on 05-25 22:03:45.281 2025-05-25 22:03:45.285415 :9BF9FDA2:db_trace:kst.c@679:kstipg(): [10280:26:0] kst: process info: ospid=10952 pso_num=26 pso_serial#=15 2025-05-25 22:03:45.285556 :9BF9FDA3:db_trace:kso.c@4093:ksonfy(): [10420:26:0] kso: new process: pid=10952 osp_idx=24 osp_ver=325650 osp_pg=0 (spawn #219169) 2025-05-25 22:03:45.285556 :9BF9FDA4:db_trace:kso.c@4099:ksonfy(): [10420:26:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-25 22:03:45.285557 :9BF9FDA5:db_trace:kso.c@4103:ksonfy(): [10420:26:0] kso: new process: pso_index=26 reservation=139 time=1186397547 2025-05-25 22:03:45.285557 :9BF9FDA6:db_trace:kso.c@4109:ksonfy(): [10420:26:0] kso: spawn diagnostics: queue time=0 secs 2025-05-25 22:03:45.285557 :9BF9FDA7:db_trace:kso.c@4111:ksonfy(): [10420:26:0] kso: spawn diagnostics: fork time=0 secs 2025-05-25 22:03:45.285558 :9BF9FDA8:db_trace:kso.c@4113:ksonfy(): [10420:26:0] kso: spawn diagnostics: exec time=0 secs 2025-05-25 22:03:45.285558 :9BF9FDA9:db_trace:kso.c@4115:ksonfy(): [10420:26:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-25 22:03:45.285558 :9BF9FDAA:db_trace:kso.c@4117:ksonfy(): [10420:26:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-25 22:03:45.286045 :9BF9FDAB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:26:209] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-25 22:03:45.286088 :9BF9FDB2:db_trace:ksl2.c@12699:ksliwat(): [10005:26:209] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 26 (osid: 10952, W000)