Registrazione di SQL Server VSS Writer

  • Articolo

Si applica a: SQL Server

SQL Server può essere coinvolto nelle operazioni di backup e ripristino del servizio Copia Shadow del volume tramite il servizio writer SQL dedicato. Per maggiori informazioni, vedere Applicazioni di backup SQL Server - Servizio Copia Shadow del volume e writer SQL.

Il servizio segnala errori di esecuzione ai log eventi dell'applicazione Windows con un evento Source (o ProviderName nel contesto PowerShell o XML) di valore SQLWRITER, come si può vedere nell'esempio riportato più avanti in questo articolo. Prima di SQL Server 2019 (15.x), non era presente alcun log attività dedicato, il che rendeva impegnative le indagini su SQL Server come partecipante alle operazioni relative al Servizio Copia Shadow del volume.

Questo articolo descrive il nuovo log introdotto da SQL Server 2019 (15.x) per offrire una migliore visibilità sulle operazioni SQLWriter. Questa funzionalità è stata resa disponibile anche su SQL Server 2016 (13.x) Service Pack 3 e SQL Server 2017 (14.x) Aggiornamento cumulativo (CU) 27.

Panoramica

Le caratteristiche principali del log SQLWriter di SQL Server 2019 (15.x) sono:

  • È attivo per impostazione predefinita
  • A livello di sistema, verrà tracciata l'attività del writer SQL in tutte le istanze di SQL Server in esecuzione nel server
  • È basato su testo
  • La directory di lavoro è C:\Program Files\Microsoft SQL Server\90\Shared
  • All'interno di tale directory:
    • La creazione del log avviene nel file SqlWriterLogger.txt
    • Questo file viene rinominato in SqlWriterLogger1.txt quando si raggiunge una dimensione massima (per impostazione predefinita 1 MB), e il log continua nel SqlWriterLogger.txt principale.
    • Esiste un solo file di rollover, quindi il secondo rollover sovrascrive l'oggetto esistente SqlWriterLogger1.txt.
    • I parametri vengono gestiti dal file SqlWriterConfig.ini

Poiché SQL Writer è un componente condiviso di SQL Server, dispone di una singola istanza in un sistema e la versione principale sarà la stessa della versione principale più recente di qualsiasi istanza di SQL Server installata. Ad esempio, se SQL Server 2016 (13.x) SP2 e SQL Server 2019 (15.x) sono installati nello stesso sistema, il file binario del writer SQL sarà quello fornito da SQL Server 2019 (15.x) e servirà le istanze in esecuzione di tutte le versioni principali (anche se la relativa home directory rimane in \90). Le istanze e le versioni locali trarranno vantaggio dalla nuova traccia di SQL Server 2019 (15.x) descritta qui. Ciò implica anche che in questa situazione solo gli aggiornamenti cumulativi di SQL Server 2019 (15.x) aggiorneranno i file binari del writer SQL.

Nota

I paragrafi seguenti descrivono la situazione a partire da SQL Server 2019 (15.x) CU 4. Le versioni precedenti di SQL Server 2019 (15.x) non avranno la stessa quantità di informazioni nel file di log nelle impostazioni predefinite.

Operazioni di base

È possibile trarre vantaggio dal nuovo log senza alcuna modifica manuale. È possibile aprire o ottenere una copia del file di log principale SqlWriterLogger.txt in C:\Program Files\Microsoft SQL Server\90\Shared\. Il file riporterà tutti gli eventi VSS che raggiungono il writer SQL, che sarebbero principalmente:

  • eventi OnIdentify, come attivato dal comando vssadmin list writers
  • Eventi di backup
  • Eventi di ripristino

Ciò significa che, anche se queste operazioni vengono eseguite correttamente, il file di log registrerà comunque voci dettagliate. È possibile verificare che le operazioni VSS si verifichino e interagiscono correttamente con il writer SQL. Si tratta di un miglioramento che offre un modo predefinito semplice per stabilire questi dettagli a livello di istanza di SQL Server.

Verranno inoltre registrati gli eventi di avvio del servizio SQLWriter e verranno riportati i parametri di log attivi.

Se un errore dell'operazione VSS coinvolge SQL Server, SqlWriterLogger diventa un luogo importante per verificare la presenza di informazioni.

Nota

Questa nuova infrastruttura di log integra la segnalazione degli errori esistente per SQL Server, ma non la sostituisce. Pertanto, in caso di errore, il log eventi dell'applicazione di Windows rimane il primo luogo in cui controllare (filtrando le origini come "SQLWRITER" e "VSS"). SqlWriterLogger.txt fornirebbe informazioni aggiuntive a questo insieme iniziale.

Revisione delle voci di log tipiche

Le esportazioni seguenti sono state effettuate con l'impostazione predefinita.

Avvio del servizio

[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 voce precedente verrà osservata per ogni avvio del servizio writer SQL (potrebbe anche essere registrata due volte per ogni avvio del servizio).

In ordine di apparizione, è possibile visualizzare le informazioni seguenti:

  • Un indicatore orario (data + ora) nell'ora del server locale e il ThreadId che ha generato la voce per ogni riga.
  • Il ProcessId del processo SQLWriter avviato.
  • Il fatto che il servizio sia stato avviato in modalità "normale" (“non in esecuzione come WIDWriter”) o in modalità Database interno di Windows.
  • La versione dei file binari del writer SQL.
  • Tutti i parametri impostati dal file SqlWriterConfig.ini:
    • Il percorso di destinazione del file di log attivo
    • Il livello di dettaglio della traccia, che in questo esempio è DEFAULT
    • Le dimensioni massime del file prima del rollover, che in questo esempio sono 1 MB
    • L'opzione ForceFlush per ogni singolo aggiornamento del file di log rispetto a un approccio più rilassato/buffered, che è False per impostazione predefinita.
  • Un promemoria che indica che il log è nell'ora locale, insieme alla differenza rispetto all'ora UTC.

Evento 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 è un'operazione VSS comune. Viene attivata dal comando vssadmin list writers. La maggior parte dei richiedenti VSS avvia un'operazione di backup o ripristino VSS da un OnIdentify evento.

In precedenza, solo la traccia del profiler attivo avrebbe consentito all'amministratore del database di rilevare tale evento. Con la nuova funzionalità di log, ogni evento porterà alla voce precedente.

In ordine di apparizione, è possibile visualizzare le informazioni seguenti registrate:

  • Una menzione esplicita dell'evento VSS OnIdentify.
  • Un elenco di tutte le istanze di SQL Server attive (in esecuzione), insieme al nome dell'istanza, alla versione principale e all'edizione.
  • L'indicazione del fatto che non si è tentato di elencare "Istanze utente", una funzionalità specifica di SQL Server nota anche come Local DB, che in genere non è coinvolta nei server di database aziendali.

Backup VSS in modalità componente completato

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

Questo evento porta a un set di voci più ridimensionabile. In ordine di apparizione, è possibile visualizzare le informazioni seguenti:

  • Una sezione completa OnIdentify, che come già indicato spesso conduce un backup.
  • Menzione di ogni fase principale VSS del backup, con il modello "Immissione di xxxx SQL Writer".
    • La prima qui è Entering SQL Writer OnPrepareBackup.
  • Una voce evidente che indica l'inizio di un backup SQL di VSS
    • (ID che rappresenta il ThreadId che esegue la registrazione del tentativo di backup in SQLWriter)
  • L'API di backup VSS selezionata dal richiedente VSS, "componente" o "non componente/volume"
  • Il numero di database inclusi nell'elenco dei componenti inviato dal richiedente VSS, in questo caso un singolo database (1).
  • La conferma che ogni nome di database fornito dal richiedente (qui “db_on_G”) viene trovato (o non trovato) nell'istanza di SQL Server a cui è stato associato dal richiedente VSS (qui l'istanza predefinita “GF19”).
  • Il tipo di backup VSS richiesto. In genere VSS_BT_FULL o VSS_BT_COPY. Vedere l'enumerazione VSS_BACKUP_TYPE.
  • Un'altra sezione OnIdentify
  • Altre voci che identificano le fasi principali del backup VSS (OnFreeze, OnThaw, OnPostSnapshot)
  • Una sezione finale OnIdentify.
  • Un report di fase finale del VSS del database, che lo rende un "evento di chiusura" utile: OnBackupComplete.

Queste voci forniscono informazioni dettagliate sulle operazioni VSS che in precedenza erano difficili da stabilire rapidamente e richiedevano la traccia avanzata a tale scopo. Un esempio emblematico è la modalità "componente" o "non componente" di qualsiasi richiesta di backup VSS. Con il writer SQL di SQL Server 2019 (15.x), vengono registrati per ogni singola richiesta VSS per impostazione predefinita e sono facilmente accessibili.

Situazione di errore: database incompleto

Per illustrare l'istruzione precedente per la quale il log del writer SQL integra l'architettura del registro eventi, verranno esaminate le voci associate a una situazione di errore nota: un database incompleto. Questo scenario può verificarsi quando un backup VSS tenta di creare un set di snapshot di volumi che includono solo un set parziale di file di un determinato database. Il writer SQL lo bloccherà in base alle convenzioni VSS.

Questo estratto è il contenuto di SqlWriterLogger.txt per l'operazione:

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

Da SqlWriterLogger.txt si noterà che si è verificato un errore, ma gli unici dettagli presenti in caso di errore sono 0x80780002 HResult. Questo valore è difficile da interpretare senza i riferimenti al codice di errore. Identifica però la situazione del database incompleto.

Visualizzare il registro eventi

A questo punto è possibile controllare il contenuto dei log eventi dell’applicazione di 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.

L'evento fornisce un messaggio formattato completo e semplice da interpretare che spiega la situazione.

Il framework VSS del sistema operativo segnala il problema anche nei registri eventi, usando la relativa nomenclatura (VSS gestisce i "componenti", ovvero i "database" nel contesto di 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

Il registro eventi in questo caso è una fonte migliore di informazioni sull'errore stesso. Tuttavia, il contenuto di SqlWriterLogger fornisce informazioni dettagliate sulla richiesta di backup (una richiesta VSS_BT_FULL di backup VSS non componente che ha avuto esito negativo durante la fase OnPrepareSnapshot del writer SQL). Qualsiasi indagine sugli errori VSS che coinvolgono SQL Server deve quindi raccogliere ed esaminare entrambe le fonti.

Modificare i parametri di log del writer SQL

La registrazione del writer SQL può essere configurata modificando il file di testo SqlWriterConfig.ini. Il file stesso contiene una rapida descrizione incorporata dei parametri disponibili, che verranno esaminati di seguito.

Nota

Il file .ini si trova in una cartella protetta di Windows (Programmi). Di conseguenza, è necessario che i privilegi elevati di amministratore siano modificati. Un doppio clic in Esplora risorse aprirà Blocco note di Windows senza privilegi elevati: questo consentirà all'utente di leggere il contenuto, ma i tentativi di salvare eventuali modifiche avranno esito negativo. Avviare Blocco note come amministratore, quindi aprire SqlWriterConfig.ini o usare un editor di testo in grado di richiedere l'elevazione dei privilegi in base alle esigenze durante il salvataggio del file.

Duplicare i commenti del file SqlWriterConfig.ini qui:

Parametro Opzioni Descrizione
EnableLogging - TRUE (impostazione predefinita)
- FALSE		 Consente all'utente di disabilitare l'intera nuova funzionalità di log, nel caso improbabile che sia necessario.
TraceFile C:\Program Files\Microsoft SQL Server\90\Shared\SqlWriterLog.txt Consente all'utente di modificare il percorso e il nome file del file di traccia. Non è consigliabile modificarlo, poiché il percorso noto predefinito semplifica l'accesso diretto alla posizione desiderata di qualsiasi SQL Server.
TraceLevel - DEFAULT (impostazione predefinita)
- MINIMAL
- VERBOSE (dettagliato)		 Livello di dettaglio del log. Altre informazioni sono disponibili in Dettagli traceLevel.
TraceFileSizeMb 1 MB (valore predefinito) Dimensione massima del file prima del rollover. Il file .txt usa la codifica UTF-8 e utilizza 2 byte per carattere. L'aumento di questo valore è valido, ad esempio, in caso di un'intensa attività VSS, mantenendo lunghi periodi di voci di log, o se i valori non predefiniti TraceLevel sono abilitati per durate lunghe. Il valore predefinito di 1 MB deve fornire un'ampia cronologia della maggior parte delle situazioni.
ForceFlush - TRUE
- FALSE (impostazione predefinita)		 L'impostazione di questa opzione su TRUE sarebbe utile solo nelle rare circostanze in cui il servizio writer SQL si arrestasse in modo anomalo prima di aver potuto scaricare le ultime voci di log; in caso contrario, mantenere il valore predefinito.

Applica modifiche

Per attivare qualsiasi modifica alle impostazioni è necessario riavviare il servizio writer SQL.

Suggerimento

Il riavvio del writer SQL è estremamente rapido e può essere eseguito in modo che il writer SQL non mantenga informazioni con lo stato né abbia alcuna attività tra chiamate VSS. L'unica precauzione consiste nell'evitare un riavvio durante l'esecuzione di un'operazione VSS (backup, ripristino).

Il writer SQL segnala i parametri attivi nel file di log al momento del (ri)avvio, come si può vedere nell'estratto dell’esempio Avvio del servizio.

Dettagli TraceLevel

Il file SqlWriterConfig.ini elenca i livelli seguenti:

Level Dettagli
DEFAULT I parametri di dettaglio predefiniti devono essere adeguati alla maggior parte delle esigenze: fare riferimento alla sezione Verifica delle voci di log tipiche per osservare ciò che è già generato per impostazione predefinita. Oltre agli errori, le chiamate VSS riuscite, insieme ai metadati VSS, verranno registrate per impostazione predefinita.
MINIMAL Questo livello manterrà la formattazione della modalità DEFAULT e i relativi eventi. Genererà anche l'output in molte posizioni chiave del codice. In particolare, registrerà tutti i file e le iterazioni di database comuni alla logica SQLWriter. Può aumentare di molto il numero di voci registrate per ogni operazione VSS (incluso l'evento ripetitivo OnIdentify), soprattutto nelle istanze che ospitano un numero elevato di database: ogni singolo file fisico di ogni singolo database può essere riportato più volte nel corso di un backup del Servizio Copia Shadow del volume. Questo livello consente solo di dare un'idea più precisa della posizione logica della logica del writer SQL quando si verifica un errore. È utile anche per scopi di indagine. Non è utile mantenerlo attivo oltre le indagini momentanee, perché il livello dei dettagli ridurrà notevolmente la profondità della cronologia del file predefinito di 1 MB. L'aumento del valore TraceFileSizeMb può essere rilevante.
VERBOSE Attualmente questo livello riporta gli stessi eventi di MINIMAL, ma antepone a ogni voce i descrittori dei metodi e del codice sorgente. Rende l'output più ampio (dimensioni maggiori rispetto a Minimo) e meno leggibile. Le informazioni aggiunte non sarebbero utili al di fuori delle interazioni con i servizi del supporto tecnico Microsoft. Vale lo stesso commento di MINIMAL: mantenere attivo questo livello per una lunga durata ridurrà notevolmente la profondità della cronologia delle dimensioni predefinite del file di 1 MB, e l'aumento del valore TraceFileSizeMb potrebbe essere rilevante.

I livelli MINIMAL e VERBOSE non forniscono dettagli aggiuntivi sull’errore in caso di esito negativo, ma solo dettagli aggiuntivi sullo stato di avanzamento di ogni operazione di basso livello correlata alle attività del writer SQL.

Passaggi successivi