SQL Server - Journalisation de l’enregistreur VSS Writer

  • Article

S’applique à :SQL Server

SQL Server peut être impliqué dans les opérations de sauvegarde et de restauration VSS (Service de cliché instantané en volume) via son service SQL Writer dédié. Pour plus d’informations, consultez SQL Server Backup Up Applications - Volume Shadow Copy Service (VSS) et SQL Writer.

Le service signale des erreurs d’exécution aux journaux des événements d’application Windows avec un événement Source (ou ProviderName dans le contexte PowerShell ou XML) de valeurSQLWRITER, comme vous pouvez le voir dans l’exemple plus loin dans cet article. Avant SQL Server 2019 (15.x), aucun journal d’activité dédié n’a été effectué, ce qui a fait des enquêtes sur SQL Server en tant que participant aux opérations VSS difficiles.

Cet article décrit le nouveau journal introduit par SQL Server 2019 (15.x) pour fournir une meilleure visibilité sur ses opérations SQLWriter. Cette fonctionnalité a également été mise à disposition dans SQL Server 2016 (13.x) Service Pack 3 et SQL Server 2017 (14.x) Mise à jour cumulative (CU) 27.

Vue d’ensemble

Les principales caractéristiques de la journalisation SQL Server 2019 (15.x) SQLWriter sont les suivantes :

  • L’option est activée par défaut
  • Elle est active à l’échelle du système (elle trace l’activité de l’enregistreur SQL Writer sur toutes les instances SQL Server s’exécutant sur le serveur)
  • Elle est basée sur du texte
  • Son répertoire de travail est C:\Program Files\Microsoft SQL Server\90\Shared
  • Dans ce répertoire :
    • La journalisation a lieu dans le fichier SqlWriterLogger.txt
    • Ce fichier est renommé SqlWriterLogger1.txt lorsqu’il atteint une taille maximale (par défaut, 1 Mo), et la journalisation continue dans le fichier SqlWriterLogger.txt principal.
    • Comme il n’y a qu’un seul fichier de substitution, la deuxième substitution remplace l’élément SqlWriterLogger1.txt existant.
    • Les paramètres sont gérés par fichier SqlWriterConfig.ini

Étant donné que SQL Writer est un composant partagé SQL Server, il dispose d’une instance unique sur un système, et sa version principale est identique à la version principale la plus élevée de n’importe quelle instance SQL Server installée. Par exemple, si SQL Server 2016 (13.x) SP2 et SQL Server 2019 (15.x) sont installés sur le même système, le fichier binaire SQL Writer est celui fourni par SQL Server 2019 (15.x) et va traiter toutes les instances de toutes les versions principales (même si son répertoire de base reste sous \90). Les instances et versions locales bénéficieront du nouveau suivi SQL Server 2019 (15.x) décrit ici. Cela implique également que seules les mises à jour cumulatives SQL Server 2019 (15.x) mettez à niveau les fichiers binaires SQL Writer dans ce cas.

Note

Les paragraphes suivants décrivent la situation commençant par SQL Server 2019 (15.x) CU 4. Les versions antérieures de SQL Server 2019 (15.x) n’auront pas la même quantité d’informations dans le fichier journal sous les paramètres par défaut.

Opérations de base

Vous pouvez tirer parti de la nouvelle journalisation sans modification manuelle. Vous pouvez ouvrir ou obtenir une copie du fichier journal principal SqlWriterLogger.txt dans C:\Program Files\Microsoft SQL Server\90\Shared\. Le fichier reflète tous les événements VSS qui atteignent l’enregistreur SQL Writer, qui sont principalement :

  • Des événements OnIdentify, tels qu’ils sont déclenchés par la commande vssadmin list writers
  • Des événements de sauvegarde
  • Des événements de restauration

Autrement dit, même si ces opérations ont lieu correctement, le fichier journal enregistre toujours les entrées détaillées. Vous pouvez vérifier que les opérations VSS se produisent et interagissent correctement avec SQL Writer. Il s’agit d’une amélioration qui offre un moyen intégré simple d’établir ces détails au niveau de l’instance SQL Server.

En outre, les événements de démarrage du service SQLWriter sont également enregistrés et signalent les paramètres de journalisation actifs.

Si un échec d’opération VSS implique SQL Server, SqlWriterLogger devient un endroit important pour rechercher des informations.

Note

Cette nouvelle infrastructure de journalisation complète la création de rapports d’erreurs existante pour SQL Server, elle ne la remplace pas. Par conséquent, en cas d’erreur, le journal des événements de l’application Windows reste le premier endroit à vérifier (filtrage sur des sources telles que « SQLWRITER » et « VSS »). SqlWriterLogger.txt fournirait des informations supplémentaires à cet ensemble initial.

Examen des entrées de journalisation typiques

Les exportations suivantes ont été apportées sous le paramètre par défaut.

Démarrage du service

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

L’entrée ci-dessus est observée pour chaque démarrage du service SQL Writer (il peut même être journalisé deux fois par démarrage de service).

Dans l’ordre d’apparence, nous pouvons voir les informations suivantes :

  • Horodatage (date + heure) dans l’heure du serveur local et threadId provenant de l’entrée pour chaque ligne.
  • ProcessId du processus SQLWriter en cours de démarrage.
  • Le fait que le service a démarré en mode « normal » (ne s’exécutant pas en tant que WIDWriter) ou en mode base de données interne Windows.
  • La version des fichiers binaires de l’enregistreur SQL Writer.
  • Tous les paramètres définis par le SqlWriterConfig.ini fichier :
    • Le chemin cible du fichier journal actif
    • Niveau de détails du suivi, qui dans cet exemple est DEFAULT
    • Taille maximale du fichier avant la substitution, qui dans cet exemple est de 1 Mo
    • Option de ForceFlush toutes les mises à jour uniques du fichier journal et une approche plus détendue/mise en mémoire tampon, qui est False par défaut.
  • Un rappel indiquant que la journalisation a l’heure locale et le décalage UTC de cette heure locale.

Événement 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 est une opération VSS courante. Elle est déclenchée par la commande vssadmin list writers. La plupart des demandeurs VSS démarrent toutes les opérations de sauvegarde ou de restauration VSS par un événement OnIdentify.

Auparavant, seul le suivi du profileur actif permettait à DBA de détecter de ce type d’événement. Avec la nouvelle fonctionnalité de journalisation, chaque événement entraîne l’entrée ci-dessus.

Dans l’ordre d’apparition, nous pouvons voir que les informations suivantes sont journalisées :

  • Une mention explicite de l’événement VSS OnIdentify.
  • Liste de toutes les instances SQL Server actives (en cours d’exécution), ainsi que leur nom d’instance, leur version principale et leur édition.
  • L’indication que nous n’avons pas tenté de répertorier « Instances utilisateur » : une fonctionnalité SQL Server spécifique également appelée LocalDB et généralement non impliquée sur les serveurs de base de données d’entreprise.

Sauvegarde VSS en mode composant réussie

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

Cet événement génère un ensemble d’entrées plus important. Dans l’ordre d’apparence, nous pouvons voir les informations suivantes :

  • Une section OnIdentify complète, qui, comme indiqué, est souvent le fait d’une sauvegarde.
  • Mention de chaque phase VSS principale de la sauvegarde, avec le modèle « Entrée de SQL Writer xxxx ».
    • La première ici étant Entering SQL Writer OnPrepareBackup.
  • Entrée remarquable indiquant le début d’une sauvegarde VSS SQL
    • (ID étant le ThreadId qui effectue la journalisation pour cette tentative de sauvegarde dans SQLWriter)
  • API de sauvegarde VSS sélectionnée par le demandeur VSS, « component » ou « non-component / Volume »
  • Nombre de bases de données incluses dans la liste des composants envoyée par le demandeur VSS, ici une base de données unique (1).
  • Une confirmation que chaque nom de base de données fourni par le demandeur (ici « db_on_G ») est trouvé (ou introuvable) sur l’instance SQL Server avec laquelle il a été associé par le demandeur VSS (ici l’instance par défaut « GF19 »).
  • La version de la sauvegarde VSS demandée. Généralement VSS_BT_FULL ou VSS_BT_COPY. Consultez l’énumération VSS_BACKUP_TYPE.
  • Une autre section OnIdentify
  • Plus d’entrées identifiant les principales phases de la sauvegarde VSS (OnFreeze, OnThaw, OnPostSnapshot)
  • Une section OnIdentify finale.
  • Un rapport de phase VSS final, qui nomme un « événement de fermeture » utile : OnBackupComplete.

Ces entrées fournissent des détails sur les opérations VSS qui étaient auparavant difficiles à établir rapidement et qui nécessitaient un suivi avancé pour le faire. Un exemple est le mode « Component » ou « non-Component » d’une demande de sauvegarde VSS. Avec SQL Server 2019 (15.x) SQL Writer, ils sont enregistrés pour chaque requête VSS par défaut et sont facilement accessibles.

Situation d’échec : base de données déchirée

Pour illustrer l’instruction précédente que la journalisation SQL Writer complète l’architecture du journal des événements, examinons les entrées associées à une situation d’échec connue : une base de données déchirée. Ce scénario peut se produire lorsqu’une sauvegarde VSS tente de créer un ensemble d’instantanés de volumes qui incluent uniquement un ensemble partiel de fichiers d’une base de données donnée. L’enregistreur SQL Writer le bloque conformément aux conventions VSS.

Cet extrait est le contenu de SqlWriterLogger.txt pour l’opération :

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

À partir de SqlWriterLogger.txt nous voyons qu’un échec s’est produit, mais les seuls détails que nous avons sur l’échec sont les 0x80780002 HResult. Cette valeur est difficile à interpréter sans les références du code d’erreur. Elle identifie toutefois la situation de base de données déchirée.

Afficher le journal des événements

Nous allons maintenant vérifier le contenu des journaux des événements d’application 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’événement fournit un message mis en forme complet et convivial expliquant la situation.

L’infrastructure VSS du système d’exploitation signale également le problème dans les journaux d’événements, à l’aide de sa nomenclature (VSS gère les « composants », qui sont des « bases de données » dans le contexte 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

Le journal des événements est une meilleure source d’informations sur l’erreur elle-même. Toutefois, le contenu de SqlWriterLogger fournit des détails sur la demande de sauvegarde (VSS_BT_FULL, demande de sauvegarde VSS non-composant qui a échoué pendant la phase OnPrepareSnapshot de l’enregistreur SQL Writer). Toute investigation des erreurs VSS impliquant SQL Server doit donc collecter et examiner les deux sources.

Modifier les paramètres de journalisation SQL Writer

La journalisation de l’enregistreur SQL Writer peut être configurée en modifiant le fichier texte SqlWriterConfig.ini. Le fichier lui-même contient une description rapide des paramètres disponibles, que nous allons examiner ci-dessous.

Note

Le fichier .ini se trouve dans un dossier protégé par Windows (Fichiers de programme). En tant que tel, sa modification requiert des privilèges d’administrateur élevés. Un double-clic dans l’Explorateur ouvre le Bloc-notes sans élévation des privilèges : cela permet à l’utilisateur de lire le contenu, mais les tentatives d’enregistrement des modifications échouent. Démarrez le Bloc-notes en tant qu’administrateur, puis ouvrez SqlWriterConfig.ini, ou utilisez un éditeur de texte qui peut demander une élévation si nécessaire lors de l’enregistrement du fichier.

Commentaires sur la duplication du fichier SqlWriterConfig.ini :

Paramètre Options Description
EnableLogging - TRUE (valeur par défaut)
-FAUX		 Permet à l’utilisateur de désactiver toute la nouvelle fonctionnalité de journalisation, dans le cas peu probable où il est nécessaire.
TraceFile C:\Program Files\Microsoft SQL Server\90\Shared\SqlWriterLog.txt Permet à l’utilisateur de modifier le chemin d’accès et le nom du fichier de trace. Il n’est pas recommandé de le changer, car l’emplacement par défaut, bien connu facilite l’accès au bon endroit sur tout SQL Server.
Tracelevel - DEFAULT (par défaut)
- MINIMAL
-VERBOSE		 Détail de la journalisation. Pour plus d’informations, consultez les détails de TraceLevel.
TraceFileSizeMb 1 Mo (par défaut) Taille maximale du fichier avant la substitution. Le fichier .txt utilise l’encodage UTF-8 et utilise 2 octets par caractère. L’augmentation de cette valeur est valide, par exemple, avec une activité VSS intense, en conservant de longues périodes d’entrées de journal ou si les valeurs non par défaut TraceLevel sont activées pendant de longues durées. La valeur par défaut de 1 Mo doit fournir un historique suffisant pour la plupart des situations.
ForceFlush -VRAI
- FALSE (valeur par défaut)		 La définition de cette option TRUE ne serait utile que dans les rares cas où le service SQL Writer se bloque avant d’avoir la possibilité de vider ses dernières entrées de journal ; sinon, conservez la valeur par défaut.

Appliquer les changements

Toute modification apportée aux paramètres nécessite un redémarrage du service de l’enregistreur SQL Writer à des fins d’activation.

Astuce

Le redémarrage de SQL Writer est extrêmement rapide et peut être effectué à la fois, car SQL Writer ne conserve pas d’informations avec état ni n’a aucune activité entre les appels VSS. La seule précaution consiste à éviter un redémarrage lors d’une opération VSS (sauvegarde, restauration).

L’enregistreur SQL Writer signale les paramètres actifs dans son fichier journal lors du (re)démarrage, comme vous pouvez le voir dans l’exemple d’extraction Service Start.

Détails de TraceLevel

Le SqlWriterConfig.ini fichier répertorie les niveaux suivants :

Level Détail
DEFAULT Les paramètres de détail par défaut doivent être adéquats pour la plupart des besoins : reportez-vous à la section Révision des entrées de journalisation classiques pour observer ce qui est déjà généré par défaut. En plus des erreurs, les appels VSS réussis, ainsi que les métadonnées VSS, sont enregistrés par défaut.
MINIMAL Ce niveau conserve la mise en forme du DEFAULT mode et ses événements. Il génère également une sortie dans de nombreux emplacements clés du code. Plus particulièrement, il journalise tous les fichiers et toutes les itérations de base de données qui sont courants dans la logique SQLWriter. Cela peut augmenter le nombre d’entrées journalisées pour chaque opération VSS (y compris les événements OnIdentify courants) par une marge importante, en particulier sur les instances hébergeant un grand nombre de bases de données : chaque fichier physique unique de chaque base de données peut être signalé plusieurs fois au cours d’une sauvegarde VSS. Ce niveau permet de donner une idée plus précise de la position logique de la logique de l’enregistreur SQL Writer au moment de la défaillance. Il est également pratique à des fins d’exploration. Il n’est pas utile de le garder actif au-delà des enquêtes momentanaires, car le niveau de détails réduit considérablement la profondeur de l’historique de la taille de fichier par défaut de 1 Mo. L’augmentation de la valeur TraceFileSizeMb peut être pertinente.
VERBOSE Actuellement, ce niveau signale les mêmes événements que MINIMAL, mais préfixe chaque entrée avec des descripteurs d’objet et de méthodes de code source. Cela rend la sortie plus large (taille supérieure à la valeur Minimal) et moins lisible. Les informations ajoutées ne sont pas utiles en dehors des interactions avec les services de support Microsoft. Le même commentaire que MINIMAL s’applique : conserver ce niveau pendant une longue durée réduit la profondeur de l’historique de la taille de fichier par défaut de 1 Mo, et l’augmentation de la valeur TraceFileSizeMb peut s’avérer utile.

MINIMALet VERBOSE les niveaux ne fournissent pas de détails d’erreur supplémentaires en cas d’échec, seuls les détails de progression supplémentaires pour chaque opération de bas niveau liée aux activités sql Writer.

Étapes suivantes