🥇Падение в заекова дупка: История за една грешка при презареждане на varnish — част 1

гостинушка, натискаща по бутоните през последните 20 минути, все едно от това зависи животът му, се обръща към мен с полудиво изражение в очите и хитра усмивка — «Човече, май разбрах.»

«Виж тук,» — казва, сочейки един от символите на екрана — «Залагам на моята червена шапка, че ако добавим тук това, което ти току-що изпратих» — сочейки на друга част от кода — «грешката вече няма да се появява.»

Неприятно изненадан и уморен, променям sed израза, над който сме работили известно време, запазвам файла и стартирам systemctl varnish reload. Съобщението за грешка изчезна...

«Имейлите, които обменях с кандидата,» продължи колегата ми, докато усмивката му преминава в искрена усмивка, пълна с радост, «изведнъж ми хрумна, че това е точно същият проблем!»

Как всичко започна

Статията предполага разбиране на принципите на работа на bash, awk, sed и systemd. Знанието за varnish е желааемо, но не е задължително.
Временните отметки в снипетите са променени.
Написано в сътрудничество с гостинушка.
Текстът е превод на оригинала, публикуван на английския език преди две седмици; превод boikoden.

Слънцето проблясва през панорамните прозорци в още един топъл есенен сутрин, чаша свежозаварен напитка с кофеин стои настрани от клавиатурата, в слушалките звучи любимата симфония на звуците, заглушаваща шумоленето на механичните клавиатури, а първата запис в списъка на тикетите на беклога на канбан дъската весело блести с решаващото заглавие “Разследвайте varnishreload sh: echo: I/O error in staging” (Разследвайте “varnishreload sh: echo: I/O error” в стейджа). Когато става въпрос за varnish, грешки не съществуват и не могат да съществуват, дори и те да не водят до никакви проблеми, както в този случай.

За тези, които не са запознати с varnishreload, това е прост шелл скрипт, използван за презареждане на конфигурацията на varnish-а — също наречен VCL.

Както подсказва името на тикета, грешката се е появила на един от сървърите на стейджа, а тъй като бях убеден, че маршрутизацията на varnish на стейджа работи коректно, предположих, че става въпрос за нещо малко. И така, просто съобщение, попаднало в затворен поток. Взимам тикета за себе си, напълно уверен, че ще го отбележа за готов след по-малко от 30 минути, ще се потупам по рамото за почистването на борда от поредния боклук и ще се върна към по-важни неща.

Сблъсквайки се в стената с 200 км/ч

Отваряйки файла varnishreload, на един от сървърите, управлявани от Debian Stretch, видях шелл скрипт с дължина по-малка от 200 реда.

Преминавайки през скрипта, не забелязах нищо, което би могло да доведе до проблеми при многократното му изпълнение директно от терминала.

Накрая, това е стейдж, дори ако се счупи, никой няма да се оплаче, ами… не прекалено много. Стартирам скрипта и гледам какво ще излезе на терминала, само че вече няма и следа от грешки.

Още няколко стартирания, за да съм сигурен, че не мога да възпроизведа грешката без допълнителни усилия, и започвам да измислям как да променя този скрипт, за да се опитам да предизвикам грешка.

Може би да пренасоча STDOUT (с помощта на > &-)? Или STDERR? Нито едно от двете в крайна сметка не сработи.

Очевидно, systemd по някакъв начин променя средата на стартиране, но как, и защо?
Включвам vim и редактирам varnishreload, добавяйки set -x точно под шебанга, надявайки се, че дебаг изходът на скрипта ще хвърли малко светлина.

Файлът е коригиран, така че рестартирам varnish и виждам, че промяната напълно е развалила всичко… Изходът е пълен хаос, в който има тонове Си-подобен код. Дори скролването в терминала не е достатъчно, за да намеря откъде започва. Аз съм в пълно объркване. Може ли режимът на отстраняване на грешки да повлияе на работата на програмите, които се стартират в скрипта? Не, абсурд. Грешка в шелла? Няколко възможни сценария минават през главата ми като хлебарки в различни посоки. Чашата с кафе се изпразва мигновено, бързо пътуване до кухнята за попълване на запаса и… напред. Отварям скрипта и внимавам на шебанга: #!/bin/sh.

/bin/sh — това всъщност е просто симлинк на bash, така че скриптът трябва да се интерпретира в POSIX съвместим режим, нали? Ами не! Оболката по подразбиране в Debian е dash, и точно това е на което се отнася /bin/sh.

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

За проба промених шебанга на #!/bin/bash, изтрих set -x и опитах отново. Накрая, при последното презареждане на varnish, се появи някаква грешка в изхода:

Jan 01 12:00:00 hostname varnishreload[32604]: /usr/sbin/varnishreload: линия 124: echo: грешка при запис: Счупена тръба
Jan 01 12:00:00 hostname varnishreload[32604]: VCL 'reload_20190101_120000_32604' компилиран

Ред 124, ето го!

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                         # всичко това е само за да се обработят празни места в 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 "неуспех при получаване на името на VCL файла"
129         fi
130
131         echo "$VCL_FILE"
132 }

Но както се оказа, ред 124 е доста празен и не представлява интерес. Можех само да предположа, че грешката се е появила като част от многострочен коментар, започващ на ред 116.
Какво всъщност се записва в променливата VCL_FILE в резултат на изпълнението на споменатия по-горе саб-шел?

Първо, той изпраща съдържанието на променливата VLC_SHOW, създадена на ред 115, на следващата команда чрез пайп. А какво се случва там?

Първо, използва се varnishadm, който е част от инсталационния пакет varnish, за настройка на varnish без перезареждане.

Подкомандата vcl.show -v се използва за извеждане на цялата конфигурация на VCL, посочена в ${VCL_NAME}, на STDOUT.

За да покажете текущата активна конфигурация VCL, както и няколко предишни версии на конфигурациите на varnish, които все още са в паметта, можете да използвате командата varnishadm vcl.list, чийто изход ще бъде подобен на посочения по-долу:

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

Стойността на променливата ${VCL_NAME} се задава в друга част на скрипта varnishreload на името на активния в момента VCL, ако такъв съществува. В този случай това ще бъде “reload_20190101_120000_12397”.

Страхотно, променливата ${VCL_SHOW} съдържа пълната конфигурация за varnish, което е ясно. Сега най-накрая разбрах защо изходът на dash с set -x се оказа толкова повреден — той включваше съдържанието на получената конфигурация.

Важно е да се разбере, че пълната конфигурация на VCL често може да бъде слепена от няколко файла. Коментарите в стил C се използват, за да се определи къде е включен един файл в друг, и именно това се отнася за цялата следваща линия от фрагмента на кода.
Синтаксисът на коментарите, описващи включените файлове, има следния формат:

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

Цифрите в този контекст не са важни, интересува ни името на файла.

Какво всъщност се случва в блатото на командите, започващи на ред 116?
Нека да разберем.
Командата се състои от четири части:

Просто echo, което извежда стойността на променливата ${VCL_SHOW}
```
echo "$VCL_SHOW"
```
awk, която търси ред (запис), където първото поле след разбиването на текста е “//”, а второто — «VCL.SHOW».
Awk ще изведе първия ред, съответстващ на тези шаблони, а след това веднага ще прекрати обработката.
```
awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'
```
Блок от код, който запазва в пет променливи стойностите на полетата, разделени с интервали. Петата променлива FILE получава остатъка от реда. Накрая, последният echo извежда съдържанието на променливата ${FILE}.
```
{ read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }
```
Тъй като всички стъпки от 1 до 3 са обгърнати в подшел, извеждането на стойността $FILE ще бъде записано в променливата VCL_FILE.

Както произтича от коментара на 119-ти ред, това служи само за една цел: да се обработват надеждно случаите, когато VCL ще се отнася до файлове с интервали в имената.

Закоментирано е оригиналното логическо обработване за ${VCL_FILE} и опитах да променя последователността на командите, но това не доведе до нищо. При мен всичко работеше безпроблемно, а при стартиране на услугата възникваше грешка.

Изглежда, че грешката просто не може да бъде възпроизведена при стартиране на скрипта ръчно, като предполагаемите 30 минути вече приключиха около шест пъти, а в допълнение се появи по-приоритетна задача, която отклони останалите ангажименти. Останалата част от седмицата беше заета с различни задачи и беше малко разредена с доклад за sed и интервю с кандидат. Проблемът с грешката в varnishreload беше безвъзвратно загубен в пясъците на времето.

Вашето така наречено sed-фу… всъщност… е глупост.

Следващата седмица имаше един доста свободен ден, така че отново реших да се занимая с този тикет. Надявах се, че в мозъка ми, някакъв фонов процес през цялото време е търсил решение на проблема и този път определено ще разбера за какво става въпрос.

Тъй като миналия път простото изменение на кода не помогна, просто реших да го пренапиша, започвайки от 116-та ред. Във всеки случай съществуващият код беше безсмислен. И в него няма абсолютно никаква необходимост да се използва read.

Гледайки грешката отново:
sh: echo: broken pipe — в тази команда echo се намира на две места, но подозирам, че първото е по-вероятният виновник (или поне съучастник). Awk също не вдъхва доверие. И в случай, че наистина awk | {read; echo} този синтаксис води до всички тези проблеми, защо да не го заменим? Тази едноредова команда не използва всичките възможности на awk, освен че добавя и това излишно read проблеми.

Тъй като миналата седмица имаше доклад за sed, исках да опитам новопридобитите си умения и да опростя echo | awk | { read; echo} до по-разбираем echo | sed. Въпреки че определено не е най-добрият подход за идентифициране на грешки, помислих, че поне ще опитам да използвам своето sed-fu и може би ще науча нещо ново за проблема. На този етап помолих колегата си, автора на доклада за sed, да ми помогне да измисля по-ефективен sed скрипт.

Изпратих съдържанието на varnishadm vcl.show -v "$VCL_NAME" в файл, така че да мога да се съсредоточа върху написването на sed скрипта без никакви притеснения свързани с рестартиране на услугата.

Кратко описание на начина, по който sed обработва входните данни, може да бъде намерено в неговото GNU ръководство. В изходния код на sed символът n явно е уточнен като разделител на редове.

С няколко итерации и с препоръките на колегата си, написахме sed скрипт, който даваше същия резултат, както и цялата оригинална ред 116.

По-долу е представен пример на файла с входните данни:

> 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

Може да не е очевидно от горното описание, но ние се интересуваме само от първия коментар // VCL.SHOW, като в входните данни може да има няколко. Именно затова оригиналният awk приключва работата си след първото съвпадение.

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

И така, съдържанието на скрипта varnishreload ще изглежда приблизително така:

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

Горепосочената логика може да бъде кратко изразена по следния начин:
Ако низът отговаря на регулярното изражение // VCL.SHOW, тогава алчно изяж текста, включващ и двете числа в този низ, и запази всичко, което ще остане след тази операция. Издай запазената стойност и приключи програмата.

Просто, нали?

Бяхме доволни от скрипта на sed и от факта, че той замества целия оригинален код. Всички мои тестове дадоха желаните резултати, затова смених “varnishreload” на сървъра и отново стартирах systemctl reload varnish. Проклетата грешка echo: write error: Broken pipe отново ни се присмиваше. Мигащият курсор очакваше въвеждането на нова команда в тъмната пустота на терминала…

Източник: habr.com

Падане в заешка дупка: История за една грешка при перезареждане на varnish — част 1

Как всичко започна

Сблъсквайки се в стената с 200 км/ч

Вашето така наречено sed-фу… всъщност… е глупост.