PostgreSQL Antipatterns: рекурсивные грабли на ровном месте, или Сказка о потерянном времени14.02.2022 16:01

В моей практике ускорения SQL-запросов для PostgreSQL, в большинстве случаев, все сводится к применению типовых методик — их не особенно-то и много, и прочитать про большинство из них можно в моем профиле.

Но иногда обнаруживаются очень странные вещи в поведении этой, безусловно, отличной СУБД.

Все началось с запроса, который мне показали с диагнозом «необъяснимо тормозит»:

EXPLAIN ANALYZE
WITH RECURSIVE ttree AS ...
-- ...
TABLE ttree;

В самом запросе не было ничего особо интересного, никаких wCTE, только попытка реализовать оптимизированный проход вниз по иерархии, а вот в плане — еще как:

CTE Scan on ttree  (actual time=0.036..0.243 rows=4 loops=1)
  CTE ttree
...
Planning time: 0.594 ms
Execution time: 413.393 ms

То есть за половину миллисекунды отработал планировщик, еще четверть заняло фактическое выполнение… и еще 412ms или 99.8% всего времени — непонятно что.

Вычленяем минимальный запрос

Если в запросе что-то ведет себя странно — начинаем отсекать «хвост» по частям, пока ситуация не станет понятной.

Режем по живому

Смотрим на конец запроса:

-- ...
, tlist AS (
  SELECT * FROM thiers
)
TABLE ttree;

Понятно, что когда wCTE в запросе нет, то генерация такой CTE, у которой нет ни одного потребителя, даже в план не попадает. Но, на всякий случай закомментируем:

-- ...
/*
, tlist AS (
  SELECT * FROM thiers
)
*/
TABLE ttree;

Запрос выполняется по-прежнему, но теперь уже ничуть не тормозит:

CTE Scan on ttree  (actual time=0.025..0.240 rows=4 loops=1)
  CTE ttree
...
Planning time: 0.289 ms
Execution time: 0.316 ms

Внезапно! Как и почему от комментирования неиспользуемой CTE запрос ускорился в 500 раз?

Борьба за воспроизводимость

Итак, мы неожиданно выяснили, что «тормозить» перестает, если убрать лишнюю CTE, с обращением к другой CTE — thier. Вот только эта CTE тоже не простая, а рекурсивная.

Отсекаем все лишнее

Возьмем тестовую микротабличку:

CREATE TABLE tbl AS
SELECT
  (random() * 1e5)::integer val
FROM
  generate_series(1, 1e5);
  
CREATE INDEX ON tbl(val);

И постепенное отсечение всех элементов приводит нас к вот такой модели запроса:

EXPLAIN (ANALYZE, COSTS OFF)
-- первая рекурсия, возвращает 0 "записей" из таблицы
WITH RECURSIVE R1 AS (
  SELECT
    '{}'::tbl[] recs
UNION ALL
  SELECT
    '{}'::tbl[]
  FROM
    R1
  WHERE
    coalesce(recs, '{}') <> '{}'
)
-- "разворачиваем" якобы полученные записи в поля
, R1v AS (
  SELECT
    (rec).val
  FROM
    (
      SELECT
        unnest(recs) rec
      FROM
        R1
    ) T
)
-- вторая рекурсия
, R2 AS (
  TABLE R1v
UNION
  SELECT
    R1v.*
  FROM
    R1v
  , R2
)
-- неиспользуемый результат второй рекурсии
, X AS (
  TABLE R2
)
TABLE R1;

Вполне логично, что все узлы, кроме первой рекурсии, не исполнялись — (never executed). Но вот итоговый план потянул почти на 600ms, вернув гордое «ничего из ничего».

Это поведение вполне стабильно и дает на версии PostgreSQL 10.19 воспроизводимый результат порядка 400–600 «лишних» миллисекунд.

Что интересно, на PostgreSQL 13.5 результат гораздо стабильнее, но не лучше — 600–615ms, а вот на случайно оказавшейся 13b2 на Win10 — неожиданно, всего 3ms!

Надеюсь, кто-то сможет «копнуть» ситуацию глубже и выложит детальный разбор причин, а пока что запомним: две рекурсии в одном запросе — проблемы. Кто предупрежден — вооружен!

© Habrahabr.ru