В ожидании 8.4 - auto-explain

Перевод Waiting for 8.4 - auto-explain с select * from depesz;

19 ноября Tom Lane применил патч Takahiro Itagaki:

Добавлено расширение auto-explain для автоматического логирования планов медленных запросов

Что оно действительно делает?

Перед тем как я погружусь в детали - небольшое замечание - это первое расширение PostgreSQL (которое я видел) использующее custom_variable_classes GUC.

Конечно же plperl это (GUC) использует, а ещё это используется как временное хранилище между вызовами функций :)

И так, есть 2 способа подключения модуля:
1. LOAD 'auto_explain';
2. shared_preload_libraries = ‘auto_explain’

Первый способ можно использовать в любой сессии (с правами суперюзера), что включит auto-explain только для данной сессии:

# LOAD 'auto_explain';
LOAD

Второй требует правки postgresql.conf, где надо добавить 'auto_explain' в shared_preload_libraries (GUC-переменную).

В этом случае эффект будет для всех сессий.

Так что используем его. Не перепутайте local_preload_libraries и shared_preload_libraries - когда у меня так получилось я не смог запустить PostgreSQL.

После подключения в общем ничего не изменится, всё будет работать как работало до этого, но появится возможность установки доп. переменной:

# set explain.log_min_duration = 5;

что позволит логировать 'explain'

2008-11-23 14:45:14.711 CET depesz@depesz 28352 [local] LOG:  duration: 1003.424 ms  plan:
Result  (cost=0.01..0.03 rows=1 width=0)
InitPlan
->  Result  (cost=0.00..0.01 rows=1 width=0)
2008-11-23 14:45:14.711 CET depesz@depesz 28352 [local] STATEMENT:  select pg_sleep((select 1));
2008-11-23 14:45:14.711 CET depesz@depesz 28352 [local] LOG:  duration: 1005.477 ms  statement: select pg_sleep((select 1));

Последняя строка добавляется из-за ‘log_min_duration_statement’.

Как теперь видно - это очень здорово. Логируется 'explain', но надо учитывать, что если установить нижний порог (explain.log_min_duration) слишком низко, то логи будут расти очень быстро. Планы запросов довольно объёмные.

Дополнительно можно включить логирование "explain analyze", что не очень хорошо, т.к. скажется на производительности, даже если у вас не много запросов выполняющихся дольше explain.log_min_duration.

Причина проста - PostgreSQL вынужден выполнять тайминг всех запросов для того, чтобы иметь возможность вывести результат analyze. Только представьте себе "довесок" от тайминга для сотен запросов в секунду ради пары планов запросов в час.

Ещё одна опция - "explain verbose output" (ознакомиться подробнее можно тут):

# set explain.log_verbose = 1;
SET

# select pg_sleep((select 1));
pg_sleep
----------

(1 row)

Log:

2008-11-23 14:54:48.443 CET depesz@depesz 28812 [local] LOG:  duration: 1001.721 ms  plan:
Result  (cost=0.01..0.03 rows=1 width=0)
Output: pg_sleep(($0)::double precision)
InitPlan
->  Result  (cost=0.00..0.01 rows=1 width=0)
Output: 1
2008-11-23 14:54:48.443 CET depesz@depesz 28812 [local] STATEMENT:  select pg_sleep((select 1));
2008-11-23 14:54:48.443 CET depesz@depesz 28812 [local] LOG:  duration: 1002.139 ms  statement: select pg_sleep((select 1));

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

Замечание от 2010-03-24
Статья была написана до релиза 8.4, с его выходом некоторые вещи могли поменяться, в связи с чем рекомендую также ознакомится с соответствующим разделом документации Appendix F. Additional Supplied Modules - F.2. auto_explain