🥇Padanje u zečju rupu: Priča o jednoj grešci ponovnog pokretanja varnisha — dio 1

ghostinushanka, pritisnuv na gumb za dvajset minut, kot da bi od tega odvisno njegovo življenje, se obrne k meni z napol divjim izrazom v očeh in zvitim nasmehom – „Človek, zdi se, da sem to ujel.“

„Poglej tukaj,“ reče, kazujoč na enega od simbolov na zaslonu – „Stavi se, da če dodamo to, kar sem ti pravkar poslal“ – kazujoč na drugi del kode – „napake ne bo več.“

Malce zmedeno in utrujeno spremenim sed izraz, s katerim smo delali že nekaj časa, shranim datoteko in zaženem systemctl varnish reload. Sporočilo o napaki je izginilo…

„Maili, ki sem jih izmenjeval s kandidatom,“ je nadaljeval moj kolega, medtem ko se njegov nasmeh spreminja v iskren nasmeh poln veselja, „nenadoma sem spoznal, da je to ista težava!“

Kako se je vse začelo

Članek zahteva razumevanje principov delovanja bash, awk, sed in systemd. Poznavanje varnish je zaželeno, vendar ni obvezno.
Časovne oznake v posnetkih so spremenjene.
Napisano skupaj z ghostinushanka.
Ta besedilo je prevod izvirnika, objavljenega v angleščini pred dvema tednoma; prevod boikoden.

Sončne žarke prodrejo skozi panoramska okna v toplo jesensko jutro, skodelica sveže pripravljene kave počiva ob strani od tipkovnice, v slušalkah se predvaja najljubša simfonija zvokov, ki prekrije šum mehanskih tipkovnic, prva postavka na seznamu nalog na kanban plošči pa s svetlečim naslovom „Raziskovanje varnishreload sh: echo: I/O error in staging“ (Raziskovanje „varnishreload sh: echo: I/O error“ v stagi) malce zasveti. Ko gre za varnish, napak ni in ne more biti, tudi če se ne odražajo v nobenih težavah, kot je v tem primeru.

Za tiste, ki niso seznanjeni z varnishreload, to je preprost shel skript, uporabljen za ponovno nalaganje konfiguracije varnish-a — znanega tudi kot VCL.

Kot kaže, je prišlo do napake na strežniku na stagi, in ker sem bil prepričan, da usmerjanje varnisha na stagi deluje pravilno, sem domneval, da bo to malenkostna napaka. Tako, samo sporočilo, ki je ušlo v že zaprte izstopne tokove. Vzamem vstopnico zase, prepričan, da jo bom označil za opravljeno v manj kot 30 minutah, se poteptam po ramenu za čiščenje deske pred novim smetjem in se vrnem k pomembnejšim nalogam.

Ko se zaletim v steno s hitrostjo 200 km/h

Odprl sem datoteko varnishreloadna enem od strežnikov pod upravljanjem Debian Stretch, videl sem shell skripto dolžine manj kot 200 vrstic.

Ko sem preletel skripto, nisem opazil nič takega, kar bi lahko povzročilo težave pri večkratni izvedbi iz terminala.

Na koncu je to staga, celo če se pokvari, nihče ne bo pritoževal… no, ne preveč. Zažgem skripto in gledam, kaj se bo izpisovalo na terminal, vendar napak že ne vidim več.

Še nekaj izvajanj, da se prepričam, da ne morem reproducirati napake brez dodatnih naporov, in začnem razmišljati, kako spremeniti to skripto, da bi dejansko povzročila napako.

Morda bi lahko skript preusmeril STDOUT (s pomočjo > &-)? Ali STDERR? Nobeno od tega na koncu ni delovalo.

Očitno systemd somehow spreminja okolje izvajanja, vendar kako in zakaj?
Vklopim vim in urejam varnishreload, dodajam set -x ravno pod shebang, upam, da bo izhod za odpravljanje napak skripte razkril kanček svetlobe.

Datoteka je popravljena, zato ponovno zaženem varnish in vidim, da je sprememba povsem pokvarila vse… Izhod je popoln nered, v katerem je tona C-podobne kode. Očitno niti pomikanje po terminalu ni dovolj, da bi našel, kje se vse začne. Sem v popolni zmedi. Ali lahko način odpravljanja napak vpliva na delovanje programov, ki jih zažene skripta? Ne, neumnost. Je težava v shells? Številni možni scenariji mi letijo po glavi kot žuželke v različne smeri. Skodelica kofeinsko-obdarjenega napitka se takoj izprazni, hitro potovanje v kuhinjo za ponovno polnjenje in… gremo. Odprl sem skripto in se osredotočil na shebang: #!/bin/sh.

/bin/sh — to je le simbolna povezava na bash, tako da se skripta interpretira v načinu združljivem s POSIX, pravi? Nič takšnega! Privzeta lupina v Debiana je dash, in točno to je, na kar Ticket_flights /bin/sh.

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

Za pokušino sem spremenil shebang na #!/bin/bash, sem odstranil set -x in ponovno poskusil. Končno, ob naslednjem ponovnem zagonu varnish-a, se je v izpisu pojavila sprejemljiva napaka:

Jan 01 12:00:00 hostname varnishreload[32604]: /usr/sbin/varnishreload: vrstica 124: echo: napaka pisanja: Broken pipe
Jan 01 12:00:00 hostname varnishreload[32604]: VCL 'reload_20190101_120000_32604' je bila kompajlirana

Vrstica 124, to je to!

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                         # vsa ta ceremonija za obvladovanje praznin v 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 "ni uspelo pridobiti imena VCL datoteke"
129         fi
130
131         echo "$VCL_FILE"
132 }

Toda kot se je izkazalo, je vrstica 124 precej prazna in ne predstavlja posebnega interesa. Lahko sem samo domneval, da je napaka nastala kot del večvrstičnega komentarja, ki se začne na 116. vrstici.
Kaj se na koncu zapiše v spremenljivko VCL_FILE kot rezultat izvajanja zgoraj omenjenega podshella?

Na začetku pošlje vsebino spremenljivke VLC_SHOW, ustvarjene na 115. vrstici, naslednjim ukazom prek pipinga. Kaj se tam zgodi?

Prvič, tam se uporablja varnishadm, ki je del namestitvenega paketa varnish, za konfiguracijo varnish-a brez ponovnega zagona.

Podukaz vcl.show -v se uporablja za izpis celotne konfiguracije VCL, določene v ${VCL_NAME}, na STDOUT.

Za prikaz trenutne aktivne konfiguracije VCL, pa tudi več prejšnjih različic konfiguracij usklajevanja varnish-a, ki so še vedno v pomnilniku, lahko uporabite ukaz varnishadm vcl.list, izpis bo podoben naslednjemu:

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

Vrednost spremenljivke ${VCL_NAME} se nastavi v drugem delu skripta varnishreload na ime trenutno aktivnega VCL, če takšna obstaja. V tem primeru bo to "reload_20190101_120000_12397".

Odlično, spremenljivka ${VCL_SHOW} vsebuje celotno konfiguracijo za varnish, kar je zdaj jasno. Zdaj sem končno razumel, zakaj je bil izpis dash set -x tako pokvarjen — vseboval je konfiguracijo, ki se je oblikovala.

Pomembno je razumeti, da se celotna konfiguracija VCL pogosto lahko sestavi iz več datotek. Komentarji v stilu C se uporabljajo za določitev, kje so bile ene konfiguracijske datoteke vključene v druge, in to je pravzaprav tisto, o čemer govori celoten spodnji del kode.
Sintaksa komentarjev, ki opisujejo vključene datoteke, ima naslednjo obliko:

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

Številke v tem kontekstu niso pomembne, zanima nas ime datoteke.

Kaj se torej dogaja v blatu ukazov, ki se začnejo na vrstici 116?
Poglejmo podrobneje.
Ukaz sestavljata štiri dela:

Preprosto echo, ki izpiše vrednost spremenljivke ${VCL_SHOW}
```
echo "$VCL_SHOW"
```
awk, ki išče vrstico (vnos), kjer bo prvo polje, po razdelitvi besedila, “//”, drugo pa “VCL.SHOW”.
Awk izpiše prvo vrstico, ki ustreza tem vzorcem, nato pa takoj preneha z obdelavo.
```
awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'
```
Blok kode, ki shrani v pet spremenljivk vrednosti polj, ločenih s presledki. Peta spremenljivka FILE prejme preostanek vrstice. Na koncu zadnji echo izpiše vsebino spremenljivke ${FILE}.
```
{ read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }
```
Ker so vsi koraki od 1 do 3 vključeni v pod-sistem, bo izhodna vrednost $FILE bila zapisana v spremenljivko. VCL_FILE.

Kot izhaja iz komentarja na 119. vrstici, je to namenjeno zgolj enemu cilju: zanesljivo obdelovati primere, ko se VCL sklicuje na datoteke s presledki v imenu.

Zakomentiral sem izvorno logiko obdelave za ${VCL_FILE} in poskušal spremeniti zaporedje ukazov, vendar to ni privedlo do ničesar. Vse se mi je delalo brez težav, medtem ko je v primeru zagonjenja storitve javljalo napako.

Zdi se, da napake ne moremo reproducirati pri ročnem zagonu skripte, pri čemer se domnevnih 30 minut že šestkrat izteče, in poleg tega se pojavi prioriteta, ki je odpravila ostale zadeve. Preostali del tedna je bil zapolnjen z različnimi nalogami in bil je le malo začinjen z poročilom o sed in intervjujem s kandidatom. Težava z napako v varnishreload je bila nepovratno izgubljena v peščenih urah.

Vaš tako imenovani sed-fu… v resnici… ni nič vredno.

V naslednjem tednu sem imel prost dan, zato sem se spet odločil za ta tiket. Upal sem, da je v mojem umu potekal neki proces, ki je cel čas iskal rešitev za ta problem in tokrat bom zagotovo razumel, kaj je narobe.

Ker prejšnjič preprosta sprememba kode ni pomagala, sem se odločil, da jo ponovno napišem, začenši s 116. vrstice. V vsakem primeru je bila obstoječa koda slaba. In v njej ni nujno, da uporabljamo preberi.

Pogledujoč napako še enkrat:
sh: echo: pokvarjena cev — v tej ukazni vrstici echo nastopa dvakrat, a sumim, da je prva verjetnejši krivec (no, ali vsaj so-akter). Awk tudi ne daje veliko zaupanja. In v primeru, da je res to awk | {preberi; echo} ukaz povzroča vse te težave, zakaj ga ne bi zamenjali? Ta enovrstčni ukaz ne izkorišča vseh možnosti awk, in poleg tega je ta odvečni preberi dodatek.

Ker je bil prejšnji teden predstava o sed, sem želel preizkusiti svoje nedavno pridobljene veščine in poenostaviti echo | awk | { preberi; echo} v bolj razumljivo echo | sed. Čeprav to zagotovo ni najboljši pristop za iskanje napake, sem pomislil, da vsaj preizkusim svoje znanje o sed in morda se naučim nekaj novega o težavi. Po poti sem prosil svojega kolega, avtorja predstave o sed, da mi pomaga razviti učinkovitejši sed skript.

Poslal sem vsebino varnishadm vcl.show -v "$VCL_NAME" v datoteko, tako da sem se lahko osredotočil na pisanje sed skripta brez skrbi o ponovnih nalaganju storitve.

Kratka razlaga, kako sed obdeluje vhodne podatke, je na voljo v njegovem GNU vodniku. V izvorni kodi sed je znak n jasno označen kot ločilni znak vrstic.

S pomočjo več prehodov in priporočil mojega kolega smo napisali sed skript, ki je dal enak rezultat kot cela izvorna vrstica 116.

Spodaj je prikazan vzorec datoteke z vhodnimi podatki:

> cat vcl-example.vcl
Text
// VCL.SHOW 0 1578 datoteka z 3 presledki.vcl
Več besedila
// VCL.SHOW 0 1578 datoteka.vcl
Še več besedila
// VCL.SHOW 0 1578 datoteka z DVA presledka.vcl
Zaključno besedilo

Morda to ni očitno iz zgornjega opisa, a zanima nas le prvi komentar // VCL.SHOW, pri čemer jih lahko v vhodnih podatkih več. Zato originalni awk konča svoje delo po prvem ujemanju.

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

Torej, vsebina skripta varnishreload bo izgledala nekako takole:

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

Gornja logika može se sažeti na sljedeći način:
Ako se niz podudara s regularnim izrazom // VCL.SHOW, tada pohlepno uzmi tekst koji uključuje oba broja u tom nizu i sačuvaj sve što ostane nakon te operacije. Izdaj sačuvanu vrijednost i završi program.

Jednostavno, zar ne?

Bili smo zadovoljni sed skriptom i činjenicom da zamjenjuje cijeli originalni kod. Svi moji testovi su dali željene rezultate, pa sam promijenio “varnishreload” na serveru i ponovno pokrenuo systemctl reload varnish. Javni greška echo: write error: Broken pipe ponovno nam se smijala u lice. Pomaknut kursor čekao je unos nove naredbe u mračnoj praznini terminala…

Izvor: habr.com

Padec v zajčjo luknjo: Zgodba o eni napaki pri ponovnem zagonu varnisha — del 1

Kako se je vse začelo

Ko se zaletim v steno s hitrostjo 200 km/h

Vaš tako imenovani sed-fu… v resnici… ni nič vredno.