Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250504060008\orcl_j001_12128_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:37549M/63366M, Ph+PgF:45030M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 24 Windows thread id: 12128, image: ORACLE.EXE (J001) *** 2025-05-04 06:00:08.823 *** SESSION ID:(193.53321) 2025-05-04 06:00:08.823 *** 2025-05-04 06:00:08.823 Process diagnostic dump for ORACLE.EXE (J001), OS id=12128, pid: 24, proc_ser: 130, sid: 193, sess_ser: 53321 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12128 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J001) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.045367 sec, exc=0.045367 sec, total=0.045367 sec wait times: max=0.500000 sec, heur=4.548201 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.000007 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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.000011 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.499985 sec, exc=0.499985 sec, total=0.499985 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.510116 sec, exc=0.510116 sec, total=0.510116 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.500002 sec, exc=0.500002 sec, total=0.500002 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.499990 sec, exc=0.499990 sec, total=0.499990 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000015 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=2 seq_num=3 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=1 seq_num=2 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 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=0 seq_num=1 snap_id=1 wait times: snap=0.492667 sec, exc=0.492667 sec, total=0.492667 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 53321 --------------------------------------------------- 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, 06:00:04 - 06:00:08] idle wait at each sample [session created at: 06:00:04] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-04 06:00:08.823 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 24 (osid: 12128, J001) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-04 05:52:54.030662 :9271EE65:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-04 05:52:54.030663 :9271EE66:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=170 time=3608751187 2025-05-04 05:52:54.030663 :9271EE67:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:52:54.030663 :9271EE68:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:52:54.030664 :9271EE69:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:52:54.030664 :9271EE6A:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:52:54.030664 :9271EE6B:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:52:54.031201 :9271EE6C: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-05-04 05:53:24.093177 :9271F853:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-04 05:53:54.094983 :92720284:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-04 05:53:54.084 2025-05-04 05:53:54.094985 :92720285:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12136 pso_num=24 pso_serial#=123 2025-05-04 05:53:54.095119 :92720286:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=12136 osp_idx=22 osp_ver=221462 osp_pg=0 (spawn #146450) 2025-05-04 05:53:54.095120 :92720287:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-04 05:53:54.095120 :92720288:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=171 time=3608811250 2025-05-04 05:53:54.095121 :92720289:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:53:54.095121 :9272028A:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:53:54.095121 :9272028B:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:53:54.095122 :9272028C:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:53:54.095122 :9272028D:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:53:54.095603 :9272028E: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-05-04 05:54:24.201395 :92720C77:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-04 05:54:54.186242 :9272166C:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-04 05:54:54.174 2025-05-04 05:54:54.186244 :9272166D:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=10352 pso_num=24 pso_serial#=124 2025-05-04 05:54:54.186378 :9272166E:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=10352 osp_idx=22 osp_ver=221463 osp_pg=0 (spawn #146453) 2025-05-04 05:54:54.186379 :9272166F:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-04 05:54:54.186379 :92721670:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=172 time=3608871343 2025-05-04 05:54:54.186380 :92721671:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:54:54.186380 :92721672:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:54:54.186380 :92721673:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:54:54.186381 :92721674:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:54:54.186381 :92721675:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:54:54.186844 :92721676: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-05-04 05:55:24.291530 :92722068:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-04 05:55:24.320035 :9272206B:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-04 05:55:24.307 2025-05-04 05:55:24.320037 :9272206C:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=11984 pso_num=24 pso_serial#=125 2025-05-04 05:55:24.320175 :9272206D:db_trace:kso.c@4070:ksonfy(): [10420:24:0] kso: new process: pid=11984 (legacy spawn) 2025-05-04 05:55:24.327701 :92722071: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-05-04 05:55:24.327873 :92722076:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] 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-04 05:55:24.328693 :9272207B:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-04 05:55:49.288558 :927228E7:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-04 05:55:49.277 2025-05-04 05:55:49.288560 :927228E8:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=8168 pso_num=24 pso_serial#=126 2025-05-04 05:55:49.288693 :927228E9:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=8168 osp_idx=22 osp_ver=221465 osp_pg=0 (spawn #146455) 2025-05-04 05:55:49.288694 :927228EA:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-04 05:55:49.288695 :927228EB:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=173 time=3608926453 2025-05-04 05:55:49.288695 :927228EC:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:55:49.288695 :927228ED:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:55:49.288696 :927228EE:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:55:49.288696 :927228EF:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:55:49.288696 :927228F0:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:55:49.289168 :927228F1: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-05-04 05:55:54.294194 :92722A68: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-05-04 05:56:24.390502 :92723448:db_trace:ksl2.c@2324:kslwtbctx(): [10005:24:0] KSL WAIT BEG [latch: call allocation] 136410064/0x82173d0 10/0xa 0/0x0 wait_id=0 seq_num=0 snap_id=0 2025-05-04 05:56:24.390528 :92723449:db_trace:ksl2.c@2611:kslwtectx(): [10005:24:0] KSL WAIT END [latch: call allocation] 136410064/0x82173d0 10/0xa 0/0x0 wait_id=0 seq_num=0 snap_id=0 2025-05-04 05:56:24.390531 :9272344A:db_trace:ksl2.c@2619:kslwtectx(): [10005:24:0] KSL WAIT END wait times (usecs) - snap=24, exc=24, tot=24 2025-05-04 05:56:24.390694 :9272344B:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-04 05:56:54.388998 :92723E46:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-04 05:56:54.377 2025-05-04 05:56:54.389000 :92723E47:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=8768 pso_num=24 pso_serial#=127 2025-05-04 05:56:54.389135 :92723E48:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=8768 osp_idx=22 osp_ver=221466 osp_pg=0 (spawn #146457) 2025-05-04 05:56:54.389136 :92723E49:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-04 05:56:54.389137 :92723E4A:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=174 time=3608991546 2025-05-04 05:56:54.389137 :92723E4B:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:56:54.389138 :92723E4C:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:56:54.389138 :92723E4D:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:56:54.389139 :92723E4E:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:56:54.389139 :92723E4F:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:56:54.389688 :92723E50: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-05-04 05:57:24.457513 :9272490C:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-04 05:57:54.458564 :92725328:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-04 05:57:54.448 2025-05-04 05:57:54.458566 :92725329:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=8760 pso_num=24 pso_serial#=128 2025-05-04 05:57:54.458703 :9272532A:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=8760 osp_idx=22 osp_ver=221467 osp_pg=0 (spawn #146459) 2025-05-04 05:57:54.458704 :9272532B:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-04 05:57:54.458704 :9272532C:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=175 time=3609051625 2025-05-04 05:57:54.458705 :9272532D:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:57:54.458705 :9272532E:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:57:54.458706 :9272532F:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:57:54.458706 :92725330:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:57:54.458706 :92725331:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:57:54.459207 :92725332: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-05-04 05:58:24.529983 :92725CD6:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-04 05:58:54.534831 :92726742:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-04 05:58:54.523 2025-05-04 05:58:54.534833 :92726743:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=7880 pso_num=24 pso_serial#=129 2025-05-04 05:58:54.534968 :92726744:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=7880 osp_idx=22 osp_ver=221468 osp_pg=0 (spawn #146461) 2025-05-04 05:58:54.534969 :92726745:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-04 05:58:54.534969 :92726746:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=176 time=3609111687 2025-05-04 05:58:54.534970 :92726747:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:58:54.534970 :92726748:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:58:54.534971 :92726749:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:58:54.534971 :9272674A:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:58:54.534971 :9272674B:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:58:54.535483 :9272674C: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-05-04 05:59:24.625100 :9272710A:db_trace:kst.c@698:kstpsodel(): [10280:24:0] kst: process state object about to be deleted 2025-05-04 05:59:54.622763 :92727B1B:db_trace:kst.c@673:kstipg(): [10280:24:0] kst: process state object created on 05-04 05:59:54.612 2025-05-04 05:59:54.622766 :92727B1C:db_trace:kst.c@679:kstipg(): [10280:24:0] kst: process info: ospid=12128 pso_num=24 pso_serial#=130 2025-05-04 05:59:54.622903 :92727B1D:db_trace:kso.c@4093:ksonfy(): [10420:24:0] kso: new process: pid=12128 osp_idx=22 osp_ver=221469 osp_pg=0 (spawn #146463) 2025-05-04 05:59:54.622904 :92727B1E:db_trace:kso.c@4099:ksonfy(): [10420:24:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-04 05:59:54.622904 :92727B1F:db_trace:kso.c@4103:ksonfy(): [10420:24:0] kso: new process: pso_index=24 reservation=177 time=3609171781 2025-05-04 05:59:54.622905 :92727B20:db_trace:kso.c@4109:ksonfy(): [10420:24:0] kso: spawn diagnostics: queue time=0 secs 2025-05-04 05:59:54.622905 :92727B21:db_trace:kso.c@4111:ksonfy(): [10420:24:0] kso: spawn diagnostics: fork time=0 secs 2025-05-04 05:59:54.622905 :92727B22:db_trace:kso.c@4113:ksonfy(): [10420:24:0] kso: spawn diagnostics: exec time=0 secs 2025-05-04 05:59:54.622906 :92727B23:db_trace:kso.c@4115:ksonfy(): [10420:24:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-04 05:59:54.622907 :92727B24:db_trace:kso.c@4117:ksonfy(): [10420:24:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-04 05:59:54.623377 :92727B25: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-05-04 06:00:02.028220 :92727FA0: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-05-04 06:00:02.028220*:92727FAF:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002495C718 estart=1746309601 eid=16779777 ctx=0x000000077FD6A000 cwh=0x0000000024950068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-05-04 06:00:02.028220*:92727FB0:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002495C718 curCtx=0x0000000024958938 pubTabIdxCnt=0 2025-05-04 06:00:02.028220*:92727FB1:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002495C718 2025-05-04 06:00:02.028220*:92727FB2:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002495C718 2025-05-04 06:00:02.028220*:92727FB5:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002495C718 curCtx=0x0000000024958938 xsc->flg4=65792 flags=2 2025-05-04 06:00:02.028220*:92727FB6:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002495C718 2025-05-04 06:00:02.033726 :92727FBF: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-05-04 06:00:02.033771 :92727FC6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpus:jslv.c:9203 2025-05-04 06:00:02.037215 :92727FEC: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-05-04 06:00:02.346702 :92728318: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-05-04 06:00:02.389913 :92728320: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-05-04 06:00:02.405706 :92728328: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-05-04 06:00:02.463101 :92728338: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-05-04 06:00:02.595669 :92728350: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-05-04 06:00:02.608775 :92728364: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-05-04 06:00:02.618822 :9272836C: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-05-04 06:00:02.633506 :92728374: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-05-04 06:00:02.647951 :9272837C: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-05-04 06:00:02.663060 :92728384: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-05-04 06:00:02.672736 :9272838C: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-05-04 06:00:02.687009 :92728394: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-05-04 06:00:02.695980 :9272839C: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-05-04 06:00:02.710535 :927283A4: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-05-04 06:00:02.720179 :927283AC: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-05-04 06:00:02.729068 :927283B4: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-05-04 06:00:02.737638 :927283BC: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-05-04 06:00:02.751857 :927283C4: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-05-04 06:00:02.766691 :927283CC: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-05-04 06:00:02.781205 :927283D4: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-05-04 06:00:02.795299 :927283DC: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-05-04 06:00:02.809589 :927283E4: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-05-04 06:00:02.819084 :927283EC: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-05-04 06:00:02.833525 :927283F4: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-05-04 06:00:02.842536 :927283FC: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-05-04 06:00:02.852410 :92728404: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-05-04 06:00:02.868159 :9272840C: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-05-04 06:00:02.883455 :92728414: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-05-04 06:00:02.890628 :9272841C: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-05-04 06:00:02.899416 :92728424: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-05-04 06:00:02.909382 :9272842C: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-05-04 06:00:02.919069 :92728434: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-05-04 06:00:02.933968 :9272843C: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-05-04 06:00:02.948683 :92728444: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-05-04 06:00:02.958617 :9272844C: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-05-04 06:00:02.967313 :92728454: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-05-04 06:00:02.981876 :9272845C: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-05-04 06:00:02.996757 :92728464: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-05-04 06:00:03.011208 :9272846C: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-05-04 06:00:03.020804 :92728474: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-05-04 06:00:03.030259 :9272847C: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-05-04 06:00:03.040045 :92728484: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-05-04 06:00:03.053447 :9272848C: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-05-04 06:00:03.062886 :92728494: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-05-04 06:00:03.077608 :9272849C: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-05-04 06:00:03.084669 :927284A4: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-05-04 06:00:03.091976 :927284AC: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-05-04 06:00:03.099440 :927284B4: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-05-04 06:00:03.106663 :927284BC: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-05-04 06:00:03.114025 :927284C4: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-05-04 06:00:03.121312 :927284CC: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-05-04 06:00:03.128666 :927284D4: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-05-04 06:00:03.136350 :927284DC: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-05-04 06:00:03.143975 :927284E4: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-05-04 06:00:03.151333 :927284EC: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-05-04 06:00:03.974801*:92728662:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002B513DF0 estart=1746309602 eid=16786426 ctx=0x0000000783637648 cwh=0x00000000291E0068 cpu=15625 buffg=456 interb=0 r=0 rb=0 w=0 wb=0 2025-05-04 06:00:03.974801*:92728663:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002B513DF0 curCtx=0x000000002B542B90 pubTabIdxCnt=0 2025-05-04 06:00:03.974801*:92728664:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002B513DF0 2025-05-04 06:00:03.974801*:92728665:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002B513DF0 2025-05-04 06:00:03.974801*:92728666:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002495C288 estart=1746309601 eid=16777257 ctx=0x000000079F654AA8 cwh=0x0000000024950158 cpu=0 buffg=162308 interb=43270144 r=2085 rb=38666240 w=24 wb=4603904 2025-05-04 06:00:03.974801*:92728667:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002495C288 curCtx=0x0000000039C6EF58 pubTabIdxCnt=0 2025-05-04 06:00:03.974801*:92728668:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002495C288 2025-05-04 06:00:03.974801*:92728669:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002495C288 2025-05-04 06:00:03.974801*:9272866A:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002B513DF0 curCtx=0x000000002B542B90 xsc->flg4=65792 flags=0 2025-05-04 06:00:03.974801*:9272866B:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002B513DF0 2025-05-04 06:00:04.241526 :9272866C: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-05-04 06:00:04.244016 :92728674: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-05-04 06:00:04.244268 :9272867C: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-05-04 06:00:04.251875 :92728684: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-05-04 06:00:04.259162 :9272868C: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-05-04 06:00:04.267544 :927286B7: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-05-04 06:00:04.267872 :927286BF: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-05-04 06:00:04.267872*:927286C7:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002495C288 curCtx=0x0000000039C6EF58 xsc->flg4=65792 flags=2 2025-05-04 06:00:04.267872*:927286C8:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002495C288 2025-05-04 06:00:04.268163 :927286C9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:24:193] atxpop:jslv.c:9203 2025-05-04 06:00:04.272840 :927286CA: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-05-04 06:00:04.272932 :927286CD: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-05-04 06:00:04.273005 :927286DA:db_trace:ksl2.c@12699:ksliwat(): [10005:24:193] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 24 (osid: 12128, J001)