ExclusiveLock on extension of relation или "медленные" insert


#1

Проводя очередное нагрузочное тестирование у заказчика на машине с 352 ядрами столкнулись с проблемой так называемых “медленных” insert. Времена ожидания на вставку единичных строк в таблицы достигало часа и более.
Первоначальный google-анализ выявил пару тредов из psql-hackers:
https://www.postgresql.org/message-id/466D72D2-68EC-4FF4-93B8-43B687E7B705@simply.name
https://www.postgresql.org/message-id/01035B69-9C16-4887-8421-C5B91A4AFACF%40gmail.com

Результат применения рекомендацих(например, уменьшить количество shared_buffers) из них привел к нулевому результату.

Выражалась проблема в виде :

  1. Большого количества сессий в состоянии wait_event= buffer_mapping (мониторинг pg_stat_activity)
  2. Появление строк , содержащих “still waiting for ExclusiveLock on extension of relation” в логе работы Postgresql (мониторинг логов)
    Вот один из семплов “мониторинга” данной ситуации:

  locks_count | active_session | buffer_content | buffer_mapping | insert_slow_count
-------------+----------------+----------------+----------------+-------------------
       68694|            843|              0 |             14 |               101
(1 row)

Где,
locks_count - это обыкновенный select count() from pg_locks;
active_session - select count(
) from pg_stat_activity where state=‘active’
insert_slow_count - select count(*) from pg_stat_activity where state=‘active’ and query like ‘%insert%’ and now()-state_change>interval ‘30 sec’;
buffer_content - число активных сессий в ожидании buffer_content
buffer_mapping - число активных сессий в ожидании buffer_mapping

Данное большое количество блокировок в системе распределялось следующим образом:


postgres=# select count(*),locktype,mode from pg_locks group by mode,locktype;
 count |  locktype  |           mode
—-----+------------+------------------------—
     3 | relation   | ShareUpdateExclusiveLock
 67823 | relation   | AccessShareLock
   843 | virtualxid | ExclusiveLock
    25 | relation   | RowExclusiveLock
(4 rows)

Большое количество AccessShareLock связано с тем, что в тестировании присутствовали развесистые select с большим количеством(~30 ) join. Из-за такого большого количества соединений таблиц, каждый select порождал сотни блокировок вида AccessShareLock, которые использовались при легковесных (lightweight) блокировках индексов и таблиц на чтение.
Далее пришло понимание что получение блокировки вида ExclusiveLock не могло пробится сквозь «стену» из многочисленных блокировок вида AccessShareLock. Из-за этого операции вида insert, update не могли в течение долгого времени изменить таблицы присутствующие в данных выражения.
При дебаге «подвисших» на insert сессий выяснилось что их backtrace выгядит следующим образом:


#0  0x00007f4bb12f63a7 in semop () from /lib64/libc.so.6
#1  0x000000000067f291 in PGSemaphoreLock (sema=sema@entry=0x2acb625499d8) at pg_sema.c:387
#2  0x00000000006e7e83 in LWLockAcquire (lock=0x2aaab1594568, mode=LW_SHARED) at lwlock.c:1339
#3  0x00000000004c0b1b in _bt_relandgetbuf (rel=rel@entry=0x3b67eb8, obuf=, blkno=bl»
#4  0x00000000004c5414 in _bt_search (rel=rel@entry=0x3b67eb8, keysz=keysz@entry=1, scankey=scankey»
#5  0x00000000004bffba in _bt_doinsert (rel=rel@entry=0x3b67eb8, itup=itup@entry=0x2c44890, checkUn»
#6  0x00000000004c2dea in btinsert (rel=0x3b67eb8, values=0x7ffd8323fac0, isnull=0x7ffd8323fbc0 "\0»
#7  0x00000000005d6205 in ExecInsertIndexTuples (slot=slot@entry=0x34ba218, tupleid=tupleid@entry=0»
#8  0x00000000005f4680 in ExecInsert (canSetTag=1 '\001', estate=0x34b8318, onconflict=<optimized o»
#9  ExecModifyTable (node=node@entry=0x2c3f108) at nodeModifyTable.c:1523
#10 0x00000000005daa98 in ExecProcNode (node=0x2c3f108) at execProcnode.c:396
#11 0x00000000005d6db7 in standard_ExecutorRun (queryDesc=, direction=<optimized out»
#12 0x00007f4ba45dd045 in pgss_ExecutorRun (queryDesc=0x3593658, direction=ForwardScanDirection, co»
#13 0x00007f4ba43d7558 in explain_ExecutorRun (queryDesc=0x3593658, direction=ForwardScanDirection,»
#14 0x00000000006f9e7e in ProcessQuery (plan=, sourceText=0x35e6f88 "INSERT INTO SBR»
#15 0x00000000006fa0bc in PortalRunMulti (portal=portal@entry=0x2382ff8, isTopLevel=isTopLevel@entr»
#16 0x00000000006fab8e in PortalRun (portal=0x2382ff8, count=9223372036854775807, isTopLevel=<optim»
#17 0x00000000006f823a in PostgresMain (argc=, argv=, dbname=<optimiz»
#18 0x0000000000477da9 in BackendRun (port=0x23b8860) at postmaster.c:4428
#19 BackendStartup (port=0x23b8860) at postmaster.c:4104
#20 ServerLoop () at postmaster.c:1804
#21 0x000000000069139a in PostmasterMain (argc=argc@entry=3, argv=argv@entry=0x2363a10) at postmast»
#22 0x0000000000478a1e in main (argc=3, argv=0x2363a10) at main.c:228

После анализа необходимой информации о поведении “подвисших” на insert сессий Александр Коротков разработал патч изменяющий поведение postgres при получении эксклюзивных легковесных (lightweight) блокировок .
Дело в том, что на текущий момент в ванильном postgresql эксклюзивные блокировки на объекты берутся в тот момент когда счетчик легковесных блокировок на чтение на объект равно нулю. Но дело в том, что количество легковесных(lightweight) блокировок на чтение в данном тестировании на несколько порядков превосходило количеству легковесных блокировок на запись, последние никак не могли быть получены. Пробится через стену легковесных блокировок на чтение того или иного объекта получалось лишь при изменении профиля нагрузки на данные объекты.
В патче Александра, легковесные блокировки на чтение и запись были уравнены в правах и получались из общей очереди.
В результате применения данного патча последующие тестирования показали отсутствие “подвисших” insert.
В данный момент ведется работа по улучшению поведения патча.
Было бы замечательно если бы в коментах отписались бы те, у кого тоже возникали такие проблемы и как их смогли забороть.


#2

Версия-то какая?
Вот тут про то как пилили ProcArrayLock.
Но, вообще, мне тоже кажется, что проблему надо решать более системно на уровне LWLock и ставить Exclusive в группы, а не в одну очередь.


#3

pgproee 9.6. Сейчас патч будет иметь улучшенную версию. Ожиданий на ProcArrayLock в этом случае не было.
Такие ожидания можно отловить если делать из нескольких десятков сессий update в таблицу, а в соседних сессиях select из нее. На больших тачках select убивать начинают производительность insert /update почти до нуля. Чот типа такого наблюдалось.

pid   | wait_event_type |      wait_event      |                          query
—------+-----------------+----------------------+----------------------------------------------------------
 653149 | IPC             | ProcArrayGroupUpdate | update test set txt=md5(random()::text)  where id=57267;
 653184 | IPC             | ProcArrayGroupUpdate | update test set txt=md5(random()::text)  where id=73724;
 653161 | IPC             | ProcArrayGroupUpdate | update test set txt=md5(random()::text)  where id=8441;
(3 rows)

при этом

bash-4.2$ cat test_upd.sql
\set id random(1, 100000)
begin;
        update test set txt=md5(random()::text)  where id=:id;
end;
bash-4.2$ cat test_sel.sql
\set id random(1, 100000)
begin;
        select *  from test  where id=:id;
end;

pgbench -f test_select.sql:
progress: 64.0 s, 372298.5 tps, lat 0.940 ms stddev 0.879
progress: 65.0 s, 358547.0 tps, lat 0.976 ms stddev 1.705
progress: 66.0 s, 384095.0 tps, lat 0.911 ms stddev 0.707
progress: 67.0 s, 387413.2 tps, lat 0.903 ms stddev 0.677

pgbench -f test_upd.sql:
progress: 64.0 s, 211.2 tps, lat 3115.314 ms stddev 1983.392
progress: 65.0 s, 0.0 tps, lat 0.000 ms stddev 0.000
progress: 66.0 s, 0.0 tps, lat 0.000 ms stddev 0.000
progress: 67.0 s, 0.0 tps, lat 0.000 ms stddev 0.000
progress: 68.0 s, 0.0 tps, lat 0.000 ms stddev 0.000


#4

А где посмотреть патч?


#5

В бенче какая-то дичь. Нет, конечно, при желании можно читать и с реплики (это шутка, если что)


#6

fair-lwlock-master-1.patch (3,3 КБ)

Пока этот патчик сыроват, но улучшения будут к нему


#7

На openpower с этим патчем постгрес в два раза медленнее работает.


#8

Пока да, позже будет более оптимальная версия


#9

Как-то на конференции у меня даже был слайд про это


Но вот в патче не совсем то что я хотел увидеть. Вообще, там главная проблема в том чтобы потом всё это отбенчмаркать везде как следует, это прямо куча работы.


#10

Картинка - огонь!