Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250828220005\orcl_j002_21560_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:35147M/63366M, Ph+PgF:40176M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 21560, image: ORACLE.EXE (J002) *** 2025-08-28 22:00:06.062 *** SESSION ID:(225.14057) 2025-08-28 22:00:06.062 *** 2025-08-28 22:00:06.062 Process diagnostic dump for ORACLE.EXE (J002), OS id=21560, pid: 28, proc_ser: 151, sid: 225, sess_ser: 14057 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 21560 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.036657 sec, exc=0.036657 sec, total=0.036657 sec wait times: max=0.500000 sec, heur=3.996829 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.000011 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.510099 sec, exc=0.510099 sec, total=0.510099 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 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.499995 sec, exc=0.499995 sec, total=0.499995 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 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.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.000012 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.499203 sec, exc=0.499203 sec, total=0.499203 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000005 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.344542 sec, exc=0.344542 sec, total=0.344542 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.499983 sec, exc=0.499983 sec, total=0.499983 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 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.510126 sec, exc=0.510126 sec, total=0.510126 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 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.499218 sec, exc=0.499218 sec, total=0.499218 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 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.096920 sec, exc=0.096920 sec, total=0.096920 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 14057 --------------------------------------------------- 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 --------------------------------------------------- [4 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-08-28 22:00:06.062 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 21560, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-28 20:08:23.843691 :C5E68270:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21540 pso_num=28 pso_serial#=145 2025-08-28 20:08:23.843831 :C5E68271:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=21540 osp_idx=26 osp_ver=268963 osp_pg=0 (spawn #535557) 2025-08-28 20:08:23.843833 :C5E68272:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-28 20:08:23.843834 :C5E68273:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=121 time=797355143 2025-08-28 20:08:23.843834 :C5E68274:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-28 20:08:23.843834 :C5E68275:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-28 20:08:23.843835 :C5E68276:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-28 20:08:23.843835 :C5E68277:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-28 20:08:23.843835 :C5E68278:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-28 20:08:23.844334 :C5E68279: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-08-28 20:08:23.844375 :C5E6827F: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-08-28 20:08:23.848420 :C5E68298:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:08:23.848467 :C5E68299:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:08:23.848731 :C5E6829A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:08:23.848747 :C5E6829B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:08:23.848963 :C5E6829C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:08:23.848977 :C5E6829D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:08:23.849181 :C5E6829E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:08:23.849194 :C5E6829F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:08:23.849402 :C5E682A0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:08:23.849415 :C5E682A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:08:23.849622 :C5E682A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:08:23.849635 :C5E682A3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:08:23.852082 :C5E682A4:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-28 20:38:27.454778 :C5E8D5CE:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-28 20:38:27.442 2025-08-28 20:38:27.454780 :C5E8D5CF:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=22088 pso_num=28 pso_serial#=146 2025-08-28 20:38:27.454923 :C5E8D5D0:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=22088 osp_idx=26 osp_ver=268964 osp_pg=0 (spawn #535624) 2025-08-28 20:38:27.454924 :C5E8D5D1:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-28 20:38:27.454924 :C5E8D5D2:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=122 time=799158752 2025-08-28 20:38:27.454925 :C5E8D5D3:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-28 20:38:27.454925 :C5E8D5D4:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-28 20:38:27.454926 :C5E8D5D5:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-28 20:38:27.454926 :C5E8D5D6:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-28 20:38:27.454927 :C5E8D5D7:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-28 20:38:27.455425 :C5E8D5D8: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-08-28 20:38:27.455466 :C5E8D5DE: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-08-28 20:38:27.459504 :C5E8D5F7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:38:27.459551 :C5E8D5F8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:38:27.459811 :C5E8D5F9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:38:27.459826 :C5E8D5FA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:38:27.460047 :C5E8D5FB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:38:27.460061 :C5E8D5FC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:38:27.460276 :C5E8D5FD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:38:27.460289 :C5E8D5FE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:38:27.460498 :C5E8D5FF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:38:27.460512 :C5E8D600:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:38:27.460722 :C5E8D601:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 20:38:27.460735 :C5E8D602:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 20:38:27.463170 :C5E8D603:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-28 21:00:31.499266 :C5EA8AE4:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-28 21:00:31.490 2025-08-28 21:00:31.499269 :C5EA8AE5:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21528 pso_num=28 pso_serial#=147 2025-08-28 21:00:31.499413 :C5EA8AE6:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=21528 (legacy spawn) 2025-08-28 21:00:31.523825 :C5EA8B1B: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-08-28 21:00:31.524013 :C5EA8B24: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-08-28 21:00:31.524896 :C5EA8B25:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-28 21:00:31.546309 :C5EA8B58:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-28 21:00:31.537 2025-08-28 21:00:31.546311 :C5EA8B59:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=20136 pso_num=28 pso_serial#=148 2025-08-28 21:00:31.546447 :C5EA8B5A:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=20136 osp_idx=26 osp_ver=268966 osp_pg=0 (spawn #535676) 2025-08-28 21:00:31.546448 :C5EA8B5B:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-28 21:00:31.546448 :C5EA8B5C:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=123 time=800482846 2025-08-28 21:00:31.546448 :C5EA8B5D:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-28 21:00:31.546449 :C5EA8B5E:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-28 21:00:31.546451 :C5EA8B5F:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-28 21:00:31.546451 :C5EA8B60:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-28 21:00:31.546452 :C5EA8B61:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-28 21:00:31.546930 :C5EA8B62: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-08-28 21:00:31.546973 :C5EA8B68: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-08-28 21:00:31.554500 :C5EA8B76: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-08-28 21:00:31.555587 :C5EA8B7E: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-08-28 21:00:31.556200 :C5EA8B86: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-08-28 21:00:31.556688 :C5EA8B8E: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-08-28 21:00:31.557136 :C5EA8B96: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-08-28 21:00:31.559859 :C5EA8B9E: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-08-28 21:00:31.561043 :C5EA8BA6: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-08-28 21:00:31.612979 :C5EA8BAE: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-08-28 21:00:31.613781 :C5EA8BB6: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-08-28 21:00:31.614003 :C5EA8BBE: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-08-28 21:00:31.614242 :C5EA8BC6: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-08-28 21:00:31.615821 :C5EA8BCE:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-28 21:08:31.062678 :C5EB2FAF:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-28 21:08:31.050 2025-08-28 21:08:31.062680 :C5EB2FB0:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=22648 pso_num=28 pso_serial#=149 2025-08-28 21:08:31.062818 :C5EB2FB1:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=22648 osp_idx=26 osp_ver=268967 osp_pg=0 (spawn #535696) 2025-08-28 21:08:31.062819 :C5EB2FB2:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-28 21:08:31.062819 :C5EB2FB3:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=124 time=800962362 2025-08-28 21:08:31.062820 :C5EB2FB4:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-28 21:08:31.062820 :C5EB2FB5:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-28 21:08:31.062821 :C5EB2FB6:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-28 21:08:31.062822 :C5EB2FB7:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-28 21:08:31.062822 :C5EB2FB8:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-28 21:08:31.063331 :C5EB2FB9: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-08-28 21:08:31.063369 :C5EB2FBF: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-08-28 21:08:31.067541 :C5EB2FD8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:08:31.067589 :C5EB2FD9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:08:31.067838 :C5EB2FDA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:08:31.067853 :C5EB2FDB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:08:31.068063 :C5EB2FDC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:08:31.068076 :C5EB2FDD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:08:31.068284 :C5EB2FDE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:08:31.068297 :C5EB2FDF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:08:31.068510 :C5EB2FE0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:08:31.068523 :C5EB2FE1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:08:31.068770 :C5EB2FE2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:08:31.068790 :C5EB2FE3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:08:31.071059 :C5EB2FE4:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-28 21:38:35.012698 :C5ED81D3:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-28 21:38:35.000 2025-08-28 21:38:35.012700 :C5ED81D4:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=22092 pso_num=28 pso_serial#=150 2025-08-28 21:38:35.012849 :C5ED81D5:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=22092 osp_idx=26 osp_ver=268968 osp_pg=0 (spawn #535764) 2025-08-28 21:38:35.012850 :C5ED81D6:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-28 21:38:35.012850 :C5ED81D7:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=125 time=802766315 2025-08-28 21:38:35.012850 :C5ED81D8:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-28 21:38:35.012851 :C5ED81D9:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-28 21:38:35.012851 :C5ED81DA:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-28 21:38:35.012852 :C5ED81DB:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-28 21:38:35.012852 :C5ED81DC:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-28 21:38:35.013343 :C5ED81DD: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-08-28 21:38:35.013382 :C5ED81E3: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-08-28 21:38:35.017434 :C5ED81FC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:38:35.017491 :C5ED81FD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:38:35.017759 :C5ED81FE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:38:35.017777 :C5ED81FF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:38:35.017994 :C5ED8200:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:38:35.018007 :C5ED8201:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:38:35.018215 :C5ED8202:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:38:35.018227 :C5ED8203:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:38:35.018428 :C5ED8204:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:38:35.018440 :C5ED8205:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:38:35.018644 :C5ED8206:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-08-28 21:38:35.018657 :C5ED8207:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-08-28 21:38:35.021071 :C5ED8208:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-08-28 22:00:02.042244 :C5EF2910:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 08-28 22:00:02.041 2025-08-28 22:00:02.042245 :C5EF2911:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=21560 pso_num=28 pso_serial#=151 2025-08-28 22:00:02.042377 :C5EF2912:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=21560 osp_idx=26 osp_ver=268969 osp_pg=0 (spawn #535816) 2025-08-28 22:00:02.042377 :C5EF2913:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-28 22:00:02.042378 :C5EF2914:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=126 time=804053330 2025-08-28 22:00:02.042378 :C5EF2915:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-08-28 22:00:02.042379 :C5EF2916:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-08-28 22:00:02.042379 :C5EF2917:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-08-28 22:00:02.042379 :C5EF2918:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-28 22:00:02.042380 :C5EF2919:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-28 22:00:02.042910 :C5EF291A: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-08-28 22:00:02.047873 :C5EF2942: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-08-28 22:00:02.047919 :C5EF2945:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203 2025-08-28 22:00:02.052516 :C5EF2970:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-08-28 22:00:02.053090 :C5EF2971:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 4f9d120000000000 2025-08-28 22:00:02.054830 :C5EF29AA: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-08-28 22:00:02.054955 :C5EF29B7: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-08-28 22:00:02.054966 :C5EF29BE:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-08-28 22:00:02.054971 :C5EF29BF: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-08-28 22:00:02.055001 :C5EF29CB: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-08-28 22:00:02.055714 :C5EF29D7:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 235837666) 2025-08-28 22:00:02.055717 :C5EF29D8: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-08-28 22:00:02.055739 :C5EF29E4: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-08-28 22:00:02.055747 :C5EF29F0:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65564 1) 2025-08-28 22:00:02.055749 :C5EF29F1: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-08-28 22:00:02.055775 :C5EF29FD: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-08-28 22:00:02.055778 :C5EF2A06:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65564) 2025-08-28 22:00:02.055781 :C5EF2A0A: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-08-28 22:00:02.055825 :C5EF2A2A: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-08-28 22:00:02.057057 :C5EF2AC1: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-08-28 22:00:02.057086 :C5EF2AD5:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-08-28 22:00:02.058050 :C5EF2AD6:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 509d120000000000 2025-08-28 22:00:02.058424 :C5EF2AD7:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 235837666) 2025-08-28 22:00:02.058430 :C5EF2AD8: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-08-28 22:00:02.058462 :C5EF2AE3: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-08-28 22:00:02.067231 :C5EF2B46:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203 2025-08-28 22:00:02.069080 :C5EF2B47: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-08-28 22:00:02.069138 :C5EF2B4A: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-08-28 22:00:02.069237 :C5EF2B57: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-08-28 22:00:02.166838 :C5EF2C28: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 2025-08-28 22:00:04.020743 :C5EF2FA5: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: 21560, J002)