Hello Falko,
> On 22 Apr 2020, at 09:59, Falko Trojahn via BackupPC-users
> <backuppc-users@lists.sourceforge.net> wrote:
>
> Usually, there are some more informations in the Xferlog. What shows the
> Xferlog of a failed attempt?
The XferLog and verbose output for three attempts are attached below.
The same user is used for all attempts: "backuppc".
Basically, it boils down to this:
1. Manually started from command-line in bash shell for "backuppc" user: ALL OK
2. Scheduled via crontab for "backuppc" user: ALL OK
3. Initiated from hourly schedule by BackupPC daemon running as "backuppc":
FAILS
4. Manually started from web interface running as "backuppc": FAILS
When it fails, it fails on the rsync_bpc command. With the following error
(example):
Xfer PIDs are now 31322
This is the rsync child about to exec /usr/bin/rsync_bpc
ssh_exchange_identification: Connection closed by remote host
rsync_bpc: connection unexpectedly closed (0 bytes received so far)
[Receiver]
This implies something goes wrong with the SSH connection. However, no outgoing
TCP packets are visible in tcpdump. The error is not reproducible when
initiated manually from shell or cron, in that case we do see outgoing TCP
packets and all is well. This is severely odd.
I still think I am doing something stupid, or I am hitting some weird bug in
this specific combination of rsync_bpc version and my system.
Your help is greatly appreciated.
XferLOG from full backup initiated through web interface (backup fails):
Running: /usr/bin/rsync_bpc --bpc-top-dir /var/lib/BackupPC/
--bpc-host-name myhostname --bpc-share-name / --bpc-bkup-num 124
--bpc-bkup-comp 3 --bpc-bkup-prevnum -1 --bpc-bkup-prevcomp -1
--bpc-bkup-inode0 175546 --bpc-attrib-new --bpc-log-level 0 -e /usr/bin/ssh\
-l\ mycompany_backup --rsync-path=/usr/bin/sudo\ /usr/bin/rsync --super
--recursive --protect-args --numeric-ids --perms --owner --group -D --times
--links --hard-links --delete --delete-excluded --one-file-system --partial
--log-format=log:\ %o\ %i\ %B\ %8U,%8G\ %9l\ %f%L --stats --checksum
--timeout=72000 --exclude=/mnt --exclude=/proc --exclude=/dev --exclude=/sys
--exclude=/var/lib/pgsql/\*/data/base --exclude=/var/lib/pgsql/\*/data/pg_wal
--exclude=/var/lib/mysql/\*/\* --exclude=/var/lib/mysql/ibdata\*
--exclude=/var/lib/mysql/ib_logfile\* --exclude=/var/lib/BackupPC/\*
--exclude=/var/mycompany/mysql/mariabackup/tmp_export
--exclude=/mariabackup/tmp_export myhostname:/ /
full backup started for directory /
Xfer PIDs are now 31322
This is the rsync child about to exec /usr/bin/rsync_bpc
ssh_exchange_identification: Connection closed by remote host
rsync_bpc: connection unexpectedly closed (0 bytes received so far)
[Receiver]
Done: 0 errors, 0 filesExist, 0 sizeExist, 0 sizeExistComp, 0 filesTotal, 0
sizeTotal, 0 filesNew, 0 sizeNew, 0 sizeNewComp, 175546 inode
rsync error: unexplained error (code 255) at io.c(226) [Receiver=3.1.2.0]
rsync_bpc exited with fatal status 255 (65280) (rsync error: unexplained
error (code 255) at io.c(226) [Receiver=3.1.2.0])
Xfer PIDs are now
Got fatal error during xfer (No files dumped for share /)
Backup aborted (No files dumped for share /)
(...)
XferLOG from full backup initiated through bash shell (backup succeeds):
(...)
Backup prep: type = full, case = 6, inPlace = 1, doDuplicate = 0,
newBkupNum = 124, newBkupIdx = 29, lastBkupNum = , lastBkupIdx = (FillCycle =
0, noFillCnt = 0)
Running: /usr/bin/rsync_bpc --bpc-top-dir /var/lib/BackupPC/
--bpc-host-name myhostname --bpc-share-name / --bpc-bkup-num 124
--bpc-bkup-comp 3 --bpc-bkup-prevnum -1 --bpc-bkup-prevcomp -1
--bpc-bkup-inode0 175546 --bpc-attrib-new --bpc-log-level 0 -e /usr/bin/ssh\
-l\ mycompany_backup --rsync-path=/usr/bin/sudo\ /usr/bin/rsync --super
--recursive --protect-args --numeric-ids --perms --owner --group -D --times
--links --hard-links --delete --delete-excluded --one-file-system --partial
--log-format=log:\ %o\ %i\ %B\ %8U,%8G\ %9l\ %f%L --stats --checksum
--timeout=72000 --exclude=/mnt --exclude=/proc --exclude=/dev --exclude=/sys
--exclude=/var/lib/pgsql/\*/data/base --exclude=/var/lib/pgsql/\*/data/pg_wal
--exclude=/var/lib/mysql/\*/\* --exclude=/var/lib/mysql/ibdata\*
--exclude=/var/lib/mysql/ib_logfile\* --exclude=/var/lib/BackupPC/\*
--exclude=/var/mycompany/mysql/mariabackup/tmp_export
--exclude=/mariabackup/tmp_export myhostname:/ /
full backup started for directory /
Xfer PIDs are now 341
This is the rsync child about to exec /usr/bin/rsync_bpc
cmdExecOrEval: about to exec /usr/bin/rsync_bpc --bpc-top-dir
/var/lib/BackupPC/ --bpc-host-name myhostname --bpc-share-name / --bpc-bkup-num
124 --bpc-bkup-comp 3 --bpc-bkup-prevnum -1 --bpc-bkup-prevcomp -1
--bpc-bkup-inode0 175546 --bpc-attrib-new --bpc-log-level 0 -e /usr/bin/ssh\
-l\ mycompany_backup --rsync-path=/usr/bin/sudo\ /usr/bin/rsync --super
--recursive --protect-args --numeric-ids --perms --owner --group -D --times
--links --hard-links --delete --delete-excluded --one-file-system --partial
--log-format=log:\ %o\ %i\ %B\ %8U,%8G\ %9l\ %f%L --stats --checksum
--timeout=72000 --exclude=/mnt --exclude=/proc --exclude=/dev --exclude=/sys
--exclude=/var/lib/pgsql/\*/data/base --exclude=/var/lib/pgsql/\*/data/pg_wal
--exclude=/var/lib/mysql/\*/\* --exclude=/var/lib/mysql/ibdata\*
--exclude=/var/lib/mysql/ib_logfile\* --exclude=/var/lib/BackupPC/\*
--exclude=/var/mycompany/mysql/mariabackup/tmp_export
--exclude=/mariabackup/tmp_export myhostname:/ /
Xfer PIDs are now 341,345
(...)
Verbose output snippet when initiated through cron (backup succeeds):
(...)
BackupPC_backupDuplicate: got 0 errors and 0 file open errors
Finished BackupPC_backupDuplicate (running time: 4 sec)
__bpc_progress_state__ backup share "/"
Running: /usr/bin/rsync_bpc --bpc-top-dir /var/lib/BackupPC/
--bpc-host-name myhostname --bpc-share-name / --bpc-bkup-num 125
--bpc-bkup-comp 3 --bpc-bkup-prevnum -1 --bpc-bkup-prevcomp -1
--bpc-bkup-inode0 175597 --bpc-attrib-new --bpc-log-level 0 -e /usr/bin/ssh\
-l\ mycompany_backup --rsync-path=/usr/bin/sudo\ /usr/bin/rsync --super
--recursive --protect-args --numeric-ids --perms --owner --group -D --times
--links --hard-links --delete --delete-excluded --one-file-system --partial
--log-format=log:\ %o\ %i\ %B\ %8U,%8G\ %9l\ %f%L --stats --checksum
--timeout=72000 --exclude=/mnt --exclude=/proc --exclude=/dev --exclude=/sys
--exclude=/var/lib/pgsql/\*/data/base --exclude=/var/lib/pgsql/\*/data/pg_wal
--exclude=/var/lib/mysql/\*/\* --exclude=/var/lib/mysql/ibdata\*
--exclude=/var/lib/mysql/ib_logfile\* --exclude=/var/lib/BackupPC/\*
--exclude=/var/mycompany/mysql/mariabackup/tmp_export
--exclude=/mariabackup/tmp_export myhostname:/ /
full backup started for directory /
started full dump, share=/
Xfer PIDs are now 1143
xferPids 1143
This is the rsync child about to exec /usr/bin/rsync_bpc
cmdExecOrEval: about to exec /usr/bin/rsync_bpc --bpc-top-dir
/var/lib/BackupPC/ --bpc-host-name myhostname --bpc-share-name / --bpc-bkup-num
125 --bpc-bkup-comp 3 --bpc-bkup-prevnum -1 --bpc-bkup-prevcomp -1
--bpc-bkup-inode0 175597 --bpc-attrib-new --bpc-log-level 0 -e /usr/bin/ssh\
-l\ mycompany_backup --rsync-path=/usr/bin/sudo\ /usr/bin/rsync --super
--recursive --protect-args --numeric-ids --perms --owner --group -D --times
--links --hard-links --delete --delete-excluded --one-file-system --partial
--log-format=log:\ %o\ %i\ %B\ %8U,%8G\ %9l\ %f%L --stats --checksum
--timeout=72000 --exclude=/mnt --exclude=/proc --exclude=/dev --exclude=/sys
--exclude=/var/lib/pgsql/\*/data/base --exclude=/var/lib/pgsql/\*/data/pg_wal
--exclude=/var/lib/mysql/\*/\* --exclude=/var/lib/mysql/ibdata\*
--exclude=/var/lib/mysql/ib_logfile\* --exclude=/var/lib/BackupPC/\*
--exclude=/var/mycompany/mysql/mariabackup/tmp_export
--exclude=/mariabackup/tmp_export myhostname:/ /
Xfer PIDs are now 1143,1147
xferPids 1143,1147
xferPids 1143,1147
__bpc_progress_fileCnt__ 1
__bpc_progress_fileCnt__ 21
(...)
Best regards,
Pim Rupert
_______________________________________________
BackupPC-users mailing list
BackupPC-users@lists.sourceforge.net
List: https://lists.sourceforge.net/lists/listinfo/backuppc-users
Wiki: http://backuppc.wiki.sourceforge.net
Project: http://backuppc.sourceforge.net/
