SQL Server VSS Writer のログ記録

適用対象:SQL Server

SQL Serverは、専用の SQL ライター サービスを使用して VSS (ボリューム シャドウ コピー サービス) のバックアップ操作と復元操作に関与できます。 詳細については、「SQL Server アプリケーションのバックアップ - ボリューム シャドウ コピー サービス (VSS) と SQL ライター」を参照してください。

このサービスは、この記事の後半ので説明するように、値 のイベント Source (または PowerShell または ProviderName XML コンテキスト) SQLWRITERを使用して Windows アプリケーション イベント ログに実行エラーを報告します。 2019 (15.x) SQL Server以前は、専用のアクティビティ ログが存在せず、VSS 操作の参加者としてSQL Serverに対する調査が困難になりました。

この記事では、SQLWriter 操作の可視性を高めるために SQL Server 2019 (15.x) で導入された新しいログについて説明します。 この機能は、SQL Server 2016 (13.x) Service Pack 3 および SQL Server 2017 (14.x) 累積更新プログラム (CU) 27 でも使用できるようになりました。

概要

SQL Server 2019 (15.x) SQLWriter ログの主な特性は次のとおりです。

  • 既定でオンになる
  • システム全体である (サーバー上で実行されているすべての SQL Server インスタンスに対する SQL ライター アクティビティをトレースする)
  • テキストベースである
  • 作業ディレクトリは C:\Program Files\Microsoft SQL Server\90\Shared である
  • そのディレクトリ内:
    • ログ記録は SqlWriterLogger.txt ファイルで行われる
    • このファイルの名前は、最大サイズ (既定では 1 MB) に達したときに SqlWriterLogger1.txt に変更され、メインの SqlWriterLogger.txt でログ記録が続行されます。
    • ロールオーバー ファイルは 1 つだけなので、2 回目のロールオーバーによって既存の SqlWriterLogger1.txt が上書きされます。
    • パラメーターは SqlWriterConfig.ini ファイルによって管理される

SQL ライターはSQL Server共有コンポーネントであるため、システム上に 1 つのインスタンスがあり、そのメジャー バージョンは、インストールされている SQL Server インスタンスの最上位メジャー バージョンと同じになります。 たとえば、SQL Server 2016 (13.x) SP2 と SQL Server 2019 (15.x) が同じシステムにインストールされている場合、SQL ライター バイナリは、SQL Server 2019 (15.x) によって提供されるバイナリになり、すべてのメジャー バージョン (ホーム ディレクトリが の下\90に残っている場合でも) のすべての実行中のインスタンスにサービスを提供します。 ローカル インスタンスおよびバージョンでは、ここで説明する新しい SQL Server 2019 (15.x) トレースを利用できます。 また、この状況では SQL Server 2019 (15.x) の累積的な更新プログラムによってのみ SQL ライター バイナリがアップグレードされることを意味します。

Note

次の段落では、SQL Server 2019 (15.x) CU 4 以降の状況について説明します。 以前のSQL Server 2019 (15.x) バージョンでは、既定の設定では、ログ ファイルに同じ量の情報は含まれません。

基本操作

手動で変更することなく、新しいログ記録を利用できます。 C:\Program Files\Microsoft SQL Server\90\Shared\ のメイン SqlWriterLogger.txt ログ ファイルを開くことも、そのコピーを取得することもできます。 ファイルには、主に次のような、SQL ライターに到達するすべての VSS イベントが反映されます。

  • コマンド vssadmin list writers によってトリガーされる OnIdentify イベント
  • バックアップ イベント
  • 復元イベント

つまり、これらの操作が正常に実行された場合でも、ログ ファイルには詳細なエントリが記録されます。 VSS 操作が発生し、SQL ライターと正常に対話していることを確認できます。 これは、インスタンス レベルでこれらの詳細を確立するための簡単な組み込み方法SQL Server提供する改善です。

さらに、SQLWriter サービスのスタートアップ イベントも記録され、アクティブなログ パラメーターが報告されます。

VSS 操作の失敗にSQL Serverが含まれる場合、SqlWriterLogger は情報を確認するための重要な場所になります。

Note

この新しいログ記録インフラストラクチャは、SQL Serverの既存のエラー報告を補完します。これは置き換えられません。 そのため、エラーが発生した場合は、Windows アプリケーション イベント ログ が最初に確認されます ("SQLWRITER" や "VSS" などのソースでフィルター処理)。 SqlWriterLogger.txt は、この初期セットに追加情報を提供します。

一般的なログ エントリの確認

既定の設定で次のエクスポートが行われています。

サービスの開始

[01/11/2021 02:54:59, TID 61f8] ****************************************************************
[01/11/2021 02:54:59, TID 61f8] **  SQLWRITER TRACING STARTED - ProcessId: 0x4124
[01/11/2021 02:54:59, TID 61f8] **  Service is not running as WIDWriter.
[01/11/2021 02:54:59, TID 61f8] **  SQL Writer version is 15.0.4073.23
[01/11/2021 02:54:59, TID 61f8] **  MODERN LOGGER V2 ENABLED ON C:\Program Files\Microsoft SQL Server\90\Shared\SqlWriterLogger.txt
[01/11/2021 02:54:59, TID 61f8] **  With TraceLevel = DEFAULT, TraceFileSizeMb = 1, ForceFlush = False
[01/11/2021 02:54:59, TID 61f8] **  Recording events in Server Local Time. UTC OFFSET: -8:00
[01/11/2021 02:54:59, TID 61f8] ****************************************************************

上記のエントリは、SQL ライター サービスの開始ごとに観察されます (サービスの開始ごとに 2 回ログに記録される場合もあります)。

外観順に、次の情報を確認できます。

  • ローカル サーバー時刻のタイム スタンプ (日付 + 時刻)、および各行のエントリを生成する ThreadId。
  • 開始中の SQLWriter プロセスの ProcessId。
  • サービスが "通常" モード (WIDWriter として実行されていない) またはWindows Internal Database モードで開始されたという事実。
  • SQL ライター バイナリのバージョン。
  • ファイルによって SqlWriterConfig.ini 設定されたすべてのパラメーター:
    • アクティブ ログ ファイルのターゲット パス
    • トレースの詳細レベル (この例では DEFAULT)
    • ロールオーバーが行われる前のファイルの最大サイズ (この例では 1 MB)
    • ログ ファイルに対する 1 回の更新ごとに ForceFlush を実行するオプションと、より緩やかな、バッファーに格納された方法 (既定では False) を指定します。
  • ローカル時刻の UTC オフセットと共に、ローカル時刻をログに記録することの通知。

VSS 'OnIdentify' イベント

[01/12/2021 08:23:40, TID 464c] Entering SQL Writer OnIdentify.
[01/12/2021 08:23:40, TID 464c] Service: MSSQLSERVER Server: GF19. Version=15
[01/12/2021 08:23:40, TID 464c] Instance MSSQL15.MSSQLSERVER Edition: Developer Edition
[01/12/2021 08:23:40, TID 464c] Instance MSSQL15.NAMED1 Edition: Enterprise Edition: Core-based Licensing
[01/12/2021 08:23:40, TID 464c] Skip User Instances Enumeration

OnIdentify は一般的な VSS 操作です。 これは vssadmin list writers コマンドによってトリガーされます。 ほとんどの VSS 要求元は、OnIdentify イベントを使用して VSS のバックアップまたは復元操作を開始します。

これまで、DBA はアクティブなプロファイラー トレースのみでこのようなイベントを検出できました。 新しいログ記録機能を使用すると、各イベントにより上記のエントリが発生するようになります。

表示順に、次の情報がログに記録されているのがわかります。

  • OnIdentify VSS イベントの明示的な言及。
  • アクティブな (実行中の) すべての SQL Server インスタンスと、それらのインスタンスの名前、メジャー バージョン、およびエディションの一覧。
  • "ユーザー インスタンス" を一覧表示しようとしなかったことを示しています。これは、LocalDB とも呼ばれる特定のSQL Server機能であり、通常はエンタープライズ データベース サーバーには関係しません。

コンポーネント モード VSS バックアップの成功

[01/11/2021 02:30:19, TID 32c8] Entering SQL Writer Initialize.
[01/11/2021 02:33:33, TID 232c] Entering SQL Writer OnIdentify.
[01/11/2021 02:33:33, TID 232c] Service: MSSQLSERVER Server: GF19. Version=15
[01/11/2021 02:33:33, TID 232c] Instance MSSQL15.MSSQLSERVER Edition: Developer Edition
[01/11/2021 02:33:33, TID 232c] Instance MSSQL15.NAMED1 Edition: Enterprise Edition: Core-based Licensing
[01/11/2021 02:33:33, TID 232c] Skip User Instances Enumeration
[01/11/2021 02:33:37, TID 232c] Entering SQL Writer OnPrepareBackup.
[01/11/2021 02:33:37, TID 232c] ****************************************************************
[01/11/2021 02:33:37, TID 232c] **  VSS SQL BACKUP BEGIN - ID: 232c
[01/11/2021 02:33:37, TID 232c] ****************************************************************
[01/11/2021 02:33:37, TID 232c] Component based backup selected.
[01/11/2021 02:33:37, TID 232c] Database count from metadata is 1
[01/11/2021 02:33:37, TID 232c] Database db_on_G on instance GF19 found in metadata
[01/11/2021 02:33:37, TID 232c] Backup type is VSS_BT_COPY
[01/11/2021 02:33:38, TID 232c] Entering SQL Writer OnPrepareSnapshot.
[01/11/2021 02:33:38, TID 232c] Service: MSSQLSERVER Server: GF19. Version=15
[01/11/2021 02:33:38, TID 232c] Instance MSSQL15.MSSQLSERVER Edition: Developer Edition
[01/11/2021 02:33:38, TID 232c] Instance MSSQL15.NAMED1 Edition: Enterprise Edition: Core-based Licensing
[01/11/2021 02:33:38, TID 232c] Skip User Instances Enumeration
[01/11/2021 02:33:38, TID 232c] Entering SQL Writer OnFreeze.
[01/11/2021 02:33:38, TID 232c] Entering SQL Writer OnThaw.
[01/11/2021 02:33:38, TID 232c] Entering SQL Writer OnPostSnapshot.
[01/11/2021 02:33:38, TID 232c] Entering SQL Writer OnIdentify.
[01/11/2021 02:33:38, TID 232c] Service: MSSQLSERVER Server: GF19. Version=15
[01/11/2021 02:33:38, TID 232c] Instance MSSQL15.MSSQLSERVER Edition: Developer Edition
[01/11/2021 02:33:38, TID 232c] Instance MSSQL15.NAMED1 Edition: Enterprise Edition: Core-based Licensing
[01/11/2021 02:33:38, TID 232c] Skip User Instances Enumeration
[01/11/2021 02:33:40, TID 232c] Entering SQL Writer OnBackupComplete.

このイベントによって、さらにかなり多くのエントリのセットが発生します。 外観順に、次の情報を確認できます。

  • 既述のとおり、完全な OnIdentify セクションにより、多くの場合、バックアップが発生します。
  • "SQL Writer xxxx の入力" パターンを使用して、バックアップのすべての主要な VSS フェーズについて説明します。
    • ここでは、Entering SQL Writer OnPrepareBackup が最初のものです。
  • VSS SQL バックアップの開始を示す明確なエントリ
    • (ID は、SQLWriter でそのバックアップ試行のログ記録を実行している ThreadId です)
  • VSS リクエスタ、"コンポーネント"、または "非コンポーネント/ボリューム" によって選択された VSS バックアップ API
  • VSS リクエスタによって送信されたコンポーネントリストに含まれるデータベースの数(ここでは単一の DB (1)。
  • VSS リクエスタによって関連付けられているSQL Server インスタンス (ここでは既定のインスタンス 'GF19') で、Requestor が指定した各データベース名 (ここで 'db_on_G') が見つかった (または見つからない) ことを確認します。
  • 要求された VSS バックアップのフレーバー。 通常は VSS_BT_FULL または VSS_BT_COPY です。 VSS_BACKUP_TYPE 列挙を参照してください。
  • 別の OnIdentify セクション
  • VSS バックアップの主なフェーズを特定するその他のエントリ (OnFreezeOnThawOnPostSnapshot)
  • 最後の OnIdentify セクション。
  • 最後の VSS フェーズ レポート。このレポートの名前は、有用な "終了イベント" になります。 OnBackupComplete

これらのエントリは、以前は迅速に確立することが困難だった VSS 操作の詳細を提供し、そのためには高度なトレースが必要でした。 主な例は、VSS バックアップ要求の "コンポーネント" または "非コンポーネント" モードです。 SQL Server 2019 (15.x) SQL ライターを使用すると、既定でそれぞれの VSS 要求についてログに記録され、簡単にアクセスできます。

障害の状況: 破損したデータベース

SQL ライター ログがイベント ログ アーキテクチャを補完するという前述のステートメントを示すために、既知のエラー状況 (破損したデータベース) に関連付けられているエントリを見てみましょう。 このシナリオは、VSS バックアップが、特定のデータベースのファイルの一部のセットのみを含むボリュームのスナップショット セットを作成しようとしたときに発生する可能性があります。 SQL ライターにより、VSS 規則に従ってブロックされます。

これは、操作の SqlWriterLogger.txt の内容を抜粋したものです。

[01/11/2021 02:57:00, TID 5a88] Entering SQL Writer OnIdentify.
[01/11/2021 02:57:00, TID 5a88] Service: MSSQLSERVER Server: GF19. Version=15
[01/11/2021 02:57:00, TID 5a88] Instance MSSQL15.MSSQLSERVER Edition: Developer Edition
[01/11/2021 02:57:00, TID 5a88] Instance MSSQL15.NAMED1 Edition: Enterprise Edition: Core-based Licensing
[01/11/2021 02:57:00, TID 5a88] Skip User Instances Enumeration
[01/11/2021 02:57:02, TID 5a88] Entering SQL Writer OnPrepareBackup.
[01/11/2021 02:57:02, TID 5a88] ****************************************************************
[01/11/2021 02:57:02, TID 5a88] **  VSS SQL BACKUP BEGIN - ID: 5a88
[01/11/2021 02:57:02, TID 5a88] ****************************************************************
[01/11/2021 02:57:02, TID 5a88] Volume based (= NonComponent) backup selected.
[01/11/2021 02:57:02, TID 5a88] Backup type is VSS_BT_FULL
[01/11/2021 02:57:03, TID 5a88] Entering SQL Writer OnPrepareSnapshot.
[01/11/2021 02:57:03, TID 5a88] Service: MSSQLSERVER Server: GF19. Version=15
[01/11/2021 02:57:03, TID 5a88] Instance MSSQL15.MSSQLSERVER Edition: Developer Edition
[01/11/2021 02:57:03, TID 5a88] Instance MSSQL15.NAMED1 Edition: Enterprise Edition: Core-based Licensing
[01/11/2021 02:57:03, TID 5a88] Skip User Instances Enumeration
[01/11/2021 02:57:03, TID 5a88] HRESULT EXCEPTION CAUGHT: hr: 0x80780002
[01/11/2021 02:57:03, TID 5a88] Entering SQL Writer OnAbort.

エラー SqlWriterLogger.txt が発生したことがわかりますが、エラーに関する詳細は 0x80780002 HResultだけです。 この値は、エラー コードを参照しないと解釈するのが困難です。 ただし 引き裂かれたデータベースの状況を特定します。

イベント ログを表示する

次に、Windows アプリケーション イベント ログの内容を確認してみましょう。

Log Name:      Application
Source:        SQLWRITER
Date:          1/11/2021 02:57:03 AM
Event ID:      24579
Task Category: None
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      GF19
Description:
Sqllib error: Database db_on_G_and_H of SQL Server instance GF19  is stored on multiple volumes, only some of which are being shadowed.

イベントにより、状況を説明する完全なユーザーフレンドリな形式のメッセージが提供されます。

OS VSS フレームワークは、イベント ログの問題も報告します。この問題は、その命名法を使用して報告されます (VSS は、SQL Serverのコンテキストで "データベース" である "コンポーネント" を管理します)。

Log Name:      Application
Source:        VSS
Date:          1/11/2021 02:57:03 AM
Event ID:      8229
Task Category: None
Level:         Warning
Keywords:      Classic
User:          N/A
Computer:      GF19
Description:
A VSS writer has rejected an event with error 0x800423f0, The shadow-copy set only
 contains only a subset of the volumes needed to correctly backup the selected
components of the writer.
Changes that the writer made to the writer components while handling the event will
 not be available to the requester.
Check the event log for related events from the application hosting the VSS writer.

Operation:
   PrepareForSnapshot Event

Context:
   Execution Context: Writer
   Writer Class Id: {a65faa63-5ea8-4ebc-9dbd-a0c4db26912a}
   Writer Name: SqlServerWriter
   Writer Instance Name: Microsoft SQL Server 2019:SQLWriter
   Writer Instance ID: {a16fed29-e555-4cc5-8938-c89201f31f7e}
   Command Line: "C:\Program Files\Microsoft SQL Server\90\Shared\sqlwriter.exe"
   Process ID: 22628

イベント ログは、エラー自体に関するより優れた情報源です。 しかし、SqlWriterLogger の内容には、バックアップ要求 (VSS_BT_FULL。SQL ライターの OnPrepareSnapshot フェーズ中に失敗した非コンポーネント VSS バックアップ要求) の詳細が示されます。 そのため、SQL Server に関連する VSS エラーの調査では、''両方'' のソースを収集して確認する必要があります。

SQL ライターのログ パラメーターを変更する

SQL ライターのログ記録は、SqlWriterConfig.ini テキスト ファイルを編集することによって構成できます。 ファイル自体には、使用可能なパラメーターの簡単なインライン説明が含まれています。これについては、以下で確認します。

Note

.ini ファイルは Windows によって保護されているフォルダー (Program Files) の下にあります。 そのため、編集するには昇格された管理者特権が必要です。 エクスプローラー内をダブルクリックすると、昇格なしでメモ帳が開きます。これにより、ユーザーは内容を読み取ることができますが、変更を保存しようとすると失敗します。 管理者としてメモ帳を起動し、 を開 SqlWriterConfig.iniくか、ファイルを保存するときに必要に応じて昇格を求めるテキスト エディターを使用します。

ここで SqlWriterConfig.ini ファイルのコメントを複製します。

パラメーター オプション 説明
EnableLogging - TRUE (既定値)
-False
ユーザーが新しいログ記録機能全体を無効にできるようにします(万一必要な場合)。
TraceFile C:\Program Files\Microsoft SQL Server\90\Shared\SqlWriterLog.txt ユーザーがトレース ファイルのパスとファイル名を変更できるようにします。 既定の既知の場所として変更し、任意の SQL Server 上の適切な場所に直接簡単に移動できるようにすることは推奨されません。
TraceLevel - DEFAULT (既定値)
-最小限
-詳細
ログ記録の詳細度。 詳細については、「 TraceLevel の詳細」を参照してください
TraceFileSizeMb 1 MB (既定値) ロールオーバー前の最大ファイル サイズ。 .txt ファイルでは UTF-8 エンコードが使用され、1 文字あたり 2 バイトが消費されます。 この値を増やすことは有効です。たとえば、VSS アクティビティが激しく、ログ エントリの期間が長い場合や、既定値 TraceLevel 以外の値が長期間有効になっている場合などです。 既定の 1 MB の値は、ほとんどの状況で十分な履歴を提供する必要があります。
ForceFlush -True
- FALSE (既定値)
このオプションを に TRUE 設定すると、SQL ライター サービスが最後のログ エントリをフラッシュする前にクラッシュするまれな状況でのみ役立ちます。それ以外の場合は既定値のままにします。

変更を適用する

設定を変更する場合は、アクティブ化するために SQL ライター サービスを再起動する必要があります。

ヒント

SQL ライターの再起動は非常に高速であり、SQL ライターはステートフルな情報を保持せず、VSS 呼び出しの間にアクティビティも行わないので、すぐに実行できます。 唯一の予防措置は、VSS 操作 (バックアップ、復元) の実行中に再起動を避けることです。

SQL ライターにより、「サービスの開始」サンプルの抜粋に示されているように、(再) 起動時にそのログ ファイルでアクティブなパラメーターが報告されます。

TraceLevel の詳細

ファイルには SqlWriterConfig.ini 、次のレベルが一覧表示されます。

Level 詳細
DEFAULT 既定の詳細度パラメーターは、ほとんどのニーズに適している必要があります。既定で既に生成されているものを確認するには、「 一般的なログ エントリの確認 」セクションを参照してください。 エラーに加え、VSS の正常な呼び出しと VSS メタデータが既定でログに記録されます。
MINIMAL このレベルでは、モードとそのイベントの DEFAULT 書式設定が維持されます。 また、コードの多くの重要な場所に出力が生成されます。 中でも注目すべきは、SQLWriter ロジックで一般的なすべてのファイルとデータベース イテレーションがログに記録されることです。 特に多数のデータベースをホストしているインスタンスでは、各 VSS 操作 (日常の OnIdentify イベントを含む) についてログに記録されるエントリの数を増やすことができます。すべての単一データベースのそれぞれの物理ファイルが、VSS バックアップの過程で複数回報告される場合があります。 このレベルは、障害発生時の SQL ライター ロジックの論理的な位置をより正確に把握するためにのみ役立ちます。 また、探索目的にも便利です。 詳細レベルによって既定の 1 MB ファイル サイズの履歴の深さが大幅に減少するため、一時的な調査を超えてアクティブな状態に保つことは役に立ちません。 TraceFileSizeMb 値を増やすことに関連する可能性があります。
VERBOSE 現在、このレベルでは と同じイベント MINIMALが報告されますが、各エントリの前にソース コード オブジェクトとメソッド記述子が付けられます。 これにより、出力の幅が広くなり (サイズが最小よりも大きくなる)、読みにくくなります。 追加された情報は、Microsoft サポート サービスとのやり取り以外では役に立ちません。 MINIMAL と同じことが当てはまります。このレベルを長時間アクティブにしておくと、既定の 1 MB ファイル サイズの履歴の深さが大幅に減少し、TraceFileSizeMb 値を増やすことに関連する可能性があります。

MINIMAL および VERBOSE レベルでは、エラーが発生した場合の 追加のエラー の詳細は提供されません。SQL ライター アクティビティに関連する低レベルの各操作に対して追加の 進行状況 の詳細のみが提供されます。

次のステップ