Cădere într-un vizuina de iepure: O poveste despre o eroare de repornire varnish — partea 1

ghostinushanka, apăsând butoanele timp de 20 de minute, ca și cum viața lui ar depinde de asta, se întoarce către mine cu o expresie semi-sălbatică în ochi și un zâmbet viclean – „Fraer, cred că am înțeles.”

„Uită-te aici,” – spune, arătând spre un simbol de pe ecran – „Pariez pe pălăria mea roșie că dacă vom adăuga aici ceea ce ți-am trimis mai devreme” – arătând spre o altă porțiune de cod – „eroarea nu va mai apărea.”

Puțin derutat și obosit, îmi schimb expresia sed pe care o foloseam de ceva timp, salvează fișierul și pornesc systemctl varnish reload. Mesajul de eroare a dispărut…

„Emailurile cu care am comunicat cu candidatul,” a continuat colegul meu, în timp ce zâmbetul său se transforma într-un zâmbet sincer plin de bucurie, „m-a lovit brusc că era exact aceeași problemă!”

De unde a început totul

Articolul presupune înțelegerea principiilor de funcționare a bash, awk, sed și systemd. Cunoașterea varnish este binevenită, dar nu este obligatorie.
Timestamp-urile din snippet-uri au fost modificate.
Scris împreună cu ghostinushanka.
Acest text este o traducere a originalului publicat în limba engleză acum două săptămâni; traducerea boikoden.

Soarele străbate prin feronerie panoramice într-o altă dimineață caldă de toamnă, o ceașcă de cafea proaspăt preparată și bogată în cofeină stă lângă tastatură, iar în căști se aude simfonia preferată, acoperind sunetul tastelor mecanice, iar prima înregistrare din lista de ticket-uri pe tabloul kanban strălucește jucăuș cu titlul decisiv „Investigate varnishreload sh: echo: I/O error in staging” (Investigarea „varnishreload sh: echo: I/O error” în staging). Când vine vorba de varnish, nu au loc erori, chiar dacă acestea nu se transformă în probleme ca în acest caz.

Pentru cei care nu sunt familiarizați cu varnishreload, acesta este un simplu script shell folosit pentru a reîncărca configurația varnish-ului – de asemenea numită VCL.

Așa cum sugerează titlul tichetului, eroarea a apărut pe unul dintre serverele de testare, și fiindcă eram sigur că rutarea varnish pe testare funcționează corect, am presupus că va fi o problemă minoră. Astfel, doar un mesaj care a ajuns în fluxul de ieșire deja închis. Îmi iau tichetul, fiind convins că îl voi marca ca fiind rezolvat în mai puțin de 30 de minute, mă bat pe umăr pentru curățarea tabloului de gunoiul altor ticheturi și mă întorc la lucruri mai importante.

Izbindu-mă de perete cu o viteză de 200 km/h

Deschizând un fișier varnishreload, pe unul dintre serverele care rulează Debian Stretch, am găsit un script shell de mai puțin de 200 de linii.

Răsfoind scriptul, nu am observat nimic care ar putea cauza probleme în cazul rularii sale repetate direct din terminal.

În cele din urmă, este un mediu de testare, chiar dacă se va strica, nimeni nu va face plângeri, ei bine... nu prea mulți. Execut scriptul și văd ce va apare în terminal, dar erorile deja nu sunt vizibile.

Încă câteva runde pentru a fi sigur că nu pot reproduce eroarea fără eforturi suplimentare și încep să mă gândesc cum să modific acest script pentru a-l face să genereze o eroare.

Poate ar trebui să redirecționez STDOUT (folosind > &-)? Sau STDERR? Niciuna dintre variante nu a funcționat, în final.

Este evident că systemd modifică în vreun fel mediul de execuție, dar cum și de ce?
Deschid vim și editez varnishreload, adăugând set -x imediat sub shebang, sperând că ieșirea de debug a scriptului va aduce un pic de lumină.

Fișierul a fost modificat, așa că repornesc varnish și văd că modificarea a stricat totul… Ieşirea este un haos complet, plină de cod asemănător C. Chiar și derularea în terminal nu este suficientă pentru a găsi de unde începe. Sunt complet confuz. Poate că modul de debug afectează comportamentul programelor apelate în script? Nu, absurditate. Este o eroare în shell? Mai multe scenarii posibile mă hăitui în minte ca gândacii în toate direcțiile. O ceașcă de băutură plină de cafeină se golește instantaneu, o călătorie rapidă în bucătărie pentru a-mi reumple proviziile și… hai la drum. Deschid scriptul și mă uit atent la shebang: #!/bin/sh.

/bin/sh — Este doar un symlink către bash, așa că scriptul este interpretat în modul compatibil POSIX, nu-i așa? Nu chiar! Shell-ul implicit în Debian este dash, și aceasta este exact ceea ce se referă /bin/sh.

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

Pentru a testa, am schimbat shebang-ul în #!/bin/bash, am șters set -x și am încercat din nou. În cele din urmă, la repornirea ulterioară a varnish-ului, a apărut o eroare rezonabilă în output:

Jan 01 12:00:00 hostname varnishreload[32604]: /usr/sbin/varnishreload: linia 124: echo: eroare la scriere: țeavă ruptă
Jan 01 12:00:00 hostname varnishreload[32604]: VCL 'reload_20190101_120000_32604' compilat

Linia 124, iată-l!

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                         # toată această ceremonie pentru a gestiona spațiile în 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 "nu s-a putut obține numele fișierului VCL"
129         fi
130
131         echo "$VCL_FILE"
132 }

Dar, după cum s-a dovedit, linia 124 este destul de goală și nu reprezintă interes. Am putut doar să presupun că eroarea a apărut ca parte a unui multilinie, care începe în linia 116.
Ce se scrie, în final, în variabila VCL_FILE ca rezultat al execuției sub-shell-ului menționat mai sus?

La început, el trimite conținutul variabilei VLC_SHOW, creată în linia 115, către următoarea comandă prin pipe. Dar ce se întâmplă acolo?

În primul rând, acolo se folosește varnishadm, care face parte din pachetul de instalare varnish, pentru a configura varnish-ul fără a reporni.

Subcomanda vcl.show -v este utilizată pentru a afișa întreaga configurație VCL specificată în ${VCL_NAME}, în STDOUT.

Pentru a afișa configurația VCL activă în prezent, precum și câteva versiuni anterioare ale configurațiilor de rutare varnish care sunt încă în memorie, se poate folosi comanda varnishadm vcl.list, outputul căreia va fi similar cu cel de mai jos:

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

Valoarea variabilei ${VCL_NAME} este setată în altă parte a scriptului varnishreload la numele VCL-ului activ în prezent, dacă există. În acest caz, va fi “reload_20190101_120000_12397”.

Excelent, variabila ${VCL_SHOW} conține întreaga configurație pentru varnish, până acum este clar. Acum, în sfârșit, am înțeles de ce output-ul dash cu set -x a fost atât de stricat – includea conținutul configurației rezultate.

Este important să înțelegem că configurația completă VCL poate fi adesea compusă din mai multe fișiere. Comentariile în stil C sunt folosite pentru a indica unde un fișier de configurare a fost inclus în altul, iar aceasta este realmente ceea ce discutăm în fragmentele de cod de mai jos.
Sintaxa comentariilor care descriu fișierele incluse are următorul format:

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

Numerele în acest context nu sunt importante, ne interesează numele fișierului.

Ce se întâmplă în vârtejul comenzilor care începe la linia 116?
Să clarificăm.
Comanda este compusă din patru părți:

1. Simplu echo, care afișează valoarea variabilei ${VCL_SHOW}

   echo "$VCL_SHOW"

2. awk, care caută o linie (înregistrare) în care primul câmp, după împărțirea textului, este „//”, iar al doilea este „VCL.SHOW”.
   Awk va imprima prima linie care se potrivește cu aceste modele, apoi va întrerupe imediat procesarea.

   awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'

3. Un bloc de cod care salvează valorile câmpurilor, separate prin spații, în cinci variabile. A cincea variabilă FILE primește restul liniei. În cele din urmă, ultimul echo va imprima conținutul variabilei ${FILE}.

   { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }

4. Deoarece toate pașii de la 1 la 3 sunt închise într-un sub-shell, valoarea returned $FILE va fi salvată în variabila VCL_FILE.

După cum sugerează comentariul de la linia 119, acest lucru servește unui singur scop: a gestiona în mod fiabil cazurile în care VCL va face referire la fișiere cu caractere de spațiu în nume.

Am comentat logica inițială de procesare pentru ${VCL_FILE} și am încercat să schimb ordinea comenzilor, dar nu a dus la nimic. Totul mi-a funcționat perfect, iar în cazul în care am pornit serviciul, a arătat o eroare.

Se pare că eroarea nu este reproducibilă la pornirea scriptului manual, iar cele 30 de minute presupuse s-au încheiat deja de vreo șase ori, în plus, a apărut o sarcină mai prioritară care a împins celelalte activități înapoi. Restul săptămânii a fost plină de sarcini variate și doar puțin atenuată de o prezentare despre sed și un interviu cu un candidat. Problema cu eroarea în varnishreload a fost pierdută pentru totdeauna în nisipurile timpului.

Așa-numitul tău sed-fu... de fapt... este prostie.

Săptămâna viitoare am avut o zi destul de liberă, așa că am decis din nou să mă ocup de acest bilet. Speram că în mintea mea, un proces de fundal căuta tot acest timp o soluție pentru această problemă și că de data aceasta voi înțelege cu adevărat despre ce este vorba.

Deoarece data trecută o simplă modificare a codului nu a ajutat, am decis să-l scriu din nou începând cu linia 116. Oricum, codul existent era cam stricat. Și nu era absolut niciun motiv să folosesc read.

Privind din nou eroarea:
sh: echo: broken pipe — în această comandă echo se află în două locuri, dar suspectez că primul este cel mai probabil vinovat (sau cel puțin un complice). Awk, de asemenea, nu inspiră încredere. Și în cazul în care acesta este awk | {read; echo} construcția care duce la toate aceste probleme, de ce nu ar trebui să o înlocuim? Această comandă pe o linie nu folosește toate capabilitățile awk, și în plus, are acest excess read pe deasupra.

Deoarece săptămâna trecută a fost o prezentare despre sed, am vrut să încerc abilitățile mele recent dobândite și să simplific echo | awk | { read; echo} într-un mod mai clar echo | sed. Deși acesta nu este cu siguranță cel mai bun mod de a depista eroarea, m-am gândit că cel puțin voi încerca să-mi folosesc sed-fu și, poate, voi învăța ceva nou despre problemă. Pe parcurs, l-am rugat pe colegul meu, autorul prezentării despre sed, să mă ajute să concepem un script sed mai eficient.

Am salvat conținutul varnishadm vcl.show -v "$VCL_NAME" într-un fișier, astfel încât să mă pot concentra pe scrierea scriptului sed fără a avea griji legate de repornirea serviciului.

O descriere succintă a modului în care sed procesează datele de intrare se poate găsi în ghidul său GNU. În sursele sed, simbolul n este clar specificat ca separator de linii.

După câteva treceri și cu recomandările colegului meu, am scris un script sed care oferea același rezultat ca și întreaga linie originală 116.

Mai jos este un exemplu de fișier cu datele de intrare:

> cat vcl-example.vcl
Text
// VCL.SHOW 0 1578 file cu 3 spații.vcl
Mai mult text
// VCL.SHOW 0 1578 file.vcl
Chiar mai mult text
// VCL.SHOW 0 1578 file cu două spații.vcl
Text final

Acest lucru poate să nu fie evident din descrierea de mai sus, dar ne interesează doar primul comentariu // VCL.SHOW, având în vedere că în datele de intrare ar putea exista mai multe. De aceea, awk-ul original își încheie activitatea după prima potrivire.

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

Așadar, conținutul scriptului varnishreload va arăta cam așa:

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

Logica de mai sus poate fi exprimată pe scurt astfel:
Dacă șirul corespunde expresiei regulate // VCL.SHOW, atunci consumă textul care include ambele numere din acest șir, și păstrează tot ce rămâne în urma acestei operații. Returnează valoarea păstrată și termină programul.

Simplu, nu-i așa?

Am fost mulțumiți de scriptul sed și de faptul că înlocuiește întregul cod original. Toate testele mele au dat rezultatele dorite, așa că am schimbat 'varnishreload' pe server și am reluat systemctl reload varnish. O eroare proastă echo: eroare la scriere: conductă ruptă ne râdea din nou în față. Cursorul care încuviințează aștepta să introducă un nou comanda în întunericul terminalului...

Sursa: habr.com