古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #13 Tweet
随分間が空いてしまったのです、覚えてますかねw 前回のネタ。私もほぼ忘れてました orz. w
思い出しながら進めましょう:)
Previously on Mac De Oracle
前回は、CTASだと、内部的にdirect path writeされてしまうのでクリーンアウトが必要な状況にはならないという動きを確認しました。
scattered read同様に、sequential readだとどうなの？（という遠くから声が聞こえたきがしたのでw）
とはいえ、遅延ブロッククリーンアウトって、自分の理解だと、全表走査時の動きだと思っているので、多分、起きないよなーと。頭の上に雲型の吹き出した出た状態でイメージしているところ。
では、試してみましょう。
これまでと異なる箇所は、sequential read でぐるぐるループさせたいので、該当表に主キー索引を作成します。また、table full scanではなく、index unique scan で全行アクセスさせてみます。（この動きが大きく異なる部分です）
strong>0) 対象表のdrop/create と主キー作成
対象表のHOGE2は削除して作り直し。このテストケースでは主キーアクセスさせるため、合わせて主キーも作成しておきます。
SCOTT@orcl> @droppurge_create_hoge2_with_pk.sql
1* drop table hoge2 purge
Table dropped.
Elapsed: 00:00:00.51
1* create table hoge2 (id number, data varchar2(2000), constraint pk_hoge2 primary key (id) using index)
Table created.
Elapsed: 00:00:00.07
1* select segment_name,blocks from user_segments where segment_name like '%HOGE2%'
no rows selected
Elapsed: 00:00:00.13
1) 統計をクリアするためOracle再起動
$ sudo service oracle restart
[sudo] password for oracle:
Restarting oracle (via systemctl): [ OK ]
2) PDBのscottでログインしてclient_infoをセット
v$sessionのclient_info列の'TargetSession'文字列で他のSCOTTユーザーのセッションを特定するため。
SCOTT@orcl> @set_client_info 1 begin 2 DBMS_APPLICATION_INFO.SET_CLIENT_INFO('Target Session'); 3* end;PL/SQL procedure successfully completed.Elapsed: 00:00:00.00SCOTT@orcl>
3) CDBのSYSで統計取得（初回）
内容は省略！ （思い出したいかたはこの辺りを参照ください。。
4) PDBのSCOTTユーザーでNOAPPENDヒント付きIASを実行（データサイズは、コミットクリーンアウトではクリーンアウト仕切れないサイズ）／ 未コミット
NOAPPENDヒントを利用している理由は前回までの内容を見ていただければわかりますが、direct path writeさせたないためです。これによりコミットクリーンアウトではクリーンアウトできない状況、つまり、遅延ブロッククリーンアウトが必要となる状態を作っています。
SCOTT@orcl> @ias_noappend_from_hoge.sql
1* insert /*+ noappend */ into hoge2 select * from hoge
200000 rows created.
Elapsed: 00:00:19.63
14:32:40 SCOTT@orcl>
5) CDBのSYSで統計取得（未コミット）
検証中に統計値が変動したもののみ記載
狙い通りdirect path writeは抑止できていることは確認できます。
(CDB）システム統計
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sysstat DBWR checkpoint buffers written 22,918
sysstat DBWR checkpoints 72
sysstat DBWR thread checkpoint buffers written 22,918
sysstat DBWR transaction table writes 22
sysstat DBWR undo block writes 983
sysstat cleanouts only - consistent read gets 0
sysstat commit cleanout failures: block lost 0
sysstat commit cleanout failures: callback failure 0
sysstat commit cleanouts 1,601
sysstat commit cleanouts successfully completed 1,601
sysstat consistent gets 122,604
sysstat db block changes 564,554
sysstat deferred (CURRENT) block cleanout applications 12
sysstat free buffer requested 70,607
sysstat immediate (CR) block cleanout applications 0
sysstat immediate (CURRENT) block cleanout applications 1,752
sysstat no work - consistent read gets 67,108
sysstat physical reads 66,750
sysstat physical reads direct 66,709
sysstat physical writes 22,918
sysstat physical writes from cache 22,918
sysstat physical writes non checkpoint 22,918
sysstat redo blocks written 967,108
sysstat redo size 479,412,088
sysstat redo writes 378
(PDB) SCOTTのセッション統計
こちらから見てもdirect path writeは発生していません
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sesstat cleanouts only - consistent read gets 0
sesstat commit cleanout failures: block lost 0
sesstat commit cleanouts 1,589
sesstat commit cleanouts successfully completed 1,589
sesstat consistent gets 122,204
sesstat db block changes 564,506
sesstat deferred (CURRENT) block cleanout applications 7
sesstat free buffer requested 70,595
sesstat immediate (CR) block cleanout applications 0
sesstat immediate (CURRENT) block cleanout applications 1,748
sesstat no work - consistent read gets 66,884
sesstat physical reads 66,740
sesstat physical reads direct 66,709
sesstat redo size 478,945,336
該当期間の待機イベント記録されていないですよね。狙い通りなので準備としては問題なしです。
EVENT WAIT_CLASS
---------------------------------------------------------------- -----------------
SQL*Net message from client Idle
log buffer space Configuration
events in waitclass Other Other
direct path read User I/O
log file switch (private strand flush incomplete) Configuration
log file switch completion Configuration
log file sync Commit
db file sequential read User I/O
SQL*Net message to client Network
Disk file operations I/O User I/O
db file scattered read User I/O
6) CDB or PDBのSYSユーザで接続し、buffer cacheをflushする
SYS@orclcdb> @flush_buffercache.sql
1* alter system flush buffer_cache
System altered.
Elapsed: 00:00:09.04
14:36:26 SYS@orclcdb>
7) CDBのSYSで統計取得（buffer cacheをflush後）
strong>(CDB）システム統計
検証中に統計値が変動したもののみ記載
バッファキャッシュをフラッシュしたのでキャッシュから書き出されたことを示す physical writes from cache および関連する統計値が上昇しています。これも想定通りの挙動ですね。
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sysstat DBWR checkpoint buffers written 0
sysstat DBWR checkpoints 0
sysstat DBWR thread checkpoint buffers written 0
sysstat DBWR transaction table writes 8
sysstat DBWR undo block writes 1912
sysstat cleanouts only - consistent read gets 0
sysstat commit cleanout failures: block lost 0
sysstat commit cleanout failures: callback failure 0
sysstat commit cleanouts 43
sysstat commit cleanouts successfully completed 43
sysstat consistent gets 20793
sysstat db block changes 429
sysstat deferred (CURRENT) block cleanout applications 21
sysstat free buffer requested 1013
sysstat immediate (CR) block cleanout applications 0
sysstat immediate (CURRENT) block cleanout applications 9
sysstat no work - consistent read gets 12321
sysstat physical reads 977
sysstat physical reads direct 0
sysstat physical writes 47900
sysstat physical writes from cache 47900
sysstat physical writes non checkpoint 47900
sysstat redo blocks written 2017
sysstat redo size 994652
sysstat redo writes 23
(PDB) SCOTTのセッション統計
キャッシュをフラッシュしただけなので、該当セッションの統計には変化がありません。（まあ、そうですよねw）
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sesstat cleanouts only - consistentread gets 0
sesstat commit cleanout failures: block lost 0
sesstat commit cleanouts 0
sesstat commit cleanouts successfully completed 0
sesstat consistent gets 0
sesstat db block changes 0
sesstat deferred (CURRENT) block cleanout applications 0
sesstat free buffer requested 0
sesstat immediate (CR) block cleanout applications 0
sesstat immediate (CURRENT) block cleanout applications 0
sesstat no work - consistent read gets 0
sesstat physical reads 0
sesstat physical reads direct 0
sesstat physical writes 0
sesstat physical writes direct 0
sesstat physical writes from cache 0
sesstat physical writes non checkpoint 0
sesstat redo blocks written 0
sesstat redo size 0
8) PDBのSCOTTユーザーでコミットの実行
SCOTT@orcl> commit;
Commit complete.
Elapsed: 00:00:00.01
9) CDBのSYSで統計取得（コミット後）
strong>(CDB）システム統計
コミット時点ではクリーンアウト仕切れないほどの更新ブロック数かつ、コミット前にバッファキャッシュをフラッシュしているので、コミット時のクリーンアウトもできない状態なっています（これも事前の準備の通りの結果。なので問題なし）
commit cleanouts と commit cleanout failures: block lost がポイントです。コミット時にクリーンアウトできる量（過去の記事を参照のこと）の閾値以下の量ですら、事前にキャッシュからフラッシュしまっているので、クリーンアウトに失敗（できないようにしたので当然ですが）しています。両方の統計値が同一であるとくことは、コミットクリーンアウトしようとした全てでくりアウトできなかった。理由はキャッシュに該当ブロックがキャッシュから落ちていたから（意図的に落としたわけですが）ということを意味します。予定通りですね。
コミットの時点で最低現おこなうクリーンアウトもさせていないですが、このケースでは 11140 ブロックをコミット時にクリーンアウトしようとしているので、コミット時のクリーンアウトが行われていたとしても 50,000 ブロック以上は遅延されていたことになりますね。今回は、 66,667 ブロックがク後続のSQLで参照されるついでにクリーンアウトされることになります。
検証中に統計値が変動したもののみ記載
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sysstat DBWR checkpoint buffers written 0sysstat DBWR checkpoints 0sysstat DBWR thread checkpoint buffers written 0sysstat DBWR transaction table writes 0sysstat DBWR undo block writes 0sysstat cleanouts only - consistent read gets 0sysstat commit cleanout failures: block lost 11140sysstat commit cleanout failures: callback failure 0sysstat commit cleanouts 11140sysstat commit cleanouts successfully completed 0sysstat consistent gets 34sysstat db block changes 1sysstat deferred (CURRENT) block cleanout applications 0sysstat free buffer requested 8sysstat immediate (CR) block cleanout applications 0sysstat immediate (CURRENT) block cleanout applications 0sysstat no work - consistent read gets 5sysstat physical reads 8sysstat physical reads direct 0sysstat physical writes 0sysstat physical writes from cache 0sysstat physical writes non checkpoint 0sysstat redo blocks written 3sysstat redo size 456sysstat redo writes 3
(PDB) SCOTTのセッション統計
セッションレベルでみるよりはっきり見るとことができます。
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sesstat cleanouts only - consistent read gets 0sesstat commit cleanout failures: block lost 11140sesstat commit cleanouts 11140sesstat commit cleanouts successfully completed 0sesstat consistent gets 0sesstat db block changes 1sesstat deferred (CURRENT) block cleanout applications 0sesstat free buffer requested 1sesstat immediate (CR) block cleanout applications 0sesstat immediate (CURRENT) block cleanout applications 0sesstat no work - consistent read gets 0sesstat physical reads 1sesstat physical reads direct 0sesstat physical writes 0sesstat physical writes direct 0sesstat physical writes from cache 0sesstat physical writes non checkpoint 0sesstat redo blocks written 0sesstat redo size 176
10) PDBのSCOTTユーザーで遅延ブロッククリーンアウト有無確認（対象表を主キーによる一意検索で全行アクセス）
さて、事前に想定している実行計画になっているかプランだけ確認しておきましょう。主キーによる索引ユニークスキャンであることが確認できます。想定通りです。この実行計画で、200,000 行をグルグル参照した場合、遅延されたブロッククリーンアウトが行われるでしょうか。。。。（してくれないと思いますが。。。試してみましょう）
SCOTT@orcl> set autot trace exp
14:41:47 SCOTT@orcl> select * from hoge2 where id = 1;
Elapsed: 00:00:00.00
Execution Plan
----------------------------------------------------------
Plan hash value: 3319133482
----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 1015 | 1 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| HOGE2 | 1 | 1015 | 1 (0)| 00:00:01 |
|* 2 | INDEX UNIQUE SCAN | PK_HOGE2 | 1 | | 1 (0)| 00:00:01 |
----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("ID"=1)
SCOTT@orcl> set autot off
SCOTT@orcl>
SCOTT@orcl> @table_unique_scan_hoge2.sql
1 begin
2 for i in 1..&1 loop
3 for hoge2_rec in (select * from hoge2 where id = i) loop
4 null;
5 end loop;
6 end loop;
7* end;
Enter value for 1: 200000
old 2: for i in 1..&1 loop
new 2: for i in 1..200000 loop
PL/SQL procedure successfully completed.
Elapsed: 00:00:14.94
14:39:36 SCOTT@orcl>
11) CDBのSYSで統計取得（遅延ブロッククリーンアウト有無確認。対象表を主キーによる一意検索で全行アクセス）
strong>(CDB）システム統計
クリーンアウトが行われていれば、データブロックの総数 66,667 ブロックは少なくともクリーンアップの対象になっているはずですが。。。。。
cleanout系の統計値に動きはありませんよね。
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sysstat DBWR checkpoint buffers written 21sysstat DBWR checkpoints 0sysstat DBWR thread checkpoint buffers written 0sysstat DBWR transaction table writes 5sysstat DBWR undo block writes 5sysstat cleanouts only - consistent read gets 0sysstat commit cleanout failures: block lost 0sysstat commit cleanout failures: callback failure 15sysstat commit cleanouts 366sysstat commit cleanouts successfully completed 351sysstat consistent gets 632775sysstat db block changes 7848sysstat deferred (CURRENT) block cleanout applications 169sysstat free buffer requested 76662sysstat immediate (CR) block cleanout applications 0sysstat immediate (CURRENT) block cleanout applications 169sysstat no work - consistent read gets 21822sysstat physical reads 69501sysstat physical reads direct 0sysstat physical writes 21sysstat physical writes from cache 21sysstat physical writes non checkpoint 10sysstat redo blocks written 5132sysstat redo size 2536084sysstat redo writes 28
(PDB) SCOTTのセッション統計
physical reads は、67706 ブロックなのでほ、HOGE2表の索引と表のセグメントサイズほどは物理読み込みされたということになります。ただ、cleanouts only - consistent read gets などのクリーンアウトを示す統計値はほぼ動いていません。ようするに、db file sequential readとなる index unique scan ではブロッククリーンアウトは発生しないということを意味しています。
おおおーーー。だったら、グルグル系の処理で一行ごとに処理するのが最高じゃん！ という単純な話ではないので要注意ですからねw
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sesstat cleanouts only - consistent read gets 0sesstat commit cleanout failures: block lost 0sesstat commit cleanouts 4sesstat commit cleanouts successfully completed 4sesstat consistent gets 600005sesstat db block changes 14sesstat deferred (CURRENT) block cleanout applications 2sesstat free buffer requested 74540sesstat immediate (CR) block cleanout applications 0sesstat immediate (CURRENT) block cleanout applications 2sesstat no work - consistent read gets 0sesstat physical reads 67706sesstat physical reads direct 0sesstat physical writes 0sesstat physical writes direct 0sesstat physical writes from cache 0sesstat physical writes non checkpoint 0sesstat redo blocks written 0sesstat redo size 2152
10) PDBのSCOTTユーザーで遅延ブロッククリーンアウト有無確認（sacattered read）
single block readを行うindex unique scanではクリーンアウトが発生しなかったということは、全表走査させる table full scan かつ scattered readさせれば発生するのではないでしょうか？ という確認です。
auto traceで統計情報をみると、なにやら、REDOログが大量に生成されてますよね。。。これは！！！
SCOTT@orcl> @table_full_scan_hoge2.sql
1* alter session set "_serial_direct_read" = never
Session altered.
Elapsed: 00:00:00.01
1* alter session set "_very_large_object_threshold" = 20400
Session altered.
Elapsed: 00:00:00.00
set autot trace exp stat
1* select * from hoge2
200000 rows selected.
Elapsed: 00:00:06.55
Execution Plan
----------------------------------------------------------
Plan hash value: 1530105727
---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 172K| 167M| 18223 (1)| 00:00:01 |
| 1 | TABLE ACCESS FULL| HOGE2 | 172K| 167M| 18223 (1)| 00:00:01 |
---------------------------------------------------------------------------
Note
-----
- dynamic statistics used: dynamic sampling (level=2)
Statistics
----------------------------------------------------------
10 recursive calls
1 db block gets
147157 consistent gets
377 physical reads
5866968 redo size
406775148 bytes sent via SQL*Net to client
147265 bytes received via SQL*Net from client
13335 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
200000 rows processed
set autot off
14:56:56 SCOTT@orcl>
11) CDBのSYSで統計取得（遅延ブロッククリーンアウト有無確認。対象表を主キーによる一意検索で全行アクセス）
strong>(CDB）システム統計
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sysstat DBWR checkpoint buffers written 1121sysstat DBWR checkpoints 0sysstat DBWR thread checkpoint buffers written 0sysstat DBWR transaction table writes 36sysstat DBWR undo block writes 347sysstat cleanouts only - consistent read gets 66676sysstat commit cleanout failures: block lost 0sysstat commit cleanout failures: callback failure 0sysstat commit cleanouts 806sysstat commit cleanouts successfully completed 806sysstat consistent gets 174296sysstat db block changes 80773sysstat deferred (CURRENT) block cleanout applications 383sysstat free buffer requested 2095sysstat immediate (CR) block cleanout applications 66676sysstat immediate (CURRENT) block cleanout applications 75sysstat no work - consistent read gets 27953sysstat physical reads 1842sysstat physical reads direct 0sysstat physical writes 1121sysstat physical writes from cache 1121sysstat physical writes non checkpoint 981sysstat redo blocks written 16550sysstat redo size 8074260sysstat redo writes 351
(PDB) SCOTTのセッション統計
HOGE2の表のクリーンアウト対象ブロック数、66,667 きっちり同じ数字が現れました。しかも cleanoutに関わる統計でかつ、大量のREDOログも生成されています。でました〜〜〜w クリーンアウト。全表走査かつ、scattered readで。
SOURCE NAME VALUE------- ---------------------------------------------------- ---------------sesstat cleanouts only - consistent read gets 66667sesstat commit cleanout failures: block lost 0sesstat commit cleanouts 1sesstat commit cleanouts successfully completed 1sesstat consistent gets 153731sesstat db block changes 66718sesstat deferred (CURRENT) block cleanout applications 0sesstat free buffer requested 690sesstat immediate (CR) block cleanout applications 66667sesstat immediate (CURRENT) block cleanout applications 0sesstat no work - consistent read gets 16317sesstat physical reads 680sesstat physical reads direct 0sesstat redo size 5877252
まとめ
index unique scanでグルグルさせつつ、全行アクセスしても発生しないですよね！
single block readになるunique index scanでは、遅延ブロッククリーンアウトは発生しない。（想像通りでよかったw）
で、そのあとで全表走査（scattered read)させてみると、やはり、遅延ブロッククリーンアウトは発生するわけですよ。面白いです。ほんと。
さあ、5月末まで追い込みだw ブログ書かないとw （頑張って、アドベントカレンダー全部俺やっとくほうが実は楽なのかもしれないw）
では、また。
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #1
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #2
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #3
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #4
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #5
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #6
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #7
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #8
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #9
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #10
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #11
・古くて新しい？ 遅延ブロッククリーンアウト (deferred block cleanout) #12
| 固定リンク | 0
コメント