- PVSM.RU - https://www.pvsm.ru -
В 2008 году в списке рассылки pgsql-hackers началось обсуждение [1] расширения по сбору статистики по запросам. Начиная с версии 8.4 расширение pg_stat_statements [2] входит в состав постгреса и позволяет получать различную статистику о запросах, которые обрабатывает сервер.
Обычно это расширение используется администраторами баз данных в качестве источника данных для отчетов (эти данные на самом деле являются суммой показателей с момента сброса счетчиков). Но на основе этой статистики можно сделать мониторинг запросов — посмотреть на статистику во времени. Это оказывается крайне полезно для поиска причин различных проблем и в целом для понимания, что происходит на сервере БД.
Я расскажу, какие метрики по запросам собирает наш агент, как мы их группируем, визуализируем, так же расскажу о некоторых граблях, по которым мы прошли.
Итак, что же у нас есть во view pg_stat_statements (мой пример из 9.4):
postgres=# d pg_stat_statements;
View "public.pg_stat_statements"
Column | Type | Modifiers
---------------------+------------------+-----------
userid | oid |
dbid | oid |
queryid | bigint |
query | text |
calls | bigint |
total_time | double precision |
rows | bigint |
shared_blks_hit | bigint |
shared_blks_read | bigint |
shared_blks_dirtied | bigint |
shared_blks_written | bigint |
local_blks_hit | bigint |
local_blks_read | bigint |
local_blks_dirtied | bigint |
local_blks_written | bigint |
temp_blks_read | bigint |
temp_blks_written | bigint |
blk_read_time | double precision |
blk_write_time | double precision |
Здесь все запросы сгруппированы, то есть статистику мы получаем не по каждому запросу, а по группе одинаковых с точки зрения pg запросов (я расскажу про это подробнее). Все счетчики растут с момента старта или с момент сброса счетчиков (pg_stat_statements_reset).
shared_blks_read — количество блоков разделяемой памяти, прочитанное не из кэша
В документации не очевидно, это суммарное количество прочитанных блоков или только то, что не нашлось в кэше, проверяем по коду [3]
/*
* lookup the buffer. IO_IN_PROGRESS is set if the requested block is
* not currently in memory.
*/
bufHdr = BufferAlloc(smgr, relpersistence, forkNum, blockNum,
strategy, &found);
if (found)
pgBufferUsage.shared_blks_hit++;
else
pgBufferUsage.shared_blks_read++;
blk_read_time и blk_write_time собираются только при включенной настройке track_io_timing [6].
Отдельно стоит отметить, что в pg_stat_statements попадают только завершенные запросы. То есть, если у вас какой-то запрос уже час делает что-то тяжелое и до сих пор не закончился, его будет видно только в pg_stat_activity [7].
Я долгое время считал, что запросы группируются по реальному плану выполнения. Смущало только то, что запросы с разным количеством аргументов в IN отображаются отдельно, план то у них должен быть одинаковый.
В коде видно, что на самом деле берется хэш [8] от "значимых" частей запроса после синтаксического разбора. Начиная с 9.4 он выводится в колонке queryid.
На практике нам приходится дополнительно нормализовывать и группировать запросы уже в агенте. Например, разное количество аргументов в IN мы схлопываем в один плейсхолдер "(?)". Или аргументы, которые прилетели в pg заинлайнеными в запрос мы сами заменяем на плейсхолдеры. Задача усложняется еще и тем, что текст запроса может быть не полным.
До 9.4 текст запроса обрезается до track_activity_query_size [9], c 9.4 текст запроса хранится вне разделяемой памяти и ограничение убрали, но мы в любом случае обрезаем запрос до 8Кб, так как если в query лежат очень увесистые строки, запросы от агента ощутимо нагружают постгрес.
Из-за этого мы не можем разобрать запрос парсером SQL для дополнительной нормализации, вместо этого пришлось написать набор регулярных выражений для дополнительной зачистки запросов. Это не очень удачное решение, так как постоянно приходится добавлять новые сценарии, но ничего лучше пока придумать не удалось.
Еще одна проблема в том, что в поле query постгрес записывает первый пришедший запрос в группе до нормализации с сохранением исходного форматирования, и если счетчики сбросить, запрос может быть другим для той же группы. Ещё очень часто разработчики используют комментарии в запросах, например для указания названия функции, которая дергает этот запрос или ID пользовательского запроса), они в query тоже сохраняются.
Для того, чтобы не плодить каждый раз новые метрики для одних и тех же запросов, мы вырезаем коментарии и лишние whitespace символы.
Мониторинг постгреса мы делали с помощью наших друзей из postgresql consulting [10]. Они подсказывали, что самое полезное при поиске проблем с базой, какие метрики не особо полезны и консультировали по внутренностям postgresql.
В итоге мы хотим получать от мониторинга ответы на следующие вопросы:
На самом деле лить счетчики по всем запросам в мониторинг достаточно дорого. Мы решили, что нас интересует только TOP-50 запросов, но нельзя просто взять top по total_time, так как если у нас появится новый запрос, его total_time еще долго будет догонять старые запросы.
Мы решили брать top по производной (rate) total_time за минуту. Для этого раз в минуту агент вычитывает pg_stat_statements целиком и хранит предудущие значения счетчиков. По каждому счетчику каждого запроса вычисляется rate, потом мы пытаемся дополнительно объединить одинаковые запросы, которые pg посчитал разными, их статистики суммируются. Дальше берем top, по ним делаем отдельные метрики, остальные запросы суммируем в некий query="~other".
В итоге мы получаем 11 метрик для каждого запроса из топа. Каждая метрика имеет набор уточняющих параметров (меток):
{"database": "<db>", "user": "<user>", "query": "<query>"}
Очень часто у пользователей появляются вопросы о физическом смысле метрик "postgresql.query.time.*". Действительно, не особо понятно, что показывает сумма времен ответов, но такие метрики обычно хорошо показывают соотношение каких-то процессов между собой.
Но если мы договоримся не брать во внимание блокировки, можно очень грубо предположить, что в течении всего времени обработки запроса постгрес утилизирует какой-то ресурс (процессор или диск). Такие метрики имеют размерность: количество потраченных ресурсных секунд в секунду. Можно еще привести это к процентам утилизации запросом процессорного ядра, если умножить на 100%.
Прежде чем полагаться на метрики, нужно проверить, правду ли они показывают. Например попробуем разобраться, что вызывает увеличение количества операций записи на сервере БД:
Смотрим, писал ли постгрес на диск в это время:
Дальше выясняем, какие запросы "пачкали" страницы:
Видим, что есть примерное совпадение, но график по запросам в точности не повторяет график сброса буферов. Это вызвано тем, что процесс записи блоков происходит в фоне и при этом профиль нагрузки на диск немного меняется.
Теперь посмотрим, какая картина у нас получилась с чтением:
Здесь мы тоже видим, что корреляция есть, но точного совпадения нет. Это можно объяснить тем, что постгрес читает блоки с диска не напрямую, а через кэш файловой системы. Таким образом мы не видим часть нагрузки на диск, так как чаcть блоков читается из кэша.
Утилизацию процессора тоже можно объяснить конкретными запросами, но абсолютной точности ожидать не приходится, так как есть ожидания различных локов итд:
На нашем демо стенде есть пример [11] метрик по запросам, но нагрузка там не очень интересная и лучше посмотреть это на ваших метриках (у нас есть бесплатный, ни к чему не обязывающий двухнедельный триал)
Автор: okmeter.io
Источник [12]
Сайт-источник PVSM.RU: https://www.pvsm.ru
Путь до страницы источника: https://www.pvsm.ru/postgresql/194112
Ссылки в тексте:
[1] обсуждение: https://www.postgresql.org/message-id/20080613173157.7FEA.52131E4D@oss.ntt.co.jp
[2] pg_stat_statements: https://www.postgresql.org/docs/9.4/static/pgstatstatements.html
[3] коду: https://github.com/postgres/postgres/blob/REL9_4_STABLE/src/backend/storage/buffer/bufmgr.c#L345
[4] "грязным": https://github.com/postgres/postgres/blob/REL9_4_STABLE/src/backend/storage/buffer/bufmgr.c#L663
[5] work_mem: https://www.postgresql.org/docs/9.4/static/runtime-config-resource.html
[6] track_io_timing: https://www.postgresql.org/docs/9.4/static/runtime-config-statistics.html#GUC-TRACK-IO-TIMING
[7] pg_stat_activity: https://www.postgresql.org/docs/9.4/static/monitoring-stats.html#PG-STAT-ACTIVITY-VIEW
[8] берется хэш: https://github.com/postgres/postgres/blob/REL9_4_STABLE/contrib/pg_stat_statements/pg_stat_statements.c#L2235
[9] track_activity_query_size: https://www.postgresql.org/docs/9.4/static/runtime-config-statistics.html#GUC-TRACK-ACTIVITY-QUERY-SIZE
[10] postgresql consulting: http://postgresql-consulting.ru/
[11] пример: https://okmeter.io/example/hosts/db2/Postgresql
[12] Источник: https://habrahabr.ru/post/311028/?utm_source=habrahabr&utm_medium=rss&utm_campaign=best
Нажмите здесь для печати.