BackupPC

From miki
Jump to navigation Jump to search

References

rsync

Troubleshooting

Broken pipe

Typical errors:

rsync_bpc: writefd_unbuffered failed to write 426 bytes to message fd [receiver]: Broken pipe (32)
Possible causes and solutions
  • Happens more frequently with big files, but some small files fail too. Not always the same file
  • Timeout issue
  • Firewall
  • Lots of packet loss / reject. The following iptable route might help [1]:
iptables -I {line} -p tcp --tcp-flags SYN,RST,ACK,FIN ACK -j ACCEPT


Links
  • Interesting discussion on samba.org, with troubleshooting ideas.
  strace -tt -f -o /tmp/rsync-$$.out rsync \
        --verbose \
        --exclude "stor/hosts" \
        --exclude "var/run" \
        --exclude "var/spool" \
        --rsh="ssh -p $backoff_port" \
        --rsync-path="sudo /usr/local/bin/rsync-debug" \
        --recursive \
        --links \
        --perms \
        --times \
        --owner \
        --group \
        --numeric-ids \
        --xattrs \
        --delete \
        --compress \
        --human-readable \
        --stats \
        --exclude='udat/backup*/*' \
        --exclude='udat/migrate/*' \
        /mnt/stor \
        $userid@$backoff_url:$destdir 2>&1

Issues on Lacie-Cloud

Broken pipe, etc

I get failed backup on the lacie-cloud server; I log my findings / tests here.

The current rsync command line is:

/opt/bin/rsync_bpc --bpc-top-dir /shares/backuppc --bpc-host-name zavcxl0005 --bpc-share-name home \
--bpc-bkup-num 1 --bpc-bkup-comp 3 --bpc-bkup-prevnum -1 --bpc-bkup-prevcomp -1 --bpc-bkup-inode0 567 \
--bpc-log-level 3 --super --recursive --protect-args --numeric-ids --perms --owner --group -D --times \
--links --hard-links --delete --partial --log-format=log: %o %i %B %8U,%8G %9l %f%L --stats \
--modify-window=5 --one-file-system --password-file=/shares/backuppc/pc/zavcxl0005/.rsyncdpw6801 \
--exclude=.cache --exclude=.recoll --exclude=.gvfs --exclude=.thumbnails --exclude=.Trash* \
--exclude=*.nobak --exclude=.*.nobak --exclude=.opera/cache --exclude=Snapshots --exclude=Cache \
--exclude=Dropbox --exclude=$RECYCLE.BIN --exclude=$Recycle.Bin --exclude=System Volume Information \
--exclude=lost+found backuppc@zavcxl0005::home /
Notes
  • Still use the old parameter --log-format, which has been deprecated and renamed to --out-format in newer rsync version.

Zombie rsync_bpc processes

I have two processes still running on lacie-cloudbox:

[root@LaCie-CloudBox ~]# /opt/bin/ps faux | grep rsync
Unknown HZ value! (73) Assume 100.
root      2249  0.0  0.0   4748     4 ?        Ss   Jun14   0:00 /usr/bin/rsync --daemon --config=/etc/rsyncd.conf --no-detach
root     26783  0.0  0.3   3608   916 pts/0    S+   20:46   0:00          \_ grep rsync
backuppc  5746  1.5  0.0  85764    56 ?        S    10:24   9:41      \_ /opt/bin/rsync_bpc --bpc-top-dir /shares/backuppc --bpc-host-name graphicdaemon --bpc-share-name d --bpc-bkup-num 213 --bpc-bkup-comp 3 --bpc-bkup-prevnum 212 --bpc-bkup-prevcomp 3 --bpc-bkup-inode0 9109 --bpc-log-level 3 --super --recursive --protect-args --numeric-ids --perms --owner --group -D --times --links --hard-links --delete --partial --log-format=log: %o %i %B %8U,%8G %9l %f%L --stats --modify-window=5 --checksum --one-file-system --password-file=/shares/backuppc/pc/graphicdaemon/.rsyncdpw3449 --exclude=.cache --exclude=.recoll --exclude=.gvfs --exclude=.thumbnails --exclude=.Trash* --exclude=*.nobak --exclude=.*.nobak --exclude=.opera/cache --exclude=Cache --exclude=Dropbox --exclude=Snapshots --exclude=$RECYCLE.BIN --exclude=$Recycle.Bin --exclude=System Volume Information --exclude=lost+found backuppc@graphicdaemon::d /
backuppc  5779 12.7  0.0  77872    56 ?        S    10:25  78:57          \_ /opt/bin/rsync_bpc --bpc-top-dir /shares/backuppc --bpc-host-name graphicdaemon --bpc-share-name d --bpc-bkup-num 213 --bpc-bkup-comp 3 --bpc-bkup-prevnum 212 --bpc-bkup-prevcomp 3 --bpc-bkup-inode0 9109 --bpc-log-level 3 --super --recursive --protect-args --numeric-ids --perms --owner --group -D --times --links --hard-links --delete --partial --log-format=log: %o %i %B %8U,%8G %9l %f%L --stats --modify-window=5 --checksum --one-file-system --password-file=/shares/backuppc/pc/graphicdaemon/.rsyncdpw3449 --exclude=.cache --exclude=.recoll --exclude=.gvfs --exclude=.thumbnails --exclude=.Trash* --exclude=*.nobak --exclude=.*.nobak --exclude=.opera/cache --exclude=Cache --exclude=Dropbox --exclude=Snapshots --exclude=$RECYCLE.BIN --exclude=$Recycle.Bin --exclude=System Volume Information --exclude=lost+found backuppc@graphicdaemon::d /

[root@LaCie-CloudBox ~]# netstat -ane | grep 100.117        
netstat: /proc/net/tcp6: No such file or directory
tcp        0      0 172.19.100.98:49947     172.19.100.117:873      ESTABLISHED 
netstat: /proc/net/udp6: No such file or directory
netstat: /proc/net/raw6: No such file or directory

But the rsyncd daemon on the server failed since 10:46 am:

$ sudo netstat -pna|grep 100.98
$ tail /var/log/rsync.log 
2015/06/19 10:04:31 [2917] send lacie-cloudbox [172.19.100.98] d (backuppc) Games/World_of_Tanks/res/packages/hangar_premium_v2.pkg 28914772
2015/06/19 10:04:31 [2917] send lacie-cloudbox [172.19.100.98] d (backuppc) Games/World_of_Tanks/res/packages/hangar_v2.pkg 27720752
2015/06/19 10:07:43 [2917] send lacie-cloudbox [172.19.100.98] d (backuppc) Games/World_of_Tanks/res/packages/misc.pkg 752868269
2015/06/19 10:12:46 [2917] send lacie-cloudbox [172.19.100.98] d (backuppc) Games/World_of_Tanks/res/packages/shaders.pkg 4879357
2015/06/19 10:17:52 [2917] send lacie-cloudbox [172.19.100.98] d (backuppc) Games/World_of_Tanks/res/packages/shared_content.pkg 950719654
2015/06/19 10:17:52 [2917] send lacie-cloudbox [172.19.100.98] d (backuppc) Games/World_of_Tanks/res/packages/shared_content.prefetch 394119
2015/06/19 10:24:52 [2917] send lacie-cloudbox [172.19.100.98] d (backuppc) Games/World_of_Tanks/res/packages/vehicles_level_01.pkg 36603536
2015/06/19 10:27:20 [2917] send lacie-cloudbox [172.19.100.98] d (backuppc) Games/World_of_Tanks/res/packages/vehicles_level_02.pkg 276573347
2015/06/19 10:46:28 [2917] rsync: [sender] write error: Invalid argument (22)
2015/06/19 10:46:28 [2917] rsync error: error in socket IO (code 10) at io.c(837) [sender=3.1.0]
$ ps faux | grep rsync
isma      8126  0.0  0.0  14776   944 pts/0    S+   20:51   0:00              \_ grep rsync

Checking the client log on lacie-cloudbox (using BackupPC_zcat to decompress), we actually observe that the log is truncated much before the rsyncd log. So it seems the client broke but did not exit. So adding param --timeout to rsync client might not help here.

bpc_fileOpen: can't open pool file

I get for each backup the same error message:

    same   recv >f......... rwxrwx---        0,      46       640 Windows/winsxs/FileMaps/$$_ime_fr-fr_0d349902e45b4cea.cdf-ms
G bpc_fileOpen: can't open pool file /shares/backuppc/cpool/f8/02/f803002e8050e1931403001000000000 (from Windows/winsxs/Manifests/amd64_prnin004.inf-languagepack_31bf3856ad364e35_6.1.7600.16385_en-us_426884f5a0a5f5a4.manifest, 3, 16)
rsync_bpc: failed to open "/Windows/winsxs/Manifests/amd64_prnin004.inf-languagepack_31bf3856ad364e35_6.1.7600.16385_en-us_426884f5a0a5f5a4.manifest", continuing: No such file or directory (2)
    same   recv >f......... rwxrwx---        0,      46      2136 Windows/winsxs/FileMaps/$$_ime_imejp10_dicts_281006c600450618.cdf-ms

The problem is not solved at next backup. A similar problem is reported by another user on backuppc-users mailing list [2].

Stale transfer

Some troubleshooting commands [3]:

strace -p $PID
lsof -f | grep rsync                          # and the following to confirm)