Re: [Duplicity-talk] Out of space error while restoring a file

[Laurynas Biveinis]

2012/9/4  <address@hidden>:
> On 04.09.2012 10:00, Laurynas Biveinis wrote:
>> Hi -
>>
>>>>>>>>>> I'm trying to restore a ~30GB file from backups. The free space on 
>>>>>>>>>> the
>>>>>>>>>> drive is about 80GB. Yet on restore I get the error below. What would
>>>>>>>>>> be causing this and how much free space do I actually need to 
>>>>>>>>>> restore?
>>>>>>>>>>
>>>>>>>>>> $ duplicity -t2D --file-to-restore "path/to/file"
>>>>>>>>>> --s3-european-buckets --s3-use-new-style s3+http://foo $HOME/file
>>>>>>>>>> Local and Remote metadata are synchronized, no sync needed.
>>>>>>>>>> Warning, found the following orphaned backup file:
>>>>>>>>>> [duplicity-inc.20120319T102409Z.to.20120320T010946Z.manifest.part]
>>>>>>>>>> Last full backup date: Thu Aug 16 00:00:27 2012
>>>>>>>>>> Traceback (most recent call last):
>>>>>>>>>>   File "/usr/bin/duplicity", line 1403, in <module>
>>>>>>>>>>     with_tempdir(main)
>>>>>>>>>>   File "/usr/bin/duplicity", line 1396, in with_tempdir
>>>>>>>>>>     fn()
>>>>>>>>>>   File "/usr/bin/duplicity", line 1330, in main
>>>>>>>>>>     restore(col_stats)
>>>>>>>>>>   File "/usr/bin/duplicity", line 623, in restore
>>>>>>>>>>     restore_get_patched_rop_iter(col_stats)):
>>>>>>>>>>   File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
>>>>>>>>>> 522, in Write_ROPaths
>>>>>>>>>>     for ropath in rop_iter:
>>>>>>>>>>   File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
>>>>>>>>>> 495, in integrate_patch_iters
>>>>>>>>>>     final_ropath = patch_seq2ropath( normalize_ps( patch_seq ) )
>>>>>>>>>>   File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
>>>>>>>>>> 475, in patch_seq2ropath
>>>>>>>>>>     misc.copyfileobj( current_file, tempfp )
>>>>>>>>>>   File "/usr/lib/python2.7/dist-packages/duplicity/misc.py", line 
>>>>>>>>>> 170,
>>>>>>>>>> in copyfileobj
>>>>>>>>>>     outfp.write(buf)
>>>>>>>>>> IOError: [Errno 28] No space left on device
>>>>>>>>>>
>>>>>>>>>> The backup chain looks as follows
>>>>>>>>>>
>>>>>>>>>> Chain start time: Thu Aug 16 00:00:27 2012
>>>>>>>>>> Chain end time: Thu Aug 30 00:00:23 2012
>>>>>>>>>> Number of contained backup sets: 12
>>>>>>>>>> Total number of contained volumes: 3477
>>>>>>>>>>  Type of backup set:                            Time:      Num 
>>>>>>>>>> volumes:
>>>>>>>>>>                 Full         Thu Aug 16 00:00:27 2012              
>>>>>>>>>> 2916
>>>>>>>>>>          Incremental         Sun Aug 19 00:00:25 2012                
>>>>>>>>>> 96
>>>>>>>>>>          Incremental         Mon Aug 20 00:00:28 2012                
>>>>>>>>>> 33
>>>>>>>>>>          Incremental         Tue Aug 21 00:00:30 2012                
>>>>>>>>>> 37
>>>>>>>>>>          Incremental         Wed Aug 22 00:00:25 2012                
>>>>>>>>>> 58
>>>>>>>>>>          Incremental         Thu Aug 23 00:00:30 2012                
>>>>>>>>>> 62
>>>>>>>>>>          Incremental         Fri Aug 24 00:00:31 2012                
>>>>>>>>>> 32
>>>>>>>>>>          Incremental         Sat Aug 25 00:00:26 2012                
>>>>>>>>>> 81
>>>>>>>>>>          Incremental         Sun Aug 26 00:00:28 2012                
>>>>>>>>>> 75
>>>>>>>>>>          Incremental         Mon Aug 27 00:00:21 2012                
>>>>>>>>>>  8
>>>>>>>>>>          Incremental         Tue Aug 28 00:00:18 2012                
>>>>>>>>>> 21
>>>>>>>>>>          Incremental         Thu Aug 30 00:00:23 2012                
>>>>>>>>>> 58
>>>>>>>>>>
>>>>>>>>>> Duplicity is 0.6.18.
>>>>>>>>>>
>>>>>>>>>> Thanks in advance,
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> you need 30GB (size of file to restore) plus the size of one volume 
>>>>>>>>> in wherever TMP points to.
>>>>>>>>
>>>>>>>> Thanks. But I have only one partition, TMP is unset (if I understand
>>>>>>>> correctly, then it defaults to /tmp), the volume size is default, so
>>>>>>>> I'd need 30GB + 25MB, and I have 80GB free, but apparently that's not
>>>>>>>> enough?
>>>>>>>>
>>>>>>>
>>>>>>> should be... runthe restore with maximum verbosity '-v9' and post the 
>>>>>>> complete output to pastebin (obfuscate private info in it) and send the 
>>>>>>> link. maybe i'll see something.
>>>>>>
>>>>>> I'm attaching the compressed log. It's 2.5MB uncompressed, that's too
>>>>>> big for pastebin. Please let me know if I should it send it in some
>>>>>> other way.
>>>>>>
>>>>>>> you might want to monitor the disk usage during the restore. my guess 
>>>>>>> would be that the final copy of 30GB fails. maybe duplicity keeps 
>>>>>>> downloaded volumes in temp until finished?
>>>>>>
>>>>>> I got the "low disk space, 200MB remaining" warning on the volume
>>>>>> which had 80GB free initially. Looking at the log file, I guess it's
>>>>>> the initial downloading that fails. But why does it have to download
>>>>>> so much?
>>>>>>
>>>>>> I will attach a volume with some 200GB free, point TMP to it, and
>>>>>> restart the restore now.
>>>>>
>>>>> I have retried with TMP pointing to a volume with 244GB and the
>>>>> restore sill fails, although slightly differently. I have attached the
>>>>> compressed log.
>>>>>
>>>>
>>>> can you verify that during the course of the restore
>>>>  /media/Sandelys/tmp/duplicity-*-tempdir/
>>>> fills up the containing file system?
>>>>
>>>> this is suggested by the debug output. trying to pinpoint your issue here.
>>>>
>>>>
>>>
>>> unlikely but possible.. could you check that
>>>
>>> - you have enough inodes free (df -i) also during the course of the restore
>>> - the file systems are sane by fsck'ing them as a precaution action
>>
>> Thanks for your help and suggestions.
>>
>> The big volume is formatted with NTFS. It was probably never mounted
>> in its native environment, so I fired a Windows VM to check it. And
>> indeed there were a few errors, involving the restore process. The
>> "lost+found" contained some downloaded volumes after the check:
>>
>> $ ls found.000/dir0000.chk/
>> duplicity-inc.20110830T210003Z.to.20110831T210003Z.vol4.difftar.gpg
>> duplicity-inc.20110830T210003Z.to.20110831T210003Z.vol7.difftar.gpg
>> duplicity-inc.20110830T210003Z.to.20110831T210003Z.vol5.difftar.gpg
>> duplicity-new-signatures.20110830T210003Z.to.20110831T210003Z.sigtar.gpg
>> duplicity-inc.20110830T210003Z.to.20110831T210003Z.vol6.difftar.gpg
>>
>> After fixing the volume I repeated the restore, monitoring the free
>> space and inodes by a script that does df -h df -i every 15 seconds.
>>
>> The restore failed in the same way as before, the log is attached
>> again. What's interesting is that according to the df the free space
>> did not change at all: http://pastebin.com/PhanxQUX (it contains two
>> partitions, originally it had only $TMP, I couldn't believe its
>> result, so I added $HOME (same as /) too and retried).
>>
>
> recheck your outputs, see below. around 09:16:58 /home/laurynas/.Private 
> overflows. my guess is that duplicity TMP is located there. use the other 
> partition as 80GB is obviously not enough.

Thanks. Something does not add up here. The restore script does
export TMPDIR=/media/Sandėlys/tmp

and the output of duplicity has

Using temporary directory /media/Sandėlys/tmp/duplicity-qD6e4q-tempdir
Registering (mkstemp) temporary file
/media/Sandėlys/tmp/duplicity-qD6e4q-tempdir/mkstemp-HzlUlf-1
Temp has 261955923968 available, backup will use approx 34078720.

Could it be that TMPDIR is ignored somewhere?

-- 
Laurynas