Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250827220006\orcl_j003_22640_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:35157M/63366M, Ph+PgF:40155M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 22640, image: ORACLE.EXE (J003) *** 2025-08-27 22:00:06.679 *** SESSION ID:(233.33167) 2025-08-27 22:00:06.679 *** 2025-08-27 22:00:06.679 Process diagnostic dump for ORACLE.EXE (J003), OS id=22640, pid: 29, proc_ser: 193, sid: 233, sess_ser: 33167 ------------------------------------------------------------------------------- current sql: call dbms_stats.gather_database_stats_job_proc ( ) client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 22640 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J003) application name: DBMS_SCHEDULER, hash value=2478762354 action name: ORA$AT_OS_OPT_SY_12985, hash value=2918010847 Current Wait Stack: Not in wait; last wait ended 0.534109 sec ago Wait State: fixed_waits=0 flags=0x21 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.534138 sec since last wait 0: waited for 'Disk file operations I/O' FileOperation=0x5, fileno=0x0, filetype=0x3 wait_id=145 seq_num=146 snap_id=1 wait times: snap=0.000284 sec, exc=0.000284 sec, total=0.000284 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000006 sec of elapsed time 1: waited for 'log file sequential read' log#=0x2a11, block#=0x0, blocks=0x0 wait_id=144 seq_num=145 snap_id=1 wait times: snap=0.000006 sec, exc=0.000006 sec, total=0.000006 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.055543 sec of elapsed time 2: waited for 'log file sequential read' log#=0x2a11, block#=0x0, blocks=0x0 wait_id=143 seq_num=144 snap_id=1 wait times: snap=0.000016 sec, exc=0.000016 sec, total=0.000016 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.165881 sec of elapsed time 3: waited for 'log file sequential read' log#=0x0, block#=0x6800, blocks=0x800 wait_id=142 seq_num=143 snap_id=1 wait times: snap=0.000326 sec, exc=0.000326 sec, total=0.000326 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 4: waited for 'log file sequential read' log#=0x0, block#=0x6000, blocks=0x800 wait_id=141 seq_num=142 snap_id=1 wait times: snap=0.000294 sec, exc=0.000294 sec, total=0.000294 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 5: waited for 'log file sequential read' log#=0x0, block#=0x5800, blocks=0x800 wait_id=140 seq_num=141 snap_id=1 wait times: snap=0.000298 sec, exc=0.000298 sec, total=0.000298 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000005 sec of elapsed time 6: waited for 'log file sequential read' log#=0x0, block#=0x5000, blocks=0x800 wait_id=139 seq_num=140 snap_id=1 wait times: snap=0.000294 sec, exc=0.000294 sec, total=0.000294 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000004 sec of elapsed time 7: waited for 'log file sequential read' log#=0x0, block#=0x4800, blocks=0x800 wait_id=138 seq_num=139 snap_id=1 wait times: snap=0.000289 sec, exc=0.000289 sec, total=0.000289 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000051 sec of elapsed time 8: waited for 'log file sequential read' log#=0x0, block#=0x4000, blocks=0x800 wait_id=137 seq_num=138 snap_id=1 wait times: snap=0.000321 sec, exc=0.000321 sec, total=0.000321 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.297919 sec of elapsed time 9: waited for 'log file sequential read' log#=0x2a11, block#=0x800, blocks=0x800 wait_id=136 seq_num=137 snap_id=1 wait times: snap=0.000205 sec, exc=0.000205 sec, total=0.000205 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.002580 sec of elapsed time Sampled Session History of session 233 serial 33167 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [7 samples, 22:00:00 - 22:00:06] not in wait at each sample [1 sample, 21:59:59] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-08-27 22:00:06.679 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 22640, J003) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-08-27 01:00:12.562464 :C51CD1C1: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-08-27 01:00:12.562649 :C51CD1CA: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-08-27 01:00:12.563491 :C51CD1CB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 01:00:12.572162 :C51CD1CE:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 01:00:12.558 2025-08-27 01:00:12.572164 :C51CD1CF:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=22692 pso_num=29 pso_serial#=183 2025-08-27 01:00:12.572297 :C51CD1D0:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=22692 (legacy spawn) 2025-08-27 01:00:12.578761 :C51CD1D1: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-08-27 01:00:12.578917 :C51CD1DA: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-08-27 01:00:12.579711 :C51CD1DB:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 01:00:14.457791 :C51CD29B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 01:00:14.448 2025-08-27 01:00:14.457793 :C51CD29C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=20192 pso_num=29 pso_serial#=184 2025-08-27 01:00:14.457935 :C51CD29D:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=20192 (legacy spawn) 2025-08-27 01:00:14.464537 :C51CD29E: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-08-27 01:00:14.464726 :C51CD2A3: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-08-27 01:00:14.465554 :C51CD2A8:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 01:00:23.969104 :C51CD73B:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 01:00:23.961 2025-08-27 01:00:23.969106 :C51CD73C:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=23112 pso_num=29 pso_serial#=185 2025-08-27 01:00:23.969242 :C51CD73D:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=23112 (legacy spawn) 2025-08-27 01:00:23.975976 :C51CD73E: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-08-27 01:00:23.976160 :C51CD743: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-08-27 01:00:23.977013 :C51CD748:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 08:15:17.095030 :C53EBC53:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 08:15:17.094 2025-08-27 08:15:17.095032 :C53EBC54:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=23224 pso_num=29 pso_serial#=186 2025-08-27 08:15:17.095206 :C53EBC55:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=23224 osp_idx=27 osp_ver=16505 osp_pg=0 (spawn #530588) 2025-08-27 08:15:17.095206 :C53EBC56:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-27 08:15:17.095207 :C53EBC57:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=226 time=668168377 2025-08-27 08:15:17.095207 :C53EBC58:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 08:15:17.095208 :C53EBC59:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 08:15:17.095208 :C53EBC5A:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 08:15:17.095208 :C53EBC5B:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 08:15:17.095208 :C53EBC5C:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 08:15:17.100511 :C53EBC5D: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-08-27 08:15:17.100567 :C53EBC63: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-08-27 08:15:17.101015 :C53EBC64:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 08:15:19.273428 :C53EBD04:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 08:15:19.266 2025-08-27 08:15:19.273429 :C53EBD05:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=21084 pso_num=29 pso_serial#=187 2025-08-27 08:15:19.273556 :C53EBD06:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=21084 osp_idx=27 osp_ver=16506 osp_pg=0 (spawn #530590) 2025-08-27 08:15:19.273557 :C53EBD07:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-27 08:15:19.273557 :C53EBD08:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=227 time=668170580 2025-08-27 08:15:19.273557 :C53EBD09:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 08:15:19.273558 :C53EBD0A:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 08:15:19.273558 :C53EBD0B:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 08:15:19.273558 :C53EBD0C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 08:15:19.273559 :C53EBD0D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 08:15:19.274070 :C53EBD0E: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-08-27 08:15:19.274106 :C53EBD14: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-08-27 08:15:19.274451 :C53EBD15:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 13:04:23.762244 :C5558188:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 13:04:23.747 2025-08-27 13:04:23.762245 :C5558189:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=21632 pso_num=29 pso_serial#=188 2025-08-27 13:04:23.762389 :C555818A:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=21632 osp_idx=27 osp_ver=16507 osp_pg=0 (spawn #531256) 2025-08-27 13:04:23.762390 :C555818B:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-27 13:04:23.762391 :C555818C:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=228 time=685515049 2025-08-27 13:04:23.762391 :C555818D:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 13:04:23.762391 :C555818E:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 13:04:23.762392 :C555818F:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 13:04:23.762392 :C5558190:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 13:04:23.762392 :C5558191:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 13:04:23.762988 :C5558192: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-08-27 13:04:23.763037 :C5558198: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-08-27 13:04:23.772207 :C55581B0:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 14:04:31.537395 :C55A2DD7:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 14:04:31.533 2025-08-27 14:04:31.537396 :C55A2DD8:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10444 pso_num=29 pso_serial#=189 2025-08-27 14:04:31.537535 :C55A2DD9:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10444 osp_idx=27 osp_ver=16508 osp_pg=0 (spawn #531395) 2025-08-27 14:04:31.537536 :C55A2DDA:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-27 14:04:31.537536 :C55A2DDB:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=229 time=689122830 2025-08-27 14:04:31.537537 :C55A2DDC:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 14:04:31.537537 :C55A2DDD:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 14:04:31.537537 :C55A2DDE:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 14:04:31.537537 :C55A2DDF:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 14:04:31.537538 :C55A2DE0:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 14:04:31.538058 :C55A2DE1: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-08-27 14:04:31.538106 :C55A2DE7: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-08-27 14:04:31.547209 :C55A2DFF:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 15:04:39.661051 :C55ECDED:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 15:04:39.657 2025-08-27 15:04:39.661052 :C55ECDEE:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=21024 pso_num=29 pso_serial#=190 2025-08-27 15:04:39.661188 :C55ECDEF:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=21024 osp_idx=27 osp_ver=16509 osp_pg=0 (spawn #531533) 2025-08-27 15:04:39.661188 :C55ECDF0:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-27 15:04:39.661189 :C55ECDF1:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=230 time=692730955 2025-08-27 15:04:39.661189 :C55ECDF2:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 15:04:39.661190 :C55ECDF3:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 15:04:39.661190 :C55ECDF4:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 15:04:39.661191 :C55ECDF5:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 15:04:39.661191 :C55ECDF6:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 15:04:39.661840 :C55ECDF7: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-08-27 15:04:39.661890 :C55ECDFD: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-08-27 15:04:39.670945 :C55ECE15:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 16:04:47.477964 :C5636E35:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 16:04:47.474 2025-08-27 16:04:47.477965 :C5636E36:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=18624 pso_num=29 pso_serial#=191 2025-08-27 16:04:47.478119 :C5636E37:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=18624 osp_idx=27 osp_ver=16510 osp_pg=0 (spawn #531671) 2025-08-27 16:04:47.478120 :C5636E38:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-27 16:04:47.478121 :C5636E39:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=231 time=696338768 2025-08-27 16:04:47.478121 :C5636E3A:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 16:04:47.478122 :C5636E3B:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 16:04:47.478122 :C5636E3C:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 16:04:47.478122 :C5636E3D:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 16:04:47.478123 :C5636E3E:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 16:04:47.478788 :C5636E3F: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-08-27 16:04:47.478829 :C5636E45: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-08-27 16:04:47.488167 :C5636E5C:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 17:04:55.381300 :C5680C7E:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 17:04:55.378 2025-08-27 17:04:55.381301 :C5680C7F:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=22844 pso_num=29 pso_serial#=192 2025-08-27 17:04:55.381464 :C5680C80:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=22844 osp_idx=27 osp_ver=16511 osp_pg=0 (spawn #531809) 2025-08-27 17:04:55.381464 :C5680C81:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-27 17:04:55.381465 :C5680C82:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=232 time=699946674 2025-08-27 17:04:55.381466 :C5680C83:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 17:04:55.381466 :C5680C84:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 17:04:55.381467 :C5680C85:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 17:04:55.381467 :C5680C86:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 17:04:55.381468 :C5680C87:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 17:04:55.382027 :C5680C88: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-08-27 17:04:55.382077 :C5680C8F: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-08-27 17:04:55.391315 :C5680CA6:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-08-27 22:00:00.322160 :C57EA4E0:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 08-27 22:00:00.315 2025-08-27 22:00:00.322161 :C57EA4E1:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=22640 pso_num=29 pso_serial#=193 2025-08-27 22:00:00.322288 :C57EA4E5:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=22640 osp_idx=27 osp_ver=16512 osp_pg=0 (spawn #532490) 2025-08-27 22:00:00.322289 :C57EA4E6:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-08-27 22:00:00.322289 :C57EA4E7:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=233 time=717651627 2025-08-27 22:00:00.322290 :C57EA4E8:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-08-27 22:00:00.322290 :C57EA4E9:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-08-27 22:00:00.322291 :C57EA4EA:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-08-27 22:00:00.322291 :C57EA4EB:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-08-27 22:00:00.322292 :C57EA4EC:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-08-27 22:00:00.322891 :C57EA4F6: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-08-27 22:00:00.327909 :C57EA512: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-08-27 22:00:00.327949 :C57EA515:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:jslv.c:9203 2025-08-27 22:00:00.345688 :C57EA6EE: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-08-27 22:00:00.345889 :C57EA6F6: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-08-27 22:00:00.346051 :C57EA6FE: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-08-27 22:00:00.346209 :C57EA706: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-08-27 22:00:00.346375 :C57EA70E: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-08-27 22:00:00.346530 :C57EA716: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-08-27 22:00:00.346692 :C57EA71E: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-08-27 22:00:00.346852 :C57EA726: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-08-27 22:00:00.347002 :C57EA72E: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-08-27 22:00:00.347149 :C57EA736: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-08-27 22:00:00.347305 :C57EA73E: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-08-27 22:00:00.347467 :C57EA746: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-08-27 22:00:00.347612 :C57EA74E: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-08-27 22:00:00.347768 :C57EA756: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-08-27 22:00:00.348002 :C57EA75E: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-08-27 22:00:00.348254 :C57EA766: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-08-27 22:00:00.348403 :C57EA76E: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-08-27 22:00:00.348559 :C57EA776: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-08-27 22:00:00.348930 :C57EA77F: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-08-27 22:00:00.349119 :C57EA787: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-08-27 22:00:00.349274 :C57EA78F: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-08-27 22:00:00.349529 :C57EA797: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-08-27 22:00:00.349779 :C57EA7A1: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-08-27 22:00:00.350010 :C57EA7AB: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-08-27 22:00:00.350645 :C57EA7C2: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-08-27 22:00:00.350868 :C57EA7CA: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-08-27 22:00:00.373352 :C57EA7D2: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-08-27 22:00:01.924208*:C57EAA57:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x0000000030183AD0 estart=1756303201 eid=21806194 ctx=0x0000000777968158 cwh=0x000000002B460AB8 cpu=0 buffg=2 interb=0 r=0 rb=0 w=0 wb=0 2025-08-27 22:00:01.924208*:C57EAA58:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x0000000030183AD0 curCtx=0x000000005B31C4B8 pubTabIdxCnt=0 2025-08-27 22:00:01.924208*:C57EAA59:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x0000000030183AD0 2025-08-27 22:00:01.924208*:C57EAA5A:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x0000000030183AD0 2025-08-27 22:00:01.924208*:C57EAA5B:sql_mon_query:keswx.c@6099:keswxCurPushMonitoring(begin): xsc=0x00000000301BAAF8 estart=1756303199 eid=16777548 ctx=0x000000077B54EAC8 cwh=0x000000002B460608 cpu=1343750 buffg=73841 interb=196608 r=24 rb=196608 w=0 wb=0 2025-08-27 22:00:01.924208*:C57EAA5C:sql_mon_query:keswx.c@2839:keswxCurPrepare(): Allocate monitor context: xsc=0x00000000301BAAF8 curCtx=0x000000005B131240 pubTabIdxCnt=0 2025-08-27 22:00:01.924208*:C57EAA5D:sql_mon_query:keswx.c@6131:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x00000000301BAAF8 2025-08-27 22:00:01.924208*:C57EAA5E:sql_mon_query:keswx.c@6263:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x00000000301BAAF8 2025-08-27 22:00:01.924208*:C57EAA5F:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x0000000030183AD0 curCtx=0x000000005B31C4B8 xsc->flg4=65792 flags=1 2025-08-27 22:00:01.924208*:C57EAA60:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x0000000030183AD0 2025-08-27 22:00:02.049213*:C57EAACF:sql_mon_query:keswx.c@3282:keswxCurEndPlanMonitoringCb(begin): xsc=0x00000000301BAAF8 curCtx=0x000000005B131240 xsc->flg4=65792 flags=2 2025-08-27 22:00:02.049213*:C57EAAD0:sql_mon_query:keswx.c@3389:keswxCurEndPlanMonitoringCb(end): monitoring has ended for xsc=0x00000000301BAAF8 2025-08-27 22:00:02.054336 :C57EAAD2: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-08-27 22:00:02.077192 :C57EAADC: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-08-27 22:00:02.079584 :C57EAAE4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:psdpgi.c:2235 2025-08-27 22:00:02.079825 :C57EAAE5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:psdpgi.c:2235 2025-08-27 22:00:02.080880 :C57EAAE6: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-08-27 22:00:02.080994 :C57EAAE9: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-08-27 22:00:02.082095 :C57EAAFB: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-08-27 22:00:02.083913 :C57EAB03: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-08-27 22:00:02.084252 :C57EAB0B: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-08-27 22:00:02.142962*:SQL_Analyze:qksan.c@3402:qksanAnalyzeSql(begin): qksanAnalyzeSql(enter): goal=15 options=16778048 pgadep=0 binds#=0 byPos=0 timeLim=0 timeFired=0 2025-08-27 22:00:02.142962*:SQL_Analyze:qksan.c@936:qksanBindSql(begin): binding for SQL analyze 2025-08-27 22:00:02.142962*:SQL_Analyze:qksan.c@1344:qksanBindSql(end): Done binding: status=0 ret=0 bind#=0 byPos=1 wasBoundP=0x0000000000000000 bindIndP=0x0000000000000000 2025-08-27 22:00:02.205462*:SQL_Analyze:qksan.c@6338:qksanAvgExecStats(): The number of total executions: 1 and execution count: 0 2025-08-27 22:00:02.205462*:SQL_Analyze:qksan.c@4776:qksanPostAnalyzeDump(begin): qksanPostAnalyzeDump(): Dumping analyze context after compilation qksanStatus=SUCCESS ecode=0 2025-08-27 22:00:02.205462*:SQL_Analyze:qksan.c@4800:qksanPostAnalyzeDump(end): 2025-08-27 22:00:02.205462*:SQL_Analyze:qksan.c@3690:qksanAnalyzeSql(end): exit: ecode=0 status=0 2025-08-27 22:00:02.268526 :C57EABA8: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-08-27 22:00:04.200750 :C57EAD17: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-08-27 22:00:04.200763 :C57EAD18:db_trace:ktur.c@3079:ktuabt(): [10444:29:233] ABORT TRANSACTION - xid: 0x0009.00b.0001db6e 2025-08-27 22:00:06.607531 :C57EAEB0: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-08-27 22:00:06.609026 :C57EAEB8: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-08-27 22:00:06.620664 :C57EAEC5: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-08-27 22:00:06.649875 :C57EAED8: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 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 22640, J003)