Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250518060006\orcl_j003_13448_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:37399M/63366M, Ph+PgF:44592M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 13448, image: ORACLE.EXE (J003) *** 2025-05-18 06:00:06.368 *** SESSION ID:(233.22465) 2025-05-18 06:00:06.368 *** 2025-05-18 06:00:06.368 Process diagnostic dump for ORACLE.EXE (J003), OS id=13448, pid: 29, proc_ser: 241, sid: 233, sess_ser: 22465 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 13448 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12450, hash value=425261859 Current Wait Stack: Not in wait; last wait ended 2.960163 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.960189 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=39 seq_num=40 snap_id=1 wait times: snap=0.000154 sec, exc=0.000154 sec, total=0.000154 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.064071 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=38 seq_num=39 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.750129 sec of elapsed time 2: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=37 seq_num=38 snap_id=1 wait times: snap=0.000003 sec, exc=0.000003 sec, total=0.000003 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.025216 sec of elapsed time 3: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000003 sec, exc=0.000003 sec, total=0.000003 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.013029 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.000073 sec, exc=0.000073 sec, total=0.000073 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049461 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=34 seq_num=35 snap_id=1 wait times: snap=0.000101 sec, exc=0.000101 sec, total=0.000101 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007855 sec of elapsed time 6: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.000074 sec, exc=0.000074 sec, total=0.000074 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.262217 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.006488 sec, exc=0.006488 sec, total=0.006488 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000167 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=31 seq_num=32 snap_id=1 wait times: snap=0.000116 sec, exc=0.000116 sec, total=0.000116 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007902 sec of elapsed time 9: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=30 seq_num=31 snap_id=1 wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.000056 sec of elapsed time Sampled Session History of session 233 serial 22465 --------------------------------------------------- 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 --------------------------------------------------- [5 samples, 06:00:02 - 06:00:06] not in wait at each sample [1 sample, 06:00:01] idle wait at each sample [session created at: 06:00:01] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-18 06:00:06.368 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 13448, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-18 01:00:18.102943 :9884A5C5:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13204 (legacy spawn) 2025-05-18 01:00:18.109458 :9884A5C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:18.109622 :9884A5CB:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 01:00:18.110453 :9884A5D0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-18 01:00:18.119083 :9884A5D3:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-18 01:00:18.104 2025-05-18 01:00:18.119085 :9884A5D4:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12576 pso_num=29 pso_serial#=234 2025-05-18 01:00:18.119224 :9884A5D5:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=12576 (legacy spawn) 2025-05-18 01:00:18.125723 :9884A5D6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:18.125890 :9884A5DF:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 01:00:18.126695 :9884A5E0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-18 01:00:21.210951 :9884A6DB:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-18 01:00:21.198 2025-05-18 01:00:21.210953 :9884A6DC:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10332 pso_num=29 pso_serial#=235 2025-05-18 01:00:21.211092 :9884A6DD:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=10332 (legacy spawn) 2025-05-18 01:00:21.230935 :9884A6DE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:21.231112 :9884A6E3:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 01:00:21.231954 :9884A6E8:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-18 01:00:21.240688 :9884A6EB:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-18 01:00:21.229 2025-05-18 01:00:21.240690 :9884A6EC:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13688 pso_num=29 pso_serial#=236 2025-05-18 01:00:21.240824 :9884A6ED:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=13688 (legacy spawn) 2025-05-18 01:00:21.247323 :9884A6EE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:21.247482 :9884A6F6:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-18 01:00:21.248323 :9884A6F8:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-18 01:00:59.959903 :9884B57D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-18 01:00:59.947 2025-05-18 01:00:59.959905 :9884B57E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12828 pso_num=29 pso_serial#=237 2025-05-18 01:00:59.960041 :9884B57F:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12828 osp_idx=27 osp_ver=11201 osp_pg=0 (spawn #192927) 2025-05-18 01:00:59.960042 :9884B580:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 01:00:59.960042 :9884B581:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=161 time=505869829 2025-05-18 01:00:59.960042 :9884B582:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 01:00:59.960043 :9884B583:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 01:00:59.960043 :9884B584:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 01:00:59.960044 :9884B585:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 01:00:59.960044 :9884B586:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 01:00:59.960522 :9884B587:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 01:00:59.960564 :9884B58D:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 01:00:59.967784 :9884B59B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:59.968828 :9884B5A3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:59.969469 :9884B5AB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:59.969959 :9884B5B3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:59.970407 :9884B5BB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:59.972867 :9884B5C3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:00:59.974071 :9884B5CB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:01:00.023632 :9884B5D3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:01:00.024537 :9884B5DB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:01:00.024770 :9884B5E3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:01:00.024989 :9884B5EB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 01:01:00.026764 :9884B5F3:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-18 01:03:58.994572 :9884F22D:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-18 01:03:58.982 2025-05-18 01:03:58.994574 :9884F22E:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11284 pso_num=29 pso_serial#=238 2025-05-18 01:03:58.994703 :9884F22F:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11284 osp_idx=27 osp_ver=11202 osp_pg=0 (spawn #192935) 2025-05-18 01:03:58.994704 :9884F230:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 01:03:58.994704 :9884F231:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=162 time=506048860 2025-05-18 01:03:58.994705 :9884F232:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 01:03:58.994705 :9884F233:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 01:03:58.994705 :9884F234:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 01:03:58.994706 :9884F235:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 01:03:58.994706 :9884F236:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 01:03:58.995289 :9884F237:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 01:03:58.995329 :9884F23D:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 01:03:59.003326 :9884F25F:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-18 01:19:00.931561 :98862AA9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-18 01:19:00.919 2025-05-18 01:19:00.931563 :98862AAA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=2956 pso_num=29 pso_serial#=239 2025-05-18 01:19:00.931702 :98862AAB:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=2956 osp_idx=27 osp_ver=11203 osp_pg=0 (spawn #192970) 2025-05-18 01:19:00.931703 :98862AAC:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 01:19:00.931704 :98862AAD:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=163 time=506950797 2025-05-18 01:19:00.931704 :98862AAE:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 01:19:00.931704 :98862AAF:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 01:19:00.931705 :98862AB0:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 01:19:00.931705 :98862AB1:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 01:19:00.931705 :98862AB2:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 01:19:00.932218 :98862AB3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 01:19:00.932258 :98862AB9:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 01:19:00.936330 :98862AE1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:19:00.936377 :98862AE2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:19:00.936630 :98862AE3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:19:00.936647 :98862AE4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:19:00.936859 :98862AE5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:19:00.936873 :98862AE6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:19:00.937077 :98862AE7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:19:00.937089 :98862AE8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:19:00.937294 :98862AE9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:19:00.937307 :98862AEA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:19:00.937506 :98862AEB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:19:00.937519 :98862AEC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:19:00.939906 :98862AED:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-18 01:49:04.861638 :98888A68:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-18 01:49:04.849 2025-05-18 01:49:04.861640 :98888A69:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11680 pso_num=29 pso_serial#=240 2025-05-18 01:49:04.861784 :98888A6A:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11680 osp_idx=27 osp_ver=11204 osp_pg=0 (spawn #193037) 2025-05-18 01:49:04.861785 :98888A6B:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 01:49:04.861785 :98888A6C:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=164 time=508754719 2025-05-18 01:49:04.861785 :98888A6D:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 01:49:04.861786 :98888A6E:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 01:49:04.861786 :98888A6F:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 01:49:04.861786 :98888A70:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 01:49:04.861787 :98888A71:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 01:49:04.862331 :98888A72:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 01:49:04.862386 :98888A78:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-18 01:49:04.866452 :98888A91:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:49:04.866496 :98888A92:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:49:04.866747 :98888A93:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:49:04.866763 :98888A94:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:49:04.866988 :98888A95:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:49:04.867001 :98888A96:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:49:04.867204 :98888A97:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:49:04.867217 :98888A98:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:49:04.867426 :98888A99:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:49:04.867438 :98888A9A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:49:04.867637 :98888A9B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-18 01:49:04.867650 :98888A9C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-18 01:49:04.870052 :98888A9D:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-18 06:00:01.641652 :989CC4D4:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-18 06:00:01.634 2025-05-18 06:00:01.641653 :989CC4D5:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13448 pso_num=29 pso_serial#=241 2025-05-18 06:00:01.641795 :989CC4D6:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13448 osp_idx=27 osp_ver=11205 osp_pg=0 (spawn #193618) 2025-05-18 06:00:01.641796 :989CC4D7:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-18 06:00:01.641796 :989CC4D8:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=165 time=523811516 2025-05-18 06:00:01.641797 :989CC4D9:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-18 06:00:01.641797 :989CC4DA:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-18 06:00:01.641798 :989CC4DB:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-18 06:00:01.641799 :989CC4DC:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-18 06:00:01.641799 :989CC4DD:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-18 06:00:01.642334 :989CC4E1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.647520 :989CC4FB:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.647571 :989CC4FE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-05-18 06:00:01.665725 :989CC6E4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.665910 :989CC6EC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.666078 :989CC6F4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.666278 :989CC6FE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.666444 :989CC706:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.666594 :989CC70E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.666752 :989CC72C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.666913 :989CC734:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.667062 :989CC73C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.667205 :989CC744:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.667353 :989CC74C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.667506 :989CC754:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.667653 :989CC75C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.667796 :989CC764:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.667950 :989CC76C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.668138 :989CC774:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.668287 :989CC77C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.668440 :989CC784:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.668593 :989CC78C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.668745 :989CC794:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.668892 :989CC79C:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.669036 :989CC7A4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.669190 :989CC7AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.669336 :989CC7B4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.669519 :989CC7BC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:01.691997 :989CC7C4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:02.727909*:989CC93D:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DB03AD0 estart=1747519202 eid=18521299 ctx=0x0000000777968158 cwh=0x000000002DB309C8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-05-18 06:00:02.727909*:989CC93E:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DB03AD0 curCtx=0x000000003D627918 pubTabIdxCnt=0 2025-05-18 06:00:02.727909*:989CC93F:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DB03AD0 2025-05-18 06:00:02.727909*:989CC940:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DB03AD0 2025-05-18 06:00:02.727909*:989CC941:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x000000002DB7B6F0 estart=1747519201 eid=16777331 ctx=0x000000077B54EAC8 cwh=0x000000002DB30518 cpu=859375 buffg=49201 interb=196608 r=24 rb=196608 w=0 wb=0 2025-05-18 06:00:02.727909*:989CC942:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x000000002DB7B6F0 curCtx=0x000000003D5087D0 pubTabIdxCnt=0 2025-05-18 06:00:02.727909*:989CC943:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x000000002DB7B6F0 2025-05-18 06:00:02.727909*:989CC944:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x000000002DB7B6F0 2025-05-18 06:00:02.727909*:989CC945:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB03AD0 curCtx=0x000000003D627918 xsc->flg4=65792 flags=1 2025-05-18 06:00:02.727909*:989CC946:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB03AD0 2025-05-18 06:00:03.323383 :989CCB10:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] 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-18 06:00:03.323383*:989CCB49:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x000000002DB7B6F0 curCtx=0x000000003D5087D0 xsc->flg4=65792 flags=2 2025-05-18 06:00:03.323383*:989CCB4A:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x000000002DB7B6F0 2025-05-18 06:00:03.333736 :989CCB4B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:03.353843 :989CCB53:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:03.355768 :989CCB5B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-05-18 06:00:03.355965 :989CCB5C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-05-18 06:00:03.356832 :989CCB5D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:03.356922 :989CCB60:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:03.357893 :989CCB72:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:03.359362 :989CCB7A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:03.359631 :989CCB82:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:03.415901*: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-18 06:00:03.415901*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-05-18 06:00:03.415901*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-05-18 06:00:03.415901*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-05-18 06:00:03.415901*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-05-18 06:00:03.415901*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-05-18 06:00:03.415901*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-05-18 06:00:03.492135 :989CCB8A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:05.355741 :989CCC4D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-18 06:00:05.355753 :989CCC4E:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0002.020.0000c0a3 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 13448, J003)