🥇Pudotus kaninkoloon: Tarina lakan uudelleenkäynnistysvirheestä — Osa 1

ghostinushanka, joka on paukuttanut nappeja viimeiset 20 minuuttia kuin hänen henkensä riippuisi siitä, kääntyy puoleeni puolivilli katse silmissään ja ovela virne kasvoillaan – "Kaveri, luulenpa ymmärtäväni."

– Katso tätä, hän sanoo osoittaen yhtä ruudulla olevista symboleista. – Lyön vetoa punaisesta hatustani, että jos lisäämme tänne sen, minkä juuri lähetin sinulle, – virhettä ei enää näytetä.

Hieman hämmentyneenä ja väsyneenä muutan sed-lauseketta, jota olemme työstäneet jonkin aikaa, tallennan tiedoston ja suoritan systemctl varnish reloadVirheilmoitus katosi…

”Sähköpostit, joita vaihdoin ehdokkaan kanssa”, kollegani jatkoi virnistäen aidoksi ilon hymyksi, ”minulle yhtäkkiä valkeni, että kyseessä on täsmälleen sama ongelma!”

Miten kaikki alkoi

Tämä artikkeli olettaa bashin, awkin, sedin ja systemd:n ymmärtämisen. Varnishin tuntemusta suositellaan, mutta se ei ole välttämätöntä.
Katkelmien aikaleimat on muutettu.
Kirjoitettu yhdessä ghostinushanka.
Tämä teksti on käännös alkuperäisestä, kaksi viikkoa sitten englanniksi julkaistusta tekstistä; käännös boikoden.

Aurinko paistaa panoraamaikkunoista lämpimänä syysaamuna, vastavalmistettu kofeiinipitoinen juoma lepää näppäimistön vieressä, kuulokkeissani soi lempisinfoniani peittäen alleen mekaanisten näppäimistöjen kahinan, ja Kanban-taulun tilauslistan ensimmäinen merkintä hehkuu leikkisästi kohtalokkaalla otsikolla "Tutki varnishreload sh: echo: I/O-virhe stagingissa". Lakkauksessa ei ole sijaa virheille, vaikka ne eivät aiheuttaisikaan ongelmia, kuten tässä tapauksessa.

Для тех, кто не знаком с lakkin uudelleenlataus, tämä on yksinkertainen komentosarja, jota käytetään kokoonpanon uudelleenlataamiseen lakka-a — kutsutaan myös VCL:ksi.

Kuten tiketin otsikko antaa ymmärtää, virhe tapahtui yhdellä vaiheen palvelimista, ja koska olin varma, että Varnish-reititys vaiheella toimi oikein, oletin sen olevan pieni virhe. Vain viesti, joka päätyi jo suljettuun tulostusvirtaan. Otin tiketin vastaan luottavaisena siihen, että merkitsisin sen valmiiksi alle 30 minuutissa, taputtaisin itseäni selkään siitä, että siivosin taas yhden roskanpalan taululta, ja palaisin tärkeämpiin asioihin.

Törmäys seinään 200 km/h nopeudella

Tiedoston avaaminen varnishreload, yhdellä hallinnassa olevista palvelimista Debian Stretch, näin alle 200 riviä pitkän komentosarjan.

Suoritettuani skriptin läpi en huomannut mitään, mikä aiheuttaisi ongelmia, jos ajaisin sen useita kertoja suoraan terminaalista.

Loppujen lopuksi se on lava, joten vaikka se hajoaisi, kukaan ei valita, no... ei liikaa. Ajan skriptin ja katson, mitä terminaaliin kirjoitetaan, mutta virheitä ei enää näy.

Pari suoritusta lisää varmistaakseni, etten pysty toistamaan virhettä ilman lisäponnisteluja, ja alan selvittää, miten saan tätä skriptiä muokkaamaan ja saamaan sen todella heittämään virheen.

Voiko komentosarja estää STDOUT:n (käyttäen > &-)? Vai STDERR? Kumpikaan ei lopulta toiminut.

On selvää, että systemd muuttaa käynnistysympäristöä jotenkin, mutta miten ja miksi?
Laitan vimin päälle ja editoin varnishreload, lisäämällä set -x aivan shebangin alla, toivoen, että skriptin debug-tuloste valaisee asiaa.

Tiedosto on korjattu, joten käynnistän Varnishin uudelleen ja näen, että muutos on rikkonut kaiken täysin... Tuloste on täysi sotku, täynnä C-tyyppistä koodia. Edes terminaalin vieritys ei riitä löytämään, mistä kaikki alkoi. Olen täysin hämmentynyt. Voisiko debug-tila vaikuttaa skriptissä suoritettaviin ohjelmiin? Ei, se on hölynpölyä. Vika komentotulkissa? Useat mahdolliset skenaariot vilahtavat päässäni kuin torakoita. Kofeiinipitoinen muki tyhjenee välittömästi, nopea reissu keittiöön täyttämään se ja... menoksi. Avaan skriptin ja tarkastelen sitä tarkemmin: #!/bin/sh.

/bin/sh — se on vain bash-symlinkki, joten skripti tulkitaan POSIX-yhteensopivassa tilassa, eikö niin? Ei todellakaan! Oletuskomentotulkki Debian - se on viiva, ja juuri sitä varten se onkin viittaa /bin/sh.

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

Testausta varten muutin shebangin muotoon #!/bin/bash, poistettu set -x ja yritin uudelleen. Lopulta, kun Varnish käynnistettiin uudelleen, tulosteeseen ilmestyi siedettävä virhe:

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

Rivi 124, tässä se on!

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 }

Mutta kuten kävi ilmi, rivi 124 oli aivan tyhjä eikä kiinnostanut. Voin vain olettaa, että virhe johtui rivillä 116 alkavasta monirivisestä lausekkeesta.
Mitä muuttujaan lopulta kirjoitetaan? VCL_FILE edellä mainitun alikuoren suorittamisen seurauksena?

Aluksi se lähettää muuttujan sisällön VLC_SHOW, joka on luotu riville 115, seuraavaan komentoon putken kautta. Mitä siellä sitten tapahtuu?

Ensinnäkin sitä käytetään siellä varnishadm, joka on osa Varnishin asennuspakettia, Varnishin konfiguroimiseksi ilman uudelleenkäynnistystä.

Alikomento vcl.show -v käytetään koko VCL-konfiguraation tulostamiseen, joka on määritetty kohdassa ${VCL_NAME}, STDOUT-lähtöön.

Voit näyttää aktiivisen VCL-kokoonpanon sekä useita aiempia, muistissa olevia lakkareitityskokoonpanojen versioita komennolla varnishadm vcl.list, jonka tuloste on samanlainen kuin alla oleva:

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

Muuttuva arvo ${VCL_NAME} on asetettu käsikirjoituksen toisessa osassa varnishreload aktiivisen VCL:n nimeen, jos sellainen on. Tässä tapauksessa se on ”reload_20190101_120000_12397”.

Erinomainen, vaihteleva ${VCL_SHOW} sisältää täydellisen kokoonpanon lakkille, toistaiseksi kaikki hyvin. Nyt vihdoin ymmärrän, miksi kojelaudan tulosteessa on set -x osoittautui niin rikkinäiseksi, että se sisälsi tuloksena olevan kokoonpanon sisällön.

On tärkeää ymmärtää, että täydellinen VCL-konfiguraatio voidaan usein koota useista tiedostoista. C-tyylisiä kommentteja käytetään tunnistamaan, missä konfiguraatiotiedostot sijaitsevat muiden tiedostojen sisällä, ja juuri siitä koko alla oleva koodirivi kertoo.
Sisällytettyjä tiedostoja kuvaavien kommenttien syntaksi on seuraava:

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

Numerot eivät ole tässä yhteydessä tärkeitä, meitä kiinnostaa tiedostonimi.

Mitä siis tapahtuu komentojen suossa alkaen riviltä 116?
Totta puhuen.
Joukkue koostuu neljästä osasta:

yksinkertainen echo, joka tuottaa muuttujan arvon ${VCL_SHOW}
```
echo "$VCL_SHOW"
```
awk, joka etsii merkkijonoa (tietuetta), jossa ensimmäinen kenttä tekstin jakamisen jälkeen on “//” ja toinen on “VCL.SHOW”.
Awk kirjoittaa ensimmäisen rivin, joka vastaa näitä kuvioita, ja lopettaa sitten välittömästi käsittelyn.
```
awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'
```
Koodilohko, joka tallentaa kenttien arvot välilyönneillä erotettuina viiteen muuttujaan. Viides muuttuja, FILE, vastaanottaa rivin loppuosan. Lopuksi viimeinen echo-lauseke kirjoittaa muuttujan sisällön. ${FILE}.
```
{ read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }
```
Koska kaikki vaiheet 1–3 on suljettu alikuoreen, arvon tuloste $FILE kirjoitetaan muuttujaan VCL_FILE.

Kuten rivillä 119 oleva kommentti viittaa, tällä on vain yksi tarkoitus: käsitellä luotettavasti tapaukset, joissa VCL viittaa tiedostoihin, joiden nimessä on välilyöntejä.

Kommentoin pois alkuperäisen käsittelylogiikan kohdasta ${VCL_FILE} Yritin muuttaa komentosarjaa, mutta se ei toiminut. Kaikki toimi minulla hyvin, mutta kun käynnistin palvelun, se antoi virheen.

Näyttää siltä, että virhettä ei yksinkertaisesti voida toistaa manuaalisesti suoritettaessa, ja oletetut 30 minuuttia ovat jo kuluneet umpeen kuusi kertaa, ja kaiken kukkuraksi esiin on ilmestynyt tärkeämpi tehtävä, joka on työntänyt muita tehtäviä syrjään. Loppuviikko oli täynnä erilaisia tehtäviä, joita vain hetkellisesti keskeyttivät sed-esitys ja haastattelu ehdokkaan kanssa. Ongelma virheessä varnishreload oli peruuttamattomasti hukkunut ajan hiekkaan.

Niin kutsuttu sed-fu... on oikeasti... paskaa

Seuraavalla viikolla minulla oli melko vapaapäivä, joten päätin työstää tätä tikettiä uudelleen. Toivoin, että jokin aivojeni taustalla oleva prosessi oli etsinyt ratkaisua koko ajan, ja tällä kertaa selvittäisin varmasti, mikä ongelma oli.

Koska yksinkertainen koodinmuutos ei auttanut viime kerralla, päätin vain kirjoittaa sen uudelleen riviltä 116 alkaen. Olemassa oleva koodi oli joka tapauksessa vähän hölmöä. Ja ei ole mitään tarvetta käyttää read.

Tarkastellaanpa virhettä uudelleen:
sh: echo: broken pipe — echo esiintyy tässä komennossa kahdessa kohdassa, mutta epäilen, että ensimmäinen on todennäköisempi syyllinen (tai ainakin rikoskumppani). Awk ei myöskään herätä luottamusta. Ja jos näin todella on, niin awk | {read; echo} Suunnittelu johtaa kaikkiin näihin ongelmiin, joten miksi ei korvattaisi sitä? Tämä yhden rivin komento ei hyödynnä kaikkia awk:n ominaisuuksia, ja lisäksi on tämä ylimääräinen read lisäksi.

Koska viime viikolla julkaistiin raportti asiasta sedHalusin kokeilla uusia taitojani ja yksinkertaistaa echo | awk | { read; echo} kohti ymmärrettävämpää echo | sedVaikka tämä ei todellakaan ole paras tapa tunnistaa virhettä, ajattelin ainakin kokeilla sed-fua ja ehkä oppia jotain uutta ongelmasta. Matkan varrella pyysin kollegaani, joka on kirjoittanut sed-keskustelun, auttamaan minua keksimään tehokkaamman sed-skriptin.

Kaadoin sisällön varnishadm vcl.show -v "$VCL_NAME" tiedostoon, jotta voisin keskittyä sed-skriptin kirjoittamiseen ilman palvelun uudelleenkäynnistyksen vaivaa.

Lyhyt kuvaus siitä, miten sed-prosessien syöttötiedot tarkalleen ottaen löytyvät kohdasta hänen GNU-käsikirjansaSed-lähdekoodissa symboli n erikseen määritelty rivierottimena.

Useiden vaiheiden ja kollegani neuvojen avulla kirjoitimme sed-skriptin, joka tuotti saman tuloksen kuin koko alkuperäinen rivi 116.

Alla on esimerkki syötetiedostosta:

> 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

Se ei ehkä käy ilmi yllä olevasta kuvauksesta, mutta meitä kiinnostaa vain ensimmäinen kommentti. // VCL.SHOW, ja niitä voi olla useita syötetiedoissa. Tästä syystä alkuperäinen awk päättyy ensimmäisen osuman jälkeen.

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

Joten varnishreload-skriptin sisältö näyttää suunnilleen tältä:

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

Yllä oleva logiikka voidaan lyhyesti ilmaista seuraavasti:
Jos merkkijono vastaa säännöllistä lauseketta // VCL.SHOW, ahmii sitten ahneesti molemmat numerot sisältävän tekstin kyseisellä rivillä ja tallenna tämän operaation jälkeen jäljelle jäänyt arvo. Tulosta tallennettu arvo ja lopeta ohjelma.

Yksinkertaista, eikö olekin?

Olimme tyytyväisiä sed-skriptiin ja siihen, että se korvasi kaiken alkuperäisen koodin. Kaikki testini tuottivat halutut tulokset, joten muokkasin "varnishreload"-komentoa palvelimella ja suoritin sen uudelleen. systemctl reload varnishIlkeä virhe echo: write error: Broken pipe nauroivat taas päin naamaa. Silmää iskevä kursori odotti uutta komentoa terminaalin pimeässä tyhjyydessä…

Lähde: will.com

Falling Down the Rabbit Hole: Tarina yhdestä lakan uudelleenkäynnistysvirheestä - Osa 1

Miten kaikki alkoi

Törmäys seinään 200 km/h nopeudella

Niin kutsuttu sed-fu... on oikeasti... paskaa