auto_explain
Модуль auto_explain предоставляет возможность автоматического
протоколирования планов выполнения медленных операторов, без необходимости
выполнения EXPLAIN вручную. Это особенно полезно для обнаружения
неоптимизированных запросов в больших приложениях.
Этот модуль не предоставляет функций, доступных из SQL. Чтобы использовать его, просто загрузите его на сервер. Это можно сделать в отдельном сеансе:
LOAD 'auto_explain';
(Для этого нужно быть суперпользователем.) Более типична практика, когда он предварительно загружается в некоторые или все сеансы путем включения auto_explain в переменную session_preload_libraries или shared_preload_libraries в файле конфигурации qhb.conf. После этого можно отслеживать неожиданно медленные запросы, независимо от того, где они происходят. Разумеется, это приводит к издержкам.
Параметры конфигурации
Есть несколько параметров конфигурации, которые управляют поведением auto_explain. Обратите внимание, что по умолчанию они ничего не делают, поэтому если вы хотите получить какие-либо результаты, необходимо установить как минимум параметр auto_explain.log_min_duration.
auto_explain.log_min_duration (integer)
Этот параметр задает минимальное время выполнения оператора в миллисекундах, при
превышении которого план оператора будет протоколироваться. При значении 0
протоколируются все планы. При значении -1 (по умолчанию) протоколирование
планов выключается. Например, если установить значение 250ms, то будут
протоколироваться все операторы, выполняющиеся 250 мс и дольше. Изменить этот
параметр могут только суперпользователи.
auto_explain.log_analyze (boolean)
При включении этого параметра в журнал будет записываться вывод команды EXPLAIN ANALYZE, а не простой EXPLAIN. По умолчанию он выключен. Изменить этот параметр
могут только суперпользователи.
Примечание
Когда этот параметр включен, замер времени на уровне узлов плана производится для всех операторов, даже если они выполняются недостаточно долго для протоколирования. Это может оказать крайне негативное влияние на производительность. Выключение auto_explain.log_timing нейтрализует это влияние, но при этом собирается меньше информации.
auto_explain.log_buffers (boolean)
Этот параметр определяет, будет ли при протоколировании плана выполнения выводиться
статистика использования буферов; он равнозначен параметру BUFFERS команды
EXPLAIN. Этот параметр действует только при включенном параметре
auto_explain.log_analyze. По умолчанию auto_explain.log_buffers
выключен. Изменить этот параметр могут только суперпользователи.
auto_explain.log_wal (boolean)
Этот параметр определяет, будет ли при протоколировании плана выполнения выводиться
статистка использования WAL; он равнозначен параметру WAL команды EXPLAIN.
Этот параметр действует только при включенном параметре
auto_explain.log_analyze. По умолчанию auto_explain.log_wal выключен.
Изменить этот параметр могут только суперпользователи.
auto_explain.log_timing (boolean)
Этот параметр определяет, будет ли при протоколировании плана выполнения выводиться
информация о длительности на уровне узлов; он равнозначен параметру TIMING
команды EXPLAIN. Издержки от постоянного чтения системных часов могут значительно
замедлить запросы в некоторых системах, поэтому может иметь смысл выключать этот
параметр, когда нужно знать только количество строк, а не точную длительность
каждого узла. Этот параметр действует только при включенном параметре
auto_explain.log_analyze. По умолчанию auto_explain.log_timing
выключен. Изменить этот параметр могут только суперпользователи.
auto_explain.log_triggers (boolean)
При включении этого параметра в журнал будет записываться статистика выполнения
триггеров. Этот параметр действует только при включенном параметре
auto_explain.log_analyze. По умолчанию auto_explain.log_triggers
выключен. Изменить этот параметр могут только суперпользователи.
auto_explain.log_verbose (boolean)
Этот параметр определяет, будут ли при протоколировании плана выполнения выводиться
подробные сведения; он равнозначен параметру VERBOSE команды EXPLAIN. По
умолчанию он выключен. Изменить этот параметр могут только суперпользователи.
auto_explain.log_settings (boolean)
Этот параметр определяет, будет ли при протоколировании плана выполнения выводиться
информация об измененных параметрах конфигурации. При этом в вывод попадут только
те параметры, которые влияют на планирование запросов и имеют значения,
отличающиеся от встроенных значений по умолчанию. По умолчанию
auto_explain.log_settings выключен. Изменить этот параметр могут только
суперпользователи.
auto_explain.log_format (enum)
Этот параметр выбирает формат вывода для команды EXPLAIN. Допустимые значения:
text, xml, json и yaml. Значение по умолчанию — text. Изменить этот
параметр могут только суперпользователи.
auto_explain.log_level (enum)
Этот параметр выбирает уровень, с которым auto_explain будет протоколировать
планы запросов. Допустимые значения: DEBUG5, DEBUG4, DEBUG3, DEBUG2,
DEBUG1, INFO, NOTICE, WARNING и LOG. Значение по умолчанию — LOG.
Изменить этот параметр могут только суперпользователи.
auto_explain.log_nested_statements (boolean)
При включении этого параметра протоколированию могут подлежать и вложенные
операторы (операторы, выполняемые внутри функции). При его выключении
протоколируются только планы запросов верхнего уровня. По умолчанию он выключен.
Изменить этот параметр могут только суперпользователи.
auto_explain.sample_rate (real)
Этот параметр задает для auto_explain процент операторов, который будет
рассматриваться в каждом сеансе. Значение по умолчанию равно 1, то есть
рассматриваются все запросы. Вложенные операторы рассматриваются полностью — либо
все, либо никакой из них. Изменить этот параметр могут только суперпользователи.
В обычной ситуации эти параметры устанавливаются в qhb.conf, хотя суперпользователи могут изменять их на ходу в рамках своих сеансов. Типичное их использование может выглядеть так:
# qhb.conf
session_preload_libraries = 'auto_explain'
auto_explain.log_min_duration = '3s'
Пример
qhb=# LOAD 'auto_explain';
qhb=# SET auto_explain.log_min_duration = 0;
qhb=# SET auto_explain.log_analyze = true;
qhb=# SELECT count(*)
FROM pg_class, pg_index
WHERE oid = indrelid AND indisunique;
В результате можно получить такой вывод:
LOG: duration: 3.651 ms plan:
Query Text: SELECT count(*)
FROM pg_class, pg_index
WHERE oid = indrelid AND indisunique;
Aggregate (cost=16.79..16.80 rows=1 width=0) (actual time=3.626..3.627 rows=1 loops=1)
-> Hash Join (cost=4.17..16.55 rows=92 width=0) (actual time=3.349..3.594 rows=92 loops=1)
Hash Cond: (pg_class.oid = pg_index.indrelid)
-> Seq Scan on pg_class (cost=0.00..9.55 rows=255 width=4) (actual time=0.016..0.140 rows=255 loops=1)
-> Hash (cost=3.02..3.02 rows=92 width=4) (actual time=3.238..3.238 rows=92 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 4kB
-> Seq Scan on pg_index (cost=0.00..3.02 rows=92 width=4) (actual time=0.008..3.187 rows=92 loops=1)
Filter: indisunique
Автор
Такахиро Итагаки (Takahiro Itagaki), itagaki.takahiro@oss.ntt.co.jp