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?
Давайте разберемся.
Команда состоит из четырех частей:
- Простое
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 вновь смеялась нам в лицо. Подмигивающий курсор ожидал ввода новой команды в темной пустоте терминала…
ссылка на оригинал статьи https://habr.com/ru/post/477968/
Добавить комментарий