, Молотивши по кнопках протягом попередніх 20 хвилин, як би від цього залежало його життя, повертається до мене з напів-диким виразом в очах і хитрою усмішкою - "Чувак, я здається зрозумів."
«Подивися ось сюди,» — каже, показуючи на один із символів на екрані — «Сперечаємося на мій червоний капелюх, що якщо ми додамо ось сюди те, що я тобі щойно послав» — показуючи на іншу ділянку коду — «помилка вже не буде виводитися.»
Трохи спантеличений і втомлений, я змінюю sed вираз, над яким ми якийсь час вже працювали, зберігаю файл і запускаю systemctl varnish reload. Повідомлення про помилку зникло…
«Мейли, якими я обмінювався з кандидатом,» продовжив мій колега, в той час як його усмішка переростає в непідробну посмішку сповнену радості, «До мене раптом дійшло що це така сама проблема!»
З чого воно все починалося
Стаття передбачає розуміння принципів роботи bash, awk, sed та systemd. Знання varnish вітається, але не є обов'язковим.
Тимчасові мітки у сніпетах змінені.
Написано разом із .
Цей текст є перекладом оригіналу, опублікованого англійською мовою два тижні тому; переклад .
Сонце просвічує крізь панорамні вікна черговим теплим осіннім ранком. оносний заголовок “Investigate varnishreload sh: echo: I/O error in staging” (Розслідуйте “varnishreload sh: echo: I/O error” у стейджі). Коли мова заходить про 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 обробляє вхідні дані, можна знайти в . У вихідниках 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