Re: Increased runtime and 4 xids for one insert

Hi Jonathan,

would snapper work for that purpose?
I have very little experience with snapper . I have a case where such option would be helpfull.

Thanks

Lothar

Am 10.04.2024 um 18:32 schrieb Jonathan Lewis:
>
> One further point, since you've probably got AWR reports over the
> period you could look at the Instance Activity stats. (Ideally a
> special task like this might capture the change in v$session_event,
> v$sess_time_model and v$sesstat for the session). Check for the
> statistics for "% - undo records applied".  This can give you some
> clues about why the UNDO was being accessed
>
> transaction tables consistent reads - undo records applied
> data blocks consistent reads - undo records applied
> rollback changes - undo records applied
>
> If you're restarting the the last one will show a large number. If
> you're dealing with competing transactions on the same table (or its
> indexes) the second will show large numbers, if you're trying to check
> whether "recent" changes from other session committed before or after
> your transaction started the first will show large numbers.
>
> Regards
> Jonathan Lewis
>
>
>
>
> On Wed, 10 Apr 2024 at 13:35, Petr Novak <dmarc-noreply_at_freelists.org>
> wrote:
>
> 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 <http://dd.mm> hh24:mi:ss') mint,
> to_char(max(sample_time),'dd.mm <http://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:15
> 2E00180051D62200 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:03
> 20001C0008633B00 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:23
> 15001100CD95C100 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:00
> 03001200F4F1B600 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:44
> 03001200F4F1B600  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 since
> last_call_et. TX start was one of these SQL_EXEC_STARTs
> In 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_id
> and 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                                32746
> RB_STAGING_TAB                          17576
>
> There 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-l