Падзенне ў трусіную нару: Гісторыя пра адну памылку перазагрузкі varnish — частка 1

ghostinushanka, Малаціўшы па кнопках на працягу папярэдніх 20 хвілін, як калі б ад гэтага залежала яго жыццё, паварочваецца да мяне з паў-дзікім выразам у вачах і хітрай ухмылкай - «Чувак, я здаецца зразумеў.»

«Паглядзі вось сюды,» - кажа, паказваючы на ​​адзін з сімвалаў на экране - «Спрачаемся на мой чырвоны капялюш, што калі мы дадамо вось сюды тое, што я табе толькі што паслаў» - паказваючы на ​​іншы ўчастак кода - «памылка ўжо не будзе выводзіцца.»

Трохі збянтэжаны і стомлены, я змяняю sed выраз, над якім мы нейкі час ужо працавалі, захоўваю файл і запускаю systemctl varnish reload. Паведамленне пра памылку знікла…

"Мэйлы, якімі я абменьваўся з кандыдатам," працягнуў мой калега, у той час як яго ўхмылка перарастае ў непадробную ўсмешку поўную радасці, "Да мяне раптам дайшло што гэта сапраўды такая ж праблема!"

З чаго яно ўсё пачыналася

Артыкул мяркуе разуменне прынцыпаў працы bash, awk, sed і systemd. Веды varnish вітаецца, але не з'яўляецца абавязковым.
Часовыя пазнакі ў сніпетах зменены.
Напісана разам з ghostinushanka.
Гэты тэкст з'яўляецца перакладам арыгінала, апублікаванага на англійскай мове два тыдні таму; пераклад boikoden.

Сонца прасвечвае скрозь панарамныя вокны чарговай цёплай восеньскай раніцай, кубак свежапрыгатаванага насычанага кафеінам напою ў баку ад клавіятуры, у слухаўках гучыць каханая сімфонія гукаў, якая перакрывае шолах механічных клавіятур. абносны загаловак “Investigate 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: 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} змяшчае поўную канфігурацыю для varnish, пакуль зразумела. Цяпер я, нарэшце, зразумеў, чаму выснова dash з set -x апынуўся такім бітым - ён уключаў у сябе змесціва атрыманай канфігурацыі.

Важна разумець, што поўная канфігурацыя VCL часта можа быць злеплена з некалькіх файлаў. Каментары ў Сі стылі выкарыстоўваюцца для вызначэння таго, дзе адны файлы канфігурацыі былі ўключаны ў іншыя, і гэта менавіта тое, пра што, уласна, увесь прыведзены ніжэй радок фрагмента кода.
Сінтаксіс каментароў, якія апісваюць уключаныя файлы, мае наступны фармат:

// 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 атрымлівае рэшту радка. Нарэшце, апошні echo выпісвае змесціва зменнай ${FILE}.
    { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }
  4. Паколькі ўсе крокі з 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

Дадаць каментар