Küülikurku kukkumine: Lugu ühest Varnishi taaskäivitamise veast — osa 1

ghostinushanka, vajutades nuppudele viimased 20 minutit justkui sellest sõltuks tema elu, pöördub ta minu poole poole metsiku ilmega silmis ja kaval naeratus näol — "Vend, tundub, et ma sain aru."

„Vaata siia,” ütleb ta, näidates ekraanil olevale sümbolile — „Panen oma punase mütsi peale, et kui me lisame siia selle, mida just saatsin” — näidates teisele koodilõigule — „siis viga enam ei tule.”

Veidi segaduses ja väsinuna muudab ma sed-i väljendit, millega oleme mõnda aega töötanud, salvestan faili ja käivitan systemctl varnish reload. Vea teade kadus...

„E-kirjad, millega ma kandidaatidega suhtlesin,” jätkas mu kolleeg, samas kui tema naeratus muutus ehtsaks rõõmuhaaigeks, „Korraga taipasin, et see on täpselt sama probleem!”

Kust see kõik algas

Artikkel eeldab, et on mõistetud bash'i, awk'i, sed'i ja systemd tööpõhimõtteid. Varnishi tundmine on teretulnud, kuid see pole kohustuslik.
Ajastustikud snippets on muudetud.
Kirjutatud koos ghostinushanka.
See tekst on tõlge originaalist, mis avaldati inglise keeles kaks nädalat tagasi; tõlge boikoden.

Päike paistab läbi panoraamakende järjekordsel soojal sügis hommikul, tass värskelt valmistatud kofeiinirikast jooki toetub klaviatuurist eemal, kõrvaklappides kõlavad lemmiksümfooniad, mis katab mehaaniliste klaviatuuride sahinat, ja esimesena kanban-seina backlogis särab saatuse määrav pealkiri „Uurige varnishreload sh: echo: I/O error stendil” (Uurige „varnishreload sh: echo: I/O error” stendil). Kui tegemist on varnish’iga, ei ole vigadele kohta, isegi kui need ei muutu probleemideks, nagu sel korral.

Neile, kes ei ole tuttavad varnishreload, see on lihtne shelli skript, mida kasutatakse varnish-i konfiguratsiooni uuesti laadimiseks — mida nimetatakse ka VCL-iks.

Nagu pealkiri viitab, tekkis viga ühe serveri etapis, ja kuna olin kindel, et varnishi suunamine etapis toimib korralikult, arvasin, et see on lihtsalt väike viga. Nii et see on lihtsalt sõnum, mis sattus juba suletud väljaandmise voogu. Võtan piletit enda peale, olles täiesti kindel, et märgin selle valmis vähem kui 30 minuti pärast, patsutan end õlal, et olen jälle koristanud tahvli ja naasen tähtsamate asjade juurde.

Sisse sõites seina kiirusel 200 km/h

Faili avades varnishreload, ühel serveritest, mis töötab Debian Stretchil, nägin vähem kui 200 rea pikkust shelli skripti.

Skripti läbi vaadates ei märganud ma midagi sellist, mis võiks põhjustada probleeme selle korduvate käivitamisega otse terminalist.

Lõppude lõpuks on see stabiilsuse etapp, isegi kui see katki läheb, ei kaeba keegi, noh... mitte liiga palju. Käivitaisin skripti ja vaatan, mis terminalile kirjutatakse, kuid vigu ei paista enam.

Veel käivitusi, et veenduda, et ma ei saa viga ilma täiendavate pingutusteta korrata, ja hakkan mõtlema, kuidas seda skripti muuta, et see tõepoolest viga annaks.

Kas on võimalik suunata skript STDOUT (kasutades > &-)? Või STDERR? Ükski neist lõpuks ei töötanud.

Ilmselgelt muudab systemd kuidagi käivituskeskkonda, aga kuidas ja miks?
Lülitan sisse vim ja redigeerin varnishreload, lisades set -x otse shebang'i alla, lootes, et skripti silumisväljastus toob veidi valgust.

Fail on parandatud, seega taaskäivitan varnish'i ja näen, et muudatus purustab kõik... Väljund on täielik segadus, kus on hunnik C-sarnast koodi. Isegi terminalis kerimine ei piisa, et leida, kust see algab. Olen täiesti hämmingus. Kas silumisrežiim võib mõjutada skripti käivitatavate programmide tööd? Ei, see on jama. Viga shell'is? Mitmed võimalikud stsenaariumid jooksevad mu peas nagu prussakad eri suundades. Tassi kofeiini täis jook tühjeneb hetkega, kiire reis kööki varude täiendamiseks ja... läheb käima. Avan skripti ja vaatan shebang'i: #!/bin/sh.

/bin/sh — see, it's just a symlink in bash, so the script is interpreted in POSIX-compatible mode, right? Not quite! The default shell in Debian is dash, and that's exactly what Ticket_flights /bin/sh.

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

I changed the shebang to #!/bin/bash, deleted set -x and tried again. Finally, upon the next reload of varnish, a decent error appeared in the output:

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

Line 124, here it is!

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 }

But it turned out that line 124 is quite empty and holds no interest. I could only guess that the error occurred as part of a multi-line command starting from line 116.
So what gets recorded in the variable VCL_FILE as a result of executing the above-mentioned subprocess?

Alguses saadab ta muutuja sisu VLC_SHOW, mis loodi 115. reale, järgmisele käsule läbi toru. Aga mida seal siis toimub?

Esiteks kasutatakse seal varnishadm, mis on osa varnishi installimispaketist, varnishi seadistamiseks ilma taaskäivitamiseta.

Alalühend vcl.show -v kasutatakse kogu VCL konfiguratsiooni väljastamiseks, nagu on määratud ${VCL_NAME}, STDOUT-is.

Aktiivse VCL konfiguratsiooni kuvamiseks, samuti paariks eelneva versiooni jaoks, mis on endiselt mälu all, võib kasutada käsku varnishadm vcl.list, mille väljund on sarnane allolevale:

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

Muutuja väärtus ${VCL_NAME} seatakse skripti teises osas varnishreload praegu aktiivseks VCL-iks, kui selline on. Antud juhul on see "reload_20190101_120000_12397".

Suurepärane, muutuja ${VCL_SHOW} sisaldab varnishi jaoks täit konfiguratsiooni, nüüd on see selge. Nüüd sain lõpuks aru, miks dash'i väljund set -x olid nii rikutud — see sisaldas määratud konfiguratsiooni sisu.

Oluline on mõista, et täielik VCL konfiguratsioon võib sageli koosneda mitmest failist. C-stiilis kommentaare kasutatakse selle määratlemiseks, kust ühed konfiguratsioonifailid on teistesse lisatud, ja see ongi see, millest järgmine koodilõik räägib.
Sisestatud failide kommentaaride süntaks on järgmine:

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

Kontekstis ei oma numbrid tähtsust, meid huvitab faili nimi.

Mis toimub käskude mudas, mis algab realt 116?
Vaatame seda lähemalt.
Käsk koosneb neljast osast:

1. Lihtne echo, mis väljendab muutuja väärtust ${VCL_SHOW}

   echo "$VCL_SHOW"

2. awk, mis otsib rida (kirjet), kus esimene väli tekstist lahutamisel on “//” ja teine — «VCL.SHOW».
   Awk väljastab esimese vastava reana nende mustritele ja lõpetab seejärel kohe töötlemise.

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

3. Koodiblokk, mis salvestab viiesse muutujasse ruuduga eraldatud väljade väärtused. Viies muutuja FILE saab ülejäänud rea. Lõpuks väljastab viimane echo muutuja sisu. ${FILE}.

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

4. Kuna kõik sammud 1 kuni 3 on paigutatud alamšelli, siis muutuja $FILE salvestatakse muutuja VCL_FILE.

Nagu 119. rea kommentaarist järeldub, teenib see ühte eesmärki: usaldusväärselt töödelda juhtumeid, kus VCL viitab failidele, mille nimedes on tühikuid.

Olen kommenteerinud välja algse töötlemise logi ${VCL_FILE} ja proovisin muuta käskude järjekorda, kuid see ei viinud mingile tulemuseni. Kõik töötas mul hästi, kuid teenuse käivitamisel andis see vea.

Tundub, et viga ei esine skripti käsitsi käivitamisel, samas kui väidetavad 30 minutit on juba kuus korda läbi saanud ja lisaks on tekkinud kõrgema prioriteediga ülesanne, mis tõukab teised asjad kõrvale. Nädala ülejäänud osa oli täidetud mitmesuguste ülesannetega ja ainult veidi oli vaheldust sed-iga seotud ettekandest ja kandidaadiga intervjuust. Viga selles varnishreload oli pöördumatult kadunud aja liivades.

Teie nii-öelda sed-fu... on tegelikult... jama.

Kuna järgmisel nädalal oli üks üsna vaba päev, otsustasin taas selle piletiga tegeleda. Lootsin, et minu ajus on mingi taustprotsess kogu aeg selle probleemi lahendust otsinud ja seekord mõistan ma kindlasti, mis on valesti.

Kuna eelmisel korral lihtne koodimuudatus ei aidanud, otsustasin selle 116. reast ümber kirjutada. Igatahes oli olemasolev kood tobe. Ja seal pole absoluutselt mingit vajadust kasutada. read.

Vaadates viga veel kord:
sh: echo: katki pipe. — selles käsus on echo kahel kohal, kuid mul on kahtlus, et esimene on tõenäolisem süüdlane (noh, vähemalt kaassüüdlane). Awk ei inspireeri samuti usaldust. Ja juhul kui tegelikult see. awk | {read; echo} ehk see konstruktsioon toob kõik need probleemid, miks mitte seda asendada? See ühisrida ei kasuta awk kõiki võimalusi, lisaks sellele see üleliigne. read kaugelt.

Kuna eelmisel nädalal oli ettekande teema sed, tahtsin proovida oma hiljuti omandatud oskusi ja lihtsustada. echo | awk | { read; echo } rohkem arusaadavaks. echo | sed. Kuigi see pole kindlasti parim meetod vea leidmiseks, mõtlesin, et prooviksin oma sed-fu ja võib-olla õpiksin probleemi kohta midagi uut. Käigupealt palusin oma kolleegil, kes on sed-i ettekande autor, aidata mul välja mõelda tõhusam sed-skript.

Saates sisu varnishadm vcl.show -v "$VCL_NAME" faili, et saaksin keskenduda sed-skripti kirjutamisele ilma teenuse taaskäivitamisega seotud probleemideta.

Lühike ülevaade sellest, kuidas sed sisendit töötleb, on saadaval oma GNU käsiraamatust. Sed-i lähtekoodis on sümbol n selgelt määratletud reajaotajana.

Mõne läbikäiguga ja oma kolleegi soovitustega kirjutasime sed-skripti, mis andis sama tulemuse, mis algne rida 116.

Siin on näidisdokumendi sisu:

> 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

See ei pruugi eelnevalt antud kirjelduse põhjal ilmselge olla, kuid meid huvitab ainult esimene kommentaar. // VCL.SHOW, kus sisendites võib olla mitu. Just seetõttu lõpetab originaal awk oma töö pärast esimest vaste leidmist.

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

Nii et skripti varnishreload sisu näeb välja umbes nii:

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

Ülaltoodud loogikat võib lühidalt väljendada järgmiselt:
Kui rida vastab regulaaravaldistele // VCL.SHOW, siis ahmi järele teksti, mis sisaldab neid kahte numbrit, ja salvesta kõik, mis pärast seda toimingut jääb. Väljasta salvestatud väärtus ja lõpeta programm.

Lihtne, eks?

Me olime sed skriptiga rahul ja ka sellega, et see asendab kogu originaalkoodi. Kõik mu testid andsid soovitud tulemused, seega muutsin "varnishreload" serveris ja käivitasin uuesti systemctl reload varnish. Neetud viga echo: write error: Broken pipe naeris meile taas näkku. Vihje kandidaat ootas uut käsku pimedas terminalis...

Allikas: habr.com