severe performance issues when flashback is on
Date: Wed, 19 Oct 2011 20:21:29 +0200
Message-ID: <CAJ2-Qb8Z6xRY7auHKd517Hx0XdLmQMoWCZ-p1JMDe+nGhmOTQw_at_mail.gmail.com>
Hi
I am currently reviweing some batch processes, most of them are INSERT... SELECT, in production environment where flashback is enabled the speed is quite slow compared with QA environment where flashback is off.
I traced one single INSERT SELECT statement and noticed that there are always tons of physical reads (db file sequential read) in the table segment where I am inserting when flashback is on. Even I have a pretty lareg buffer cache and running the same insert more than once (so the second execution can use buffer reads), the same test with flashback off works as expected. I dont see any reasoning why db file sequential reads always occur.
I expected overheads with flashback but it just seems too much overhead, I did the same test in 11.2.0.2 and 10.2.0.5 and both shows similar behaviour. Am I missing anything?
Thanks
a simple test when flashback is on with 11.2.0.2 Linux x64, these tables are plain tables, no indexes:
create table t1
as
select * from dba_source
union all
select * from dba_source
union all
select * from dba_source
union all
select * from dba_source
union all
select * from dba_source
union all
select * from dba_source;
create table t2
as
select * from t1
where 1 = 0;
insert into t2
select * from t1;
Elapsed: 00:00:25.45
Statistics
989 recursive calls 165874 db block gets 41894 consistent gets 36232 physical reads 121920148 redo size 841 bytes sent via SQL*Net to client 788 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 10 sorts (memory) 0 sorts (disk) 899628 rows processed
10046 tracefile
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 1 0 0 Execute 2 11.32 52.25 54331 86771 327219 1799256 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------
total 4 11.32 52.26 54331 86772 327219 1799256
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
- Waited ----------
db file sequential read 36759 1.06 30.21* --> this slows the insert* log buffer space 4 0.47 0.60 flashback buf free by RVWR 17 0.99 4.98 log file switch (checkpoint incomplete) 6 2.33 4.72 log file switch completion 4 0.11 0.30 SQL*Net message to client 2 0.00 0.00 SQL*Net message from client 2 0.00 0.00 db file scattered read 212 0.53 3.06- second execution
Elapsed: 00:00:26.86
Statistics
189 recursive calls 161345 db block gets 44974 consistent gets 18099 physical reads 121684968 redo size 844 bytes sent via SQL*Net to client 788 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 899628 rows processed
without flashback:
Elapsed: 00:00:08.12
Statistics
831 recursive calls 146925 db block gets 41943 consistent gets 2 physical reads 121923948 redo size 830 bytes sent via SQL*Net to client 788 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 899628 rows processed
Elapsed: 00:00:10.65
Statistics
180 recursive calls 143188 db block gets 44656 consistent gets 0 physical reads 121702204 redo size 839 bytes sent via SQL*Net to client 788 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 899628 rows processed
10046 tracefile
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 1 0 0 Execute 2 3.83 18.74 2 86469 290113 1799256 Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ----------
total 4 3.84 18.74 2 86470 290113 1799256
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
- Waited ----------
Disk file operations I/O 2 0.00 0.00 db file sequential read 2 0.00 0.00 log buffer space 11 0.78 2.90 log file switch completion 6 0.40 0.87 log file switch (checkpoint incomplete) 8 3.70 10.56 SQL*Net message to client 2 0.00 0.00 SQL*Net message from client 2 0.00 0.00
--
http://www.freelists.org/webpage/oracle-l
Received on Wed Oct 19 2011 - 13:21:29 CDT