Разбор инцидента: несколько часов деградации PostgreSQL в проде

Я с коллегами пишу сервис, который использует внутренний инстанс публичного приложения Arize Phoenix (система LLM-observability — наблюдаемости за LLM-приложениями). Arize Phoenix использует в качестве БД PostgreSQL. СУБД обычно жила спокойно: AAS (Average Active Sessions — среднее число одновременно активных сессий: выполняющих запрос или ожидающих ресурса) держался около 1.0 на инстансе с 2 vCPU (виртуальными ядрами процессора). Однажды случилась аномалия: AAS взлетел до 25.

Как искали причину

Начал с облачного инструмента Performance Insights и метрики AAS. Правило простое: AAS на уровне числа vCPU — база на пределе, выше — запросы стоят в очереди. У нас потолок был 2, а стало 25.

Дальше — разрезы той же нагрузки:

• По wait events доминировали IO:DataFileRead (сессия ждёт чтения страницы с диска, потому что её нет в памяти) и IPC:BufferIo (несколько бэкендов одновременно ждут одну и ту же страницу — по сути ожидание на latch при чтении в shared memory). Вместе это классическая картина: горячий рабочий набор вытеснен из shared_buffers (общий буфер кэша страниц базы в оперативной памяти), запросы пошли на диск.

• По Top SQL увидел две нагрузки, совпавшие по времени: тяжёлый агрегирующий запрос дашборда Phoenix (вклад в AAS 14.37) и FETCH FORWARD по таблице spans — это не наш запрос, а выгрузка трейсов соседней командой (за 22 дня, курсором, порциями).

Причина 1: чужая выгрузка остудила кэш

Выгрузка соседей шла курсором по индексу, а не последовательным сканом. Это важно: последовательный скан в PostgreSQL проходит через ограниченный ring buffer (кольцевой буфер небольшого размера) и почти не трогает основной кэш, а вот чтение курсором по индексу — это random I/O, и каждая прочитанная страница попадает в shared_buffers. Прогнав гигабайты холодных спанов за прошлые недели, выгрузка вытеснила оттуда горячие страницы дашбордов. После этого каждый запрос Phoenix читал с диска — отсюда IO:DataFileRead и взрыв AAS.

Сама аналитика базу не роняла: шесть дней до этого, включая собственную нагрузку, всё было нормально. Её убила конкуренция за кэш.

Причина 2: запросы без индексов

Разобрав тексты запросов из Top SQL, нашёл вторую проблему: часть запросов самого Phoenix шла без индексов — фильтры и джойны по spans делали full scan (полное сканирование таблицы без использования индекса). Пока кэш горячий, это маскируется: скан страницы в памяти дёшев. Тот же запрос при холодном кэше — чтение с диска. Инцидент случился ровно на пересечении: кто-то остудил кэш, а тяжёлым запросам нечего было противопоставить.

Здесь полезное наблюдение: Performance Insights хорошо показывает, кто создал нагрузку, но не почему запрос её не выдержал — на второй вопрос отвечает EXPLAIN (команда, показывающая план выполнения запроса).

Кстати, мы в этом не одни: медленные запросы Phoenix на больших таблицах spans — известная публичная проблема (см. GitHub issues в репозитории Arize), там же приводят индексы, ускоряющие такие запросы с ~15 секунд до ~1. В свежих версиях Phoenix read-нагрузку можно вообще вынести на PostgreSQL read replica (реплику базы, предназначенную только для чтения).

Фикс 1: разнесли нагрузки по времени

Со смежной командой договорились: тяжёлая выгрузка теперь работает только ночью. У их экспортёра простое правило — в бизнес-часы закрывать соединение, спать, потом переподключаться и продолжать. Ни одной строчки кода Phoenix не трогали.

Честно: ночью выгрузка всё равно гоняет холодные страницы через кэш, и первые утренние дашборды стартуют на остывшем кэше. Но это минуты прогрева вместо трёх часов деградации. Радикальный вариант — вообще не пускать такие выгрузки в продовую базу: отдельный инстанс для тестов или read replica. Это отличное решение когда есть запасной(read) инстанс, в начале у нас его не было.

Фикс 2: индексы под запросы Phoenix

Создали недостающие индексы. Показательный пример — частичный индекс под запросы по root-спанам, которые упирались в тайм-аут (соединение рвал клиент/балансировщик, потому что ответ не успевал прийти), например :

CREATE INDEX CONCURRENTLY ix_spans_root_trace_rowid_error
    ON spans (trace_rowid, cumulative_error_count)
    WHERE parent_id IS NULL;

Почему частичный: root-спанов мало относительно всех спанов, индекс получается компактным и целиком помещается в память. CONCURRENTLY строит индекс без блокировки записи; нюанс — его нельзя выполнять внутри транзакции, запускайте с автокоммитом.

Результат и выводы

После договорённости о ночном окне повторений не было, после индексов пропали тайм-ауты дашборда на 7-дневном диапазоне.

Что вынес из инцидента:

1. Программы, которые распространяются под свободной лицензией и открытым исходным кодом - имеют баги, дикую скорость разработки, теперь, в эру LLM и вайбкодинга, отсутсвие хорошего тестирования.

2. AAS против vCPU — быстрый способ отличить «на пределе» от «есть очередь».

3. Wait events IO:DataFileRead + latch-ожидания = вытеснение кэша; дальше смотрим Top SQL, кто его остудил.

4. Запрос без индекса опасен не сам по себе, а в сочетании с холодным кэшем — проверяйте планы через EXPLAIN.

5. Иногда фикс организационный: не запускать две тяжёлые задачи одновременно. Это дёшево и часто эффективнее тюнинга.