書き出し一貫性 - Restartメカニズム

先日、特定のDMLが多すぎるロジカルリードを持つ問題に対する問い合わせがありました。たとえその問題に対する原因ではありませんでしたけど、おかげで書き出し一貫性(Write Consistency)問題を一度話し合う必要性を感じました。

簡単なテストを通じて話し合ってみます。まず次のようにテーブルを一つ作ります。

UKJA@ukja1021> select * from v$version where rownum = 1;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Prod

UKJA@ukja1021> create table t1
  2  as
  3  select level as c1, rpad('x',1000) as c2
  4  from dual
  5  connect by level <= 10000
  6  ;

Table created.

テーブルT1に対してトリガーを作って行一件が変更されるたびにpkg_temp.g_update_cnt値を１づつ増加します。

UKJA@ukja1021> create or replace package pkg_temp
  2  is
  3   g_update_cnt number;
  4  end;
  5  /

Package created.

UKJA@ukja1021> -- create trigger
UKJA@ukja1021> create or replace trigger trg1
  2  after update on t1
  3  for each row
  4  begin
  5   pkg_temp.g_update_cnt := pkg_temp.g_update_cnt + 1;
  6  end;
  7  /

次のように10,000件を変更するとpkg_temp.g_update_cnt値は10,000になります。

UKJA@ukja1021> exec pkg_temp.g_update_cnt := 0;

PL/SQL procedure successfully completed.

UKJA@ukja1021> 
UKJA@ukja1021> update t1 set c2 = rpad('y',1000)
  2  where c1 = c1
  3  ;

10000 rows updated.

UKJA@ukja1021> commit;

Commit complete.

UKJA@ukja1021> 
UKJA@ukja1021> exec dbms_output.put_line('update cnt = ' || pkg_temp.g_update_cnt);
update cnt = 10000

PL/SQL procedure successfully completed.

今、次のようにテストを変更します。

1. セッションAで10,000件を変更します。
   
2. セッションAがまだ最後の行を変更する前にセッションBが最後の行の値を変えてコミットを行います。
   
3. セッションAが変更を終えたあとpkg_temp.g_update_cnt値を確認します。
   

セッションAが10,000件を変更始めます。

UKJA@ukja1021> exec pkg_temp.g_update_cnt := 0;

PL/SQL procedure successfully completed.

UKJA@ukja1021> 
UKJA@ukja1021> update t1 set c2 = rpad('y',1000)
  2  where c1 = c1
  3  ;
....

セッションAがまだ最後の行を変更する前にセッションBが最後の行の値を変えてコミットを行います。

UKJA@ukja1021> update t1 set c1 = c1+1 where c1 = 10000;

1 row updated.

UKJA@ukja1021> commit;

Commit complete.

セッションAが変更を終えた後pkg_temp.g_update_cnt値を確認します。驚いたことにpgk_temp.g_update_cntの値は19,999件です!

...
10000 rows updated.

UKJA@ukja1021> commit;

Commit complete.

UKJA@ukja1021> exec dbms_output.put_line('update cnt = ' || pkg_temp.g_update_cnt);
update cnt = 19999

PL/SQL procedure successfully completed.

これは10,000件ではなくてその二倍に該当する20,000件ぐらいが変更されたということを意味します。これをよくRestartメカニズムと呼びます。

1. セッションAが最後の行を変更するため一応Consistent Readモードで該当ブロックを読み込みます。
   
2. セッションAはクエリが始まった後該当行がセッションBに変更されてコミットされたのを確認します。
   
3. UPDATE文のwhere c1 = c1 条件で一貫性確認(Consistency Check)がなされます。セッションAは最後の行はUPDATEが始まった後で変更されたので該当条件を満足するかしないかを確認するのが不可能だと判断します。
   
4. こんな場合セッションAは今までの変更をロールバックし、UPDATE文を行い直します。これをRestartメカニズムと言います。したがって9,999＋10,000＝19,999件の行が変更されたことです。
   

Restartの副作用はSQL*Traceの結果でもよく現れます。Restartが発生した場合同じに10,000個の行を変更しますが、ずっと多い仕事をします。ロールバックをして行い直さなければならないからです。

-- Restartがなされない場合
update t1 set c2 = rpad('y',1000)
where c1 = c1

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          7          0           0
Execute      1      0.34       0.52          0       1443      12992       10000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.35       0.53          0       1450      12992       10000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61  

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  UPDATE  T1 (cr=1487 pr=0 pw=0 time=530716 us)
  10000   TABLE ACCESS FULL T1 (cr=1432 pr=0 pw=0 time=74012 us)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  log buffer space                                5        0.01          0.05
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

-- Restartがなされる場合
update t1 set c2 = rpad('y',1000)
where c1 = c1

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      1.25       6.29          0       4323      67568       10000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      1.25       6.29          0       4323      67568       10000

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61  

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  UPDATE  T1 (cr=4411 pr=0 pw=0 time=5643605 us)
  30000   TABLE ACCESS FULL T1 (cr=4297 pr=0 pw=0 time=180259 us)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  log file switch completion                      4        0.99          2.28
  log file switch (checkpoint incomplete)         2        0.38          0.44
  log buffer space                               18        0.68          1.98
  enq: TX - row lock contention                   1        0.07          0.07
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

このようなRestartメカニズムはよくオラクルは読み取り一貫性(Read Consistency)のみならず書き出し一貫性(Write Consistency)を持っているとも言います。もっと正確に言えばオラクルの読み取り一貫性(Read Consistency)のメカニズムがDMLに掛ける特殊な影響だと言っても良いでしょう。