Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250621220707\orcl_j000_10360_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:36400M/63366M, Ph+PgF:42697M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 25 Windows thread id: 10360, image: ORACLE.EXE (J000) *** 2025-06-21 22:07:07.418 *** SESSION ID:(201.36453) 2025-06-21 22:07:07.418 *** 2025-06-21 22:07:07.418 Process diagnostic dump for ORACLE.EXE (J000), OS id=10360, pid: 25, proc_ser: 113, sid: 201, sess_ser: 36453 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 10360 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12633, hash value=1117129802 Current Wait Stack: Not in wait; last wait ended 2.171667 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.171693 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=62 seq_num=63 snap_id=1 wait times: snap=0.000170 sec, exc=0.000170 sec, total=0.000170 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.054723 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=61 seq_num=62 snap_id=1 wait times: snap=0.000007 sec, exc=0.000007 sec, total=0.000007 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.755533 sec of elapsed time 2: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=60 seq_num=61 snap_id=1 wait times: snap=0.000004 sec, exc=0.000004 sec, total=0.000004 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.025532 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=59 seq_num=60 snap_id=1 wait times: snap=0.000007 sec, exc=0.000007 sec, total=0.000007 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.012893 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=58 seq_num=59 snap_id=1 wait times: snap=0.000109 sec, exc=0.000109 sec, total=0.000109 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049848 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=57 seq_num=58 snap_id=1 wait times: snap=0.006786 sec, exc=0.006786 sec, total=0.006786 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007775 sec of elapsed time 6: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=56 seq_num=57 snap_id=1 wait times: snap=0.000121 sec, exc=0.000121 sec, total=0.000121 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.263702 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=55 seq_num=56 snap_id=1 wait times: snap=0.003843 sec, exc=0.003843 sec, total=0.003843 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000174 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=54 seq_num=55 snap_id=1 wait times: snap=0.000123 sec, exc=0.000123 sec, total=0.000123 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007990 sec of elapsed time 9: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=53 seq_num=54 snap_id=1 wait times: snap=0.000000 sec, exc=0.000000 sec, total=0.000000 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.000057 sec of elapsed time Sampled Session History of session 201 serial 36453 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [4 samples, 22:07:03 - 22:07:06] not in wait at each sample [11 samples, 22:06:52 - 22:07:02] idle wait at each sample [session created at: 22:06:52] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-06-21 22:07:07.418 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 25 (osid: 10360, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-06-21 22:04:50.343990 :A7D63821:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:04:50.335 2025-06-21 22:04:50.343992 :A7D63822:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=9064 pso_num=25 pso_serial#=99 2025-06-21 22:04:50.344129 :A7D63823:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=9064 (legacy spawn) 2025-06-21 22:04:50.350538 :A7D63824:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:04:50.350718 :A7D6382C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:04:50.351624 :A7D6382E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:04:51.967536 :A7D638EE:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:04:51.954 2025-06-21 22:04:51.967539 :A7D638EF:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17164 pso_num=25 pso_serial#=100 2025-06-21 22:04:51.967686 :A7D638F0:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=17164 osp_idx=23 osp_ver=163922 osp_pg=0 (spawn #309174) 2025-06-21 22:04:51.967687 :A7D638F1:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-21 22:04:51.967688 :A7D638F2:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=3 time=3519235157 2025-06-21 22:04:51.967688 :A7D638F3:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-21 22:04:51.967688 :A7D638F4:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-21 22:04:51.967689 :A7D638F5:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-21 22:04:51.967689 :A7D638F6:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-21 22:04:51.967690 :A7D638F7:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-21 22:04:51.968180 :A7D638F8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-21 22:04:51.968819 :A7D6390D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:04:51.979882 :A7D63929:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-06-21 22:04:51.980359 :A7D6392A:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-06-21 22:04:51.982708 :A7D6392B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-06-21 22:04:51.983101 :A7D6392C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:04:51.983138 :A7D6392F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-06-21 22:04:51.984031 :A7D63935:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:04:51.984152 :A7D6393D:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:05:22.032888 :A7D64B63:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:05:38.746832 :A7D65042:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:05:38.738 2025-06-21 22:05:38.746834 :A7D65043:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17616 pso_num=25 pso_serial#=101 2025-06-21 22:05:38.746975 :A7D65044:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=17616 (legacy spawn) 2025-06-21 22:05:38.753461 :A7D65045:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:05:38.753633 :A7D6504A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:05:38.754449 :A7D6504F:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:05:44.693445 :A7D65224:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:05:44.684 2025-06-21 22:05:44.693448 :A7D65225:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16256 pso_num=25 pso_serial#=102 2025-06-21 22:05:44.693594 :A7D65226:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=16256 (legacy spawn) 2025-06-21 22:05:44.700577 :A7D65227:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:05:44.700750 :A7D6522C:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:05:44.701662 :A7D65231:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:05:50.404341 :A7D653FF:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:05:50.390 2025-06-21 22:05:50.404343 :A7D65400:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15584 pso_num=25 pso_serial#=103 2025-06-21 22:05:50.404479 :A7D65401:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15584 (legacy spawn) 2025-06-21 22:05:50.410967 :A7D65402:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:05:50.411167 :A7D6540A:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:05:50.411974 :A7D6540C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:05:50.420656 :A7D6540F:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:05:50.406 2025-06-21 22:05:50.420658 :A7D65410:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17476 pso_num=25 pso_serial#=104 2025-06-21 22:05:50.420790 :A7D65411:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=17476 (legacy spawn) 2025-06-21 22:05:50.427224 :A7D65412:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:05:50.427389 :A7D6541B:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:05:50.428166 :A7D6541C:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:05:52.056906 :A7D654E2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:05:52.051 2025-06-21 22:05:52.056907 :A7D654E3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=14940 pso_num=25 pso_serial#=105 2025-06-21 22:05:52.057044 :A7D654E4:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=14940 osp_idx=23 osp_ver=163927 osp_pg=0 (spawn #309176) 2025-06-21 22:05:52.057045 :A7D654E5:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-21 22:05:52.057045 :A7D654E6:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=4 time=3519295250 2025-06-21 22:05:52.057045 :A7D654E7:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-21 22:05:52.057046 :A7D654E8:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-21 22:05:52.057046 :A7D654E9:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-21 22:05:52.057046 :A7D654EA:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-21 22:05:52.057047 :A7D654EB:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-21 22:05:52.057528 :A7D654EC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-21 22:05:52.058193 :A7D65501:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:05:52.065711 :A7D6551D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-06-21 22:05:52.066080 :A7D6551E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:05:52.066121 :A7D65521:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-06-21 22:05:52.067050 :A7D65527:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:05:52.067178 :A7D65530:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:06:22.186880 :A7D66068:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:06:26.899633 :A7D661A2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:06:26.885 2025-06-21 22:06:26.899635 :A7D661A3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16720 pso_num=25 pso_serial#=106 2025-06-21 22:06:26.899774 :A7D661A4:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=16720 (legacy spawn) 2025-06-21 22:06:26.906274 :A7D661A5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:26.906444 :A7D661AA:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:06:26.907226 :A7D661AF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:06:26.915888 :A7D661B2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:06:26.900 2025-06-21 22:06:26.915890 :A7D661B3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17208 pso_num=25 pso_serial#=107 2025-06-21 22:06:26.916029 :A7D661B4:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=17208 (legacy spawn) 2025-06-21 22:06:26.922418 :A7D661B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:26.922594 :A7D661BE:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:06:26.923369 :A7D661BF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:06:30.095897 :A7D662D2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:06:30.082 2025-06-21 22:06:30.095899 :A7D662D3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=17392 pso_num=25 pso_serial#=108 2025-06-21 22:06:30.096035 :A7D662D4:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=17392 (legacy spawn) 2025-06-21 22:06:30.102477 :A7D662D5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:30.102644 :A7D662DA:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:06:30.103437 :A7D662DF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:06:30.111981 :A7D662E2:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:06:30.098 2025-06-21 22:06:30.111983 :A7D662E3:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16572 pso_num=25 pso_serial#=109 2025-06-21 22:06:30.112120 :A7D662E4:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=16572 (legacy spawn) 2025-06-21 22:06:30.118650 :A7D662E5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:30.118825 :A7D662ED:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:06:30.119635 :A7D662EF:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:06:33.480724 :A7D66411:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:06:33.472 2025-06-21 22:06:33.480727 :A7D66412:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=16516 pso_num=25 pso_serial#=110 2025-06-21 22:06:33.480888 :A7D66413:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=16516 (legacy spawn) 2025-06-21 22:06:33.487275 :A7D66414:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:33.487449 :A7D66419:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:06:33.488282 :A7D6641E:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:06:46.917020 :A7D6681B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:06:46.908 2025-06-21 22:06:46.917022 :A7D6681C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=15596 pso_num=25 pso_serial#=111 2025-06-21 22:06:46.917162 :A7D6681D:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=15596 (legacy spawn) 2025-06-21 22:06:46.923656 :A7D6681E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:46.923826 :A7D66823:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:06:46.924628 :A7D66828:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:06:46.932768 :A7D6682B:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:06:46.924 2025-06-21 22:06:46.932770 :A7D6682C:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=18088 pso_num=25 pso_serial#=112 2025-06-21 22:06:46.932908 :A7D6682D:db_trace:kso.c@4070:ksonfy(): [10420:25:0] kso: new process: pid=18088 (legacy spawn) 2025-06-21 22:06:46.939320 :A7D6682E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:46.939490 :A7D66837:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:06:46.940327 :A7D66838:db_trace:kst.c@698:kstpsodel(): [10280:25:0] kst: process state object about to be deleted 2025-06-21 22:06:52.156465 :A7D669F3:db_trace:kst.c@673:kstipg(): [10280:25:0] kst: process state object created on 06-21 22:06:52.151 2025-06-21 22:06:52.156467 :A7D669F4:db_trace:kst.c@679:kstipg(): [10280:25:0] kst: process info: ospid=10360 pso_num=25 pso_serial#=113 2025-06-21 22:06:52.156607 :A7D669F5:db_trace:kso.c@4093:ksonfy(): [10420:25:0] kso: new process: pid=10360 osp_idx=23 osp_ver=163935 osp_pg=0 (spawn #309178) 2025-06-21 22:06:52.156608 :A7D669F6:db_trace:kso.c@4099:ksonfy(): [10420:25:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-06-21 22:06:52.156609 :A7D669F7:db_trace:kso.c@4103:ksonfy(): [10420:25:0] kso: new process: pso_index=25 reservation=5 time=3519355344 2025-06-21 22:06:52.156609 :A7D669F8:db_trace:kso.c@4109:ksonfy(): [10420:25:0] kso: spawn diagnostics: queue time=0 secs 2025-06-21 22:06:52.156610 :A7D669F9:db_trace:kso.c@4111:ksonfy(): [10420:25:0] kso: spawn diagnostics: fork time=0 secs 2025-06-21 22:06:52.156610 :A7D669FA:db_trace:kso.c@4113:ksonfy(): [10420:25:0] kso: spawn diagnostics: exec time=0 secs 2025-06-21 22:06:52.156610 :A7D669FB:db_trace:kso.c@4115:ksonfy(): [10420:25:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-06-21 22:06:52.156611 :A7D669FC:db_trace:kso.c@4117:ksonfy(): [10420:25:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-06-21 22:06:52.157094 :A7D669FD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-06-21 22:06:52.157755 :A7D66A12:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:52.168780 :A7D66A2E:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-06-21 22:06:52.169235 :A7D66A2F:db_trace:kwqid.c@2146:kwqidrdq(): [10960:25:201] kwqidrdq: Error: 1403 occured in OCI execute 2025-06-21 22:06:52.171588 :A7D66A30:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-06-21 22:06:52.171970 :A7D66A31:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:52.172005 :A7D66A34:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-06-21 22:06:52.172914 :A7D66A3A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:06:52.173043 :A7D66A43:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:07:03.482755 :A7D66F24:db_trace:ksl2.c@12699:ksliwat(): [10005:25:201] 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-21 22:07:03.482755*:A7D66F26:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000026BEC718 estart=1750514822 eid=16782771 ctx=0x000000077FD6A000 cwh=0x0000000026BE0068 cpu=0 buffg=1 interb=0 r=0 rb=0 w=0 wb=0 2025-06-21 22:07:03.482755*:A7D66F27:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 pubTabIdxCnt=0 2025-06-21 22:07:03.482755*:A7D66F28:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000026BEC718 2025-06-21 22:07:03.482755*:A7D66F29:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000026BEC718 2025-06-21 22:07:03.482755*:A7D66F32:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000026BEC718 curCtx=0x0000000026BE8938 xsc->flg4=65792 flags=2 2025-06-21 22:07:03.482755*:A7D66F33:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000026BEC718 2025-06-21 22:07:03.484568 :A7D66F3E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.484591 :A7D66F42:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:jslv.c:9203 2025-06-21 22:07:03.502786 :A7D66F68:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.502975 :A7D66F70:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.503132 :A7D66F78:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.503280 :A7D66F80:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.503442 :A7D66F88:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.503616 :A7D66F90:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.503831 :A7D66F98:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.503975 :A7D66FA0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.504284 :A7D66FA8:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.504525 :A7D66FB0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:03.522660 :A7D66FC4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:04.887006*:A7D6707C:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000027A83AD0 estart=1750514824 eid=19642967 ctx=0x0000000777968158 cwh=0x00000000299B0068 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-06-21 22:07:04.887006*:A7D6707D:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000027A83AD0 curCtx=0x0000000029A719A8 pubTabIdxCnt=0 2025-06-21 22:07:04.887006*:A7D6707E:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000027A83AD0 2025-06-21 22:07:04.887006*:A7D6707F:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000027A83AD0 2025-06-21 22:07:04.887006*:A7D67080:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000027AEB820 estart=1750514822 eid=16777405 ctx=0x000000077B54EAC8 cwh=0x0000000026C10608 cpu=1171875 buffg=65389 interb=196608 r=24 rb=196608 w=0 wb=0 2025-06-21 22:07:04.887006*:A7D67081:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000027AEB820 curCtx=0x0000000029A79FF0 pubTabIdxCnt=0 2025-06-21 22:07:04.887006*:A7D67082:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000027AEB820 2025-06-21 22:07:04.887006*:A7D67083:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000027AEB820 2025-06-21 22:07:04.887006*:A7D67084:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000027A83AD0 curCtx=0x0000000029A719A8 xsc->flg4=65792 flags=1 2025-06-21 22:07:04.887006*:A7D67085:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000027A83AD0 2025-06-21 22:07:05.168258*:A7D6711B:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000027AEB820 curCtx=0x0000000029A79FF0 xsc->flg4=65792 flags=2 2025-06-21 22:07:05.168258*:A7D6711C:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000027AEB820 2025-06-21 22:07:05.177077 :A7D6711D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:05.197068 :A7D6713F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:05.199062 :A7D67147:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpus:psdpgi.c:2235 2025-06-21 22:07:05.199257 :A7D67148:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:25:201] atxpop:psdpgi.c:2235 2025-06-21 22:07:05.200747 :A7D67149:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:05.200893 :A7D6714C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:05.202040 :A7D6715E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:05.203821 :A7D67166:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:05.204142 :A7D6716E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:05.246385*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-06-21 22:07:05.246385*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-06-21 22:07:05.246385*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-06-21 22:07:05.262009*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-06-21 22:07:05.262009*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-06-21 22:07:05.262009*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-06-21 22:07:05.262009*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-06-21 22:07:05.335015 :A7D671DB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:07.213630 :A7D672D7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:25:201] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-06-21 22:07:07.213642 :A7D672D8:db_trace:ktur.c@3079:ktuabt(): [10444:25:201] ABORT TRANSACTION - xid: 0x0002.00e.0000c3a1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 25 (osid: 10360, J000)