SE の雑記

SQL Server の情報をメインに Microsoft 製品の勉強内容を日々投稿

チェックポイント実行時のログ出力について

2 comments

SQL Server では定期的にチェックポイント (CHECKPOINT) が実行され、メモリ上のデータとディスク上のデータの同期が行われます。

今回の投稿ではこのチェックポイントが実行された際の情報を SQL Server のログに出力するための方法を見ていきたいと思います。

■チェックポイントとは


データ挿入時の基本的な流れを図にしたものがこちらになります。
# 以前、勉強会で使用した資料からの抜粋になります。
image

RDBMS の一般的な動作になると思いますが、データの変更が発生した場合、ログには先行書き込みでディスク上にログレコードが記録されます。
実際のデータへの変更に関しては、メモリ上のデータを変更しチェックポイントの発生時にメモリ上で変更されたデータをディスク上にも反映させます。
メモリ上にしかデータが変更されていない状態で障害が発生し、サーバーがダウンした場合は起動時にログの内容をディスクに反映 (REDO 処理) する ことで最新のデータへの復旧を行います。
# ディスク上の各ページのページヘッダには更新時の LSN (Log Sequence Number : ログシーケンス番号) が保存されていますのでログレコードの LSN と比較をすることでそのログをデータに反映すべきかの判断をすることができます。

SQL Server の復旧間隔はこのチェックポイントの発生頻度を変更するための設定となります。
復旧間隔が長い場合は、チェックポイントの発生頻度が長くなります。そのためディスク上へのデータの反映頻度が少なくなりますが、メモリ上にしか反映されていないデータ数が多くなりますので、サーバーの起動時に REDO で必要となる時間が伸びます。

復旧間隔を短くした場合は逆ですね。
チェックポイントの発生頻度が短くなりますので、頻繁にディスク上にデータの反映が行われますので REDO の処理時間は短くなります。

SQL Server 2008 R2 までは復旧間隔の設定はインスタンス単位でのみ可能だったのですが、SQL Server 2012 では間接チェックポイント (Indirect Checkpoint : インダイレクトチェックポイント) が追加され、データベース単位で設定をすることができるようになりました。

 

■DMV でディスク上へのフラッシュ状況を確認


メモリ上にのみ変更されているデータがどれだけあるかですが、DMV で確認をすることができます。
以下のようなクエリで確認できます。

SELECT
    DB_NAME(database_id)
    , is_modified
    , COUNT(*)
FROM
    sys.dm_os_buffer_descriptors
GROUP BY
    database_id
    , is_modified
ORDER BY 1

 

実行結果がこちらになります。
image

今回は [TEST[ というデータベースを使用しているのですが、[is_modified = 1] のページが存在していることが確認できます。
is_modified = 1 のデータはメモリ上にのみ更新が行われているデータですので、これがチェックポイントでディスク上に書かれる対象となります。

それでは [CHECKPOINT] を実行し、手動でチェックポイントを発生させ、再度データを取得してみます。
image

先ほどは [1389] となっていた is_modified = 1 のデータがなくなった (is_modified = 0 が増えた) ことが確認できますね。
これがチェックポイント時の動作になります。

メモリ上のデータをディスク (データファイル) に書き込み (フラッシュ) しますのでチェックポイントの発生時にはディスク負荷が一時的に上がることになります。

 

■チェックポイントの発生状況の取得


ここからが今回の投稿の本題になります。

チェックポイントの発生状況を確認するための方法として、パフォーマンスモニターで SQL Server: Buffer Manager オブジェクト の [Checkpoint pages/sec] を取得する方法があります。

このカウンターでチェックポイントで書き込みが行われたページを取得できますので、どの程度の頻度でデータファイルに書き込みが行われているかを確認できます。

それ以外の方法として今回紹介するトレースフラグ 3504 (TF3504) を使用する方法があります。
このトレースフラグを設定することでチェックポイントが発生した際の情報を SQL Server の ERRORLOG に出力することができます。
チェックポイントの発生ごとに出力がされますので、長い期間設定しているとログのサイズが肥大化するので注意してください。
# TF3505 という自動チェックポイントの発生を無効にするトレースフラグもあったりします。

SQL Server のトレースフラグを設定する場合、起動時のオプションとして [-T] で設定することが多いかと思います。
image

今回のようなオプションは常時設定しておく必要はあまりないかもしれませんので、このような場合はグローバルトレーするラグを T-SQL で一時的に設定するのが良いかと思います。

具体的には以下のような
クエリになります。

DBCC TRACEON (3504, -1)        — トレースフラグの有効化
DBCC TRACESTATUS            — トレースフラグの確認
DBCC TRACEOFF (3504, -1)    — トレースフラグの無効化

DBCC TRACEON でトレースフラグを有効にし、TRACESTATUS で確認、TRACEOFF で無効にしています。

トレースフラグを有効にした状態でチェックポイントが発生すると、以下のようなログが出力されるようになります。
image

このログはデータ挿入の SQL を流したままにした状態で取得をしたのですが 1 分間隔でチェックポイントが発生したのがログから確認できますね。
image

どれだけのページがフラッシュされてレイテンシーがどれくらいだったのかが出力されます。

トレースフラグを設定中はこのログが頻繁に出力されることになりますので、データの取得が終了したら TRACEOFF するのが良いかと。

SQL Server を長期間起動した状態だと、ERRORLOG を開くのに時間がかかることがありますので [sp_cycle_errorlog] を実行してログのローテーションを行ってから取得するとよいかと思います。

調査系のトレースフラグになりますがディスク負荷を調べるときには利用できそうですね。

Share

Written by Masayuki.Ozawa

6月 22nd, 2012 at 8:47 am

Posted in SQL Server

Tagged with

2 Responses to 'チェックポイント実行時のログ出力について'

Subscribe to comments with RSS or TrackBack to 'チェックポイント実行時のログ出力について'.

  1. チェックポイント実行時のログ出力について ≪ SE の雑記…
    素敵なエントリーの登録ありがとうございます – .NET Clipsからのトラックバック…

    .NET Clips

    22 6月 12 at 09:28

  2. […] チェックポイント実行時のログ出力について at SE の雑記 (engineer-memo.com) […]

Leave a Reply