Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250916220006\orcl_j002_24892_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:35980M/63366M, Ph+PgF:40300M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 24892, image: ORACLE.EXE (J002) *** 2025-09-16 22:00:06.737 *** SESSION ID:(225.3323) 2025-09-16 22:00:06.737 *** 2025-09-16 22:00:06.737 Process diagnostic dump for ORACLE.EXE (J002), OS id=24892, pid: 28, proc_ser: 107, sid: 225, sess_ser: 3323 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 24892 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) 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.222762 sec, exc=0.222762 sec, total=0.222762 sec wait times: max=0.500000 sec, heur=4.523438 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 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 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 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.500111 sec, exc=0.500111 sec, total=0.500111 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 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.500017 sec, exc=0.500017 sec, total=0.500017 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 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.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.000009 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.499194 sec, exc=0.499194 sec, total=0.499194 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 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.313298 sec, exc=0.313298 sec, total=0.313298 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 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.500011 sec, exc=0.500011 sec, total=0.500011 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 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.500113 sec, exc=0.500113 sec, total=0.500113 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 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.487845 sec, exc=0.487845 sec, total=0.487845 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 225 serial 3323 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [5 samples, 22:00:02 - 22:00:06] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-16 22:00:06.737 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 24892, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-16 10:32:42.466936 :CE2746C8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 10:32:42.466952 :CE2746C9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 10:32:42.467172 :CE2746CA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 10:32:42.467185 :CE2746CB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 10:32:42.467397 :CE2746CC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 10:32:42.467409 :CE2746CD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 10:32:42.467618 :CE2746CE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 10:32:42.467631 :CE2746CF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 10:32:42.467834 :CE2746D0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 10:32:42.467846 :CE2746D1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 10:32:42.470220 :CE2746D2:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 11:02:46.454817 :CE299FA3:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 11:02:46.442 2025-09-16 11:02:46.454820 :CE299FA4:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=24584 pso_num=28 pso_serial#=98 2025-09-16 11:02:46.454957 :CE299FA5:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=24584 osp_idx=26 osp_ver=329096 osp_pg=0 (spawn #597667) 2025-09-16 11:02:46.454957 :CE299FA6:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-16 11:02:46.454958 :CE299FA7:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=86 time=2406217752 2025-09-16 11:02:46.454958 :CE299FA8:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-09-16 11:02:46.454959 :CE299FA9:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-09-16 11:02:46.454959 :CE299FAA:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-09-16 11:02:46.454959 :CE299FAB:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-16 11:02:46.454960 :CE299FAC:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-16 11:02:46.455499 :CE299FAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-16 11:02:46.455538 :CE299FB3:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 11:02:46.459519 :CE299FCB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 11:02:46.459560 :CE299FCC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 11:02:46.459839 :CE299FCD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 11:02:46.459870 :CE299FCE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 11:02:46.460166 :CE299FCF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 11:02:46.460180 :CE299FD0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 11:02:46.460390 :CE299FD1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 11:02:46.460403 :CE299FD2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 11:02:46.460621 :CE299FD3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 11:02:46.460634 :CE299FD4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 11:02:46.460854 :CE299FD5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-09-16 11:02:46.460868 :CE299FD6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-09-16 11:02:46.463265 :CE299FF9:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 13:00:03.595270 :CE32DE0E:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 13:00:03.590 2025-09-16 13:00:03.595272 :CE32DE0F:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=24572 pso_num=28 pso_serial#=99 2025-09-16 13:00:03.595408 :CE32DE10:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=24572 osp_idx=26 osp_ver=329097 osp_pg=0 (spawn #597938) 2025-09-16 13:00:03.595409 :CE32DE11:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-16 13:00:03.595410 :CE32DE12:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=87 time=2413254877 2025-09-16 13:00:03.595410 :CE32DE13:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-09-16 13:00:03.595411 :CE32DE14:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-09-16 13:00:03.595411 :CE32DE15:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-09-16 13:00:03.595412 :CE32DE16:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-16 13:00:03.595412 :CE32DE17:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-16 13:00:03.595986 :CE32DE18:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.596029 :CE32DE1E:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 13:00:03.603855 :CE32DE2C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.604963 :CE32DE34:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.605528 :CE32DE3C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.606013 :CE32DE54:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.606448 :CE32DE5C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.609241 :CE32DE64:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.610323 :CE32DE6C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.661551 :CE32DE74:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.662459 :CE32DE7C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.662704 :CE32DE84:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.662950 :CE32DE8C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 13:00:03.664724 :CE32DE94:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 16:00:20.202702 :CE41181C:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 16:00:20.188 2025-09-16 16:00:20.202704 :CE41181D:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=25100 pso_num=28 pso_serial#=100 2025-09-16 16:00:20.202847 :CE41181E:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=25100 (legacy spawn) 2025-09-16 16:00:20.209731 :CE41181F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:20.209909 :CE411824:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-09-16 16:00:20.210843 :CE411829:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 16:00:20.219681 :CE41182C:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 16:00:20.219 2025-09-16 16:00:20.219683 :CE41182D:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21912 pso_num=28 pso_serial#=101 2025-09-16 16:00:20.219850 :CE41182E:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=21912 (legacy spawn) 2025-09-16 16:00:20.226593 :CE41182F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:20.226754 :CE411838:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-09-16 16:00:20.227572 :CE411839:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 16:00:22.669901 :CE4118E2:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 16:00:22.661 2025-09-16 16:00:22.669904 :CE4118E3:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=24948 pso_num=28 pso_serial#=102 2025-09-16 16:00:22.670042 :CE4118E4:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=24948 (legacy spawn) 2025-09-16 16:00:22.676747 :CE4118E5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:22.676913 :CE4118EA:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-09-16 16:00:22.677722 :CE4118EF:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 16:00:23.284110 :CE41192C:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 16:00:23.271 2025-09-16 16:00:23.284113 :CE41192D:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=24316 pso_num=28 pso_serial#=103 2025-09-16 16:00:23.284256 :CE41192E:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=24316 (legacy spawn) 2025-09-16 16:00:23.290740 :CE41192F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:23.290905 :CE411938:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-09-16 16:00:23.291709 :CE411939:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 16:00:23.300702 :CE41193C:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 16:00:23.286 2025-09-16 16:00:23.300705 :CE41193D:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=23460 pso_num=28 pso_serial#=104 2025-09-16 16:00:23.300883 :CE41193E:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=23460 (legacy spawn) 2025-09-16 16:00:23.307550 :CE41193F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:23.307714 :CE411948:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-09-16 16:00:23.308514 :CE411949:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 16:00:25.818953 :CE411A3B:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 16:00:25.812 2025-09-16 16:00:25.818955 :CE411A3C:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=24344 pso_num=28 pso_serial#=105 2025-09-16 16:00:25.819096 :CE411A3D:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=24344 osp_idx=26 osp_ver=329103 osp_pg=0 (spawn #598351) 2025-09-16 16:00:25.819097 :CE411A3E:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-16 16:00:25.819097 :CE411A3F:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=88 time=2424077127 2025-09-16 16:00:25.819098 :CE411A40:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-09-16 16:00:25.819098 :CE411A41:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-09-16 16:00:25.819098 :CE411A42:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-09-16 16:00:25.819099 :CE411A43:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-16 16:00:25.819099 :CE411A44:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-16 16:00:25.819648 :CE411A45:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-16 16:00:25.819691 :CE411A4B:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 16:00:25.824291 :CE411A5E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:25.847205 :CE411A66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:25.863385 :CE411A79:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:25.897345 :CE411A81:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:25.901295 :CE411A89:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:25.905141 :CE411A91:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:25.909517 :CE411A99:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:25.910720 :CE411AA1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:27.056405*:CE411AD9:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000299635B0 estart=1758009626 eid=16781493 ctx=0x000000077BA4B1C8 cwh=0x0000000029950B90 cpu=468750 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-09-16 16:00:27.056405*:CE411ADA:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000299635B0 curCtx=0x000000002999F9B8 pubTabIdxCnt=0 2025-09-16 16:00:27.056405*:CE411ADB:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000299635B0 2025-09-16 16:00:27.056405*:CE411ADC:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000299635B0 2025-09-16 16:00:27.056405*:CE411ADD:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000299AFCB8 estart=1758009626 eid=16781468 ctx=0x0000000787AD5BF0 cwh=0x0000000029950AA0 cpu=468750 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-09-16 16:00:27.056405*:CE411ADE:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000299AFCB8 curCtx=0x00000000299A25F8 pubTabIdxCnt=0 2025-09-16 16:00:27.056405*:CE411ADF:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000299AFCB8 2025-09-16 16:00:27.056405*:CE411AE0:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000299AFCB8 2025-09-16 16:00:27.103282*:CE411AE1:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000299635B0 curCtx=0x000000002999F9B8 xsc->flg4=65792 flags=1 2025-09-16 16:00:27.103282*:CE411AE2:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000299635B0 2025-09-16 16:00:27.103282*:CE411AE3:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000299AFCB8 curCtx=0x00000000299A25F8 xsc->flg4=65792 flags=2 2025-09-16 16:00:27.103282*:CE411AE4:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000299AFCB8 2025-09-16 16:00:27.190399 :CE411AF1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:27.238193 :CE411AF9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:27.238475 :CE411B01:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:27.238748 :CE411B09:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:27.238765 :CE411B0C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 16:00:27.238844 :CE411B1E:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-09-16 16:00:27.241662 :CE411B26:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 18:58:29.243354 :CE4F1F27:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 18:58:29.232 2025-09-16 18:58:29.243356 :CE4F1F28:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=17248 pso_num=28 pso_serial#=106 2025-09-16 18:58:29.243496 :CE4F1F29:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=17248 (legacy spawn) 2025-09-16 18:58:29.250284 :CE4F1F2A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 18:58:29.255085 :CE4F1F39:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-09-16 18:58:29.255831 :CE4F1F40:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-09-16 22:00:02.083414 :CE5D7EB4:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 09-16 22:00:02.080 2025-09-16 22:00:02.083416 :CE5D7EB5:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=24892 pso_num=28 pso_serial#=107 2025-09-16 22:00:02.083559 :CE5D7EB9:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=24892 osp_idx=26 osp_ver=329105 osp_pg=0 (spawn #599185) 2025-09-16 22:00:02.083560 :CE5D7EBA:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-16 22:00:02.083560 :CE5D7EBB:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=89 time=2445653377 2025-09-16 22:00:02.083561 :CE5D7EBC:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-09-16 22:00:02.083561 :CE5D7EBD:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-09-16 22:00:02.083562 :CE5D7EBE:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-09-16 22:00:02.083562 :CE5D7EBF:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-16 22:00:02.083563 :CE5D7EC0:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-16 22:00:02.084135 :CE5D7EC7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.089659 :CE5D7EE4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.089695 :CE5D7EE7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203 2025-09-16 22:00:02.142206 :CE5D8071:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-09-16 22:00:02.142779 :CE5D8072:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 2dc3120000000000 2025-09-16 22:00:02.155723 :CE5D8086:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.155832 :CE5D8096:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 22:00:02.155841 :CE5D809A:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-09-16 22:00:02.155846 :CE5D809B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.155874 :CE5D80A7:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 22:00:02.161731 :CE5D80B3:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 237725279) 2025-09-16 22:00:02.161738 :CE5D80B4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.161773 :CE5D80BF:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 22:00:02.161784 :CE5D80CA:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65564 1) 2025-09-16 22:00:02.161786 :CE5D80CD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.161806 :CE5D80D9:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 22:00:02.161809 :CE5D80DD:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65564) 2025-09-16 22:00:02.161811 :CE5D80E0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.161857 :CE5D810E:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 22:00:02.162700 :CE5D8205:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 22:00:02.162725 :CE5D820F:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-09-16 22:00:02.167600 :CE5D8210:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 2ec3120000000000 2025-09-16 22:00:02.168021 :CE5D8211:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 237725279) 2025-09-16 22:00:02.168028 :CE5D8212:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.168061 :CE5D821B:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-09-16 22:00:02.215143 :CE5D8256:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203 2025-09-16 22:00:02.216782 :CE5D8257:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.216826 :CE5D825A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-09-16 22:00:02.216932 :CE5D8267:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-09-16 22:00:04.018747 :CE5D85B6:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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 28 (osid: 24892, J002)