Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250516220007\orcl_j005_12956_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:37363M/63366M, Ph+PgF:44549M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 31 Windows thread id: 12956, image: ORACLE.EXE (J005) *** 2025-05-16 22:00:07.483 *** SESSION ID:(249.703) 2025-05-16 22:00:07.483 *** 2025-05-16 22:00:07.483 Process diagnostic dump for ORACLE.EXE (J005), OS id=12956, pid: 31, proc_ser: 88, sid: 249, sess_ser: 703 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 12956 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J005) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.000714 sec, exc=0.000714 sec, total=0.000714 sec wait times: max=0.500000 sec, heur=6.552588 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.000013 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.500095 sec, exc=0.500095 sec, total=0.500095 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000013 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.499987 sec, exc=0.499987 sec, total=0.499987 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=10 seq_num=11 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.000009 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.515413 sec, exc=0.515413 sec, total=0.515413 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.500002 sec, exc=0.500002 sec, total=0.500002 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=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.000012 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.510102 sec, exc=0.510102 sec, total=0.510102 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=5 seq_num=6 snap_id=1 wait times: snap=0.510101 sec, exc=0.510101 sec, total=0.510101 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=4 seq_num=5 snap_id=1 wait times: snap=0.510095 sec, exc=0.510095 sec, total=0.510095 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000014 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=3 seq_num=4 snap_id=1 wait times: snap=0.500002 sec, exc=0.500002 sec, total=0.500002 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time Sampled Session History of session 249 serial 703 --------------------------------------------------- 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 --------------------------------------------------- [7 samples, 22:00:00 - 22:00:07] 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-05-16 22:00:07.483 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 31 (osid: 12956, J005) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-14 23:59:13.478222 :97295E57:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-14 23:59:13.476 2025-05-14 23:59:13.478223 :97295E58:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=12604 pso_num=31 pso_serial#=75 2025-05-14 23:59:13.478361 :97295E59:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=12604 (legacy spawn) 2025-05-14 23:59:13.492462 :97295E5A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-14 23:59:46.527382 :97296A37:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-14 23:59:47.152122 :97296AA6:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-14 23:59:47.149 2025-05-14 23:59:47.152124 :97296AA7:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=10320 pso_num=31 pso_serial#=76 2025-05-14 23:59:47.152255 :97296AA8:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=10320 (legacy spawn) 2025-05-14 23:59:47.166845 :97296AA9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-14 23:59:50.504582 :97296B99:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-14 23:59:50.504762 :97296B9E:db_trace:ksl2.c@12699:ksliwat(): [10005:31:249] 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-05-14 23:59:50.506251 :97296BA3:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-14 23:59:50.753146 :97296BB5:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-14 23:59:50.748 2025-05-14 23:59:50.753149 :97296BB6:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=10908 pso_num=31 pso_serial#=77 2025-05-14 23:59:50.753285 :97296BB7:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=10908 (legacy spawn) 2025-05-14 23:59:50.767397 :97296BB8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 00:00:23.823741 :97297920:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 01:00:13.249664 :972E2B20:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 01:00:13.238 2025-05-15 01:00:13.249666 :972E2B21:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=6832 pso_num=31 pso_serial#=78 2025-05-15 01:00:13.249794 :972E2B22:db_trace:kso.c@4093:ksonfy(): [10420:31:0] kso: new process: pid=6832 osp_idx=29 osp_ver=332 osp_pg=0 (spawn #182913) 2025-05-15 01:00:13.249795 :972E2B23:db_trace:kso.c@4099:ksonfy(): [10420:31:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 01:00:13.249796 :972E2B24:db_trace:kso.c@4103:ksonfy(): [10420:31:0] kso: new process: pso_index=31 reservation=114 time=246623110 2025-05-15 01:00:13.249796 :972E2B25:db_trace:kso.c@4109:ksonfy(): [10420:31:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 01:00:13.249796 :972E2B26:db_trace:kso.c@4111:ksonfy(): [10420:31:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 01:00:13.249797 :972E2B27:db_trace:kso.c@4113:ksonfy(): [10420:31:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 01:00:13.249797 :972E2B28:db_trace:kso.c@4115:ksonfy(): [10420:31:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 01:00:13.249797 :972E2B29:db_trace:kso.c@4117:ksonfy(): [10420:31:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 01:00:13.250301 :972E2B2A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.250351 :972E2B30:db_trace:ksl2.c@12699:ksliwat(): [10005:31:249] 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-05-15 01:00:13.257557 :972E2B3E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.258618 :972E2B46:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.259113 :972E2B4E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.259554 :972E2B56:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.259974 :972E2B5E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.262712 :972E2B66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.263801 :972E2B6E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.313047 :972E2B76:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.313928 :972E2B7E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.314160 :972E2B86:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.314775 :972E2B8E:db_trace:ktu.c@4871:ktuaex1r(): [10442:31:249] Extension usn 6, ext 3, nex 6 2025-05-15 01:00:13.314786 :972E2B8F:db_trace:ktusm.c@2117:ktusmasp(): [10445:31:249] des1:tsn:1 rdba:0x0081421b where: kduwh01: kdusru 2025-05-15 01:00:13.315041 :972E2B90:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 01:00:13.316797 :972E2B98:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 22:00:00.746802 :97922A49:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 22:00:00.743 2025-05-15 22:00:00.746803 :97922A4A:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=3736 pso_num=31 pso_serial#=79 2025-05-15 22:00:00.746938 :97922A4B:db_trace:kso.c@4093:ksonfy(): [10420:31:0] kso: new process: pid=3736 osp_idx=29 osp_ver=333 osp_pg=0 (spawn #185827) 2025-05-15 22:00:00.746939 :97922A4C:db_trace:kso.c@4099:ksonfy(): [10420:31:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 22:00:00.746940 :97922A4D:db_trace:kso.c@4103:ksonfy(): [10420:31:0] kso: new process: pso_index=31 reservation=115 time=322210610 2025-05-15 22:00:00.746940 :97922A4E:db_trace:kso.c@4109:ksonfy(): [10420:31:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 22:00:00.746942 :97922A4F:db_trace:kso.c@4111:ksonfy(): [10420:31:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 22:00:00.746943 :97922A50:db_trace:kso.c@4113:ksonfy(): [10420:31:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 22:00:00.746943 :97922A51:db_trace:kso.c@4115:ksonfy(): [10420:31:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 22:00:00.746943 :97922A52:db_trace:kso.c@4117:ksonfy(): [10420:31:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 22:00:00.747766 :97922A5B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.753331 :97922BF2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.753379 :97922BF5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:31:249] atxpus:jslv.c:9203 2025-05-15 22:00:00.770642 :97922CAB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.770832 :97922CB3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.771004 :97922CBB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.771165 :97922CC3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.771328 :97922CCB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.771483 :97922CD3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.771635 :97922CDB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.771787 :97922CE3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.771938 :97922CEB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.772092 :97922CF3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.772245 :97922CFB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.772396 :97922D03:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.772567 :97922D0B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.772737 :97922D13:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.772987 :97922D1B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.773144 :97922D23:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.773333 :97922D2B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.773662 :97922D33:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.773848 :97922D3B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.774007 :97922D43:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.774261 :97922D4B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.774506 :97922D53:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.774748 :97922D5B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.775365 :97922D63:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.775636 :97922D6B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.775885 :97922D73:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.776102 :97922D7B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.776354 :97922D83:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.776513 :97922D8B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.776666 :97922D93:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.776815 :97922D9B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:00.792745 :97922DCA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] 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-05-15 22:00:00.795056 :97922DD9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] 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-05-15 22:00:00.802586 :97922DF6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] 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-05-15 22:00:00.803317 :97922DFD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:02.489183 :9792322B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:02.511375 :9792324D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:02.513574 :97923255:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:31:249] atxpus:psdpgi.c:2235 2025-05-15 22:00:02.513808 :97923256:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:31:249] atxpop:psdpgi.c:2235 2025-05-15 22:00:02.514809 :97923257:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:02.514913 :9792325A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:02.515820 :9792326C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:02.517491 :97923274:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:02.517804 :9792327C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:02.581183*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-05-15 22:00:02.581183*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-15 22:00:02.581183*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-15 22:00:02.581183*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-15 22:00:02.581183*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-15 22:00:02.581183*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-15 22:00:02.581183*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-15 22:00:02.628059*:97923336:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000003CE7D688 estart=1747317602 eid=16777615 ctx=0x000000079F4EAD08 cwh=0x0000000034170930 cpu=0 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-05-15 22:00:02.628059*:97923337:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000003CE7D688 curCtx=0x000000003CEC84A0 pubTabIdxCnt=0 2025-05-15 22:00:02.628059*:97923338:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000003CE7D688 2025-05-15 22:00:02.628059*:97923339:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000003CE7D688 2025-05-15 22:00:02.643693*:97923343:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000003CE7D688 curCtx=0x000000003CEC84A0 xsc->flg4=65792 flags=1 2025-05-15 22:00:02.643693*:97923344:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000003CE7D688 2025-05-15 22:00:02.664575 :97923345:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:04.543876 :97923565:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:04.543889 :97923566:db_trace:ktur.c@3079:ktuabt(): [10444:31:249] ABORT TRANSACTION - xid: 0x0009.013.0001c718 2025-05-15 22:00:07.158774 :979237E2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:07.160403 :979237EA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:07.171753 :979237F2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:07.195912 :979237FA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:08.342696 :979238B0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:31:249] atxpop:jslv.c:9203 2025-05-15 22:00:08.352991 :979238B1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:0] KSL POST SENT postee=59 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:08.353402 :979238B9:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 22:00:15.436323 :97923BA8:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 22:00:15.423 2025-05-15 22:00:15.436325 :97923BA9:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=7548 pso_num=31 pso_serial#=80 2025-05-15 22:00:15.436459 :97923BAA:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=7548 (legacy spawn) 2025-05-15 22:00:15.444152 :97923BAB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:15.444320 :97923BB3:db_trace:ksl2.c@12699:ksliwat(): [10005:31:249] 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-05-15 22:00:15.445115 :97923BB5:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 22:00:19.062970 :97923D01:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 22:00:19.055 2025-05-15 22:00:19.062972 :97923D02:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=12276 pso_num=31 pso_serial#=81 2025-05-15 22:00:19.063103 :97923D03:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=12276 (legacy spawn) 2025-05-15 22:00:19.069524 :97923D04:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:19.069698 :97923D09:db_trace:ksl2.c@12699:ksliwat(): [10005:31:249] 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-05-15 22:00:19.070493 :97923D0E:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 22:00:21.218918 :97923DAE:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 22:00:21.205 2025-05-15 22:00:21.218920 :97923DAF:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=13252 pso_num=31 pso_serial#=82 2025-05-15 22:00:21.219060 :97923DB0:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=13252 (legacy spawn) 2025-05-15 22:00:21.225558 :97923DB1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:21.225729 :97923DB6:db_trace:ksl2.c@12699:ksliwat(): [10005:31:249] 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-05-15 22:00:21.226535 :97923DBB:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 22:00:21.235138 :97923DBE:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 22:00:21.221 2025-05-15 22:00:21.235140 :97923DBF:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=12508 pso_num=31 pso_serial#=83 2025-05-15 22:00:21.235276 :97923DC0:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=12508 (legacy spawn) 2025-05-15 22:00:21.241715 :97923DC1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:21.241889 :97923DCA:db_trace:ksl2.c@12699:ksliwat(): [10005:31:249] 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-05-15 22:00:21.242682 :97923DCB:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 22:00:24.327471 :97923EBB:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 22:00:24.315 2025-05-15 22:00:24.327473 :97923EBC:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=12632 pso_num=31 pso_serial#=84 2025-05-15 22:00:24.327603 :97923EBD:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=12632 (legacy spawn) 2025-05-15 22:00:24.334008 :97923EBE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:24.334177 :97923EC6:db_trace:ksl2.c@12699:ksliwat(): [10005:31:249] 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-05-15 22:00:24.334999 :97923EC8:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 22:00:24.343597 :97923ECB:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 22:00:24.330 2025-05-15 22:00:24.343599 :97923ECC:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=10952 pso_num=31 pso_serial#=85 2025-05-15 22:00:24.343733 :97923ECD:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=10952 (legacy spawn) 2025-05-15 22:00:24.350213 :97923ECE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-15 22:00:24.350382 :97923ED7:db_trace:ksl2.c@12699:ksliwat(): [10005:31:249] 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-05-15 22:00:24.351160 :97923ED8:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 23:59:11.835278 :979BC7C5:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 23:59:11.824 2025-05-15 23:59:11.835280 :979BC7C6:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=8672 pso_num=31 pso_serial#=86 2025-05-15 23:59:11.835402 :979BC7C7:db_trace:kso.c@4093:ksonfy(): [10420:31:0] kso: new process: pid=8672 osp_idx=29 osp_ver=340 osp_pg=0 (spawn #186104) 2025-05-15 23:59:11.835402 :979BC7C8:db_trace:kso.c@4099:ksonfy(): [10420:31:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-15 23:59:11.835403 :979BC7C9:db_trace:kso.c@4103:ksonfy(): [10420:31:0] kso: new process: pso_index=31 reservation=116 time=329361704 2025-05-15 23:59:11.835403 :979BC7CA:db_trace:kso.c@4109:ksonfy(): [10420:31:0] kso: spawn diagnostics: queue time=0 secs 2025-05-15 23:59:11.835404 :979BC7CB:db_trace:kso.c@4111:ksonfy(): [10420:31:0] kso: spawn diagnostics: fork time=0 secs 2025-05-15 23:59:11.835404 :979BC7CC:db_trace:kso.c@4113:ksonfy(): [10420:31:0] kso: spawn diagnostics: exec time=0 secs 2025-05-15 23:59:11.835404 :979BC7CD:db_trace:kso.c@4115:ksonfy(): [10420:31:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-15 23:59:11.835404 :979BC7CE:db_trace:kso.c@4117:ksonfy(): [10420:31:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-15 23:59:11.835907 :979BC7CF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-15 23:59:41.891056 :979BD2E9:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-15 23:59:55.108605 :979BD78E:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-15 23:59:55.106 2025-05-15 23:59:55.108607 :979BD78F:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=13916 pso_num=31 pso_serial#=87 2025-05-15 23:59:55.108771 :979BD790:db_trace:kso.c@4070:ksonfy(): [10420:31:0] kso: new process: pid=13916 (legacy spawn) 2025-05-15 23:59:55.122944 :979BD791:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-16 00:00:28.250571 :979BE7AB:db_trace:kst.c@698:kstpsodel(): [10280:31:0] kst: process state object about to be deleted 2025-05-16 22:00:00.930126 :9803D944:db_trace:kst.c@673:kstipg(): [10280:31:0] kst: process state object created on 05-16 22:00:00.927 2025-05-16 22:00:00.930127 :9803D945:db_trace:kst.c@679:kstipg(): [10280:31:0] kst: process info: ospid=12956 pso_num=31 pso_serial#=88 2025-05-16 22:00:00.930258 :9803D946:db_trace:kso.c@4093:ksonfy(): [10420:31:0] kso: new process: pid=12956 osp_idx=29 osp_ver=342 osp_pg=0 (spawn #189157) 2025-05-16 22:00:00.930259 :9803D947:db_trace:kso.c@4099:ksonfy(): [10420:31:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-16 22:00:00.930260 :9803D948:db_trace:kso.c@4103:ksonfy(): [10420:31:0] kso: new process: pso_index=31 reservation=117 time=408610782 2025-05-16 22:00:00.930261 :9803D949:db_trace:kso.c@4109:ksonfy(): [10420:31:0] kso: spawn diagnostics: queue time=0 secs 2025-05-16 22:00:00.930261 :9803D94A:db_trace:kso.c@4111:ksonfy(): [10420:31:0] kso: spawn diagnostics: fork time=0 secs 2025-05-16 22:00:00.930262 :9803D94B:db_trace:kso.c@4113:ksonfy(): [10420:31:0] kso: spawn diagnostics: exec time=0 secs 2025-05-16 22:00:00.930262 :9803D94C:db_trace:kso.c@4115:ksonfy(): [10420:31:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-16 22:00:00.930263 :9803D94D:db_trace:kso.c@4117:ksonfy(): [10420:31:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-16 22:00:00.930849 :9803D95F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:31:249] 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 31 (osid: 12956, J005)