Share via

SQL Server VSS Writer 記錄

  • 發行項

適用於：SQL Server

SQL Server 可透過專用的 SQL 寫入器服務，參與 VSS (磁碟區陰影複製服務) 的備份和還原作業。 如需詳細資訊，請參閱 SQL Server 備份應用程式 - 磁碟區陰影複製服務 (VSS) 和 SQL 寫入器。

此服務會將執行錯誤回報給 Windows 應用程式事件記錄檔，其中包含 SQLWRITER 值的 Source 事件 (若為 PowerShell 或 XML 內容，則為 ProviderName)，如本文稍後的範例所述。 SQL Server 2019 (15.x) 以前沒有專屬活動記錄，因此很難以 VSS 作業參與者的身分調查 SQL Server。

本文說明 SQL Server 2019 (15.x) 推出的全新記錄功能，可針對其 SQLWriter 作業提供更佳可見性。 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 中進行。
    • 只有一個換用檔案，因此第二個換用檔案會覆寫現有的 SqlWriterLogger1.txt。
    • 參數由 SqlWriterConfig.ini 檔案管理

由於 SQL 寫入器是 SQL Server 的共用元件，因此在系統上具備單一執行個體，且主要版本會與任何已安裝 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 寫入器二進位檔。

注意

下列段落說明用 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 事件
  • Microsoft Azure備份事件
  • 還原的事件

換言之，就算這些作業成功執行，記錄檔仍會記錄詳細的內容。 您可確認 VSS 作業正在進行並成功與 SQL 寫入器互動。 這項改善提供簡易的內建功能，可在 SQL Server 執行個體等級建立這些詳細資料。

此外，系統也會記錄 SQLWriter 服務啟動事件，同時回報作用中的記錄參數。

如果 VSS 作業失敗涉及 SQL Server，則 SqlWriterLogger 會成為檢查資訊的關鍵位置。

注意

這項新版記錄基礎結構的目的，在於補充 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 寫入器服務時，系統都會觀察上述項目 (甚至會於服務啟動時記錄兩次)。

依照顯示的順序，我們能發現下列資訊：

  • 依當地伺服器時間顯示的時間戳記 (日期 + 時間)，以及每行輸入的原始 ThreadId。
  • 啟動的 SQLWriter 流程 ProcessId。
  • 服務以 'normal' 模式 ('not running as WIDWriter') 或 Windows Internal Database 啟動的事實。
  • SQL 寫入器二進位檔案的版本。
  • SqlWriterConfig.ini 檔案設定的所有參數：
    • 作用中記錄檔的目標路徑
    • 追蹤的詳細資料等級，此範例顯示為 DEFAULT
    • 變換發生前檔案的大小上限，此範例為 1 MB
    • 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 執行個體的清單，加上其執行個體的名稱、主要版本和 Edition。
  • 我們未嘗試列出「使用者執行個體」的指示；這是 SQL Server 的特定功能，別名 LocalDB，通常不會涉及企業資料庫伺服器。

成功的元件模式的 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 區段，我們已指出這常常會產生備份。
  • 提及備份每次主要的 VSS 階段，其模式為「Entering SQL Writer xxxx」。
    • 此處的第一句為Entering SQL Writer OnPrepareBackup。
  • 用顯眼的項目指出 VSS SQL Microsoft Azure 備份已啟動
    • (其識別碼為記錄 SQLWriter 中備份嘗試的 ThreadId)
  • VSS 要求者選取的 VSS 備份 API，包括「元件」或「非元件/磁碟區」
  • VSS 要求者傳送元件清單中涵蓋的資料庫計數，此處為單一資料庫 (1)。
  • 確認每個要求者提供的資料庫名稱 (此處為 'db_on_G') 已在 SQL Server 執行個體上找到 (或找不到)，此執行個體已由 VSS 要求者建立關聯 (此處為預設執行個體 'GF19')。
  • VSS 備份要求的 Flavor。 通常不是 VSS_BT_FULL 就是 VSS_BT_COPY。 請參閱 VSS_BACKUP_TYPE 的列舉。
  • 另一OnIdentify 區段
  • 更多辨識 VSS Microsoft Azure備份主要階段的項目 (OnFreeze、OnThaw、OnPostSnapshot)
  • 最後的 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 會管理 'components’，這在 SQL Server 內容中為 'databases')。

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 備份要求)。 故此，任何針對 VSS 錯誤並涉及 SQL Server 的調查，都應收集並檢閱這兩個來源。

修改 SQL 寫入器紀錄參數

SQL 寫入器記錄可藉由編輯 SqlWriterConfig.ini 文字檔進行設定。 該檔案本身包含可用參數的快速內嵌描述，這部分會於下方詳述。

注意

.ini 檔案位於 Windows-Protected 資料夾下 (Program Files)。 因此需要較高的管理員權限才能編輯。 在總管中按兩下會在權限未提高的狀況下開啟記事本：這能讓使用者讀取內容，但試圖儲存變更時則會失敗。 您可以管理員身分啟動記事本並開啟 SqlWriterConfig.ini，或使用文字編輯器，後者會在儲存檔案時提示您視需求提高權限。

在此複製 SqlWriterConfig.ini 檔案註解：

參數 選項 Description
EnableLogging - TRUE (預設)
- 錯誤		 允許使用者停用整個新的記錄功能 (此情況可能不多見)。
TraceFile C:\Program Files\Microsoft SQL Server\90\Shared\SqlWriterLog.txt 允許使用者變更追蹤檔案的路徑和檔案名稱。 我們不建議將之變更為預設，因為較常見的位置可讓您在 SQL Server 上迅速前往正確的位置。
TraceLevel - DEFAULT (預設)
- 最小化
- 詳細資訊		 記錄的詳細程度。 詳細資訊請參閱 TraceLevel　細節。
TraceFileSizeMb 1 MB (預設) 滑鼠指向效果前的檔案大小上限。 .txt 檔案會用針對每個字元採用 UTF-8 編碼並取用 2 位元組。 以下情境可以增加這個值：針對密集的 VSS 活動、保留長時間記錄項目，或長時間啟用非預設的 TraceLevel 值的時候。 預設的 1 MB 值應在多數情況下提供豐富的歷程記錄。
ForceFlush - 正確
- 錯誤 (預設)		 將此選項設定為 TRUE 只適用於非常罕見的狀況，因為這會導致 SQL 寫入器服務在有機會排清最後的記錄項目之前損毀。請盡可能保持預設值。

套用變更

針對設定的任何變更都需要重新啟動 SQL 寫入器服務才能生效。

提示

重新啟動 SQL 寫入器非常快速且可隨時進行，因為 SQL 寫入器不會保留任何具狀態資訊，在 VSS 呼叫之間也不具備任何活動。 唯一要注意的是，請避免在 VSS 作業 (備份、還原) 期間重新啟動。

SQL 寫入器會在啟動 (或重新啟動) 時於記錄檔中報告作用中的參數，如服務啟動範例擷取所示。

TraceLevel 的詳細資料

SqlWriterConfig.ini 檔案列出下列等級：

層級 詳細資料
DEFAULT 預設的詳細程度參數應已足以應付多數需求：請參閱檢閱一般記錄項目一節，觀察預設已經產生的項目。 除了錯誤，成功的 VSS 呼叫與 VSS 中繼資料，系統都會預設記錄。
MINIMAL 這個等級會保留 DEFAULT 模式的格式及其事件。 也會在程式碼的許多關鍵位置產生輸出。 最出色的是，系統會記錄 SQLWriter 邏輯中常見部分的所有檔案和資料庫反覆項目。 這能大幅增加增加每項 VSS 作業 (包括例行性 OnIdentify 事件) 記錄的項目數量，對於主控大量資料庫的執行個體尤其如此：每個資料庫的每個實體檔案，在 VSS 備份期間都可能受系統報告一次以上。 這個等級只能在失敗時，幫忙針對 SQL 寫入器邏輯給予更精確的邏輯位置。 另外也能用於探索。 這個等級不適合在暫時調查以外的時機保持作用，因為詳細資料的等級會大幅降低預設 1 MB 檔案大小的歷程記錄深度。 提升 TraceFileSizeMb 的值可能較為相關。
VERBOSE 目前此等級會報告與 MINIMAL 相同的事件，但為每個項目加上原始程式碼物件和方法描述項前置詞。 這會導致輸出更廣泛 (大小超過 Minimal) 並降低可讀性。 多餘的資訊無法用於與 Microsoft 支援服務以外的互動。 與 MINIMAL 相同的註解較適用：長時間保持此等級作用會大幅降低預設 1 MB 檔案大小的歷程記錄深度，提升 TraceFileSizeMb 的值可能較為相關。

MINIMAL 和 VERBOSE 等級不會在失敗時提供額外錯誤詳細資料，只會針對每個與 SQL 寫入器活動有關之低等級作業提供其他進度詳細資料。

下一步