BackupPC-users

Re: [BackupPC-users] Bug in Backuppc causing unnecessary re-transfer of data with rsync

2009-07-23 15:36:34
Subject: Re: [BackupPC-users] Bug in Backuppc causing unnecessary re-transfer of data with rsync
From: Chris Robertson <crobertson AT gci DOT net>
To: "General list for user discussion, questions and support" <backuppc-users AT lists.sourceforge DOT net>
Date: Thu, 23 Jul 2009 11:31:53 -0800
Adam Goryachev wrote:
> One of my remote server being backed up had a very large log file, which
> was growing rather quickly (4GB growing at 2k/sec). This caused the
> backup to timeout sometimes...
>
> Anyway, see an extract of the log file which 'causes' the problem:
> Executing DumpPreUserCmd: /etc/backuppc/scripts/host1tunnel-start.sh
> incr backup started back to 2009-07-19 00:24:59 (backup #336) for
> directory cdrive
> Connected to 127.0.0.1:1515, remote version 29
> Negotiated protocol version 28
> Connected to module cdrive
> Sending args: --server --sender --numeric-ids --perms --owner --group -D
> - --links --times --block-size=2048 --recursive -D --checksum-seed=32761
> - --one-file-s
> ystem --bwlimit=26 . .
> Checksum caching enabled (checksumSeed = 32761)
> Sent exclude: PartImage
> Sent exclude: hcn/BACKUP
> Sent exclude: hcn/Backups
> Sent exclude: users/Michael
> Sent exclude: users/User1
> Xfer PIDs are now 12320
>   create d 755    18/544           0 .
>   create d 755    18/544           0 AVPDOS
>   create d 755    18/544           0 BCBackup
>   create d 755    18/544           0 BCBackup/BlueData
> etc, continues as per normal until:
>   create d 755    18/544           0 Program Files/eScan/Updater
>   create d 755    18/544           0 Program Files/eScan/VXP64
>   create d 755    18/544           0 Program Files/eScan/Vista
>   create d 755    18/544           0 Program Files/eScan/Vista/AVCBack
>   create   644    18/544       17771 Program
> Files/eScan/Vista/AVCBack/avp._et
>   create   644    18/544      122214 Program
> Files/eScan/Vista/AVCBack/avp._lb
>   create   644    18/544       17771 Program
> Files/eScan/Vista/AVCBack/avp_ext._et
>   create   644    18/544       17771 Program
> Files/eScan/Vista/AVCBack/avp_x._et
> Read EOF:
> Tried again: got 0 bytes
>   

This indicates there was a problem with the connection.  While trying to 
synchronize "Program Files/eScan/Vista/AVCBack/avp_x.et" an End Of File 
was unexpectedly encountered.  The transfer was attempted again, but no 
data was received.  I usually see this when my SSH connection (between 
my BackupPC server and the client) is interrupted.  Since this was an 
incremental backup...

> finish: removing in-process file Program
> Files/eScan/Vista/AVCBack/base279c._vc
>   delete   644    18/544       54207 Program
> Files/eScan/Vista/AVCBack/base319c._vc
>   delete   644    18/544       50464 Program
> Files/eScan/Vista/AVCBack/base649c._vc
>   delete   644    18/544      165934 Program
> Files/eScan/Vista/AVCBack/fa001._vc
>   delete   644    18/544       53160 Program
> Files/eScan/Vista/AVCBack/base675c._vc
>   delete   644    18/544       49358 Program
> Files/eScan/Vista/AVCBack/unp037._vc
>   delete   644    18/544       41666 Program
> Files/eScan/Vista/AVCBack/base772c._vc
>   delete   644    18/544       50984 Program
> Files/eScan/Vista/AVCBack/base475c._vc
>   delete   644    18/544       52555 Program
> Files/eScan/Vista/AVCBack/base421c._vc
>   delete   644    18/544       51594 Program
> Files/eScan/Vista/AVCBack/base641c._vc
>
> - From here on, all the files in this directory are "delete" even though
> they were never removed from the system and then:
>
>   delete d 755    18/544           0 System Volume Information
>   delete   644    18/544         211 boot.ini
>   delete   444    18/544      297072 ntldr
>   delete d 755    18/544           0 RECYCLER
>   delete   644    18/544       24064 Walter.doc
>   delete d 755    18/544           0 hcn
>   delete d 755    18/544           0 rsyncd
>   delete d 755    18/544           0 myob12
>   delete d 755    18/544           0 TEMP
>   delete d 755    18/544           0 users
>   delete d 755    18/544           0 var
>   delete d 755    18/544           0 TempData
>   delete   644    18/544         208 bootini.ins
>   delete d 755    18/544           0 wmpub
>   delete d 755    18/544           0 WINDOWS
>   delete d 755    18/544           0 cygwin
>   delete   644    18/544         248 back.cmd
>   delete d 755    18/544           0 TempEI4
>   delete   644    18/544         522 RHDSetup.log
> Child is aborting
> Done: 74 files, 4334969856 bytes
>   

...it is aborted, and thrown away.

> ie, all the remaining directories are also deleted.
>
> I'm using BackupPC 3.1.0 from Debian Lenny, connecting to a windows box
> running rsyncd via SSH running on a Debian Etch box on the same subnet
> as the windows box.
>
> Linux (Backuppc) --SSH--> Linux (middle) --rsyncd--> Windows 2003 Server
>
> Obviously the windows directory itself didn't vanish especially.
>
> So, the problem is the following day, the backup will use this
> incremental as it's basis (IncrLevels = [1,2,3,4,5,6,7,8,9]) and so all
> files will be re-downloaded and 'pooled' like this:
>   

Why are the files being transfered if they are in the pool?  Are they 
pooled from another computer's backup?

>   pool     644    18/544      126206 Program
> Files/eScan/Vista/AVCBack/base279c._vc
>   pool     644    18/544       50441 Program
> Files/eScan/Vista/AVCBack/base280c._vc
>   pool     644    18/544       49835 Program
> Files/eScan/Vista/AVCBack/base281c._vc
>   pool     644    18/544       56395 Program
> Files/eScan/Vista/AVCBack/base282c._vc
>   pool     644    18/544       48297 Program
> Files/eScan/Vista/AVCBack/base283c._vc
>   pool     644    18/544       48586 Program
> Files/eScan/Vista/AVCBack/base284c._vc
>   pool     644    18/544       49252 Program
> Files/eScan/Vista/AVCBack/base285c._vc
>   pool     644    18/544       48126 Program
> Files/eScan/Vista/AVCBack/base286c._vc
>   pool     644    18/544       49125 Program
> Files/eScan/Vista/AVCBack/base287c._vc
>   pool     644    18/544       49124 Program
> Files/eScan/Vista/AVCBack/base288c._vc
>   pool     644    18/544       50316 Program
> Files/eScan/Vista/AVCBack/base289c._vc
>   pool     644    18/544       50531 Program
> Files/eScan/Vista/AVCBack/base290c._vc
> etc, same for all files until the end of the backup.
>
> Any hints/suggestions on how to resolve this would be appreciated, if
> more information is required, please let me know.
>   

Well, you might refrain from backing up a large and rapidly changing log 
file...

> Regards,
> Adam
>
> - --
> Adam Goryachev
> Website Managers
> www.websitemanagers.com.au
>   

Chris


------------------------------------------------------------------------------
_______________________________________________
BackupPC-users mailing list
BackupPC-users AT lists.sourceforge DOT net
List:    https://lists.sourceforge.net/lists/listinfo/backuppc-users
Wiki:    http://backuppc.wiki.sourceforge.net
Project: http://backuppc.sourceforge.net/