Re: [Duplicity-talk] Problems with "librsync error 103 while in patch cycle"

[edgar . soldin]

good to hear.. looking forward to your findings! ..ede

On 11.11.2013 16:43, Michael Terry wrote:
> I looked at this a bit last night.  For your later issue of hitting a 
> KeyError: 4 exception, I have a fix: lp:~mterry/duplicity/manifest-oddities 
> (not proposed for merging yet, since there is more research needed, see below)
> 
> I'm currently also investigating a similar problem that can occur, though you 
> didn't happen to run into it.  For your original issue of having 
> patch_seq[-1] == None, I'm not sure how that can happen yet.  Still (slowly) 
> looking into it.
> 
> -mt
> 
> 
> 
> On 4 November 2013 15:57, <address@hidden <mailto:address@hidden>> wrote:
> 
>     thanks :) .. at least we pointed him in the right direction. _and_ now 
> we've got some pointers in writing on how to fix that for when we come around 
> to tackle it.
> 
>     thanks Echo as well for keeping us posted!
> 
>     ..ede/duply.net <http://duply.net>
> 
> 
>     On 04.11.2013 21:52, Michael Terry wrote:
>     > Heyo!  I'm just dropping a line to say I've seen this email and it 
> looks like I need to do some further work on that area of code in terms of 
> letting the user continue.  But I've been very busy lately and haven't gotten 
> to it.
>     >
>     > So I acknowledge the problem, but haven't had time to work on it.  :-/
>     >
>     > -mt
>     >
>     >
>     > On 3 November 2013 21:21, Echo Nolan <address@hidden 
> <mailto:address@hidden> <mailto:address@hidden <mailto:address@hidden>>> 
> wrote:
>     >
>     >     Hi again. I managed to get most of my data restored :) I'm not sure 
> what the NoneType error means exactly, but the below patch allows restore to 
> continue.
>     >
>     >     === modified file 'duplicity/patchdir.py'
>     >     --- duplicity/patchdir.py    2013-09-19 00:26:01 +0000
>     >     +++ duplicity/patchdir.py    2013-11-03 22:20:35 +0000
>     >     @@ -23,6 +23,7 @@
>     >      import types
>     >      import os
>     >      import tempfile
>     >     +import pprint
>     >
>     >      from duplicity import tarfile address@hidden
>     >      from duplicity import librsync address@hidden
>     >     @@ -504,11 +505,16 @@
>     >                      # otherwise final patch was delete
>     >                      yield final_ropath
>     >              except Exception, e:
>     >     -            filename = 
> patch_seq[-1].get_ropath().get_relative_path()
>     >     -            log.Warn(_("Error '%s' patching %s") %
>     >     -                     (str(e), filename),
>     >     -                     log.WarningCode.cannot_process,
>     >     -                     util.escape(filename))
>     >     +            if patch_seq[-1] != None:
>     >     +                filename = 
> patch_seq[-1].get_ropath().get_relative_path()
>     >     +                log.Warn(_("Error '%s' patching %s") %
>     >     +                         (str(e), filename),
>     >     +                         log.WarningCode.cannot_process,
>     >     +                         util.escape(filename))
>     >     +            else:
>     >     +                log.Warn(_("Error '%s' patching unknown file") %
>     >     +                         (str(e)),
>     >     +                         log.WarningCode.cannot_process)
>     >
>     >      def tarfiles2rop_iter( tarfile_list, restrict_index=() ):
>     >          """Integrate tarfiles of diffs into single ROPath iter
>     >
>     >     That got me a new error, further into the restore process. I was 
> getting a KeyError exception:
>     >
>     >
>     >     Traceback (most recent call last):
>     >       File "bin/duplicity", line 1469, in <module>
>     >         with_tempdir(main)
>     >       File "bin/duplicity", line 1462, in with_tempdir
>     >         fn()
>     >       File "bin/duplicity", line 1396, in main
>     >
>     >         restore(col_stats)
>     >       File "bin/duplicity", line 687, in restore
>     >         restore_get_patched_rop_iter(col_stats)):
>     >       File "/home/enolan/duplicity/duplicity/patchdir.py", line 541, in 
> Write_ROPaths
>     >         for ropath in rop_iter:
>     >       File "/home/enolan/duplicity/duplicity/patchdir.py", line 501, in 
> integrate_patch_iters
>     >         for patch_seq in collated:
>     >       File "/home/enolan/duplicity/duplicity/patchdir.py", line 381, in 
> yield_tuples
>     >         setrorps( overflow, elems )
>     >       File "/home/enolan/duplicity/duplicity/patchdir.py", line 370, in 
> setrorps
>     >         elems[i] = iter_list[i].next()
>     >       File "/home/enolan/duplicity/duplicity/patchdir.py", line 140, in 
> difftar2path_iter
>     >         tarinfo_list[0] = tar_iter.next()
>     >       File "/home/enolan/duplicity/duplicity/patchdir.py", line 336, in 
> next
>     >         self.set_tarfile()
>     >       File "/home/enolan/duplicity/duplicity/patchdir.py", line 325, in 
> set_tarfile
>     >         self.current_fp = self.fileobj_iter.next()
>     >       File "bin/duplicity", line 726, in get_fileobj_iter
>     >         backup_set.volume_name_dict[vol_num],
>     >     KeyError: 4
>     >
>     >     To figure out what was going on, I added some debug print lines:
>     >
>     >     === modified file 'bin/duplicity'
>     >     --- bin/duplicity    2013-09-20 01:32:31 +0000
>     >     +++ bin/duplicity    2013-11-04 02:05:07 +0000
>     >     @@ -29,7 +29,7 @@
>     >
>     >      import getpass, gzip, os, sys, time, types
>     >      import traceback, platform, statvfs, resource, re
>     >     -import threading
>     >     +import threading, pprint
>     >      from datetime import datetime
>     >
>     >      pwd = os.path.abspath(os.path.dirname(sys.argv[0]))
>     >     @@ -719,6 +719,9 @@
>     >              manifest = backup_set.get_manifest()
>     >              volumes = manifest.get_containing_volumes(index)
>     >              for vol_num in volumes:
>     >     +            print "vol_num: " + str(vol_num)
>     >     +            print "volume_name_dict"
>     >     +            pprint.pprint(backup_set.volume_name_dict)
>     >                  yield restore_get_enc_fileobj(backup_set.backend,
>     >                                                
> backup_set.volume_name_dict[vol_num],
>     >                                                
> manifest.volume_info_dict[vol_num])
>     >
>     >     Results showed it was looking for a fourth volume in 
> duplicity-inc.20121218T113324Z.to.20130121T051302Z. I decrypted the manifest:
>     >
>     >     Hostname localhost6.localdomain6
>     >     Localdir /home/enolan
>     >     Volume 1:
>     >         StartingPath   .
>     >         EndingPath     ".config/google-chrome/Default/Top\x20Sites" 3
>     >         Hash SHA1 40f6ddd332d82b5197db4bdbf13278b9abfb6e71
>     >     Volume 2:
>     >         StartingPath   ".config/google-chrome/Default/Top\x20Sites" 4
>     >         EndingPath     .dropbox-dist/library.zip 112
>     >         Hash SHA1 3ec708b2a6b48e6efa9662dcdb751dcad6c153cf
>     >     Volume 3:
>     >         StartingPath   .dropbox-dist/library.zip 113
>     >         EndingPath     
> .local/share/Steam/SteamApps/common/Uplink/lib/libmikmod.so.2 8
>     >         Hash SHA1 76e5a803315ff9bca2a6de9c7d2a04d81ab77e0f
>     >     Volume 4:
>     >         StartingPath   
> .local/share/Steam/SteamApps/common/Uplink/lib/libmikmod.so.2 9
>     >         EndingPath     
> ".local/share/Steam/SteamApps/common/World\x20of\x20Goo/WorldOfGoo" 49
>     >         Hash SHA1 f7ea5f82fa34ce159095b46555b3877cd16d5b5a
>     >     Volume 3:
>     >         StartingPath   .local/share/Steam/ClientRegistry.blob
>     >         EndingPath     "mystuff/writing/misc/resume\x20non\x20tech.pdf"
>     >         Hash SHA1 10eaa0b647bd998c34d7f5775894152a16e45dd1
>     >
>     >     There are only three volumes in that incremental backup in reality. 
> I deleted the first volume 3 and 4 entries, and made sure that the SHA1 of 
> volume 3 matched the real hash of the volume. After that, restore finished 
> properly, though still with many errors.
>     >
>     >     Hope this helps somebody. :)
>     >
>     >
>     >
>     >     On Sun, Nov 3, 2013 at 1:37 PM, <address@hidden 
> <mailto:address@hidden> <mailto:address@hidden <mailto:address@hidden>>> 
> wrote:
>     >
>     >         you should definitely rethink your backup strategy for the next 
> time, but i guess you've already came to that conclusion ;)
>     >
>     >         wrt. the problem. as i wrote to Mike. try catching the error 
> where it is thrown. the restore should continue then with the next file 
> instead of breaking completely.
>     >
>     >
>     >         ..ede/duply.net <http://duply.net> <http://duply.net>
>     >
>     >
>     >
>     >         On 03.11.2013 20:02, Echo Nolan wrote:
>     >         > Edgar et al,
>     >         >
>     >         > Unfortunately, it looks like the initial full backup is 
> corrupt. The restore reaches "Processed volume 13 of 75" before dying, and 
> the initial backup is 25 volumes. I was able to get two important files out 
> with --file-to-restore, I guess they didn't get created until after the first 
> backup? Is there something else I can do to get a partial restore?
>     >         >
>     >         >
>     >         > On Sun, Nov 3, 2013 at 3:30 AM, <address@hidden 
> <mailto:address@hidden> <mailto:address@hidden <mailto:address@hidden>> 
> <mailto:address@hidden <mailto:address@hidden> <mailto:address@hidden 
> <mailto:address@hidden>>>> wrote:
>     >         >
>     >         >     On 03.11.2013 07:08, Echo Nolan wrote:
>     >         >     > Hi All.
>     >         >     >
>     >         >     > I'm trying to restore a backup. Here's what happens 
> with the version of duplicity shipping with Ubuntu 13.10 (0.6.21):
>     >         >     >
>     >         >     > address@hidden:~$ rm -r restore && duplicity 
> file://enolan-desktop-backup restore/
>     >         >     > Local and Remote metadata are synchronized, no sync 
> needed.
>     >         >     > Last full backup date: Sun Jan 15 08:05:07 2012
>     >         >     > GnuPG passphrase:
>     >         >     > python: ERROR: (rs_tube_catchup) reached end of file 
> while copying literal data through buffers
>     >         >     > python: ERROR: (rs_job_complete) patch job failed: 
> unexpected end of input
>     >         >     > Traceback (most recent call last):
>     >         >     >   File "/usr/bin/duplicity", line 1411, in <module>
>     >         >     >     with_tempdir(main)
>     >         >     >   File "/usr/bin/duplicity", line 1404, in with_tempdir
>     >         >     >     fn()
>     >         >     >   File "/usr/bin/duplicity", line 1338, in main
>     >         >     >     restore(col_stats)
>     >         >     >   File "/usr/bin/duplicity", line 632, in restore
>     >         >     >     restore_get_patched_rop_iter(col_stats)):
>     >         >     >   File 
> "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 526, in 
> Write_ROPaths
>     >         >     >     for ropath in rop_iter:
>     >         >     >   File 
> "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 499, in 
> integrate_patch_iters
>     >         >     >     final_ropath = patch_seq2ropath( normalize_ps( 
> patch_seq ) )
>     >         >     >   File 
> "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 479, in 
> patch_seq2ropath
>     >         >     >     misc.copyfileobj( current_file, tempfp )
>     >         >     >   File 
> "/usr/lib/python2.7/dist-packages/duplicity/misc.py", line 166, in copyfileobj
>     >         >     >     buf = infp.read(blocksize)
>     >         >     >   File 
> "/usr/lib/python2.7/dist-packages/duplicity/librsync.py", line 80, in read
>     >         >     >     self._add_to_outbuf_once()
>     >         >     >   File 
> "/usr/lib/python2.7/dist-packages/duplicity/librsync.py", line 94, in 
> _add_to_outbuf_once
>     >         >     >     raise librsyncError(str(e))
>     >         >     > librsyncError: librsync error 103 while in patch cycle
>     >         >     >
>     >         >     > I googled, and found this ticket in Ubuntu's 
> bugtracker: https://bugs.launchpad.net/duplicity/+bug/662442
>     >         >     >
>     >         >     > It seemed like the same problem, and oh look, someone 
> has already committed a patch allowing me to continue restoring a backup 
> containing broken files 
> (https://code.launchpad.net/~mterry/duplicity/catch-seq-copy-error/+merge/186106
>  
> <https://code.launchpad.net/%7Emterry/duplicity/catch-seq-copy-error/+merge/186106>
>  
> <https://code.launchpad.net/%7Emterry/duplicity/catch-seq-copy-error/+merge/186106>
>  
> <https://code.launchpad.net/%7Emterry/duplicity/catch-seq-copy-error/+merge/186106>
>  
> <https://code.launchpad.net/%7Emterry/duplicity/catch-seq-copy-error/+merge/186106>).
>  So I grabbed duplicity from bzr (bzr branch lp:duplicity) and built it. 
> Trying with that version gives a different error however:
>     >         >     >
>     >         >     > address@hidden:~/duplicity$ bin/duplicity 
> file://../enolan-desktop-backup ../restore
>     >         >     > Import of duplicity.backends.dpbxbackend Failed: No 
> module named dropbox
>     >         >     > Local and Remote metadata are synchronized, no sync 
> needed.
>     >         >     > Last full backup date: Sun Jan 15 08:05:07 2012
>     >         >     > GnuPG passphrase:
>     >         >     > python: ERROR: (rs_tube_catchup) reached end of file 
> while copying literal data through buffers
>     >         >     > python: ERROR: (rs_job_complete) patch job failed: 
> unexpected end of input
>     >         >     > Traceback (most recent call last):
>     >         >     >   File "bin/duplicity", line 1466, in <module>
>     >         >     >     with_tempdir(main)
>     >         >     >   File "bin/duplicity", line 1459, in with_tempdir
>     >         >     >     fn()
>     >         >     >   File "bin/duplicity", line 1393, in main
>     >         >     >     restore(col_stats)
>     >         >     >   File "bin/duplicity", line 687, in restore
>     >         >     >     restore_get_patched_rop_iter(col_stats)):
>     >         >     >   File "/home/enolan/duplicity/duplicity/patchdir.py", 
> line 535, in Write_ROPaths
>     >         >     >     for ropath in rop_iter:
>     >         >     >   File "/home/enolan/duplicity/duplicity/patchdir.py", 
> line 507, in integrate_patch_iters
>     >         >     >     filename = 
> patch_seq[-1].get_ropath().get_relative_path()
>     >         >     > AttributeError: 'NoneType' object has no attribute 
> 'get_ropath'
>     >         >     >
>     >         >     > Can any of you help me out? This is my only copy of 
> several important files..
>     >         >     >
>     >         >
>     >         >     Echo,
>     >         >
>     >         >     currently rsync errors or others restore errors break 
> restoring. the usual workaround is, assuming you have a full/incr backup 
> chain, to restore a time before the broken volumes.
>     >         >
>     >         >     1. try listing your backup chains and save the output.
>     >         >     2. then run your restore as before but with '-v9' maximum 
> verbosity. check which volume breaks the restore. it should be mentioned 
> right above the error stack. interpret it's time value in the file name.
>     >         >     3. now try restoring giving a time before the time value 
> you retrieved in step 2.
>     >         >
>     >         >     Mike: you tackled this before. could you catch his error 
> higher up? we probably need to log a warning that this file will not be 
> restored too.
>     >         >
>     >         >
>     >         >     ..ede/duply.net <http://duply.net> <http://duply.net> 
> <http://duply.net>
>     >         >
>     >         >     _______________________________________________
>     >         >     Duplicity-talk mailing list
>     >         >     address@hidden <mailto:address@hidden> 
> <mailto:address@hidden <mailto:address@hidden>> <mailto:address@hidden 
> <mailto:address@hidden> <mailto:address@hidden <mailto:address@hidden>>>
>     >         >     https://lists.nongnu.org/mailman/listinfo/duplicity-talk
>     >         >
>     >         >
>     >         >
>     >         >
>     >         > _______________________________________________
>     >         > Duplicity-talk mailing list
>     >         > address@hidden <mailto:address@hidden> <mailto:address@hidden 
> <mailto:address@hidden>>
>     >         > https://lists.nongnu.org/mailman/listinfo/duplicity-talk
>     >         >
>     >
>     >         _______________________________________________
>     >         Duplicity-talk mailing list
>     >         address@hidden <mailto:address@hidden> <mailto:address@hidden 
> <mailto:address@hidden>>
>     >         https://lists.nongnu.org/mailman/listinfo/duplicity-talk
>     >
>     >
>     >
>     >     _______________________________________________
>     >     Duplicity-talk mailing list
>     >     address@hidden <mailto:address@hidden> <mailto:address@hidden 
> <mailto:address@hidden>>
>     >     https://lists.nongnu.org/mailman/listinfo/duplicity-talk
>     >
>     >
>     >
>     >
>     > _______________________________________________
>     > Duplicity-talk mailing list
>     > address@hidden <mailto:address@hidden>
>     > https://lists.nongnu.org/mailman/listinfo/duplicity-talk
>     >
> 
>     _______________________________________________
>     Duplicity-talk mailing list
>     address@hidden <mailto:address@hidden>
>     https://lists.nongnu.org/mailman/listinfo/duplicity-talk
> 
> 
> 
> 
> _______________________________________________
> Duplicity-talk mailing list
> address@hidden
> https://lists.nongnu.org/mailman/listinfo/duplicity-talk
>