Falling Down the Rabbit Hole: The Story of One Varnish Reload Failure - Part 1

ghostinushanka, eftir að hafa hamrað á hnöppunum undanfarnar 20 mínútur eins og líf hans væri háð því, snýr sér að mér með hálf-villt augnaráði í augum hans og hláturmildu - "Guð, ég held ég hafi náð því."

„Sjáðu hérna,“ segir hann og bendir á eitt af táknunum á skjánum, „ég veðja á rauða hattinn minn að ef við bætum hér við það sem ég sendi þér,“ bendir á annan hluta kóðans, „villan verður ekki lengur verður birt."

Dálítið undrandi og þreytt, ég breyti sed-tjáningunni sem við höfum verið að vinna í í smá stund, vista skrána og keyra systemctl varnish reload. Villuboðin eru horfin...

„Tölvupóstarnir sem ég skiptist á við frambjóðandann,“ hélt kollegi minn áfram, þegar bros hans óx í ósvikið bros af gleði, „Það rann allt í einu upp fyrir mér að þetta er nákvæmlega sama vandamálið!

Hvernig þetta byrjaði allt saman

Greinin gerir ráð fyrir skilningi á því hvernig bash, awk, sed og systemd virka. Þekking á lakki er æskileg en ekki nauðsynleg.
Tímastimplum í bútum hefur verið breytt.
Skrifað með ghostinushanka.
Þessi texti er þýðing á frumritinu sem kom út á ensku fyrir tveimur vikum; þýðing boikoden.

Sólin skín inn um gluggana á öðrum heitum haustmorgni, bolli af nýlöguðum koffínríkum drykk hvílir frá lyklaborðinu, uppáhalds sinfónían þín hljómar í heyrnartólunum þínum, drekkir þvæsti vélrænna hljómborða og fyrsta inngangurinn í listanum yfir backlog miða á Kanban borðinu glóir leikandi með örlagatitlinum „Investigate varnishreload“ sh: echo: I/O error in staging“ (rannsakið „varnishreload sh: echo: I/O error“ í sviðsetningu). Þegar kemur að lakki er og getur ekki verið pláss fyrir villur, jafnvel þótt þær valdi ekki vandamálum eins og í þessu tilviki.

Fyrir þá sem ekki kannast við fernishreload, þetta er einfalt skeljaforskrift sem er notað til að endurhlaða stillingarnar lakk - einnig kallað VCL.

Eins og titill miðans gefur til kynna kom villan upp á einum servernum á sviðinu og þar sem ég var viss um að lakkleiðingin á sviðinu virkaði rétt gerði ég ráð fyrir að þetta væri smávilla. Svo, bara skilaboð sem enduðu í þegar lokaðri framleiðslustraumi. Ég tek miðann fyrir mig, í fullu trausti um að ég merki hann tilbúinn eftir innan við 30 mínútur, klappa mér á bakið fyrir að hreinsa borðið af enn einu draslinu og snúa aftur að mikilvægari málum.

Rekast á vegg á 200 km/klst

Að opna skrána varnishreload, á einum af netþjónunum sem keyra Debian Stretch, sá ég skeljaskrift sem var minna en 200 línur að lengd.

Eftir að hafa farið í gegnum handritið tók ég ekki eftir neinu sem gæti valdið vandamálum þegar ég keyrði það margoft beint frá flugstöðinni.

Enda er þetta áfangi, þótt það brotni mun enginn kvarta, ja... ekki of mikið. Ég keyri scriptið og sé hvað verður skrifað í flugstöðina, en villurnar eru ekki lengur sýnilegar.

Nokkrar keyrslur í viðbót til að ganga úr skugga um að ég geti ekki endurskapað villuna án frekari fyrirhafnar, og ég er að byrja að finna út hvernig á að breyta þessu handriti og láta það samt kasta villu.

Getur handritið hnekið STDOUT (með því að nota > &-)? Eða STDERR? Hvorugt þessara virkaði á endanum.

Svo virðist sem systemd breytir einhvern veginn ræsingarumhverfinu, en hvernig og hvers vegna?
Ég opna vim og edit varnishreload, bætir við set -x rétt undir skítkastinu, í von um að kembiútgangur handritsins muni varpa ljósi.

Skráin er leiðrétt þannig að ég endurhleð lakk og sé að breytingin gjörsamlega braut allt... Útblásturinn er algjört rugl, þar sem það eru tonn af C-líkum kóða. Jafnvel að fletta í flugstöðinni er ekki nóg til að finna hvar það byrjar. Ég er alveg í ruglinu. Getur villuleitarhamur haft áhrif á virkni forrita sem ræst er í handriti? Nei, það er bull. Pöddur í skelinni? Nokkrar mögulegar aðstæður þjóta í gegnum höfuðið á mér eins og kakkalakkar í mismunandi áttir. Bikarinn af koffíndrykknum er tæmdur samstundis, stutt ferð í eldhúsið til að fylla á lagerinn og... af stað. Ég opna handritið og lít nánar á shebang: #!/bin/sh.

/bin/sh - þetta er bara táknmynd í bash, svo handritið er túlkað í POSIX-samhæfðri ham, ekki satt? Ekki svo! Sjálfgefin skel á Debian er strik, og það er nákvæmlega það sem það lítur út. vísar /bin/sh.

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

Sem próf breytti ég shebang í #!/bin/bash, eytt set -x og reyndi aftur. Að lokum, við síðari endurræsingu á lakki, birtist þolanleg villa í úttakinu:

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ína 124, hér er hún!

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 }

En eins og það kemur í ljós er lína 124 alveg tóm og ekki áhugaverð. Ég gat aðeins gert ráð fyrir að villa hafi átt sér stað sem hluti af marglínu streng sem byrjaði á línu 116.
Hvað er að lokum skrifað í breytuna? VCL_FILE sem afleiðing af framkvæmd ofangreindrar undirskeljar?

Í upphafi sendir það innihald breytunnar VLC_SHOW, búin til á línu 115, eftir skipuninni í gegnum pípuna. Og hvað gerist þá þar?

Í fyrsta lagi er það notað þar varnishadm, sem er hluti af uppsetningarpakkanum fyrir lakk, til að setja upp lakk án þess að endurræsa.

Undirlið vcl.show -v notað til að gefa út alla VCL uppsetninguna sem tilgreind er í ${VCL_NAME}, til STDOUT.

Til að sýna núverandi virku VCL stillingu, sem og nokkrar fyrri útgáfur af lakkleiðarstillingum sem eru enn í minni, geturðu notað skipunina varnishadm vcl.list, þar sem framleiðsla verður svipuð og hér að neðan:

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

Breytilegt gildi ${VCL_NAME} er sett upp í öðrum hluta skriftunnar varnishreload til nafns á virku VCL, ef það er til. Í þessu tilfelli verður það „reload_20190101_120000_12397“.

Frábært, breytilegt ${VCL_SHOW} inniheldur fullkomna uppsetningu fyrir lakk, glær í bili. Nú skil ég loksins hvers vegna strikaúttakið er set -x reyndist vera svo bilaður - það innihélt innihald stillingarinnar sem varð til.

Það er mikilvægt að skilja að fullkomna VCL uppsetningu er oft hægt að leggja saman úr nokkrum skrám. Athugasemdir í C-stíl eru notaðar til að bera kennsl á hvar ákveðnar stillingarskrár hafa verið innifaldar í öðrum, og það er það sem eftirfarandi lína af kóðabút snýst um.
Setningafræði athugasemda sem lýsa meðfylgjandi skrám er á eftirfarandi sniði:

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

Tölurnar skipta ekki máli í þessu samhengi, við höfum áhuga á skráarnafninu.

Hvað gerist að lokum í mýri skipana sem byrja á línu 116?
Við skulum reikna það út.
Hópurinn samanstendur af fjórum hlutum:

1. Einfalt echo, sem prentar gildi breytunnar ${VCL_SHOW}

   echo "$VCL_SHOW"

2. awk, sem leitar að línu (skrá) þar sem fyrsti reiturinn, eftir að hafa brotið textann, er “//”, og sá seinni er “VCL.SHOW”.
   Awk mun skrifa út fyrstu línuna sem passar við þessi mynstur og hætta síðan vinnslu strax.

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

3. Kóðablokk sem geymir svæðisgildi í fimm breytur, aðskilin með bilum. Fimmta FILE breytan tekur við restinni af línunni. Að lokum skrifar síðasta bergmálið út innihald breytunnar ${FILE}.

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

4. Þar sem öll skref 1 til 3 eru umlukin í undirskel sem gefur út gildið $FILE verður skrifað í breytu VCL_FILE.

Eins og athugasemdin á línu 119 gefur til kynna þjónar þetta þeim eina tilgangi að meðhöndla á áreiðanlegan hátt mál þar sem VCL mun vísa til skráa með bilum í nöfnum þeirra.

Ég hef tjáð mig um upprunalegu vinnslurökfræðina fyrir ${VCL_FILE} og reyndi að breyta skipanaröðinni, en það leiddi ekki til neins. Allt virkaði vel fyrir mig, en þegar ég byrjaði þjónustuna kom upp villa.

Svo virðist sem villan sé einfaldlega ekki hægt að endurtaka þegar handritið er keyrt handvirkt, á meðan hinar meintu 30 mínútur eru þegar liðnar sex sinnum og að auki hefur verkefni með hærri forgang birst og ýtt öðrum málum til hliðar. Það sem eftir var vikunnar var fullt af ýmsum verkefnum og var aðeins útþynnt með skýrslu um sed og viðtal við frambjóðanda. Vandamál með villu í varnishreload týndist óafturkallanlega í sandi tímans.

Svokallað sed-fu þitt... er í raun... rusl

Næstu viku átti ég einn frekar lausan dag svo ég ákvað að tækla þennan miða aftur. Ég vonaði að í heila mínum hefði eitthvað bakgrunnsferli verið að leita að lausn á þessu vandamáli allan þennan tíma og í þetta skiptið myndi ég örugglega skilja hvað var í gangi.

Þar sem einfaldlega að breyta kóðanum hjálpaði ekki síðast ákvað ég bara að endurskrifa hann frá línu 116. Í öllum tilvikum var kóðinn sem fyrir var heimskulegur. Og það er algjör óþarfi að nota það read.

Skoða villuna aftur:
sh: echo: broken pipe — echo kemur fyrir á tveimur stöðum í þessari skipun, en mig grunar að sá fyrri sé líklegasti sökudólgurinn (eða að minnsta kosti vitorðsmaður). Awk vekur heldur ekki sjálfstraust. Og ef það er í raun og veru awk | {read; echo} hönnunin leiðir til allra þessara vandamála, hvers vegna ekki að skipta um það? Þessi einlínu skipun notar ekki alla eiginleika awk, og jafnvel þessa auka read Auk þess.

Síðan í síðustu viku var skýrsla um sed, Mig langaði að prófa nýfengna færni mína og einfalda echo | awk | { read; echo} í skiljanlegri echo | sed. Þó að þetta sé örugglega ekki besta aðferðin til að bera kennsl á villuna, hélt ég að ég myndi að minnsta kosti prófa sed-fu og kannski læra eitthvað nýtt um vandamálið. Í leiðinni bað ég kollega minn, höfund sed-spjallsins, að hjálpa mér að koma með skilvirkara sed-handrit.

Ég sleppti innihaldinu varnishadm vcl.show -v "$VCL_NAME" í skrá, svo ég gæti einbeitt mér að því að skrifa sed handritið án þess að þurfa að þurfa að endurræsa þjónustuna.

Stutt lýsing á nákvæmlega hvernig sed vinnur inntak er að finna í GNU handbók hans. Í sed heimildum táknið n sérstaklega tilgreint sem línuskil.

Í nokkrum lotum og með ráðleggingum kollega míns skrifuðum við sed handrit sem gaf sömu niðurstöðu og öll upprunalega línan 116.

Hér að neðan er sýnishorn af skrá með inntaksgögnum:

> 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

Þetta er kannski ekki augljóst af lýsingunni hér að ofan, en við höfum aðeins áhuga á fyrstu athugasemdinni // VCL.SHOW, og það geta verið nokkrir þeirra í inntaksgögnunum. Þetta er ástæðan fyrir því að upprunalega awk endar eftir fyrsta leik.

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

Svo, innihald varnishreload handritsins mun líta einhvern veginn svona út:

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

Rökfræðina hér að ofan má lýsa í stuttu máli sem hér segir:
Ef strengurinn passar við venjulega tjáningu // VCL.SHOW, neyttu síðan textann sem inniheldur báðar tölurnar í þessari línu ágirnd og vistaðu allt sem eftir er eftir þessa aðgerð. Sendu geymt gildi og ljúktu forritinu.

Einfalt, er það ekki?

Við vorum ánægð með sed handritið og þá staðreynd að það kom í staðinn fyrir allan upprunalega kóðann. Öll prófin mín gáfu tilætluðum árangri, svo ég breytti „varnishreload“ á þjóninum og keyrði hann aftur systemctl reload varnish. Slæm mistök echo: write error: Broken pipe hló aftur í andlitið á okkur. Blikkandi bendillinn beið eftir að ný skipun yrði slegin inn í myrkri tómleika flugstöðvarinnar...

Heimild: www.habr.com