Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Ошибка при попытке выполнить полный бэкап #642

Open
konsmalakhov opened this issue Dec 18, 2024 · 6 comments
Open

Ошибка при попытке выполнить полный бэкап #642

konsmalakhov opened this issue Dec 18, 2024 · 6 comments

Comments

@konsmalakhov
Copy link

konsmalakhov commented Dec 18, 2024 •
edited
Loading

Добрый день.
При запуске полного бэкапа и который идёт дольше 10 минут, получаю ошибку в логе ниже, при этом же если бэкап идёт менее 10 минут то завершается без ошибок.

Guest OS Ubuntu 22.04.5 LTS
Backup VM pg_probackup-16 2.5.15 (PostgreSQL 16.2)
DB VM PostgreSQL 16.4

Postgresql.log

2024-12-18 12:48:55.354 MSK [2064846] WARNING:  aborting backup due to backend exiting before pg_backup_stop was called
2024-12-18 12:51:02.506 MSK [2064920] LOG:  unexpected EOF on standby connection
2024-12-18 12:51:02.506 MSK [2064920] STATEMENT:  START_REPLICATION 694/CF000000 TIMELINE 43

pg_probackup log

VERBOSE: (query) SET client_min_messages = warning;
ERROR: query failed: server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
query was: SET client_min_messages = warning;
WARNING: A backup is in progress, stopping it.
VERBOSE: (query) SET datestyle = 'ISO, DMY';
ERROR: query failed: no connection to the server
query was: SET datestyle = 'ISO, DMY';
VERBOSE: (query) SELECT pg_catalog.txid_snapshot_xmax(pg_catalog.txid_current_snapshot()), current_timestamp(0)::timestamptz, lsn, labelfile, spcmapfile FROM pg_catalog.pg_backup_stop(false)
WARNING: query failed: no connection to the server
query was: SELECT pg_catalog.txid_snapshot_xmax(pg_catalog.txid_current_snapshot()), current_timestamp(0)::timestamptz, lsn, labelfile, spcmapfile FROM pg_catalog.pg_backup_stop(false)
ERROR: Failed to send pg_backup_stop query
WARNING: Backup SOOO4S is running, setting its status to ERROR

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


# Backup instance information
pgdata = /data/patroni
system-identifier = 7410756962539012540
xlog-seg-size = 16777216
# Connection parameters
pgdatabase = backupdb
pghost = db.domain.com
pgport = 5434
pguser = backup
# Replica parameters
replica-timeout = 5min
# Archive parameters
archive-timeout = 5min
# Logging parameters
log-level-console = VERBOSE
log-level-file = LOG
log-format-console = PLAIN
log-format-file = PLAIN
log-filename = pg_probackup.log
log-directory = /backup/log
log-rotation-size = 0TB
log-rotation-age = 0d
# Retention parameters
retention-redundancy = 2
retention-window = 14
wal-depth = 3
# Compression parameters
compress-algorithm = zlib
compress-level = 6
# Remote access parameters
remote-proto = ssh
remote-host = db.domain.com
remote-port = 2303
remote-user = postgres
@fukanchik
Copy link

Здравствуйте, а что при это появляется в логе сервера postgres?

@konsmalakhov
Copy link
Author

Здравствуйте, а что при это появляется в логе сервера postgres?

2024-12-18 12:48:55.354 MSK [2064846] WARNING: aborting backup due to backend exiting before pg_backup_stop was called
2024-12-18 12:51:02.506 MSK [2064920] LOG: unexpected EOF on standby connection
2024-12-18 12:51:02.506 MSK [2064920] STATEMENT: START_REPLICATION 694/CF000000 TIMELINE 43

@fukanchik
Copy link

Попробуйте увеличить wal_sender_timeout https://www.postgresql.org/docs/current/runtime-config-replication.html#GUC-WAL-SENDER-TIMEOUT

@konsmalakhov
Copy link
Author

Попробуйте увеличить wal_sender_timeout https://www.postgresql.org/docs/current/runtime-config-replication.html#GUC-WAL-SENDER-TIMEOUT

Сделал wal_sender_timeout: 0
Ошибка та же

@dura0ok
Copy link

dura0ok commented Dec 24, 2024

А можете приложить полный лог, пожалуйста?

@konsmalakhov
Copy link
Author

konsmalakhov commented Dec 25, 2024 •
edited
Loading

А можете приложить полный лог, пожалуйста?

Добрый день.
Лог большой файл приатачить не могу, чуть больше выдержка ниже.

2024-12-20 16:46:24 MSK [16825]: LOG: File "/data/patroni/base/42537/16326222.1". Copied 339891435 bytes
2024-12-20 16:46:24 MSK [16825]: INFO: Progress: (5733/5750). Process file "base/42537/17280317.1"
2024-12-20 16:46:24 MSK [16825]: INFO: Progress: (5733/5750). Process file "base/42537/17280317.1"
2024-12-20 16:46:25 MSK [16825]: LOG: File "/data/patroni/base/42537/16326216.1". Copied 244643069 bytes
2024-12-20 16:46:25 MSK [16825]: INFO: Progress: (5734/5750). Process file "base/42537/16008862.1"
2024-12-20 16:46:25 MSK [16825]: INFO: Progress: (5734/5750). Process file "base/42537/16008862.1"
2024-12-20 16:46:32 MSK [16825]: LOG: File "/data/patroni/base/42537/15379353.1". Copied 244255566 bytes
2024-12-20 16:46:32 MSK [16825]: INFO: Progress: (5735/5750). Process file "base/42537/15379359"
2024-12-20 16:46:32 MSK [16825]: INFO: Progress: (5735/5750). Process file "base/42537/15379359"
2024-12-20 16:46:36 MSK [16825]: LOG: File "/data/patroni/base/42537/17280323.1". Copied 337003201 bytes
2024-12-20 16:46:36 MSK [16825]: INFO: Progress: (5736/5750). Process file "base/42537/15379359.1"
2024-12-20 16:46:36 MSK [16825]: INFO: Progress: (5736/5750). Process file "base/42537/15379359.1"
2024-12-20 16:46:42 MSK [16825]: LOG: File "/data/patroni/base/42537/16961374". Copied 356772534 bytes
2024-12-20 16:46:42 MSK [16825]: INFO: Progress: (5737/5750). Process file "base/42537/16008868"
2024-12-20 16:46:42 MSK [16825]: INFO: Progress: (5737/5750). Process file "base/42537/16008868"
2024-12-20 16:46:51 MSK [16825]: LOG: File "/data/patroni/base/42537/16326216". Copied 243592235 bytes
2024-12-20 16:46:51 MSK [16825]: INFO: Progress: (5738/5750). Process file "base/42537/15691517.1"
2024-12-20 16:46:51 MSK [16825]: INFO: Progress: (5738/5750). Process file "base/42537/15691517.1"
2024-12-20 16:47:18 MSK [16825]: LOG: File "/data/patroni/base/42537/17758370". Copied 360008371 bytes
2024-12-20 16:47:18 MSK [16825]: INFO: Progress: (5739/5750). Process file "base/42537/15379353"
2024-12-20 16:47:18 MSK [16825]: INFO: Progress: (5739/5750). Process file "base/42537/15379353"
2024-12-20 16:47:27 MSK [16825]: LOG: File "/data/patroni/base/42537/16008862". Copied 243420720 bytes
2024-12-20 16:47:27 MSK [16825]: INFO: Progress: (5740/5750). Process file "base/42537/16643250.1"
2024-12-20 16:47:27 MSK [16825]: INFO: Progress: (5740/5750). Process file "base/42537/16643250.1"
2024-12-20 16:47:33 MSK [16825]: LOG: File "/data/patroni/base/42537/17280317.1". Copied 245069915 bytes
2024-12-20 16:47:33 MSK [16825]: INFO: Progress: (5741/5750). Process file "base/42537/15691517"
2024-12-20 16:47:33 MSK [16825]: INFO: Progress: (5741/5750). Process file "base/42537/15691517"
2024-12-20 16:47:34 MSK [16825]: LOG: File "/data/patroni/base/42537/15379359.1". Copied 340505634 bytes
2024-12-20 16:47:34 MSK [16825]: INFO: Progress: (5742/5750). Process file "base/42537/17758364"
2024-12-20 16:47:34 MSK [16825]: INFO: Progress: (5742/5750). Process file "base/42537/17758364"
2024-12-20 16:47:35 MSK [16825]: LOG: File "/data/patroni/base/42537/15379359". Copied 355379913 bytes
2024-12-20 16:47:35 MSK [16825]: INFO: Progress: (5743/5750). Process file "base/42537/16643250"
2024-12-20 16:47:35 MSK [16825]: INFO: Progress: (5743/5750). Process file "base/42537/16643250"
2024-12-20 16:47:37 MSK [16825]: LOG: File "/data/patroni/base/42537/16008862.1". Copied 243563000 bytes
2024-12-20 16:47:37 MSK [16825]: INFO: Progress: (5744/5750). Process file "base/42537/16961374.1"
2024-12-20 16:47:37 MSK [16825]: INFO: Progress: (5744/5750). Process file "base/42537/16961374.1"
2024-12-20 16:47:44 MSK [16825]: LOG: File "/data/patroni/base/42537/16008868". Copied 355671885 bytes
2024-12-20 16:47:44 MSK [16825]: INFO: Progress: (5745/5750). Process file "base/42537/16643244"
2024-12-20 16:47:44 MSK [16825]: INFO: Progress: (5745/5750). Process file "base/42537/16643244"
2024-12-20 16:47:52 MSK [16825]: LOG: File "/data/patroni/base/42537/15691517.1". Copied 344305290 bytes
2024-12-20 16:47:52 MSK [16825]: INFO: Progress: (5746/5750). Process file "base/42537/16643244.1"
2024-12-20 16:47:52 MSK [16825]: INFO: Progress: (5746/5750). Process file "base/42537/16643244.1"
2024-12-20 16:48:29 MSK [16825]: LOG: File "/data/patroni/base/42537/15379353". Copied 242907070 bytes
2024-12-20 16:48:29 MSK [16825]: INFO: Progress: (5747/5750). Process file "base/42537/15691511"
2024-12-20 16:48:29 MSK [16825]: INFO: Progress: (5747/5750). Process file "base/42537/15691511"
2024-12-20 16:48:30 MSK [16825]: LOG: File "/data/patroni/base/42537/16643250.1". Copied 337298523 bytes
2024-12-20 16:48:30 MSK [16825]: INFO: Progress: (5748/5750). Process file "base/42537/16961368"
2024-12-20 16:48:30 MSK [16825]: INFO: Progress: (5748/5750). Process file "base/42537/16961368"
2024-12-20 16:48:32 MSK [16825]: LOG: File "/data/patroni/base/42537/16643250". Copied 353302112 bytes
2024-12-20 16:48:32 MSK [16825]: INFO: Progress: (5749/5750). Process file "base/42537/17280317"
2024-12-20 16:48:32 MSK [16825]: INFO: Progress: (5749/5750). Process file "base/42537/17280317"
2024-12-20 16:48:35 MSK [16825]: LOG: File "/data/patroni/base/42537/15691517". Copied 360307218 bytes
2024-12-20 16:48:35 MSK [16825]: INFO: Progress: (5750/5750). Process file "base/42537/15691511.1"
2024-12-20 16:48:35 MSK [16825]: INFO: Progress: (5750/5750). Process file "base/42537/15691511.1"
2024-12-20 16:48:42 MSK [16825]: LOG: File "/data/patroni/base/42537/16961374.1". Copied 340275577 bytes
2024-12-20 16:48:42 MSK [16825]: LOG: SSH process 16840 is terminated with status 0
2024-12-20 16:48:45 MSK [16825]: LOG: File "/data/patroni/base/42537/17758364". Copied 244124851 bytes
2024-12-20 16:48:45 MSK [16825]: LOG: SSH process 16837 is terminated with status 0
2024-12-20 16:48:50 MSK [16825]: LOG: File "/data/patroni/base/42537/16643244". Copied 243592758 bytes
2024-12-20 16:48:50 MSK [16825]: LOG: SSH process 16843 is terminated with status 0
2024-12-20 16:48:55 MSK [16825]: LOG: File "/data/patroni/base/42537/16643244.1". Copied 244724810 bytes
2024-12-20 16:48:55 MSK [16825]: LOG: SSH process 16846 is terminated with status 0
2024-12-20 16:49:13 MSK [16825]: LOG: File "/data/patroni/base/42537/16961368". Copied 244027914 bytes
2024-12-20 16:49:13 MSK [16825]: LOG: SSH process 16841 is terminated with status 0
2024-12-20 16:49:14 MSK [16825]: LOG: File "/data/patroni/base/42537/15691511". Copied 243609359 bytes
2024-12-20 16:49:14 MSK [16825]: LOG: SSH process 16844 is terminated with status 0
2024-12-20 16:49:17 MSK [16825]: LOG: File "/data/patroni/base/42537/17280317". Copied 244114768 bytes
2024-12-20 16:49:17 MSK [16825]: LOG: SSH process 16838 is terminated with status 0
2024-12-20 16:49:18 MSK [16825]: LOG: File "/data/patroni/base/42537/15691511.1". Copied 243616662 bytes
2024-12-20 16:49:18 MSK [16825]: LOG: SSH process 16853 is terminated with status 0
2024-12-20 16:49:18 MSK [16825]: INFO: Progress: Backup file "global/pg_control"
2024-12-20 16:49:18 MSK [16825]: LOG: Start SSH client process, pid 16902, cmd "pg_probackup-16 agent"
2024-12-20 16:49:19 MSK [16825]: LOG: Agent version=20509

2024-12-20 16:49:19 MSK [16825]: LOG: Agent compatibility params:
PG_MAJORVERSION=16
edition=vanilla
SIZEOF_VOID_P=8

2024-12-20 16:49:19 MSK [16825]: INFO: Data files are transferred, time elapsed: 10m:24s
2024-12-20 16:49:19 MSK [16825]: ERROR: query failed: server closed the connection unexpectedly
	This probably means the server terminated abnormally
	before or while processing the request.
query was: SET client_min_messages = warning;
2024-12-20 16:49:19 MSK [16825]: WARNING: A backup is in progress, stopping it.
2024-12-20 16:49:19 MSK [16825]: ERROR: query failed: no connection to the server
query was: SET datestyle = 'ISO, DMY';
2024-12-20 16:49:19 MSK [16825]: WARNING: query failed: no connection to the server
query was: SELECT pg_catalog.txid_snapshot_xmax(pg_catalog.txid_current_snapshot()), current_timestamp(0)::timestamptz, lsn, labelfile, spcmapfile FROM pg_catalog.pg_backup_stop(false)
2024-12-20 16:49:19 MSK [16825]: ERROR: Failed to send pg_backup_stop query
2024-12-20 16:49:19 MSK [16825]: WARNING: Backup SOSOKT is running, setting its status to ERROR`

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@fukanchik @dura0ok @konsmalakhov