BackupPC

References

rsync

• How Rsync works
• A patch for rsync about computing and caching checksums

Install and configuration

ntfs-3g backups

When backing up ntfs-3g shares, the option --links and --hard-links must be removed from RsyncArgs and RsyncRestoreArgs (see troubleshooting section below)

Since these options are common to a same client, one must create a separate backuppc client if a given physical host contains both ntfs-3g and non-ntfs-3g partitions. In that case, one client will match the name of the host, where others will have different names. For these clients, set the variable ClientNameAlias to the name of the physical host in the client configuration.

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)

FIXED - rsync_bpc keep transfering same file on ntfs-3g mount

SOLUTION: Remove options --links and --hard-links when backing up ntfs-3g partitions !!!

Setup

• /c is a ntfs-3g mount. Content of /etc/fstab:

UUID=445E1B975E1B813A 				/c              ntfs    ro,defaults,nls=utf8,umask=007,gid=46 0       0

• To test this, add to /etc/rsyncd.conf:

+[test1]
+comment = Test share 1
+path = /c/Boot

• In a separate window, monitor the rsyncd log file:

tail -f /var/log/rsync.log

• Create rsync password file:

sudo -v; sudo sed -r 's/^.*://' /etc/rsyncd.secrets | sudo tee /tmp/rsyncd.secrets > /dev/null; sudo chmod 600 /tmp/rsyncd.secrets

Test case one - using rsync

• Initialize:

sudo rm -rf /tmp/rsynctest; sudo mkdir /tmp/rsynctest

• Repeat the following step, and observe that files are only txfed the first time:

sudo rsync --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=/tmp/rsyncd.secrets \ 
--checksum backuppc@griffin::test1 /tmp/rsynctest

Test case two - using rsync_bpc on ntfs-3g share

• Initialize:

sudo rm -rf /tmp/rsynctest; sudo mkdir -p /tmp/rsynctest/cpool; i=0

• Repeat the following step, and observe that files are always txfed:

cd /tmp/rsynctest; i=$((i+1)); echo backup $i; sudo cp -ar pc/griffin/$((i-1)) pc/griffin/$i; \
sudo rsync_bpc --bpc-top-dir /tmp/rsynctest --bpc-host-name griffin --bpc-share-name test1 --bpc-bkup-num $i \
--bpc-bkup-comp 3 --bpc-bkup-prevnum $((i-1)) --bpc-bkup-prevcomp 3 --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=/tmp/rsyncd.secrets backuppc@griffin::test1 /

Increase --bpc-log-level (say set it to 9) to get more debug output.

Test case three - using rsync_bpc on other share

• Edit /etc/rsyncd.conf such that share test1 no longer points to an ntfs-3g mount point. For instance:

 [test1]
 comment = Test share 1
-path = /c/Boot
+path = /boot

• Run step above, and observe that files are only txfed once.
• If running other cases, reset share to ntfs-3g:

 [test1]
 comment = Test share 1
-path = /boot
+path = /c/Boot

Test case fourth - rsync_bpc + ntfs-3g that works

• Initialize:

sudo rm -rf /tmp/rsynctest; sudo mkdir -p /tmp/rsynctest/cpool; i=0

• Repeat the following step, and observe that files are only txfed the first time when removing parameters --links --hard-links:

cd /tmp/rsynctest; i=$((i+1)); echo backup $i; sudo cp -ar pc/griffin/$((i-1)) pc/griffin/$i; \
sudo rsync_bpc --bpc-top-dir /tmp/rsynctest --bpc-host-name griffin --bpc-share-name test1 --bpc-bkup-num $i \
--bpc-bkup-comp 3 --bpc-bkup-prevnum $((i-1)) --bpc-bkup-prevcomp 3 --bpc-log-level 3  --super --recursive \
--protect-args --numeric-ids --perms --owner --group -D --times --delete --partial \
--log-format='log: %o %i %B %8U,%8G %9l %f%L' --stats --modify-window=5 --one-file-system \
--password-file=/tmp/rsyncd.secrets backuppc@griffin::test1 /