Ведение журнала модуля записи VSS SQL Server

  • Статья

Применимо к:SQL Server

SQL Server может участвовать в операциях резервного копирования и восстановления VSS (служба теневого копирования томов) с помощью выделенной службы записи SQL. Дополнительные сведения см. в статьях SQL Server Back up Applications — Служба теневого копирования томов (VSS) и средство записи SQL.

Служба сообщит об ошибках выполнения в журналы событий приложения Windows с событием Source (или ProviderName в контексте PowerShell или XML), SQLWRITERкак показано в примере ниже в этой статье. До SQL Server 2019 (15.x) не было выделенного журнала действий, что привело к расследованию SQL Server в качестве участника операций VSS.

В этой статье описывается новый журнал, представленный SQL Server 2019 (15.x), чтобы повысить видимость операций SQLWriter. Эта функция также была доступна в SQL Server 2016 (13.x) с пакетом обновления 3 и накопительным пакетом обновления (CU) SQL Server 2017 (14.x).

Обзор

Основные характеристики ведения журнала SQL Server 2019 (15.x) SQLWriter:

  • Включено по умолчанию.
  • Выполняется на уровне системы, то есть позволят отслеживать действия модуля записи SQL по всем экземплярам SQL Server в пределах одного сервера.
  • Выполняется в текстовом формате.
  • Использует рабочий каталог C:\Program Files\Microsoft SQL Server\90\Shared.
  • В этом каталоге:
    • Журнал сохраняется в файл SqlWriterLogger.txt.
    • При достижении предельного размера (по умолчанию это 1 МБ) этот файл переименовывается в SqlWriterLogger1.txt. Запись продолжается в новый основной файл SqlWriterLogger.txt.
    • Используется только один файл продолжения, то есть следующий файл будет записан поверх существующего SqlWriterLogger1.txt.
    • За параметры процесса отвечает файл SqlWriterConfig.ini.

Так как модуль записи SQL является общим компонентом SQL Server, он имеет один экземпляр в системе, и его основная версия будет совпадать с самой высокой основной версией любого установленного экземпляра SQL Server. Например, если SQL Server 2016 (13.x) с пакетом обновления 2 (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) не будут иметь одинаковый объем сведений в файле журнала в параметрах по умолчанию.

Базовые операции

Чтобы использовать возможность нового ведения журнала, не требуется никаких изменений вручную. Вы можете открыть или скопировать основной файл журнала SqlWriterLogger.txt с помощью C:\Program Files\Microsoft SQL Server\90\Shared\. Этот файл будет содержать все события VSS, которые достигли модуля записи SQL, по большей части следующие:

  • события OnIdentify, активированные командой vssadmin list writers;
  • события резервного копирования;
  • события восстановления.

То есть, даже если эти операции выполняются успешно, файл журнала по-прежнему записывает подробные записи. Вы можете подтвердить, что операции 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, отправляющая запись для каждой строки.
  • Запущен процесс ProcessId процесса SQLWriter.
  • Факт, что служба запущена в "обычном" режиме (не работает как WIDWriter) или в режиме внутренней базы данных Windows.
  • Версия двоичных файлов модуля записи SQL.
  • Все параметры, заданные файлом SqlWriterConfig.ini :
    • Целевой путь для активного файла журнала.
    • Уровень детализации трассировки, который в этом примере — DEFAULT
    • Максимальный размер файла перед откатом, который в этом примере составляет 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 начинают любые операции резервного копирования и восстановления через VSS с события OnIdentify.

Ранее администратор базы данных мог обнаружить это событие только при трассировке активного профилировщика. С введением новой возможности ведения журнала при каждом таком событии появляется указанная выше запись.

В этой записи журнала отображаются следующие данные в порядке появления:

  • Явное упоминание события VSS OnIdentify.
  • Список всех активных (запущенных) экземпляров 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 с шаблоном "Ввод xxxx средства записи SQL".
    • Первым из этих этапов в нашем примере является Entering SQL Writer OnPrepareBackup.
  • Заметный элемент, указывающий начало резервного копирования VSS SQL
    • (Идентификатор threadId, выполняющий ведение журнала для этой попытки резервного копирования в SQLWriter)
  • API резервного копирования VSS, выбранный запрашивателем VSS, компонентом или некомпонентным или томом.
  • Количество баз данных, включенных в список компонентов, отправляемых запросом VSS, здесь одна база данных (1).
  • Подтверждение того, что каждое указанное в запросе имя базы данных (здесь db_on_G) найдено (или не найдено) на экземпляре SQL Server, с которым он связан с запросом VSS (здесь используется экземпляр GF19 по умолчанию).
  • Запрошенный вариант резервного копирования VSS. Обычно это VSS_BT_FULL или VSS_BT_COPY. См. описание перечисления VSS_BACKUP_TYPE.
  • Еще один раздел OnIdentify.
  • Дополнительные записи, идентифицирующие основные этапы резервного копирования VSS (OnFreeze, OnThaw, OnPostSnapshot).
  • Заключительный раздел OnIdentify.
  • Окончательный отчет этапа VSS, который называет его полезным "закрывающим событием": OnBackupComplete

Эти записи содержат подробные сведения об операциях VSS, которые ранее были трудно установить быстро, и требуется расширенная трассировка для этого. Хороший пример — режим любого запроса на резервное копирование VSS: Component или non-Component. При использовании средства записи SQL Server 2019 (15.x) они регистрируются для каждого отдельного запроса 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.

Это событие содержит сообщение с описанием ситуации в понятном для пользователя формате.

Платформа VSS ОС также сообщит о проблеме в журналах событий, используя ее nomenclature (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 VSS_BT_FULL в режиме non-component завершилось сбоем на этапе OnPrepareSnapshot в модуле записи SQL). Это означает, что при любом исследовании ошибок SQL Server необходимо собирать и изучать сведения из обоих источников.

Изменение параметров ведения журнала записи SQL

Ведение журнала модуля записи SQL можно настроить в текстовом файле SqlWriterConfig.ini. Сам файл содержит краткое описание доступных параметров, которые мы рассмотрим ниже.

Заметка

Файл .ini расположен в защищенной папке Windows (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 МБ (по умолчанию) Максимальный размер файла перед переключением. В файле TXT используется кодировка UTF-8. То есть каждый символ занимает два байта. Увеличение этого значения допустимо, например с интенсивным действием VSS, сохранением длительных периодов записей журнала или если значения по умолчанию TraceLevel включены в течение длительной длительности. Значение по умолчанию 1 МБ должно содержать достаточно журнал для большинства ситуаций.
ForceFlush -ИСТИННЫЙ
— FALSE (по умолчанию)		 Установка этого параметра TRUE будет полезно только в редких случаях, когда служба записи SQL завершится сбоем, прежде чем она получила возможность удалить последние записи журнала; в противном случае сохраните значение по умолчанию.

Применение изменений

При любых изменениях этих параметров необходимо перезапустить службу модуля записи SQL, чтобы они вступили в силу.

Совет

Перезагрузка средства записи SQL очень быстра и может быть выполнена, так как средство записи SQL не сохраняет данные с отслеживанием состояния и не имеет никаких действий между вызовами VSS. Единственная предосторожность, которую мы советуем соблюдать — не выполняйте перезапуск при активной операции VSS (резервное копирование или восстановление).

Модуль записи SQL при перезапуске запишет в файл журнала свои текущие параметры, что мы демонстрировали выше в примере запуска службы.

Уровень детализации TraceLevel

В SqlWriterConfig.ini файле перечислены следующие уровни:

Уровень Подробности
DEFAULT Параметры детализации по умолчанию должны соответствовать большинству потребностей: ознакомьтесь с разделом "Обзор типичных записей ведения журнала", чтобы узнать, что уже создано по умолчанию. Кроме сообщений об ошибках, на уровне детализации по умолчанию сохраняются успешные вызовы VSS и метаданные VSS.
MINIMAL Этот уровень будет поддерживать форматирование DEFAULT режима и его события. Кроме того, создаются записи во многих ключевых точках выполнения кода. Возможно, самое важное, что при этом сохраняются все файлы и итерации базы данных, которые являются стандартным механизмом в логике SQLWriter. На этом уровне может значительно увеличиться количество записей в журнале для каждой операции VSS (включая обычные события OnIdentify), особенно в экземплярах с большим числом баз данных. Для каждого физического файла каждой отдельной базы данных может появляться по несколько сообщений в ходе одной операции резервного копирования VSS. Такой уровень нужен только для более четкого представления о логической схеме действий модуля записи SQL на момент сбоя. Кроме того, этот уровень удобен для исследования. Это не полезно, чтобы сохранить его активным за пределами моментарных исследований, так как уровень подробностей значительно уменьшит глубину журнала размера файла по умолчанию 1 МБ. Возможно, потребуется увеличить значение TraceFileSizeMb.
VERBOSE В настоящее время этот уровень сообщает те же события, что MINIMALи записи, но префиксы каждой записи с помощью дескрипторов объектов и методов исходного кода. Это делает вывод более подробным (и большим по размеру, чем на уровне MINIMAL (Минимальный)), затрудняя его чтение. Эта дополнительная информация не имеет никакого значения вне контекста взаимодействий со службой поддержки Майкрософт. Здесь мы можем повторить ту же рекомендацию, что и для MINIMAL: при сохранении этого уровня на длительный период значительно сократится историческая перспектива данных в файле ограниченного размера (1 МБ по умолчанию) и, возможно, потребуется увеличить размер TraceFileSizeMb.

MINIMAL и VERBOSE уровни не предоставляют дополнительные сведения об ошибках в случае сбоя, а только дополнительные сведения о ходе выполнения для каждой низкоуровневой операции, связанной с действиями записи SQL.

Далее