Registro de VSS Writer de SQL Server

  • Artículo

Se aplica a:SQL Server

SQL Server pueden participar en las operaciones de copia de seguridad y restauración de VSS (Servicio de instantáneas de volumen) a través de su servicio de escritura de SQL dedicado. Para obtener más información, vea SQL Server Copia de seguridad de aplicaciones: servicio de instantáneas de volumen (VSS) y escritor de SQL.

El servicio notificaría errores de ejecución a los registros de eventos de aplicación de Windows con un evento Source (o ProviderName en el contexto de PowerShell o XML) del valor SQLWRITER, como puede ver en el ejemplo más adelante en este artículo. Antes de SQL Server 2019 (15.x), no había ningún registro de actividad dedicado, que hacía investigaciones contra SQL Server como participante en las operaciones de VSS desafiantes.

En este artículo se describe el nuevo registro incluido en SQL Server 2019 (15.x) por primera vez para proporcionar una mejor visibilidad sobre sus operaciones SQLWriter. Esta funcionalidad también se puso a disposición en SQL Server 2016 (13.x) Service Pack 3 y SQL Server 2017 (14.x) Actualización acumulativa (CU) 27.

Información general

Las características principales del registro de SQLWriter de SQL Server 2019 (15.x) son:

  • Está activado de forma predeterminada.
  • Es para todo el sistema (realizará un seguimiento de la actividad del objeto de escritura de SQL en todas las instancias de SQL Server que se ejecutan en el servidor).
  • Se basa en texto.
  • Su directorio de trabajo es C:\Program Files\Microsoft SQL Server\90\Shared.
  • Dentro de ese directorio:
    • El registro tiene lugar en el archivo SqlWriterLogger.txt.
    • El nombre de este archivo se cambia a SqlWriterLogger1.txt al alcanzar un tamaño máximo (de forma predeterminada, 1 MB), y el registro continúa en SqlWriterLogger.txt principal.
    • Solo hay un archivo de sustitución incremental, por lo que la segunda sustitución sobrescribiría el SqlWriterLogger1.txt existente.
    • Los parámetros se administran por el archivo SqlWriterConfig.ini.

Dado que SQL Writer es un componente compartido de SQL Server, tiene una sola instancia en un sistema y su versión principal será la misma que la versión principal más alta de cualquier instancia de SQL Server instalada. Por ejemplo, si SQL Server 2016 (13.x) SP2 y SQL Server 2019 (15.x) están instalados en el mismo sistema, el binario del objeto de escritura de SQL será el proporcionado por SQL Server 2019 (15.x) y atenderá todas las instancias en ejecución de todas las versiones principales (aunque su directorio principal permanezca en \90). Las instancias y versiones locales se beneficiarán del nuevo seguimiento de SQL Server 2019 (15.x) que se describe aquí. También implica que solo las actualizaciones acumulativas de SQL Server 2019 (15.x) actualizarán los archivos binarios del objeto de escritura de SQL en esta situación.

Nota:

En los párrafos siguientes se describe la situación a partir de SQL Server 2019 (15.x) CU 4. Las versiones anteriores de SQL Server 2019 (15.x) no tendrán la misma cantidad de información en el archivo de registro en la configuración predeterminada.

Operaciones básicas

Puede beneficiarse del nuevo registro sin ningún cambio manual. Puede abrir el archivo de registro de SqlWriterLogger.txt principal, u obtener una copia de este, en C:\Program Files\Microsoft SQL Server\90\Shared\. El archivo reflejará todos los eventos de VSS que lleguen al objeto de escritura de SQL, que serían principalmente:

  • Eventos OnIdentify, desencadenados por el comando vssadmin list writers
  • Eventos de copia de seguridad
  • Eventos de restauración

Es decir, aunque estas operaciones se realicen correctamente, el archivo de registro seguirá registrando entradas detalladas. Puede confirmar que las operaciones de VSS se están produciendo e interactuando correctamente con SQL Writer. Es una mejora que ofrece una forma sencilla integrada de establecer estos detalles en SQL Server nivel de instancia.

Además, los eventos de inicio del servicio SQLWriter también se registrarán y notificarán los parámetros de registro activos.

Si un error de operación de VSS implica SQL Server, SqlWriterLogger se convierte en un lugar importante para comprobar si hay información.

Nota:

Esta nueva infraestructura de registro complementa el informe de errores existente uno para SQL Server, no lo reemplaza. Por lo tanto, en caso de error, el registro de eventos de la aplicación Windows sigue siendo el primer lugar para comprobar (filtrado en orígenes como "SQLWRITER" y "VSS"). SqlWriterLogger.txt proporcionaría información adicional a este conjunto inicial.

Revisión de entradas de registro típicas

Las siguientes exportaciones se han realizado en la configuración predeterminada.

Inicio del servicio

[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] ****************************************************************

La entrada anterior se observará para cada inicio de Servicio del objeto de escritura de SQL (incluso se puede registrar dos veces por inicio de servicio).

En orden de apariencia, podemos ver la siguiente información:

  • Marca de tiempo (fecha y hora) en la hora del servidor local y threadId que origina la entrada para cada línea.
  • ProcessId del proceso sqlWriter que se está iniciando.
  • El hecho de que el servicio se inició en modo "normal" ("no se ejecuta como WIDWriter") o en modo Windows Internal Database.
  • La versión de los archivos binarios del objeto de escritura de SQL.
  • Todos los parámetros establecidos por el SqlWriterConfig.ini archivo:
    • La ruta de acceso de destino del archivo de registro activo.
    • El nivel de detalles del seguimiento, que en este ejemplo es DEFAULT
    • El tamaño máximo del archivo antes de que se produzca la sustitución, que en este ejemplo es de 1 MB.
    • La opción para ForzarFlush cada actualización única del archivo de registro frente a un enfoque más relajado o almacenado en búfer, que es False de forma predeterminada.
  • Un recordatorio de que el registro es la hora local junto con la diferencia horaria con UTC de esa hora local.

Evento "OnIdentify" de VSS

[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 es una operación común de VSS. Se desencadena mediante el comando vssadmin list writers. La mayoría de los solicitantes de VSS iniciarían cualquier operación de copia de seguridad o restauración de VSS mediante un evento OnIdentify.

Anteriormente, solo el seguimiento del generador de perfiles activo permitía que el DBA detectara este tipo de evento. Con la nueva característica de registro, cada evento dará lugar a la entrada anterior.

En orden de apariencia, podemos ver que se registra la siguiente información:

  • Una mención explícita del evento VSS OnIdentify.
  • Una lista de todas las instancias de SQL Server activas (en ejecución), junto con el nombre de la instancia, la versión principal y la edición.
  • Indicación de que no hemos intentado enumerar "Instancias de usuario": una característica de SQL Server específica también conocida como LocalDB y normalmente no implicada en servidores de bases de datos empresariales.

Copia de seguridad de VSS en modo componente correcta

[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.

Este evento conduce a un conjunto de entradas más amplio. En orden de apariencia, podemos ver la siguiente información:

  • Una sección OnIdentify completa, que como ya se ha indicado a menudo lleva una copia de seguridad.
  • Mencione cada fase principal de VSS de la copia de seguridad, con el patrón "Especificación de SQL Writer xxxx".
    • El primero aquí es Entering SQL Writer OnPrepareBackup.
  • Entrada visible que indica el inicio de una copia de seguridad SQL de VSS.
    • (Identificador que es threadId que realiza el registro para ese intento de copia de seguridad en SQLWriter)
  • LA API de copia de seguridad de VSS seleccionada por el solicitante de VSS, "component" o "non-component/Volume"
  • Recuento de bases de datos incluidas en la lista de componentes enviada por el solicitante de VSS, aquí una sola base de datos (1).
  • Confirmación de que se encuentra (o no se encuentra) cada nombre de base de datos proporcionado por el solicitante (aquí "db_on_G") en la instancia de SQL Server a la que está asociado el solicitante de VSS (aquí la instancia predeterminada "GF19").
  • Tipo de copia de seguridad de VSS solicitada. Normalmente VSS_BT_FULL o VSS_BT_COPY. Vea la enumeración VSS_BACKUP_TYPE.
  • Otra sección OnIdentify.
  • Más entradas que identifican las fases principales de la copia de seguridad de VSS (OnFreeze, OnThaw, OnPostSnapshot).
  • Una sección OnIdentify final.
  • Un informe final de fase de VSS, que los nombres lo convierten en un "evento de cierre" útil: OnBackupComplete.

Estas entradas proporcionan detalles sobre las operaciones de VSS que anteriormente eran difíciles de establecer rápidamente y requerían un seguimiento avanzado para hacerlo. Un ejemplo excelente es el modo "componente" o "no componente" de cualquier solicitud de copia de seguridad de VSS. Con el objeto de escritura de SQL de SQL Server 2019 (15.x), se registran para cada solicitud de VSS única de forma predeterminada y son fácilmente accesibles.

Situación de error: base de datos rasgada

Para ilustrar la instrucción anterior que el registro de SQL Writer complementa la arquitectura del registro de eventos, echemos un vistazo a las entradas asociadas a una situación de error conocida: una base de datos rasgada. Este escenario puede producirse cuando una copia de seguridad de VSS intenta crear un conjunto de instantáneas de volúmenes que incluyen solo un conjunto parcial de archivos de una base de datos determinada. El objeto de escritura de SQL lo bloqueará según las convenciones de VSS.

Este extracto es el contenido de SqlWriterLogger.txt para la operación:

[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.

A partir de SqlWriterLogger.txt vemos que se ha producido un error, pero los únicos detalles que tenemos en caso de error son .0x80780002 HResult Este valor es difícil de interpretar sin las referencias de código de error. Sin embargo, identifica la situación de la base de datos rasgada.

Visualización del registro de eventos

Ahora vamos a comprobar el contenido de los registros de eventos de aplicación de 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.

El evento proporciona un mensaje con formato descriptivo completo que explica la situación.

El marco vsS del sistema operativo también notificará el problema en los registros de eventos, mediante su nomenclatura (VSS administra "componentes", que son "bases de datos" en el contexto de 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

El registro de eventos es un mejor origen de información sobre el propio error aquí. Sin embargo, el contenido de SqlWriterLogger proporciona detalles sobre la solicitud de copia de seguridad (VSS_BT_FULL, una solicitud de copia de seguridad de VSS que no es de componente y que no se ha podido realizar durante la fase OnPrepareSnapshot del objeto de escritura de SQL). Cualquier investigación de los errores de VSS que implique a SQL Server por lo tanto debe recopilar y revisar ambos orígenes.

Modificación de parámetros de registro de SQL Writer

El registro del objeto de escritura de SQL se puede configurar editando el archivo de texto SqlWriterConfig.ini. El propio archivo contiene una descripción rápida en línea de los parámetros disponibles, que revisaremos a continuación.

Nota:

El archivo .ini está en una carpeta protegida por Windows (Archivos de programa). Por lo tanto, requiere privilegios de administrador elevados para editar. Al hacer doble clic en el explorador, se abrirá el Bloc de notas sin elevación: permitirá al usuario leer el contenido, pero se producirá un error al intentar guardar cualquier cambio. Inicie el Bloc de notas como administrador y, a continuación, abra SqlWriterConfig.inio use un editor de texto que pueda solicitar la elevación según sea necesario al guardar el archivo.

Duplicación de los comentarios del archivo SqlWriterConfig.ini aquí:

Parámetro Opciones Descripción
EnableLogging - TRUE (valor predeterminado)
-FALSO		 Permite al usuario deshabilitar toda la nueva característica de registro, en el caso improbable de que sea necesario.
TraceFile C:\Program Files\Microsoft SQL Server\90\Shared\SqlWriterLog.txt Permite al usuario cambiar la ruta de acceso y el nombre de archivo del archivo de seguimiento. No se recomienda cambiarla, ya que la ubicación predeterminada y conocida hace que sea fácil ir directamente al lugar correcto en cualquier servidor SQL Server.
TraceLevel - DEFAULT (valor predeterminado)
-MÍNIMO
-DETALLADO		 Detalle del registro. Más información se encuentra en Detalles de TraceLevel.
TraceFileSizeMb 1 MB (valor predeterminado) Tamaño máximo del archivo antes de la sustitución. El archivo .txt usa la codificación UTF-8 y consume 2 bytes por carácter. Aumentar este valor es válido, por ejemplo, con una actividad de VSS intensa, conservando largos períodos de entradas de registro o si los valores no predeterminados TraceLevel están habilitados durante largos períodos. El valor predeterminado de 1 MB debe proporcionar un historial amplio para la mayoría de las situaciones.
ForceFlush -VERDAD
- FALSE (valor predeterminado)		 Establecer esta opción TRUE en solo sería útil en las raras circunstancias en las que el servicio escritor de SQL se bloquearía antes de tener la oportunidad de vaciar sus últimas entradas de registro; de lo contrario, mantenga el valor predeterminado.

Aplicación de cambios

Cualquier cambio en la configuración requiere un reinicio del servicio del objeto de escritura de SQL para activarse.

Sugerencia

Reiniciar el objeto de escritura de SQL es extremadamente rápido y se puede realizar a voluntad, ya que el escritor de SQL no conserva ninguna información con estado ni tiene ninguna actividad entre llamadas de VSS. La única precaución es evitar un reinicio mientras se realiza una operación de VSS (copia de seguridad, restauración).

El objeto de escritura de SQL informa de los parámetros activos en su archivo de registro tras el (re)inicio, como se puede ver en la extracción de ejemplo del inicio del servicio.

Detalles de TraceLevel

El SqlWriterConfig.ini archivo muestra los siguientes niveles:

Nivel Detalle
DEFAULT Los parámetros de detalle predeterminados deben ser adecuados para la mayoría de las necesidades: consulte la sección Revisión de entradas de registro típicas para observar lo que ya se ha generado de forma predeterminada. Además de los errores, las llamadas de VSS correctas, junto con los metadatos de VSS, se registrarán de forma predeterminada.
MINIMAL Este nivel mantendrá el formato del DEFAULT modo y sus eventos. También generará la salida en muchos lugares clave del código. En concreto, registrará todos los archivos e iteraciones de base de datos que son comunes en la lógica de SQLWriter. Puede aumentar el número de entradas registradas para cada operación de VSS (incluido el evento OnIdentify mundano) en un gran margen, especialmente en las instancias que hospedan un gran número de bases de datos: cada archivo físico único de cada base de datos única se puede registrar más de una vez durante una copia de seguridad de VSS. Este nivel sólo ayuda a dar una idea más precisa de la posición lógica del objeto de SQL en el momento en que se produce un error. También es conveniente para fines de exploración. No es útil mantenerla activa más allá de las investigaciones momentáneas, ya que el nivel de detalles reducirá considerablemente la profundidad del historial del tamaño de archivo predeterminado de 1 MB. Aumentar el valor TraceFileSizeMb puede ser pertinente.
VERBOSE Actualmente, este nivel informa de los mismos eventos que MINIMAL, pero prefijos cada entrada con descriptores de métodos y objetos de código fuente. Hace que la salida sea más ancha (mayor en tamaño que mínima) y menos legible. La información agregada no sería útil fuera de las interacciones con el servicio de soporte técnico de Microsoft. Se aplicaría el mismo comentario que MINIMAL: mantener este nivel activo durante mucho tiempo reducirá en gran medida la profundidad del historial del archivo de 1 MB predeterminado, y aumentar el valor de TraceFileSizeMb puede ser pertinente.

MINIMAL y VERBOSE los niveles no proporcionan detalles de error adicionales en caso de error, solo detalles de progreso adicionales para cada operación de bajo nivel relacionada con las actividades del objeto de escritura de SQL.

Pasos siguientes