BackupPC-users

Re: [BackupPC-users] BackupPC 4.0.0 Alpha 3

2014-10-21 16:03:45
Subject: Re: [BackupPC-users] BackupPC 4.0.0 Alpha 3
From: Adam Goryachev <mailinglists AT websitemanagers.com DOT au>
To: backuppc-users AT lists.sourceforge DOT net
Date: Wed, 22 Oct 2014 07:01:10 +1100
Hi all,

I'm still having problems getting backups for a number of hosts using 
backuppc 4.0.0 alpha 3

Contents of file /var/lib/backuppc/pc/blackbar/XferLOG.1732.z, modified 
2014-10-21 21:24:15 (Extracting only Errors)

XferLOG file /var/lib/backuppc/pc/blackbar/XferLOG.1732.z created 
2014-10-11 15:28:36
Backup prep: type = full, case = 2, inPlace = 1, doDuplicate = 1, 
newBkupNum = 1732, newBkupIdx = 51, lastBkupNum = , lastBkupIdx = 
(FillCycle = 0, noFillCnt = 2)
Executing /usr/share/backuppc/bin/BackupPC_backupDuplicate -h blackbar
Copying v3 backup #1731 to v4 #1732
BackupPC_backupDuplicate: got 0 errors and 0 file open errors
Running: /usr/local/bin/rsync_bpc --bpc-top-dir /var/lib/backuppc 
--bpc-host-name blackbar --bpc-share-name /e --bpc-bkup-num 1732 
--bpc-bkup-comp 9 --bpc-bkup-prevnum -1 --bpc-bkup-prevcomp -1 
--bpc-bkup-inode0 90003 --bpc-log-level 1 -e /usr/bin/ssh -C -q -x -l 
root --rsync-path=/usr/bin/rsync --numeric-ids --perms --owner --group 
--devices --links --times --block-size=2048 --recursive 
--checksum-seed=32761 -D --one-file-system --checksum blackbar:/e/ /
full backup started for directory /e
Xfer PIDs are now 9457
This is the rsync child about to exec /usr/local/bin/rsync_bpc
cmdExecOrEval: about to exec /usr/local/bin/rsync_bpc --bpc-top-dir 
/var/lib/backuppc --bpc-host-name blackbar --bpc-share-name /e 
--bpc-bkup-num 1732 --bpc-bkup-comp 9 --bpc-bkup-prevnum -1 
--bpc-bkup-prevcomp -1 --bpc-bkup-inode0 90003 --bpc-log-level 1 -e 
/usr/bin/ssh\ -C\ -q\ -x\ -l\ root --rsync-path=/usr/bin/rsync 
--numeric-ids --perms --owner --group --devices --links --times 
--block-size=2048 --recursive --checksum-seed=32761 -D --one-file-system 
--checksum blackbar:/e/ /
Xfer PIDs are now 9457,9459
xferPids 9457,9459
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/fautorun.inf
 
(from 36f60f419e433e155ecbd44b87848e/autorun.inf, 9, 0)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/fautorun.inf
 
(from 36f60f419e433e155ecbd44b87848e/autorun.inf, 9, 0)
rsync_bpc: failed to open "/36f60f419e433e155ecbd44b87848e/autorun.inf", 
continuing: No such file or directory (2)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/freadme.txt
 
(from 36f60f419e433e155ecbd44b87848e/readme.txt, 9, 0)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/freadme.txt
 
(from 36f60f419e433e155ecbd44b87848e/readme.txt, 9, 0)
rsync_bpc: failed to open "/36f60f419e433e155ecbd44b87848e/readme.txt", 
continuing: No such file or directory (2)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/freadmesql2k32desksp4.htm
 
(from 36f60f419e433e155ecbd44b87848e/readmesql2k32desksp4.htm, 9, 0)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/freadmesql2k32desksp4.htm
 
(from 36f60f419e433e155ecbd44b87848e/readmesql2k32desksp4.htm, 9, 0)
rsync_bpc: failed to open 
"/36f60f419e433e155ecbd44b87848e/readmesql2k32desksp4.htm", continuing: 
No such file or directory (2)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/fsetup.exe
 
(from 36f60f419e433e155ecbd44b87848e/setup.exe, 9, 0)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/fsetup.exe
 
(from 36f60f419e433e155ecbd44b87848e/setup.exe, 9, 0)
rsync_bpc: failed to open "/36f60f419e433e155ecbd44b87848e/setup.exe", 
continuing: No such file or directory (2)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/fsetup.ini
 
(from 36f60f419e433e155ecbd44b87848e/setup.ini, 9, 0)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/fsetup.ini
 
(from 36f60f419e433e155ecbd44b87848e/setup.ini, 9, 0)
rsync_bpc: failed to open "/36f60f419e433e155ecbd44b87848e/setup.ini", 
continuing: No such file or directory (2)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/fsetup.rll
 
(from 36f60f419e433e155ecbd44b87848e/setup.rll, 9, 0)
G bpc_fileOpen: can't open V3 file 
/var/lib/backuppc/pc/blackbar/1732/f%2fe/f36f60f419e433e155ecbd44b87848e/fsetup.rll
 
(from 36f60f419e433e155ecbd44b87848e/setup.rll, 9, 0)


Can anyone please advise why I'm getting the above errors, why they 
don't get fixed (either by re-downloading the file or else skipping the 
file), so that at least all the other files will be properly backed up?

I wrote a lengthy analysis below, which I now think is completely bogus. 
Probably the method I used to calculate the pool file was wrong, and 
that's why the files didn't seem to exist in the pool.

The only other thing I can think of doing is to create a new host, and 
start a fresh backup, hoping that all the content of the V3 pool will 
still be used (actually, I'm pretty sure they won't, since the MD5 is 
calculated wrong). So the only way I could do that is to somehow convert 
the V3 pool into a V4 pool, or do a complete restore from the last 
proper full, and then let that directory get backed up by the localhost. 
Will try this if I don't get any other good suggestions soon.

Thanks,
Adam

On 12/10/14 04:11, Adam Goryachev wrote:
> Please see a rather lengthy and perhaps overly complicated discussion on
> what could be a problem with the V4 alpha3.
>
> I've recently upgraded from BackupPC v3.2.1 to BackupPC 4.0.0Alpha 3
>
> I'm seeing a lot of messages like this:
>
> __bpc_progress_fileCnt__ 36041
> __bpc_progress_fileCnt__ 36061
> G bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
> (from var/lib/dpkg/info/zlib1g:i386.postinst, 9, 0)
> G bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
> (from var/lib/dpkg/info/zlib1g:i386.postinst, 9, 0)
> rsync_bpc: failed to open "/var/lib/dpkg/info/zlib1g:i386.postinst",
> continuing: No such file or directory (2)
> G bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postrm
> (from var/lib/dpkg/info/zlib1g:i386.postrm, 9, 0)
> G bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postrm
> (from var/lib/dpkg/info/zlib1g:i386.postrm, 9, 0)
> rsync_bpc: failed to open "/var/lib/dpkg/info/zlib1g:i386.postrm",
> continuing: No such file or directory (2)
> __bpc_progress_fileCnt__ 36081
> R bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/fcache/fman/fda/findex.db
> (from var/cache/man/da/index.db, 9, 0)
> R bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/fcache/fman/fda/f.index.db.000000
> (from var/cache/man/da/.index.db.000000, 9, 0)
> rsync_bpc: mkstemp "/var/cache/man/da/.index.db.000000" failed: No such
> file or directory (2)
> R bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/fcache/fman/fsl/findex.db
> (from var/cache/man/sl/index.db, 9, 0)
> R bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/fcache/fman/fsl/f.index.db.000000
> (from var/cache/man/sl/.index.db.000000, 9, 0)
> rsync_bpc: mkstemp "/var/cache/man/sl/.index.db.000000" failed: No such
> file or directory (2)
> __bpc_progress_fileCnt__ 36101
> __bpc_progress_fileCnt__ 36121
> __bpc_progress_fileCnt__ 36141
> [SNIP]
> R bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
> (from var/lib/dpkg/info/zlib1g:i386.postinst, 9, 0)
> R bpc_fileOpen: can't open V3 file
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postrm
> (from var/lib/dpkg/info/zlib1g:i386.postrm, 9, 0)
> R bpc_sysCall_checkFileMatch(var/lib/dpkg/triggers/Lock): couldn't
> unmark pool file
> /var/lib/backuppc/cpool/d4/1c/d41d8cd98f00b204e9800998ecf8427e - rewriting
> __bpc_progress_fileCnt__ 36561
> __bpc_progress_fileCnt__ 36581
> Done: 185 errors, 98 filesExist, 96863484 sizeExist, 26854849
> sizeExistComp, 0 filesTotal, 0 sizeTotal, 49 filesNew, 90478572 sizeNew,
> 32585824 sizeNewComp, 40055 inode
> DoneGen: 362 errors, 0 filesExist, 0 sizeExist, 0 sizeExistComp, 36588
> filesTotal, 1146156705 sizeTotal, 0 filesNew, 0 sizeNew, 0 sizeNewComp,
> 39680 inode
> rsync error: some files/attrs were not transferred (see previous errors)
> (code 23) at main.c(1542) [generator=3.0.9.3]
> rsync_bpc exited with benign status 23 (5888)
>
> Which comes from this section of the code:
>          /*
>           * need to read existing file
>           */
>          if ( file->digest.len > 0 ) {
>              /*
>               * all non-empty V4+ files have digests, so use the digest
> to look in the pool
>               */
>              bpc_digest_md52path(fullPath, file->compress, &file->digest);
>              if ( bpc_fileZIO_open(&fdz, fullPath, 0, file->compress) ) {
>                  bpc_logErrf("bpc_fileOpen: can't open pool file %s (from
> %s, %d, %d)\n", fullPath, fd->fileName, file->compress, file->digest.len);
>                  Stats.ErrorCnt++;
>                  bpc_fileDescFree(fd);
>                  return NULL;
>              }
>          } else {
>              /*
>               * must be a V3 file - look in the backup directory
>               */
>              bpc_attribCache_getFullMangledPath(&acNew, fullPath,
> (char*)fileName, file->backupNum);
>              if ( bpc_fileZIO_open(&fdz, fullPath, 0, file->compress) ) {
>                  bpc_logErrf("bpc_fileOpen: can't open V3 file %s (from
> %s, %d, %d)\n", fullPath, fd->fileName, file->compress, file->digest.len);
>                  Stats.ErrorCnt++;
>                  bpc_fileDescFree(fd);
>                  return NULL;
>
>
> >From my limited understanding, this says that it should be one of the
> old V3 files (most likely correct), but seems to suggest it failed to
> read the content of the file. Now after seeing the error, I checked, and
> indeed the file does not exist:
> keep:/var/lib/backuppc/pc/filesrv# ls -l
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
> ls: cannot access
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst:
> No such file or directory
>
> However, I can see the file DID exist in older backups:
> keep:/var/lib/backuppc/pc/filesrv# ls -l
> /var/lib/backuppc/pc/hostname/185?/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
> -rwxr-x--- 59299 backuppc backuppc 184 Mar  9  2009
> /var/lib/backuppc/pc/hostname/1850/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
> -rwxr-x--- 59299 backuppc backuppc 184 Mar  9  2009
> /var/lib/backuppc/pc/hostname/1853/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
>
> BTW, 1850 and 1853 were full backups from V3, 1854 is the first V4
> backup being run
>
> So, why didn't the file get copied along with all the other files before
> the backup started?
> There were no reported errors during the copy stage:
> BackupPC_backupDuplicate: got 0 errors and 0 file open errors
>
> So, my obvious concern is that there is some error where files are not
> copied during the duplicate stage, and then during the backup stage
> those files are not re-created (ie, backed up)
>
> I can see:
> /usr/share/backuppc/bin/BackupPC_attribPrint
> /var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/attrib
> [SNIP]
>    'zlib1g:i386.postinst' => {
>      'compress' => 9,
>      'digest' => '5d0e769df33e016b3c52a0971e8d258c',
>      'gid' => 0,
>      'inode' => 40049,
>      'mode' => 493,
>      'mtime' => 1340384585,
>      'name' => 'zlib1g:i386.postinst',
>      'nlinks' => 0,
>      'size' => 135,
>      'type' => 0,
>      'uid' => 0
>    },
> [SNIP]
> So this seems to be the problem:
> ls -l /var/lib/backuppc/cpool/5/d/0/5d0e769df33e016b3c52a0971e8d258c
> ls: cannot access
> /var/lib/backuppc/cpool/5/d/0/5d0e769df33e016b3c52a0971e8d258c: No such
> file or directory
>
> /usr/share/backuppc/bin/BackupPC_zcat
> /var/lib/backuppc/pc/hostname/1853/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
> #!/bin/sh
> set -e
> # Automatically added by dh_makeshlibs
> if [ "$1" = "configure" ]; then
>      ldconfig
> fi
> # End automatically added section
>
> So, we can see the file existed in the previous full backup, can still
> be decompressed, but seems to be missing from the pool.
> Here is the information from the old attrib file:
>    'zlib1g:i386.postinst' => {
>      'compress' => 9,
>      'digest' => '',
>      'gid' => 0,
>      'inode' => 0,
>      'mode' => 33261,
>      'mtime' => 1340384585,
>      'name' => 'zlib1g:i386.postinst',
>      'nlinks' => 0,
>      'size' => 135,
>      'type' => 0,
>      'uid' => 0
>    },
>
> Also, uncompressing the old file, and then computing the full file md5:
> /usr/share/backuppc/bin/BackupPC_zcat `pwd`/fzlib1g:i386.postinst >
> /tmp/zlib1g:i386.postinst
> md5sum /tmp/zlib1g\:i386.postinst
> 5d0e769df33e016b3c52a0971e8d258c  /tmp/zlib1g:i386.postinst
>
> The MD5 seems to match what backuppc 4 is expecting.
>
> So, why is the pool file missing, and why doesn't this get fixed? I
> suspect what will happen is that backuppc v4 would continue to report
> this "error" on every future backup, but never actually fix it.
> Eventually all old V3 backups will be deleted, and after that I won't be
> able to recover the file (assuming this wasn't a standard OS file that I
> can simply re-download and install, eg, if it was some document that I
> had created/etc).
>
> I seem to have this same issue with a number of other hosts (but not
> every host has the problem, and most files are working correctly).
>
> One thought to fix this would be to simply hardlink the file into the
> pool from the old backups...
>
> Error message:
> missing=/var/lib/backuppc/pc/hostname/1854/f%2f/fvar/flib/fdpkg/finfo/fzlib1g:i386.postinst
> pcdir=`echo $missing | cut -d/ -f1-6`
> cd $pcdir
> bkup=`echo $missing | awk -F/ '{ print $7 }'`
> prevbkup=`grep full backups|grep -B1 $bkup| head -1|awk '{ print $1 }'`
> file=`echo $missing | cut -d/ -f8-`
> if [ -f $prevbkup/$file ]
> then
>      #find the md5, and then link into the pool
>      attrib=`dirname $missing`/attrib
>      missingfile=`basename $missing | sed -e s/^f//`
>      digest=`/usr/share/backuppc/bin/BackupPC_attribPrint $attrib | egrep
> "$missingfile. =>|digest" | grep -A1 $missingfile|grep digest|awk -F\'
> '{print $4 }'`
>      # confirm it is missing from the pool both V4 and V3
>      v4one=`echo $digest | cut -c-2`
>      v4two=`echo $digest | cut -c3-4`
>      if [ -f /var/lib/backuppc/cpool/$v4one/$v4two/$digest ]
>      then
>          echo "ERROR: The pool file already exists... check this
> manually: $missing"
>      else
>          v3one=`echo $digest | cut -c1`
>          v3two=`echo $digest | cut -c2`
>          v3three=`echo $digest | cut -c3`
>          if [ -f /var/lib/backuppc/cpool/$v3one/$v3two/$v3three/$digest ]
>          then
>              echo "ERROR: The pool file already exists... check this
> manually: $missing"
>          else
>              # Create the needed directory
>              mkdir -p /var/lib/backuppc/cpool/$v4one/$v4two
>              # Actually link the file from the previous backup to the pool
>              ln $prevbkup/$file /var/lib/backuppc/cpool/$v4one/$v4two/$digest
>          fi
>
> else
>      echo "ERROR: Couldn't fix missing file, please correct manually:
> $missing"
> fi
>
> Ooops, I think I've worked out the common factor for the "missing"
> files. It's the number of hardlinks. I've checked a number of them, and
> they all have a large number of existing links:
> stat fzlib1g:i386.postinst
>    File: `fzlib1g:i386.postinst'
>    Size: 184           Blocks: 8          IO Block: 4096   regular file
> Device: 903h/2307d    Inode: 23963       Links: 59300
> Access: (0750/-rwxr-x---)  Uid: (  104/backuppc)   Gid: (  106/backuppc)
> Access: 2014-10-12 02:58:23.000000000 +1100
> Modify: 2009-03-09 18:35:31.000000000 +1100
> Change: 2014-10-12 03:40:57.000000000 +1100
>   Birth: -
>
> In fact, some files have over 60000 links.
> My /etc/backuppc/config.pl includes this line:
> $Conf{HardLinkMax} = '999999';
> So, having over 60000 hard links should not be an issue.
>
> Well, now I'm still rather confused... Reading through
> BackupPC_backupDuplicate I'm thinking that really the whole v4 is not
> relevent, because v3 should have created the link in the cpool (V3
> cpool) anyway, and so the question is why did that fail?
>
> Equally, regardless of why the pool file is missing, v4 should be
> ensuring that the pool file exists.... That way the problem will at
> least get repaired (eg, imagine some issue where some pool files
> vanished by mistake, it seems this would never be repaired/discovered),
> not that I've tested that.
>
> I'd appreciate any suggestions on how I should proceed.
> Should I run my messy code above to "fix" the pool?
> Should I simply delete all backups for this host, and then start fresh?
> (I'm assuming V4 won't actually download the files since most will still
> exist in the pool).
> Delete some number of backups to reduce the number of hard links?
>
> Thank you for even reading this far :)
>
> Regards,
> Adam
>


-- 
Adam Goryachev
Website Managers
P: +61 2 8304 0000                    adam AT websitemanagers.com DOT au
F: +61 2 8304 0001                     www.websitemanagers.com.au


-- 
Adam Goryachev Website Managers www.websitemanagers.com.au

------------------------------------------------------------------------------
Comprehensive Server Monitoring with Site24x7.
Monitor 10 servers for $9/Month.
Get alerted through email, SMS, voice calls or mobile push notifications.
Take corrective actions from your mobile device.
http://p.sf.net/sfu/Zoho
_______________________________________________
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/

<Prev in Thread] Current Thread [Next in Thread>