Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250629181045\orcl_j003_18300_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:36549M/63366M, Ph+PgF:42668M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 18300, image: ORACLE.EXE (J003) *** 2025-06-29 18:10:45.564 *** SESSION ID:(233.27435) 2025-06-29 18:10:45.564 *** 2025-06-29 18:10:45.564 Process diagnostic dump for ORACLE.EXE (J003), OS id=18300, pid: 29, proc_ser: 160, sid: 233, sess_ser: 27435 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 18300 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.226543 sec, exc=0.226543 sec, total=0.226543 sec wait times: max=0.500000 sec, heur=7.226065 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.499977 sec, exc=0.499977 sec, total=0.499977 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=12 seq_num=13 snap_id=1 wait times: snap=0.500104 sec, exc=0.500104 sec, total=0.500104 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.500005 sec, exc=0.500005 sec, total=0.500005 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.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 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.499989 sec, exc=0.499989 sec, total=0.499989 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.500007 sec, exc=0.500007 sec, total=0.500007 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.500114 sec, exc=0.500114 sec, total=0.500114 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.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.000009 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.500010 sec, exc=0.500010 sec, total=0.500010 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time Sampled Session History of session 233 serial 27435 --------------------------------------------------- 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 --------------------------------------------------- [8 samples, 18:10:38 - 18:10:45] idle wait at each sample [session created at: 18:10:38] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-29 18:10:45.564 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 18300, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-29 15:00:13.200914 :AB41C844:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:00:13.201120 :AB41C845:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:00:13.201138 :AB41C846:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:00:13.201436 :AB41C851:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:00:13.201450 :AB41C852:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:00:13.201659 :AB41C853:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:00:13.201673 :AB41C854:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:00:13.204307 :AB41C871:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 15:30:17.040552 :AB442443:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 15:30:17.028 2025-06-29 15:30:17.040554 :AB442444:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12136 pso_num=29 pso_serial#=150 2025-06-29 15:30:17.040685 :AB442445:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12136 osp_idx=27 osp_ver=13664 osp_pg=0 (spawn #334943) 2025-06-29 15:30:17.040686 :AB442446:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 15:30:17.040687 :AB442447:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=250 time=4186760219 2025-06-29 15:30:17.040688 :AB442448:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 15:30:17.040689 :AB442449:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 15:30:17.040689 :AB44244A:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 15:30:17.040689 :AB44244B:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 15:30:17.040690 :AB44244C:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 15:30:17.041209 :AB44244D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-29 15:30:17.041259 :AB442453:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 15:30:17.045374 :AB44246C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:30:17.045418 :AB44246D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:30:17.045674 :AB44246E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:30:17.045690 :AB44246F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:30:17.045902 :AB442470:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:30:17.045915 :AB442471:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:30:17.046123 :AB442472:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:30:17.046136 :AB442473:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:30:17.046340 :AB442474:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:30:17.046353 :AB442475:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:30:17.046561 :AB442476:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 15:30:17.046575 :AB442477:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 15:30:17.049066 :AB442478:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 16:00:19.579602 :AB4673AE:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 16:00:19.567 2025-06-29 16:00:19.579604 :AB4673AF:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=17544 pso_num=29 pso_serial#=151 2025-06-29 16:00:19.579746 :AB4673B0:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=17544 (legacy spawn) 2025-06-29 16:00:19.586328 :AB4673B1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:19.586495 :AB4673B6:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 16:00:19.587302 :AB4673BB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 16:00:20.557097 :AB46740E:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 16:00:20.552 2025-06-29 16:00:20.557099 :AB46740F:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18396 pso_num=29 pso_serial#=152 2025-06-29 16:00:20.557252 :AB467410:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=18396 osp_idx=27 osp_ver=13666 osp_pg=0 (spawn #335009) 2025-06-29 16:00:20.557253 :AB467411:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 16:00:20.557253 :AB467412:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=251 time=4188563750 2025-06-29 16:00:20.557254 :AB467413:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 16:00:20.557254 :AB467414:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 16:00:20.557255 :AB467415:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 16:00:20.557255 :AB467416:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 16:00:20.557256 :AB467417:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 16:00:20.557764 :AB467418:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-29 16:00:20.557815 :AB46741E:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 16:00:20.578473 :AB4674AC:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 16:00:21.964246 :AB4677A8:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 16:00:21.952 2025-06-29 16:00:21.964248 :AB4677A9:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14488 pso_num=29 pso_serial#=153 2025-06-29 16:00:21.964384 :AB4677AA:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14488 osp_idx=27 osp_ver=13667 osp_pg=0 (spawn #335013) 2025-06-29 16:00:21.964384 :AB4677AB:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 16:00:21.964385 :AB4677AC:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=252 time=4188565141 2025-06-29 16:00:21.964385 :AB4677AD:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 16:00:21.964386 :AB4677AE:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 16:00:21.964386 :AB4677AF:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 16:00:21.964387 :AB4677B0:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 16:00:21.964387 :AB4677B1:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 16:00:21.964889 :AB4677B2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-29 16:00:21.964931 :AB4677B8:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 16:00:21.972395 :AB4677C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:21.973445 :AB4677CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:21.974088 :AB4677D6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:21.974581 :AB4677DE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:21.975027 :AB4677E6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:21.977484 :AB4677EE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:21.978682 :AB4677F6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:22.028772 :AB46780C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:22.029664 :AB467814:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:22.029906 :AB46781C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:22.030127 :AB467824:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:22.032017 :AB46782C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 16:00:24.353917 :AB4678FE:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 16:00:24.345 2025-06-29 16:00:24.353919 :AB4678FF:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=4972 pso_num=29 pso_serial#=154 2025-06-29 16:00:24.354054 :AB467900:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=4972 (legacy spawn) 2025-06-29 16:00:24.377763 :AB467901:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 16:00:24.377941 :AB467906:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 16:00:24.378823 :AB46790B:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 16:30:24.175549 :AB48CFD2:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 16:30:24.163 2025-06-29 16:30:24.175551 :AB48CFD3:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=15640 pso_num=29 pso_serial#=155 2025-06-29 16:30:24.175684 :AB48CFD4:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=15640 osp_idx=27 osp_ver=13669 osp_pg=0 (spawn #335079) 2025-06-29 16:30:24.175685 :AB48CFD5:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 16:30:24.175685 :AB48CFD6:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=253 time=4190367360 2025-06-29 16:30:24.175685 :AB48CFD7:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 16:30:24.175686 :AB48CFD8:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 16:30:24.175686 :AB48CFD9:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 16:30:24.175686 :AB48CFDA:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 16:30:24.175687 :AB48CFDB:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 16:30:24.176195 :AB48CFDC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-29 16:30:24.176240 :AB48CFE2:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 16:30:24.180399 :AB48CFFB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 16:30:24.180444 :AB48CFFC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 16:30:24.180696 :AB48CFFD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 16:30:24.180712 :AB48CFFE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 16:30:24.180932 :AB48CFFF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 16:30:24.180946 :AB48D000:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 16:30:24.181159 :AB48D001:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 16:30:24.181174 :AB48D002:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 16:30:24.181378 :AB48D003:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 16:30:24.181390 :AB48D004:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 16:30:24.181586 :AB48D005:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 16:30:24.181598 :AB48D006:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 16:30:24.184111 :AB48D007:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 17:00:27.991972 :AB4B212C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 17:00:27.981 2025-06-29 17:00:27.991973 :AB4B212D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=14828 pso_num=29 pso_serial#=156 2025-06-29 17:00:27.992108 :AB4B212E:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=14828 osp_idx=27 osp_ver=13670 osp_pg=0 (spawn #335146) 2025-06-29 17:00:27.992109 :AB4B212F:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 17:00:27.992109 :AB4B2130:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=254 time=4192171172 2025-06-29 17:00:27.992110 :AB4B2131:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 17:00:27.992110 :AB4B2132:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 17:00:27.992111 :AB4B2133:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 17:00:27.992111 :AB4B2134:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 17:00:27.992112 :AB4B2135:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 17:00:27.992712 :AB4B2136:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-29 17:00:27.992763 :AB4B213C:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 17:00:28.001603 :AB4B2151:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 17:30:31.714612 :AB4D7B0A:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 17:30:31.702 2025-06-29 17:30:31.714614 :AB4D7B0B:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11144 pso_num=29 pso_serial#=157 2025-06-29 17:30:31.714758 :AB4D7B0C:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11144 osp_idx=27 osp_ver=13671 osp_pg=0 (spawn #335215) 2025-06-29 17:30:31.714759 :AB4D7B0D:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 17:30:31.714759 :AB4D7B0E:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=255 time=4193974891 2025-06-29 17:30:31.714760 :AB4D7B0F:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 17:30:31.714760 :AB4D7B10:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 17:30:31.714760 :AB4D7B11:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 17:30:31.714761 :AB4D7B12:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 17:30:31.714761 :AB4D7B13:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 17:30:31.715286 :AB4D7B14:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-29 17:30:31.715341 :AB4D7B1A:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 17:30:31.719434 :AB4D7B33:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 17:30:31.719478 :AB4D7B34:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 17:30:31.719731 :AB4D7B35:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 17:30:31.719746 :AB4D7B36:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 17:30:31.719966 :AB4D7B37:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 17:30:31.719980 :AB4D7B38:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 17:30:31.720193 :AB4D7B39:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 17:30:31.720206 :AB4D7B3A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 17:30:31.720423 :AB4D7B3B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 17:30:31.720437 :AB4D7B3C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 17:30:31.720638 :AB4D7B3D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-06-29 17:30:31.720651 :AB4D7B3E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-06-29 17:30:31.723135 :AB4D7B3F:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 18:00:35.470428 :AB4FCA59:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 18:00:35.461 2025-06-29 18:00:35.470429 :AB4FCA5A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12088 pso_num=29 pso_serial#=158 2025-06-29 18:00:35.470563 :AB4FCA5B:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12088 osp_idx=27 osp_ver=13672 osp_pg=0 (spawn #335283) 2025-06-29 18:00:35.470564 :AB4FCA5C:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 18:00:35.470565 :AB4FCA5D:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=0 time=4195778657 2025-06-29 18:00:35.470565 :AB4FCA5E:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 18:00:35.470565 :AB4FCA5F:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 18:00:35.470566 :AB4FCA60:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 18:00:35.470566 :AB4FCA61:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 18:00:35.470567 :AB4FCA62:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 18:00:35.471113 :AB4FCA63:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-29 18:00:35.471165 :AB4FCA69:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 18:00:35.479992 :AB4FCA7E:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 18:10:37.034972 :AB509C6C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 18:10:37.026 2025-06-29 18:10:37.034974 :AB509C6D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18236 pso_num=29 pso_serial#=159 2025-06-29 18:10:37.035109 :AB509C6E:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=18236 (legacy spawn) 2025-06-29 18:10:37.041581 :AB509C6F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-29 18:10:37.041741 :AB509C78:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] 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-06-29 18:10:37.042652 :AB509C79:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-06-29 18:10:38.345400 :AB509D5E:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 06-29 18:10:38.339 2025-06-29 18:10:38.345403 :AB509D5F:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18300 pso_num=29 pso_serial#=160 2025-06-29 18:10:38.345529 :AB509D60:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=18300 osp_idx=27 osp_ver=13674 osp_pg=0 (spawn #335311) 2025-06-29 18:10:38.345530 :AB509D61:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-29 18:10:38.345530 :AB509D62:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=1 time=4196381532 2025-06-29 18:10:38.345531 :AB509D63:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-06-29 18:10:38.345532 :AB509D64:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-06-29 18:10:38.345532 :AB509D65:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-06-29 18:10:38.345532 :AB509D66:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-29 18:10:38.345533 :AB509D67:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-29 18:10:38.346058 :AB509D68:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 18300, J003)