Skip to content

DELTA-backup может выполняться не от крайнего FULL-backup #142

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.

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

Closed
triwada opened this issue Nov 3, 2019 · 6 comments
Labels

Comments

@triwada
Copy link

triwada commented Nov 3, 2019

Обнаружил неприятную особенность: из-за того, что начиная с какой-то версии стал возможен одновременный запуск бэкапов FULL и DELTA, возникает ситуация, когда новые бэкапы DELTA выполняются относительно более старого FULL. В итоге в один момент по истечению определенного retention удаляются все DELTA относительно старого FULL

Для примера ниже лог выполнения двух бэкапов DELTA с разницей в 2 часа, после последнего в списке бэкапов остаются только FULL и новый DELTA, все промежуточные DELTA удалились


$ pg_probackup -V
pg_probackup 2.2.5 (PostgreSQL 10.10)

$ pg_probackup show-config -B /backup/ --instance ****
# Backup instance information
pgdata = /PGDATA/10/data

# Connection parameters
pgdatabase = postgres
pghost = 127.0.0.1
pguser = backup
# Replica parameters
master-db = postgres
master-host = 127.0.0.1
master-port = 5432
master-user = backup
replica-timeout = 10min
# Archive parameters
archive-timeout = 10min
# Logging parameters
log-level-console = OFF
log-level-file = LOG
log-filename = pg_probackup.log
error-log-filename = pg_probackup_error.log
log-directory = /backup/log
log-rotation-size = 0TB
log-rotation-age = 3d
# Retention parameters
retention-redundancy = 3
retention-window = 0
wal-depth = 0
# Compression parameters
compress-algorithm = zlib
compress-level = 1
# Remote access parameters
remote-proto = ssh


2019-11-03 08:20:00 MSK: INFO: Backup Q0DN82 data files are valid
2019-11-03 08:20:00 MSK: INFO: Backup Q0DN82 completed
2019-11-03 08:20:00 MSK: LOG: REDUNDANCY=3
2019-11-03 08:20:00 MSK: INFO: Evaluate backups by retention
2019-11-03 08:20:00 MSK: INFO: Backup Q0DN82, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0.00d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0DHO1, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0.08d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0DC41, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0.16d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0D6K1, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0.25d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0D3S1, mode: FULL, status: OK. Redundancy: 1/3, Time Window: 0.20d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0D101, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0.34d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0CVG1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0.42d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0CPW1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0.51d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0CKC1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0.59d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0CES1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0.67d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0C981, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0.76d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0C3O1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0.84d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0BY41, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0.92d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0BSK1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1.00d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0BN02, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1.08d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0BHG1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1.15d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0BBW1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1.25d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0B941, mode: FULL, status: OK. Redundancy: 2/3, Time Window: 1.19d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0B6C1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1.34d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0B0S1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1.42d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0AV81, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1.51d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0APO1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1.59d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0AK41, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1.67d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0AEK1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1.75d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0A901, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1.84d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q0A3G1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1.92d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q09XW1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2.00d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q09SC1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2.08d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q09MS1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2.16d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q09H81, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2.25d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q09EG1, mode: FULL, status: OK. Redundancy: 3/3, Time Window: 2.20d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q09BO1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2.34d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q09641, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2.42d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q090K1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2.51d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q08V01, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2.59d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q08PG1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2.67d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q08JW1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2.75d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q08EC1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2.84d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q088S1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2.92d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q08381, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3.00d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q07XO1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3.08d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q07U32, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3.13d/0d. Expired
2019-11-03 08:20:00 MSK: INFO: Backup Q07JS1, mode: FULL, status: OK. Redundancy: 4/3, Time Window: 3.20d/0d. Expired
2019-11-03 08:20:00 MSK: LOG: Consider backup Q09BO1 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q09BO1 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q09BO1 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q09641 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q09641 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q09641 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q090K1 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q090K1 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q090K1 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q08V01 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q08V01 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q08V01 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q08PG1 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q08PG1 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q08PG1 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q08JW1 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q08JW1 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q08JW1 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q08EC1 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q08EC1 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q08EC1 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q088S1 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q088S1 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q088S1 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q08381 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q08381 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q08381 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q07XO1 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q07XO1 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q07XO1 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q07U32 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q07U32 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q07U32 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: Consider backup Q07JS1 for purge
2019-11-03 08:20:00 MSK: LOG: Check if backup Q07JS1 is parent of backup Q09H81
2019-11-03 08:20:00 MSK: LOG: Retain backup Q07JS1 from purge because his descendant Q09H81 is guarded by retention
2019-11-03 08:20:00 MSK: LOG: removing WAL segments older than 000000010000170B00000030
2019-11-03 08:20:00 MSK: INFO: There are no backups to merge by retention policy
2019-11-03 08:20:00 MSK: INFO: There are no backups to delete by retention policy


2019-11-03 10:21:42 MSK: INFO: pg_probackup archive-push completed successfully
2019-11-03 10:21:43 MSK: INFO: wait for pg_stop_backup()
2019-11-03 10:21:43 MSK: INFO: pg_stop backup() successfully executed
2019-11-03 10:21:43 MSK: LOG: Looking for LSN 1724/5204C090 in segment: 000000010000172400000052
2019-11-03 10:21:43 MSK: LOG: Found LSN: 1724/5204C090
2019-11-03 10:21:43 MSK: LOG: finished streaming WAL at 1724/53000000 (timeline 1)
2019-11-03 10:21:43 MSK: LOG: Getting the Recovery Time from WAL
2019-11-03 10:21:43 MSK: LOG: current.stop_lsn: 1724/5204C090
2019-11-03 10:22:40 MSK: INFO: Validating backup Q0DSS1
2019-11-03 10:24:31 MSK: INFO: Backup Q0DSS1 data files are valid
2019-11-03 10:24:31 MSK: INFO: Backup Q0DSS1 resident size: 9084MB
2019-11-03 10:24:31 MSK: INFO: Backup Q0DSS1 completed
2019-11-03 10:24:31 MSK: LOG: REDUNDANCY=3
2019-11-03 10:24:31 MSK: INFO: Evaluate backups by retention
2019-11-03 10:24:31 MSK: INFO: Backup Q0DSS1, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Active
2019-11-03 10:24:31 MSK: INFO: Backup Q0DN82, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0DHO1, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0DC41, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0D6K1, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0D3S1, mode: FULL, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Active
2019-11-03 10:24:31 MSK: INFO: Backup Q0D101, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0CVG1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0CPW1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0CKC1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0CES1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0C981, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0C3O1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BY41, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BSK1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BN02, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BHG1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BBW1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0B941, mode: FULL, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Active
2019-11-03 10:24:31 MSK: INFO: Backup Q0B6C1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0B0S1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0AV81, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0APO1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0AK41, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0AEK1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0A901, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0A3G1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09XW1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09SC1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09MS1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09H81, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09EG1, mode: FULL, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Active
2019-11-03 10:24:31 MSK: INFO: Backup Q09BO1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09641, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q090K1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08V01, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08PG1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08JW1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08EC1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q088S1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08381, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q07XO1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q07U32, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q07JS1, mode: FULL, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: LOG: Consider backup Q0DN82 for purge
2019-11-03 10:24:31 MSK: INFO: Delete: Q0DN82 2019-11-03 08:19:58+03
2019-11-03 10:24:32 MSK: LOG: Consider backup Q0DHO1 for purge
2019-11-03 10:24:32 MSK: INFO: Delete: Q0DHO1 2019-11-03 06:22:04+03
2019-11-03 10:24:32 MSK: LOG: Consider backup Q0DC41 for purge
2019-11-03 10:24:32 MSK: INFO: Delete: Q0DC41 2019-11-03 04:33:01+03
2019-11-03 10:24:32 MSK: LOG: Consider backup Q0D6K1 for purge
2019-11-03 10:24:32 MSK: INFO: Delete: Q0D6K1 2019-11-03 02:13:36+03
2019-11-03 10:24:32 MSK: LOG: Consider backup Q0D101 for purge
2019-11-03 10:24:32 MSK: INFO: Delete: Q0D101 2019-11-03 00:12:34+03
2019-11-03 10:24:32 MSK: LOG: Consider backup Q0CVG1 for purge
2019-11-03 10:24:32 MSK: INFO: Delete: Q0CVG1 2019-11-02 22:12:10+03
2019-11-03 10:24:32 MSK: LOG: Consider backup Q0CPW1 for purge
2019-11-03 10:24:32 MSK: INFO: Delete: Q0CPW1 2019-11-02 20:13:33+03
2019-11-03 10:24:32 MSK: LOG: Consider backup Q0CKC1 for purge
2019-11-03 10:24:32 MSK: INFO: Delete: Q0CKC1 2019-11-02 18:11:28+03
2019-11-03 10:24:32 MSK: LOG: Consider backup Q0CES1 for purge
2019-11-03 10:24:32 MSK: INFO: Delete: Q0CES1 2019-11-02 16:11:43+03
2019-11-03 10:24:33 MSK: LOG: Consider backup Q0C981 for purge
2019-11-03 10:24:33 MSK: INFO: Delete: Q0C981 2019-11-02 14:12:32+03
2019-11-03 10:24:33 MSK: LOG: Consider backup Q0C3O1 for purge
2019-11-03 10:24:33 MSK: INFO: Delete: Q0C3O1 2019-11-02 12:13:55+03
2019-11-03 10:24:33 MSK: LOG: Consider backup Q0BY41 for purge
2019-11-03 10:24:33 MSK: INFO: Delete: Q0BY41 2019-11-02 10:14:46+03
2019-11-03 10:24:33 MSK: LOG: Consider backup Q0BSK1 for purge
2019-11-03 10:24:33 MSK: INFO: Delete: Q0BSK1 2019-11-02 08:20:24+03
2019-11-03 10:24:33 MSK: LOG: Consider backup Q0BN02 for purge
2019-11-03 10:24:33 MSK: INFO: Delete: Q0BN02 2019-11-02 06:27:49+03
2019-11-03 10:24:33 MSK: LOG: Consider backup Q0BHG1 for purge
2019-11-03 10:24:33 MSK: INFO: Delete: Q0BHG1 2019-11-02 04:39:06+03
2019-11-03 10:24:34 MSK: LOG: Consider backup Q0BBW1 for purge
2019-11-03 10:24:34 MSK: INFO: Delete: Q0BBW1 2019-11-02 02:14:36+03
2019-11-03 10:24:34 MSK: LOG: Consider backup Q0B6C1 for purge
2019-11-03 10:24:34 MSK: INFO: Delete: Q0B6C1 2019-11-02 00:11:48+03
2019-11-03 10:24:34 MSK: LOG: Consider backup Q0B0S1 for purge
2019-11-03 10:24:34 MSK: INFO: Delete: Q0B0S1 2019-11-01 22:11:31+03
2019-11-03 10:24:34 MSK: LOG: Consider backup Q0AV81 for purge
2019-11-03 10:24:34 MSK: INFO: Delete: Q0AV81 2019-11-01 20:12:11+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q0APO1 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q0APO1 2019-11-01 18:12:08+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q0AK41 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q0AK41 2019-11-01 16:12:51+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q0AEK1 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q0AEK1 2019-11-01 14:15:51+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q0A901 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q0A901 2019-11-01 12:15:55+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q0A3G1 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q0A3G1 2019-11-01 10:17:28+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q09XW1 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q09XW1 2019-11-01 08:19:54+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q09SC1 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q09SC1 2019-11-01 06:23:24+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q09MS1 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q09MS1 2019-11-01 04:28:31+03
2019-11-03 10:24:35 MSK: LOG: Consider backup Q09H81 for purge
2019-11-03 10:24:35 MSK: INFO: Delete: Q09H81 2019-11-01 02:19:13+03
2019-11-03 10:24:36 MSK: LOG: Consider backup Q09BO1 for purge
2019-11-03 10:24:36 MSK: INFO: Delete: Q09BO1 2019-11-01 00:11:19+03
2019-11-03 10:24:36 MSK: LOG: Consider backup Q09641 for purge
2019-11-03 10:24:36 MSK: INFO: Delete: Q09641 2019-10-31 22:10:29+03
2019-11-03 10:24:36 MSK: LOG: Consider backup Q090K1 for purge
2019-11-03 10:24:36 MSK: INFO: Delete: Q090K1 2019-10-31 20:11:53+03
2019-11-03 10:24:36 MSK: LOG: Consider backup Q08V01 for purge
2019-11-03 10:24:36 MSK: INFO: Delete: Q08V01 2019-10-31 18:11:35+03
2019-11-03 10:24:36 MSK: LOG: Consider backup Q08PG1 for purge
2019-11-03 10:24:36 MSK: INFO: Delete: Q08PG1 2019-10-31 16:12:01+03
2019-11-03 10:24:36 MSK: LOG: Consider backup Q08JW1 for purge
2019-11-03 10:24:36 MSK: INFO: Delete: Q08JW1 2019-10-31 14:15:46+03
2019-11-03 10:24:36 MSK: LOG: Consider backup Q08EC1 for purge
2019-11-03 10:24:36 MSK: INFO: Delete: Q08EC1 2019-10-31 12:14:10+03
2019-11-03 10:24:37 MSK: LOG: Consider backup Q088S1 for purge
2019-11-03 10:24:37 MSK: INFO: Delete: Q088S1 2019-10-31 10:16:35+03
2019-11-03 10:24:37 MSK: LOG: Consider backup Q08381 for purge
2019-11-03 10:24:37 MSK: INFO: Delete: Q08381 2019-10-31 08:18:34+03
2019-11-03 10:24:37 MSK: LOG: Consider backup Q07XO1 for purge
2019-11-03 10:24:37 MSK: INFO: Delete: Q07XO1 2019-10-31 06:20:21+03
2019-11-03 10:24:37 MSK: LOG: Consider backup Q07U32 for purge
2019-11-03 10:24:37 MSK: INFO: Delete: Q07U32 2019-10-31 05:08:53+03
2019-11-03 10:24:37 MSK: LOG: Consider backup Q07JS1 for purge
2019-11-03 10:24:37 MSK: INFO: Delete: Q07JS1 2019-10-31 03:35:31+03
2019-11-03 10:24:42 MSK: INFO: On timeline 1 WAL segments between 0000170B00000030 and 0000171100000029 will be removed
2019-11-03 10:24:42 MSK: INFO: Logical WAL size to remove on timeline 1 : 24GB
2019-11-03 10:24:42 MSK: INFO: Resident WAL size to free on timeline 1 : 7836MB
2019-11-03 10:24:42 MSK: INFO: There are no backups to merge by retention policy
2019-11-03 10:24:42 MSK: INFO: Purging finished

Хочется понять, такое поведение задумывалось изначально или это bug? После работы с Microsoft SQL Server такое поведение кажется неожиданным, т.к. после каждого нового FULL-бэкапа там начинается новая цепочка бэкапов

@gsmolk
Copy link
Contributor

gsmolk commented Nov 3, 2019

Инкрементальный бэкап при старте ищет себе последнего валидного FULL предка. После того как он найден, он идет по цепочке до самого последнего потомка этого FULL предка и объявляет его своим родителем.
Поведение, которое Вы наблюдаете - это не баг, а неизбежное следствие того, что можно запускать несколько бэкапов одновременно. Пока создается новый FULL, для любого параллельно ему запущенного DELTA бэкапа он не может являться потенциальный предком(вдруг он завершится неуспешно). Получается такой своеобразный "нахлест":

DELTA_a2
FULLb - RUNNING
DELTA_a1 
FULL_a - OK

После того, как FULLb выполнился, все новые DELTA бэкапы будут "наследоваться" от него:

DELTA_b1
DELTA_a2
FULLb - OK
DELTA_a1 
FULL_a - OK

Со своей стороны мы можем сделать дополнительный флаг --lock. Таск: #59

Временный воркараунд тут - использовать flock перед взятием бэкапа. Например, лок с таймаутом в 5 часов:

 flock --timeout 18000 -с 'pg_probackup backup ...'

@postgrespro postgrespro deleted a comment from triwada Nov 3, 2019
@gsmolk gsmolk added the question label Nov 3, 2019
@triwada
Copy link
Author

triwada commented Nov 3, 2019

После того, как FULLb выполнился, все новые DELTA бэкапы будут "наследоваться" от него:

DELTA_b1
DELTA_a2
FULLb - OK
DELTA_a1
FULL_a - OK

Это было бы понятным. Но в описанном выше случае не слишком много DELTA-бэкапов оказалось зависимым от одного бэкапа?

По этой логике после этого бэкапа в этом списке Q09MS1 уже должен был быть зависимым от Q09EG1, но в итоге он пометился как expired, при этом Q09EG1 остался
2019-11-03 08:20:00 MSK: INFO: Backup Q09MS1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2.16d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q09H81, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2.25d/0d. Active
2019-11-03 08:20:00 MSK: INFO: Backup Q09EG1, mode: FULL, status: OK. Redundancy: 3/3, Time Window: 2.20d/0d. Active

Инкрементальный бэкап при старте ищет себе последнего валидного FULL предка. После того как он найден, он идет по цепочке до самого последнего потомка этого FULL предка и объявляет его своим родителем.

И зачем он объявляется своим родителем самый старый FULL-бэкап?

@gsmolk
Copy link
Contributor

gsmolk commented Nov 3, 2019

Хм, только сейчас увидел это безобразие:

2019-11-03 10:24:31 MSK: LOG: REDUNDANCY=3
2019-11-03 10:24:31 MSK: INFO: Evaluate backups by retention
2019-11-03 10:24:31 MSK: INFO: Backup Q0DSS1, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Active
2019-11-03 10:24:31 MSK: INFO: Backup Q0DN82, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0DHO1, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0DC41, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0D6K1, mode: DELTA, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0D3S1, mode: FULL, status: OK. Redundancy: 1/3, Time Window: 0d/0d. Active
2019-11-03 10:24:31 MSK: INFO: Backup Q0D101, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0CVG1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0CPW1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0CKC1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0CES1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0C981, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0C3O1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 0d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BY41, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BSK1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BN02, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BHG1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0BBW1, mode: DELTA, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0B941, mode: FULL, status: OK. Redundancy: 2/3, Time Window: 1d/0d. Active
2019-11-03 10:24:31 MSK: INFO: Backup Q0B6C1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0B0S1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0AV81, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0APO1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0AK41, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0AEK1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0A901, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 1d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q0A3G1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09XW1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09SC1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09MS1, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09H81, mode: DELTA, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09EG1, mode: FULL, status: OK. Redundancy: 3/3, Time Window: 2d/0d. Active
2019-11-03 10:24:31 MSK: INFO: Backup Q09BO1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q09641, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q090K1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08V01, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08PG1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08JW1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08EC1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 2d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q088S1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q08381, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q07XO1, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q07U32, mode: DELTA, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired
2019-11-03 10:24:31 MSK: INFO: Backup Q07JS1, mode: FULL, status: OK. Redundancy: 4/3, Time Window: 3d/0d. Expired

Это, конечно, же нелегально.
А какой версией были сделаны эти бэкапы?

@triwada
Copy link
Author

triwada commented Nov 3, 2019

А какой версией были сделаны эти бэкапы?

2.1.2

@gsmolk
Copy link
Contributor

gsmolk commented Nov 3, 2019

А, тогда понятно. Вы поймали вот этот баг(исправлено в 2.1.5):
#92

@triwada triwada closed this as completed Nov 3, 2019
@triwada
Copy link
Author

triwada commented Nov 3, 2019

тогда закрываю

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants