Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250907180706\orcl_j000_19064_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:34965M/63366M, Ph+PgF:39777M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 19064, image: ORACLE.EXE (J000) *** 2025-09-07 18:07:06.837 *** SESSION ID:(177.13401) 2025-09-07 18:07:06.837 *** 2025-09-07 18:07:06.837 Process diagnostic dump for ORACLE.EXE (J000), OS id=19064, pid: 22, proc_ser: 218, sid: 177, sess_ser: 13401 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 19064 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J000) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_13049, hash value=3540045600 Current Wait Stack: Not in wait; last wait ended 2.360131 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 2.360158 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x2, fileno=0xc9, filetype=0x2 wait_id=40 seq_num=41 snap_id=1 wait times: snap=0.000169 sec, exc=0.000169 sec, total=0.000169 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.046260 sec of elapsed time 1: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=39 seq_num=40 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.756079 sec of elapsed time 2: 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.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.026134 sec of elapsed time 3: 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.000009 sec, exc=0.000009 sec, total=0.000009 sec wait times: max=307445734561 min 49 sec wait counts: calls=0 os=0 occurred after 0.013875 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x78fa, blocks=0x1 wait_id=36 seq_num=37 snap_id=1 wait times: snap=0.000111 sec, exc=0.000111 sec, total=0.000111 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.049614 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x1e5a, blocks=0x1 wait_id=35 seq_num=36 snap_id=1 wait times: snap=0.011510 sec, exc=0.011510 sec, total=0.011510 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.007774 sec of elapsed time 6: waited for 'db file sequential read' file#=0x1, block#=0x2d00, blocks=0x1 wait_id=34 seq_num=35 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.260249 sec of elapsed time 7: waited for 'db file sequential read' file#=0x1, block#=0x130, blocks=0x1 wait_id=33 seq_num=34 snap_id=1 wait times: snap=0.002661 sec, exc=0.002661 sec, total=0.002661 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000196 sec of elapsed time 8: waited for 'db file sequential read' file#=0x1, block#=0xc8, blocks=0x1 wait_id=32 seq_num=33 snap_id=1 wait times: snap=0.000134 sec, exc=0.000134 sec, total=0.000134 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.008474 sec of elapsed time 9: waited for 'asynch descriptor resize' outstanding #aio=0x0, current aio limit=0xffffffff, new aio limit=0x82 wait_id=31 seq_num=32 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.000061 sec of elapsed time Sampled Session History of session 177 serial 13401 --------------------------------------------------- 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, 18:07:03 - 18:07:06] not in wait at each sample [1 sample, 18:07:02] idle wait at each sample [session created at: 18:07:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-09-07 18:07:06.837 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 19064, J000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-09-07 18:04:59.712403 :CA4D4696:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20732 pso_num=22 pso_serial#=205 2025-09-07 18:04:59.712579 :CA4D4697:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20732 (legacy spawn) 2025-09-07 18:04:59.719017 :CA4D4698:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:04:59.719190 :CA4D46A1:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:04:59.720016 :CA4D46A2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:05:02.787721 :CA4D47B2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:05:02.774 2025-09-07 18:05:02.787723 :CA4D47B3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22800 pso_num=22 pso_serial#=206 2025-09-07 18:05:02.787865 :CA4D47B4:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22800 (legacy spawn) 2025-09-07 18:05:02.794361 :CA4D47B5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:05:02.794534 :CA4D47BE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:05:02.795323 :CA4D47BF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:05:02.804000 :CA4D47C2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:05:02.790 2025-09-07 18:05:02.804003 :CA4D47C3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23748 pso_num=22 pso_serial#=207 2025-09-07 18:05:02.804143 :CA4D47C4:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23748 (legacy spawn) 2025-09-07 18:05:02.810641 :CA4D47C5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:05:02.810805 :CA4D47CE:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:05:02.811595 :CA4D47CF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:05:11.138832 :CA4D4F5C:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:05:11.133 2025-09-07 18:05:11.138834 :CA4D4F5D:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24524 pso_num=22 pso_serial#=208 2025-09-07 18:05:11.138972 :CA4D4F5E:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=24524 osp_idx=0 osp_ver=585760 osp_pg=0 (spawn #568625) 2025-09-07 18:05:11.138973 :CA4D4F5F:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 18:05:11.138973 :CA4D4F60:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=239 time=1653962440 2025-09-07 18:05:11.138974 :CA4D4F61:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 18:05:11.138974 :CA4D4F62:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 18:05:11.138974 :CA4D4F63:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 18:05:11.138974 :CA4D4F64:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 18:05:11.138975 :CA4D4F65:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 18:05:11.139470 :CA4D4F66:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-07 18:05:11.140116 :CA4D4F7B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:05:11.147675 :CA4D4F97:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 18:05:11.148041 :CA4D4F98:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:05:11.148080 :CA4D4F9B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 18:05:11.148952 :CA4D4FA1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:05:11.149064 :CA4D4FAA:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:05:41.230080 :CA4D5A3D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:05:53.081380 :CA4D5DF3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:05:53.071 2025-09-07 18:05:53.081382 :CA4D5DF4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24564 pso_num=22 pso_serial#=209 2025-09-07 18:05:53.081570 :CA4D5DF5:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=24564 (legacy spawn) 2025-09-07 18:05:53.088078 :CA4D5DF6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:05:53.088264 :CA4D5DFB:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:05:53.089093 :CA4D5E00:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:05:57.534026 :CA4D5F72:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:05:57.525 2025-09-07 18:05:57.534028 :CA4D5F73:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22724 pso_num=22 pso_serial#=210 2025-09-07 18:05:57.534165 :CA4D5F74:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22724 (legacy spawn) 2025-09-07 18:05:57.540633 :CA4D5F75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:05:57.540806 :CA4D5F7A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:05:57.541569 :CA4D5F7F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:06:11.206504 :CA4D63A8:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:06:11.201 2025-09-07 18:06:11.206506 :CA4D63A9:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24308 pso_num=22 pso_serial#=211 2025-09-07 18:06:11.206649 :CA4D63AA:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=24308 osp_idx=0 osp_ver=585763 osp_pg=0 (spawn #568627) 2025-09-07 18:06:11.206650 :CA4D63AB:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 18:06:11.206650 :CA4D63AC:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=240 time=1654022502 2025-09-07 18:06:11.206651 :CA4D63AD:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 18:06:11.206651 :CA4D63AE:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 18:06:11.206651 :CA4D63AF:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 18:06:11.206652 :CA4D63B0:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 18:06:11.206652 :CA4D63B1:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 18:06:11.207155 :CA4D63B2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-07 18:06:11.207814 :CA4D63C7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:11.222093 :CA4D63E3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 18:06:11.222184 :CA4D63E4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 18:06:11.223070 :CA4D63E5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 18:06:11.223434 :CA4D63E6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:11.223474 :CA4D63E9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 18:06:11.231484 :CA4D63EF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:11.231555 :CA4D63F2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:ktcc.c:879 2025-09-07 18:06:11.231590 :CA4D63F3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:ktcc.c:879 2025-09-07 18:06:11.231988 :CA4D63F9:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-09-07 18:06:11.232362 :CA4D63FA:db_trace:kwqid.c@2146:kwqidrdq(): [10960:22:177] kwqidrdq: Error: 1403 occured in OCI execute 2025-09-07 18:06:11.232555 :CA4D63FB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 18:06:11.232817 :CA4D63FC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:11.232845 :CA4D63FF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 18:06:11.234412 :CA4D6405:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 18:06:11.234626 :CA4D6406:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:11.234655 :CA4D6409:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 18:06:11.235631 :CA4D640F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:11.235744 :CA4D6418:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:06:41.329708 :CA4D6DAD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:06:48.396186 :CA4D6FE0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:06:48.392 2025-09-07 18:06:48.396188 :CA4D6FE1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23664 pso_num=22 pso_serial#=212 2025-09-07 18:06:48.396325 :CA4D6FE2:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=23664 (legacy spawn) 2025-09-07 18:06:48.402795 :CA4D6FE3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:48.402962 :CA4D6FEC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:06:48.403731 :CA4D6FED:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:06:48.412590 :CA4D6FF0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:06:48.408 2025-09-07 18:06:48.412592 :CA4D6FF1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=24192 pso_num=22 pso_serial#=213 2025-09-07 18:06:48.412725 :CA4D6FF2:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=24192 (legacy spawn) 2025-09-07 18:06:48.419237 :CA4D6FF3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:48.419403 :CA4D6FFC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:06:48.420191 :CA4D6FFD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:06:51.518261 :CA4D7107:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:06:51.505 2025-09-07 18:06:51.518263 :CA4D7108:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22716 pso_num=22 pso_serial#=214 2025-09-07 18:06:51.518399 :CA4D7109:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22716 (legacy spawn) 2025-09-07 18:06:51.524840 :CA4D710A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:51.525011 :CA4D710F:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:06:51.525884 :CA4D7114:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:06:51.534551 :CA4D7117:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:06:51.521 2025-09-07 18:06:51.534553 :CA4D7118:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=20512 pso_num=22 pso_serial#=215 2025-09-07 18:06:51.534687 :CA4D7119:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=20512 (legacy spawn) 2025-09-07 18:06:51.541140 :CA4D711A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:51.541304 :CA4D7123:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:06:51.542100 :CA4D7124:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:06:55.174818 :CA4D721F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:06:55.167 2025-09-07 18:06:55.174820 :CA4D7220:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=22864 pso_num=22 pso_serial#=216 2025-09-07 18:06:55.174961 :CA4D7221:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=22864 (legacy spawn) 2025-09-07 18:06:55.181439 :CA4D7222:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:06:55.181617 :CA4D722B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:06:55.182485 :CA4D722C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:07:02.608196 :CA4D7480:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:07:02.603 2025-09-07 18:07:02.608198 :CA4D7481:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=23872 pso_num=22 pso_serial#=217 2025-09-07 18:07:02.608340 :CA4D7482:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=23872 osp_idx=0 osp_ver=585769 osp_pg=0 (spawn #568629) 2025-09-07 18:07:02.608340 :CA4D7483:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 18:07:02.608341 :CA4D7484:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=241 time=1654073908 2025-09-07 18:07:02.608341 :CA4D7485:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 18:07:02.608342 :CA4D7486:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 18:07:02.608342 :CA4D7487:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 18:07:02.608342 :CA4D7488:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 18:07:02.608343 :CA4D7489:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 18:07:02.608850 :CA4D748A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.608894 :CA4D7490:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-09-07 18:07:02.629671 :CA4D7525:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-09-07 18:07:02.715443 :CA4D7607:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 09-07 18:07:02.713 2025-09-07 18:07:02.715448 :CA4D7608:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=19064 pso_num=22 pso_serial#=218 2025-09-07 18:07:02.715777 :CA4D7609:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=19064 osp_idx=0 osp_ver=585770 osp_pg=0 (spawn #568632) 2025-09-07 18:07:02.715777 :CA4D760A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-09-07 18:07:02.715778 :CA4D760B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=242 time=1654074002 2025-09-07 18:07:02.715778 :CA4D760C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-09-07 18:07:02.715779 :CA4D760D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-09-07 18:07:02.715779 :CA4D760E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-09-07 18:07:02.715779 :CA4D760F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-09-07 18:07:02.715780 :CA4D7610:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-09-07 18:07:02.716517 :CA4D7611:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.721615 :CA4D7630:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.721658 :CA4D7633:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:jslv.c:9203 2025-09-07 18:07:02.738517 :CA4D7649:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.738732 :CA4D7651:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.739081 :CA4D7659:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.739334 :CA4D7661:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.739648 :CA4D7669:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.739808 :CA4D7671:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.739957 :CA4D7679:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.740109 :CA4D7681:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.740264 :CA4D7689:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.740484 :CA4D7691:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.740633 :CA4D7699:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.740772 :CA4D76A1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.740913 :CA4D76A9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.741067 :CA4D76B1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.741206 :CA4D76B9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.741342 :CA4D76C1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:02.760241 :CA4D76C9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:04.399611 :CA4D7838:db_trace:ktu.c@4871:ktuaex1r(): [10442:22:177] Extension usn 8, ext 6, nex 7 2025-09-07 18:07:04.399619 :CA4D7839:db_trace:ktusm.c@2117:ktusmasp(): [10445:22:177] des1:tsn:1 rdba:0x00800356 where: kduwh01: kdusru 2025-09-07 18:07:04.414558 :CA4D7854:db_trace:ktu.c@4871:ktuaex1r(): [10442:22:177] Extension usn 8, ext 7, nex 8 2025-09-07 18:07:04.414566 :CA4D7855:db_trace:ktusm.c@2117:ktusmasp(): [10445:22:177] des1:tsn:1 rdba:0x008191c3 where: kdiwh22: kdifind 2025-09-07 18:07:04.418305 :CA4D7856:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:04.438865 :CA4D7897:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:04.440850 :CA4D78A7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpus:psdpgi.c:2235 2025-09-07 18:07:04.441038 :CA4D78A8:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:22:177] atxpop:psdpgi.c:2235 2025-09-07 18:07:04.441945 :CA4D78A9:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:04.442049 :CA4D78AC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:04.442936 :CA4D78BE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:04.444417 :CA4D78C6:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:04.444700 :CA4D78CE:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:04.488113*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-09-07 18:07:04.488113*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-09-07 18:07:04.488113*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-09-07 18:07:04.488113*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-09-07 18:07:04.488113*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-09-07 18:07:04.488113*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-09-07 18:07:04.488113*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-09-07 18:07:04.534946*:CA4D7933:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000272103F0 estart=1757239624 eid=16778532 ctx=0x000000079F4EAD08 cwh=0x0000000026E40338 cpu=0 buffg=0 interb=0 r=0 rb=0 w=0 wb=0 2025-09-07 18:07:04.534946*:CA4D7934:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000272103F0 curCtx=0x00000000291FA688 pubTabIdxCnt=0 2025-09-07 18:07:04.534946*:CA4D7935:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000272103F0 2025-09-07 18:07:04.534946*:CA4D7936:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000272103F0 2025-09-07 18:07:04.534946*:CA4D7937:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000272103F0 curCtx=0x00000000291FA688 xsc->flg4=65792 flags=1 2025-09-07 18:07:04.534946*:CA4D7938:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000272103F0 2025-09-07 18:07:04.557840 :CA4D7939:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:06.432822 :CA4D79CF:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-09-07 18:07:06.432832 :CA4D79D0:db_trace:ktur.c@3079:ktuabt(): [10444:22:177] ABORT TRANSACTION - xid: 0x0006.003.0000caf9 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 22 (osid: 19064, J000)