Найти в Дзене
Postgres DBA

"[Patroni heartbeat] ERROR: canceling statement due to statement timeout" на тестовом стенде

Воспроизведение ошибки тайм-аута Patroni: изменение statement_timeout через исходный код
В данном отчете представлен эксперимент по воспроизведению комбинации ошибок «Exception when called state_handler.last_operation()» и «ОШИБКА: выполнение оператора отменено из-за тайм-аута» на тестовом стенде с PostgreSQL 17.6 и Patroni 4.0.6. Поскольку Patroni задаёт параметр statement_timeout
Оглавление

Воспроизведение ошибки тайм-аута Patroni: изменение statement_timeout через исходный код

Строка подключения решает всё.
Строка подключения решает всё.

В данном отчете представлен эксперимент по воспроизведению комбинации ошибок «Exception when called state_handler.last_operation()» и «ОШИБКА: выполнение оператора отменено из-за тайм-аута» на тестовом стенде с PostgreSQL 17.6 и Patroni 4.0.6. Поскольку Patroni задаёт параметр statement_timeout непосредственно в строке подключения через опцию -c, этот таймаут имеет наивысший приоритет и не переопределяется ни глобальными настройками PostgreSQL, ни параметрами в postgresql.parameters конфигурации Patroni. Единственным способом изменения таймаута является правка исходного кода Patroni (файл config.py), что и было выполнено в ходе работы для подтверждения условий возникновения ошибки под нагрузкой.

Начало и подготовка эксперимента

Задача

Воспроизвести ошибку "ОШИБКА:  выполнение оператора отменено из-за тайм-аута" на тестовом стенде .

Базовая конфигурация тестового стенда

Версия PostgreSQL

$ psql -c 'select version()'
version
----------------------------------------------------------------------------------------------
PostgreSQL 17.6 on x86_64-pc-linux-gnu, compiled by gcc (AstraLinuxSE 8.3.0-6) 8.3.0, 64-bit

Версия Patroni

$ patronictl version
patronictl version 4.0.6

CPU

$ lscpu
Architecture:        x86_64
CPU op-mode(s):      32-bit, 64-bit
Byte Order:          Little Endian
Address sizes:       40 bits physical, 48 bits virtual
CPU(s):              1
On-line CPU(s) list: 0
Thread(s) per core:  1
Core(s) per socket:  1
Socket(s):           1
NUMA node(s):        1
Vendor ID:           GenuineIntel
CPU family:          6
Model:               85
Model name:          Intel Xeon Processor (Skylake, IBRS, no TSX)
Stepping:            4
CPU MHz:             2693.660
BogoMIPS:            5387.32
Hypervisor vendor:   KVM
Virtualization type: full
L1d cache:           32K
L1i cache:           32K
L2 cache:            4096K
L3 cache:            16384K
NUMA node0 CPU(s):   0
Flags:               fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch cpuid_fault invpcid_single pti ibrs ibpb fsgsbase bmi1 avx2 smep bmi2 erms invpcid avx512f avx512dq rdseed adx smap clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 arat pku ospke

RAM

$ free -b | awk '/^Mem:/ {printf "%.2f GB\n", $2/1024/1024/1024}'
3.57 GB

IO

$ lsblk
NAME            MAJ:MIN RM  SIZE RO TYPE MOUNTPOINT
vda             252:0    0   70G  0 disk
├─vda1          252:1    0  976M  0 part /boot
└─vda2          252:2    0   69G  0 part
├─rootvg-root 253:0    0   20G  0 lvm  /
├─rootvg-opt  253:1    0    5G  0 lvm  /opt
├─rootvg-home 253:2    0    5G  0 lvm  /home
├─rootvg-tmp  253:3    0    5G  0 lvm  /tmp
├─rootvg-swap 253:4    0    1G  0 lvm  [SWAP]
└─rootvg-var  253:5    0   15G  0 lvm  /var

Конфигурация Patroni

$ patronictl show-config
failsafe_mode: true
ignore_slots:
- name: slot_receivewal_local
type: physical
- name: slot_receivewal
type: physical
loop_wait: 10
master_start_timeout: 300
master_stop_timeout: 300
maximum_lag_on_failover: 1048576
postgresql:
parameters:
max_connections: 1000
max_locks_per_transaction: 256
max_pred_locks_per_transaction: 256
max_prepared_transactions: 256
max_worker_processes: 8
shared_buffers: 16
track_commit_timestamp: false
wal_level: replica
wal_log_hints: true
use_pg_rewind: true
use_slots: true
retry_timeout: 110
synchronous_mode: true
synchronous_mode_strict: false
synchronous_node_count: 1
ttl: 240

PostgreSQL - statement_timeout

$ psql -c "SELECT name, setting, source FROM pg_settings WHERE name = 'statement_timeout'"
name | setting | source
-------------------+---------+--------------------
statement_timeout | 3600000 | configuration file

-2

План эксперимента

  1. Изменение параметра statement_timeout в config.py
  2. Контроль значения statement_timeout
  3. Мониторинг логов
  4. Создание нагрузки
  5. Контроль нагрузки в top

Ожидаемый результат:

Повторение ошибки "ОШИБКА:  выполнение оператора отменено из-за тайм-аута"

⚠️Почему нельзя изменить через параметры PostgreSQL или конфигурацию Patroni

  • Глобальные параметры PostgreSQL не работают, потому что Patroni задаёт statement_timeout непосредственно в строке подключения, и опции -c имеют наивысший приоритет.
-3

1.Изменение параметра statement_timeout в config.py

Порядок действий:

1. На каждом узле отредактировать файл config.py (новое значение statement_timeout).

2. На каждом узле перезапустить Patroni.

1. На каждом узле отредактировать файл config.py (новое значение statement_timeout)

1️⃣Узел ...n1

...n1:/usr/lib/python3/dist-packages/patroni/postgresql# cd /usr/lib/python3/dist-packages/patroni/postgresql/

...n1:/usr/lib/python3/dist-packages/patroni/postgresql# nano config.py

...n1:/usr/lib/python3/dist-packages/patroni/postgresql# cat config.py | grep statement_timeout

'options': '-c statement_timeout=8'

2️⃣Узел ...n2

...n2:/usr/lib/python3/dist-packages/patroni/postgresql# cd /usr/lib/python3/dist-packages/patroni/postgresql/

...n2:/usr/lib/python3/dist-packages/patroni/postgresql# nano config.py

...n2:/usr/lib/python3/dist-packages/patroni/postgresql# cat config.py | grep statement_timeout

'options': '-c statement_timeout=8'

patronictl list

Cluster: test
| ...n1 | ...n1 | Leader | running | 40 | |
| ..n2 | ...n2 | Sync Standby | streaming | 40 | 0 |

На реплике: рестарт Patroni -switchover

systemctl restart patroni
systemctl status patroni
patronictl switchover

На бывшем мастере: рестарт Patroni - switchover

systemctl restart patroni
systemctl status patroni
patronictl switchover

2.Контроль значения statement_timeout

patronictl show-config

psql -c "SELECT name, setting, source FROM pg_settings WHERE name = 'statement_timeout'"

$ patronictl show-config
failsafe_mode: true
ignore_slots:
- name: slot_receivewal_local
type: physical
- name: slot_receivewal
type: physical
loop_wait: 10
master_start_timeout: 300
master_stop_timeout: 300
maximum_lag_on_failover: 1048576
postgresql:
parameters:
max_connections: 1000
max_locks_per_transaction: 256
max_pred_locks_per_transaction: 256
max_prepared_transactions: 256
max_worker_processes: 8
shared_buffers: 16
track_commit_timestamp: false
wal_level: replica
wal_log_hints: true
use_pg_rewind: true
use_slots: true
retry_timeout: 110
synchronous_mode: true
synchronous_mode_strict: false
synchronous_node_count: 1
ttl: 240
$ psql -c "SELECT name, setting, source FROM pg_settings WHERE name = 'statement_timeout'"
name | setting | source
-------------------+---------+--------------------
statement_timeout | 3600000 | configuration file
(1 row)

3.Мониторинг логов

tail -f /log/patroni/patroni.log | grep "ERROR"

tail -f ...postgresql.log | grep "Patroni" | grep "ERROR"

4.Создание нагрузки

1️⃣pgbench -i -s 100 --foreign-keys bench

pgbench -c 100 -j 4 -T 600 bench

2️⃣pgbench -i -s 100 --foreign-keys bench2

pgbench -c 100 -j 4 -T 600 bench2

3️⃣pgbench -i -s 100 --foreign-keys bench3

pgbench -c 100 -j 4 -T 600 bench3

4️⃣pgbench -i -s 100 --foreign-keys bench4

pgbench -c 100 -j 4 -T 600 bench4

5. Контроль нагрузки в top

top - 11:24:29 up 135 days, 23:28, 15 users,  load average: 2.58, 2.65, 4.33

Tasks: 193 total,   3 running, 189 sleeping,   0 stopped,   1 zombie

%Cpu(s): 25.3 us, 26.7 sy,  0.0 ni,  0.0 id, 47.3 wa,  0.0 hi,  0.7 si,  0.0 st

MiB Mem :   3652.0 total,   2309.1 free,    452.3 used,    890.6 buff/cache

MiB Swap:   1024.0 total,    750.9 free,    273.1 used.   2808.6 avail Mem

Результат: "ОШИБКА:  выполнение оператора отменено из-за тайм-аута"

Patroni:

2026-03-22 10:56:12,639 ERROR: Exception when called state_handler.last_operation()

PostgreSQL:

2026-03-22 10:56:12 MSK [2911495]: [Patroni heartbeat] ERROR: canceling statement due to statement timeout

Итог

Параметр statement_timeout, заданный в строке подключения Patroni к локальному PostgreSQL, определяет максимальное время выполнения SQL-запросов, инициируемых Patroni. По умолчанию он равен 2000 мс (2 секунды). Это защитный механизм, предотвращающий зависание Patroni из‑за долгих операций.

⚠️Важно: значение statement_timeout передаётся через опцию командной строки -c statement_timeout=2000 в момент установки соединения. Такая опция имеет наивысший приоритет и переопределяет любые глобальные настройки PostgreSQL (как в postgresql.conf, так и установленные через ALTER SYSTEM). Поэтому изменение параметров PostgreSQL не влияет на поведение Patroni.

⚠️Единственный способ изменить этот таймаут – модифицировать исходный код Patroni.

Послесловие

Таким образом, в ходе эксперимента удалось успешно воспроизвести целевое сочетание ошибок, подтвердив, что тайм-аут выполнения операторов Patroni определяется исключительно значением, переданным через строку подключения, и не может быть изменён стандартными средствами настройки PostgreSQL или Patroni. Единственным рабочим способом коррекции этого параметра остаётся прямое изменение исходного кода, что следует учитывать при эксплуатации кластеров под управлением Patroni и планировании отладки подобных инцидентов.

P.S. Выводы для проблемы продуктивного кластера Patroni:

1. Непосредственная причина (механизм возникновения ошибки).

Превышение значения statement_timeout=2000, заданного в options='-c statement_timeout=2000'.

 Когда время выполнения heartbeat-запроса Patroni становится больше 2 секунд, PostgreSQL принудительно отменяет его и выдаёт сообщение canceling statement due to statement timeout.

2. Предпосылка (условие, создающее ситуацию для срабатывания механизма)

Периодический рост нагрузки на СУБД.

 ⚠️Именно из-за повышенной нагрузки (блокировок, высокой задержки I/O, конкуренции за ресурсы) простой запрос Patroni начинает выполняться дольше обычного и «врезается» в установленный лимит в 2 секунды.