Нагрузочное тестирование PostgreSQL честно: pgbench, прогрев, перцентили и coordinated omission

Один сервер можно описать как «820 tx/s, 20 мс» и как «p99 4,8 с при пятисекундной паузе». Первое даёт pgbench по умолчанию, второе — нагрузка заданным темпом и латентность по каждой транзакции. Про checkpoint — статья про всплески ввода-вывода, про выбор запросов — pg_stat_statements.

Стенд и что здесь «больше чего»

docker run -d --name dba-bench --memory 2g --cpus 4 -e POSTGRES_PASSWORD=pg postgres:18 \
  -c shared_buffers=256MB -c checkpoint_timeout=1min -c max_wal_size=1GB \
  -c track_io_timing=on -c log_checkpoints=on
docker exec dba-bench pgbench -U postgres -i -s 75 -q postgres
docker exec dba-bench psql -U postgres -Atc "select pg_size_pretty(pg_database_size('postgres')), current_setting('shared_buffers')"

вывод:

1129 MB|256MB

База (1129 МБ) в 4,4 раза больше shared_buffers, но меньше лимита памяти контейнера (2 ГБ). Page cache входит в этот лимит и вмещает всю базу, поэтому «данные больше RAM» здесь не выполнено: чтения идут из кэша ядра, а не с диска. Больше 2 ГБ базу делать нельзя из-за места на диске машины, так что опыт показывает работу с shared_buffers, а не с накопителем. Опыт шёл на общей машине вместе с чужими контейнерами, поэтому разброс между повторами включает посторонний шум; именно поэтому повторов не меньше трёх.

checkpoint_timeout снижен с 5 минут по умолчанию (документация) до 1 минуты: прогон должен быть длиннее интервала, и на стенде это достигается за две минуты, а не за часы. На продовых настройках правило то же: прогон охватывает несколько интервалов checkpoint_timeout.

Для каждого запуска pgbench пишет лог всех транзакций (-l) в /tmp/lg, число checkpoint за прогон — разность select num_timed + num_requested from pg_stat_checkpointer до и после, а перцентили считает короткий скрипт. В логе третья колонка — латентность транзакции в микросекундах; скрипт читает docker exec dba-bench sh -c 'cat /tmp/lg/pgbench_log.*' | python3 -I stats.py:

import sys
v = sorted(int(f[2]) for f in map(str.split, sys.stdin) if len(f) > 2 and f[2].isdigit())
p = lambda q: v[-(-len(v) * q // 100) - 1] / 1000
print(f"n={len(v)} mean={sum(v)/len(v)/1000:.1f} p50={p(50):.1f} p95={p(95):.1f} p99={p(99):.1f} max={v[-1]/1000:.1f} мс")

Строки skipped в лог попадают без числа в третьей колонке, фильтр isdigit их отбрасывает.

Правильный запуск

Протокол: 120 секунд прогрева (результат отбрасывается), затем три повтора по 120 секунд. Сначала закрытая модель определяет потолок: три прогона -c 16 дали 981, 820 и 796 tx/s, среднее 865. Затем темп задаётся явно, в долях потолка: 30 %, 60 % и 90 % (259, 519 и 778 tx/s). Каждый уровень повторён три раза:

docker exec dba-bench sh -c 'mkdir -p /tmp/lg && cd /tmp/lg && \
  pgbench -U postgres -n -l -c 16 -j 4 -T 120 --rate=519 -L 100 postgres'

вывод (один из трёх повторов уровня 60 %):

number of transactions actually processed: 60753
number of transactions skipped: 1266 (2.041%)
number of transactions above the 100.0 ms latency limit: 1588/60753 (2.614%)
latency average = 23.880 ms
latency stddev = 29.119 ms
rate limit schedule lag: avg 6.059 (max 99.991) ms
tps = 506.186304 (without initial connection time)

--rate включает открытую модель: транзакции приходят по расписанию независимо от того, успел ли сервер ответить на предыдущие. -L 100 заставляет pgbench не отправлять транзакции, которые уже опоздали на 100 мс и больше, и считать их отдельно (skipped). Результат по трём уровням, медиана трёх повторов, в скобках — минимум и максимум:

Все 120-секундные прогоны видели ровно два checkpoint (pg_stat_checkpointer, разность до и после).

DBA / 01koddo

p50, p95 и p99 при трёх уровнях нагрузки

Следствие для отчёта: p99 не выше сотни миллисекунд на 90 % нагрузки читается правильно только вместе с долей пропущенных транзакций. Без -L хвост был бы длиннее, а с ним он обрезан и переехал в счётчик.

Пять ошибочных запусков

Каждый из них на той же базе даёт число, которое выглядит как результат.

Только среднее и закрытая модель. При -c 16 в полёте всегда ровно 16 транзакций, поэтому среднее — это 16 / TPS: 16 / 819,8 = 19,5 мс, pgbench напечатал 19,517. Число не описывает сервер, оно описывает выбранное число клиентов. Хвост в тех же прогонах: p99 в 2,7 раза выше среднего (медианы 52,7 и 19,5 мс), максимум 0,8–1,0 с при двух checkpoint за прогон.

Короткий прогон. За 10 секунд checkpoint не случился в четырёх из пяти запусков; максимум 73–262 мс против 0,8–1,0 с у двухминутных. Короткий прогон измеряет интервал между checkpoint и обещает отсутствие пауз, которые на самом деле есть. Разброс TPS (735–877) включает посторонний шум машины.

Без прогрева. Перезапуск контейнера опустошает shared_buffers, но в этом стенде не замедлил прогон: два из трёх повторов дали 1223 и 1262 tx/s, быстрее установившихся 796–981 из двухминутных, третий — 817. Условия всех трёх одинаковы, checkpoint ни в одном не было, причина разброса не выделена. Вероятная роль страничного кэша ядра (он переживает перезапуск контейнера и вмещает 1129 МБ) не проверялась: сбросить его без прав суперпользователя на хосте нельзя. Вывод для методики: на этой базе и в этих условиях эффект прогрева не выделен из шума. Чтобы утверждать обратное для другой базы, нужны оба варианта запуска с повторами.

Малый масштаб. Scale 1 — это одна строка в pgbench_branches и десять в pgbench_tellers: 16 клиентов обновляют одни и те же строки и ждут друг друга. 109–114 tx/s против 796–981 при scale 75 — разница примерно в восемь раз (865 в среднем против 110), и это не мощность сервера, а блокировка строки. Диагноз виден по среднему 141–147 мс при том же числе клиентов.

Coordinated omission: пауза, которая не попадает в среднее

Закрытая модель теряет данные о паузе: пока сервер стоит, клиенты заблокированы и новых запросов не присылают. Те запросы, которые пользователь успел бы прислать за эти секунды, в статистике не появляются. Это называют coordinated omission. Открытая модель их планирует заранее, и pgbench в режиме --rate считает латентность от запланированного старта:

				thread->throttle_trigger +=
					getPoissonRand(&thread->ts_throttle_rs, throttle_delay);
				st->txn_scheduled = thread->throttle_trigger;

Расписание движется по throttle_trigger, который сдвигается на пуассоновский интервал независимо от того, закончилась ли предыдущая транзакция (строки 3777–3779).

		/* compute latency & lag */
		latency = (*now) - st->txn_scheduled;
		lag = st->txn_begin - st->txn_scheduled;

Латентность в итоге и в логе — now − txn_scheduled, а не now − txn_begin; задержка расписания — их разность (строки 4752–4754). Документация говорит то же: при --rate латентность включает время ожидания предыдущей транзакции.

Пауза воспроизводится блокировкой, в которой каждая транзакция упирается в pgbench_branches:

docker exec dba-bench psql -U postgres -c "BEGIN; LOCK TABLE pgbench_branches IN ACCESS EXCLUSIVE MODE; SELECT pg_sleep(5); COMMIT;"

Команду запускали на 20-й секунде 60-секундного прогона. Три варианта, по три повтора, медианы (в скобках минимум и максимум):

Закрытая модель получила пятисекундную паузу и осталась со средним 18,9 мс — таким же, как у прогона без паузы (16,3–20,1). Максимум 5055 мс виден, но это 16–35 транзакций из 50 тысяч: на p99 они не влияют. Открытая модель за те же 5 секунд накопила расписание, по которому транзакции опоздали: p99 вырос до 4,8 с, среднее до 670 мс.

С -L 100 картина снова спрятана: p99 137 мс, среднее 30 мс. Пауза ушла в skipped (11–13 % расписания) и в разброс: latency stddev вырос до 125–129 мс, у двухминутных прогонов на 60 % без паузы он был 22–30 мс. Вывод в отчёт: цифры латентности с -L приводятся только с процентом пропущенных.

вывод (открытая модель без -L, первый повтор):

latency average = 670.464 ms
latency stddev = 1225.437 ms
rate limit schedule lag: avg 647.037 (max 5006.399) ms

Свой профиль нагрузки, TPC и HammerDB

Встроенный сценарий TPC-B-подобен и мало похож на нагрузку приложения. Запросы для воспроизведения берут из pg_stat_statements (разбор), каждому дают скрипт и вес @N в одном запуске:

pgbench -U postgres -n -c 16 -j 4 -T 30 -f /tmp/read.sql@9 -f /tmp/write.sql@1 postgres

вывод:

latency average = 1.604 ms
tps = 9974.710865 (without initial connection time)
SQL script 1: /tmp/read.sql
 - latency average = 0.072 ms
SQL script 2: /tmp/write.sql
 - latency average = 15.702 ms

Общее среднее 1,6 мс скрывает запись на 15,7 мс: сводную строку нельзя читать без разбивки по скриптам. Скрипты:

-- read.sql
\set aid random(1, 100000 * :scale)
SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
-- write.sql
\set aid random(1, 100000 * :scale)
UPDATE pgbench_accounts SET abalance = abalance + 1 WHERE aid = :aid;

TPC-C и TPC-H — стандартизованные тесты: первый моделирует учётную систему оптового поставщика и измеряется в tpmC, второй — набор аналитических запросов (decision support) с параллельными изменениями данных (TPC-C, TPC-H). Их результат определён спецификацией, схемой, масштабом и правилами отчётности, поэтому число со своего стенда не равно опубликованному и не переносится на твою нагрузку. HammerDB реализует нагрузки TPROC-C и TPROC-H, «derived from» TPC-C и TPC-H, как называет их его документация: это готовый генератор, а не сертифицированный результат.

Что из этого следует

• Нагрузку задают темпом (--rate), а не числом клиентов. Число клиентов определяет среднее в закрытой модели через клиенты / TPS.
• Прогон длиннее интервала checkpoint_timeout и с несколькими повторами: у двухминутных прогонов были ровно два checkpoint и максимум около секунды, у десятисекундных — ноль или один и максимум в разы меньше.
• В отчёте — p50, p95, p99, максимум и доля пропущенных, а не одно среднее. На 60 % нагрузки p99 был в 7,5 раза выше p50.
• Масштаб данных называют вместе с тем, что он превышает: здесь 1129 МБ больше shared_buffers, но меньше памяти контейнера.
• Пауза сервера проверяется отдельным прогоном: если она не видна в p99, нагрузка не открытая или данные урезаны.

Чек-лист

Перед тем как показывать число:

1. Прогрев отброшен, длительность охватывает несколько checkpoint, повторов не меньше трёх, разброс показан.
2. Темп задан --rate, -L указан вместе с долей пропущенных.
3. Масштаб больше shared_buffers, и написано, влезает ли база в кэш ядра.
4. Перцентили посчитаны по логу -l, а не взяты из среднего.
5. Для приложения использован профиль из pg_stat_statements, а не встроенный TPC-B.

Контейнер и его том убирают одной командой: docker rm -f -v dba-bench.