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

Гостинушанка, след като удряше копчетата през предходните 20 минути, сякаш животът му зависеше от това, се обръща към мен с полудиво изражение на очите и лукава усмивка - "Пич, май разбрах".

„Вижте тук“, казва той, сочейки един от знаците на екрана, „обзалагам се, че ако добавим тук това, което току-що ви изпратих“ – сочейки друга част от кода – „грешката вече няма да е да се покаже."

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

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

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

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

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

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

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

Блъскане в стена с 200 км/ч

Отваряне на файл varnishreload, на един от сървърите, изпълняващи Debian Stretch, видях shell скрипт с дължина под 200 реда.

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

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

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

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

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

Файлът е фиксиран, така че презареждам лак и виждам, че промяната напълно счупи всичко ... Ауспухът е пълна бъркотия, с тонове C-подобен код в него. Дори превъртането в терминала не е достатъчно, за да намерите къде започва. Напълно съм объркана. Може ли режимът за отстраняване на грешки да повлияе на работата на програми, изпълнявани в скрипт? Без глупости. Грешка в черупката? Няколко възможни сценария летят в главата ми като хлебарки в различни посоки. Чаша пълна с кофеин напитка се изпразва мигновено, бързо пътуване до кухнята за презареждане и... да тръгваме. Отварям скрипта и разглеждам по-отблизо shebang: #!/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

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

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

Ред 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                         # 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 }

Но както се оказа, линия 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} съдържа пълната конфигурация за лак, засега ясна. Сега най-накрая разбирам защо тире извежда с set -x се оказа толкова развален - включваше съдържанието на получената конфигурация.

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

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

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

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

1. прост echo, който показва стойността на променливата ${VCL_SHOW}

   echo "$VCL_SHOW"

2. awk, който търси ред (запис), където първото поле след разделяне на текста ще бъде “//”, а второто ще бъде “VCL.SHOW”.
   Awk ще напише първия ред, който съответства на тези шаблони и след това ще спре обработката веднага.

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

3. Блок от код, който съхранява стойностите на полетата в пет променливи, разделени с интервали. Петата променлива FILE получава останалата част от реда. Накрая последното ехо изписва съдържанието на променливата ${FILE}.

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

4. Тъй като всички стъпки от 1 до 3 са затворени в под-обвивка, изходът на стойността $FILE ще бъде записано в променлива VCL_FILE.

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

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

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

Вашият така наречен сед-фу... всъщност... боклук

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

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

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

От миналата седмица имаше доклад за sedИсках да изпробвам новопридобитите си умения и да опростя echo | awk | { read; echo} в по-разбираемо echo | sed. Въпреки че това определено не е най-добрият подход за улавяне на грешката, реших поне да опитам моя sed-fu и може би да науча нещо ново за проблема. По пътя помолих моя колега, автора на sed talk, да ми помогне да измисля по-ефективен 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 пак ни се изсмя в лицето. Намигащ курсор чакаше да бъде въведена нова команда в тъмната празнота на терминала...

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