canceling statement due to conflict with recovery - długie zapytania na replice są przerywane

PostgreSQL

canceling statement due to conflict with recovery - długie zapytania na replice są przerywane

W skrócie

Ten problem dotyczy replik hot standby, czyli serwerów zapasowych otwartych do odczytu, na które przenosisz raporty i analizy, żeby odciążyć primary. Krótkie zapytania działają bez zarzutu, a dłuższe co jakiś czas kończą się błędem, który aplikacja zgłasza jak awarię. Odtworzyliśmy ten błąd na PostgreSQL 16. Pokażemy, skąd się bierze, jak potwierdzić przyczynę w statystykach repliki i jak dobrać ustawienie do roli, jaką replika pełni.

Jak to wygląda w praktyce

Zapytanie raportowe na replice przez chwilę działa, po czym zostaje przerwane:

shop=# SELECT count(*), pg_sleep(30) FROM orders;
ERROR:  canceling statement due to conflict with recovery
DETAIL:  User query might have needed to see row versions that must be removed.

W tym samym czasie na primary ktoś usuwał lub zmieniał wiersze tej tabeli, a VACUUM (ręczny albo autovacuum) sprzątnął ich stare wersje. Błąd ma kod SQLSTATE 40001 (serialization_failure), który zobaczysz po \set VERBOSITY verbose w psql. Gdy na replice włączysz log_recovery_conflict_waits, log pokaże, że odtwarzanie czekało na Twoje zapytanie, a po limicie je przerwało:

LOG:  recovery still waiting after 1024.560 ms: recovery conflict on snapshot
DETAIL:  Conflicting process: 1023805.
ERROR:  canceling statement due to conflict with recovery
LOG:  recovery finished waiting after 5031.266 ms: recovery conflict on snapshot

Zobacz też: Szkolenie Zaawansowana administracja PostgreSQL: High Availability, Disaster Recovery

Dlaczego tak się dzieje

Replika fizyczna jest kopią primary blok po bloku i odtwarza WAL, czyli dziennik zmian, jednym procesem. Gdy VACUUM na primary usuwa martwe wersje wierszy, do WAL trafia rekord czyszczenia, który replika musi odtworzyć. Jeśli na replice trwa zapytanie z migawką (snapshot, czyli obrazem danych z chwili startu zapytania), która nadal widzi te wersje, powstaje konflikt. Replika czeka najwyżej tyle, ile wynosi max_standby_streaming_delay (domyślnie 30 s, w naszym teście 5 s), licząc od odebrania danych WAL, a potem przerywa zapytanie, żeby nie zostawać w tyle. Gdy replika już odstaje po wcześniejszym konflikcie, kolejne zapytania mają mniej czasu. Primary nie wie o zapytaniach na replice, bo hot_standby_feedback jest domyślnie wyłączony.

Dokumentacja PostgreSQL opisuje dwa wyjścia. Przy hot_standby_feedback = on replika co wal_receiver_status_interval (domyślnie 10 s) przekazuje primary informację o najstarszej aktywnej transakcji, a VACUUM zostawia wiersze, których ona potrzebuje. Kosztem jest bloat, czyli puchnięcie tabel na primary, dopóki długie zapytanie trwa. Drugie wyjście to większy max_standby_streaming_delay albo -1 (czekanie bez limitu), ale wtedy replika na czas zapytania wstrzymuje odtwarzanie i odstaje od primary. Dokumentacja zaleca niskie wartości dla repliki pełniącej rolę wysokiej dostępności, a dla repliki raportowej dopuszcza wartości liczone w godzinach. Oba parametry mają kontekst sighup, więc zmieniasz je na replice i robisz reload.

Jak to rozwiązać krok po kroku

1. Potwierdź przyczynę na replice: SELECT datname, confl_snapshot, confl_lock, confl_bufferpin FROM pg_stat_database_conflicts;. Rosnące confl_snapshot oznacza konflikt z czyszczeniem wierszy, czyli ten przypadek. Wzrost w innej kolumnie to konflikt na blokadzie albo na przypiętym buforze, z innym komunikatem DETAIL.
2. Włącz na replice logowanie oczekiwań: ALTER SYSTEM SET log_recovery_conflict_waits = on; i SELECT pg_reload_conf();. Log pokaże każde czekanie dłuższe niż deadlock_timeout (domyślnie 1 s) razem z numerem procesu, który blokuje odtwarzanie.
3. Jeśli replika służy do raportów, włącz na niej ALTER SYSTEM SET hot_standby_feedback = on; i wykonaj SELECT pg_reload_conf();. W naszym teście restart nie był potrzebny.
4. Na primary sprawdź, że informacja zwrotna dociera: SELECT application_name, state, backend_xmin FROM pg_stat_replication;. Kolumna backend_xmin przestaje być pusta po kilku do kilkunastu sekundach, bo informacja zwrotna nie jest wysyłana częściej niż co wal_receiver_status_interval.
5. Pilnuj kosztu. Na primary VACUUM (VERBOSE) orders wykonany w trakcie długiego zapytania na replice pokaże wiersze, których nie wolno jeszcze usunąć, u nas 50000 are dead but not yet removable. Jeśli raporty trwają godzinami na często zmienianych tabelach, rozważ osobną replikę raportową z wyłączonym feedbackiem i dużym max_standby_streaming_delay, której opóźnienie wobec primary jest dla Ciebie akceptowalne.
6. W aplikacji obsłuż kod 40001 ponowieniem zapytania. Ponowione zapytanie startuje z nową migawką danych.

Jak sprawdzić, że zadziałało

Powtórz scenariusz z włączonym feedbackiem: długie zapytanie na replice, a w tym czasie DELETE i VACUUM na primary. Zapytanie kończy się wynikiem, a licznik konfliktów się nie zmienia:

shop=# SELECT count(*), pg_sleep(20) FROM orders;
 count | pg_sleep
-------+----------
 50000 |
(1 row)

shop=# SELECT datname, confl_snapshot FROM pg_stat_database_conflicts WHERE datname = 'shop';
 datname | confl_snapshot
---------+----------------
 shop    |              1
(1 row)

Wartość 1 to konflikt sprzed zmiany, nowego nie było. Kilka sekund po zakończeniu zapytania na replice VACUUM na primary usunął już martwe wiersze (tuples: 50000 removed), czyli wstrzymanie czyszczenia trwało tylko tyle, ile zapytanie.

Powiązane problemy

• Gdy replika ma też inne kłopoty, zestaw widoków i logów do diagnozy znajdziesz w tekście częste problemy z replikacją i jak je diagnozować.
• Jeśli po wydłużeniu max_standby_streaming_delay replika zostaje w tyle, przejdź do tekstu standby nie nadąża za primary, czyli jak zmierzyć i zmniejszyć lag.
• Koszt hot_standby_feedback po stronie primary wyjaśniamy w tekście tabela puchnie mimo usuwania wierszy, czyli czym jest bloat.

Wróć do listy: 112 najczęstszych pytań i problemów z PostgreSQL