Falling Down the Rabbit Hole: Příběh jedné chyby restartu laku - část 1

Ghostinushanka, poté, co předchozích 20 minut bušil do knoflíků, jako by na tom závisel jeho život, se na mě otočí s polodivokým výrazem v očích a potutelným úsměvem - "Ty vole, myslím, že rozumím."

"Podívejte se sem," říká a ukazuje na jeden ze symbolů na obrazovce, "vsadím se o svůj červený klobouk, pokud přidáme to, co jsem vám sem právě poslal," ukazuje na další část kódu, "chyba se již nebude zobrazovat."

Trochu zmatený a unavený změním příkaz sed, na kterém jsme chvíli pracovali, uložím soubor a spustím systemctl varnish reload. Chybová zpráva zmizela...

"Ty e-maily, které jsem si vyměnil s kandidátem," pokračoval můj kolega, když se jeho úšklebek přeměnil v upřímný úsměv plný radosti, "Najednou mi došlo, že je to úplně stejný problém!"

Jak to všechno začalo

Článek předpokládá pochopení toho, jak funguje bash, awk, sed a systemd. Znalost laku je výhodná, ale není nutná.
Časová razítka ve úryvcích byla změněna.
Napsáno s Ghostinushanka.
Tento text je překladem originálu vydaného v angličtině před dvěma týdny; překlad boyikoden.

Sluníčko prosvítá panoramatickými okny dalšího teplého podzimního rána, šálek čerstvě uvařeného kofeinového nápoje odpočívá od klávesnice, oblíbená symfonie zvuků hraje přes šustění mechanických klávesnic ve sluchátkách a první záznam v seznamu nevyřízených tiketů na nástěnce kanban hravě září osudovým názvem „InvestigateInlakvestigate institush staging“ : echo: I/O error” ve fázi). Co se týče laku, nejsou a nemohou být žádné chyby, i když z nich neplynou žádné problémy, jako v tomto případě.

Pro ty, kteří nejsou obeznámeni přeložit lak, jedná se o jednoduchý shell skript používaný k opětovnému načtení konfigurace lak - nazývaný také VCL.

Jak název tiketu napovídá, k chybě došlo na jednom ze serverů ve fázi, a protože jsem si byl jistý, že směrování laku ve fázi funguje správně, předpokládal jsem, že se bude jednat o drobnou chybu. Takže jen zpráva, která se dostala do již uzavřeného výstupního proudu. Beru si lístek pro sebe, s plnou důvěrou, že ho označím za připravený za méně než 30 minut, poplácám se po rameni, abych vyčistil tabuli od dalšího harampádí a vracím se k důležitějším věcem.

Náraz do zdi v rychlosti 200 km/h

Otevření souboru varnishreload, na jednom ze serverů, na kterých běží Debian Stretch, jsem viděl skript shellu dlouhý méně než 200 řádků.

Při běhu skriptu jsem neviděl nic, co by mohlo způsobit problémy při jeho vícenásobném spuštění přímo z terminálu.

To je přeci etapa, i když se to rozbije, nikdo si nebude stěžovat, no ... nic moc. Spustím skript a uvidím, co se zapíše do terminálu, ale chyby už nejsou vidět.

Několik dalších běhů, abych se ujistil, že nemohu chybu reprodukovat bez zvláštního úsilí, a začínám zjišťovat, jak změnit tento skript, aby stále házel chybu.

Může skript blokovat STDOUT (pomocí > &-)? Nebo STDERR? Ani jedno se nakonec nepovedlo.

Je zřejmé, že systemd nějakým způsobem mění běhové prostředí, ale jak a proč?
Zapnu vim a upravím varnishreload, přidání set -x přímo pod shebangem v naději, že ladění výstupu skriptu vrhne trochu světla.

Pilník je opravený, tak znovu nabiju lak a vidím, že změna úplně všechno rozbila... Výfuk je naprostý nepořádek, v něm jsou tuny kódu jako C. Ani rolování v terminálu nestačí k nalezení místa, kde začíná. Jsem úplně zmatená. Může režim ladění ovlivnit práci programů spuštěných ve skriptu? Ne, kecy. Chyba ve skořápce? V hlavě mi létá několik možných scénářů jako švábi různými směry. Šálek nápoje plného kofeinu se okamžitě vyprázdní, rychlý výlet do kuchyně pro doplnění zásob a... jdeme na to. Otevřu scénář a podívám se blíže na shebang: #!/bin/sh.

/bin/sh - toto je jen bash symbolický odkaz, takže skript je interpretován v režimu kompatibilním s POSIX, že? To tam nebylo! Výchozí shell na Debianu je dash, což je přesně ono odkazuje /bin/sh.

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

Kvůli soudu jsem změnil shebang na #!/bin/bash, odstraněno set -x a zkusil to znovu. Nakonec se při následném nabití laku objevila ve výstupu tolerovatelná chyba:

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

Linka 124, tady to je!

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 }

Jak se ale ukázalo, linka 124 je spíše prázdná a bez zájmu. Mohl jsem pouze předpokládat, že k chybě došlo v rámci víceřádku začínajícího na řádku 116.
Co se nakonec zapíše do proměnné VCL_FILE v důsledku provedení výše uvedeného sub-shell?

Na začátku odešle obsah proměnné VLC_SHOW, vytvořený na řádku 115, k dalšímu příkazu přes potrubí. A co se tam potom stane?

Za prvé, používá varnishadm, který je součástí instalačního balíčku laku, pro konfiguraci laku bez restartování.

dílčí příkaz vcl.show -v se používá k výstupu celé konfigurace VCL specifikované v ${VCL_NAME}, do STDOUT.

Chcete-li zobrazit aktuálně aktivní konfiguraci VCL a také několik předchozích verzí konfigurací směrování laku, které jsou stále v paměti, můžete použít příkaz varnishadm vcl.list, jehož výstup bude podobný následujícímu:

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

Proměnná hodnota ${VCL_NAME} zasazené do jiné části scénáře varnishreload na název aktuálně aktivního VCL, pokud existuje. V tomto případě to bude „reload_20190101_120000_12397“.

Dobře, variabilní. ${VCL_SHOW} obsahuje kompletní konfiguraci pro lak, zatím přehlednou. Teď konečně chápu, proč pomlčka výstup s set -x se ukázalo být tak rozbité - zahrnovalo obsah výsledné konfigurace.

Je důležité pochopit, že kompletní konfiguraci VCL lze často sestavit z více souborů. Komentáře ve stylu C se používají k definování toho, kde byl jeden konfigurační soubor zahrnut do jiného, ​​a přesně o tom je následující řádek úryvku kódu.
Syntaxe komentářů popisujících zahrnuté soubory má následující formát:

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

Čísla v této souvislosti nejsou důležitá, nás zajímá název souboru.

Co se tedy stane v bažině příkazů, která začíná na řádku 116?
Zjistíme to.
Příkaz se skládá ze čtyř částí:

  1. Jednoduché echo, který zobrazuje hodnotu proměnné ${VCL_SHOW}
    echo "$VCL_SHOW"
  2. awk, který hledá řádek (záznam), kde první pole po rozdělení textu bude „//“ a druhé pole „VCL.SHOW“.
    Awk vypíše první řádek, který odpovídá těmto vzorům, a poté okamžitě zastaví zpracování.

    awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'
  3. Blok kódu, který ukládá hodnoty pole do pěti proměnných oddělených mezerami. Pátá proměnná FILE přijímá zbytek řádku. Nakonec poslední echo vypíše obsah proměnné ${FILE}.
    { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }
  4. Protože všechny kroky 1 až 3 jsou uzavřeny v podslupce, výstup hodnoty $FILE bude zapsána do proměnné VCL_FILE.

Jak naznačuje komentář na řádku 119, slouží to jedinému účelu, a to spolehlivému řešení případů, kdy VCL bude odkazovat na soubory s mezerami v jejich názvech.

Původní logiku zpracování jsem okomentoval ${VCL_FILE} a pokusil se změnit pořadí příkazů, ale k ničemu to nevedlo. Vše mi fungovalo čistě a v případě spuštění služby to hlásilo chybu.

Zdá se, že při ručním spouštění skriptu chyba prostě není reprodukovatelná, přičemž odhadovaných 30 minut již šestkrát skončilo a navíc se objevil úkol s vyšší prioritou, který odsouvá zbytek případů stranou. Zbytek týdne byl naplněn nejrůznějšími úkoly a byl jen mírně rozmělněn povídáním o sed a pohovorem s kandidátem. Problém s chybou v varnishreload nenávratně ztracený v písku času.

Vaše takzvané sed-fu... vlastně... svinstvo

Následující týden měl jeden docela volný den, tak jsem se rozhodl vzít si tento lístek znovu. Doufal jsem, že v mém mozku nějaký proces na pozadí celou tu dobu hledal řešení tohoto problému a tentokrát už určitě pochopím, co je špatně.

Protože minule jen změna kódu nepomohla, rozhodl jsem se jej přepsat od 116. řádku. V každém případě byl stávající kód hloupý. A není absolutně nutné používat read.

Znovu se podívejte na chybu:
sh: echo: broken pipe - v tomto příkazu je echo na dvou místech, ale mám podezření, že první je pravděpodobnější viník (no, nebo alespoň spolupachatel). Awk také nevzbuzuje důvěru. A v případě, že tomu tak skutečně je awk | {read; echo} design vede ke všem těmto problémům, proč jej nenahradit? Tento jednořádkový příkaz nepoužívá všechny funkce awk a dokonce ani toto navíc read v přídavku.

Od minulého týdne tu byla zpráva o sedChtěl jsem vyzkoušet své nově nabyté dovednosti a zjednodušit echo | awk | { read; echo} do srozumitelnějšího echo | sed. I když to rozhodně není nejlepší přístup k odchytu chyby, řekl jsem si, že alespoň vyzkouším své sed-fu a možná se o problému dozvím něco nového. Cestou jsem požádal svého kolegu, spisovatele sed talk, aby mi pomohl vymyslet efektivnější sed skript.

Zahodil jsem obsah varnishadm vcl.show -v "$VCL_NAME" do souboru, abych se mohl soustředit na psaní skriptu sed bez jakýchkoli potíží s restartováním služby.

Stručný popis toho, jak přesně sed zpracovává vstup, najdete v jeho GNU manuál. Ve zdrojích sed symbol n explicitně specifikován jako oddělovač řádků.

V několika průchodech a s radou mého kolegy jsme napsali sed skript, který dal stejný výsledek jako celý původní řádek 116.

Níže je ukázkový soubor se vstupními daty:

> 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

Z popisu výše to možná není zřejmé, ale nás zajímá pouze první komentář // VCL.SHOWa ve vstupních datech jich může být několik. To je důvod, proč původní awk skončí po prvním zápase.

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

Obsah skriptu pro lakreload by tedy vypadal asi takto:

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

Výše uvedená logika se dá shrnout takto:
Pokud řetězec odpovídá regulárnímu výrazu // VCL.SHOW, pak nenasytně hltat text, který obsahuje obě čísla v tomto řádku, a uložit vše, co po této operaci zbyde. Zadejte uloženou hodnotu a ukončete program.

Jednoduché, že?

Byli jsme spokojeni se skriptem sed a skutečností, že nahrazuje veškerý původní kód. Všechny mé testy poskytly požadované výsledky, takže jsem na serveru změnil „varnishreload“ a znovu spustil systemctl reload varnish. Špinavá chyba echo: write error: Broken pipe znovu se nám vysmál do tváře. Mrkající kurzor čekal na zadání nového příkazu v temné prázdnotě terminálu...

Zdroj: www.habr.com

Přidat komentář