Falling Down the Rabbit Hole: La història d'un error de reinici del vernís - Part 1

Ghostinushanka, després de colpejar els botons durant els 20 minuts anteriors com si la seva vida depengués d'això, es gira cap a mi amb una expressió semi salvatge als ulls i un somriure astut: "Amic, crec que ho entenc".

"Mira aquí", diu, assenyalant un dels personatges de la pantalla, "Aposto el meu barret vermell que si afegim aquí el que t'acabo d'enviar" - assenyalant una altra secció del codi - "l'error ja no és es mostrarà".

Una mica desconcertat i cansat, canvio la declaració sed en la qual hem estat treballant durant un temps, deso el fitxer i executo systemctl varnish reload. El missatge d'error ha desaparegut...

"Els correus electrònics que vaig intercanviar amb el candidat", va continuar el meu company, mentre el seu somriure es transforma en un somriure genuí ple d'alegria, "De sobte em vaig adonar que aquest és exactament el mateix problema!"

Com va començar tot

L'article suposa una comprensió de com funcionen bash, awk, sed i systemd. Es prefereix el coneixement del vernís, però no és obligatori.
S'han canviat les marques de temps dels fragments.
Escrit amb Ghostinushanka.
Aquest text és una traducció de l'original publicat en anglès fa dues setmanes; traducció boyikoden.

El sol brilla per les finestres panoràmiques en un altre matí càlid de tardor, una tassa de beguda amb cafeïna acabada de fer descansa al costat del teclat, una simfonia preferida de sons sona als auriculars sobre el soroll dels teclats mecànics i la primera entrada al teclat. la llista d'entrades enrere al tauler kanban brilla amb el fatídic títol "Investiga el vernishreload sh: echo: error I/O in staging" (Investiga "varnishreload sh: echo: I/O error" a la posada en escena). Pel que fa al vernís, no hi ha ni pot haver-hi errors, encara que no suposin cap problema, com en aquest cas.

Per a aquells que no ho coneguin càrrega de vernís, aquest és un script d'intèrpret d'ordres senzill utilitzat per tornar a carregar la configuració vernís - també anomenat VCL.

Tal com indica el títol del bitllet, l'error s'ha produït en un dels servidors de l'etapa i, com que estava segur que l'encaminament del vernís a l'etapa funcionava correctament, vaig suposar que seria un petit error. Per tant, només un missatge que va entrar en un flux de sortida ja tancat. Agafo un bitllet per mi mateix, amb la total confiança que el marcaré a punt en menys de 30 minuts, em donen cops a l'espatlla per netejar el tauler de la següent brossa i tornaré a coses més importants.

Xoc contra una paret a 200 km/h

Obrint un fitxer varnishreload, en un dels servidors amb Debian Stretch, vaig veure un script d'intèrpret d'ordres de menys de 200 línies.

En executar l'script, no vaig veure res que pogués causar problemes en executar-lo diverses vegades directament des del terminal.

Al cap i a la fi, això és una etapa, encara que es trenqui, ningú es queixarà, bé... no massa. Executo l'script i veig què s'escriurà al terminal, però els errors ja no són visibles.

Un parell d'execucions més per assegurar-me que no puc reproduir l'error sense un esforç addicional, i començo a esbrinar com canviar aquest script i fer que encara es produeixi un error.

Pot l'script bloquejar STDOUT (utilitzant > &-)? O STDERR? Cap dels dos va funcionar al final.

Òbviament, systemd canvia l'entorn d'execució d'alguna manera, però com i per què?
Encenc vim i edito varnishreload, afegint set -x just a sota del shebang, amb l'esperança que la depuració de la sortida de l'script faci una mica de llum.

El fitxer està arreglat, així que torno a carregar el vernís i veig que el canvi ho va trencar tot completament... L'escapament és un embolic complet, amb tones de codi semblant a C. Fins i tot desplaçar-se pel terminal no és suficient per trobar on comença. Estic completament confós. El mode de depuració pot afectar el treball dels programes executats en un script? Cap tonteria. Error a la closca? Diversos escenaris possibles estan volant al meu cap com paneroles en diferents direccions. Una tassa de beguda plena de cafeïna es buida a l'instant, un ràpid viatge a la cuina per reabastir-se i... anem-hi. Obro el guió i miro més de prop el shebang: #!/bin/sh.

/bin/sh - això és només un enllaç simbòlic bash, de manera que l'script s'interpreta en mode compatible amb POSIX, oi? No hi era! L'intèrpret d'ordres per defecte a Debian és dash, que és exactament el que es refereix /bin/sh.

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

Pel bé de la prova, vaig canviar el shebang per #!/bin/bash, eliminat set -x i ho va tornar a intentar. Finalment, en la recàrrega posterior del vernís, va aparèixer un error tolerable a la sortida:

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

Línia 124, aquí la teniu!

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 }

Però, segons va resultar, la línia 124 està més aviat buida i no té cap interès. Només podria suposar que l'error es va produir com a part d'una línia multilingüe que començava a la línia 116.
El que finalment s'escriu a la variable VCL_FILE com a resultat d'executar el subshell anterior?

Al principi, envia el contingut de la variable VLC_SHOW, creat a la línia 115, a la següent ordre a través de la canonada. I llavors què passa allà?

En primer lloc, fa servir varnishadm, que forma part del paquet d'instal·lació del vernís, per configurar el vernís sense reiniciar-lo.

subcomandament vcl.show -v s'utilitza per generar tota la configuració de VCL especificada a ${VCL_NAME}, a STDOUT.

Per mostrar la configuració de VCL activa actualment, així com diverses versions anteriors de les configuracions d'encaminament de vernis que encara es troben a la memòria, podeu utilitzar l'ordre varnishadm vcl.list, la sortida del qual serà similar a la següent:

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

Valor variable ${VCL_NAME} ambientat en una altra part del guió varnishreload al nom de la VCL activa actualment, si n'hi ha. En aquest cas serà "reload_20190101_120000_12397".

D'acord, variable. ${VCL_SHOW} conté la configuració completa per al vernís, fins ara clara. Ara finalment entenc per què la sortida del guió amb set -x va resultar tan trencat: incloïa el contingut de la configuració resultant.

És important entendre que sovint es pot combinar una configuració VCL completa a partir de diversos fitxers. Els comentaris d'estil C s'utilitzen per definir on s'ha inclòs un fitxer de configuració en un altre, i això és exactament del que tracta la següent línia de fragment de codi.
La sintaxi dels comentaris que descriuen els fitxers inclosos té el format següent:

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

Els números en aquest context no són importants, ens interessa el nom del fitxer.

Aleshores, què passa al pantà d'ordres que comença a la línia 116?
A veure.
La comanda consta de quatre parts:

  1. Senzill echo, que mostra el valor de la variable ${VCL_SHOW}
    echo "$VCL_SHOW"
  2. awk, que busca una línia (registre), on el primer camp, després de dividir el text, serà “//”, i el segon serà “VCL.SHOW”.
    Awk escriurà la primera línia que coincideixi amb aquests patrons i després deixarà de processar-se immediatament.

    awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'
  3. Un bloc de codi que emmagatzema els valors del camp en cinc variables, separades per espais. La cinquena variable FILE rep la resta de la línia. Finalment, l'últim eco escriu el contingut de la variable ${FILE}.
    { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }
  4. Com que tots els passos de l'1 al 3 estan tancats en un subshell, la sortida del valor $FILE s'escriurà en una variable VCL_FILE.

Tal com suggereix el comentari de la línia 119, això serveix per a l'únic propòsit de gestionar de manera fiable els casos en què la VCL es referirà a fitxers amb caràcters d'espai en blanc en els seus noms.

He comentat la lògica de processament original per ${VCL_FILE} i va intentar canviar la seqüència d'ordres, però no va conduir a res. Em va funcionar tot net i, en el cas d'iniciar el servei, va donar un error.

Sembla que l'error simplement no és reproduïble quan s'executa l'script manualment, mentre que els 30 minuts estimats ja han finalitzat sis vegades i, a més, ha aparegut una tasca de major prioritat, deixant de banda la resta de casos. La resta de la setmana es va omplir de diverses tasques i només es va diluir lleugerament amb una xerrada sobre sed i una entrevista amb el candidat. Problema d'error a varnishreload perdut irremeiablement en les sorres del temps.

La teva anomenada sed-fu... en realitat... escombraries

La setmana següent tenia un dia força lliure, així que vaig decidir tornar a agafar aquest bitllet. Esperava que al meu cervell, algun procés de fons durant tot aquest temps buscava una solució a aquest problema, i aquesta vegada definitivament entendré què passa.

Com que l'última vegada només canviar el codi no va ajudar, només vaig decidir reescriure'l a partir de la línia 116. En qualsevol cas, el codi existent era ximple. I no hi ha absolutament cap necessitat d'utilitzar read.

Tornant a mirar l'error:
sh: echo: broken pipe - en aquesta comanda, l'eco es troba a dos llocs, però sospito que el primer és el culpable més probable (bé, o almenys un còmplice). Awk tampoc inspira confiança. I per si realment ho és awk | {read; echo} el disseny comporta tots aquests problemes, per què no substituir-lo? Aquesta ordre d'una línia no utilitza totes les característiques d'awk, i fins i tot aquest extra read a l'apèndix.

Des de la setmana passada hi havia un informe sedVolia provar les meves habilitats recentment adquirides i simplificar echo | awk | { read; echo} en un més entenedor echo | sed. Tot i que definitivament no és el millor enfocament per detectar l'error, vaig pensar que almenys provaria el meu sed-fu i potser aprendria alguna cosa nova sobre el problema. Durant el camí, vaig demanar al meu col·lega, l'escriptor sed talk, que m'ajudés a crear un guió sed més eficient.

Vaig deixar caure el contingut varnishadm vcl.show -v "$VCL_NAME" a un fitxer perquè em pugui centrar a escriure l'script sed sense la molèstia de reiniciar el servei.

Es pot trobar una breu descripció de com el sed gestiona l'entrada el seu manual GNU. A les fonts sed, el símbol n especificat explícitament com a separador de línies.

En diverses passades, i amb l'assessorament del meu company, vam escriure un guió sed que va donar el mateix resultat que tota la línia original 116.

A continuació es mostra un fitxer de mostra amb dades d'entrada:

> 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

Potser no és obvi a la descripció anterior, però només ens interessa el primer comentari // VCL.SHOW, i pot haver-ne diversos a les dades d'entrada. És per això que l'awk original finalitza després del primer partit.

# шаг первый, вывести только строки с комментариями
# используя возможности 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

Així, el contingut de l'script de càrrega de vernis tindria un aspecte semblant a això:

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

La lògica anterior es pot resumir de la següent manera:
Si la cadena coincideix amb l'expressió regular // VCL.SHOW, després devoreu amb avidesa el text que inclou els dos números en aquesta línia i deseu el que quedi després d'aquesta operació. Emet el valor emmagatzemat i finalitza el programa.

Simple, no?

Estem contents amb l'script sed i el fet que substitueix tot el codi original. Totes les meves proves van donar els resultats desitjats, així que vaig canviar el "varnishreload" al servidor i vaig tornar a executar-me systemctl reload varnish. Error brut echo: write error: Broken pipe va tornar a riure a la nostra cara. Un cursor que feia l'ullet esperava que s'introduïs una nova ordre al buit fosc del terminal...

Font: www.habr.com

Afegeix comentari