Backing up fails with 'IOError CRC check failed'.

Bug #875676 reported by Georg Schölly on 2011-10-16
98
This bug affects 15 people
Affects Status Importance Assigned to Milestone
Duplicity
High
Kenneth Loafman
duplicity (Ubuntu)
High
Unassigned

Bug Description

For 4 days déjà dup hasn't been able to perform a backup. It fails with the error

Failed to read /tmp/duplicity-lJcUDl-tempdir/mktemp-o4LYSJ-1: (<type 'exceptions.IOError'>, IOError('CRC check failed 0x8434f7d2L != 0x3d503338L',), <traceback object at 0x9fe0554>)

There is another similar bug #676767 where deleting ~/.cache/deja-dup helps. In this case it doesn't.

I'm quite certain that my backup drive isn't corrupted. (It's a raid5.) I'd be happy to provide any additional information needed.

----------

System information:
Ubuntu 11.10
deja-dup 20.0-0ubuntu3
duplicity 0.6.15-0ubuntu2

Logs:
deja-dup.log: http://pastie.org/2705320
deja-dup.gsettings: http://pastie.org/2705322

Michael Terry (mterry) wrote :

I've never seen this error before. I don't suppose it's possible for you to share the backup data itself? I totally understand if you can't, just thought I'd ask.

Georg Schölly (georg-schoelly) wrote :

I've looked through the deja-dup log which mentions running this command:

/usr/bin/duplicity collection-status --exclude=/home/gs/Downloads... --include=/home/gs ... --exclude=** --gio sftp://<email address hidden>/home/gs/Backup --no-encryption --verbosity=9 --gpg-options=--no-use-agent --archive-dir=/home/gs/.cache/deja-dup --log-fd=16

but interestingly this yields the following error if I run it in a terminal:

    OSError: [Errno 9] Bad file descriptor

which is not the same as reported by Deja-Dup. Am I running the wrong command or is it correct that not the same error gets reported?

(Full traceback: http://pastie.org/2745708)

Georg Schölly (georg-schoelly) wrote :

Never mind, I can see where that last backtrace came from. (It was the --log-fd argument)

Georg Schölly (georg-schoelly) wrote :

The error gets thrown in the file /usr/bin/duplicity on line 960

class SrcIter:
    ...
    def next(self, size):
        try:
--> res = Block(self.fileobj.read(size))
        except Exception:

I've attached the failing gzip file. Ungzipping it on the command line gives an EOF error.

Michael Terry (mterry) wrote :

Ah! Thanks for the research, Georg!

So this looks like a similar error we fixed to prevent volume difftar.gz files from causing CRC check failures, but it's now with sigtar.gz files.

For a workaround, you can delete the sigtar.gz file (which will invalidate that incremental backup completely) and next backup should succeed in creating a new incremental backup.

But for a long term fix, we need to either re-upload sigtar files on resume or find a way to verify the checksum.

Michael Terry (mterry) wrote :

Georg, do you still have those files around? Can I have a list of files on the backend when this happend? Ideally also a list of the files in ~/.cache/deja-dup at the time?

I understand if you don't have them, but thought I'd ask.

If I remove the newer files in the backup, delete the cache and restore
the damaged file, is that enough to recreate how it was before?

Michael Terry (mterry) wrote :

Uh, possibly not. I wouldn't worry about it if you've moved on. I was just having trouble reproducing the problem in a laboratory setting. I'll try a few things more.

Jason Daborn (mtx-lives) wrote :

Looks like I'm having the same error:

Error:
Failed to read /home/user/.cache/deja-dup/tmp/duplicity-_iMN0j-tempdir/mktemp-gaL9K9-1: (<type 'exceptions.IOError'>, IOError('CRC check failed 0x5e4002c5 != 0x7abf8fa9L',), <traceback object at 0x27b3ea8>)

Additional info:
Has been backing up without issue to a Synology NAS for months. Not sure if this may be the issue, but I had clicked the backup later button due to needing to get stuff done and I may have done a yum update without it completing? I have checked the location of the file it is complaining about and the directory is empty. I have changed the destination to an external HDD and it is now doing a backup to that ok.
Having successfully finished a backup to a new destination (External HDD) I switched it back the NAS box and it failed with the previous error.

duplicity.x86_64 0.6.22-5.fc20
deja-dup.x86_64 27.3.1-2.fc20

Giana (giana-n) wrote :

Every time I start a backup I get the following error:
Failed to read /home/user/.cache/deja-dup/tmp/duplicity-7EsAky-tempdir/mktemp-hqHmHI-63: (<type 'exceptions.IOError'>, IOError('CRC check failed 0x6ae5ab23 != 0x78b803e5L',), <traceback object at 0x7f4f3cfa06c8>)
Deleting the cace dir does not help.

This issue showed up since some weeks but apparently I didn't change settings.
I'm using Ubuntu 14.10 with kernel 3.16.0-34-generic
deja-dup 32.0-0ubuntu1.1
duplicity 0.6.23-1ubuntu5
Any clue on solving and debugging?

Giana (giana-n) wrote :

Short update:
Deleting the cache dir does not help but deleting (or renaming) the destination backup directory yes.
A fresh backup has been done without problem.

JadeYe (newebgen) wrote :

Hello everyone,
Is this bug solved??

Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in deja-dup (Ubuntu):
status: New → Confirmed
Matej Kovacic (matej-kovacic) wrote :

I have the same error with DejaDup in Ubuntu 16.04.

I am trying to run a backup (not restore!), and got this error:

Ni mogoče brati /tmp/duplicity-gUZKem-tempdir/mktemp-jecFmU-5: (<type 'exceptions.IOError'>, IOError('CRC check failed 0x5528869f != 0x2aeb4411L',), <traceback object at 0x7fd5292a9830>)

It is in slovenian, but it means:
Cannot read /tmp/duplicity-gUZKem-tempdir/mktemp-jecFmU-5: (<type 'exceptions.IOError'>, IOError('CRC check failed 0x5528869f != 0x2aeb4411L',), <traceback object at 0x7fd5292a9830>)

I tried to delete .cache/deja-dup, but the error is still there.

I am doing a backup to a remote server via ssh. I have reported this under another bug, but it seems it belongs here.

Anyway, I deleted a file "duplicity-new-signatures.20161011T065304Z.to.20161013T050922Z.sigtar.gz" on a backup server, and now it is working (however, it started a new backup). But this is really bad.

And just another question - would it be possible for me to restore backup in that case?

Niklas Sombert (ytvwld) wrote :

I think I've got the same problem.

DejaDup with Ubuntu 16.04 prints the same error message and even duplicity can't do anything in the backup folder. ("remove-older-than" fails with "(<type 'exceptions.IOError'>, IOError('CRC check failed 0xb1276c7b != 0x9b944aa5L',), <traceback object at 0x7faa2fe00ef0>)".)

If I delete or move duplicity-new-signatures.20160922T090645Z.to.20160929T083644Z.sigtar.gz, it might work again.

But this is really not good.

Matej Kovacic (matej-kovacic) wrote :

No that it is not good. This is completely irresponsible and lame.

It is a shame, that so important software is a part of core Ubuntu system. Canonical should reconsider using it. Because backup is critical and if DejaDup is a part of a core system, people rely on it.

There is a disconnect between Ubuntu distribution and upstream distribution
(me). Ubuntu will not, repeat will not, allow changes that add
functionality, or upgrade the version number of a product in a
distribution. I can't live with that, so my distribution version changes
with every release. Before you upgrade manually, apt remove the old
version of duplicity and install from one of the sources below to stay
up-to-date.

Please upgrade to the current version of duplicity. This will assure that
any bugs fixed since your release are available and my fix your issue.

There are three options:

   - Release tarball Install - https://launchpad.net/duplicity/+download
   - Daily duplicity builds -
   https://launchpad.net/~duplicity-team/+archive/ubuntu/daily
   - Stable duplicity builds -
   https://launchpad.net/~duplicity-team/+archive/ubuntu/ppa

On Mon, Jan 30, 2017 at 8:04 AM, Matej Kovacic <email address hidden>
wrote:

> No that it is not good. This is completely irresponsible and lame.
>
> It is a shame, that so important software is a part of core Ubuntu
> system. Canonical should reconsider using it. Because backup is critical
> and if DejaDup is a part of a core system, people rely on it.
>
> --
> You received this bug notification because you are subscribed to
> Duplicity.
> https://bugs.launchpad.net/bugs/875676
>
> Title:
> Backing up fails with 'IOError CRC check failed'.
>
> Status in Déjà Dup:
> New
> Status in Duplicity:
> New
> Status in deja-dup package in Ubuntu:
> Confirmed
>
> Bug description:
> For 4 days déjà dup hasn't been able to perform a backup. It fails
> with the error
>
> Failed to read /tmp/duplicity-lJcUDl-tempdir/mktemp-o4LYSJ-1: (<type
> 'exceptions.IOError'>, IOError('CRC check failed 0x8434f7d2L !=
> 0x3d503338L',), <traceback object at 0x9fe0554>)
>
> There is another similar bug #676767 where deleting ~/.cache/deja-dup
> helps. In this case it doesn't.
>
> I'm quite certain that my backup drive isn't corrupted. (It's a
> raid5.) I'd be happy to provide any additional information needed.
>
> ----------
>
> System information:
> Ubuntu 11.10
> deja-dup 20.0-0ubuntu3
> duplicity 0.6.15-0ubuntu2
>
> Logs:
> deja-dup.log: http://pastie.org/2705320
> deja-dup.gsettings: http://pastie.org/2705322
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/deja-dup/+bug/875676/+subscriptions
>

Vej (vej) wrote :

Setting to "Confirmed", because this bug affects multiple users.

Changed in deja-dup:
status: New → Confirmed
Changed in duplicity:
status: New → Confirmed
Changed in deja-dup:
importance: Undecided → High
Changed in duplicity:
importance: Undecided → High
milestone: none → 0.7.12
Vej (vej) on 2017-02-17
tags: added: xenial
Changed in deja-dup (Ubuntu):
importance: Undecided → High
Changed in duplicity:
milestone: 0.7.12 → 0.7.13
Changed in duplicity:
milestone: 0.7.13 → 0.7.14
Changed in duplicity:
milestone: 0.7.13.1 → 0.7.14
Michael Terry (mterry) on 2017-08-02
no longer affects: deja-dup
Michael Terry (mterry) on 2017-08-21
affects: deja-dup (Ubuntu) → duplicity (Ubuntu)
Changed in duplicity:
assignee: nobody → Kenneth Loafman (kenneth-loafman)
milestone: 0.7.14 → 0.7.15
status: Confirmed → In Progress
Changed in duplicity:
milestone: 0.7.15 → 0.7.16
Changed in duplicity:
milestone: 0.7.16 → 0.7.17
Changed in duplicity:
milestone: 0.7.17 → none
Ian Molton (spyro2) wrote :

Hi,

This bug is affecting me still.

$ duplicity --version
duplicity 0.7.17

$ apt-cache show duplicity
Package: duplicity
Architecture: amd64
Version: 0.7.17-0ubuntu1
Priority: optional
Section: utils
Origin: Ubuntu

In the past (129 days ago!) I tried to fix this but got nowhere.

Given that the problem persists, perhaps we can debug this together? Where shall I start? How do I get useful debugging out of this for you (obviously I cannot share my mothers data (her machine)).

I'm a dev, so complex instructions wont be a problem. Let me know if I can help?

(I havent tried to see if its fixed in the development builds of duplicity, since I don't want to accidentally clear the error somehow and remove the ability to reproduce it)

A couple of things to check:

- If you run with -v9 you will get a long and detailed log of the run. The individual file that is causing the problem should be listed. Test that file by unzipping and decoding. If it fails, you can delete the incrementals containing it and all subsequent incrementals. You will need to do this in a separate directory so you don't modify the original file.

- Check your system logs for "Bad File Descriptor" or other IO errors. A bad file descriptor means that you've run out of descriptors and need to set the limit much higher. This can happen with a long string of incrementals.

- Please post the command line you use.

Chris (qubitcoder) wrote :

I'm also seeing this error pop up in the last few days, despite not making any changes to the backup configuration (using deja-dup).

Thanks Kenneth for the suggestion above about running with the -v9 command.

Is there a way that I could see the exact duplicity backup command that's triggered by deja-dup? (I'm new to duplicity & deja-dup). Thanks!

Here's my system details:

➜ ~ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 18.04.1 LTS
Release: 18.04
Codename: bionic

➜ ~ uname -a
Linux ryzen 4.15.0-30-generic #32-Ubuntu SMP Thu Jul 26 17:42:43 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

And the error message:

Traceback (innermost last):
  File "/usr/bin/duplicity", line 1555, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1541, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1393, in main
    do_backup(action)
  File "/usr/bin/duplicity", line 1523, in do_backup
    incremental_backup(sig_chain)
  File "/usr/bin/duplicity", line 668, in incremental_backup
    globals.backend)
  File "/usr/bin/duplicity", line 432, in write_multivol
    at_end = gpg.GzipWriteFile(tarblock_iter, tdp.name, globals.volsize)
  File "/usr/lib/python2.7/dist-packages/duplicity/gpg.py", line 446, in GzipWriteFile
    new_block = block_iter.next()
  File "/usr/lib/python2.7/dist-packages/duplicity/diffdir.py", line 523, in next
    result = self.process(self.input_iter.next())
  File "/usr/lib/python2.7/dist-packages/duplicity/diffdir.py", line 195, in get_delta_iter
    for new_path, sig_path in collated:
  File "/usr/lib/python2.7/dist-packages/duplicity/diffdir.py", line 286, in collate2iters
    relem2 = riter2.next()
  File "/usr/lib/python2.7/dist-packages/duplicity/diffdir.py", line 354, in combine_path_iters
    refresh_triple_list(triple_list)
  File "/usr/lib/python2.7/dist-packages/duplicity/diffdir.py", line 341, in refresh_triple_list
    new_triple = get_triple(old_triple[1])
  File "/usr/lib/python2.7/dist-packages/duplicity/diffdir.py", line 327, in get_triple
    path = path_iter_list[iter_index].next()
  File "/usr/lib/python2.7/dist-packages/duplicity/diffdir.py", line 239, in sigtar2path_iter
    for tarinfo in tf:
  File "/usr/lib/python2.7/tarfile.py", line 2510, in next
    tarinfo = self.tarfile.next()
  File "/usr/lib/python2.7/tarfile.py", line 2350, in next
    self.fileobj.seek(self.offset - 1)
  File "/usr/lib/python2.7/gzip.py", line 443, in seek
    self.read(1024)
  File "/usr/lib/python2.7/gzip.py", line 268, in read
    self._read(readsize)
  File "/usr/lib/python2.7/gzip.py", line 332, in _read
    self._read_eof()
  File "/usr/lib/python2.7/gzip.py", line 354, in _read_eof
    hex(self.crc)))
 IOError: CRC check failed 0x83aebe8 != 0xa6bb597L

Chris (qubitcoder) wrote :

After running the backup again, I'm now getting this error message: "UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position 37: ordinal not in range(128)".

Unfortunately, I've encountered this several times in the past. Also, I can no longer see the backup log in the deja-dup gui, only the error message.

I wonder if there's a log file of the entire backup process, so that I could at least determine the problematic file(s)?

Here's the full error message:

Traceback (innermost last):
  File "/usr/bin/duplicity", line 1555, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1541, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1393, in main
    do_backup(action)
  File "/usr/bin/duplicity", line 1523, in do_backup
    incremental_backup(sig_chain)
  File "/usr/bin/duplicity", line 668, in incremental_backup
    globals.backend)
  File "/usr/bin/duplicity", line 454, in write_multivol
    (tdp, dest_filename, vol_num)))
  File "/usr/lib/python2.7/dist-packages/duplicity/asyncscheduler.py", line 146, in schedule_task
    return self.__run_synchronously(fn, params)
  File "/usr/lib/python2.7/dist-packages/duplicity/asyncscheduler.py", line 172, in __run_synchronously
    ret = fn(*params)
  File "/usr/bin/duplicity", line 453, in <lambda>
    vol_num: put(tdp, dest_filename, vol_num),
  File "/usr/bin/duplicity", line 342, in put
    backend.put(tdp, dest_filename)
  File "/usr/lib/python2.7/dist-packages/duplicity/backend.py", line 395, in inner_retry
    % (n, e.__class__.__name__, util.uexc(e)))
  File "/usr/lib/python2.7/dist-packages/duplicity/util.py", line 79, in uexc
    return ufn(unicode(e).encode('utf-8'))
 UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position 37: ordinal not in range(128)

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers