Re: [Duplicity-talk] "tarfile.ReadError: unexpected end of data" when restoring

[Jerry Raj]

On 5/31/20, edgar.soldin--- via Duplicity-talk
<duplicity-talk@nongnu.org> wrote:
> On 31.05.2020 14:06, Jerry Raj via Duplicity-talk wrote:
>> Hello,
>> I have some files backed up on a B2 bucket. The backup was done in
>> 2016 and I don't recall seeing any errors when running the backup. A
>> bunch of incrementals were also run after that. Now, while trying to
>> restore from the backup, it writes a bunch of files and then prints
>> this error:
>>
>> Writing folder jun 04/19.jpg of type reg
>> Releasing lockfile b'/root/.cache/duplicity/oldpics/lockfile'
>> Removing still remembered temporary file
>> /tmp/duplicity-g54acfp_-tempdir/mkstemp-0q8ek77p-1
>> Removing still remembered temporary file
>> /tmp/duplicity-g54acfp_-tempdir/mktemp-c6rtyy0l-15
>> Removing still remembered temporary file
>> /tmp/duplicity-g54acfp_-tempdir/mktemp-wvy4ygnk-16
>> Releasing lockfile b'/root/.cache/duplicity/oldpics/lockfile'
>> Traceback (innermost last):
>>   File "/usr/bin/duplicity", line 106, in <module>
>>     with_tempdir(main)
>>   File "/usr/bin/duplicity", line 92, in with_tempdir
>>     fn()
>>   File "/usr/lib/python3/dist-packages/duplicity/dup_main.py", line
>> 1538, in main
>>     do_backup(action)
>>   File "/usr/lib/python3/dist-packages/duplicity/dup_main.py", line
>> 1618, in do_backup
>>     restore(col_stats)
>>   File "/usr/lib/python3/dist-packages/duplicity/dup_main.py", line
>> 723, in restore
>>     if not patchdir.Write_ROPaths(globals.local_path,
>>   File "/usr/lib/python3/dist-packages/duplicity/patchdir.py", line
>> 578, in Write_ROPaths
>>     for ropath in rop_iter:
>>   File "/usr/lib/python3/dist-packages/duplicity/patchdir.py", line
>> 541, in integrate_patch_iters
>>     for patch_seq in collated:
>>   File "/usr/lib/python3/dist-packages/duplicity/patchdir.py", line
>> 407, in yield_tuples
>>     setrorps(overflow, elems)
>>   File "/usr/lib/python3/dist-packages/duplicity/patchdir.py", line
>> 396, in setrorps
>>     elems[i] = next(iter_list[i])
>>   File "/usr/lib/python3/dist-packages/duplicity/patchdir.py", line
>> 135, in difftar2path_iter
>>     multivol_fileobj.close()  # aborting in middle of multivol
>>   File "/usr/lib/python3/dist-packages/duplicity/patchdir.py", line
>> 264, in close
>>     if not self.addtobuffer():
>>   File "/usr/lib/python3/dist-packages/duplicity/patchdir.py", line
>> 248, in addtobuffer
>>     self.buffer += fp.read()
>>   File "/usr/lib/python3.8/tarfile.py", line 684, in read
>>     raise ReadError("unexpected end of data")
>>  tarfile.ReadError: unexpected end of data
>>
>> It then just hangs there and does not proceed, I have to ctrl-C to
>> exit. Is there some way I can recover at least some of the remaining
>> files? "duplicity list-current-files" returns over 700 files, but only
>> 240 are written before it errors out.
>>
>> FWIW, running restore with -vd provides this summary:
>>
>> Collection Status
>> -----------------
>> Connecting with backend: BackendWrapper
>> Archive dir: /root/.cache/duplicity/oldpics
>>
>> Found 0 secondary backup chains.
>>
>> Found primary backup chain with matching signature chain:
>> -------------------------
>> Chain start time: Sat Oct 15 13:36:44 2016
>> Chain end time: Wed Mar 29 22:10:38 2017
>> Number of contained backup sets: 13
>> Total number of contained volumes: 21
>>  Type of backup set:                            Time:      Num volumes:
>>                 Full         Sat Oct 15 13:36:44 2016                 5
>>          Incremental         Sun Jan  8 08:48:27 2017                 5
>>          Incremental         Sun Jan  8 09:19:42 2017                 1
>>          Incremental         Mon Jan  9 07:03:47 2017                 1
>>          Incremental         Mon Jan 16 19:34:53 2017                 1
>>          Incremental         Thu Jan 19 21:21:56 2017                 1
>>          Incremental         Tue Feb  7 05:33:27 2017                 1
>>          Incremental         Tue Feb  7 05:39:58 2017                 1
>>          Incremental         Tue Feb  7 05:59:27 2017                 1
>>          Incremental         Sat Feb 11 04:57:12 2017                 1
>>          Incremental         Wed Mar 29 17:41:50 2017                 1
>>          Incremental         Wed Mar 29 17:55:07 2017                 1
>>          Incremental         Wed Mar 29 22:10:38 2017                 1
>> -------------------------
>> No orphaned or incomplete backup sets found.
>>
>> Any help is appreciated!
>
> hey Jerry,
>
> for convenience (and speed) you may copy the whole backup from b2 bucket to
> a local folder just for now.
>
> it's unclear if your backup is corrupted or just not restoring properly
> because of a bug.
>
> questions
> 1. is your backup encrypted or compressed?
> 2. what is your restore command?
> 3. when monitoring ram usage during restore until the hanging process, does
> it get full and starts to swap at any point?
> 4. what is the output of 'ulimit -n' ?
> 5. when duplicity hangs, can you check take a 'ps -xfa' and post the
> duplicity part here to see which process is pausing it?
>
> in case of a memory leak (ram running full) it might help to restore only
> parts of your backup using the '--file-to-restore <file/folder>' parameter.
>
> good luck ..ede/duply.net
>
> _______________________________________________
> Duplicity-talk mailing list
> Duplicity-talk@nongnu.org
> https://lists.nongnu.org/mailman/listinfo/duplicity-talk
>

Hi,
Thanks a lot for your help. Answers below:

> 1. is your backup encrypted or compressed?
It's encrypted, but I don't think it's compressed. I used a command like:
duplicity --name oldpics /store/oldpics  <b2url>
PASSPHRASE was set to a random string

> 2. what is your restore command?
duplicity -vd  --name oldpics
"b2://$B2_ACCOUNTID:$B2_APPLICATION_KEY@$B2_BUCKET_NAME/oldpics"
/store/oldpics
PASSPHRASE is set to the same string as used during backup.

> 3. when monitoring ram usage during restore until the hanging process, does
> it get full and starts to swap at any point?
No it doesn't seem to be doing anything at that point. Watching it
with top doesn't show RES or VIRT increasing.
> 4. what is the output of 'ulimit -n' ?
1024
> 5. when duplicity hangs, can you check take a 'ps -xfa' and post the
> duplicity part here to see which process is pausing it?
30754 pts/2    Sl+    0:14  |       \_ /usr/bin/python3
/usr/bin/duplicity --force -vd --name oldpics
b2://<redacted>@<redacted>/oldpics /store/oldpics
  30812 pts/2    SL+    0:01  |           \_ gpg --passphrase-fd 19
--status-fd 15 --logger-fd 8 --batch --no-tty --no-secmem-warning
--ignore-mdc-error --pinentry-mode=loopback --decrypt


Thanks again for your help.

-Jerry