> sudo apt install postgresql-10
Success. You can now start the database server using:
/usr/lib/postgresql/10/bin/pg_ctl -D /var/lib/postgresql/10/main -l logfile start
Ver Cluster Port Status Owner Data directory Log file
10 main 5432 down postgres /var/lib/postgresql/10/main /var/log/postgresql/postgresql-10-main.log
update-alternatives: using /usr/share/postgresql/10/man/man1/postmaster.1.gz to provide /usr/share/man/man1/postmaster.1.gz (postmaster.1.gz) in auto mode
Processing triggers for ureadahead (0.100.0-20) ...
Processing triggers for systemd (237-3ubuntu10) ...
> sudo -u postgres psql postgres
psql (10.3 (Ubuntu 10.3-1))
Type "help" for help.
postgres=# \password postgres
Enter new password: 1
Enter it again: 1
postgres=# create DATABASE test;
> sudo -u postgres psql test
test=# show config_file;
config_file
-----------------------------------------
/etc/postgresql/10/main/postgresql.conf
(1 row)auto_explain
Для автоматического логирования планов выполнения существует модуль auto_explain
Модуль auto_explain предоставляет возможность автоматического протоколирования планов выполнения медленных операторов, что позволяет обойтись без выполнения EXPLAIN вручную. Это особенно полезно для выявления неоптимизированных запросов в больших приложениях.Т.е. в Postgres возможно узнать план запроса на момент его исполнения
Сделать это можно двумя путями:
- Включив модуль для запроса:
Это полезно, если попрофилировать нужно конкретный запросload 'auto_explain'; SET auto_explain.log_min_duration = 10; SET auto_explain.log_analyze = true; select count(*) from somet where number < 1000 - Включить модуль на все запросы на сервере
попутно подправлю логирование
Не забудь применить конфиги
test=# SELECT pg_reload_conf(); pg_reload_conf ---------------- t (1 row)
Ну всё, можно тестить
CREATE EXTENSION IF NOT EXISTS "uuid-ossp";
create table somet(
id uuid PRIMARY key,
number INTEGER,
text text
);
insert into somet
select uuid_generate_v1(), round(random() * 1000000), round(random() * 1000000)::text from generate_series(1,10000000)А вот запрос, которым будем отлаживать логи:
select count(*) from somet where number < 1000Го в логи, там план:
Собственно хорошо, только нюанс — залогировался запрос 4 раза, а план — трижды, почему так — Parallel Seq Scan, а именно — запрос начал обрабатываться в 2 потока (Workers Planned: 2) и после собрался в общий результат (новый шаг в плане выполнения PG10 — Gather). Так и получается ровно 3 плана, на каждый запрос )
Итак, собственно вот, видим «на лету», что у нас есть что-то нехорошее — Sec Scan тысяч строк
Уверен поможет индекс:
create index on somet (number) where number < 1000Всё, модуль автоэксплейна ничего в логи не пишет:
pgBadger
Просматривать логи глазками неудобно, потому для поиска подобных запросов по логам есть утилита — pgbadger. Она группирует и агрегирует запросы в простенький html-отчёт. И будет он настолько подробным, насколько подробны ваши логи
Установка:
> sudo apt install pgbadgerГенерация отчёта на основании логов:
> pgbadger -j 4 -p '%t [%p]:[%l-1]' /var/log/postgresql/postgresql-9.6-main.log -o bad.html
[========================>] Parsed 43578 bytes of 43578 (100.00%), queries: 115, events: 1
LOG: Ok, generating html report...И подобная красота получается:
В общем не буду рассказывать обо всех возможностях pgbadger, ибо и сам их не знаю, а документация у него очень хорошая, тем более есть "живой отчёт", который нагляднее покажет всё.
И коротко, как у нас:
- auto_explain в проде отключен
- К логам постгрес обращаемся очень редко, но pgBadger использовали
- Для real time мониторинга используем вовсе okmeter, отлично себя показал, но лучше логов, порой, ничего нет )
Комментарии (5)
linuxover
06.05.2018 22:35я про инструмент EXPLAIN думал и мне кажется что складывать EXPLAIN в лог по времени выполнения — плохая идея.
плохая по следующей причине.
допустим у вас проект на Pg. Имеется 100500 запросов от вебсервера, десятка демонов и пары десятков крон-скриптов.
и вдруг — факап. БД лежит. диск 100%.
Вы начинаете заглядывать в slowlog (который например настроен на >15 секунд) и что там видите?
SELECT * FROM "table" WHERE "id" = 123
и таких записей сотни, тысячи. Потом база приходит в себя и разгрести slow log и найти проблемный запрос крайне проблематично.
что интересно — запрос, вызвавший факап — далеко не всегда присутствует в slow log.
соответственно EXPLAIN-аналог slow log считаю неправильной идеей.
а вот было бы неплохо следующее:
Поскольку большинство запросов передаются в БД отдельно от биндинга переменных то есть в виде
SELECT * FROM "table" WHERE "id" = $1
То было бы неплохо если бы этот запрос бы становился ключем в таблице статистики и рядом с ним бы помещался текст EXPLAIN.
Плюс в соседнем столбике счетчики.
вот это был бы полезный инструмент
Melkij
06.05.2018 23:00Вы описали работу pg_stat_statements за двумя оговорками: автоматически результата explain в нём пока нет (потому что неясно какой именно план писать в результат, патчи есть для записи лучшего/худшего планов, но в pg11 они не вошли), зато нормализация запросов давно есть и отлично работает с plain text запросами даже без prepared statements.
Попутно заметки:
если логи пишутся на отдельный раздел, то его переполнение не приведёт к остановке базы. Просто за это время не будет логов. Logging collector не считает недостаток места поводом останавливать работу.
Разгрести лог аварии — упомянутый pgbadger и другие утилитки такого плана.Melkij
06.05.2018 23:13диск 100%
Я запоздало сообразил, что вы скорее имели в виду дисковую утилизацию в потолок.
Вообще понять только по логам что пошло не так — весьма непросто бывает. Графики мониторинга нужны, простой график top-N запросов по общему времени выполнения — уже значительно упрощает жизнь. Цифры есть в pg_stat_statements и даже отдельно время для дисковых операций. И единственная сложность — счётчики инкрементные, значит мониторинг должен показывать разницу между метриками во времени, а не сиюминутные stateless значения, как большинство системных метрик.
Melkij
Не упомянули ещё что auto_explain можно включать на отдельного пользователя:
ALTER ROLE some_user SET session_preload_libraries TO 'auto_explain';ALTER ROLE some_user SET "auto_explain.log_min_duration" TO '100ms';
Штука хорошая, особенно если надо ловить некий подземный стук когда план внезапно плывёт. Или интересный фокус был с приложением, которое неверно заявляло типы данных для prepared statement (передавался numeric вместо int), из-за чего планировщиком не использовался индекс, но сам запрос выполнялся корректно. Выполнялся медленно, и не ловилось через explain, т.к. не было видно передаваемый тип.
Если интересуют просто тяжёлые запросы — лучше включить pg_stat_statements и раз в сутки (или своим мониторингом) строить отчёт по времени выполнения. Мы например кругом настраиваем вот такой отчёт с топ-40 запросами по общему времени выполнения за сутки.
Окметр — хорошая штука, и даже если не используете его, то весьма советую посмотреть какие метрики выводятся на графиках postgresql и сделать в своём мониторинге такие же. Ну а вообще у них огромная куча метрик собирается. (циферки по конкретным запросам к слову именно pg_stat_statements и собирает)
SanSYS Автор
Спасибо за качественный коммент
Если честно — не знал, что для ролей можно определять свои настройки (хотя это же пг, кажется тут всё возможно)