ExclusiveLock extend на пустой базе и с ее ростом пропадает / PostgreSQL

ReSQL.ru

Мобильная версия Контакт Правила FAQ Помощь

Гость

Войти | Регистрация | Профиль | Очистить

Новые сообщения | Избранное

Форумы | Пользователи | Статистика | Мод. лог | Поиск

Доб. в избранное | Игнор. тему | Прикреп. тему | Пометить прочит. / непрочит. | Фильтр

Форумы / PostgreSQL [игнор отключен] [закрыт для гостей] / ExclusiveLock extend на пустой базе и с ее ростом пропадает

3 сообщений из 3, страница 1 из 1

ExclusiveLock extend на пустой базе и с ее ростом пропадает

#40131535

serg_777777

Гость

День добрый.

Тестируем некоторое Java приложение и наблюдаем следующее поведение.

Код: sql

1.
2.
3.
4.
5.
6.

RHEL 7.9
виртуалка, 8vCPU/16Gb
PG 11.14 (пробовал и 12.9)
swap off
echo never > /sys/kernel/mm/transparent_hugepage/enabled
echo never > /sys/kernel/mm/transparent_hugepage/defrag

Очищаю тестовую БД (truncate table->vacuum)
shared_buffers = '2096MB'

Подаю нагрузку и через какие-то интервалы получаю ExclusiveLock extend. Ожидаю пока таблица вырастет до ~4Gb и все нормализуется. Жду еще 2 часа и все ок.

Опять очищаю тестовую БД (truncate table->vacuum)
shared_buffers = '128MB'

Подаю нагрузку и все ок.

Перерыл весь гугл.
И тут https://www.sql.ru/forum/904894-2/exclusivelock и эти же обсуждения на других ресурсах.
https://www.postgresql.org/message-id/flat/466D72D2-68EC-4FF4-93B8-43B687E7B705@simply.name]https://www.postgresql.org/message-id/flat/466D72D2-68EC-4FF4-93B8-43B687E7B705@simply.name

Много читал где про патч на 9.6 (хотя мой perf top другой . см ниже.), но у меня же уже 11.14 и на 12.9 тоже пробовал.

Дисковая система, судя по iostat, в норме. latency до 5мс и то редкие. Очередей нет.

Опции на томе LVM как советовал Космодемъянский такие:
ext4 (rw,noatime,nodiratime,nobarrier,data=ordered)

Игрался на таблице с fillfactor (пробовал 10 и 70) - не помогло.

perf top в эти моменты показывает следующее:

Код: sql

1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.

   6.56%  postgres                    [.] tuplehash_insert
   5.74%  postgres                    [.] slot_deform_tuple
   5.39%  postgres                    [.] ExecInterpExpr
   5.27%  [vdso]                      [.] __vdso_clock_gettime
   4.22%  postgres                    [.] HeapTupleSatisfiesMVCC
   3.34%  libc-2.17.so                [.] get_next_seq
   2.21%  postgres                    [.] AllocSetAlloc
   1.91%  postgres                    [.] hash_search_with_hash_value
   1.71%  postgres                    [.] hash_any
   1.58%  postgres                    [.] ExecEvalScalarArrayOp
   1.53%  postgres                    [.] heap_getnext
   1.48%  libc-2.17.so                [.] __memcpy_ssse3_back
   1.39%  [kernel]                    [k] _raw_spin_unlock_irqrestore
   1.33%  postgres                    [.] nocachegetattr

И это "картина" явно отличается от обсуждаемых в ссылках выше про 9ку.

ExecInterpExpr вроде как участвует при разборе SQL для оптимизатора.

CPU в такие моменты в 100%, естественно выстраивается очередь на CPU.

pgbouncer лишь немного смягчает ситуацию урезая кол-во сессий, но не приyципиально.

Меня ставит в тупик именно такое поведение на фактически пустой БД и с ростом БД нормализация ситуации и самое главное отсутствие понимания причины и ее устранения.

Но если фактически убрать shared_buffer до "нуля" (128Мб) этого нет.

Вообщем если у кого есть мысли - направьте на путь истинный.

...

Рейтинг:

0 / 0

03.02.2022, 18:46

| Ответить | Цитировать | Написать

ExclusiveLock extend на пустой базе и с ее ростом пропадает

#40131547

Maxim Boguk

Участник

Откуда: Melbourne, Австралия

Сообщения: 5 148

Рейтинг: 0 / 0

serg_777777,

Не помешало бы подробное описание нагрузки...
что именно делается, сколько активных соединений с базой, сколько соединения всего?
Включить log_checkpoints и посмотреть не связанны ли " через какие-то интервалы получаю ExclusiveLock extend." как то со временем окончания checkpoint...
" через какие-то интервалы получаю ExclusiveLock extend." - на какое время этот ExclusiveLock висит?
Точно ли именно в это время дисковая система не задумывается (высокая latency).
fillfactor тут точно не поможет.

Какая дисковая система на хосте? nvme/ssd? механика? какой то cloud storage?

Наиболее вероятное объяснение ситуации - это дисковая система становится раком в конце checkpoint при fsync
и поэтому не получается оперативно добавлять страницы к файлам с данными.

PS: "Дисковая система, судя по iostat, в норме. latency до 5мс и то редкие." - c каким временным разрешением вы эту latency снимаете? Если раз в 1-5 минут то и ExclusiveLock extend вызванные проблемами с IO вы там увидите только если там эта проблема будет 1-5 минут продолжаться.

PPS: я бы сильно уменьшил vm.dirty_bytes и vm.dirty_background_bytes (предположим до 8MB и 1MB как совсем safe values, если поможет можно будет аккуратно поднимать удваивая пока норально дисковая система справляется с fsync)

PPPS: это ГИПОТЕЗЫ а не гарантия что проблема именно там.

--
Maxim Boguk
лучшая поддержка PostgreSQL: dataegret.ru

...

Рейтинг:

0 / 0

03.02.2022, 19:47

| Ответить | Цитировать | Написать

ExclusiveLock extend на пустой базе и с ее ростом пропадает

#40131648

serg_777777

Гость

Maxim Boguk,
спасибо за советы.

Нагрузка тестовая, синтетическая.
~2.5K транзакций/сек (коммитов)
Диски конечно облачные, куда же теперь без этих облаков :) Вообщем неизвестно что там и через какие кэши это все проходит.

Конкурируют Insert-ы и select за одну таблицу вроде бы.

Пока попробовал следующе:
выставил
sudo sysctl vm.dirty_bytes=8388608
sudo sysctl vm.dirty_background_bytes=1048576

shared_buffers = '2096MB'
Очистил БД (truncate table->vacuum)

Проблема повторилась.

Что касается статистики IO - собираю часто, 1 раз в секунду через /proc....
Вот привожу пример через iostat

Видим начало проблемы в vmstat в 11:05:27:
Видим дикую очередь процессов (первый столбец и ~100% утилизацию CPU)

Код: java

1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- -----timestamp-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st                 MSK
 7  1      0 4657076  33924 5962620    0    0     0 33468 75747 23501 51  9 37  3  0 2022-02-04 11:05:16
 6  0      0 4645740  33924 5973564    0    0     0 33024 77162 25113 37  8 51  3  0 2022-02-04 11:05:17
 8  0      0 4629492  33932 5985912    0    0     0 33468 78668 26283 32  8 57  3  0 2022-02-04 11:05:18
 5  1      0 4612892  33932 5996964    0    0     0 34160 79945 26756 32  8 56  4  0 2022-02-04 11:05:19
 9  0      0 4594892  33932 6007308    0    0     0 32208 79373 26640 32  7 57  4  0 2022-02-04 11:05:20
 0  0      0 4574860  33952 6018336    0    0     0 33272 77824 25960 31  7 58  4  0 2022-02-04 11:05:21
19  0      0 4559568  33952 6029812    0    0     0 33472 79238 26248 35  8 53  4  0 2022-02-04 11:05:22
 4  1      0 4543100  33960 6041884    0    0     0 33880 78733 26194 33  8 55  4  0 2022-02-04 11:05:23
19  1      0 4528008  33960 6051976    0    0     0 31560 77886 25720 32  8 56  3  0 2022-02-04 11:05:24
 7  0      0 4463660  33960 6062248    0    0     0 31604 76042 23937 37  8 51  3  0 2022-02-04 11:05:25
15  2      0 4437692  33976 6072540    0    0     0 30888 74440 23513 43  8 47  3  0 2022-02-04 11:05:26
87  1      0 4180616  33976 6081436    0    0     0 23468 67858 19549 65 10 23  2  0 2022-02-04 11:05:27
139  2      0 3725588  33976 6088460    0    0     0 17412 59115 12455 85 15  0  0  0 2022-02-04 11:05:28
199  0      0 3510272  33984 6094420    0    0     0 14876 64538 12077 87 13  0  0  0 2022-02-04 11:05:29
135  0      0 3936920  33984 6101428    0    0     0 17632 69199 13589 86 14  0  0  0 2022-02-04 11:05:30
138  0      0 3834260  34000 6106856    0    0     0 12728 59761 10709 90 10  0  0  0 2022-02-04 11:05:31
198  1      0 3160476  34000 6112936    0    0     0 16144 65052 13865 88 12  0  0  0 2022-02-04 11:05:32

Вот вывод iostat (извиняюсь за длинный листинг):
WAL лежат на sdb, datafiles на sdc
Вроде как все красиво. Я бы сказал, что нагрузка на IO наоборот упала.

Код: java

1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
37.
38.
39.
40.
41.
42.
43.
44.
45.
46.
47.
48.
49.
50.
51.
52.
53.
54.
55.
56.
57.
58.
59.
60.
61.
62.
63.
64.
65.
66.
67.
68.
69.
70.
71.
72.
73.
74.
75.
76.
77.
78.
79.
80.
81.
82.
83.
84.
85.
86.
87.
88.
89.

02/04/2022 11:05:16 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00    74.00    0.00  957.00     0.00 20944.00    43.77     0.47    0.49    0.00    0.49   0.48  45.80
sdc               0.00   115.00    0.00  174.00     0.00 12584.00   144.64     0.21    1.20    0.00    1.20   0.26   4.50

02/04/2022 11:05:17 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00  997.00     0.00 21424.00    42.98     0.44    0.44    0.00    0.44   0.43  43.30
sda               0.00     7.00    0.00    4.00     0.00    44.00    22.00     0.00    0.25    0.00    0.25   0.25   0.10
sdc               0.00     2.00    0.00  111.00     0.00 10520.00   189.55     0.19    1.73    0.00    1.73   0.20   2.20

02/04/2022 11:05:18 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00 1110.00     0.00 22360.00    40.29     0.44    0.39    0.00    0.39   0.39  43.30
sdc               0.00    10.00    0.00  139.00     0.00 10832.00   155.86     0.31    2.22    0.00    2.22   0.22   3.10

02/04/2022 11:05:19 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00 1082.00     0.00 22232.00    41.09     0.46    0.43    0.00    0.43   0.43  46.40
sdc               0.00     1.00    0.00   96.00     0.00 11912.00   248.17     0.20    2.14    0.00    2.14   0.25   2.40

02/04/2022 11:05:20 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00 1019.00     0.00 21980.00    43.14     0.49    0.49    0.00    0.49   0.48  49.20
sda               0.00     2.00    0.00    7.00     0.00    36.00    10.29     0.00    0.00    0.00    0.00   0.00   0.00
sdc               0.00     1.00    0.00  112.00     0.00 11448.00   204.43     0.18    1.64    0.00    1.64   0.21   2.40

02/04/2022 11:05:21 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00    32.00    0.00 1048.00     0.00 22004.00    41.99     0.46    0.44    0.00    0.44   0.43  45.40
sdc               0.00    85.00    0.00  114.00     0.00 10108.00   177.33     0.25    2.19    0.00    2.19   0.25   2.80

02/04/2022 11:05:22 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00  963.00     0.00 22384.00    46.49     0.54    0.56    0.00    0.56   0.56  54.00
sdc               0.00     1.00    0.00  105.00     0.00 11056.00   210.59     0.19    1.87    0.00    1.87   0.26   2.70

02/04/2022 11:05:23 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00 1043.00     0.00 22624.00    43.38     0.48    0.47    0.00    0.47   0.46  48.00
sda               0.00     2.00    0.00    2.00     0.00    16.00    16.00     0.00    0.50    0.00    0.50   0.50   0.10
sdc               0.00     1.00    0.00  102.00     0.00 11360.00   222.75     0.17    1.72    0.00    1.72   0.22   2.20

02/04/2022 11:05:24 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00 1075.00     0.00 22536.00    41.93     0.40    0.37    0.00    0.37   0.37  39.70
sdc               0.00     0.00    0.00  102.00     0.00 10520.00   206.27     0.16    1.59    0.00    1.59   0.23   2.30

02/04/2022 11:05:25 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00  913.00     0.00 20624.00    45.18     0.44    0.48    0.00    0.48   0.48  43.50
sdc               0.00     2.00    0.00  175.00     0.00 10184.00   116.39     0.20    1.18    0.00    1.18   0.14   2.50

02/04/2022 11:05:26 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     6.00    0.00  949.00     0.00 20672.00    43.57     0.39    0.41    0.00    0.41   0.41  39.00
sdc               0.00    40.00    0.00   91.00     0.00  9380.00   206.15     0.10    1.12    0.00    1.12   0.19   1.70

02/04/2022 11:05:27 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     3.00    0.00  676.00     0.00 16604.00    49.12     0.32    0.48    0.00    0.48   0.47  31.50
sdc               0.00     2.00    0.00   63.00     0.00  6800.00   215.87     0.17    2.76    0.00    2.76   0.30   1.90

02/04/2022 11:05:28 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00  247.00     0.00  9876.00    79.97     0.12    0.50    0.00    0.50   0.47  11.60
sda               0.00     2.00    0.00    2.00     0.00    16.00    16.00     0.00    0.50    0.00    0.50   0.50   0.10
sdc               0.00     1.00    0.00   56.00     0.00  7032.00   251.14     0.10    1.80    0.00    1.80   0.30   1.70

02/04/2022 11:05:29 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00  196.00     0.00 10036.00   102.41     0.10    0.53    0.00    0.53   0.48   9.50
sdc               0.00     1.00    0.00   95.00     0.00  4712.00    99.20     0.33    3.46    0.00    3.46   0.18   1.70

02/04/2022 11:05:30 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00  281.00     0.00 10860.00    77.30     0.14    0.49    0.00    0.49   0.47  13.30
sda               0.00     0.00    0.00    3.00     0.00    20.00    13.33     0.00    0.00    0.00    0.00   0.00   0.00
sdc               0.00     1.00    0.00  175.00     0.00  6792.00    77.62     0.23    1.31    0.00    1.31   0.12   2.10

02/04/2022 11:05:31 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00    17.00    0.00  243.00     0.00  8000.00    65.84     0.12    0.49    0.00    0.49   0.43  10.50
sdc               0.00    30.00    0.00   32.00     0.00  4808.00   300.50     0.09    2.75    0.00    2.75   0.31   1.00

02/04/2022 11:05:32 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdb               0.00     0.00    0.00  259.41     0.00 11196.04    86.32     0.12    0.45    0.00    0.45   0.42  10.99
sdc               0.00     9.90    0.00  222.77     0.00  4954.46    44.48     0.35    1.57    0.00    1.57   0.05   1.19

...

Рейтинг:

0 / 0

04.02.2022, 11:42

| Ответить | Цитировать | Написать

3 сообщений из 3, страница 1 из 1

Форумы / PostgreSQL [игнор отключен] [закрыт для гостей] / ExclusiveLock extend на пустой базе и с ее ростом пропадает

Цитировать

Написать

Автор*:

Ввести пароль для входа

Тема*:

Сообщение

Данное сообщение тематическое

Сообщение содержит картинки или видео 18+

Автор:

ВНИМАНИЕ! На данном подфоруме действуют строгие правила. Удостоверьтесь, что ваше сообщение соответствует им!

Форум или тема закрыты для гостей. Необходима авторизация!

Загрузить последнюю сохраненную версию

Вложение:

Вставить как галерею

Максимальный размер вложений: 4,0 МБ, аудио/видео: 8,0 МБ. Картинки большего размера ужимаются, если возможно.

Введите код, изображенный на картинке. Если код нечитаемый, кликните картинку, чтобы загрузить другой вариант.

Отправляя сообщение, я выражаю свое согласие с правилами форума и принимаю пользовательское соглашение.

Читали тему (0):

Читали форум (0):

Пользователи онлайн (0):

start [/forum/topic.php?fid=53&gotonew=1&tid=1993671]:	0ms
get settings:	11ms
get forum list:	12ms
check forum access:	4ms
check topic access:	4ms
track hit:	29ms
get topic data:	11ms
get first new msg:	7ms
get forum data:	2ms
get page messages:	41ms
get tp. blocked users:	2ms
others:	280ms

total:	403ms