AssertionError re: BLOCKSIZE in tarfile.py when fields exceed expected size.

[william]

When asking duplicity to perform a backup, it fails with a traceback.

Note: this error only affects a particular directory.. if I use the same options on a different directory, everything runs fine. Also, running the command on the failing directory with --dry-run works fine.. this bug occurs every time it is run on this particular directory.

There is nothing special about this directory that I'm aware of.. its one of dozens of home directories, all created/managed by a control panel product for web hosting, so the directories have identical layouts and permissions and whatnot.

Got this error -
Traceback (most recent call last):
  File "/usr/bin/duplicity", line 1236, in ?
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1229, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1207, in main
    full_backup(col_stats)
  File "/usr/bin/duplicity", line 416, in full_backup
    globals.backend)
  File "/usr/bin/duplicity", line 294, in write_multivol
    globals.gpg_profile, globals.volsize)
  File "/usr/lib/python2.4/site-packages/duplicity/gpg.py", line 282, in GPGWriteFile
    data = block_iter.next(min(block_size, bytes_to_go)).data
  File "/usr/lib/python2.4/site-packages/duplicity/diffdir.py", line 509, in next
    result = self.process(self.input_iter.next(), size)
  File "/usr/lib/python2.4/site-packages/duplicity/diffdir.py", line 212, in get_delta_iter
    (new_path, sig_path, sigTarFile))
  File "/usr/lib/python2.4/site-packages/duplicity/robust.py", line 38, in check_common_error
    return function(*args)
  File "/usr/lib/python2.4/site-packages/duplicity/diffdir.py", line 142, in get_delta_path
    sigTarFile.addfile(ti)
  File "/usr/lib/python2.4/site-packages/duplicity/tarfile.py", line 764, in addfile
    assert len(full_headers) % BLOCKSIZE == 0
AssertionError

duplicity 0.6.06

 Args: /usr/bin/duplicity -v6 --log-file /tmp/duplicitylogs/2009_11_27/sitefiles_XXXX.com /home/username ssh://backup_
eth:<email address hidden>:22/gm_xxxxnet/duplicity_sitefiles_xxxx.com

INFO 1
. Linux xxxx.net 2.6.18-92.1.22.el5 #1 SMP Tue Dec 16 12:03:43 EST 2008 i686 i686

INFO 1
. /usr/bin/python 2.4.3 (#1, Sep 3 2009, 15:37:12)
. [GCC 4.1.2 20080704 (Red Hat 4.1.2-46)]

tail /tmp/duplicitylogs/2009_11_27/sitefiles_XXXX.com

INFO 4 'etc/svn-access.conf'
. A etc/svn-access.conf

INFO 4 'etc/svn.basic.passwd'
. A etc/svn.basic.passwd

INFO 4 'homes'
. A homes

[william (williamdw)]

By the way - onice this happens, duplicity doesn't exit, it just sits there forever and has to be killed.

Strace of this issue..

futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x8241bc8, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
unlink("/tmp/duplicity-vNyyyB-tempdir/mkstemp-9aaLkR-1") = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
unlink("/tmp/duplicity-vNyyyB-tempdir/mktemp-M808f7-2") = 0
futex(0x82ac690, FUTEX_WAKE, 1) = 0
rmdir("/tmp/duplicity-vNyyyB-tempdir") = 0
futex(0x829c898, FUTEX_WAKE, 1) = 0
write(2, "Traceback (most recent call last"..., 35Traceback (most recent call last):
) = 35
open("/usr/bin/duplicity", O_RDONLY|O_LARGEFILE) = 8
write(2, " File \"/usr/bin/duplicity\", lin"..., 45 File "/usr/bin/duplicity", line 1236, in ?
) = 45
fstat64(8, {st_mode=S_IFREG|0755, st_size=46428, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fc4000
read(8, "#!/usr/bin/python\n# -*- Mode:Pyt"..., 4096) = 4096
read(8, "getpass.getpass(\"Retype passphra"..., 4096) = 4096
read(8, "kup.get_local_manifest()\n "..., 4096) = 4096
read(8, "st=True,\n "..., 4096) = 4096
read(8, "fdir.DirDelta(globals.select,\n "..., 4096) = 4096
read(8, "c_fileobj(backend, filename, vol"..., 4096) = 4096
read(8, " globals.archive_dir.appe"..., 4096) = 4096
read(8, " if ext in suffixes:\n "..., 4096) = 4096
read(8, "edpass):\n globals"..., 4096) = 4096
read(8, "ackup.time:\n self.typ"..., 4096) = 4096
read(8, "st_backup info\n "..., 4096) = 4096
write(2, " ", 4 ) = 4
write(2, "with_tempdir(main)\n", 19with_tempdir(main)
) = 19
close(8) = 0
munmap(0xb7fc4000, 4096) = 0
open("/usr/bin/duplicity", O_RDONLY|O_LARGEFILE) = 8
write(2, " File \"/usr/bin/duplicity\", lin"..., 56 File "/usr/bin/duplicity", line 1229, in with_tempdir
) = 56
fstat64(8, {st_mode=S_IFREG|0755, st_size=46428, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fc4000
read(8, "#!/usr/bin/python\n# -*- Mode:Pyt"..., 4096) = 4096
read(8, "getpass.getpass(\"Retype passphra"..., 4096) = 4096
read(8, "kup.get_local_manifest()\n "..., 4096) = 4096
read(8, "st=True,\n "..., 4096) = 4096
read(8, "fdir.DirDelta(globals.select,\n "..., 4096) = 4096
read(8, "c_fileobj(backend, filename, vol"..., 4096) = 4096
read(8, " globals.archive_dir.appe"..., 4096) = 4096
read(8, " if ext in suffixes:\n "..., 4096) = 4096
read(8, "edpass):\n globals"..., 4096) = 4096
read(8, "ackup.time:\n self.typ"..., 4096) = 4096
read(8, "st_backup info\n "..., 4096) = 4096
write(2, " ", 4 ) ...

[Kenneth Loafman (kenneth-loafman)]

In the directory you're trying to back up is there an invalid date/time stamp, notably one before 1970 or after 2038?

[az (az-debian)]

this issue has just been re-reported (debian bug #605878, over here: http://bugs.debian.org/605878), with 0.6.08:
after a successful remove-older-than, the following backup op fails with the blocksize assertion and any subsequent backups
fail in the same fashion.

[fuscata (d-launchpad-fuscata-com)]

I haven't been able to pin down the exact object that causes the problem on my system, however, it does look like long directory/file owner's user name may be the culprit, as described here:
http://comments.gmane.org/gmane.comp.sysutils.backup.duplicity.general/661

I have a user on the system with a 50-character name, and excluding the directories owned by that user seems to have solved the problem.

[Julian O. (g-launchpad-somethinkodd-com)]

A quick analysis of this bug, from looking at the tarfile.py code.

Line 386: TarInfo.getheader() returns a tar header block which is padded to 512 bytes.

It constructs it from several parts, such as the "member" name, file permissions, link name, user name, group name, etc.

Each field is padded to its own field length. e.g. User and group names are padded to 32 characters. They however, are not restricted to their appropriate sizes.

The code will fail to pad/truncate the whole header to 512 bytes if any of these fields exceed their intended size. The assert checks the size is a multiple of 512.

I am not familiar with each of the fields or external checks to ensure that they are not too long, but those checks do not appear to be here. I cannot tell if the appropriate action is to truncate the fields, to assert, or to take some other preventative action when these fields are too long.