Home » RDBMS Server » Performance Tuning » Materialized view refresh thrashing DBWR (In post)
Materialized view refresh thrashing DBWR [message #624483] |
Tue, 23 September 2014 03:04 |
Roachcoach
Messages: 1576 Registered: May 2010 Location: UK
|
Senior Member |
|
|
NO_SID:/apps/ora/home> uname -a
Linux upora1ja 2.6.32-431.11.2.el6.x86_64 #1 SMP Mon Mar 3 13:32:45 EST 2014 x86_64 x86_64 x86_64 GNU/Linux
SQL> select * from v$version
2 /
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
PL/SQL Release 11.2.0.4.0 - Production
CORE 11.2.0.4.0 Production
TNS for Linux: Version 11.2.0.4.0 - Production
NLSRTL Version 11.2.0.4.0 - Production
The problem/quandry:
I have a materialized view that when refreshed, is absolutely thrashing dbwr with write requests - to the tune of 20-30k per second. This feels like it is not the expected behaviour but it is currently beyond me to explain why it is doing this.
I've included the ddl etc below as well as crude writes/second in real time code - the numbers it generates are close enough to grid/awr to give a flavour of the behaviour.
The view itself is 4.7m rows and is 571mb, the indexes are a further 660mb.
>Db cache is 6gb, redo logs are sufficiently large the operation can occur without a log switch.
>filesystemio_options=SETALL
>ODM is present
>One DBWR process
>The view is not truncated first (let's assume that isnt an option) so it is running a delete/insert operation.
>Testing is in isolation
I'm at a bit of a loss here - I'm struggling to explain why a single, serial process is pushing so much work towards dbwr.
I can't think what is causing so much write pressure here, sure delete is a heavy operation, but it can fit the entire set, dirty and clean in the cache several times over, there are no log switches to force checkpoints (initially logs looked undersized). There are no triggers either.
So am I just mistaken? Is this behaviour expected? Because it is putting sufficient pressure on the stack that it really doesn't play well with others and is part of an overnight batch so monopolising the system is not an option.
Any help or pointers towards either explaining or (better still) stopping this behaviour would be greatly appreciated.
Object Metadata
Toggle Spoiler08:47:23 SQL> @metadata
Enter value for object_type: MATERIALIZED_VIEW
Enter value for object_name: CMF_BALANCE_MV
Enter value for object_owner: BIL
old 1: select dbms_metadata.get_ddl('&object_type','&object_name','&object_owner') txt from dual
new 1: select dbms_metadata.get_ddl('MATERIALIZED_VIEW','CMF_BALANCE_MV','BIL') txt from dual
TXT
------------------------------------------------------------------------------------------------------------------------
CREATE MATERIALIZED VIEW "BIL"."CMF_BALANCE_MV" ("ACCOUNT_NO", "CURRENCY_CODE", "BILL_REF_NO", "BILL_REF_RESETS",
"PPDD_DATE", "ORIG_PPDD_DATE", "CLOSED_DATE", "NEW_CHARGES", "NET_NEW_CHARGES", "TOTAL_DUE", "TOTAL_ADJ", "TOTAL_PAID",
"BALANCE_DUE", "DISPUTE_AMT", "LATE_EXEMPT_CHARGES", "COLLECTION_INDICATOR", "CHG_DATE", "CHG_WHO", "GL_AMOUNT",
"CONVERTED", "NEW_CHARGE_CREDITS")
ORGANIZATION HEAP PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255
NOCOMPRESS LOGGING
STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
BUFFER_POOL DEFAULT)
TABLESPACE "KENAN_DATA_AUTO_01"
BUILD IMMEDIATE
USING INDEX PCTFREE 10 INITRANS 2 MAXTRANS 255
STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
BUFFER_POOL DEFAULT)
TABLESPACE "KENAN_DATA_AUTO_01"
REFRESH FORCE ON DEMAND
WITH PRIMARY KEY USING DEFAULT LOCAL ROLLBACK SEGMENT
USING ENFORCED CONSTRAINTS DISABLE QUERY REWRITE
AS SELECT "CMF_BALANCE"."ACCOUNT_NO" "ACCOUNT_NO","CMF_BALANCE"."CURRENCY_CODE"
"CURRENCY_CODE","CMF_BALANCE"."BILL_REF_NO" "BILL_REF_NO","CMF_BALANCE"."BILL_REF_RESETS"
"BILL_REF_RESETS","CMF_BALANCE"."PPDD_DATE" "PPDD_DATE","CMF_BALANCE"."ORIG_PPDD_DATE"
"ORIG_PPDD_DATE","CMF_BALANCE"."CLOSED_DATE" "CLOSED_DATE","CMF_BALANCE"."NEW_CHARGES"
"NEW_CHARGES","CMF_BALANCE"."NET_NEW_CHARGES" "NET_NEW_CHARGES","CMF_BALANCE"."TOTAL_DUE"
"TOTAL_DUE","CMF_BALANCE"."TOTAL_ADJ" "TOTAL_ADJ","CMF_BALANCE"."TOTAL_PAID" "TOTAL_PAID","CMF_BALANCE"."BALANCE_DUE"
"BALANCE_DUE","CMF_BALANCE"."DISPUTE_AMT" "DISPUTE_AMT","CMF_BALANCE"."LATE_EXEMPT_CHARGES"
"LATE_EXEMPT_CHARGES","CMF_BALANCE"."COLLECTION_INDICATOR" "COLLECTION_INDICATOR","CMF_BALANCE"."CHG_DATE"
"CHG_DATE","CMF_BALANCE"."CHG_WHO" "CHG_WHO","CMF_BALANCE"."GL_AMOUNT" "GL_AMOUNT","CMF_BALANCE"."CONVERTED"
"CONVERTED","CMF_BALANCE"."NEW_CHARGE_CREDITS" "NEW_CHARGE_CREDITS" FROM "KENAN"."CMF_BALANCE" "CMF_BALANCE"
Elapsed: 00:00:00.65
08:47:43 SQL> @index_scan
tname is owner.tablename
Enter value for tname: bil.CMF_BALANCE_MV
old 11: where loweR(table_owner||'.'||table_name) = lower('&tname'))
new 11: where loweR(table_owner||'.'||table_name) = lower('bil.CMF_BALANCE_MV'))
INDEX_NAME COLUMN_NAME COLUMN_POSITION DESC
------------------------------- --------------------------------------------- --------------- ----
CMF_BALANCE_MV_IDX1 BILL_REF_NO 1 ASC
BILL_REF_RESETS 2 ASC
CMF_BALANCE_PK ACCOUNT_NO 1 ASC
BILL_REF_NO 2 ASC
BILL_REF_RESETS 3 ASC
IDX$$_1C3940001 ACCOUNT_NO 1 ASC
6 rows selected.
Elapsed: 00:00:01.04
08:47:57 SQL> @metadata
Enter value for object_type: INDEX
Enter value for object_name: CMF_BALANCE_MV_IDX1
Enter value for object_owner: BIL
old 1: select dbms_metadata.get_ddl('&object_type','&object_name','&object_owner') txt from dual
new 1: select dbms_metadata.get_ddl('INDEX','CMF_BALANCE_MV_IDX1','BIL') txt from dual
TXT
------------------------------------------------------------------------------------------------------------------------
CREATE INDEX "BIL"."CMF_BALANCE_MV_IDX1" ON "BIL"."CMF_BALANCE_MV" ("BILL_REF_NO", "BILL_REF_RESETS")
PCTFREE 10 INITRANS 2 MAXTRANS 255
STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
BUFFER_POOL DEFAULT)
TABLESPACE "KENAN_DATA_AUTO_01"
Elapsed: 00:00:00.99
08:48:47 SQL> /
Enter value for object_type: INDEX
Enter value for object_name: CMF_BALANCE_PK
Enter value for object_owner: BIL
old 1: select dbms_metadata.get_ddl('&object_type','&object_name','&object_owner') txt from dual
new 1: select dbms_metadata.get_ddl('INDEX','CMF_BALANCE_PK','BIL') txt from dual
TXT
------------------------------------------------------------------------------------------------------------------------
CREATE UNIQUE INDEX "BIL"."CMF_BALANCE_PK" ON "BIL"."CMF_BALANCE_MV" ("ACCOUNT_NO", "BILL_REF_NO", "BILL_REF_RESETS")
PCTFREE 10 INITRANS 2 MAXTRANS 255 COMPUTE STATISTICS
STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
BUFFER_POOL DEFAULT)
TABLESPACE "KENAN_DATA_AUTO_01"
Elapsed: 00:00:00.02
08:48:56 SQL> /
Enter value for object_type: INDEX
Enter value for object_name: IDX$$_1C3940001
Enter value for object_owner: BIL
old 1: select dbms_metadata.get_ddl('&object_type','&object_name','&object_owner') txt from dual
new 1: select dbms_metadata.get_ddl('INDEX','IDX$$_1C3940001','BIL') txt from dual
TXT
------------------------------------------------------------------------------------------------------------------------
CREATE INDEX "BIL"."IDX$$_1C3940001" ON "BIL"."CMF_BALANCE_MV" ("ACCOUNT_NO")
PCTFREE 10 INITRANS 2 MAXTRANS 255
STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
BUFFER_POOL DEFAULT)
TABLESPACE "KENAN_DATA_AUTO_01"
Elapsed: 00:00:00.01
08:49:02 SQL>
Writes/second [crude] for those without grid/cloud/similar:
set serveroutput on
---writes per second
declare
v_reads_start number;
v_reads_end number;
v_readT_start number;
v_readT_end number;
v_poll_interval number := 1;
v_intervals_to_poll number := 180;
begin
select sum(t), sum(tim) into v_reads_end, v_readT_end
from (
select sum(PHYWRTS) t
,sum(WRITETIM) tim
from v$filestat
);
dbms_lock.sleep(v_poll_interval);
for i in 1..v_intervals_to_poll loop
select sum(t), sum(tim) into v_reads_start, v_readT_start
from ( select
sum(PHYWRTS) t
,sum(WRITETIM) tim
from v$filestat
--where file#=13
);
dbms_output.put_line('Writes: ' || to_char(v_reads_start-v_reads_end)||', Write time :'||to_char((v_readT_start-v_readT_end)*10)||', avg write: '||
case when (v_reads_start-v_reads_end)=0 then 'No writes' else to_char(round(((v_readT_start-v_readT_end)/(v_reads_start-v_reads_end)*10),4)) end );
v_reads_end := v_reads_start;
dbms_lock.sleep(v_poll_interval);
end loop;
end;
/
MV refresh method
BEGIN DBMS_MVIEW.REFRESH('BIL.CMF_BALANCE_MV'); END;
/
|
|
|
Re: Materialized view refresh thrashing DBWR [message #624484 is a reply to message #624483] |
Tue, 23 September 2014 03:22 |
John Watson
Messages: 8962 Registered: January 2010 Location: Global Village
|
Senior Member |
|
|
You said "a single serial process". This immediately makes me think of serial direct reads. In release 11.2.0.4, you may well be getting direct read for this operation. That will force segment checkpoints for all the tables involved. Could this be part of your DBWR activity? Can you try setting _serial_direct_read=never ?
|
|
|
|
Re: Materialized view refresh thrashing DBWR [message #624508 is a reply to message #624486] |
Tue, 23 September 2014 05:32 |
Roachcoach
Messages: 1576 Registered: May 2010 Location: UK
|
Senior Member |
|
|
Out of interest the following testing/results have been observed.
Direct path insert - double digit iops. Lower Mb/s throughput to complete operation too (would have expected less iops, same throughput)
Drop all the indexes and the iops are vastly reduced to (factor of ~10).
It seems related to the indexes at this point, but they're not particularly weird, or loads of them. I'd still not expect the behaviour of DBWR.
Edit:
Here's a test case which should show the huge io spike.
--create staging table
create table t1 as
select * from dba_objects
/
--bulk up staging table - aiming for 4-5 million+ rows
insert into t1 select * from t1
/
/
/
/
/
/
/
--create target table
create table t2 as select * from t1 where 1=2
/
--insert into target table with no indexes - normal IOPS expected
insert into t2 select * from t1
/
--clear up
truncate table t2
/
--create a composite index on target table
create index idxt1_1 on t2(object_id, object_type, object_name)
/
--expect here to see a huge increase in IOPS from previous test
insert into t2 select * from t1
/
I realise bulk dml like this, it is advised to drop the indexes, but this is not always possible (like the MV above).
[Updated on: Tue, 23 September 2014 07:59] Report message to a moderator
|
|
|
Re: Materialized view refresh thrashing DBWR [message #625875 is a reply to message #624508] |
Wed, 15 October 2014 04:38 |
Roachcoach
Messages: 1576 Registered: May 2010 Location: UK
|
Senior Member |
|
|
So it turns out that (for reasons unknown) someone had modified a couple of parameters
log_checkpoint_interval
log_checkpoint_timeout
away from default which was causing dbwr to be super aggressive. Whilst likely not "technically" accurate, the manifestation was that is basically stopped writing "lazily" and went into overdrive trying to keep pace with cache changes needlessly thus murdering the SAN.
Hope it helps
|
|
|
Goto Forum:
Current Time: Thu Jan 02 18:22:55 CST 2025
|