Down the Rabbit Hole: A Story of One varnishreload Error - partie 1

Après avoir appuyé sur les boutons du clavier pendant les 20 dernières minutes, comme s'il tapait pour sa vie, ghostinushanka se tourne vers moi avec un regard à moitié fou dans les yeux et un sourire malicieux: «Mec, je pense que je l'ai.


Regardez ça »- comme il pointe vers l'un des personnages à l'écran -« Je parie mon chapeau rouge que si nous ajoutons ce que je viens de vous envoyer ici »- comme il pointe vers un autre endroit dans le code -« il y aura plus d'erreur. "
Légèrement perplexe et fatigué, je modifie l'expression sed que nous essayons de comprendre depuis un certain temps maintenant, enregistre le fichier et systemctl varnish reload . Message d'erreur disparu ...


"Ces e-mails que j'ai échangés avec le candidat", poursuit mon collègue, alors que son sourire se transforme en un sourire large et authentique, "Cela m'a soudainement frappé que c'est exactement le même problème!"


Comment tout a commencé


Cet article suppose une certaine familiarité avec bash, awk et systemd. Une certaine connaissance du vernis est bénéfique, mais pas obligatoire.
Les horodatages des exemples de fragments ont été supprimés.
Co-écrit avec ghostinushanka .


Le soleil brille à travers les fenêtres murales sur une autre chaude matinée d'automne, une tasse de liquide caféiné fraîchement moulu se trouve sur le côté du clavier, des écouteurs vocalisent la symphonie bien-aimée des sons couvrant le bruissement des claviers mécaniques autour et la première entrée dans le carnet de commandes sur le tableau kanban affiche de façon ludique le titre du ticket fatidique «Enquêter sur le vernis de rechargement sh: echo: I/O error lors de la mise en scène». Chaque fois que le vernis est concerné, il n'y a pas de place pour l'erreur (s), même si celui-ci en particulier ne semble pas causer de problèmes réels.


Pour ceux d'entre vous qui ne connaissent pas le rechargement de vernis , il s'agit simplement d'un script shell utilisé pour recharger la configuration - également appelée VCL - du serveur de mise en cache Varnish .


Comme l'indique le titre du ticket, l'erreur a été rencontrée sur l'une des machines de transfert et j'étais presque sûr que le routage Varnish fonctionne dans l'environnement de transfert, donc je suppose que cela doit être un problème mineur. Juste un message de sortie convivial écrit dans un flux fermé. J'attrape le ticket, croyant fermement que je pourrai le marquer résolu en moins de 30 minutes, me tapoter dans le dos pour effacer une autre tâche banale et revenir à des choses plus importantes.


Frapper le mur à 200 km / h


En ouvrant le fichier varnishreload sur l'un des serveurs affectés fonctionnant sur Debian Stretch, je trouve un script shell de moins de 200 lignes. En le lisant brièvement, je ne vois rien de dangereux qui m'empêcherait d'exécuter le script depuis le terminal encore et encore. Après tout, c'est de la mise en scène, même si ça casse, personne ne va se plaindre, enfin ... pas trop, c'est. Je lance le script et observe, seulement pour découvrir qu'il n'y a pas d'erreurs à voir. Quelques exécutions répétées supplémentaires pour m'assurer raisonnablement que je ne peux pas reproduire l'erreur sans effort supplémentaire et je commence à concevoir des plans pour modifier et plier l'environnement du script. La fermeture de STDOUT pour le script (avec > &- ) aide-t-elle quelque chose? Ou stderr? Ni l'un ni l'autre.


De toute évidence, systemd perturbe l'environnement d'une manière ou d'une autre, mais comment et ... pourquoi? Je varnishreload vim et varnishreload le varnishreload du système, en ajoutant set -x juste sous le shebang, en espérant que la sortie détaillée de l'exécution du script éclairera la lumière.


Le fichier est corrigé, donc je recharge le vernis, seulement pour voir que le changement avait complètement cassé le script ... La sortie est un désordre complet affichant des tonnes de code de style C et le tampon de défilement par défaut ne suffit pas pour trouver d'où il vient. Je me sens confus. La définition de l'option de débogage pour le script shell peut-elle interrompre le programme qu'il appelle? Non, c'est impossible. Un bug dans le shell? Plusieurs scénarios possibles fonctionnant de manière extravagante dans différentes directions dans mon esprit. Une tasse de boisson caféinée est finie instantanément, voyage rapide à la cuisine pour une recharge et c'est reparti. J'ouvre le fichier et regarde attentivement le shebang: #!/bin/sh .


Mais /bin/sh n'est sûrement qu'un lien symbolique vers bash, de sorte que le script est interprété en mode compatible POSIX, non? Faux! Le shell non interactif par défaut sur Debian est dash, et c'est exactement ce vers quoi /bin/sh pointe .


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

Ne serait-ce que pour le débogage, j'ai changé le shebang en #!/bin/bash , supprimé l' set -x et réessayé. Enfin, une erreur de sortie raisonnable de la prochaine recharge de vernis:


 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, maintenant nous parlons!


 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'avère que la ligne 124 est assez calme. Je ne pouvais que supposer que l'erreur avait été produite dans le cadre de la commande multiligne exécutée à la ligne 116.


Alors, que produit le sous-shell ci-dessus pour stocker dans la variable VCL_FILE ? Dans la première partie, il envoie le contenu de la variable VCL_SHOW créée sur la ligne 115 dans le tube. Que se passe-t-il alors?


Tout d'abord, il utilise varnishadm , qui est une partie standard d'une installation de Varnish utilisée pour configurer Varnish sans avoir à le redémarrer. La sous-commande vcl.show -v est utilisée pour imprimer la totalité de la configuration VCL spécifiée par ${VCL_NAME} sur STDOUT.


Pour afficher la configuration VCL active actuelle ainsi que plusieurs versions précédentes du routage de vernis qui sont toujours en mémoire, vous pouvez utiliser une autre commande varnishadm vcl.list , dont la sortie serait similaire à la suivante:


 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 variable ${VCL_NAME} est définie ailleurs dans le script varnishreload au nom de la VCL actuellement active, le cas échéant. Dans ce cas, ce serait "reload_20190101_120000_12397".


Génial, donc ${VCL_SHOW} contient maintenant une configuration complète pour Varnish, assez facile jusqu'à présent. Maintenant, j'ai finalement compris pourquoi la sortie du tableau de bord avec set -x semblait être si cassée - elle comprenait le contenu de la configuration de vernis résultante.


L'important ici est que la configuration VCL complète peut souvent être épissée à partir de plusieurs fichiers. Les commentaires de style C sont utilisés pour délimiter où les fichiers de configuration ont été inclus dans d'autres fichiers de configuration, ce qui correspond exactement à la ligne suivante de l'extrait de code.


La syntaxe des commentaires dénotant un fichier a le format suivant


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

Les chiffres ne sont pas importants ici, ce qui nous intéresse, c'est le nom du fichier.


Alors, que se passe-t-il dans le monde des commandes commençant à la ligne 116?
Choisissons-le à part.
La commande comprend quatre parties:


  1. Un echo simple qui ${VCL_SHOW} la valeur de ${VCL_SHOW}
     echo "$VCL_SHOW" 
  2. awk qui recherche une ligne (enregistrement) où le premier champ est '//' et le second est "VCL.SHOW".
    Awk est invité à imprimer la première ligne correspondant à ces modèles, puis à arrêter immédiatement le traitement.
     awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}' 
  3. Un bloc de code qui lit dans les champs délimités par des espaces en cinq variables. La cinquième variable FILE obtient le reste de la ligne. Enfin, un dernier écho imprime le contenu de la variable ${FILE} .
     { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }. 
  4. Comme les étapes 1 à 3 sont toutes enfermées dans un sous-shell, la sortie de $FILE se retrouvera dans la variable VCL_FILE .

Comme le commentaire de la ligne 119 le suggère, cette façon de faire sert un seul objectif: gérer de manière fiable le cas où VCL ferait référence à des noms de fichiers avec des espaces.


J'ai commenté la logique de traitement d'origine pour le ${VCL_FILE} et essayé de modifier la chaîne de commandes mais sans fin raisonnable. Tout fonctionnait dans ma coquille mais jamais lorsqu'il était exécuté en tant que service.


Il semble que l'erreur ne soit pas du tout reproductible lorsqu'elle est exécutée par moi - pendant ce temps, les 30 minutes estimées se sont écoulées six fois et une nouvelle tâche hautement prioritaire a tout mis de côté. Le reste de la semaine a été assez chargé avec différentes tâches, les deux exceptions étant un entretien interne que notre équipe a eu sur l'utilisation de sed et un entretien avec un candidat prometteur. Le problème de la disparition de l'erreur de varnishreload été complètement perdu dans le temps.


Votre soi-disant sed-fu ... est vraiment ... assez pathétique


L'un des jours de la semaine qui a suivi était assez libre, j'ai donc repris la tâche. J'avais espéré que peut-être un processus d'arrière-plan dans mon cerveau réduisait encore le problème et je serais enfin en mesure de le résoudre.


Étant donné que le fait de plier le code la dernière fois n'a pas aidé, j'ai simplement opté pour une réécriture de la ligne 116. Le code existant était fou, de toute façon. Il n'est absolument pas nécessaire d'utiliser read ici.


En regardant à nouveau l'erreur:
sh: echo: broken pipe - l'écho est à deux endroits dans cette commande, mais je soupçonne que le tout premier est un coupable plus probable (ou un complice). Awk n'inspire pas non plus confiance. Eh bien, au cas où ce serait vraiment l' awk | {read; echo} awk | {read; echo} construction awk | {read; echo} causant tous ces problèmes, pourquoi ne pas utiliser autre chose? Awk n'est pas vraiment utilisé à ses pleines capacités sur ce one-liner et puis il y a ce surplus de read .


Voyant que nous avons eu une discussion interne sur sed l'autre semaine, j'ai voulu essayer mes compétences nouvellement acquises et optimiser l' echo | awk | { read; echo } echo | awk | { read; echo } echo | awk | { read; echo } en un echo | sed plus simple echo | sed echo | sed . Bien que ce ne soit certainement pas la bonne façon d'aborder le débogage, j'ai pensé au moins essayer mon sed-fu et peut-être apprendre quelque chose de nouveau sur le problème dans le processus. Dans le processus, j'ai demandé à mon collègue - l'auteur de la conférence sed - de m'aider à trouver une commande sed plus efficace.


J'ai vidé le varnishadm vcl.show -v "$VCL_NAME" dans un fichier, afin que je puisse me concentrer sur l'écriture de sed sans tous les tracas liés aux rechargements de service.


Une brève introduction sur la façon exacte dont sed traite les entrées 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.


Après plusieurs itérations et contributions de mon collègue, nous avons créé une expression sed qui a produit exactement le même résultat que la ligne 116 d'origine.


Créons ici 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 apparent à 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 en entrée. C'est exactement pourquoi awk se ferme après le premier match.


 # step 1, capture just the comment lines # using sed capability to specify delimiter character with '\#' instead of the commonly used '/' so there is no need to escape slashes themselves # and the “address” capability defined as regex “// VCL.SHOW” to search for lines with specific pattern # -n flag makes sure that the sed does not print all as it does by default (see above link) # -E switches to the extended regex > 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 # step 2, only print out the file name # using the “substitute” command with regex capture groups to print just that group # and this is done only for the matches of the previous search > 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 # step 3, make sure to only get the first result # same as with the awk before, add an immediate exit after the first processed match is printed > 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 # step 4, wrap it up into a one-liner using the colon to separate commands > 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 ressemblerait à ceci:


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

La logique ci-dessus peut s'exprimer succinctement par:
si une ligne correspond à l'expression // VCL.SHOW , alors // VCL.SHOW correspondre avec avidité le texte, y compris les deux nombres sur cette ligne et capturez tout ce qui vient après. Emettez la capture et quittez.


C'est simple, non?


Nous étions satisfaits du script sed et du fait que le code d'origine qu'il remplace, tous les tests que j'ai effectués ont produit les résultats souhaités.J'ai donc modifié le varnishreload de varnishreload sur le serveur et tiré à nouveau le systemctl reload varnish . L' echo: write error: Broken pipe redouté echo: write error: Broken pipe souriait au visage. Le curseur clignotant attendait une nouvelle entrée de commande dans le vide sombre du terminal ...

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


All Articles