Plongée dans le terrier du lapin : Une histoire sur une erreur de redémarrage de varnish - partie 1

ghostinushanka, tapotant sur les boutons pendant les 20 dernières minutes comme si sa vie en dépendait, il se retourne vers moi avec une expression à moitié sauvage dans les yeux et un sourire sournois — «Mec, je crois que j'ai compris.»

«Regarde ici,» dit-il en montrant un des symboles à l'écran — «Parie ma casquette rouge que si nous ajoutons ici ce que je viens de t'envoyer» — montrant une autre partie du code — «l'erreur ne s'affichera plus.»

Un peu perplexe et fatigué, je modifie l'expression sed sur laquelle nous avons travaillé un moment, sauvegarde le fichier et exécute systemctl varnish reload. Le message d'erreur a disparu...

«Les emails que j'ai échangés avec le candidat,» continua mon collègue, tandis que son sourire se transforme en un sourire authentique plein de joie, «je me suis soudain rendu compte que c'était exactement le même problème!»

D'où tout cela avait-il commencé

Cet article suppose une compréhension des principes de fonctionnement de bash, awk, sed et systemd. La connaissance de varnish est bienvenue, mais n'est pas obligatoire.
Les horodatages dans les extraits ont été modifiés.
Écrit en collaboration avec ghostinushanka.
Ce texte est une traduction de l'original publié en anglais il y a deux semaines ; traduction boikoden.

Le soleil filtre à travers les fenêtres panoramiques lors d'une autre chaude matinée d'automne, une tasse de café fraîchement préparé repose à côté du clavier, dans les écouteurs joue ma symphonie préférée des sons, couvrant le bruit des claviers mécaniques, et le premier enregistrement dans la liste des tickets du backlog sur le tableau Kanban brille avec le titre déterminant "Investigate varnishreload sh: echo: I/O error in staging" (Enquêter sur "varnishreload sh: echo: I/O error" dans la mise en scène). Quand il s'agit de varnish, il n'y a pas de place pour les erreurs, même si elles ne se transforment pas en problèmes comme c'est le cas ici.

Pour ceux qui ne sont pas familiers avec varnishreload, c'est un simple script shell utilisé pour recharger la configuration de varnish — également appelée VCL.

Comme l'indique le titre du ticket, l'erreur s'est produite sur l'un des serveurs en stage, et comme j'étais convaincu que le routage de Varnish fonctionnait correctement en stage, j'ai supposé qu'il s'agissait d'un petit bug. Juste un message entré dans un flux de sortie déjà fermé. Je prends le ticket, convaincu que je vais le marquer comme résolu dans moins de 30 minutes, me félicitant d’avoir nettoyé le tableau de ce nouveau déchets et revenant à des tâches plus importantes.

En percutant un mur à 200 km/h

En ouvrant le fichier varnishreload, sur l'un des serveurs sous Debian Stretch, j'ai trouvé un script shell de moins de 200 lignes.

En parcourant le script, je n'ai rien remarqué qui pourrait provoquer des problèmes lors de son exécution répétée directement dans le terminal.

Après tout, c'est un stage, même s'il tombe en panne, personne ne se plaignera, enfin... pas trop. J'exécute le script et regarde ce qui va s'afficher dans le terminal, mais il n'y a déjà plus d'erreurs.

Encore quelques exécutions pour m'assurer que je ne peux pas reproduire l'erreur sans efforts supplémentaires, et je commence à réfléchir à comment modifier ce script pour qu'il génère finalement une erreur.

Peut-être devrais-je rediriger STDOUT (avec > &-)? Ou STDERR? Aucun des deux n'a finalement fonctionné.

Évidemment, systemd change d'une manière ou d'une autre l'environnement d'exécution, mais comment, et pourquoi ?
J'ouvre vim et édite varnishreload, ajoutant set -x juste sous le shebang, en espérant que la sortie de débogage du script apporte un peu de clarté.

Le fichier est corrigé, donc je redémarre Varnish et je vois que le changement a complètement tout cassé... La sortie est un véritable désastre, remplie de tonnes de code semblable à C. Même le défilement dans le terminal n'est pas suffisant pour trouver où ça commence. Je suis complètement perdu. Le mode débogage peut-il affecter le fonctionnement des programmes lancés dans le script ? Non, c'est absurde. Un bug dans le shell ? Plusieurs scénarios possibles se précipitent dans ma tête comme des cafards dans toutes les directions. Ma tasse de caféine est vide en un instant, je fais un rapide voyage à la cuisine pour faire le plein et... c'est parti. J'ouvre le script et j'examine le shebang : #!/bin/sh.

/bin/sh — c'est juste un symlink vers bash, donc le script est interprété en mode compatible POSIX, n'est-ce pas ? Pas si sûr ! Le shell par défaut dans Debian est dash, et c'est exactement ce sur quoi fait référence à /bin/sh.

# ls -l /bin/sh
lrwxrwxrwx 1 root root 4 Jan 24  2017 /bin/sh -> dash

Pour l'essai, j'ai modifié le shebang en #!/bin/bash, supprimé set -x et j'ai essayé encore une fois. Enfin, lors du redémarrage suivant de varnish, une erreur convenable est apparue dans la sortie :

Jan 01 12:00:00 hostname varnishreload[32604]: /usr/sbin/varnishreload: line 124: echo: write error: Broken pipe
Jan 01 12:00:00 hostname varnishreload[32604]: VCL 'reload_20190101_120000_32604' compilé

Ligne 124, voilà !

114 find_vcl_file() {
115         VCL_SHOW=$(varnishadm vcl.show -v "$VCL_NAME" 2>&1) || :
116         VCL_FILE=$(
117                 echo "$VCL_SHOW" |
118                 awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}' | {
119                         # toute cette cérémonie pour gérer les espaces dans FILE
120                         read -r DELIM VCL_SHOW INDEX SIZE FILE
121                         echo "$FILE"
122                 }
123         ) || :
124
125         if [ -z "$VCL_FILE" ]
126         then
127                 echo "$VCL_SHOW" >&2
128                 fail "échec pour obtenir le nom du fichier VCL"
129         fi
130
131         echo "$VCL_FILE"
132 }

Mais il s'est avéré que la ligne 124 est plutôt vide et n'est pas intéressante. Je n'ai pu que supposer que l'erreur est survenue comme partie d'une chaîne multiple, commençant à la ligne 116.
Qu'est-ce qui est finalement enregistré dans la variable VCL_FILE résultant de l'exécution du sous-shell mentionné ci-dessus ?

Au départ, il envoie le contenu de la variable VLC_SHOW, créée à la ligne 115, à la commande suivante via un pipe. Et que se passe-t-il alors ?

Tout d'abord, il utilise varnishadm, qui fait partie du paquet d'installation de varnish, pour configurer varnish sans redémarrer.

La sous-commande vcl.show -v est utilisée pour afficher toute la configuration VCL indiquée dans ${VCL_NAME}, en STDOUT.

Pour afficher la configuration VCL active actuelle, ainsi que plusieurs versions précédentes des configurations de routage de varnish encore en mémoire, vous pouvez utiliser la commande varnishadm vcl.list, dont la sortie sera similaire à celle ci-dessous :

discarded   cold/busy       1 reload_20190101_120000_11903
discarded   cold/busy       2 reload_20190101_120000_12068
discarded   cold/busy       16 reload_20190101_120000_12259
discarded   cold/busy       16 reload_20190101_120000_12299
discarded   cold/busy       28 reload_20190101_120000_12357
active      auto/warm       32 reload_20190101_120000_12397
available   auto/warm       0 reload_20190101_120000_12587

La valeur de la variable ${VCL_NAME} est définie dans une autre partie du script varnishreload au nom de l'actuel VCL actif, si disponible. Dans ce cas, ce sera “reload_20190101_120000_12397”.

Bien, la variable ${VCL_SHOW} contient la configuration complète pour varnish, cela semble clair. Maintenant, j'ai enfin compris pourquoi la sortie du dash avec set -x était si corrompue — elle incluait le contenu de la configuration résultante.

Il est important de comprendre que la configuration complète de VCL peut souvent être assemblée à partir de plusieurs fichiers. Les commentaires au style C sont utilisés pour déterminer où un fichier de configuration est inclus dans un autre, et c'est précisément le sujet de la ligne fragmentée de code ci-dessous.
La syntaxe des commentaires décrivant les fichiers inclus a le format suivant :

// VCL.SHOW <NUM> <NUM> <FILENAME>

Les chiffres dans ce contexte ne sont pas importants, nous sommes intéressés par le nom du fichier.

Que se passe-t-il donc dans le marécage de commandes, à partir de la ligne 116 ?
Décomposons cela.
La commande se compose de quatre parties :

  1. Simple echo, qui affiche la valeur de la variable ${VCL_SHOW}
    echo "$VCL_SHOW"
  2. awk, qui cherche une ligne (enregistrement) où le premier champ, après division du texte, sera "//", et le second sera "VCL.SHOW".
    Awk imprimera la première ligne correspondant à ces modèles et cessera immédiatement le traitement.
    awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'
  3. Un bloc de code qui stocke dans cinq variables les valeurs des champs séparés par des espaces. La cinquième variable FILE reçoit le reste de la ligne. Enfin, le dernier echo affiche le contenu de la variable ${FILE}.
    { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }
  4. Étant donné que toutes les étapes de 1 à 3 sont contenues dans un sous-shell, la sortie de la valeur $FILE sera enregistrée dans la variable VCL_FILE.

Comme le mentionne le commentaire à la ligne 119, cela a un seul objectif : gérer les cas où VCL fait référence à des fichiers avec des espaces dans les noms.

J'ai commenté la logique de traitement d'origine pour ${VCL_FILE} et j'ai essayé de changer l'ordre des commandes, mais cela n'a rien donné. Tout fonctionnait bien pour moi, mais en cas de démarrage du service, une erreur apparaissait.

Il semble que l'erreur ne soit tout simplement pas reproductible lors de l'exécution du script manuellement, avec les supposés 30 minutes ayant déjà pris fin plusieurs fois, et en plus, une tâche plus prioritaire a décalé les autres à l'écart. Le reste de la semaine a été rempli de diverses tâches, légèrement agrémentées d'un rapport sur sed et d'un entretien avec un candidat. Le problème d'erreur dans varnishreload a été irrémédiablement perdu dans les sables du temps.

Votre prétendu sed-fu… est en réalité… de la camelote.

La semaine prochaine, j'ai eu un jour plutôt libre, donc j'ai décidé de m'attaquer à ce ticket encore une fois. J'espérais qu'un processus en arrière-plan dans mon cerveau avait cherché une solution tout ce temps et que cette fois-ci, je comprendrais exactement de quoi il s'agit.

Puisque la dernière fois, un simple changement de code n'a pas fonctionné, j'ai simplement décidé de le réécrire à partir de la ligne 116. De toute façon, le code existant était quelque peu fou. Il n'y a absolument aucune nécessité d'utiliser read.

En regardant l'erreur encore une fois :
sh: echo: pipe cassé — dans cette commande echo, il apparaît à deux endroits, mais je soupçonne que le premier est le coupable le plus probable (ou au moins un complice). Awk ne semble également pas fiable. Et au cas où cela serait vraiment le cas awk | {read; echo} si cette construction cause tous ces problèmes, pourquoi ne pas la remplacer ? Cette commande en une ligne n’exploite pas toutes les capacités d’awk, et il y a de plus ce surplus read .

Puisque la semaine dernière il y a eu une présentation sur sed, je voulais essayer mes compétences récemment acquises et simplifier echo | awk | { read; echo} en quelque chose de plus compréhensible echo | sed. Bien que ce ne soit certainement pas la meilleure approche pour identifier l'erreur, j'ai pensé que je pourrais au moins essayer mon sed-fu et peut-être apprendre quelque chose de nouveau sur le problème. En cours de route, j'ai demandé à un collègue, l'auteur de la présentation sur sed, de m'aider à créer un script sed plus efficace.

J'ai envoyé le contenu varnishadm vcl.show -v "$VCL_NAME" dans un fichier, afin que je puisse me concentrer sur l'écriture du script sed sans soucis liés aux redémarrages de service.

Une brève description de la manière dont sed traite les entrées se trouve dans son manuel GNU. Dans le code source de sed, le caractère n est clairement indiqué comme séparateur de lignes.

Avec plusieurs passages et avec les recommandations de mon collègue, nous avons écrit un script sed qui produisait le même résultat que toute la chaîne d'origine à la ligne 116.

Voici un exemple de fichier avec les données d'entrée :

> cat vcl-example.vcl
Texte
// VCL.SHOW 0 1578 fichier avec 3 espaces.vcl
Plus de texte
// VCL.SHOW 0 1578 fichier.vcl
Encore plus de texte
// VCL.SHOW 0 1578 fichier avec DEUXespaces.vcl
Texte final

Cela peut ne pas être évident à partir de la description ci-dessus, mais nous ne nous intéressons qu'au premier commentaire // VCL.SHOW, et dans les données d'entrée, il peut y en avoir plusieurs. C'est pourquoi l'original awk termine son exécution après la première correspondance.

# шаг первый, вывести только строки с комментариями
# используя возможности sed, определяется символ-разделитель с помощью конструкции '#' вместо обычно используемого '/', за счёт этого не придётся экранировать косые в искомом комментарии
# определяется регулярное выражение “// VCL.SHOW”, для поиска строк с определенным шаблоном
# флаг -n позаботится о том, чтобы sed не выводил все входные данные, как он это делает по умолчанию (см. ссылку выше)
# -E позволяет использовать расширенные регулярные выражения
> cat vcl-processor-1.sed
#// VCL.SHOW#p
> sed -En -f vcl-processor-1.sed vcl-example.vcl
// VCL.SHOW 0 1578 file with 3 spaces.vcl
// VCL.SHOW 0 1578 file.vcl
// VCL.SHOW 0 1578 file with TWOspaces.vcl

# шаг второй, вывести только имя файла
# используя команду “substitute”, с группами внутри регулярных выражений, отображается только нужная группa
# и это делается только для совпадений, ранее описанного поиска
> cat vcl-processor-2.sed
#// VCL.SHOW# {
    s#.* [0-9]+ [0-9]+ (.*)$#1#
    p
}
> sed -En -f vcl-processor-2.sed vcl-example.vcl
file with 3 spaces.vcl
file.vcl
file with TWOspaces.vcl

# шаг третий, получить только первый из результатов
# как и в случае с awk, добавляется немедленное завершения после печати первого найденного совпадения
> cat vcl-processor-3.sed
#// VCL.SHOW# {
    s#.* [0-9]+ [0-9]+ (.*)$#1#
    p
    q
}
> sed -En -f vcl-processor-3.sed vcl-example.vcl
file with 3 spaces.vcl

# шаг четвертый, схлопнуть всё в однострочник, используя двоеточия для разделения команд
> sed -En -e '#// VCL.SHOW#{s#.* [0-9]+ [0-9]+ (.*)$#1#p;q;}' vcl-example.vcl
file with 3 spaces.vcl

Ainsi, le contenu du script varnishreload ressemblera à peu près à ceci :

VCL_FILE="$(echo "$VCL_SHOW" | sed -En '#// VCL.SHOW#{s#.*[0-9]+ [0-9]+ (.*)$#1#p;q;};')"

La logique ci-dessus peut être exprimée brièvement comme suit :
Si la chaîne correspond à l'expression régulière // VCL.SHOW, alors consommez avidement le texte contenant les deux nombres dans cette chaîne, et conservez tout ce qui reste après cette opération. Renvoie la valeur conservée et termine le programme.

C'est simple, n'est-ce pas ?

Nous étions satisfaits du script sed et du fait qu'il remplace tout le code original. Tous mes tests ont produit les résultats souhaités, donc j'ai modifié “varnishreload” sur le serveur et relancé systemctl reload varnish. Une erreur pourrie echo : erreur d'écriture : Pipe brisé se moquait de nous à nouveau. Le curseur clignotant attendait une nouvelle commande dans l'obscurité du terminal…

Source : habr.com

Acheter un hébergement fiable pour les sites avec protection DDoS, serveurs VPS VDS 🔥 Acheter un hébergement fiable pour les sites avec protection DDoS, serveurs VPS VDS | ProHoster