Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250611220008\orcl_j002_9904_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:36742M/63366M, Ph+PgF:43286M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 27 Windows thread id: 9904, image: ORACLE.EXE (J002) *** 2025-06-11 22:00:08.591 *** SESSION ID:(219.51541) 2025-06-11 22:00:08.591 *** 2025-06-11 22:00:08.591 Process diagnostic dump for ORACLE.EXE (J002), OS id=9904, pid: 27, proc_ser: 98, sid: 219, sess_ser: 51541 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 9904 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.451203 sec, exc=0.451203 sec, total=0.451203 sec wait times: max=0.500000 sec, heur=7.953374 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.000008 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.500110 sec, exc=0.500110 sec, total=0.500110 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.500151 sec, exc=0.500151 sec, total=0.500151 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=11 seq_num=12 snap_id=1 wait times: snap=0.501820 sec, exc=0.501820 sec, total=0.501820 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=10 seq_num=11 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.499997 sec, exc=0.499997 sec, total=0.499997 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.500177 sec, exc=0.500177 sec, total=0.500177 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 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.000017 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 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.000007 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.499994 sec, exc=0.499994 sec, total=0.499994 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time Sampled Session History of session 219 serial 51541 --------------------------------------------------- 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, 22:00:00 - 22:00:08] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-11 22:00:08.591 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 27 (osid: 9904, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-11 15:06:54.095801 :A34D63F5:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-11 15:06:54.095802 :A34D63F6:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-11 15:06:54.096305 :A34D63F7: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-11 15:06:54.096347 :A34D63FD: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-11 15:06:54.100483 :A34D6416:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 15:06:54.100526 :A34D6417:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 15:06:54.100774 :A34D6418:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 15:06:54.100790 :A34D6419:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 15:06:54.101004 :A34D641A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 15:06:54.101017 :A34D641B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 15:06:54.101221 :A34D641C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 15:06:54.101234 :A34D641D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 15:06:54.101440 :A34D641E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 15:06:54.101452 :A34D641F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 15:06:54.101658 :A34D6420:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 15:06:54.101670 :A34D6421:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 15:06:54.104160 :A34D6422:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:00.920202 :A3517721:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:00.915 2025-06-11 16:00:00.920204 :A3517722:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16260 pso_num=27 pso_serial#=88 2025-06-11 16:00:00.920341 :A3517723:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=16260 osp_idx=25 osp_ver=58482 osp_pg=0 (spawn #274981) 2025-06-11 16:00:00.920342 :A3517724: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-11 16:00:00.920343 :A3517725:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=145 time=2633344110 2025-06-11 16:00:00.920343 :A3517726:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-11 16:00:00.920343 :A3517727:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-11 16:00:00.920344 :A3517728:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-11 16:00:00.920344 :A3517729:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-11 16:00:00.920344 :A351772A:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-11 16:00:00.920827 :A351772B: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-11 16:00:00.920873 :A3517731: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-11 16:00:00.925271 :A3517744: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-11 16:00:00.950498 :A351775F:db_trace:ksb.c@6610:ksbcic_int(): [10254:27:219] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 4286475969 8491328) 2025-06-11 16:00:00.950506 :A3517760: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-11 16:00:00.950555 :A351776B: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-11 16:00:00.950605 :A3517778: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-11 16:00:00.965561 :A3517780: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-11 16:00:00.993292 :A3517788: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-11 16:00:00.996877 :A3517790: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-11 16:00:01.000669 :A3517798: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-11 16:00:01.004920 :A35177A0: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-11 16:00:01.006027 :A35177A8: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-11 16:00:01.041155 :A35177B0:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 1, ext 1, nex 3 2025-06-11 16:00:01.041163 :A35177B1:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x008012b6 where: kdiwh22: kdifind 2025-06-11 16:00:01.059945 :A35177B2:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 1, ext 2, nex 4 2025-06-11 16:00:01.059954 :A35177B3:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x00819164 where: kdiwh22: kdifind 2025-06-11 16:00:01.634704 :A35177CE:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 1, ext 3, nex 5 2025-06-11 16:00:01.634712 :A35177CF:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:1 rdba:0x00819239 where: kdiwh22: kdifind 2025-06-11 16:00:02.188110*:A35177DC:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000028BE8C88 estart=1749628801 eid=16779151 ctx=0x000000077BA4B1C8 cwh=0x0000000028BA0918 cpu=562500 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-06-11 16:00:02.188110*:A35177DD:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000028BE8C88 curCtx=0x000000002925CAF0 pubTabIdxCnt=0 2025-06-11 16:00:02.188110*:A35177DE:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000028BE8C88 2025-06-11 16:00:02.188110*:A35177DF:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000028BE8C88 2025-06-11 16:00:02.188110*:A35177E0:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000028BE1E20 estart=1749628801 eid=16779140 ctx=0x0000000787AD5BF0 cwh=0x0000000028BA0828 cpu=562500 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-06-11 16:00:02.188110*:A35177E1:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000028BE1E20 curCtx=0x0000000028BE9C28 pubTabIdxCnt=0 2025-06-11 16:00:02.188110*:A35177E2:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000028BE1E20 2025-06-11 16:00:02.188110*:A35177E3:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000028BE1E20 2025-06-11 16:00:02.188110*:A35177E4:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000028BE8C88 curCtx=0x000000002925CAF0 xsc->flg4=65792 flags=1 2025-06-11 16:00:02.188110*:A35177E5:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000028BE8C88 2025-06-11 16:00:02.188110*:A35177E6:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000028BE1E20 curCtx=0x0000000028BE9C28 xsc->flg4=65792 flags=2 2025-06-11 16:00:02.188110*:A35177E7:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000028BE1E20 2025-06-11 16:00:02.250125 :A35177E8: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-11 16:00:02.282737 :A35177F0: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-11 16:00:02.283074 :A35177F8: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-11 16:00:02.283354 :A3517800: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-11 16:00:02.283370 :A3517803: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-11 16:00:02.283432 :A3517811: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-11 16:00:02.286284 :A351781D:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:13.438086 :A3517C27:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:13.426 2025-06-11 16:00:13.438088 :A3517C28:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=14704 pso_num=27 pso_serial#=89 2025-06-11 16:00:13.438223 :A3517C29:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=14704 (legacy spawn) 2025-06-11 16:00:13.444645 :A3517C2A: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-11 16:00:13.444823 :A3517C33: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-11 16:00:13.445601 :A3517C34:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:14.842095 :A3517CA1:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:14.833 2025-06-11 16:00:14.842098 :A3517CA2:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=14632 pso_num=27 pso_serial#=90 2025-06-11 16:00:14.842274 :A3517CA3:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=14632 (legacy spawn) 2025-06-11 16:00:14.848760 :A3517CA4: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-11 16:00:14.848935 :A3517CA9: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-11 16:00:14.849757 :A3517CAE:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:26.531801 :A3518020:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:26.530 2025-06-11 16:00:26.531803 :A3518021:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=15128 pso_num=27 pso_serial#=91 2025-06-11 16:00:26.531939 :A3518022:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=15128 (legacy spawn) 2025-06-11 16:00:26.538380 :A3518023: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-11 16:00:26.538557 :A3518028: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-11 16:00:26.539352 :A351802D:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:26.548043 :A3518030:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:26.545 2025-06-11 16:00:26.548046 :A3518031:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=14020 pso_num=27 pso_serial#=92 2025-06-11 16:00:26.548187 :A3518032:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=14020 (legacy spawn) 2025-06-11 16:00:26.554606 :A3518033: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-11 16:00:26.554769 :A351803C: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-11 16:00:26.555574 :A351803D:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:27.497059 :A3518094:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:27.483 2025-06-11 16:00:27.497061 :A3518095:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=12676 pso_num=27 pso_serial#=93 2025-06-11 16:00:27.497195 :A3518096:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=12676 (legacy spawn) 2025-06-11 16:00:27.503653 :A3518097: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-11 16:00:27.503828 :A35180A0: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-11 16:00:27.504596 :A35180A1:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:27.513267 :A35180A4:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:27.498 2025-06-11 16:00:27.513269 :A35180A5:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=5896 pso_num=27 pso_serial#=94 2025-06-11 16:00:27.513404 :A35180A6:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=5896 (legacy spawn) 2025-06-11 16:00:27.519861 :A35180B2: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-11 16:00:27.520028 :A35180BB: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-11 16:00:27.520814 :A35180BC:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:30.719384 :A3518388:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:30.706 2025-06-11 16:00:30.719386 :A3518389:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=8928 pso_num=27 pso_serial#=95 2025-06-11 16:00:30.719523 :A351838A:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=8928 (legacy spawn) 2025-06-11 16:00:30.725994 :A351838B: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-11 16:00:30.726164 :A3518394: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-11 16:00:30.726947 :A3518395:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 16:00:30.735581 :A3518398:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 16:00:30.722 2025-06-11 16:00:30.735584 :A3518399:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=16564 pso_num=27 pso_serial#=96 2025-06-11 16:00:30.735719 :A351839A:db_trace:kso.c@4070:ksonfy(): [10420:27:0] kso: new process: pid=16564 (legacy spawn) 2025-06-11 16:00:30.742724 :A351839B:db_trace:ktu.c@4871:ktuaex1r(): [10442:27:219] Extension usn 1, ext 4, nex 6 2025-06-11 16:00:30.742731 :A351839C:db_trace:ktusm.c@2117:ktusmasp(): [10445:27:219] des1:tsn:0 rdba:0x00512b88 where: ktswh72: ktsbget 2025-06-11 16:00:30.742882 :A351839D: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-11 16:00:30.743054 :A35183A6: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-11 16:00:30.744110 :A35183A7:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 19:07:22.876946 :A35FE370:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 19:07:22.864 2025-06-11 19:07:22.876948 :A35FE371:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=15128 pso_num=27 pso_serial#=97 2025-06-11 19:07:22.877093 :A35FE372:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=15128 osp_idx=25 osp_ver=58491 osp_pg=0 (spawn #275417) 2025-06-11 19:07:22.877094 :A35FE373: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-11 19:07:22.877094 :A35FE374:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=146 time=2644586063 2025-06-11 19:07:22.877095 :A35FE375:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-11 19:07:22.877095 :A35FE376:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-11 19:07:22.877096 :A35FE377:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-11 19:07:22.877096 :A35FE378:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-11 19:07:22.877096 :A35FE379:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-11 19:07:22.877658 :A35FE37A: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-11 19:07:22.877699 :A35FE380: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-11 19:07:22.881761 :A35FE399:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 19:07:22.881808 :A35FE39A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 19:07:22.882064 :A35FE39B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 19:07:22.882080 :A35FE39C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 19:07:22.882296 :A35FE39D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 19:07:22.882309 :A35FE39E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 19:07:22.882516 :A35FE39F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 19:07:22.882529 :A35FE3A0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 19:07:22.882736 :A35FE3A1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 19:07:22.882749 :A35FE3A2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 19:07:22.882947 :A35FE3A3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:kelt.c:517 2025-06-11 19:07:22.882960 :A35FE3A4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:kelt.c:517 2025-06-11 19:07:22.885483 :A35FE3A5:db_trace:kst.c@698:kstpsodel(): [10280:27:0] kst: process state object about to be deleted 2025-06-11 22:00:00.516122 :A36D3331:db_trace:kst.c@673:kstipg(): [10280:27:0] kst: process state object created on 06-11 22:00:00.515 2025-06-11 22:00:00.516124 :A36D3332:db_trace:kst.c@679:kstipg(): [10280:27:0] kst: process info: ospid=9904 pso_num=27 pso_serial#=98 2025-06-11 22:00:00.516253 :A36D3333:db_trace:kso.c@4093:ksonfy(): [10420:27:0] kso: new process: pid=9904 osp_idx=25 osp_ver=58492 osp_pg=0 (spawn #275811) 2025-06-11 22:00:00.516254 :A36D3334:db_trace:kso.c@4099:ksonfy(): [10420:27:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-11 22:00:00.516254 :A36D3335:db_trace:kso.c@4103:ksonfy(): [10420:27:0] kso: new process: pso_index=27 reservation=147 time=2654943688 2025-06-11 22:00:00.516255 :A36D3336:db_trace:kso.c@4109:ksonfy(): [10420:27:0] kso: spawn diagnostics: queue time=0 secs 2025-06-11 22:00:00.516255 :A36D3337:db_trace:kso.c@4111:ksonfy(): [10420:27:0] kso: spawn diagnostics: fork time=0 secs 2025-06-11 22:00:00.516255 :A36D3338:db_trace:kso.c@4113:ksonfy(): [10420:27:0] kso: spawn diagnostics: exec time=0 secs 2025-06-11 22:00:00.516255 :A36D3339:db_trace:kso.c@4115:ksonfy(): [10420:27:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-11 22:00:00.516256 :A36D333A:db_trace:kso.c@4117:ksonfy(): [10420:27:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-11 22:00:00.516754 :A36D3344:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-11 22:00:00.522102 :A36D3369: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-11 22:00:00.522130 :A36D336A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:jslv.c:9203 2025-06-11 22:00:00.533386 :A36D33D1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=30 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 2025-06-11 22:00:00.534031 :A36D33D7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-06-11 22:00:00.534326 :A36D33DF: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-11 22:00:00.540317 :A36D3576: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-11 22:00:00.541010 :A36D3587: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-11 22:00:00.546616 :A36D35BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-06-11 22:00:00.546766 :A36D35CD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-11 22:00:00.547562 :A36D35D5: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-11 22:00:00.547747 :A36D35DD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:jslv.c:9203 2025-06-11 22:00:00.548326 :A36D35E0:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=29 loc='kcb2.h LINE:3844 ID:kcbzww' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-11 22:00:00.549346 :A36D35F5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=14 loc='kcrf.h LINE:3299 ID:kcrfw_redo_gen: wake LGWR after redo copy' id1=0 id2=0 name= type=0 2025-06-11 22:00:00.549385 :A36D35F7: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-11 22:00:00.549423 :A36D35F8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-06-11 22:00:00.549541 :A36D360D: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-11 22:00:00.641901 :A36D37EC:db_trace:ksl2.c@12699:ksliwat(): [10005:27:219] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-06-11 22:00:00.643979 :A36D37ED: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-11 22:00:00.644023 :A36D37F0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpus:jslv.c:9203 2025-06-11 22:00:00.646457 :A36D37F6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:27:219] atxpop:jslv.c:9203 2025-06-11 22:00:00.649981 :A36D37F7: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-11 22:00:00.650060 :A36D37FA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:27:219] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-06-11 22:00:00.650156 :A36D3807: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 27 (osid: 9904, J002)