SQL Server VSS 编写器日志记录

适用于：SQL Server

SQL Server 可以通过其专用 SQL 编写器服务参与 VSS（卷影复制服务）备份和还原操作。 有关详细信息，请参阅 SQL Server 备份应用程序 - 卷影复制服务 (VSS) 和 SQL 编写器。

该服务将使用值为 SQLWRITER 的事件 Source（或 PowerShell 或 XML 上下文中的 ProviderName）向 Windows 应用程序事件日志报告执行错误，如本文后面的示例中所示。 在 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 事件，其中主要是：

• OnIdentify 事件，这些事件由 vssadmin list writers 命令触发
• 备份事件
• 还原事件

也就是说，即使这些操作成功完成，日志文件仍会记录详细的条目。 你可以确认 VSS 操作正在进行并成功与 SQL 编写器交互。 这是一项改进功能，它提供了一种简单的内置方法，在 SQL Server 实例级别建立这些详细信息。

此外，系统还将记录 SQLWriter 服务启动事件，并报告活动日志记录参数。

如果有一个涉及 SQL Server 的 VSS 操作失败，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。
• 服务以“正常”模式（“不以 WIDWriter 身份运行”）或“Windows 内部数据库”模式启动。
• 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 实例的列表，以及它们的实例名称、主版本和版本类别。
• 指明我们未尝试列出“用户实例”，这是一种特定的 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 阶段，模式为“正在进入 SQL 编写器 xxxx”。
  • 这里，第一个为 Entering SQL Writer OnPrepareBackup。
• 一个指示 VSS SQL 备份启动的明显条目
  • （ID 是正在为 SQLWriter 中的该备份尝试进行日志记录的 ThreadId）
• VSS 请求程序选择的 VSS 备份 API，“组件”或“非组件/卷”
• VSS 请求程序发送的组件列表中包含的数据库计数，此处为单个 DB (1)。
• 一个确认信息，确认已在 SQL Server 实例上找到（或未找到）每个请求程序提供的数据库名称（此处为“db_on_G”），该实例已由 VSS 请求程序（此处为默认实例“GF19”）关联。
• 请求的 VSS 备份类型。 通常为 VSS_BT_FULL 或 VSS_BT_COPY。 请参阅 VSS_BACKUP_TYPE 枚举。
• 另一个 OnIdentify 部分
• 用于标识 VSS 备份的主要阶段的更多条目（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 管理“组件”，在 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 内容提供了有关备份请求（在 SQL 编写器的 OnPrepareSnapshot 阶段失败的非组件 VSS 备份请求 VSS_BT_FULL）的详细信息。 因此，对涉及 SQL Server 的 VSS 错误的任何调查都应收集和查看这两个源。

修改 SQL 编写器日志记录参数

通过编辑 SqlWriterConfig.ini 文本文件，可以配置 SQL 编写器日志记录。 文件本身包含了对可用参数的快速内联说明，我们将在下面进行介绍。

注意

该 .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（默认值） - MINIMAL - VERBOSE	日志记录的详细程度。 详细信息位于 TraceLevel 详细信息中。
TraceFileSizeMb	1 MB（默认值）	滚动更新前的最大文件大小。 .txt 文件使用 UTF-8 编码，每个字符占用 2 个字节。 增加此值对于 VSS 活动频繁、长时间保留日志条目，或者长时间启用非默认 TraceLevel 值的情况是有效的。 在大多数情况下，默认的 1MB 值应该可以提供足够的历史记录。
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 编写器逻辑的逻辑位置。 它也便于浏览。 除了暂时的调查外，使其保持活动状态并不是很有用，因为详细信息级别会大大降低默认的 1MB 文件大小的历史记录深度。 增大 TraceFileSizeMb 值可能会有用。
VERBOSE	目前，此级别与 MINIMAL 报告的事件相同，但会在每个条目前面加上源代码对象和方法描述符。 这会使输出更宽（大小比 MINIMAL 大），可读性更差。 除了与 Microsoft 支持服务进行交互之外，添加的信息将不会有用。 它适用与 MINIMAL 相同的注释：长时间保持此级别的活动状态将大大降低默认 1MB 文件大小的历史记录深度，增大 TraceFileSizeMb 值可能会有用。

MINIMAL 和 VERBOSE 级别不会在发生失败时提供额外的错误详细信息，而是只提供与 SQL 编写器活动相关的每个低级别操作的额外进度详细信息。

后续步骤

• SQL Server 备份应用程序 - 卷影复制服务 (VSS) 和 SQL 编写器
• BACKUP (Transact-SQL)
• RESTORE (Transact-SQL)
• SQL Server 数据库的备份和还原
• SQL Server 事务日志体系结构和管理指南