Русский
Русский
English
Статистика
Реклама

PostgreSQL Antipatterns анализируем блокировки SELF JOIN vs WINDOW

Ранее мы уже научились перехватывать блокировки из лога сервера PostgreSQL. Давайте теперь положим их в БД и разберем, какие фактические ошибки и проблемы производительности можно допустить на примере их простейшего анализа.

В логах у нас отражается всего 3 вида событий, которые могут происходить с блокировкой:

  • ожидание блокировки
    LOG: process 38162 still waiting for ExclusiveLock on advisory lock [225382138,225386226,141586103,2] after 100.047 ms
  • получение блокировки
    LOG: process 38162 acquired ExclusiveLock on advisory lock [225382138,225386226,141586103,2] after 150.741 ms
  • взаимоблокировка
    ERROR: deadlock detected

deadlock'и исключим из анализа это просто ошибки, и попробуем выяснить, сколько всего времени мы потеряли из-за блокировок за конкретный день на определенном хосте.

Для начала нам понадобится таблица, куда мы будем собирать все такие записи:

CREATE TABLE lock(  dt       -- ключ хронологического секционирования    date, host     -- сервер, на котором возникла блокировка    uuid, pid      -- PID процесса из строки лога    integer, ts       -- момент события    timestamp, event    -- { lock-wait | lock-acquire | deadlock-detect }    lockevent, type     -- { relation | extend | ... }    locktype, mode     -- { AccessShare | RowShare | ... }    lockmode, lock     -- объект блокировки    uuid, exectime -- продолжительность    numeric(32,2));

Более подробно про организацию секционирования в нашей системе мониторинга можно прочитать в статье Пишем в PostgreSQL на субсветовой: 1 host, 1 day, 1TB, а про различные типы и режимы блокировок в DBA: кто скрывается за блокировкой.

Как слышится, так и пишется


Попробуем ответить на вопрос, вынесенный в начало статьи, простейшим способом.



Что такое время ожидания блокировки? Ну, очевидно же, это время ее получения для каждого случая ее ожидания:

  • берем каждый случай ожидания (lock-wait)
  • для него находим ближайшую снизу по времени запись получения (lock-acquire) этой же (lock, pid, mode) блокировки то есть на тот же объект, в том же процессе, с тем же режимом

Тип блокировки (type) в нашем случае можно опустить, поскольку он однозначно определяется самим объектом (lock).

Дальше останется только просуммировать полученные результаты.

SELECT  ts, pid, event, type, mode, lock, exectime, T.*FROM  lock lc, LATERAL (    SELECT      exectime waittime    FROM      lock    WHERE      (        dt      , host      , lock      , pid      , mode      , event      ) = (        '2020-06-19'::date      , lc.host      , lc.lock      , lc.pid      , lc.mode      , 'lock-acquire'      ) AND      ts >= lc.ts    ORDER BY      ts    LIMIT 1  ) TWHERE  (    lc.dt  , lc.host  , lc.event  ) = (    '2020-06-19'::date  , 'e828a54d-7e8a-43dd-b213-30c3201a6d8e'::uuid  , 'lock-wait'::lockevent  );

Все просто и ясно! А что нам покажет EXPLAIN?..



Оу пришлось прочитать почти 900MB данных, причем почти все из-за поиска связанной записи для каждой блокировки, не очень красиво.

Но является ли этот запрос вообще корректным для нашей задачи? Нет! Посмотрим внимательно в собранные данные:



Ой Оказывается, сервер жалуется в логи на одну и ту же неполученную блокировку иногда много-много раз. А это означает, что мы учли время ее ожидания кратно количеству таких записей в логе, что совсем не соответствует желаемому.

Помни о цели!


Собственно, а зачем мы вообще для каждой записи ожидания ищем связанную? Мы же хотим узнать, сколько заняло ожидание, а оно прямо записано в lock-acquire. Так давайте сразу отбирать только их, тогда будет всего лишь один Index Scan правильно?

Почти, да не совсем. Дело в том, что под нагрузкой лог-процесс может пропускать любые из записей хоть о начале ожидания блокировке, хоть о факте ее получения:



Так неужели нет способа за одно чтение сразу получить все нужные нам данные?

Window Functions: семерых одним ударом


На помощь нам придут оконные функции.


А конкретнее модель выделения цепочек в готовой выборке из статьи SQL HowTo: собираем цепочки с помощью window functions.

Сначала поймем, что условием окончания цепочки то есть сегмента подряд идущих по ключу (host, lock, pid, mode) записей блокировки для нас является или явное возникновение event = 'lock-acquire' или (что очень редко, но бывает) начало нового сегмента блокировки того же объекта, чья длительность (exectime) начала считаться заново.



Также надо учесть тот факт, что время может совпадать для нескольких записей лога даже с одного PID. В этом случае надо дополнительно сортировать по exectime, чтобы получить правильную последовательность:



-- формируем условие окончания блокировкиWITH lc AS (  SELECT    *  , CASE      WHEN event = 'lock-wait' THEN        exectime > coalesce(lead(exectime) OVER(PARTITION BY lock, pid, mode ORDER BY ts, exectime), 0) -- "перелом" времени ожидания      ELSE TRUE -- 'lock-acquire' - блокировка получена    END cond -- условие окончания "цепочки"  FROM    lock lc  WHERE    event <> 'deadlock-detect' AND -- исключаем все deadlock    (      lc.dt    , lc.host    ) = (      '2020-06-19'::date    , 'e828a54d-7e8a-43dd-b213-30c3201a6d8e'::uuid    ))-- оставляем только "последние" записи - их exectime и есть время ожидания "всей" блокировкиSELECT  ts, pid, event, type, mode, lock, exectimeFROM  lcWHERE  cond;



Теперь мы прочитали всего 8MB данных (в 100 раз меньше!), чуть-чуть уменьшив итоговое время выполнения.

Его можно уменьшить еще, если создать индекс, идеально подходящий под OVER (то есть включающий lock, pid, mode, ts, exectime), избавившись от Sort-узла. Но обычно поле в индексе за timestamp делать не стоит.
Источник: habr.com
К списку статей
Опубликовано: 08.07.2020 10:20:45
0

Сейчас читают

Комментариев (0)
Имя
Электронная почта

Блог компании тензор

Postgresql

Sql

Администрирование баз данных

Dba

Explain

Базы данных

Sql tips and tricks

Window functions

Категории

Последние комментарии

© 2006-2020, personeltest.ru