2021-06-03

techquisitor: (sis)
2021-06-03 11:25 pm

Давно я что-то про работу не писал...

...а теперь представился случай. Расскажу-ка я про занятный случай связанный Varnish.

Итак, есть энное количество кешей, ранее работавших на Varnish 3. Работало всё хорошо, но третья ветка давно очень устарела и более не поддерживается. Так что мы смигрировали на ветку 6.0.x, которая является LTS релизом. Пришлось правда переписать кастомные модули для него, но это отдельная история.

Всё б ничего, но после апгрейдв мы заметили в мониторинге такую вещь, что Varnish стал постоянно перезапускаться. Расследование показало, что умирал порождаемый варнишем процесс.
Хочу заметить, что у нас для кастомных сервисов используется runit. Простой как палка, но своё дело делает (systemd-хейтеры и любители поотлаживать bash — вам сюда!). Так вот в процессе дебага мы отловили такую хрень, что SIGTERM посылает сам runit. Что за ерунда? С третьим варнишем таких проблем не было, исправно работал годами.
Тем не менее, в strace видно следующую картину:

1622625209.201334 --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=4431, si_uid=0} ---
1622625209.202221 --- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=4431, si_uid=0} ---
1622625209.203109 rt_sigreturn({mask=[]}) = 0 <0.065258>
1622625209.333354 write(2, "Error: Manager got SIGTERM\n", 27) = 27 <0.000865>
1622625209.590396 getpid()              = 22267 <0.001420>
1622625209.592812 sendto(7, "<131>Jun  2 09:13:29 varnishd[22"..., 57, MSG_NOSIGNAL, NULL, 0) = 57 <0.000927>
1622625209.718907 write(2, "Debug: Stopping Child\n", 22) = 22 <0.157719>
1622625209.877579 getpid()              = 22267 <0.000890>
1622625209.879363 sendto(7, "<135>Jun  2 09:13:29 varnishd[22"..., 52, MSG_NOSIGNAL, NULL, 0) = 52 <0.000916>
После некоторого времени дебага, обнаружили странную вещь. У нас на машинах крутится два инстанса варниша с разными vcl и настройками. Один runit-сервис так и называется varnish, а второй несколько иначе. И вот второй, что интересно, работает как надо.
Нас взяло любопытство и мы взяли и запихвли во второй инстанс настройки от первого. Что интересно, всё заработало.
Дальше мы в порядке бреда просто переименовали runit varnish в что-то другое и... всё заработало.

Проблема решена, но вообще интересно, что её породило. Пока в гипотезе у нас значится, что сам varnish вызывает что-то с точно таким же именем и ранит принимает это за лишний форк или ещё что-то и естественно его прибивает. Дальше вы уже знаете.

Так и живём.