Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250625080140\orcl_m002_12488_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:36357M/63366M, Ph+PgF:42538M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 27 Windows thread id: 12488, image: ORACLE.EXE (M002) *** 2025-06-25 08:01:40.701 *** SESSION ID:(219.6851) 2025-06-25 08:01:40.701 *** 2025-06-25 08:01:40.701 Process diagnostic dump for ORACLE.EXE (M002), OS id=12488, pid: 27, proc_ser: 159, sid: 219, sess_ser: 6851 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=370 seq_num=371 snap_id=1 wait times: snap=0.001043 sec, exc=0.001043 sec, total=0.001043 sec wait times: max=infinite, heur=0.160608 sec wait counts: calls=0 os=0 in_wait=1 iflags=0x5a0 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000017 sec since current wait 0: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=369 seq_num=370 snap_id=1 wait times: snap=0.003638 sec, exc=0.003638 sec, total=0.003638 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000017 sec of elapsed time 1: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=368 seq_num=369 snap_id=1 wait times: snap=0.004961 sec, exc=0.004961 sec, total=0.004961 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000016 sec of elapsed time 2: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=367 seq_num=368 snap_id=1 wait times: snap=0.003061 sec, exc=0.003061 sec, total=0.003061 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000008 sec of elapsed time 3: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=366 seq_num=367 snap_id=1 wait times: snap=0.000059 sec, exc=0.000059 sec, total=0.000059 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000017 sec of elapsed time 4: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=365 seq_num=366 snap_id=1 wait times: snap=0.006502 sec, exc=0.006502 sec, total=0.006502 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000017 sec of elapsed time 5: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=364 seq_num=365 snap_id=1 wait times: snap=0.005622 sec, exc=0.005622 sec, total=0.005622 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000015 sec of elapsed time 6: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=363 seq_num=364 snap_id=1 wait times: snap=0.010446 sec, exc=0.010446 sec, total=0.010446 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 7: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=362 seq_num=363 snap_id=1 wait times: snap=0.000041 sec, exc=0.000041 sec, total=0.000041 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 8: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=361 seq_num=362 snap_id=1 wait times: snap=0.000044 sec, exc=0.000044 sec, total=0.000044 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 9: waited for 'ADR block file read' =0x0, =0x0, =0x0 wait_id=360 seq_num=361 snap_id=1 wait times: snap=0.000044 sec, exc=0.000044 sec, total=0.000044 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time Sampled Session History of session 219 serial 6851 --------------------------------------------------- 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 --------------------------------------------------- [1 sample, 08:01:40] idle wait at each sample [session created at: 08:01:40] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.016000 sec (max dump time=30.000000 sec) *** 2025-06-25 08:01:40.716 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 27 (osid: 12488, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-25 06:47:19.447598 :A953CA0E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 06:47:19.447803 :A953CA0F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 06:47:19.447816 :A953CA10:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 06:47:19.450066 :A953CA11:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-25 07:00:22.594318 :A954CFC8:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-25 07:00:22.581 2025-06-25 07:00:22.594320 :A954CFC9:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=14676 pso_num=27 pso_serial#=152 2025-06-25 07:00:22.594480 :A954CFCA:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=14676 osp_idx=25 osp_ver=101650 osp_pg=0 (spawn #320411) 2025-06-25 07:00:22.594481 :A954CFCB:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:00:22.594482 :A954CFCC:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=191 time=3810565782 2025-06-25 07:00:22.594483 :A954CFCD:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:00:22.594483 :A954CFCE:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:00:22.594484 :A954CFCF:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:00:22.594484 :A954CFD0:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:00:22.594484 :A954CFD1:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:00:22.595047 :A954CFD2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.595100 :A954CFD8:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-25 07:00:22.602443 :A954CFE6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.603551 :A954CFEE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.604149 :A954CFF6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.604602 :A954CFFE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.605026 :A954D006:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.607914 :A954D00E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.609051 :A954D016:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.660119 :A954D01E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.660998 :A954D026:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.661240 :A954D02E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.661500 :A954D036:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 07:00:22.663177 :A954D03E:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-25 07:02:21.474728 :A954F81B:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-25 07:02:21.462 2025-06-25 07:02:21.474730 :A954F81C:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=14672 pso_num=27 pso_serial#=153 2025-06-25 07:02:21.474871 :A954F81D:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=14672 osp_idx=25 osp_ver=101651 osp_pg=0 (spawn #320418) 2025-06-25 07:02:21.474871 :A954F81E:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:02:21.474872 :A954F81F:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=192 time=3810684657 2025-06-25 07:02:21.474872 :A954F820:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:02:21.474873 :A954F821:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:02:21.474873 :A954F822:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:02:21.474873 :A954F823:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:02:21.474874 :A954F824:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:02:21.475393 :A954F825:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:02:21.475434 :A954F82B:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-25 07:02:21.483279 :A954F83D:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-25 07:17:23.479787 :A9562CD8:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-25 07:17:23.467 2025-06-25 07:17:23.479789 :A9562CD9:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=17332 pso_num=27 pso_serial#=154 2025-06-25 07:17:23.479921 :A9562CDA:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=17332 osp_idx=25 osp_ver=101652 osp_pg=0 (spawn #320453) 2025-06-25 07:17:23.479921 :A9562CDB:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:17:23.479922 :A9562CDC:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=193 time=3811586657 2025-06-25 07:17:23.479922 :A9562CDD:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:17:23.479922 :A9562CDE:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:17:23.479922 :A9562CDF:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:17:23.479922 :A9562CE0:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:17:23.479923 :A9562CE1:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:17:23.480466 :A9562CE2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:17:23.480516 :A9562CE8:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-25 07:17:23.484651 :A9562D01:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:17:23.484697 :A9562D02:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:17:23.484949 :A9562D03:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:17:23.484964 :A9562D04:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:17:23.485170 :A9562D05:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:17:23.485183 :A9562D06:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:17:23.485389 :A9562D07:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:17:23.485401 :A9562D08:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:17:23.485602 :A9562D09:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:17:23.485614 :A9562D0A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:17:23.485818 :A9562D0B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:17:23.485830 :A9562D0C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:17:23.488239 :A9562D0D:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-25 07:47:27.022696 :A958884E:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-25 07:47:27.009 2025-06-25 07:47:27.022698 :A958884F:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=8380 pso_num=27 pso_serial#=155 2025-06-25 07:47:27.022833 :A9588850:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=8380 osp_idx=25 osp_ver=101653 osp_pg=0 (spawn #320521) 2025-06-25 07:47:27.022834 :A9588851:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 07:47:27.022834 :A9588852:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=194 time=3813390204 2025-06-25 07:47:27.022835 :A9588853:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 07:47:27.022835 :A9588854:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 07:47:27.022835 :A9588855:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 07:47:27.022835 :A9588856:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 07:47:27.022835 :A9588857:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 07:47:27.023336 :A9588858:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 07:47:27.023375 :A958885E:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-25 07:47:27.027474 :A9588886:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:47:27.027516 :A9588887:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:47:27.027775 :A9588888:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:47:27.027791 :A9588889:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:47:27.027999 :A958888A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:47:27.028012 :A958888B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:47:27.028218 :A958888C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:47:27.028231 :A958888D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:47:27.028432 :A958888E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:47:27.028445 :A958888F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:47:27.028666 :A9588890:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-25 07:47:27.028686 :A9588891:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-25 07:47:27.030960 :A9588892:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-25 08:00:28.706066 :A9598C91:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-25 08:00:28.701 2025-06-25 08:00:28.706068 :A9598C92:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=9584 pso_num=27 pso_serial#=156 2025-06-25 08:00:28.706203 :A9598C93:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=9584 osp_idx=25 osp_ver=101654 osp_pg=0 (spawn #320550) 2025-06-25 08:00:28.706204 :A9598C94:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 08:00:28.706204 :A9598C95:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=195 time=3814171891 2025-06-25 08:00:28.706205 :A9598C96:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 08:00:28.706205 :A9598C97:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 08:00:28.706205 :A9598C98:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 08:00:28.706206 :A9598C99:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 08:00:28.706207 :A9598C9A:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 08:00:28.706698 :A9598C9B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 08:00:28.706742 :A9598CA1:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-25 08:00:28.711180 :A9598CB4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:28.736425 :A9598CB5:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 4286471168 8496128) 2025-06-25 08:00:28.736432 :A9598CB6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:28.736474 :A9598CC1:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-25 08:00:28.746903 :A9598CCE:db_trace:ktur.c@3079:ktuabt(): [10444:27:219] ABORT TRANSACTION - xid: 0x0008.010.0000cd31 2025-06-25 08:00:28.747384 :A9598CCF:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 8, ext 1, nex 3 2025-06-25 08:00:28.747391 :A9598CD0:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x00815f61 where: kdiwh133: kdisdelete 2025-06-25 08:00:28.840213 :A9598CF5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:28.844182 :A9598CFF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:28.848609 :A9598D08:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:28.849725 :A9598D10:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:28.859624 :A9598D31:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 5, ext 1, nex 2 2025-06-25 08:00:28.859633 :A9598D32:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x0081923e where: kdiwh22: kdifind 2025-06-25 08:00:28.871781 :A9598D33:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 5, ext 2, nex 3 2025-06-25 08:00:28.871789 :A9598D34:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x0081b103 where: kdtwh01: kdtgrs 2025-06-25 08:00:28.892563 :A9598D35:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:28.892577 :A9598D36:db_trace:ktur.c@3079:ktuabt(): [10444:27:219] ABORT TRANSACTION - xid: 0x0005.011.0000c447 2025-06-25 08:00:28.892865 :A9598D3E:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 5, ext 3, nex 4 2025-06-25 08:00:28.892873 :A9598D3F:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x0081b10b where: ktspbwh1: ktspfsrch 2025-06-25 08:00:28.903812 :A9598D40:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 5, ext 4, nex 5 2025-06-25 08:00:28.903819 :A9598D41:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x0081b0c9 where: kdiwh22: kdifind 2025-06-25 08:00:29.482380 :A9598D52:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 5, ext 5, nex 6 2025-06-25 08:00:29.482389 :A9598D53:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x0081b127 where: kdiwh22: kdifind 2025-06-25 08:00:30.030164*:A9598DA3:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000027652740 estart=1750809628 eid=16779481 ctx=0x000000077BA4B1C8 cwh=0x0000000027610738 cpu=546875 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-06-25 08:00:30.030164*:A9598DA4:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000027652740 curCtx=0x0000000028BA8460 pubTabIdxCnt=0 2025-06-25 08:00:30.030164*:A9598DA5:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000027652740 2025-06-25 08:00:30.030164*:A9598DA6:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000027652740 2025-06-25 08:00:30.030164*:A9598DA7:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000027651E20 estart=1750809628 eid=16779468 ctx=0x0000000787AD5BF0 cwh=0x0000000027610918 cpu=546875 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-06-25 08:00:30.030164*:A9598DA8:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000027651E20 curCtx=0x0000000027659C28 pubTabIdxCnt=0 2025-06-25 08:00:30.030164*:A9598DA9:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000027651E20 2025-06-25 08:00:30.030164*:A9598DAA:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000027651E20 2025-06-25 08:00:30.030164*:A9598DAB:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000027652740 curCtx=0x0000000028BA8460 xsc->flg4=65792 flags=1 2025-06-25 08:00:30.030164*:A9598DAC:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000027652740 2025-06-25 08:00:30.030164*:A9598DAD:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000027651E20 curCtx=0x0000000027659C28 xsc->flg4=65792 flags=2 2025-06-25 08:00:30.030164*:A9598DAE:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000027651E20 2025-06-25 08:00:30.106002 :A9598DAF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:30.140346 :A9598DB7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:30.140714 :A9598DBF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:30.141005 :A9598DC7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:30.141023 :A9598DCA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:00:30.141099 :A9598DD7:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-25 08:00:30.144623 :A9598DE3:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-25 08:01:38.233049 :A959A980:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-25 08:01:38.230 2025-06-25 08:01:38.233051 :A959A981:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=12088 pso_num=27 pso_serial#=157 2025-06-25 08:01:38.233215 :A959A982:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=12088 osp_idx=25 osp_ver=101655 osp_pg=0 (spawn #320555) 2025-06-25 08:01:38.233216 :A959A983:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 08:01:38.233216 :A959A984:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=196 time=3814241407 2025-06-25 08:01:38.233216 :A959A985:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 08:01:38.233217 :A959A986:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 08:01:38.233217 :A959A987:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 08:01:38.233217 :A959A988:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 08:01:38.233218 :A959A989:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 08:01:38.234013 :A959A98A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 08:01:38.234068 :A959A990:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-25 08:01:38.359344 :A959A9D2:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-25 08:01:38.755760 :A959A9D5:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-25 08:01:38.747 2025-06-25 08:01:38.755762 :A959A9D6:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=18244 pso_num=27 pso_serial#=158 2025-06-25 08:01:38.755900 :A959A9D7:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=18244 (legacy spawn) 2025-06-25 08:01:38.762369 :A959A9D8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-25 08:01:38.762536 :A959A9E1:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] 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-25 08:01:38.763387 :A959A9E2:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-25 08:01:40.476065 :A959AA83:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-25 08:01:40.466 2025-06-25 08:01:40.476067 :A959AA84:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=12488 pso_num=27 pso_serial#=159 2025-06-25 08:01:40.476207 :A959AA85:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=12488 osp_idx=25 osp_ver=101657 osp_pg=0 (spawn #320557) 2025-06-25 08:01:40.476207 :A959AA86:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-25 08:01:40.476208 :A959AA87:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=197 time=3814243657 2025-06-25 08:01:40.476208 :A959AA88:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-25 08:01:40.476209 :A959AA89:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-25 08:01:40.476209 :A959AA8A:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-25 08:01:40.476209 :A959AA8B:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-25 08:01:40.476210 :A959AA8C:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-25 08:01:40.476722 :A959AA8D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-25 08:01:40.476767 :A959AA93:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 27 (osid: 12488, M002)