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

[edgar . soldin]

On 17.09.2012 17:40, Laurynas Biveinis wrote:
>>>>>>>>>>>>>>>>>>>>>>>>> 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?
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>> 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.
>>>>>>>>>>>>>
>>>>>>>>>>>>> So I might have found something useful: I started duplicity with
>>>>>>>>>>>>> strace. Then I did lsof while it's in progress and got one open 
>>>>>>>>>>>>> handle
>>>>>>>>>>>>> outside the /media/Sandėlys:
>>>>>>>>>>>>>
>>>>>>>>>>>>> duplicity 31759 laurynas   44u   REG     8,1 529465344 15467022
>>>>>>>>>>>>> /tmp/tmpfxLhqjk (deleted)
>>>>>>>>>>>>>
>>>>>>>>>>>>> It is deleted and ever-growing. I looked for it in strace:
>>>>>>>>>>>>>
>>>>>>>>>>>>> 31759 stat("/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=45056, 
>>>>>>>>>>>>> ...}) = 0
>>>>>>>>>>>>> 31759 open("/tmp/tmpfxLhqjk", O_RDWR|O_CREAT|O_EXCL, 0600) = 44
>>>>>>>>>>>>> 31759 unlink("/tmp/tmpfxLhqjk")         = 0
>>>>>>>>>>>>> 31759 fcntl(44, F_GETFL)                = 0x8002 (flags 
>>>>>>>>>>>>> O_RDWR|O_LARGEFILE)
>>>>>>>>>>>>> 31759 fstat(44, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
>>>>>>>>>>>>>
>>>>>>>>>>>>> First write contents suggests that this is going to be the final 
>>>>>>>>>>>>> file:
>>>>>>>>>>>>>
>>>>>>>>>>>>> 31759 write(44, "<<< Oracle VM VirtualBox Disk Im"..., 65536 
>>>>>>>>>>>>> <unfinished ...>
>>>>>>>>>>>>>
>>>>>>>>>>>>> Any idea or pointers?
>>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>> try setting all 3 env vars..
>>>>>>>>>>>> http://duplicity.nongnu.org/duplicity.1.html#sect7
>>>>>>>>>>>> maybe it's a bug deep down, not respecting TMPDIR only
>>>>>>>>>>>
>>>>>>>>>>> export TEMP=/media/Sandėlys/tmp
>>>>>>>>>>> export TMP=/media/Sandėlys/tmp
>>>>>>>>>>> export TMPDIR=/media/Sandėlys/tmp
>>>>>>>>>>>
>>>>>>>>>>> Does not seem to help:
>>>>>>>>>>>
>>>>>>>>>>> duplicity 32278 laurynas   44u   REG     8,1 282394624 15467022
>>>>>>>>>>> /tmp/tmpf7oQNmc (deleted)
>>>>>>>>>>>
>>>>>>>>>>>> still i wonder what's up with /media/Sandėlys versus 
>>>>>>>>>>>> /media/Sande.lys .. can you explain?
>>>>>>>>>>>
>>>>>>>>>>> I am not sure what you mean by "Sande.lys"?.. It's 
>>>>>>>>>>> "/media/Sandėlys".
>>>>>>>>>>> I have a diacritic letter in the path, seems to work OK. I did check
>>>>>>>>>>> /media while the restore was running that there were no "Sandelys" 
>>>>>>>>>>> (no
>>>>>>>>>>> diacritic) or "Sande.lys" or anything else similar there being
>>>>>>>>>>> created.
>>>>>>>>>>>
>>>>>>>>>>> Thanks again,
>>>>>>>>>>> --
>>>>>>>>>>> Laurynas
>>>>>>>>>>
>>>>>>>>>> Ping? Thanks.
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> maybe an issue with the special character in the path? .. try 
>>>>>>>>> mounting it on a plain path.
>>>>>>>>>
>>>>>>>>> '/media/Sandėlys versus /media/Sande.lys' meant that in the df output 
>>>>>>>>> you sent earlier a mount point called '/media/Sande.lys' was listed. 
>>>>>>>>> why was that?
>>>>>>>>
>>>>>>>> I am unable to find it. I see it in your message quoting from the
>>>>>>>> pastebin df output. But the pastebin http://pastebin.com/PhanxQUX does
>>>>>>>> not contain it.
>>>>>>>>
>>>>>>>>> ok, i think i found it.. please manually patch 
>>>>>>>>> 'duplicity/patchdir.py' around line 473
>>>>>>>>> http://bazaar.launchpad.net/~duplicity-team/duplicity/0.6-series/view/head:/duplicity/patchdir.py#L473
>>>>>>>>>
>>>>>>>>> from
>>>>>>>>>
>>>>>>>>>  # librsync needs true file
>>>>>>>>>  tempfp = os.tmpfile()
>>>>>>>>>  misc.copyfileobj( current_file, tempfp )
>>>>>>>>>
>>>>>>>>> to
>>>>>>>>>
>>>>>>>>>  # librsync needs true file
>>>>>>>>>  from duplicity import tempdir
>>>>>>>>>  tempfp_fd = tempdir.default().mkstemp()[0]
>>>>>>>>>  tempfp = os.fdopen(tempfp_fd,'w+b')
>>>>>>>>>  misc.copyfileobj( current_file, tempfp )
>>>>>>>>>
>>>>>>>>> i guess the os.tmpfile() is the culprit here and places everything in 
>>>>>>>>> /tmp.
>>>>>>>>
>>>>>>>> Patched and restarted. It still failed, the log is attached. I did not
>>>>>>>> catch any file in /tmp being opened with strace, but perhaps I looked
>>>>>>>> too early. Now I will get a full strace and peek around again.
>>>>>>>>
>>>>> TL;DR: it worked but there are some gotchas.
>>>>>
>>>>> Full story: I downloaded all of my backups from S3 to local storage. I
>>>>> replaced the previous fix with "tmpspacefix" Launchpad MP patch. I run
>>>>> the restore and it completed. Interestingly it completed at around 750
>>>>> volumes processed out of 3400. Also the last 100 volumes took about 24
>>>>> hours to complete.
>>>>
>>>> interesting. could you check which files took that long? do you still have 
>>>> the output? could you run a full restore with -v9 and post the output 
>>>> (private strings obfuscated)?
>>>
>>> Attached.
>>
>> will look at it later.
> 
> Thanks in advance.
> 
>>> So, "twice the size of the restored file + one volume?" But originally
>>> it failed with 80GB free for a 30GB file, so it's even more than that.
>>
>> right, we would have to disect filesystem usage during restoring to find out 
>> what is going on here. actually the v9 dump tells you when temp files are 
>> created and deleted (though not their size) so you can work through that if 
>> you want.
>>
>> alternatively you have to observe what happens in the tmp folder during 
>> restore ;)
> 
> Here's the open file snapshot around volume 704 (out of ~750):
> http://pastebin.com/pGFH6Wju
> 
> Note that "Sandėlys" has been replaced with "Elements", that's another
> volume (so that locally-downloaded backup sets would fit)
> 
> Thanks again,
> 

ok, just wanted to check the command line output promised above, just to see 
there was nothing attached ;)

wrt to the lsof output. it shows
duplicity 8946 laurynas    7u   REG   8,33 25211305984     8622 
/media/Elements/Laurynas/tmp/duplicity-DL3ypc-tempdir/tmpgxn0pY (deleted)
and
duplicity 8946 laurynas   12u   REG   8,33 34465812480     8614 
/media/Elements/Laurynas/tmp/duplicity-DL3ypc-tempdir/tmpYZgzig (deleted)

and some others, all of them have the tag (deleted), so i assume the space was 
already freed again? 
even if not this is what we assumed: 2 times the 30GB file plus some.

what would be interesting is a "multiplexed" output of 'duplicity -v9' _and_ 
and a periodic 'ls -la' of TMP . so one could see what files duplicity 
creates/deletes and how this reflects in the TMP folder. i believe this would 
be possible with bash magic. 

..ede/duply.net

..ede