今回は [自動拡張] について振り返ってみたいと思います。。
セミナーのログ管理のセッションでは [自動拡張] についてのお話がありました。
SQL Server のデータファイル / ログファイルには [自動拡張] という設定があります。
自動拡張を設定することでファイルの空きが無くなったときにディスクに空きがある場合、自動的に拡張するように設定することができます。 
自動拡張のサイズは、[現在のサイズに対しての比率 (%)] と [MB 単位] で、最大サイズに関しては [MB 単位] と [無制限] で指定することができます。
それでは、ログファイルの自動拡張についてまとめていきたいと思います。
■ログファイルの自動拡張について
ログファイルは以下の構成となっています。
自動拡張が発生すると以下のように拡張がされます。
# 手動拡張でも同様です。 
拡張が発生すると拡張分のディスクサイズが確保されます、その拡張分が仮想ログ (VLF) で分割されます。
上の絵では、VLF が 4 つで構成された形になっていますが、拡張するサイズによって 4 / 8 / 16 のどの個数で分割するかが決まります。
そのため、細かな拡張を繰り返すとログファイルを構成する VLF の個数が多くなりパフォーマンスに影響が出てきます。
# これに関しては別の機会にまとめようと思っています。
それでは、実際の環境で自動拡張を見ていきたいと思います。
現在、ログは 13,041,644 Byte の 2 個の VLF で構成がされています。
# VLF は作成 / 拡張時は最小で 4 個になるのですが、ファイルの圧縮 (SHRINK FILE) をすることで最小で 2 個にできます。 
データベースのプロパティからみた設定はこのようになっています。 
それでは、データを追加 (INSERT) して、ログファイルの自動拡張を見ていきたいと思います。 
このグラフはパフォーマンスモニタで、[Log File(s) Used (KB)] と、[Log Growths] を取得したものになります。
# Log Growths に関しては SQL Server のサービスが最後に起動してからの値だったはずなので、0 からは始まっていません。
ログファイルの現在のサイズと使用状況がこちらになります。 
25MB だったものが、925MB になっています。
今回は、100MB 単位で自動拡張をするように設定していますので、 9 回の拡張が発生したことになります。
上のグラフでも自動拡張の発生回数は 4 → 13 になっていますので回数は合っていますね。
仮想ログの状態も見てみたいと思います。 
この下にもデータは続いており、全部で 74 個の仮想ログがあります。
100MB の拡張だと一度の拡張に対して仮想ログが 8 個作成されます。
そのため
8 個 × 拡張 9 回 = 72 個 + 初期の 2 個 = 74 個
の仮想ログが作成されたことになります。
自動拡張に関しては、SQL Server のデフォルト トレースにも出力がされます。
デフォルト トレースは SQL Server をインストールしたインスタンスのディレクトリの [LOG] フォルダに出力がされます。
私が今回使用している環境では以下のディレクトリになります。
[C:Program FilesMicrosoft SQL ServerMSSQL10_50.SQL2008R2MSSQLLog]
デフォルト トレースは SQLTrace の .trc ファイルですので [SQL Server Profiler] で開くか [fn_trace_gettable ] を使用してクエリで情報を取得することができます。
今回はfn_trace_gettable を使用して情報を取得したいと思います。
|
DECLARE @filename varchar(500) |
実行後の結果はこちらになります。 
今回は、20:35 ～ 20:37 に実行していますので、デフォルト トレースにもこの時間帯のログは 9 件出力されています。
自動拡張を設定していない場合は、以下のようになります。 
ログファイルの上限まで達したら拡張ができないため、上限に達した後の追加処理はエラーとなります。
自動拡張を設定しておくことで、当初想定していたログファイルでは足りなくなったときでも処理を継続することができるようになります。
セミナーではログの拡張時には [ログの書き込み待ち] が発生するため、拡張は発生させないように最初から適切なサイズを設定するというお話がありました。
続いてログの書き込み待ちについてみていきたいと思います。
■拡張時のログの書き込み待ち
自動拡張だけに限らずログの拡張が行われている際にはログの書き込みがブロックされ、拡張が終わるまで待ち状態となります。
[自動拡張のログファイルの使用状況] のグラフで拡張が発生している際に、ログファイルの使用状況が一瞬止まって入るのが確認できます。
# さほど負荷をかけていない検証なので、本当に一瞬ですが。
自動拡張ではログの書き込み待ちを確認するのが難しいので、データの追加を行っている最中に、10GB のファイル拡張を行って検証をしてみたいと思います。
# 自動チェックポイントの実行は無効にしています。
拡張をしないでデータの追加を行った場合は以下のようなグラフになります。
ログファイルの使用状況も停止することなく上がっており、ログの書き込み待ちに関しては発生していません。
データの追加中に10GB のログの拡張を行ったものがこちらになります。
ログファイルの使用状況が平らになっている部分が拡張を実行したタイミングになります。
ログの拡張中は使用状況の上がりも鈍り、書き込み待ちの秒数が発生しているのが確認できます。
それでは、この書き込み待ちを [WRITELOG] の待ち事象からも見てみたいと思います。
WRITELOG の待ち事象を取得するには以下のクエリを実行します。
| SELECT * FROM sys.dm_os_wait_stats WHERE wait_type = ‘WRITELOG’ |
こちらが通常の追加を行う前後の待ち事象の状態になります。
処理を行っている間に
waiting_tasks_count = 501,013 ? 400,927 = 100,086
wait_time_ms = 306,407 ? 248,635 = 57,772
の WRITELOG に関しての待ち事象が発生していたのが確認できます。
それでは、拡張をした場合はどうなるでしょう。 
waiting_tasks_count = 607,419 ? 507,039 = 100,380
wait_time_ms = 378,033 ? 310,391 = 67,642
というようにログの書き込み待ちによる待ち事象が増加していることが確認できます。
余談ですが、ファイルの瞬時初期化 (SQL Server のサービス起動アカウントに [ボリュームの保守タスクを実行] を付与) に関しては BOL に [ログ ファイルの初期化ではそのまま空にする必要がありますが～] と書かれているように有効にしても効果は出ません。
waiting_tasks_count = 100,397 ? 13 = 100384
wait_time_ms = 67,068 ? 86 = 66,982
ログ管理に置いて自動拡張は保険として考え、運用中は発生しないようにすることでログの書き込み待ちを減らし、パフォーマンスの向上につなげることが可能となります。
セミナーでは、ログ管理のもしもの時の備えとして、[パフォーマンス条件警告] を使用したログの管理のお話がありました。
次の投稿では、パフォーマンス条件警告とその簡単な応用についてまとめてみたいと思います。