Increased runtime and 4 xids for one insert
Date: Wed, 10 Apr 2024 12:34:39 +0000 (UTC)
Message-ID: <1904337234.11254675.1712752479019_at_mail.yahoo.com>
Hallo,
there is problem with increasing execution time of simple Insert statement.(insert into T_TARGET select * from T_SOURCE)Execution time increased overproportionally to increased number of rows.11 millions rows took 3,5 hours , 38 million rows 3 days.T_TARGET is 1,5 TB range partitioned table , 1469 partitions and 5 local indexes (same partitioned key as the table).
for shorter execution time there was one XID, but for long execution time 4 XIDs ??
select xid, SQL_EXEC_START,SESSION_ID,SESSION_SERIAL#,count(*) ,to_char(min(sample_time),'dd.mm hh24:mi:ss') mint,to_char(max(sample_time),'dd.mm hh24:mi:ss') maxt from dba_hist_active_sess_history where sql_id='fdq9c3q9jfavc' and sample_time>to_date('2404052000','yymmddhh24mi') and sample_time< to_date('2404082100','yymmddhh24mi')group by xid,SQL_EXEC_START,SESSION_ID,SESSION_SERIAL# order by SQL_EXEC_START,min(sample_time);
XID SQL_EXEC_START SESSION_ID SESSION_SERIAL# COUNT(*) Min(IntervalEnd) Max(IntervalEnd)---------------- ------------------- -------------- --------------- -------------- -------------------- -------------------- 05.04.2024 20:13:40 1141 11657 8 05.04 20:13:44 05.04 20:14:152E00180051D62200 05.04.2024 20:13:40 1141 11657 12532 05.04 20:14:25 06.04 14:04:03 05.04.2024 20:13:40 1064 35873 12 05.04 20:39:31 06.04 01:42:10 05.04.2024 20:13:40 1016 54350 8 05.04 20:49:35 05.04 22:16:08 05.04.2024 20:13:40 1103 5986 16 05.04 21:00:10 06.04 02:49:36
05.04.2024 20:13:40 986 61332 6 05.04 21:34:39 06.04 04:26:0320001C0008633B00 06.04.2024 14:04:10 1141 11657 24486 06.04 14:04:13 08.04 00:55:20 06.04.2024 14:04:10 1057 63794 6 06.04 14:08:29 07.04 01:10:29 06.04.2024 14:04:10 1026 41466 8 06.04 14:21:17 06.04 23:58:37 06.04.2024 14:04:10 1103 51053 16 06.04 14:36:49 06.04 22:38:2315001100CD95C100 08.04.2024 00:55:22 1141 11657 8986 08.04 00:55:31 08.04 13:42:29 08.04.2024 00:55:22 1026 1396 8 08.04 00:59:06 08.04 03:59:52 08.04.2024 00:55:22 1104 28322 8 08.04 01:05:14 08.04 02:51:25 08.04.2024 00:55:22 1005 29042 8 08.04 01:21:07 08.04 03:53:02 08.04.2024 00:55:22 1075 54721 4 08.04 02:05:30 08.04 02:20:0003001200F4F1B600 08.04.2024 13:42:30 1141 11657 4178 08.04 13:42:39 08.04 19:39:05 08.04.2024 13:42:30 325 35023 10 08.04 13:48:48 08.04 16:16:38 08.04.2024 13:42:30 296 7915 2 08.04 14:30:27 08.04 14:30:27 08.04.2024 13:42:30 369 46540 4 08.04 14:55:12 08.04 16:05:22 08.04.2024 13:42:30 395 14967 8 08.04 15:38:13 08.04 18:20:4403001200F4F1B600 1141 11657 16 08.04 19:39:15 08.04 19:40:27
In dba_hist_undostat are same 4 execution start times for this query (maxquerylen,maxquerysqlid). During the execution I checked the transaction_start and last_call_et in the session 1141 and it loooked like TX started hours later sincelast_call_et. TX start was one of these SQL_EXEC_STARTsIn dba_hist_sqlstat only one execution is shown, most time was spend with CPU. most ASH samples are related to UNDO TS. select tablespace_name,count(*) from dba_hist_active_sess_history ,dba_data_files where sql_id='fdq9c3q9jfavc' and CURRENT_FILE#=file_idand sample_time>to_date('2404052000','yymmddhh24mi') and sample_time< to_date('2404082100','yymmddhh24mi')group by tablespace_name order by count(*) desc;
TABLESPACE_NAME COUNT(*)------------------------------ --------------UNDOTBS1 32746RB_STAGING_TAB 17576There are also some intervals with increased commit times (2->100ms) , but for me it looks like another issue. I have two main questions :- how it is possible to have for one execution 4 XIDs ?- where the statements spends the time ? Any ideas ?
Best Regards,Petr
-- http://www.freelists.org/webpage/oracle-lReceived on Wed Apr 10 2024 - 14:34:39 CEST