Falling into a Rabbit Hole: A Story about One Varnish Reboot Error - Partie 1

ghostinushanka , après avoir battu les boutons pendant les 20 minutes précédentes, comme si sa vie en dépendait, se tourne vers moi avec une expression à moitié sauvage dans ses yeux et un sourire narquois - "Mec, je pense que je comprends."


"Regardez par ici", - dit en pointant sur l'un des symboles à l'écran - "Je parie sur mon chapeau rouge que si nous ajoutons ici ce que je viens de vous envoyer" - pointant sur un autre morceau de code - "l'erreur n'est plus s'affiche. "


Un peu perplexe et fatigué, je change l'expression sed sur laquelle nous travaillons depuis un certain temps, enregistre le fichier et systemctl varnish reload . Le message d'erreur a disparu ...


"Les mails que j'ai échangés avec le candidat", a poursuivi mon collègue, tandis que son sourire se transforme en un véritable sourire plein de joie, "J'ai soudain réalisé que c'est exactement le même problème!"


Comment tout a commencé


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


Le soleil brille à travers les fenêtres panoramiques sur une autre chaude matinée d'automne, la tasse de la boisson caféinée fraîchement préparée reste à l'écart du clavier, la symphonie de sons préférée dans les écouteurs, chevauchant le bruissement des claviers mécaniques, et le titre fatidique "Enquêter sur le vernis" brille de manière ludique la première entrée de la liste des billets en attente sur le tableau kanban. sh: echo: erreur d'E / S lors de la mise en scène »(recherchez« varnishreload sh: echo: erreur d'E / S »dans l'étape). Lorsqu'il s'agit de vernis, il n'y a pas d'erreurs et il ne peut y avoir de place, même si elles ne se traduisent par aucun problème, comme dans ce cas.


Pour ceux qui ne sont pas familiers avec varnishreload , il s'agit d'un simple script shell utilisé pour recharger une configuration de vernis - également appelée VCL.


Comme le nom du ticket l'indique, une erreur s'est produite sur l'un des serveurs de la scène, et comme j'étais sûr que le routage du vernis sur la scène fonctionne correctement, j'ai supposé que ce serait une erreur mineure. Donc, juste un message qui est entré dans un flux de sortie déjà fermé. Je prends le ticket pour moi, en toute confiance que je vais le marquer comme prêt en moins de 30 minutes, me tapoter l'épaule pour nettoyer la planche de la prochaine poubelle et revenir à des sujets plus importants.


S'écraser contre un mur à une vitesse de 200 km / h


Après avoir ouvert le fichier varnishreload , sur l'un des serveurs exécutant Debian Stretch, j'ai vu un script shell d'une longueur inférieure à 200 lignes.


Après avoir exécuté le script, je n'ai rien remarqué qui pourrait entraîner des problèmes lorsqu'il a été exécuté plusieurs fois directement à partir du terminal.


Au final, c'est une étape, même si elle casse, personne ne se plaindra, enfin ... pas trop. J'exécute le script et vois ce qui sera écrit sur le terminal, mais je ne vois aucune erreur.


Un couple de plus commence à m'assurer que je ne peux pas reproduire l'erreur sans effort supplémentaire, et je commence à comprendre comment changer ce script et à le faire quand même donner une erreur.


Un script peut-il remplacer STDOUT (en utilisant > &- )? Ou STDERR? Aucun des deux n'a donc fonctionné.


De toute évidence, systemd modifie en quelque sorte l'environnement de démarrage, mais comment et pourquoi?
Je coupe vim et édite varnishreload , en ajoutant set -x directement sous le shebang, en espérant que la sortie du script de débogage éclairera un peu.


Le fichier est corrigé, donc je redémarre le vernis et vois que le changement a tout cassé complètement ... L'échappement est un gâchis complet, dans lequel il y a des tonnes de code de type C. Même le défilement dans le terminal ne suffit pas pour trouver où il commence. Je suis complètement confus. Le mode débogage peut-il affecter le travail des programmes lancés dans un script? Non, un non-sens. Un bug dans le shell? Plusieurs scénarios possibles me traversent la tête comme des cafards dans différentes directions. Une tasse de boisson pleine de caféine s'est vidé instantanément, un rapide voyage dans la cuisine pour reconstituer le stock et ... c'est parti. J'ouvre le script et regarde le shebang: #!/bin/sh .


/bin/sh est simplement un lien symbolique bash, donc le script est interprété en mode compatible POSIX, non? Ça y était! Le shell par défaut dans Debian est dash, et c'est exactement ce à quoi /bin/sh fait référence .


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

Pour des raisons de test, j'ai changé le shebang en #!/bin/bash , supprimé set -x et réessayé. Enfin, lors du redémarrage ultérieur du vernis, une erreur tolérable 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' compiled 

Ligne 124, ça y est!


 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 # all this ceremony to handle blanks in 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 "failed to get the VCL file name" 129 fi 130 131 echo "$VCL_FILE" 132 } 

Mais il s'est avéré que la ligne 124 est assez vide et ne présente aucun intérêt. Je ne pouvais que supposer que l'erreur était survenue dans le cadre d'une ligne multiple commençant à la ligne 116.
Qu'est-ce qui est finalement écrit dans la variable VCL_FILE à la suite de l'exécution du sous-shell susmentionné?


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


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


La vcl.show -v utilisée pour sortir la configuration VCL entière spécifiée dans ${VCL_NAME} vers STDOUT.


Pour afficher la configuration VCL active actuelle, ainsi que plusieurs versions précédentes de configurations de routage de vernis qui sont toujours en mémoire, vous pouvez utiliser la 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} définie dans une autre partie du script varnishreload au nom de la VCL actuellement active, le cas échéant. Dans ce cas, ce sera «reload_20190101_120000_12397».


${VCL_SHOW} , la variable ${VCL_SHOW} contient la configuration complète du vernis, jusqu'à présent, c'est clair. Maintenant, j'ai finalement compris pourquoi la sortie du tiret avec set -x s'est avérée si cassée - elle comprenait le contenu de la configuration résultante.


Il est important de comprendre qu'une configuration VCL complète peut souvent être bricolée à partir de plusieurs fichiers. Les commentaires de style C sont utilisés pour déterminer où certains fichiers de configuration ont été inclus dans d'autres, et c'est exactement ce que représente la ligne entière d'extrait de code ci-dessous.
La syntaxe des commentaires décrivant les fichiers inclus a le format suivant:


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

Les nombres dans ce contexte ne sont pas importants, nous nous intéressons au nom du fichier.


Que se passe-t-il donc dans le marécage des équipes commençant à la ligne 116?
Voyons cela.
L'équipe se compose de quatre parties:


  1. Un echo simple qui affiche la valeur de la variable ${VCL_SHOW}
     echo "$VCL_SHOW" 
  2. awk , qui recherche une ligne (enregistrement), où le premier champ, après avoir rompu le texte, sera «//», et le second «VCL.SHOW».
    Awk écrira la première ligne correspondant à ces modèles, puis arrêtera immédiatement le traitement.
     awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}' 
  3. Un bloc de code qui stocke dans cinq valeurs de champs variables séparées par des espaces. La cinquième variable FILE obtient le reste de la chaîne. Enfin, le dernier écho écrit le contenu de la variable ${FILE} .
     { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" } 
  4. Comme toutes les étapes 1 à 3 sont enfermées dans un sous-shell, la sortie de la valeur $FILE sera écrite dans la variable VCL_FILE .

Comme il ressort du commentaire de la ligne 119, cela sert un seul objectif: gérer de manière fiable les cas où la VCL fera référence à des fichiers avec des caractères d'espace dans le nom.


J'ai commenté la logique de traitement d'origine pour ${VCL_FILE} et essayé de changer la séquence de commandes, mais cela n'a mené à rien. Tout a bien fonctionné pour moi, et dans le cas du démarrage du service, cela a donné une erreur.


Il semble que l'erreur ne soit tout simplement pas reproductible lorsque vous exécutez le script manuellement, alors que les 30 minutes attendues se sont déjà terminées six fois et, dans l'annexe, une tâche plus prioritaire est apparue, repoussant le reste des cas. Le reste de la semaine a été rempli de tâches diverses et n'a été que légèrement dilué avec un rapport sur sed et un entretien avec le candidat. Le problème avec l' varnishreload été irrémédiablement perdu dans les sables du temps.


Votre soi-disant sed-fu ... vraiment ... des ordures


La semaine suivante s'est avérée être une journée assez libre, j'ai donc décidé à nouveau de prendre ce billet. J'espérais que dans mon cerveau, un processus d'arrière-plan cherchait pendant tout ce temps une solution à ce problème, et cette fois, je comprends certainement de quoi il s'agit.


Depuis la dernière fois qu'un simple changement de code n'a pas aidé, j'ai juste décidé de le réécrire à partir de la 116ème ligne. En tout cas, le code existant était nul. Et il n'est absolument pas nécessaire d'utiliser read .


En regardant à nouveau l'erreur:
sh: echo: broken pipe - dans cette commande, l'écho est à deux endroits, mais je soupçonne que le premier est le coupable le plus probable (enfin, ou du moins un complice). Awk n'est pas non plus crédible. Et au cas où c'est vraiment awk | {read; echo} awk | {read; echo} awk | {read; echo} construction entraîne tous ces problèmes, pourquoi ne pas la remplacer? Cette commande d'une ligne n'utilise pas toutes les fonctionnalités de awk, et même cette read supplémentaire dans l'appendice.


Puisqu'il y avait un rapport sur sed la semaine dernière, je voulais essayer mes compétences nouvellement acquises et simplifier l' echo | awk | { read; echo} echo | awk | { read; echo} echo | awk | { read; echo} en un echo | sed plus compréhensible echo | sed echo | sed . Bien que ce ne soit certainement pas la meilleure approche pour détecter une erreur, j'ai pensé qu'au moins j'essaierais mon sed-fu et j'apprendrais peut-être quelque chose de nouveau sur le problème. Dans le processus, j'ai demandé à mon collègue, l'auteur du rapport sur sed, de m'aider à trouver un script sed plus efficace.


J'ai laissé tomber le contenu de varnishadm vcl.show -v "$VCL_NAME" dans le fichier, afin que je puisse me concentrer sur l'écriture d'un script sed sans aucun tracas associé au rechargement du service.


Une brève description de la façon dont sed gère l'entrée peut être trouvée dans son manuel GNU . Dans les sources sed, le caractère \n est explicitement spécifié comme séparateur de ligne.


En plusieurs passes et avec les recommandations de mon collègue, nous avons écrit un script sed qui a donné le même résultat que la ligne source entière 116.


Voici un exemple de fichier d'entrée:


 > cat vcl-example.vcl Text // VCL.SHOW 0 1578 file with 3 spaces.vcl More text // VCL.SHOW 0 1578 file.vcl Even more text // VCL.SHOW 0 1578 file with TWOspaces.vcl Final text 

Cela peut ne pas être évident à partir de la description ci-dessus, mais nous ne sommes intéressés que par le premier commentaire // VCL.SHOW , et il peut y en avoir plusieurs dans l'entrée. C'est pourquoi l'awk d'origine termine son travail après le premier match.


 #  ,      #   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 à ceci:


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

La logique ci-dessus peut être résumée comme suit:
Si la ligne correspond à l'expression régulière // VCL.SHOW , alors mangez avidement le texte qui inclut les deux nombres sur cette ligne et enregistrez tout ce qui reste après cette opération. Donnez la valeur enregistrée et terminez le programme.


C'est simple, non?


Nous avons été satisfaits du script sed et du fait qu'il remplace tout le code original. Tous mes tests ont donné les résultats escomptés, j'ai donc changé le «varnishreload» sur le serveur et exécuté à nouveau systemctl reload varnish . L' echo: write error: Broken pipe erreur sale echo: write error: Broken pipe encore ri dans nos visages. Un curseur clignotant attendait qu'une nouvelle commande soit entrée dans le vide sombre du terminal ...

Source: https://habr.com/ru/post/fr477968/


All Articles