Перейти к содержанию

Медленный SQL-запрос

Runbook для ситуации: endpoint тормозит, в трассе видно долгий SQL-span, в логах pgx превышает таймаут. Или профильный outbox_forwarder_lag_seconds растёт, потому что SELECT FROM outbox идёт 5 секунд. Эта страница — как локализовать проблемный запрос, найти причину и починить.

Reference по pgx, индексам, транзакциям — в ../conventions/db-pgx.md. Про миграции и EXPLAIN ANALYZE — в ../how-to/add-migration.md.

Содержание

Симптомы

  • HTTP-endpoint отдаёт 504 (gateway timeout) или 500 с context deadline exceeded в логе.
  • Tempo-trace показывает span SELECT ... 2+ секунды.
  • Метрика http_request_duration_seconds по конкретному route выбивается выше обычного p99.
  • pg_stat_activity полон state = 'active' с query_start минуту назад.
  • Pool: PoolStat().AcquireCount() растёт, но AvailableConns низкий → handler'ы ждут соединение.

Что смотреть первым

Порядок диагностики:

  1. Grafana → Dashboard сервиса → график p99 по route. Один конкретный route или все сразу? Один → проблема в его SQL. Все → скорее всего pool исчерпан или БД-инфра лагает.
  2. Tempo → trace проблемного запроса → span'ы. pgx-span'ы показывают точное SQL-statement и длительность.
  3. pg_stat_statements (§2) → топ медленных запросов за последний час.
  4. pg_stat_activity (§4) → что сейчас висит, кто держит lock.

1. Найти проблемный запрос

Через OpenTelemetry (pgx-tracer включён по ../conventions/observability.md) каждый SQL-запрос = span с атрибутами db.statement, db.operation. В Tempo ищи по атрибуту:

{ service.name="review", db.statement =~ ".*FROM reviews.*" }

Либо открой конкретный долгий trace → внутри найди самый длинный query span → текст запроса и параметры.

Если tracing по какой-то причине недоступен — найдёшь в логе:

docker compose logs --since 10m <service> | grep -i "slow query"

(предполагается, что pgx-tracer логирует запросы > SlowQueryThreshold).

2. pg_stat_statements

Postgres-модуль, агрегирующий статистику по каждому уникальному SQL- запросу. Должен быть включён в postgresql.conf:

shared_preload_libraries = 'pg_stat_statements'
pg_stat_statements.track = all

Включение в БД (разовая команда):

CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

Топ-20 самых медленных запросов за последний интервал:

SELECT
    calls,
    round(total_exec_time::numeric / 1000, 2) AS total_sec,
    round(mean_exec_time::numeric, 2)          AS mean_ms,
    round((mean_exec_time * calls / 1000)::numeric, 2) AS wall_sec,
    rows,
    query
FROM pg_stat_statements
WHERE query NOT LIKE '%pg_stat_statements%'
ORDER BY total_exec_time DESC
LIMIT 20;

Читай так:

  • mean_ms высокий (> 100ms для OLTP) → запрос сам медленный, нужен индекс / переписывание.
  • calls высокий + mean_ms низкий → «N+1», каждый вызов быстрый, но их тысячи. Обычно виден в api-composition (см. ../patterns/api-composition.md).
  • wall_sec высокий — реально больше всего процессорного времени съедает. Это твой первый кандидат на оптимизацию.
  • rows / calls большое — запрос возвращает много строк, может, нужен LIMIT / пагинация.

Сброс счётчиков (если хочешь смотреть на свежем окне):

SELECT pg_stat_statements_reset();

3. EXPLAIN ANALYZE

Для конкретного запроса смотри план:

EXPLAIN (ANALYZE, BUFFERS, VERBOSE)
SELECT r.id, r.rating, r.text
  FROM review.reviews r
 WHERE r.place_id = $1
   AND r.deleted_at IS NULL
 ORDER BY r.created_at DESC
 LIMIT 20;

Что искать в output:

  • Seq Scan на таблице > 10k строк — индекса нет или он не выбран планировщиком. Смотри WHERE-предикат, добавь индекс.
  • Rows Removed by Filter большой — Postgres читает много строк и отбрасывает большую часть. Индекс по фильтрующей колонке или partial index.
  • Несоответствие actual rows и estimated rows (> 10x) — статистика устарела: ANALYZE <table>.
  • Nested Loop на больших таблицах — часто индикатор N+1 или отсутствия join-индекса.
  • Sort, Hash — если читают много данных, запросу не хватает индекса для порядка.
  • Heap Fetches > Index Only Scan — индекс есть, но Postgres лезет в heap: VACUUM для обновления visibility map.
  • Buffers: shared read=N — БД читает с диска, не из кэша. Большое N → холодный кэш или нехватка shared_buffers.

Общая метрика качества — actual time vs rows. Оптимально — actual time растёт линейно от rows. Если растёт экспоненциально — есть Cartesian product или неэффективный sort.

4. pg_stat_activity и блокировки

Что сейчас активно:

SELECT pid,
       state,
       wait_event_type,
       wait_event,
       NOW() - query_start AS duration,
       left(query, 100) AS q
  FROM pg_stat_activity
 WHERE state != 'idle'
   AND backend_type = 'client backend'
 ORDER BY query_start;

Столбцы:

  • state = 'active' — запрос исполняется.
  • state = 'idle in transaction' — транзакция открыта, ничего не делает (код забыл commit/rollback). Долгая idle in transaction держит locks на измененных строках → все, кто ждёт lock, висят.
  • wait_event_type = 'Lock' — запрос заблокирован чужим lock'ом. wait_event показывает тип (relation, transactionid, tuple).

Кто кого держит:

SELECT blocked.pid     AS blocked_pid,
       blocked.query   AS blocked_query,
       blocking.pid    AS blocking_pid,
       blocking.query  AS blocking_query,
       NOW() - blocking.xact_start AS blocking_xact_age
  FROM pg_stat_activity blocked
  JOIN pg_stat_activity blocking
    ON blocking.pid = ANY(pg_blocking_pids(blocked.pid))
 WHERE NOT pg_try_advisory_lock(blocked.pid);

Если blocking_xact_age > 1 минуты — это либо «висящая» транзакция (см. типовые причины §c), либо долгий backfill из миграции. В крайнем случае:

SELECT pg_terminate_backend(<blocking_pid>);

Террминат транзакции освобождает locks, но убивает работу этого pid'а — делай только, если уверен, что это не user-facing запрос (обычно SELECT ... FOR UPDATE от самого сервиса).

Типовые причины

a) Отсутствует индекс

Симптом. Seq Scan на большой таблице, mean_ms высокий.

Проверка. EXPLAIN ANALYZE + список индексов:

\di review.reviews*
SELECT indexname, indexdef
  FROM pg_indexes
 WHERE schemaname = 'review' AND tablename = 'reviews';

Фикс. Добавь индекс миграцией:

-- в миграции, НЕ вручную в prod
CREATE INDEX CONCURRENTLY idx_reviews_place_created
    ON review.reviews (place_id, created_at DESC)
    WHERE deleted_at IS NULL;

CONCURRENTLY — обязательно для prod: не блокирует writes. Важно: вне транзакции (нет BEGIN/COMMIT), миграция должна быть одним statement'ом или дроблена на отдельные миграции.

b) N+1 в api-composition

Симптом. Endpoint отдаёт список из 20 элементов, в trace видно 21 SQL-запрос (SELECT FROM reviews + 20× SELECT FROM users).

Проверка. В handler-коде поиск for _, r := range reviews { user, _ := c.users.Get(...) }.

Фикс. Один batch-запрос в downstream-сервис:

userIDs := make([]int64, len(reviews))
for i, r := range reviews {
    userIDs[i] = r.UserID
}
users, err := c.users.GetBatch(ctx, userIDs)  // один HTTP-запрос

На стороне владельца downstream endpoint'а:

SELECT id, name, avatar_url FROM auth.users WHERE id = ANY($1::bigint[]);

Подробнее — ../patterns/api-composition.md.

c) Висячая idle in transaction

Симптом. wait_event = 'Lock' / 'transactionid', у blocking_pid — state = 'idle in transaction', xact_start давно.

Причина. Код открыл транзакцию, сделал SELECT/UPDATE, и не закрыл (забыл defer tx.Rollback, висит на внешнем HTTP-вызове внутри InTx, что запрещено — см. ../conventions/db-pgx.md).

Фикс. - Немедленно: SELECT pg_terminate_backend(<blocking_pid>) — разорвёт транзакцию, откатит её, освободит lock. - Долгосрочно: ищи InTx с внешними вызовами; выноси их наружу InTx.

d) Устаревшая статистика планировщика

Симптом. EXPLAIN ANALYZE показывает rows=100000 (actual rows=10) — планировщик ждёт много строк, берёт Seq Scan вместо Index Scan.

Фикс.

ANALYZE review.reviews;

Для больших таблиц занимает минуты. Делается штатно автовакуумом, но после massive insert/delete может запаздывать — ручной ANALYZE ускоряет.

e) Bloat таблицы / индекса

Симптом. Таблица физически большая, хотя по SELECT count(*) строк немного. pg_stat_user_tables.n_dead_tup высокий.

SELECT relname, n_live_tup, n_dead_tup,
       round(n_dead_tup::numeric / NULLIF(n_live_tup,0), 2) AS dead_ratio
  FROM pg_stat_user_tables
 WHERE schemaname = 'review'
 ORDER BY n_dead_tup DESC;

Фикс. - VACUUM ANALYZE <table> — для таблиц, где bloat < 50%. - VACUUM FULL <table> — требует exclusive lock, только в maintenance-окне. - Настроить autovacuum_vacuum_scale_factor = 0.05 per-table для hot-таблиц (outbox, sessions) — agressive autovacuum держит bloat низким.

f) Pool исчерпан

Симптом. Не все запросы медленные, но все handler'ы ждут pool.Acquire. Метрика pool_acquired_connections ≈ PoolMax.

Причина. - Долгие транзакции (§c) занимают соединения. - PoolMax слишком маленький для RPS × mean query duration. - В том же пуле работает и forwarder, и HTTP — они конкурируют.

Фикс. - Увеличь DB_POOL_MAX в env. Начни с удвоения. - Выдели forwarder'у отдельный пул (3–5 соединений), чтобы он не конкурировал с HTTP — ../patterns/outbox.md. - Проверь statement_timeout — без него одна висящая транзакция навсегда забирает соединение.

g) Огромный JSON в payload

Симптом. EXPLAIN ANALYZE показывает нормальный план, но запрос медленный. Buffers: shared read большой → диск.

Причина. Колонка типа JSONB хранит 100 KB на строку, SELECT * читает весь payload.

Фикс. - Не делай SELECT * — перечисляй нужные колонки. - Для аналитики: SELECT payload->'field' без всего блоба. - Рассмотри, точно ли нужен JSONB — часто нормализованные колонки быстрее.

h) ORDER BY + LIMIT без индекса на sort-колонку

Симптом. EXPLAIN ANALYZE показывает Sort node, читающий всю таблицу.

Фикс. Композитный индекс с sort-колонкой в конце:

CREATE INDEX idx_reviews_place_created
    ON review.reviews (place_id, created_at DESC);

Теперь Postgres делает Index Scan в нужном порядке и останавливается через LIMIT.

Фиксы

Приоритет:

  1. Индекс — решает 70% медленных OLTP-запросов. CONCURRENTLY, миграцией, после проверки EXPLAIN ANALYZE.
  2. Переписать запрос — выкинуть лишние JOIN, заменить correlated subquery на LATERAL или JOIN, убрать SELECT *.
  3. Кэш — если запрос результат стабилен (read-mostly), оберни в Redis cache-aside (../conventions/caching.md).
  4. Батч — для N+1: один запрос с WHERE id = ANY($1).
  5. Архивирование — если таблица растёт до десятков миллионов строк, выдели холодные данные (reviews старше года) в отдельную таблицу.
  6. Разбиение на партиции — если таблица > 100M строк и это неизбежно.

Каждый фикс прогоняй через EXPLAIN ANALYZE на prod-snapshot'е БД, не на пустой dev-БД: план планировщика зависит от статистики, которой на dev нет.

Что нельзя делать под нагрузкой

  • CREATE INDEX без CONCURRENTLY — exclusive lock, блокирует writes на минуты. Всегда CONCURRENTLY, вынесенное в отдельную миграцию без BEGIN/COMMIT.
  • VACUUM FULL — эксклюзивный lock, перепакует таблицу. Только в maintenance-окне.
  • ALTER TABLE ... ADD COLUMN ... NOT NULL DEFAULT <expr> на большой таблице — Postgres переписывает все строки, держит lock. Разбивай на expand-contract — ../conventions/db-pgx.md.
  • Массовый DELETE FROM — создаёт bloat, лочит индексы. Батчи по 1000–10000 строк с паузой.
  • pg_terminate_backend на случайный pid — без понимания, что это за транзакция, можешь порвать in-flight бизнес-операцию.

Чеклист

  • Tempo-trace показал конкретный SQL-statement или группу.
  • pg_stat_statements подтвердил, что этот запрос — в топе по total_exec_time.
  • EXPLAIN ANALYZE (BUFFERS) прогнан на prod-snapshot'е или staging.
  • Причина определена: отсутствующий индекс / N+1 / idle-tx / bloat / pool / payload.
  • Фикс подготовлен миграцией с CONCURRENTLY (если индекс).
  • После фикса повторный EXPLAIN ANALYZE показывает правильный план.
  • Метрика p99 по route вернулась в норму в течение 15 минут.
  • Если правил indexes — ANALYZE <table> для обновления статистики.

Связанные разделы