pgbackrest
pgbackrest copied to clipboard
pgbackrest
SFTP to TrueNAS Core 13.0-U6.1 - unable to open file backup_label.zst
Please provide the following information when submitting an issue (feature requests or general comments can skip this):
-
pgBackRest version: 2.51
-
PostgreSQL version: 13.12-1.pgdg120+1
-
Operating system/version - if you have more than one server (for example, a database server, a repository host server, one or more standbys), please specify each: Debian 12.2 - Trying to backup to a SFTP Repo on a
TrueNAS-13.0-U6.1 Core machine, FreeBSD 13.1-Release-p9 -
Did you install pgBackRest from source or from a package? Debian Package
-
Please attach the following as applicable:
2024-03-29 14:06:38.851 P00 DEBUG: storage/storage::storageNewWrite: (this: {type: sftp, path: /mnt/tank/pgbackrest/storage/egdb3/main, write: true}, fileExp: {"REPO:BACKUP/20240329-140410F/pg_data/backup_label.zst"}, param.modeFile: 0000, param.modePath: 0000, param.user: null, param.group: null, param.timeModified: 0, param.noCreatePath: false, param.noSyncFile: false, param.noSyncPath: false, param.noAtomic: false, param.noTruncate: false, param.compressible: true) 2024-03-29 14:06:38.851 P00 DEBUG: storage/storage::storageNewWrite: => {type: sftp, name: /mnt/tank/pgbackrest/storage/egdb3/main/backup/main/20240329-140410F/pg_data/backup_label.zst, modeFile: 0640, modePath: 0750, createPath: true, syncFile: true, syncPath: false, atomic: true} 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: hash}) 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: zst-cmp}) 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: cipher-blk}) 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: hash}) 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: size}) 2024-03-29 14:06:38.851 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:06:38.851 P00 DEBUG: storage/storage::storagePut: (file: {type: sftp, name: /mnt/tank/pgbackrest/storage/egdb3/main/backup/main/20240329-140410F/pg_data/backup_label.zst, modeFile: 0640, modePath: 0750, createPath: true, syncFile: true, syncPath: false, atomic: true}, buffer: {used: 261, size: 261}) 2024-03-29 14:06:38.860 P00 DEBUG: command/exit::exitSafe: (result: 0, error: true, signalType: 0) ERROR: [041]: unable to open file '/mnt/tank/pgbackrest/storage/egdb3/main/backup/main/20240329-140410F/pg_data/backup_label.zst' for write: libssh2 error [-43] -------------------------------------------------------------------- If SUBMITTING AN ISSUE please provide the following information:
version: 2.51
command: backup
options: --archive-timeout=300 --compress-type=zst --exec-id=2922792-15221063 --log-level-console=debug --pg1-path=/var/lib/postgresql/13/main --process-max=8 --repo=4 --repo1-bundle --repo4-bundle --repo4-cipher-pass=<redacted> --repo4-cipher-type=aes-256-cbc --repo1-path=/var/lib/pgbackrest --repo4-path=/mnt/tank/pgbackrest/storage/egdb3/main --repo1-retention-full=5 --repo4-retention-full=12 --repo4-sftp-host=192.168.46.39 --repo4-sftp-host-key-hash-type=sha256 --repo4-sftp-host-user=pgbackrest --repo4-sftp-private-key-file=/var/lib/postgresql/.ssh/id_ed25519_sftp --repo4-sftp-public-key-file=/var/lib/postgresql/.ssh/id_ed25519_sftp.pub --repo4-type=sftp --no-resume --stanza=main --start-fast --type=full
stack trace:
storage/sftp/storage.c:storageSftpEvalLibSsh2Error:363:(test build required for parameters)
... function(s) omitted ...
storage/sftp/write.c:storageWriteSftpOpen:(trace log level required for parameters)
common/io/write.c:ioWriteOpen:(trace log level required for parameters)
storage/storage.c:storagePut:(file: {type: sftp, name: /mnt/tank/pgbackrest/storage/egdb3/main/backup/main/20240329-140410F/pg_data/backup_label.zst, modeFile: 0640, modePath: 0750, createPath: true, syncFile: true, syncPath: false, atomic: true}, buffer: {used: 261, size: 261})
command/backup/backup.c:backupFilePut:(backupData: {BackupData}, manifest: {Manifest}, name: {"backup_label"}, timestamp: 1711739198, content: {"START WAL LOCATION: 96/E4000028 (file 0000000100000096000000E4)
CHECKPOINT LOCATION: 96/E4016760
BACKUP METHOD: streamed
BACKUP FROM: master
START TIME: 2024-03-29 14:04:11 CDT
LABEL: pgBackRest backup started at 2024-03-29 14:04:10.451302-05
START TIMELINE: 1
"})
command/backup/backup.c:backupStop:(backupData: {BackupData}, manifest: {Manifest})
command/backup/backup.c:cmdBackup:(void)
main.c:main:(debug log level required for parameters)
--------------------------------------------------------------------
- log file in `/var/log/pgbackrest` for the commands run (e.g. `/var/log/pgbackrest/mystanza_backup.log`)
-------------------PROCESS START-------------------
2024-03-29 13:54:02.809 P00 INFO: backup command begin 2.51: --archive-timeout=300 --compress-type=zst --exec-id=2913581-b78fd95c --log-level-console=info --pg1-path=/var/lib/postgresql/13/main --process-max=8 --repo=4 --repo1-bundle --repo4-bundle --repo4-cipher-pass=
-------------------PROCESS START-------------------
2024-03-29 13:57:17.636 P00 INFO: backup command begin 2.51: --archive-timeout=300 --compress-type=zst --exec-id=2916269-f76349f5 --log-level-console=debug --pg1-path=/var/lib/postgresql/13/main --process-max=8 --repo=4 --repo1-bundle --repo4-bundle --repo4-cipher-pass=
-------------------PROCESS START-------------------
2024-03-29 14:04:09.403 P00 INFO: backup command begin 2.51: --archive-timeout=300 --compress-type=zst --exec-id=2922792-15221063 --log-level-console=debug --pg1-path=/var/lib/postgresql/13/main --process-max=8 --repo=4 --repo1-bundle --repo4-bundle --repo4-cipher-pass=
- Describe the issue:
Trying to backup to sftp repo on a TrueNAS-13.0-U6.1 Core machine, FreeBSD 13.1-Release-p9. OpenSSH_8.8p1, OpenSSL 1.1.1o-freebsd 3 may 2022
Just upgraded to 2.51 from 2.48 after seeing the fixes related to RSYNC.net sftp backups since I was running into the file deletion errors.
https://github.com/pgbackrest/pgbackrest/issues/2219
Got past those with version 2.51, but now I'm getting an error about not being able to open the backup_label.zst for writing.
ERROR: [041]: unable to open file '/mnt/tank/pgbackrest/storage/egdb3/main/backup/main/20240329-143216F/pg_data/backup_label.zst' for write: libssh2 error [-43]
The backup seems complete copying all the files, then I get: 2024-03-29 14:39:58.567 P00 DEBUG: command/backup/backup::backupFilePut: (backupData: {BackupData}, manifest: {Manifest}, name: {"backup_label"}, timestamp: 1711741198, content: {"START WAL LOCATION: 96/ED000028 (file 0000000100000096000000ED) CHECKPOINT LOCATION: 96/ED000060 BACKUP METHOD: streamed BACKUP FROM: master START TIME: 2024-03-29 14:37:10 CDT LABEL: pgBackRest backup started at 2024-03-29 14:37:10.114533-05 START TIMELINE: 1 "}) 2024-03-29 14:39:58.567 P00 DEBUG: storage/storage::storageNewWrite: (this: {type: sftp, path: /mnt/tank/pgbackrest/storage/egdb3/main, write: true}, fileExp: {"REPO:BACKUP/20240329-143709F/pg_data/backup_label.zst"}, param.modeFile: 0000, param.modePath: 0000, param.user: null, param.group: null, param.timeModified: 0, param.noCreatePath: false, param.noSyncFile: false, param.noSyncPath: false, param.noAtomic: false, param.noTruncate: false, param.compressible: true) 2024-03-29 14:39:58.567 P00 DEBUG: storage/storage::storageNewWrite: => {type: sftp, name: /mnt/tank/pgbackrest/storage/egdb3/main/backup/main/20240329-143709F/pg_data/backup_label.zst, modeFile: 0640, modePath: 0750, createPath: true, syncFile: true, syncPath: false, atomic: true} 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: hash}) 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: zst-cmp}) 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: cipher-blk}) 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: hash}) 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: (this: {inputSame: false, done: false}, filter: {type: size}) 2024-03-29 14:39:58.567 P00 DEBUG: common/io/filter/group::ioFilterGroupAdd: => {inputSame: false, done: false} 2024-03-29 14:39:58.567 P00 DEBUG: storage/storage::storagePut: (file: {type: sftp, name: /mnt/tank/pgbackrest/storage/egdb3/main/backup/main/20240329-143709F/pg_data/backup_label.zst, modeFile: 0640, modePath: 0750, createPath: true, syncFile: true, syncPath: false, atomic: true}, buffer: {used: 261, size: 261}) 2024-03-29 14:39:58.576 P00 DEBUG: command/exit::exitSafe: (result: 0, error: true, signalType: 0) ERROR: [041]: unable to open file '/mnt/tank/pgbackrest/storage/egdb3/main/backup/main/20240329-143709F/pg_data/backup_label.zst' for write: libssh2 error [-43]
The ERROR: [041] is a pgbackrest file open error that appears to be being triggered by an error in the libssh2 libraries -43 (defined as LIBSSH2_ERROR_SOCKET_RECV) when libssh2 is attempting to communicate with the sftp server.
Can you advise which libssh2 library version you are using(looking online, it looks like deb12 uses v1.10)?
Checking the libssh2 code, LIBSSH2_ERROR_SOCKET_RECV is only returned in a few places, but doesn't output any messages in several of these unless compiled with LIBSSH2DEBUG.
Is this using the same repo that had deletion issues with v2.48, or on a newly created repo? (i.e. does the error occur with a new repo: pgbackrest stanza-create... pgbackrest check... pgbackrest backup...) Does the error occur with a different or no compression and smaller value for process-max?
Info about the libssh2 library version. libssh2-1:amd64 1.10.0-3+b1
Yes same repo as the v2.48. I'll try a new repo and report back. As well as the other options you mentioned.
Deleted the stanza on the sftp repo and re-created it.
Received a different error ERROR: [053]: unable to list file info for path '/mnt/tank/pgbackrest/storage/egdb3/main/archive/main/13-1/0000000100000097': libssh2 error [-43] 2024-04-01 16:10:49.473 P00 INFO: backup command end: aborted with exception [053]
Tried --compress-type=none and --process-max=1 and backup failed with this error.
2024-04-01 16:21:53.801 P01 DETAIL: backup file /var/lib/postgresql/13/main/base/4601745/5927508.1 (976.2MB, 32.12%) checksum 7d3dc9307ef4db251736b32e5e24ee74ca9034b6 ERROR: [039]: client state is 'data-get' but expected 'idle' 2024-04-01 16:21:53.902 P00 DETAIL: statistics: {"socket.client":{"total":2},"socket.session":{"total":2}} 2024-04-01 16:21:53.902 P00 INFO: backup command end: aborted with exception [039] WARN: unable to wait on child process: [10] No child processes
Tried "--compress-type=none --process-max=4"
Maybe it is looking for the non compressed wal archive... I'll give it another try tomorrow.
I'll try and get back to this later once I setup a test system. I'll just plan on not using Truenas as a repo for now.