duplicity-talk
[Top][All Lists]
Advanced
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [Duplicity-talk] Duplicity - Resource Unavailable Errors

From: Colin Ryan
Subject: Re: [Duplicity-talk] Duplicity - Resource Unavailable Errors
Date: Wed, 11 Nov 2009 17:03:32 -0500
User-agent: Thunderbird 2.0.0.23 (Windows/20090812) 
Ken,

No problem, your a busy man ;-).

Summary/Update
----------
Well I tried this on the source system and I get something different but the same in a way. 
It appears that I'm running into the following type of issue:

http://www.google.ca/url?sa=t&source=web&ct=res&cd=1&ved=0CAcQFjAA&url=http%3A%2F%2Fbugs.debian.org%2Fcgi-bin%2Fbugreport.cgi%3Fbug%3D531786&ei=qDL7Ssj7AcfZnAfxoMmDDQ&usg=AFQjCNFeZMg6JCzACjbX3nmxpkXvFPxkKQ&sig2=_sCXzLVFuZkEvVmEcdFWHw

or

http://www.google.ca/url?sa=t&source=web&ct=res&cd=5&ved=0CBMQFjAE&url=http%3A%2F%2Fwww.mail-archive.com%2Fduplicity-tracker%40nongnu.org%2Fmsg00632.html&ei=qDL7Ssj7AcfZnAfxoMmDDQ&usg=AFQjCNEwImqEAQLUmA7ab5S44D1MlHpnZw&sig2=LNsQa64sQk-4GObh8B0sQA
i.e. see below when it's running the restore it's hanging at 39 gpg sub-processes. 

My environment is:
*Linux rdrive 2.6.22-univ-423 #1 PREEMPT Wed Jul 2 13:04:26 EDT 2008 i686 GNU/Linux 

Custom Kernel on Stripped down version of Debian Lenny

* rdrive:/# gpg --version
gpg (GnuPG) 1.4.6
Copyright (C) 2006 Free Software Foundation, Inc.
This program comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to redistribute it
under certain conditions. See the file COPYING for details.

Home: ~/.gnupg
Supported algorithms:
Pubkey: RSA, RSA-E, RSA-S, ELG-E, DSA
Cipher: 3DES, CAST5, BLOWFISH, AES, AES192, AES256, TWOFISH
Hash: MD5, SHA1, RIPEMD160, SHA256, SHA384, SHA512, SHA224
Compression: Uncompressed, ZIP, ZLIB, BZIP2

* rdrive:/# duplicity --version
duplicity 0.6.05

(Hand compiled to a distribution tar then unpacked onto this system)

Full Details Below:
-------------------

The following command:
/usr/bin/duplicity restore -v9 --encrypt-key=xxxxxx --sign-key=xxxxxxx --gpg-options=--default-key=xxxxxx --archive-dir=/opt/aa/service/nas/restores --tempdir=/opt/aa/service/nas/restores s3+http://<amazone url>/office-demo.accessanywhere.net /opt/aa/service/nas/restores/office
Run fine without errors as it's the same UID/GID etc. But eventually it now barfs out with a 

<code>
tores/duplicity-sQKaRZ-tempdir/mktemp-kgeAuN-75
Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-3Pq-mM-26 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-3Pq-mM-26 Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-T0z4xe-67 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-T0z4xe-67 Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-t8culd-72 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-t8culd-72 Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-eBy5OU-87 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-eBy5OU-87 Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp--H-_I3-29 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp--H-_I3-29 Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-NSeApT-82 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-NSeApT-82 Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-_m-wf1-91 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-_m-wf1-91 Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-r1Z3CO-83 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-r1Z3CO-83 Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-RLNUrL-68 DEBUG:duplicity:Removing still remembered temporary file /opt/aa/service/nas/restores/duplicity-sQKaRZ-tempdir/mktemp-RLNUrL-68 
Traceback (most recent call last):
 File "/usr/bin/duplicity", line 1241, in ?
   with_tempdir(main)
 File "/usr/bin/duplicity", line 1234, in with_tempdir
   fn()
 File "/usr/bin/duplicity", line 1188, in main
   restore(col_stats)
 File "/usr/bin/duplicity", line 542, in restore
   restore_get_patched_rop_iter(col_stats)):
File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line 519, in Write_ROPaths 
   for ropath in rop_iter:
File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line 492, in integrate_patch_iters 
   final_ropath = patch_seq2ropath(normalize_ps(patch_seq))
File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line 472, in patch_seq2ropath 
   misc.copyfileobj(current_file, tempfp)
File "/usr/lib/python2.4/site-packages/duplicity/misc.py", line 170, in copyfileobj 
   outfp.write(buf)
IOError: [Errno 28] No space left on device

ERROR:duplicity:Traceback (most recent call last):
 File "/usr/bin/duplicity", line 1241, in ?
   with_tempdir(main)
 File "/usr/bin/duplicity", line 1234, in with_tempdir
   fn()
 File "/usr/bin/duplicity", line 1188, in main
   restore(col_stats)
 File "/usr/bin/duplicity", line 542, in restore
   restore_get_patched_rop_iter(col_stats)):
File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line 519, in Write_ROPaths 
   for ropath in rop_iter:
File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line 492, in integrate_patch_iters 
   final_ropath = patch_seq2ropath(normalize_ps(patch_seq))
File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line 472, in patch_seq2ropath 
   misc.copyfileobj(current_file, tempfp)
File "/usr/lib/python2.4/site-packages/duplicity/misc.py", line 170, in copyfileobj 
   outfp.write(buf)
IOError: [Errno 28] No space left on device
</code>
This despite that the /opt/aa/service/nas path is a 400MB volume, that is totally empty.
More interestingly is that at the time of this error (duplicity just hangs it doesn't crash) the 
Virtual Mem. footprint is 310Mb with 12MB resident.

And all the GPG processes look like:
nas 2302 2250 0 16:39 pts/1 00:00:00 gpg --status-fd 33 --passphrase-fd 37 --logger-fd 7 --batch --no-tty --default-key xxxxx --no-secmem-warning --default-key=xxxxx --decrypt nas 2308 2250 0 16:39 pts/1 00:00:00 gpg --status-fd 39 --passphrase-fd 43 --logger-fd 34 --batch --no-tty --default-key xxxxxx --no-secmem-warning --default-key=xxxxx --decrypt nas 2312 2250 0 16:39 pts/1 00:00:00 gpg --status-fd 44 --passphrase-fd 48 --logger-fd 40 --batch --no-tty --default-key xxxxx --no-secmem-warning --default-key=xxxxx --decrypt nas 2314 2250 0 16:39 pts/1 00:00:00 gpg --status-fd 48 --passphrase-fd 52 --logger-fd 45 --batch --no-tty --default-key xxxxxx --no-secmem-warning --default-key=xxxxx --decrypt 



Colin Ryan


Kenneth Loafman wrote:

Sorry for the slow response.  This seems to be a ulimit issue, but
that's not normal for only 45 incrementals.  Please run 'ulimit -n' and
post the response here.  Try increasing the ulimit with 'ulimit -n 4096'
or higher and retry.  That could help.

I'm not sure what's happening, but its possible that the permission
failures are somehow eating up file slots.  During the run you could try
'lsof -p <duplicity's pid>' just to see if any of those files are open.

...Thanks,
...Ken

Colin Ryan wrote:

Update:

Tried this same test again and it is not always that this failure leaves
the rest of the system unable to fork other processes such as "ls" or
"top" etc etc. sometimes yes, sometimes no...in any even duplicity does
continue to grow in excess of 200Mb put I do have physical RAM reported
as free when this occurs.

Any thoughts?

Colin Ryan wrote:

I should know the answer to this but can't seem to confirm. Clearly
such errors are generally flimit/ulimit issues or RAM.

But I'm testing restore a not huge ( ~ 8 GB archive that is only 1
full and 45 days of incremental's) and get the following from the
following command line.

/duplicity restore  -v9 --encrypt-key=xxxxxxx --sign-key=xxxxxx
--gpg-options='--default-key=xxxxxxx'
--archive-dir="/opt/aa/service/nas/restores"
--tempdir="/opt/aa/service/nas/restores" --ignore-errors
s3+http://URL/<backup set name> "/opt/aa/service/nas/restores/office"

I'm using the -ignore-errors as I'm unpacking as a non-root user other
than the one that did the backups so it was throwing "no permission"
errors on what I expect was the chmod/chown stages ( I say this
because the files themselves were extracted)...Anyhow...

Version is 6.0.5 hand rolled in Debian Lenny.

When it ceases the system is unable to fork any other processes until
I kill duplicity.

A already running top in another terminal shows that duplicity at this
point is ~ 200 MB virtual and 11 MB resident but that I have ~ 200M
RAM free (this is a fairly small footprint system).

I believe it's out of memory for forking but is it normal.

<code>
BEGNj3-tempdir/mktemp-QYdP4e-85
DEBUG:duplicity:Removing still remembered temporary file
/opt/aa/service/nas/restores/duplicity-BEGNj3-tempdir/mktemp-QYdP4e-85
Removing still remembered temporary file
/opt/aa/service/nas/restores/duplicity-BEGNj3-tempdir/mktemp-aDi69N-61
DEBUG:duplicity:Removing still remembered temporary file
/opt/aa/service/nas/restores/duplicity-BEGNj3-tempdir/mktemp-aDi69N-61
Removing still remembered temporary file
/opt/aa/service/nas/restores/duplicity-BEGNj3-tempdir/mktemp-2YCFpS-81
DEBUG:duplicity:Removing still remembered temporary file
/opt/aa/service/nas/restores/duplicity-BEGNj3-tempdir/mktemp-2YCFpS-81
Removing still remembered temporary file
/opt/aa/service/nas/restores/duplicity-BEGNj3-tempdir/mktemp-CXX67i-73
DEBUG:duplicity:Removing still remembered temporary file
/opt/aa/service/nas/restores/duplicity-BEGNj3-tempdir/mktemp-CXX67i-73
Traceback (most recent call last):
 File "/usr/bin/duplicity", line 1241, in ?
   with_tempdir(main)
 File "/usr/bin/duplicity", line 1234, in with_tempdir
   fn()
 File "/usr/bin/duplicity", line 1188, in main
   restore(col_stats)
 File "/usr/bin/duplicity", line 542, in restore
   restore_get_patched_rop_iter(col_stats)):
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
519, in Write_ROPaths
   for ropath in rop_iter:
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
491, in integrate_patch_iters
   for patch_seq in collated:
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
376, in yield_tuples
   setrorps(overflow, elems)
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
365, in setrorps
   elems[i] = iter_list[i].next()
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
110, in difftar2path_iter
   tarinfo_list = [tar_iter.next()]
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
326, in next
   self.set_tarfile()
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
320, in set_tarfile
   self.current_fp = self.fileobj_iter.next()
 File "/usr/bin/duplicity", line 579, in get_fileobj_iter
   manifest.volume_info_dict[vol_num])
 File "/usr/bin/duplicity", line 603, in restore_get_enc_fileobj
   fileobj = tdp.filtered_open_with_delete("rb")
 File "/usr/lib/python2.4/site-packages/duplicity/dup_temp.py", line
114, in filtered_open_with_delete
   fh = FileobjHooked(path.DupPath.filtered_open(self, mode))
 File "/usr/lib/python2.4/site-packages/duplicity/path.py", line 724,
in filtered_open
   return gpg.GPGFile(False, self, gpg_profile)
 File "/usr/lib/python2.4/site-packages/duplicity/gpg.py", line 135,
in __init__
   attach_fhs={'stdin': encrypt_path.open("rb"),
 File "/usr/lib/python2.4/site-packages/duplicity/GnuPGInterface.py",
line 365, in run
   create_fhs, attach_fhs)
 File "/usr/lib/python2.4/site-packages/duplicity/GnuPGInterface.py",
line 407, in _attach_fork_exec
   process.pid = os.fork()
OSError: [Errno 11] Resource temporarily unavailable

ERROR:duplicity:Traceback (most recent call last):
 File "/usr/bin/duplicity", line 1241, in ?
   with_tempdir(main)
 File "/usr/bin/duplicity", line 1234, in with_tempdir
   fn()
 File "/usr/bin/duplicity", line 1188, in main
   restore(col_stats)
 File "/usr/bin/duplicity", line 542, in restore
   restore_get_patched_rop_iter(col_stats)):
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
519, in Write_ROPaths
   for ropath in rop_iter:
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
491, in integrate_patch_iters
   for patch_seq in collated:
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
376, in yield_tuples
   setrorps(overflow, elems)
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
365, in setrorps
   elems[i] = iter_list[i].next()
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
110, in difftar2path_iter
   tarinfo_list = [tar_iter.next()]
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
326, in next
   self.set_tarfile()
 File "/usr/lib/python2.4/site-packages/duplicity/patchdir.py", line
320, in set_tarfile
   self.current_fp = self.fileobj_iter.next()
 File "/usr/bin/duplicity", line 579, in get_fileobj_iter
   manifest.volume_info_dict[vol_num])
 File "/usr/bin/duplicity", line 603, in restore_get_enc_fileobj
   fileobj = tdp.filtered_open_with_delete("rb")
 File "/usr/lib/python2.4/site-packages/duplicity/dup_temp.py", line
114, in filtered_open_with_delete
   fh = FileobjHooked(path.DupPath.filtered_open(self, mode))
 File "/usr/lib/python2.4/site-packages/duplicity/path.py", line 724,
in filtered_open
   return gpg.GPGFile(False, self, gpg_profile)
 File "/usr/lib/python2.4/site-packages/duplicity/gpg.py", line 135,
in __init__
   attach_fhs={'stdin': encrypt_path.open("rb"),
 File "/usr/lib/python2.4/site-packages/duplicity/GnuPGInterface.py",
line 365, in run
   create_fhs, attach_fhs)
 File "/usr/lib/python2.4/site-packages/duplicity/GnuPGInterface.py",
line 407, in _attach_fork_exec
   process.pid = os.fork()
OSError: [Errno 11] Resource temporarily unavailable

Error in atexit._run_exitfuncs:
Traceback (most recent call last):
 File "atexit.py", line 24, in _run_exitfuncs
   func(*targs, **kargs)
 File "threading.py", line 634, in __exitfunc
   t.join()
 File "threading.py", line 540, in join
   self.__block.wait()
 File "threading.py", line 203, in wait
   waiter.acquire()
</code>

Cheers and Thanks

Colin


_______________________________________________
Duplicity-talk mailing list
address@hidden
http://lists.nongnu.org/mailman/listinfo/duplicity-talk


_______________________________________________
Duplicity-talk mailing list
address@hidden
http://lists.nongnu.org/mailman/listinfo/duplicity-talk
------------------------------------------------------------------------ 

_______________________________________________
Duplicity-talk mailing list
address@hidden
http://lists.nongnu.org/mailman/listinfo/duplicity-talk
reply via email to
[Prev in Thread] Current Thread [Next in Thread]