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

[edgar . soldin]

On 04.09.2012 16:03, Laurynas Biveinis wrote:
> 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?
> 

are you sure /media/Sandėlys/tmp/duplicity-qD6e4q-tempdir is located on the big 
file system? you could have forgotten that you placed a symlink there (shot in 
the dark).

find out which data on /home/laurynas fills it up. you are right the output 
above suggests it uses the big partition (/media/Sande.lys) but obviously the 
other one fills up.

check the beginning of the output of your restore run with -v9 . duplicity 
states which folders it uses here. yopur old output had

*Using archive dir: 
/home/laurynas/.cache/duplicity/01871362fe22149381ffe67e3950a08f*
Using backup name: 01871362fe22149381ffe67e3950a08f
[SNIP]
================================================================================
duplicity 0.6.18 (February 29, 2012)
Args: /usr/bin/duplicity -v9 -t4D --file-to-restore path/path2/file 
--s3-european-buckets --s3-use-new-style s3+http://url /home/laurynas/file
Linux laurynas-ThinkPad-T410 3.2.0-29-generic #46-Ubuntu SMP Fri Jul 27 
17:03:23 UTC 2012 x86_64 x86_64
/usr/bin/python 2.7.3 (default, Aug  1 2012, 05:14:39) 
[GCC 4.6.3]
================================================================================
*Using temporary directory /media/Sandelys/tmp/duplicity-R97YuE-tempdir*

did you notice that /media/Sande.lys is *not* /media/Sandelys?


..ede/duply.net