Недавно я опубликовал статью про генератор демобазы 2.0 от PostgresPro. Как я там писал — у этой системы большой потенциал. Например, можно посмотреть что происходит внутри базы во время генерации (т. е. когда добавляются данные в таблицы).
Вот это как раз я и сделал — запустил генерацию и стал лазить по статистическим представлениям PostgreSQL со страницы про систему накопительной статистики, т. е. в те представления, которые начинают на pg_stat_*.
Оглавление:
- Цель экспериментов
- Список использованных статистических представлений
- Описание эксперимента
- Установка параметров на уровне кластера
- Первый эксперимент (gen.max_hops = 1)
- Второй эксперимент (gen.max_hops = 10)
- Смотрим на статистику
- Краткий итог
Цель экспериментов
Цель всех этих экспериментов — просто посмотреть на эти представления. Поэтому цифр получилось очень много! Если цель будет более конкретной, то, конечно, можно будет более точно написать необходимые мониторинговые скрипты для тестов.
Я эти тесты гонял около трёх недель, с разными параметрами генератора, с разными параметрами сервера. Сил обо всём рассказать у меня уже нет. Но самое интересное постараюсь показать.
Запросы, которые используются в этой статье, я тоже немного менял в течение этих трёх недель. Что-то добавлял, что-то удалял. Но, так как цель у меня была — просто посмотреть на сами представления на более-менее реальной нагрузке — то я своей цели достиг.
Ниже представлен результат одного прогона. Но я выполнял по три прогона для каждого из параметров чтобы исключить неожиданные всплески (а они действительно были).
Важный момент — в код генератора я ещё не смотрел, так что все мысли ниже — просто мысли основанные на полученных статистических данных.
Статистических данных очень много, обо всём рассказать не получится. А некоторые запланированные эксперименты провести не получилось. Например, я хотел смотреть в pg_stat_user_functions при генерации — но этот вариант «отвалился» потому что это представление показывает выполнение подпрограмм для текущей сессии, а генератор запускает генерацию в параллельных сессиях.
Список использованных статистических представлений
После разных экспериментов я остановился на следующих представлениях:
Описание эксперимента
Дважды запускаю генерацию демобазы для одного и того же объема данных — на месяц. Но при этом меняю значение параметра gen.max_hops:
Максимальное количество пересадок в одном билете.
Значение по умолчанию: 4.
Примечание
Чем больше значение, тем больше вероятность, что пассажир сумеет воспользоваться авиакомпанией, чтобы добраться до желаемого пункта.
- Первый эксперимент: gen.max_hops = 1;
- Второй эксперимент: gen.max_hops = 10.
Логика у меня была такой — в первом случае генератор должен справиться быстрее, т. к. ему, можно сказать, не нужно будет формировать пересадки. А во втором случае придётся поработать в поисках необходимого количества пересадок.
Я сравнивал ещё с одним параметром — gen.domestic_frac. Опытным путём выяснено что у max_hops нагрузка всё-таки побольше за счёт чтения бо́льшего количества страниц.
Установка параметров на уровне кластера
В какой-то момент я немного запутался с параметрами, так что предлагаю сразу заглянуть в файл postgresql.auto.conf чтобы понять что уже установлено, а что — ещё нет. Сделать это можно SQL-запросом:
SELECT pg_read_file(‘postgresql.auto.conf’);
А тут можно подробнее почитать про команды для просмотра конфигурационных файлов и параметров в PostgreSQL.
Итак, устанавливаем следующие параметры:
ALTER SYSTEM SET shared_preload_libraries = 'pg_stat_statements'; ALTER SYSTEM SET pg_stat_statements.track = 'all'; ALTER SYSTEM SET track_io_timing = on; ALTER SYSTEM SET track_functions = 'all'; ALTER SYSTEM SET shared_buffers = '64 MB';
- shared_preload_libraries = ‘pg_stat_statements‘ — чтобы заработало это расширение;
- pg_stat_statements.track = ‘all’ — чтобы отслеживались не только верхнеуровневые операторы, но и вложенные;
- track_io_timing = on — так включим замер времени ожидания ввода-вывода;
- track_functions = ‘all’ — а так включим подсчёт вызовов функций и времени их выполнения на всех языках (ну нам нужен SQL);
- shared_buffers = ’64 MB’ — решил уменьшить чтобы посмотреть на показатели работы с общей памятью.
После этого нужно перезагрузить сервер:
sudo systemctl restart postgresql@18-main.service
Первый эксперимент (gen.max_hops = 1)
Далее в едином блоке кода вывод самого эксперимента. В его рамках я полностью удаляю демобазу для чистоты эксперимента, устанавливаю параметр gen.max_hops, сбрасываю необходимые статистики и запускаю генерацию на месяц. Напомню что посмотреть как устанавливать демобазу можно в прошлой статье: Генератор демобазы 2.0 от PostgresPro. Далее обращаюсь к статистическим представлениям и вывожу информацию из них:
DROP DATABASE demo;
DROP DATABASE
\i install.sql
SET gen.max_hops = 1;
SET
CREATE EXTENSION pg_stat_statements;
CREATE EXTENSION
SELECT pg_stat_reset();
SELECT pg_stat_statements_reset();
SELECT pg_stat_reset_shared('io');
SELECT pg_stat_reset_shared('bgwriter');
SELECT pg_stat_reset_shared('checkpointer');
SELECT blks_hit, blks_read FROM pg_stat_database WHERE datname = 'demo';
-- CALL generate( now(), now() + interval '1 month', 12 );
SELECT busy();
busy
------
f
(1 row)
# SELECT
pid,
usename,
application_name,
state,
now() - query_start AS query_age,
query
FROM pg_stat_activity
WHERE pid <> pg_backend_pid()
AND state <> 'idle'
ORDER BY xact_start NULLS LAST;
pid | usename | application_name | state | query_age | query
--------+----------+--------------------+--------+-----------------+-----------------------------------------------------
684759 | postgres | Airlines processor | active | 00:01:02.264364 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684768 | postgres | Airlines processor | active | 00:01:02.237406 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684765 | postgres | Airlines processor | active | 00:01:02.246208 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684763 | postgres | Airlines processor | active | 00:01:02.251437 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684770 | postgres | Airlines processor | active | 00:01:02.232489 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684769 | postgres | Airlines processor | active | 00:01:02.234888 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684760 | postgres | Airlines processor | active | 00:01:02.260956 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684767 | postgres | Airlines processor | active | 00:01:02.24025 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684764 | postgres | Airlines processor | active | 00:01:02.248801 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684761 | postgres | Airlines processor | active | 00:01:02.257462 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684766 | postgres | Airlines processor | active | 00:01:02.243765 | CALL process_queue('2026-11-19 19:47:16.866911+00')
684762 | postgres | Airlines processor | active | 00:01:02.254279 | CALL process_queue('2026-11-19 19:47:16.866911+00')
(12 rows)
# \dt+
List of tables
Schema | Name | Type | Owner | Persistence | Access method | Size | Description
----------+-----------------+-------+-------+-------------+---------------+---------+----------------------------------------
bookings | airplanes_data | table | pavel | unlogged | heap | 56 kB | Airplanes (internal multilingual data)
bookings | airports_data | table | pavel | unlogged | heap | 1288 kB | Airports (internal multilingual data)
bookings | boarding_passes | table | pavel | unlogged | heap | 1824 kB | Boarding passes
bookings | bookings | table | pavel | unlogged | heap | 25 MB | Bookings
bookings | flights | table | pavel | unlogged | heap | 752 kB | Flights
bookings | routes | table | pavel | unlogged | heap | 128 kB | Routes
bookings | seats | table | pavel | unlogged | heap | 128 kB | Seats
bookings | segments | table | pavel | unlogged | heap | 95 MB | Flight segment (leg)
bookings | tickets | table | pavel | unlogged | heap | 84 MB | Tickets
(9 rows)
# SELECT
calls,
round(total_exec_time::numeric, 2) AS total_ms,
round((total_exec_time / NULLIF(calls, 0))::numeric, 2) AS avg_ms_per_call,
round(
((total_exec_time - shared_blk_read_time - shared_blk_write_time) / NULLIF(calls, 0))::numeric,
2
) AS estimated_non_disk_ms,
round((shared_blks_read::numeric / NULLIF(calls, 0)), 2) AS avg_blks_read,
round((shared_blks_hit::numeric / NULLIF(calls, 0)), 2) AS avg_blks_hit,
round(100.0 * shared_blks_hit / nullif(shared_blks_hit + shared_blks_read, 0), 2) AS hit_ratio_pct,
left(query, 100) AS query
FROM pg_stat_statements
WHERE dbid = (SELECT oid FROM pg_database WHERE datname = 'demo')
AND (
query ILIKE 'CALL process_queue%'
OR query ILIKE 'CALL process_event%'
OR query ILIKE 'CALL make_booking%'
OR query ILIKE 'CALL create_segment%'
OR query ILIKE 'CALL open_booking%'
)
ORDER BY total_exec_time DESC;
calls | total_ms | avg_ms_per_call | estimated_non_disk_ms | avg_blks_read | avg_blks_hit | hit_ratio_pct | query
--------+------------+-----------------+-----------------------+---------------+--------------+---------------+--------------------------------------------------
12 | 4525470.45 | 377122.54 | 373069.91 | 431027.25 | 106886220.83 | 99.60 | CALL process_queue($1)
536705 | 4323964.56 | 8.06 | 7.97 | 9.60 | 1959.60 | 99.51 | CALL process_event(evt, end_date)
502464 | 4245411.23 | 8.45 | 8.35 | 10.02 | 2085.42 | 99.52 | CALL make_booking(evt)
903700 | 1102075.81 | 1.22 | 1.20 | 2.80 | 159.08 | 98.27 | CALL create_segment(outb_ticket_no, l_flight_id)
560543 | 633054.34 | 1.13 | 1.11 | 2.68 | 125.55 | 97.91 | CALL create_segment(inb_ticket_no, l_flight_id)
10336 | 5207.34 | 0.50 | 0.49 | 0.78 | 37.43 | 97.95 | CALL open_booking(evt)
(6 rows)
# SELECT
backend_type,
object,
context,
writes,
evictions,
round(write_time::numeric, 2) AS total_write_ms,
round((write_time / NULLIF(writes, 0))::numeric, 4) AS avg_write_ms
FROM pg_stat_io
WHERE backend_type = 'client backend'
AND object = 'relation'
AND context = 'normal';
backend_type | object | context | writes | evictions | total_write_ms | avg_write_ms
----------------+----------+---------+---------+-----------+----------------+--------------
client backend | relation | normal | 1065435 | 5208316 | 9794.68 | 0.0092
(1 row)
# SELECT
datname,
blks_hit,
blks_read,
round(100.0 * blks_hit / nullif(blks_hit + blks_read, 0), 2) AS hit_ratio_pct,
tup_inserted,
tup_updated,
tup_deleted,
parallel_workers_launched
FROM pg_stat_database
WHERE datname = 'demo';
datname | blks_hit | blks_read | hit_ratio_pct | tup_inserted | tup_updated | tup_deleted | parallel_workers_launched
---------+------------+-----------+---------------+--------------+-------------+-------------+---------------------------
demo | 1282917328 | 5429602 | 99.58 | 4759086 | 4980813 | 536950 | 0
(1 row)
# SELECT
bg.buffers_clean,
bg.maxwritten_clean,
bg.buffers_alloc
FROM pg_stat_bgwriter bg;
buffers_clean | maxwritten_clean | buffers_alloc
---------------+------------------+---------------
160192 | 1528 | 5226034
(1 row)
Второй эксперимент (gen.max_hops = 10)
Это полностью аналогичный эксперимент, кроме того что устанавливаю другое значение для gen.max_hops:
DROP DATABASE demo;
DROP DATABASE
\i install.sql
SET gen.max_hops = 10;
SET
CREATE EXTENSION pg_stat_statements;
CREATE EXTENSION
SELECT pg_stat_reset();
SELECT pg_stat_statements_reset();
SELECT pg_stat_reset_shared('io');
SELECT pg_stat_reset_shared('bgwriter');
SELECT pg_stat_reset_shared('checkpointer');
SELECT blks_hit, blks_read FROM pg_stat_database WHERE datname = 'demo';
-- CALL generate( now(), now() + interval '1 month', 12 );
SELECT busy();
busy
------
f
(1 row)
# SELECT
pid,
usename,
application_name,
state,
now() - query_start AS query_age,
query
FROM pg_stat_activity
WHERE pid <> pg_backend_pid()
AND state <> 'idle'
ORDER BY xact_start NULLS LAST;
pid | usename | application_name | state | query_age | query
--------+----------+--------------------+--------+-----------------+-----------------------------------------------------
690665 | postgres | Airlines processor | active | 00:01:15.157955 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690667 | postgres | Airlines processor | active | 00:01:15.151948 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690669 | postgres | Airlines processor | active | 00:01:15.147086 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690670 | postgres | Airlines processor | active | 00:01:15.144867 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690671 | postgres | Airlines processor | active | 00:01:15.142055 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690668 | postgres | Airlines processor | active | 00:01:15.149714 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690662 | postgres | Airlines processor | active | 00:01:15.168773 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690663 | postgres | Airlines processor | active | 00:01:15.164831 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690672 | postgres | Airlines processor | active | 00:01:15.138989 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690664 | postgres | Airlines processor | active | 00:01:15.161313 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690673 | postgres | Airlines processor | active | 00:01:15.13568 | CALL process_queue('2026-11-19 19:55:08.363197+00')
690666 | postgres | Airlines processor | active | 00:01:15.154828 | CALL process_queue('2026-11-19 19:55:08.363197+00')
(12 rows)
# \dt+
List of tables
Schema | Name | Type | Owner | Persistence | Access method | Size | Description
----------+-----------------+-------+-------+-------------+---------------+---------+----------------------------------------
bookings | airplanes_data | table | pavel | unlogged | heap | 56 kB | Airplanes (internal multilingual data)
bookings | airports_data | table | pavel | unlogged | heap | 1288 kB | Airports (internal multilingual data)
bookings | boarding_passes | table | pavel | unlogged | heap | 1592 kB | Boarding passes
bookings | bookings | table | pavel | unlogged | heap | 26 MB | Bookings
bookings | flights | table | pavel | unlogged | heap | 792 kB | Flights
bookings | routes | table | pavel | unlogged | heap | 128 kB | Routes
bookings | seats | table | pavel | unlogged | heap | 128 kB | Seats
bookings | segments | table | pavel | unlogged | heap | 95 MB | Flight segment (leg)
bookings | tickets | table | pavel | unlogged | heap | 88 MB | Tickets
(9 rows)
# SELECT
calls,
round(total_exec_time::numeric, 2) AS total_ms,
round((total_exec_time / NULLIF(calls, 0))::numeric, 2) AS avg_ms_per_call,
round(
((total_exec_time - shared_blk_read_time - shared_blk_write_time) / NULLIF(calls, 0))::numeric,
2
) AS estimated_non_disk_ms,
round((shared_blks_read::numeric / NULLIF(calls, 0)), 2) AS avg_blks_read,
round((shared_blks_hit::numeric / NULLIF(calls, 0)), 2) AS avg_blks_hit,
round(100.0 * shared_blks_hit / nullif(shared_blks_hit + shared_blks_read, 0), 2) AS hit_ratio_pct,
left(query, 100) AS query
FROM pg_stat_statements
WHERE dbid = (SELECT oid FROM pg_database WHERE datname = 'demo')
AND (
query ILIKE 'CALL process_queue%'
OR query ILIKE 'CALL process_event%'
OR query ILIKE 'CALL make_booking%'
OR query ILIKE 'CALL create_segment%'
OR query ILIKE 'CALL open_booking%'
)
ORDER BY total_exec_time DESC;
calls | total_ms | avg_ms_per_call | estimated_non_disk_ms | avg_blks_read | avg_blks_hit | hit_ratio_pct | query
--------+------------+-----------------+-----------------------+---------------+--------------+---------------+--------------------------------------------------
12 | 4595791.93 | 382982.66 | 378714.92 | 457169.25 | 109547285.00 | 99.58 | CALL process_queue($1)
534823 | 4395921.28 | 8.22 | 8.12 | 10.22 | 2034.89 | 99.50 | CALL process_event(evt, end_date)
502947 | 4321412.10 | 8.59 | 8.49 | 10.63 | 2157.37 | 99.51 | CALL make_booking(evt)
893595 | 1102631.65 | 1.23 | 1.21 | 2.89 | 158.32 | 98.21 | CALL create_segment(outb_ticket_no, l_flight_id)
571720 | 659993.99 | 1.15 | 1.13 | 3.05 | 126.88 | 97.65 | CALL create_segment(inb_ticket_no, l_flight_id)
10764 | 5385.44 | 0.50 | 0.49 | 0.78 | 37.36 | 97.95 | CALL open_booking(evt)
(6 rows)
# SELECT
backend_type,
object,
context,
writes,
evictions,
round(write_time::numeric, 2) AS total_write_ms,
round((write_time / NULLIF(writes, 0))::numeric, 4) AS avg_write_ms
FROM pg_stat_io
WHERE backend_type = 'client backend'
AND object = 'relation'
AND context = 'normal';
backend_type | object | context | writes | evictions | total_write_ms | avg_write_ms
----------------+----------+---------+---------+-----------+----------------+--------------
client backend | relation | normal | 1096397 | 5522555 | 10107.72 | 0.0092
(1 row)
# SELECT
datname,
blks_hit,
blks_read,
round(100.0 * blks_hit / nullif(blks_hit + blks_read, 0), 2) AS hit_ratio_pct,
tup_inserted,
tup_updated,
tup_deleted,
parallel_workers_launched
FROM pg_stat_database
WHERE datname = 'demo';
datname | blks_hit | blks_read | hit_ratio_pct | tup_inserted | tup_updated | tup_deleted | parallel_workers_launched
---------+------------+-----------+---------------+--------------+-------------+-------------+---------------------------
demo | 1314847453 | 5747185 | 99.56 | 4819884 | 4989654 | 535069 | 0
(1 row)
# SELECT
bg.buffers_clean AS bgwriter_cleaned_buffers,
bg.maxwritten_clean,
bg.buffers_alloc
FROM pg_stat_bgwriter bg;
bgwriter_cleaned_buffers | maxwritten_clean | buffers_alloc
--------------------------+------------------+---------------
162755 | 1543 | 5540101
(1 row)
Смотрим на статистику
pg_stat_activity
Сразу напомню что запросы к pg_stat_activity надо выполнять пока есть нагрузка, т. к. после окончания генерации процессы перейдут в состояние idle и ничего не будут делать. Их можно «прибить» выполнив функцию abort:
CALL abort();
После этого все процессы имеющие application_name = Airlines processor будут завершены.
pg_stat_statements
Тут посмотрим на значение для верхнеуровневых процедур для процессов process_queue:
- total_exec_time — общее время, затраченное на выполнение оператора, в миллисекундах
- calls — число выполнений
Тут можно увидеть что эта процедура process_queue была выполнена 12 раз, это ровно то количество параллельных процессов, которые я и запустил.
А по времени total_exec_time:
Показатель | Значение ----------------------+------------- Было (max_hops = 1) | 4 525 470,45 Стало (max_hops = 10) | 4 595 791,93 Разница | +70 321,48
Видно что второй эксперимент выполнялся дольше.
pg_stat_database
Тут по одной строке на каждую базу данных. Тоже куча важной и полезной информации, но уже на уровне всей базы данных в целом.
Здесь мы посмотрим на параметр вычисляемое значение которое можно назвать hit_ratio_pct — процент попаданий в кеш (shared_buffers) при чтениях. Т.е. отношение суммарных чтений из буферного кеша к сумме всех чтений в этой базе данных. А если попроще, то этот показатель покажет хватает ли нам выделенной оперативной памяти для нашей текущей нагрузки:
Показатель | Значение ----------------------+--------- Было (max_hops = 1) | 99,58 Стало (max_hops = 10) | 99,56 Разница | -0,02
А вот серьезного отличия в попадании в кеш я не обнаружил в своих экспериментах.
pg_stat_io
Очень много интересного из этого представления можно узнать (как вариант, когда-нибудь в будущем потестирую io_uring). Но цифр слишком много, так что я оставил только работу обслуживающих процессов (backend_type = ‘client backend’) для постоянных таблиц (object = ‘relation’) и стандартного контекста операций ввода-вывода (context = ‘normal’).
А посмотрим мы на значение writes — количество операций записи:
Показатель | Значение ----------------------+---------- Стало (max_hops = 1) | 1 065 435 Стало (max_hops = 10) | 1 096 397 Разница | +30 962
Видно что во втором эксперименте обслуживающим процессам пришлось потрудиться побольше.
pg_stat_bgwriter
И тут тоже много интересного было но, в итоге, я оставил только три числа здесь. А посмотреть предлагаю на buffers_clean — количество буферов, записанных фоновым процессом записи:
Показатель | Значение ----------------------+--------- Стало (max_hops = 1) | 160 192 Стало (max_hops = 10) | 162 755 Разница | +2 563
Ну и процессу фоновой записи тоже пришлось поднапрячься чуть больше второй раз.
На последние два представления я бы предложил посмотреть чуть внимательнее. Моя глобальная идея тут была такой — если не вдаваться в очень важные детали (!), то можно грубо посчитать что pg_stat_io.writes — это, без учёта extends, сколько раз обслуживающим процессам пришлось самостоятельно сбросить грязные страницы на диск (т. е. процесс фоновой записи не успел этого сделать). А pg_stat_bgwriter.buffers_clean — сколько страниц записал процесс фоновой записи.
Для текущих настроек видно что процесс фоновой записи максимально нагружен и не успевает очищать страницы. Явно можно тут поиграть с параметрами.
Краткий итог
Ниже — мои мысли которые я надумал проводя эксперименты и анализируя полученные результаты.
Так как я с этими экспериментами и цифрами уже три недели, то данный вывод основан именно на этих неделях, а не на результатах одного эксперимента выше.
Изменение параметров генератора (gen.max_hops от 1 до 10, gen.domestic_frac от 0.01 до 0.99) не привносят какого-то усложнения в расчёты.
Однако, если увеличить gen.max_hops до 10 — то postgres начинает больше обрабатывать страниц в памяти (рост pg_stat_statements.shared_blks_hit, я это тут не рассматривал). Эти страницы надо обрабатывать, поэтому-то процессор больше времени на это тратит, а не на сложные вычисления.
А вот изменение gen.domestic_frac от 0.01 до 0.99 не даёт такого результата, там рост чтений небольшой.
Но, повторюсь, цель всех этих экспериментов была в том чтобы посмотреть статистические представления, «потрогать» их руками на примере генератора демобазы. Мне было интересно и, надеюсь, полезно.
Leave a Reply