Registro del escritor VSS de SQL Server

Se aplica a:SQL Server

SQL Server puede intervenir en las operaciones de copia de seguridad y restauración de VSS (Servicio de instantáneas de volumen) a través de su servicio SQL Writer dedicado. Para más información, consulte Aplicaciones para realizar copias de seguridad de SQL Server - Servicio de instantáneas de volumen (VSS) y SQL Writer.

El servicio notificaría errores de ejecución a los registros de eventos de la aplicación de Windows con un evento Source (o ProviderName en PowerShell o contexto XML) de 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, lo que dificultaba las investigaciones en SQL Server como participante en las operaciones de VSS.

En este artículo se describe el nuevo registro introducido en SQL Server 2019 (15.x) para ofrecer una mayor visibilidad de las operaciones de SQLWriter. Esta función también estaba disponible en SQL Server 2016 (13.x) Service Pack 3 y SQL Server 2017 (14.x) actualización acumulativa (CU) 27.

Información general

Las principales características 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 rotación, por lo que la segunda rotación sobrescribiría el SqlWriterLogger1.txt existente.
    • Los parámetros se administran por el archivo SqlWriterConfig.ini.

Como el objeto de escritura de SQL es un componente compartido de SQL Server, tiene una instancia única 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 archivo binario del objeto de escritura de SQL será el proporcionado por SQL Server 2019 (15.x) y dará servicio a todas las instancias en ejecución de todas las versiones principales (aunque su directorio principal permanezca bajo \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 a SQL Writer, que serían principalmente:

  • Eventos OnIdentify, desencadenados por el comando vssadmin list writers
  • Eventos de copia de seguridad
  • Restaurar eventos

Es decir, incluso si estas operaciones se llevan a cabo correctamente, el archivo de registro aún registrará entradas detalladas. Puede confirmar que se están realizando operaciones de VSS y que interactúan correctamente con SQL Writer. Es una mejora que ofrece una manera integrada sencilla de establecer estos detalles en el nivel de instancia de SQL Server.

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

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

Nota:

Esta nueva infraestructura de registro complementa el informe de errores existente para SQL Server, no lo reemplaza. Por lo tanto, en caso de error, los registros de eventos de la aplicación de Windows siguen siendo el primer lugar donde comprobar (filtrando por 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 indicada arriba aparecerá cada vez que se inicie el servicio SQL Writer (incluso puede registrarse dos veces por cada inicio del servicio).

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

  • Una marca de tiempo (fecha y hora) según la hora local del servidor, y el ThreadId del que procede la entrada en cada línea.
  • ProcessID del proceso SQLWriter que se está iniciando.
  • El hecho de que el servicio se haya iniciado en modo "normal" ("sin ejecutarse como WIDWriter") o en modo Windows Internal Database.
  • La versión de los binarios de SQL Writer.
  • Todos los parámetros establecidos por el SqlWriterConfig.ini archivo:
    • La ruta de destino del archivo de registro activo.
    • El nivel de detalle del seguimiento, que en este ejemplo es DEFAULT
    • El tamaño máximo del archivo antes de la sustitución, que en este ejemplo es 1 MB
    • La opción de ForceFlush cada vez que se actualiza el archivo de registro frente a un enfoque más relajado o de almacenamiento en búfer, que es False de forma predeterminada.
  • Recuerde que el registro utiliza la hora local junto con el desfase con respecto a 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 intentamos enumerar "instancias de usuario": una característica de SQL Server específica también conocida como LocalDB y que normalmente no está implicada en servidores de bases de datos empresariales.

Copia de seguridad de VSS en modo de componentes realizada correctamente

[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 da lugar a un conjunto mayor de entradas. En orden de apariencia, podemos ver la siguiente información:

  • Una sección OnIdentify completa, que, como ya se ha indicado, a menudo va seguida de una copia de seguridad.
  • Mención de cada fase principal de VSS durante la copia de seguridad, con el patrón "Entrando en 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
    • (siendo el ID el identificador del hilo que realiza el registro de ese intento de copia de seguridad en SQLWriter)
  • La API de copia de seguridad de VSS seleccionada por el solicitante de VSS, "componente" o "no-componente/volumen"
  • Recuento de bases de datos incluidas en la lista de componentes enviada por el solicitante de VSS, aquí una base de datos única (1).
  • Confirmación de que cada nombre de base de datos proporcionado por el solicitante (aquí, "db_on_G") se encuentra (o no se encuentra) en la instancia de SQL Server con la que ha sido asociado por el solicitante 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 OnIdentify sección
  • 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 la fase de VSS, cuyos nombres lo convierten en un "evento de cierre" útil: OnBackupComplete.

Estas entradas proporcionan detalles sobre las operaciones de VSS que antes 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 SQL Writer de SQL Server 2019 (15.x), se registran de forma predeterminada para todas y cada una de las solicitudes VSS y son fácilmente accesibles.

Situación de error: base de datos dividida

Para ilustrar la afirmación anterior de que SQL Writer complementa la arquitectura del registro de eventos, veamos las entradas asociadas a una situación de error bien conocida: una base de datos dañada. Este escenario puede producirse cuando una copia de seguridad con VSS intenta crear un conjunto de instantáneas de volúmenes que incluya solo parte de los archivos de una base de datos determinada. SQL Writer lo bloqueará de acuerdo con 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.

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

Ver los registros 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 de VSS del sistema operativo también informa del 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 una mejor fuente de información sobre el propio error aquí. Sin embargo, el contenido de SqlWriterLogger ofrece detalles sobre la solicitud de copia de seguridad (una solicitud VSS_BT_FULL de copia de seguridad de VSS sin componentes que falló durante la fase OnPrepareSnapshot de SQL Writer). Cualquier investigación de los errores de VSS que implique a SQL Server por lo tanto debe recopilar y revisar ambos orígenes.

Modificar los 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 en línea rápida 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. O bien inicie el Bloc de notas como administrador y, después, abra SqlWriterConfig.ini, o use un editor de texto que pueda solicitar permisos de elevación cuando sea necesario al guardar el archivo.

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

Parámetro Opciones Descripción
EnableLogging - VERDADERO (valor por defecto)
- FALSO		 Permite al usuario deshabilitar toda la nueva característica de registro, en el improbable caso 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 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
- VERBOSE		 El nivel de detalle del registro. Más información en Detalles de TraceLevel.
TraceFileSizeMb 1 MB (valor predeterminado) Tamaño máximo de archivo antes de la rotación. El archivo .txt usa la codificación UTF-8 y consume 2 bytes por carácter. Aumentar este valor puede ser adecuado, por ejemplo, en caso de intensa actividad de VSS, al conservar entradas de registro durante largos periodos o si se habilitan valores no predeterminados de TraceLevel durante periodos prolongados. El valor predeterminado de 1 MB debe proporcionar un historial amplio para la mayoría de las situaciones.
ForceFlush - VERDADERO
- FALSO (valor predeterminado)		 El establecimiento de esta opción en TRUE solo sería útil en las raras circunstancias en las que el servicio del objeto de escritura de SQL se bloquearía antes de tener la oportunidad de vaciar sus últimas entradas de registro; de lo contrario, conservaría el valor predeterminado.

Aplicación de cambios

Cualquier cambio en la configuración requiere reiniciar el servicio SQL Writer para que los cambios surtan efecto.

Sugerencia

Reiniciar SQL Writer es extremadamente rápido y puede hacerse siempre que se desee, ya que SQL Writer no conserva ninguna información de estado ni realiza ninguna actividad entre llamadas a VSS. La única precaución es evitar un reinicio mientras se realiza una operación de VSS (copia de seguridad, restauración).

SQL Writer registrará los parámetros activos en su archivo de registro al (re)iniciarse, como puede verse en el extracto de ejemplo Inicio del servicio.

Detalles de TraceLevel

El archivo SqlWriterConfig.ini enumera los siguientes niveles:

Nivel Detalle
DEFAULT Los parámetros del nivel 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 satisfactorias, junto con los metadatos de VSS, se registrarán de forma predeterminada.
MINIMAL Este nivel mantendrá el formato del modo DEFAULT y sus eventos. También generará resultados en varios puntos 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 considerablemente el número de entradas registradas para cada operación de VSS (incluido el evento OnIdentify más trivial), especialmente en instancias que alojan un gran número de bases de datos: todos y cada uno de los archivos físicos de cada base de datos pueden registrarse más de una vez en el transcurso de una copia de seguridad de VSS. Este nivel solo ayuda a proporcionar una idea más precisa de la posición lógica de la lógica de SQL Writer en el momento en que se produce un fallo. También es conveniente para fines de exploración. No es útil mantenerlo activo más allá de las investigaciones momentáneas, ya que el nivel de detalles reducirá en gran medida la profundidad del historial del tamaño de archivo de 1 MB predeterminado. Aumentar el valor TraceFileSizeMb puede ser pertinente.
VERBOSE Actualmente, este nivel notifica los mismos eventos que MINIMAL, pero agrega a cada entrada un prefijo con descriptores de métodos y objetos de código fuente. Hace que la salida sea más amplia (de mayor tamaño que la opción 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.

Los niveles MINIMAL y VERBOSE no proporcionarán detalles de error adicionales en caso de que se produzca algún problema, solo detalles de progreso adicionales para cada operación de bajo nivel relacionada con las actividades del objeto de escritura de SQL.

Pasos siguientes

  • Last updated on