Отчёт нагрузки PostgreSQL: как читать и ставить диагноз

← назад к разделу

Ситуация знакомая почти каждому, кто дежурил у боевой базы. Вчера с двух до четырёх часов дня всё тормозило, сейчас работает нормально, а объяснить, что это было, нужно сегодня.

Дашборд показывает графики за тот период, и по ним видно, что было плохо. Но главный вопрос он не закрывает: на что база потратила время. Лог медленных запросов ближе к делу, однако он показывает отдельные выбросы — те, что перевалили за порог, — и ничего не говорит про их долю в общей картине. Запрос, который сам по себе быстрый, но выполнялся сто тысяч раз, в этот лог даже не попадёт.

Отвечает на такой вопрос отчёт нагрузки за период. В мире Oracle эту роль играет AWR, и многие знают её именно оттуда. В PostgreSQL то же самое делают расширения pg_profile и pgpro_pwr — второе идёт в сборках Postgres Pro.

Самое ценное в таком отчёте — не сами числа, а колонка, по которой их сортируют: от неё зависит, кого назначат виноватым.

Откуда берётся отчёт за период

Все нужные числа PostgreSQL считает сам, но счётчики у него накопительные: они растут с момента запуска сервера, и в них лежит сумма за всё время сразу. Копит их pg_stat_statements — по запросам, а семейство pg_stat_* — по таблицам, индексам и базам.

Посмотреть на такой счётчик — всё равно что посмотреть на одометр машины: пробег видно, а сколько проехали вчера — нет.

Отсюда и устройство инструмента. Он периодически вызывает take_sample() и сохраняет состояние счётчиков в свою схему — это снимок. Отчёт за интервал строится функцией get_report(start_id, end_id) и представляет собой разницу между двумя снимками: сколько накрутилось между ними. Есть и get_diffreport() — она сравнивает сразу два периода, чем удобно сличать вчерашний пик с обычным днём неделей раньше.

Чтобы отчёт был полным, включают несколько вещей:

• pg_stat_statements — обязательно, без него не будет разделов про запросы;
• pg_wait_sampling — формально необязательно, но именно он даёт разделы про ожидания. Без него будет видно, сколько времени ушло, но не на чём система стояла;
• pg_stat_kcache — по желанию, добавляет процессорное время и обращения к файловой системе;
• в конфигурации track_io_timing = on, иначе все времена ввода-вывода останутся нулями.

Снимки обычно снимают раз в полчаса, а на нагруженных базах — чаще, вплоть до пяти минут, как в самодельном сборщике из соседней статьи. Частота — компромисс: чем реже, тем сильнее короткий всплеск усредняется внутри интервала и теряется; чем чаще, тем больше места и накладных расходов.

Это дополнение к обычному мониторингу, а не замена ему. Мониторинг отвечает на вопрос «плохо ли прямо сейчас», отчёт — «куда ушло время за те два часа».

Как это завести у себя

Статья объясняет устройство, а отчёта у вас пока нет. Завести его — работа на полчаса, и состоит она из четырёх шагов.

1. Расширения. pg_stat_statements требует перезапуска (он загружается при старте сервера), остальное — нет:

# postgresql.conf
shared_preload_libraries = 'pg_stat_statements, pg_wait_sampling'
track_io_timing = on
pg_stat_statements.max = 10000

Включают расширения:

CREATE EXTENSION pg_stat_statements;
CREATE EXTENSION pg_wait_sampling;
CREATE EXTENSION pg_profile;      -- сам отчёт, ставится в одну базу

Само pg_profile — обычное расширение из репозитория (в сборках Postgres Pro его роль играет pgpro_pwr): пакет ставится на сервер, дальше одна команда. Живёт оно в одной базе, откуда видит статистику всего сервера, и для этой базы обычно завидят отдельную схему.

2. Сервер в списке наблюдаемых. Расширение умеет собирать статистику не только своей, но и соседних баз и серверов, поэтому у него есть список:

live example

SELECT profile.set_server_connstr('local', 'dbname=postgres port=5432');

Run

Running examples is part of paid access. There the same code runs inside the article: editor, run and check next to the paragraph. Three free days →

3. Планировщик снимков. Это шаг, без которого ничего не работает, и именно его чаще всего пропускают: расширение само по расписанию ничего не делает. Вызывать take_sample() должен кто-то извне — pg_cron внутри базы или обычный системный планировщик:

-- вариант с pg_cron: снимок каждые 30 минут
SELECT cron.schedule('pg_profile_sample', '*/30 * * * *', 'SELECT profile.take_sample()');

По расписанию:

# вариант с системным планировщиком (crontab пользователя postgres)
*/30 * * * * psql -d postgres -c 'SELECT profile.take_sample()' >/dev/null 2>&1

4. Выгрузка отчёта. Отчёт — это HTML, который функция возвращает текстом, и его сохраняют в файл:

-- какие снимки есть и за какое время
SELECT * FROM profile.show_samples('local');

Выгрузка одной командой:

psql -Aqtc "SELECT profile.get_report('local', 143, 149)" -d postgres > report.html

Номера снимков берутся из списка выше; есть и вариант с временем вместо номеров, и get_diffreport для сравнения двух периодов — им пользуются чаще всего.

В каком порядке читать

Отчёт большой, и читать его подряд бессмысленно — утонешь на второй странице. Работает движение сверху вниз, от масштаба к виновнику.

Сначала масштаб. Раздел со статистикой по базе: сколько было транзакций, сколько прочитано и изменено строк, сколько ушло во временные файлы и в журнал. Здесь вы отвечаете на первый вопрос — период вообще был необычным по нагрузке или нагрузка была штатной, а плохо стало по другой причине. Разница принципиальная: «пришло вдвое больше запросов» и «запросов столько же, но каждый втрое медленнее» — совершенно разные расследования.

Потом ожидания. Разделы про типы ожиданий и топ событий показывают, во что упирается система:

Что преобладает	О чём это говорит
IO	Читаем с диска: рабочий набор не помещается в память или не хватает индекса
Lock	Блокировки: длинные транзакции, конкурирующие обновления одних строк
LWLock	Внутренняя конкуренция — часто буферы, журнал, распухшие таблицы
CPU (ожиданий нет)	Упираемся в вычисления: тяжёлые сортировки, обработка большого объёма строк
Client	База ждёт приложение — обычно долгие транзакции с походами во внешние сервисы
IPC	Процессы ждут друг друга: чаще всего параллельные запросы (ведущий ждёт рабочих) или ожидание фиксации на реплике
Timeout	Штатные паузы: интервал автовакуума, задержка восстановления на реплике. Обычно не проблема, но большая доля означает, что уборка упирается в свои же настройки
Extension	Ожидания внутри расширения — смотреть, какое расширение и что оно делает
BufferPin	Процесс ждёт освобождения страницы, с которой кто-то читает; встречается редко и указывает на конкуренцию за одни и те же строки

Затем виновники. Топы SQL: по суммарному времени, по числу выполнений, по чтению с диска, по временным файлам, по объёму журнала. Порядок здесь важен — сначала суммарное время, всё остальное потом.

Чтобы это не оставалось описанием невидимого объекта, вот как выглядит главная таблица отчёта — «Top SQL by elapsed time» — в упрощённом виде:

Query ID	Database	Elapsed(s)	%Total	Calls	Mean(ms)	Rows	Shared hit	Shared read
a1f4c8e2	orders	4210	38.1 %	1 842 306	2.3	1 842 306	71 M	0.4 M
7b09d3aa	orders	2980	27.0 %	214	13 925	88 M	12 M	9.1 M
c52e1b77	orders	690	6.2 %	51 204	13.5	51 204	8 M	1.2 M

Читается это ровно так, как учит следующий раздел. Первая строка: почти два миллиона вызовов по 2,3 миллисекунды — треть времени базы уходит на запрос, который сам по себе быстрый, значит проблема в приложении. Вторая: двести вызовов по четырнадцать секунд каждый, девять миллионов блоков прочитано с диска — вот это тяжёлый запрос, и ему нужен план и индекс. Третья попала в топ и не заслуживает внимания, пока не разобрались с первыми двумя.

Query ID — ключ, по которому в другом разделе отчёта («SQL query texts») лежит полный текст запроса; в самой таблице текст обрезан или отсутствует, чтобы она читалась. Названия разделов в отчёте английские и устроены одинаково: «Server statistics» (масштаб), «SQL query statistics» (топы SQL), «Schema object statistics» (таблицы и индексы), «Vacuum-related statistics», «Cluster settings» — то есть оглавление отчёта повторяет порядок чтения из этого раздела, и по нему удобно прыгать ссылками.

В сравнительном отчёте у каждой такой таблицы две строки на запрос — из первого и второго периода, друг под другом, — и смотреть надо именно на разницу: тот же запрос с тем же числом вызовов, но вдвое большим временем, и есть находка.

Дальше объекты. Топ таблиц по последовательному чтению, по изменениям, по числу мёртвых строк, статистика вакуума.

И в конце настройки. Отчёт показывает параметры сервера, а сравнительный отчёт — что между периодами изменилось. Иногда всё расследование заканчивается строчкой «кто-то тронул work_mem».

Главная ловушка: среднее вместо суммарного

Самая частая ошибка чтения — отсортировать запросы по среднему времени и смотреть верхние строки.

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

Смотреть надо на суммарное время — долю от общего времени базы. Запрос, который отрабатывает за четыре миллисекунды, но вызывается два миллиона раз, съедает больше двух часов процессорного времени. Он и делает базе плохо, а по среднему времени стоит в самом низу списка.

Из этого следует простое разделение диагнозов.

Если суммарное время большое и среднее большое — перед вами тяжёлый запрос. Дальше смотрят план через EXPLAIN, ищут недостающий индекс, переписывают запрос.

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

Второй случай встречается чаще первого и почти всегда приезжает из кода.

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

Сравнить с эталоном. Это единственный случай, где без сравнения не обойтись. Тот же запрос неделю назад: столько же вызовов по три миллисекунды — значит, дело не в запросе, а в том, что вокруг него изменилось; вдвое меньше вызовов по тринадцать — значит, выросла нагрузка, а запрос как был.

Посмотреть, что изменилось вокруг. Тринадцать миллисекунд вместо трёх при том же плане — обычно это чтение с диска вместо кэша (таблица выросла или её вытеснили), распухание таблицы (страниц втрое больше при том же числе строк) или ожидание блокировок, если запрос изменяющий. Все три видны в соседних разделах отчёта: чтение — в колонке Shared read, распухание — в статистике объектов, блокировки — в ожиданиях.

Проверить, нужен ли он вообще. Пятьдесят тысяч вызовов — это много для многих задач. Частая находка: запрос вызывается на каждый запрос пользователя, хотя его результат меняется раз в час (справочник, настройки, курс) — и лечится кешированием на стороне приложения, а не в базе.

И только потом план. Тринадцать миллисекунд редко бывают ошибкой плана, но иногда бывают: соединение по неиндексированному полю на маленькой таблице стоит именно столько и растёт с данными.

Практически: первый случай (большое среднее) — это работа с планом, второй (много вызовов) — с кодом, третий — со сравнением, и если эталонного отчёта нет, разобрать его нечем. Это главный аргумент за привычку держать базовый снимок нормального дня.

От чисел к диагнозу

Дальше — типовые картины, которые складываются из этих разделов.

Много чтения с диска, ожидания в IO, средний запрос вырос. Данные читаются с диска, а не из кэша. Причин обычно три: рабочий набор перерос память; пропал индекс, и база пошла читать таблицу целиком — это видно по топу таблиц; либо таблица распухла, и строк столько же, а страниц втрое больше.

Большой объём временных файлов у нескольких запросов. Сортировки и соединения не поместились в память и ушли на диск. Лечится увеличением work_mem — осторожно, он выделяется на операцию, а не на соединение, — уменьшением выборки или индексом, который сразу отдаёт нужный порядок.

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

Растёт число мёртвых строк, автовакуум отстаёт. Видно по разделу вакуума: доля мёртвых строк увеличивается, дата последней уборки старая. Дальше по цепочке — распухание, чтение с диска, деградация планов. Что с этим делать, разобрано в статье про vacuum.

Один запрос с огромным объёмом журнала. Обычно это массовое обновление: UPDATE по всей таблице, миграция данных, перестроение. Такое разбивают на порции — и заодно проверяют, не отстала ли реплика, пока это ехало.

Транзакций стало вдвое больше, а время каждой не изменилось. База ни при чём: выросла нагрузка. Дальше вопрос про ёмкость, пул соединений и кэширование, а не про индексы.

Как этим пользоваться

Отчёт приносит пользу не в момент аварии, а как привычка.

Держите эталон. Снимите отчёт за нормальный рабочий день и сохраните. Без него любое число не с чем сравнить: 40% времени базы на одном запросе — это авария или так было всегда?

Сравнивайте периоды, а не читайте один отчёт. Сравнительный отчёт между «сейчас» и «неделю назад» отвечает на вопрос быстрее, чем чтение обоих по отдельности.

Смотрите отчёт после крупных изменений. Вышел релиз, проехала миграция, поменяли параметр — через день загляните в топ запросов. Так регрессия находится за неделю до того, как о ней сообщат пользователи.

Не выбрасывайте историю. Снимки занимают немного, а возможность посмотреть, каким запрос был три месяца назад, окупается на первом же разборе.

Если хочется понять, из каких именно запросов складывается каждый раздел, — это разобрано в статье «Отчёт нагрузки своими руками»: там по каждому разделу дан запрос, который его порождает.

Глубже: сколько это стоитрасширенное

Три расхода, о которых стоит знать заранее, чтобы не выяснять на большой базе.

Время снимка. take_sample() читает все накопительные счётчики и складывает разницу в свои таблицы. На базе с сотней таблиц это доли секунды; на базе, где в pg_stat_statements десятки тысяч записей, — секунды, потому что читается и сохраняется каждая запись. Это не блокирует работу, но заметно на слабом сервере, и это причина не ставить снимки каждую минуту «на всякий случай».

Место. Каждый снимок хранит строку на каждый запрос, таблицу и индекс. Порядок величины: база с десятью тысячами записей статистики и снимком каждые полчаса даёт несколько сотен мегабайт за месяц. Немного, но это данные внутри вашей базы, они попадают в резервные копии и растут линейно.

Ротация. Она настраивается и по умолчанию не бесконечна: у сервера в списке есть срок хранения снимков (по умолчанию порядка недели у части сборок), и старые удаляются при очередном снимке. Это стоит проверить и выставить осознанно: слишком короткий срок лишает возможности сравнить с прошлым месяцем — а именно сравнение и составляет главную ценность метода; слишком длинный растит схему. Разумная развилка: подробные снимки за последние две-три недели плюс сохранённые файлы отчётов за эталонные дни, которые места почти не занимают.

И одно замечание про надёжность: если сервер перезапустили, накопительные счётчики обнулились, и разница между снимками «до» и «после» получится отрицательной. Инструмент это распознаёт и помечает интервал как непригодный — но знать об этом надо, чтобы не удивляться пропуску в отчёте.

Глубже: чего отчёт не покажетрасширенное

У метода есть границы, и знать их важнее, чем помнить названия разделов.

Плана конкретного запроса. Отчёт называет виновника, но не объясняет, почему тот медленный. Следующий шаг всегда один — EXPLAIN (ANALYZE, BUFFERS).

Разных планов одного запроса. Запросы в статистике нормализуются: параметры заменяются плейсхолдерами, и все выполнения слипаются в одну строку. Запрос, который для одного клиента идёт по индексу за миллисекунду, а для другого читает половину таблицы, будет одной строкой со средним по больнице.

Того, что не поместилось. У pg_stat_statements есть предел на число хранимых запросов, и когда их становится больше, редкие вытесняются. Если отчёт предупреждает об этом — часть картины потеряна, и предел стоит поднять.

Событий короче интервала. Тридцатисекундная блокировка внутри часового окна растворится в средних без следа. Для такого нужны либо частые выборки состояния сессий, либо обычный мониторинг.

Коротко

• Отчёт нагрузки — это разница между двумя снимками накопительной статистики; в Oracle ту же роль играет AWR, в PostgreSQL — pg_profile и pgpro_pwr.
• Нужны pg_stat_statements и track_io_timing; ожидания появляются только с pg_wait_sampling, процессорное время — с pg_stat_kcache.
• Порядок чтения: масштаб нагрузки → ожидания → топы SQL → объекты схемы → настройки и их изменения.
• Сортировать надо по суммарному времени, а не по среднему: тысяча мелких запросов дороже одного тяжёлого отчёта.
• Большое среднее время лечится планом и индексами; огромное число вызовов — изменениями в приложении.
• Отчёт называет виновника, но не показывает план: следующий шаг всегда EXPLAIN (ANALYZE, BUFFERS).
• Одиночный отчёт почти бесполезен без эталонного периода — держите базовый снимок нормального дня.
• Снимки сами не снимаются: take_sample() вызывает планировщик (pg_cron или системный), отчёт выгружается функцией в HTML по номерам снимков.
• Снимки стоят времени (секунды на большой статистике), места (сотни мегабайт за месяц внутри базы) и требуют осознанного срока хранения; перезапуск сервера делает интервал непригодным.
• Третий диагноз кроме тяжёлого запроса и цикла в приложении: умеренные вызовы и умеренное среднее — тогда разбирают сравнением с эталоном, ищут чтение с диска, распухание и ненужную частоту вызова.

Что почитать дальше

• Отчёт нагрузки своими руками — какими запросами получается каждый раздел отчёта.
• Мониторинг PostgreSQL — что смотреть в реальном времени и какие метрики держать на дашборде.
• EXPLAIN и планы запросов — следующий шаг после того, как виновник найден.
• VACUUM и распухание — почему таблица растёт, а строк не прибавляется.