今回は [自動拡張] について振り返ってみたいと思います。。

セミナーのログ管理のセッションでは [自動拡張] についてのお話がありました。

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) SELECT @filename = path FROM sys.traces WHERE is_default = 1 SELECT @filename SELECT     convert(int, EventClass) as EventClass,     DatabaseName,     Filename,     (Duration/1000) as Duration,     StartTime,     EndTime,     (IntegerData*8.0/1024) as ChangeInSize FROM     sys.fn_trace_gettable(@filename, default) WHERE     EventClass >=  92     AND     EventClass <=  95     AND     DatabaseName = DB_NAME() ORDER BY     StartTime DESC

 

実行後の結果はこちらになります。

今回は、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

ログ管理に置いて自動拡張は保険として考え、運用中は発生しないようにすることでログの書き込み待ちを減らし、パフォーマンスの向上につなげることが可能となります。

セミナーでは、ログ管理のもしもの時の備えとして、[パフォーマンス条件警告] を使用したログの管理のお話がありました。

次の投稿では、パフォーマンス条件警告とその簡単な応用についてまとめてみたいと思います。

ログ管理の中でお話頂いた [復旧モデル] について振り返ってみます。
今回は復旧モデルによる、ログの使用状況の違いをまとめて見たいと思います。

SQL Server には復旧モデルという考えがあり、この復旧モデルがリストア時に復旧可能なタイミングとトランザクションログの管理 (解放のタイミング) に影響します。

復旧モデルには、以下の 3 種類があります。

• 完全
• 一括ログ
• 単純

完全復旧モデルと一括ログ復旧モデルに関しては、定期的なバックアップによるログの管理が必要となり、単純復旧モデルに関しては特定のタイミングで自動的に解放 (チェックポイント時のログの切り捨て) が行われます。
そのため、完全 / 一括ログ復旧モデルでないとログを使用したリストアを実施することはできません。

まずは、完全復旧モデルと単純復旧モデルのログの利用のされ方について確認してみたいと思います。
今回は、ログファイルを 30MB にして自動拡張を無効にした状態で大量のデータを追加 (INSERT) してテストをしています。

■チェックポイント発生時のログの切り捨て

完全復旧モデルの場合には、チェックポイントが発生してもログは切り捨てられません。そのため、トランザクションログの使用状況が上限に達した際には、トランザクションログが上限に達したというメッセージが表示されそれ以上のデータの追加ができなくなります。
# 一括ログ復旧モデルもチェックポイント時のログ切り捨ては行われないので、同じトレンドになります。

メッセージとしては以下のエラーが出力されます。

メッセージ 9002、レベル 17、状態 2、行 2 データベース ‘TEST’ のトランザクション ログがいっぱいです。ログの領域を再利用できない理由を確認するには、sys.databases の log_reuse_wait_desc 列を参照してください。

[sys.databases] を確認すると以下の情報を取得することができます。

今回の場合、ログの領域が再利用できない理由はログ領域がフルになってしまい、バックアップの必要があるという事を確認できます。

 

それでは、単純復旧モデルにした場合にはログの使用状況はどうなるでしょう。

データの追加操作としては全く同じ内容を実行したのですが、単純復旧モデルの場合はチェックポイントの発生タイミングに合わせてログの使用状況が下がっていることが確認できます。

この挙動を [チェックポイント発生時のログの切り捨て] と呼びます。
復旧モデルが単純復旧モデルとなっているデータベースはログのバックアップを取得することができません。
そのため、チェックポイントが発生してメモリ上のダーティーページをディスクに書き込んだタイミングでそれまでのログレコードが不要 (変更箇所がデータファイルに書き込まれているため) となり切り捨てることが可能になります。
チェックポイントの発生ですが、バックアップの取得 / 手動による [CHECKPOINT] ステートメントの実行 / [復旧間隔] の設定に応じた自動チェックポイントなどで発生がします。
今回発生しているチェックポイントは自動チェックポイントにより実行されています。
# 最後の一回だけは私が手動でチェックポイントを発生させているので山の形が少し変わっています。
余談ではありますが自動チェックポイントはトレースフラグ [3505] を設定することで無効にすることもできます。
INF: Use Trace Flag 3505 to Control SQL Server Checkpoint Behavior

 

■完全復旧モデルと一括ログ復旧モデルのログの使用状況の違い

それでは、次に完全復旧モデルと一括ログ復旧モデルの違いを確認してみたいと思います。
この復旧モデルの違いですが、最小ログ記録が可能な操作をした際のログの書き込みが変わってきます。

完全復旧モデルでは、すべての操作のログが完全に記録されますが、一括ログ復旧モデルでは最初ログ記録が可能な操作をした場合は、ログは最小限のもののみ記録がされます。
最小ログ記録が可能な操作
# インデックス系の操作は一括ログ復旧モデルでないと、最小ログにならないと思っていたのですが上記の内容を読むとそうでもないらしいですね。別の機会で検証したいと思います。また、操作方法によっては完全復旧にしていても最小ログになってしまったので今回は完全復旧モデルでは意図的に最小ログ記録にならない操作をしています。

 

今回は、[BULK INSERT] を使って違いを確認してみたいと思います。

どちらの復旧モデルでも波形は一緒になってしまっていますね。
これですが、今回は以下のようなクエリを実行していました。

BULK INSERT Table_1 FROM ‘F:Dataexport.txt’

BULK INSERT を実行する場合、上記のクエリでは最小ログ記録での動作にはなりません。
そのため、一括ログ復旧モデルでも完全なログの記憶動作となり、両復旧モデルで同じ波形となっています。

BULK INSERT に限った話ではないのですが、一括インポート時のログを最小ログ記録にするためには条件があり、[テーブルロックを指定] する必要があります。
一括インポートで最小ログ記録を行うための前提条件
# 他にも条件はあるのですが、今回はインデックスを持たない 1 列の単純なヒープ構造のテーブルを使用しています。

それでは、クエリを以下のように書き換えて実行をしてみます。

BULK INSERT Table_1 FROM ‘F:Dataexport.txt’ WITH (TABLOCK)

波形だけをみると一緒の波形になっているのですが、ログファイルの使用状況には大きな差が出ています。
テーブルロックを使用する前はログファイルの使用状況は 30MB まで上昇していました。
テーブルロックを使用した場合は、20KB 程度の使用で処理を完了することができています。
# 実は、テーブルロックを使用しなかった場合は、ログがフルになっていたりもしたのですが。

それでは、実際のログレコードから完全ログ記録と最小ログ記録の違いを比較してみたいと思います。

[完全ログ記録]

[最小ログ記録]

完全ログ記録の場合は [LOP_INSERT_ROWS] という形で、追加した行単位でログレコードを書き込んでいきます。
最小ログ記録の場合は、[LOP_SET_BITS] という形で行を追加するにあたって [変更のあったエクステント] の情報のみを書き込んでいます。
最小ログ記録が発生する、一括ログ操作に関しての変更は BCM (一括変更マップ : Bulk Changed Map) という領域を使用して管理されるためこのような動きになります。

使用する復旧モデルによって、ログの使用状況に差が出てきます。
単純復旧モデルを使用した場合はチェックポイント発生時に解放できるログは解放されますが、それ以外の復旧モデルに関してはログのバックアップを取得ないと使用している領域は解放されません。

ログはログのバックアップのタイミングを考慮したうえで、そのタイミングで解放される領域で処理がうまく回るようなサイズを指定しておくことで、ログがフルにならず処理を継続することが可能となります。

ただし、一時的なトランザクションの増加に備えて、[自動拡張] を設定して保険とすることも考えられれます。
セミナーの中では自動拡張時のログの書き込み待ちについても触れられていました。

次の投稿では [自動拡張] についてお話しいただいたことについて振り返ってみたいと思います。

12 月 8 日に Microsoft 社が開催している SQL Server の Get The Fact セミナーに参加をしてきました。
SQL Server の真実 – Get The Fact セミナー

このセミナーですがチョークトークの形で開催されており、Microsoft 社 の SQL Server Product Manager チームの方と、かなり近い距離でセッションを受けられるとても貴重な機会でした。
# 質問を Twitter でつぶやくと答えてくれたり。

第 1 回は運用管理について以下の内容についてのセッションでした。

1. ログ管理
2. バックアップ & リカバリ
3. でタッチ & アタッチによるデータベースの移動
4. パフォーマンスデータコレクション

まずは、ログ管理について数回に分けてまとめていきたいと思います。
今回はデータ書き込み時にログがどのように使われるかと、ログの基本的な構成について、セッションの内容をふまえ振り返っていきたいと思います。

■データ書き込みの基本動作

トランザクションログについてまとめるにあたり、セミナーでもお話しがあったのですが、データ書き込みの基本動作について軽くまとめてみたいと思います。

SQL Server のデータ書き込みですが、ログキャッシュに書き込み → トランザクションログファイルに書き込み → メモリ上のデータを変更 → チェックポイント発生時にメモリ上のデータをデータファイルに書き込みという流れになります。
# ログキャッシュと、ログファイルへの書き込みタイミングは大抵の場合、タイムラグはさほどないというお話でした。

データ変更時の流れを概要図としてまとめると以下のようになります。
# 概要図なので実際の挙動とは少し違うところがあるのですが。

データ変更 (INSERT / UPDATE / DELETE / TRUNCATE) をした場合、ログに書き込んだ後にすぐにデータファイルを更新するのではなくメモリ上のデータを変更して、その後に実際のデータファイルの更新が行われます。
② の処理でメモリ上のデータは変更されているが、実際のデータファイルが更新されていないデータ (ページ) を [ダーティーページ] (汚れたページ) と呼び、メモリ上のデータをデータファイルに書き込むタイミングを [チェックポイント] と呼びます。

ダーティーページに関しては、以下のクエリで確認をすることが可能です。

SELECT     CASE database_id         WHEN 32767 THEN ‘Resources’         ELSE DB_NAME(database_id)     END AS [DatabaseName],     COUNT(*) AS [TotalPage],     SUM(CONVERT(int,is_modified)) AS [DirtyPage] FROM     sys.dm_os_buffer_descriptors GROUP BY     database_id

TEST というデータベースに対してデータ更新を行った際のダーティーページの情報が以下になります。
TEST データベースでメモリを 8 ページ使用しており、そのすべてのページがダーティページとなっています。
# データを新規に INSERT した時のメモリの情報になります。

チェックポイントが発生し、メモリ上のデータがデータファイルに書き込まれると、その処理で使用していたログファイルの内容 (変更されたデータの情報) はデータファイルに反映された状態となりますので、そこまでの処理が終了しすることで、ログの内容が消せる状態となります。

メモリ上のデータにしか変更が反映されていない状態で、その変更分のログが消されてしまいますと、メモリの内容が無くなった 場合 (シャットダウンや異常終了等) に、変更内容を戻すことができなくなってしまいますので。

 

手動でチェックポイント (CHECKPOINT ステートメントを実行) した後に、ページの状態を取得するクエリを実行した時の結果が以下になります。

ダーティーページがフラッシュされ、0 になっているのが確認できます。
ダーティーページをフラッシュしても、メモリ上にはキャッシュとしてデータは残った状態になります。
更新されたデータをそのままメモリ上に残しておいた方が、そのデータを使用する処理が発生した場合、ディスクからデータを読まずに済みますので。

■トランザクションログファイルの構成

ログファイルは [ldf] という拡張子のファイルで構成がされています。
ログファイルは複数の ldf ファイルで構成することも可能なのですが、ログファイルはシーケンシャルに使われますので複数のファイルで構成しても、ファイルが並行で使用され負荷が分散されるという事はありません。

概要図を書くと以下のようになります。

ログファイルを複数用意するのは、負荷分散ではなく (複数ファイルを用意しても負荷は分散されない) ログファイルを格納しているドライブの容量がなくなり、追加のログファイ
ルを設定しなくなてしまった場合になるのかと思います。
# このような状況が発生しないようにするのがベストなのですけどね。

ログファイルは、データファイルとは異なりファイルグループと言った概念がなく、単一のファイルで構成されているのですが内部的には仮想ログファイル (Virtual Log File : VLF) という単位に分割がされています。

ログファイルはトランザクションログのバックアップを適切に実行することでこの仮想ログが循環されながら使用されることになります。

データ変更時のログの内容ですが、ログレコードとして管理されており、ログレコードには [LSN] (Log Sequence Number) というシーケンシャル No が振られています。

トランザクションログのログレコードの内容は [DBCC LOG] を実行することで確認をすることができます。
DBCC ログは以下の形式で実行を行います。

dbcc LOG (dbname | dbid [,{0|1|2|3|4}[,[‘lsn’,'[0x]x:y:z’]|[‘dir’, 0|1]|[‘numrecs’,num]|[‘xdesid’,’x:y’]|[‘extent’,’x:y’]|[‘pageid’,’x:y’]|[‘objid’,{x,’y’}]|[‘logrecs’,{‘lop’|op}…]|[‘output’,x,[‘filename’,’x’]]|[‘column’,'<value>’]|[‘key’,'<value>’]|[‘nolookup’]|[‘allocid’,BIGINT]…]]])

 

ログレコードの詳細まで表示する場合は、オプションとして [4] を設定します。
[DBCC LOG(N’TEST’, 4)] といった形式で実行することでログレコードの内容を含めて取得することが可能です。

トランザクションをロールバック / ロールフォワードするときなどは、この LSN を使用することで、どの地点まで戻せばよいのかを判断しています。 
データファイルのページでも LSN は保持しており、ページの LSN とログの LSN を比較することで、ロールフォワードの必要があるかを判断しています。
# この辺の詳細は別途まとめる予定です。

ページの情報は [DBCC PAGE] を実行することで、取得ができます。
以下は DBCC PAGE の実行例です。
# DBCC PAGE で情報を取得するためには、トレースフラグ [3604] を有効にする必要があります。

DBCC TRACEON(3604) DBCC PAGE (N’TEST’, 1, 78) DBCC TRACEOFF(3604)

PAGE: (1:78) BUFFER: BUF @0x0000000085FB5F00 bpage = 0x00000000853A8000           bhash = 0x0000000000000000           bpageno = (1:78) bdbid = 5                            breferences = 0                      bcputicks = 0 bsampleCount = 0                     bUse1 = 23176                        bstat = 0xc00009 blog = 0x21212159                    bnext = 0x0000000000000000          PAGE HEADER: Page @0x00000000853A8000 m_pageId = (1:78)                    m_headerVersion = 1                  m_type = 1 m_typeFlagBits = 0x4                 m_level = 0                          m_flagBits = 0x8200 m_objId (AllocUnitId.idObj) = 45     m_indexId (AllocUnitId.idInd) = 256  Metadata: AllocUnitId = 72057594040877056                                 Metadata: PartitionId = 72057594039173120                                 Metadata: IndexId = 0 Metadata: ObjectId = 2137058649      m_prevPage = (0:0)                   m_nextPage = (0:0) pminlen = 5                          m_slotCnt = 700                      m_freeCnt = 396 m_freeData = 6396                    m_reservedCnt = 0                   m_lsn = (286:13625:2) m_xactReserved = 0                   m_xdesId = (0:0)                     m_ghostRecCnt = 0

ページ情報の [m_lsn] からページが更新された際の LSN を確認することが可能です。

仮想ログにはシーケンシャル No が内部的に振られており、ログレコードはこのシーケンシャル No を考慮しながら仮想ログを先頭から使用しながら書き込まれていきます。

このように書き込みが
行われますので、複数のファイルを用意した場合は以下のように使用されます。

仮想ログファイルは [DBCC LOGINFO] を実行することで確認することができます。
このクエリを実行すると以下のような情報が取得できます。

この情報を確認することで、ログファイルが内部的にいくつの仮想ログに分かれていて、今どの仮想ログが使用されている (再利用ができない) 状態なのかを確認することができます。
Status = 2 は ACTIVE なログが存在している VLF となるため、再利用することができません。
# この辺は SQL Server を実行しているコンピュータでトランザクション ログのサイズが予期せず増大する、または、ログがいっぱいになる に少し記載があります。

この状態の VLF は [トランザクションログのバックアップ] を取得することで、アクティブなログレコードを含んでいない VLF のStatus が 0 (REUSABLE) となります。

REUSABLE に変わった VLF は再利用が可能になりますので、新規にログレコードを書き込むことが可能となります。

現在、アクティブなログを含んでいる VLF に関しては、Status = 2 のままですが、アクティブなログを含んでいない VLF に関しては Status = 0 となり再利用が可能となります。
# アクティブなログを含む (Status = 2) の VLF もログレコードが書き込める (空きがある) のであれば利用されます。

ログの切り捨て時 (再利用のために解放) には、[MinLSN] (最小復旧 LSN：データベース全体をロールバックするために必要となる最初の LSN) が切り捨て可能なスタート地点となります。
この、MinLSN から、最後に書き込まれたログまでを [アクティブなログ] と呼び、このアクティブなログが含まれている仮想ログに関しては、データベースの回復に必要となるため、再利用することはできません。
# MinLSN が実際に見れれば説明がしやすかったのですが、ちょっと取得方法がわかりませんでした。

この Status = 0 の状態の VLF ですが、[DBCC SHRINKFILE] を実行した際に、縮小される単位になります。
VLF はログファイルを作成 (あるいは拡張) したタイミングでファイルサイズとログの個数が決まりますので、使用している VLF の状態によっては、SHRINKFILE をしても思ったよりファイルが小さくならないことがあります。

セミナーではログ管理をするにあたって、このようなログの基本的な動作についてのお話を聞くことができました。
# 基本的に振り返りの内容は、私が間違って理解している個所があるかもしれませんので、間違っていた場合はセミナーの内容ではなく私の理解力不足です…。あと、今回の内容をすべてお話しいただいたのではなく、調べる取りかかりの情報をいただけた形になります。

他にも SQL Server のログ管理 (バックアップ) で重要となる [復旧モデル] についてもお話しがありました。

次の投稿では、この復旧モデルについて振り返ってみたいと思います。