oracle慎用基于on commit刷新物化视图的方式（二）
oracle慎用基于on commit刷新物化视图的方式（二）
环境模拟
首先，需要有示例用户SCOTT，以emp表为例子。
首先是串行下无物化视图的emp表，做update操作的情况，
16:56:14 SYS@zkm(27)> begin 16:56:21 2 for i in 1..10000 loop 16:56:21 3 update scott.emp set sal=9999 where empno=7934; 16:56:21 4 commit; 16:56:21 5 end loop; 16:56:21 6 end ; 16:56:21 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:00.48 16:56:23 SYS@zkm(27)> begin 16:56:26 2 for i in 1..10000 loop 16:56:26 3 update scott.emp set sal=9999 where empno=7934; 16:56:26 4 commit; 16:56:26 5 end loop; 16:56:26 6 end ; 16:56:26 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:00.65 16:56:27 SYS@zkm(27)> begin 16:56:28 2 for i in 1..10000 loop 16:56:28 3 update scott.emp set sal=9999 where empno=7934; 16:56:28 4 commit; 16:56:28 5 end loop; 16:56:28 6 end ; 16:56:28 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:00.65
然后是串行下有物化视图的emp表，做update操作的情况，
17:15:23 SYS@zkm(27)> conn scott/oracle Connected. 17:15:32 SCOTT@zkm(27)> create materialized view scott.mv_emp 17:15:33 2 REFRESH force on commit 17:15:33 3 as 17:15:33 4 select * from scott.emp; Materialized view created. Elapsed: 00:00:00.55 17:15:34 SCOTT@zkm(27)> begin 17:16:06 2 for i in 1..10000 loop 17:16:06 3 update scott.emp set sal=9999 where empno=7934; 17:16:06 4 commit; 17:16:06 5 end loop; 17:16:06 6 end ; 17:16:06 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:21.73 17:16:29 SCOTT@zkm(27)> / PL/SQL procedure successfully completed. Elapsed: 00:00:21.64 17:16:53 SCOTT@zkm(27)> / PL/SQL procedure successfully completed. Elapsed: 00:00:20.70
可以看到，有物化视图的情况下，性能下降40多倍。
更不要说在并行情况下产生行级锁的情况了，几乎会导致业务都瘫痪掉。
并行下也进行一次模拟看看，开启两个session，sid分别为27和31。
删除上边的物化视图，
17:33:58 SCOTT@zkm(27)> drop materialized view scott.mv_emp; Materialized view dropped. Elapsed: 00:00:00.50
为了保证同时运行匿名块，使用crt的command windows功能，将匿名块同时发送到活动的会话里边，
可以发现，运行时间情况为
17:34:07 SCOTT@zkm(27)> begin 17:34:32 2 for i in 1..10000 loop 17:34:32 3 update scott.emp set sal=9999 where empno=7934; 17:34:32 4 commit; 17:34:32 5 end loop; 17:34:32 6 end ; 17:34:32 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:01.06 17:34:33 SCOTT@zkm(27)> / PL/SQL procedure successfully completed. Elapsed: 00:00:01.12 17:34:39 SCOTT@zkm(27)> / PL/SQL procedure successfully completed. Elapsed: 00:00:01.17 17:34:43 SCOTT@zkm(27)>
----------------------------同时sid=31的运行----------------------------- 17:34:16 SCOTT@zkm(31)> begin 17:34:32 2 for i in 1..10000 loop 17:34:32 3 update scott.emp set sal=9999 where empno=7934; 17:34:32 4 commit; 17:34:32 5 end loop; 17:34:32 6 end ; 17:34:32 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:01.13 17:34:33 SCOTT@zkm(31)> / PL/SQL procedure successfully completed. Elapsed: 00:00:01.18 17:34:39 SCOTT@zkm(31)> / PL/SQL procedure successfully completed. Elapsed: 00:00:01.24 17:34:43 SCOTT@zkm(31)>
相对于串行下，性能稍微下降。
再试试有物化视图下，并发的执行情况，
17:40:44 SCOTT@zkm(27)> create materialized view scott.mv_emp 17:40:44 2 REFRESH force on commit 17:40:44 3 as 17:40:44 4 select * from scott.emp; Materialized view created. Elapsed: 00:00:00.03
17:40:47 SCOTT@zkm(27)> begin 17:41:01 2 for i in 1..10000 loop 17:41:01 3 update scott.emp set sal=9999 where empno=7934; 17:41:01 4 commit; 17:41:01 5 end loop; 17:41:01 6 end ; 17:41:01 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:44.82 17:41:46 SCOTT@zkm(27)> / PL/SQL procedure successfully completed. Elapsed: 00:00:49.45
----------------------------同时sid=31的运行-----------------------------
17:34:43 SCOTT@zkm(31)> begin 17:41:01 2 for i in 1..10000 loop 17:41:01 3 update scott.emp set sal=9999 where empno=7934; 17:41:01 4 commit; 17:41:01 5 end loop; 17:41:01 6 end ; 17:41:01 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:44.78 17:41:46 SCOTT@zkm(31)> / PL/SQL procedure successfully completed. Elapsed: 00:00:49.32
性能相对串行下降了将近一倍。
如果并发的会话是3个或者更多，那么预计性能下降会更大，这里不做测试。
这里对有物化视图的情况下做个10046，
08:36:10 SYS@zkm(27)> select value from v$diag_info where name like 'De%'; VALUE -------------------------------------------------------------------------------- /u01/app/oracle/diag/rdbms/zkm/zkm/trace/zkm_ora_6102.trc Elapsed: 00:00:00.10 08:37:05 SYS@zkm(27)> alter session set events '10046 trace name context forever,level 12'; Session altered. Elapsed: 00:00:00.01 08:37:26 SYS@zkm(27)> update scott.emp set sal=9999 where empno=7934; 1 row updated. Elapsed: 00:00:00.09 08:37:59 SYS@zkm(27)> commit; Commit complete. Elapsed: 00:00:00.43
使用tkprof格式化，
[oracle@oracle ~]$ tkprof /u01/app/oracle/diag/rdbms/zkm/zkm/trace/zkm_ora_6102.trc 10046.trc
去掉其余无用的递归SQL，剩余信息如下：
update scott.emp set sal=9999 where empno=7934 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.00 0.00 0 1 3 1 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2 0.00 0.00 0 1 3 1 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: SYS Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 0 0 0 UPDATE EMP (cr=1 pr=0 pw=0 time=116 us) 1 1 1 INDEX UNIQUE SCAN PK_EMP (cr=1 pr=0 pw=0 time=25 us cost=0 size=8 card=1)(object id 87109) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 1 0.00 0.00 SQL*Net message from client 1 66.12 66.12 ******************************************************************************** SQL ID: 23wm3kz7rps5y Plan Hash: 0 commit call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.01 0.03 0 0 2 0 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2 0.01 0.03 0 0 2 0 Misses in library cache during parse: 0 Parsing user id: SYS Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ log file sync 1 0.00 0.00 SQL*Net message to client 1 0.00 0.00 ******************************************************************************** delete from "SCOTT"."MV_EMP" call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 2 0 Execute 1 0.00 0.00 0 1 43 14 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2 0.00 0.00 0 1 45 14 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 83 (recursive depth: 1) Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 0 0 0 DELETE MV_EMP (cr=1 pr=0 pw=0 time=490 us) 14 14 14 INDEX FULL SCAN PK_EMP1 (cr=1 pr=0 pw=0 time=7 us cost=1 size=56 card=14)(object id 96640) ******************************************************************************** INSERT /*+ */ INTO "SCOTT"."MV_EMP"("EMPNO","ENAME","JOB","MGR","HIREDATE", "SAL","COMM","DEPTNO") SELECT "EMP"."EMPNO","EMP"."ENAME","EMP"."JOB", "EMP"."MGR","EMP"."HIREDATE","EMP"."SAL","EMP"."COMM","EMP"."DEPTNO" FROM "SCOTT"."EMP" "EMP" call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 2 0 Execute 1 0.00 0.00 0 7 31 14 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2 0.00 0.00 0 7 33 14 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 83 (recursive depth: 1) Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 0 0 0 LOAD TABLE CONVENTIONAL (cr=7 pr=0 pw=0 time=211 us) 14 14 14 TABLE ACCESS FULL EMP (cr=6 pr=0 pw=0 time=69 us cost=3 size=546 card=14) ********************************************************************************
这里可以总结以下几点，在无物化视图日志的情况下，on commit方式同步刷新的物化视图在dml并commit的情况下：
- 基表(emp)的所有dml操作，只要不提交并不会触发去更新对应的物化视图(mv_emp)。
- 提交之后，会先直接删除整张物化视图（trc中有“delete from "SCOTT"."MV_EMP"）。
- 删除整张物化视图的数据后，进行insert操作。
注意一点，上述的全部步骤均会对应产生TX锁，并且第2步的影响最大因为是直接delete掉全部的行。
另外，insert部分有个明显的“hint”标志/*+ */，我在这次的生产事故中的awr也有同样看到。
也难怪，一次基表的dml会这么多锁，并发差也正常。
类似这类方式创建的物化视图，适用于dml相对少并且不是特别重要的表上。
至于存在物化视图可以快速刷新的情况，这个就不在做实验了。
日志激增问题
在第一篇中，问题出现时候明显还有一个问题，那就是归档目录爆了。
查询日志切换频率也可以看到日志从个位数变为三位数。
这里也探究一下，删除物化视图，
09:08:17 SYS@zkm(27)> drop materialized view scott.mv_emp; Materialized view dropped. Elapsed: 00:00:00.56
创建视图v_redo_size作为查询会话产生的日志量，
14:10:47 SYS@zkm(28)> create or replace view v_redo_size as 14:11:04 2 select a.name,b.value 14:11:04 3 from v$statname a,v$mystat b 14:11:04 4 where a.statistic#=b.statistic# 14:11:04 5 and a.name='redo size'; View created. Elapsed: 00:00:00.10
运行update之前先查询该视图，接着运行update，在查询视图，两次的值相减就是会话产生的redo量。
14:11:13 SYS@zkm(28)> col name for a15 14:11:19 SYS@zkm(28)> select * from v_redo_size; NAME VALUE --------------- ---------- redo size 10940 14:20:29 SYS@zkm(28)> begin 14:20:34 2 for i in 1..10000 loop 14:20:34 3 update scott.emp set sal=9999 where empno=7934; 14:20:34 4 commit; 14:20:34 5 end loop; 14:20:34 6 end ; 14:20:34 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:01.15 14:20:36 SYS@zkm(28)> select * from v_redo_size; NAME VALUE --------------- ---------- redo size 5406192 Elapsed: 00:00:00.00 14:20:41 SYS@zkm(28)> select (5406192-10940)/1024 kb from dual; KB ---------- 5268.80078 Elapsed: 00:00:00.02
可以看到日志量差不多为5M，创建物化视图，
14:22:47 SCOTT@zkm(27)> create materialized view scott.mv_emp 14:22:48 2 REFRESH force on commit 14:22:48 3 as 14:22:48 4 select * from scott.emp; Materialized view created. Elapsed: 00:00:00.42
再试运行匿名块，
14:22:30 SYS@zkm(28)> select * from v_redo_size; NAME VALUE --------------- ---------- redo size 10757024 Elapsed: 00:00:00.00 14:22:58 SYS@zkm(28)> begin 14:23:07 2 for i in 1..10000 loop 14:23:07 3 update scott.emp set sal=9999 where empno=7934; 14:23:07 4 commit; 14:23:07 5 end loop; 14:23:07 6 end ; 14:23:07 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:22.28 14:23:31 SYS@zkm(28)> select * from v_redo_size; NAME VALUE --------------- ---------- redo size 177995832 Elapsed: 00:00:00.00 14:23:33 SYS@zkm(28)> select (177995832-10757024)/1024 kb from dual; KB ---------- 163319.148 Elapsed: 00:00:00.00
产生日志量差不多是163M，多这么多也难怪归档会爆掉。
这估计还受基表字段数量的影响，字段要是再多一点，估计redo量还更大。
至此，完毕！！
