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量還更大。
至此，完畢！！