Der CollabDocdenburg: Постмортем одного инцидента в Fibery
DISCLAIMER: Текст написан инженерами команды Fibery (в основном Володей) в назидание молодым поколениям и как памятник сложности современной разработки программного обеспечения.
В тексте присутствует большое количество специальной и нецензурной лексики, поэтому читать рекомендуется инженерам, познавшим даунтайм в продакшене.
Действующие лица:
- Коллаб — сервис коллаборативных документов в Fibery
- Вова — разработчик Коллаба
- Андрей — друг Вовы (тоже разработчик, но ядра)
- Балансер — неизвестно как устроенный кусок чего-то
БЕСПЕЧНЫЙ ВТОРНИК
27 апреля (вторник) коллаб начал рестартовать по памяти.
Илья поднял лимит и оповестил о проблеме.
Вова посмотрел на график коллаба и подумал, что выросла нагрузка — вот и память подросла.
Решил понаблюдать за сервисом с поднятым лимитом (и лицом).
Память потиху росла, но до 2 гигов выставленного лимита ещё, казалось, было время подумать…
ПЫЛАЮЩАЯ СРЕДА
Пиздец наступил без привета в 16:48 среды.
Коллаб начал рестартовать, не доходя до лимита памяти в 2Gb.
Сам node процесс больше не мог выделять память. Стало очевидно, что утечка всё же есть.
После каждого рестарта — память опять забивалась в течение 30–40 минут. На графиках нагрузки коллаба это выглядело как фатальные пиковые нагрузки по миллиону записей.
Причём коллаб с ними справлялся, но вылетал по памяти:
Выяснились следующие проблемы:
- в балансере коллаба застряло порядка 1.5 миллиона записей
- очистка обработанных записей в базе балансера занимает порядка минуты на батч из 100
Попытались снизить нагрузку на балансер, подкрутив настройки коллаба, но это не дало результата.
В 1:26 ночи четверг Андрей делает ход конём — VACUUM на таблице балансера
После вакуума балансер пришёл в себя.
Вова всмотрелся в код балансера и нашёл, что он имеет кэш, в который выгружаются сообщения из базы балансера на каждый рестарт. По дефолту размер кэша ничем не ограничен, поэтому на каждый рестарт он всасывал ВСЕ 1.3 миллиона сообщений и отдавал их в обработку коллабу, который послушно выщемливал из них бэкрефы, нотификации и т.д. с достаточно приличной скоростью, НО…
…кэш наполнялся… сервис падал по памяти… после рестарта всё начиналось сначала.
Такое поведение оказалось неожиданностью. ОЖИДАЛОСЬ, что балансер не берёт в работу следующие записи, пока не убедится, что обработанные вычищены.
В 2:28 ночи Вова растыкал настройки кэша и вернул лимит памяти контейнеру.
ЧУДОВИЩНЫЙ ЧЕТВЕРГ
Кастомеры начали жаловаться на дубликаты нотификаций и бэкрефов.
…тут до Вовы дошло, что ночью было только начало…
Также обратили внимание на пищащий алерт в очереди сервиса collab-2-fibery (далее C2F). До него не доходили руки ранее, т.к. тушили пожар в коллабе.
Очередь стала активно расти с 16–30 среды (совпадает по времени с огнём в коллабе):
Начальная проблема была в том, что один аккаунт xxx.fibery.io блочил очередь ошибкой 504 и сервис пытался безуспешно её решить ретраями.
Впилили явное исключение этого аккаунта, чтобы обработка пошла дальше. В логе ядра обнаружили соот-е ошибки о превышении времени выполнения запроса лимита в 60 сек.
Очередь начала медленно разгребаться, но по балансу всё равно продолжила расти.
Лёша добавил сенсоров.
Андрей всмотрелся в потенциальные проблемные запросы к ядру от C2F.
Андрей нашёл запрос за выгребанием ACL’ов, который стал жутко втупливать.
Андрей применил оптимизацию, понятную только разработчикам ядра. Оптимизация заключалась в НЕприменении формы запроса, которая приводит к неэффективному плану выполнения запроса и выполняется вечность. На это есть баг в ядре старый как Андрей. Андрей всё это знал и по-дедовски смекнул что к чему, потому что наелся подобного говна год назад в ядре.
С 3 попытки около 14:00 учередь ушла в пикЕ.
Все выдохнули и поменяли памперсы.
Причины пиздеца
- накопление коллабом + балансером миллиона сообщений для разгребания. Почему так произошло непонятно. По логам видно, что в 3:30 ночи 27 апреля база балансера встала колом. Причём произошло это скачкообразно и по логам не связано с пиками нагрузки на коллаб сервис. Нужна экспертиза Ильи.. возможно инфраструктурная проблема, сбой автовакуума.
- пухнущая очередь у C2F. Тут гипотеза следующая — в результате, секуризации fibery типов (fibery/view, …) кол-во ентитей типа fibery/access-group возросло примерно на 100. Это могло повлиять на окончательное проседание производительности запроса за доступом в ядро, выполняющимся в обработчике сообщений C2F, что окончательно убило скорость разгребания сообщений.
Проблемы
- дублирующиеся нотификации. Сделать ничего уже нельзя.. репутационный импакт. Надеемся на дипломатические навыки Полины и Миши.
- дублирующиеся бэкрефы — Вова сделает реиндексацию, должны исчезнуть. Пока дипломатично обещаем жалующимся.
- баг в ядре, приводящий к неэффективному плану выполнения запроса, отправленного C2F. В итоге, запрос обваливался по таймауту, и C2F наивно начинал его ретраить с надеждой на опционы лучшее будущее. В результате, забуксовала логика обработки сообщений от всех акков.
Action Points
- изучить гарантии, предоставляемые балансером!!!
- дублирующиеся нотификации → идемпотентность операции отправки нотификации
- дублирующиеся бэкрефы → миграция-убийца дубликатов + upsert бэкрефа?
- пофиксить баг в ядре + не ретраить в C2F на таймаут + очертить логику работы в C2F с ошибками для сужения их импакта
