Debian Bug report logs - #654198
obnam fsck: error: Error -3 while decompressing data: incorrect data check

Toggle useless messages

Message #5 received at submit@bugs.debian.org (full text, mbox, reply):

From: Sami Liedes <sliedes@cc.hut.fi>

To: Debian Bug Tracking System <submit@bugs.debian.org>

Subject: obnam fsck: error: Error -3 while decompressing data: incorrect data check

Date: Mon, 2 Jan 2012 13:31:56 +0200

[Message part 1 (text/plain, inline)]

Package: obnam
Version: 0.24.1-1
Severity: normal

[This may actually be a data loss bug, consider grave severity]

I tested obnam by backing up a few subdirectories of my home
directory. I interrupted the backup a few times with ctrl-C; don't
know if that's required for this bug to happen.

My ~/.obnam.conf:

------------------------------------------------------------
[config]
repository = /media/backup/obnam
compress-with = gzip
exclude = /home/.*/scratch
exclude-caches = True
root = /
#log = /home/sliedes/scratch/obnam.log
------------------------------------------------------------

After doing a backup, obnam fsck fails (after running for quite a
while):

------------------------------------------------------------
$ obnam fsck
Checking 10873/246658: lh:903:/home/sliedes/Maildir/.old.nilfs/dovecot.indexTraceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/cliapp/app.py", line 141, in _run
    self.process_args(args)
  File "/usr/lib/python2.7/dist-packages/obnamlib/app.py", line 127, in process_args
    cliapp.Application.process_args(self, args)
  File "/usr/lib/python2.7/dist-packages/cliapp/app.py", line 318, in process_args
    method(args[1:])
  File "/usr/lib/python2.7/dist-packages/obnamlib/plugins/fsck_plugin.py", line 304, in fsck
    for more in work.do() or []:
  File "/usr/lib/python2.7/dist-packages/obnamlib/plugins/fsck_plugin.py", line 103, in do
    metadata = self.repo.get_metadata(self.genid, self.filename)
  File "/usr/lib/python2.7/dist-packages/obnamlib/repo.py", line 511, in get_metadata
    encoded = self.client.get_metadata(gen, filename)
  File "/usr/lib/python2.7/dist-packages/obnamlib/clientmetadatatree.py", line 291, in get_metadata
    tree = self.find_generation(genid)
  File "/usr/lib/python2.7/dist-packages/obnamlib/clientmetadatatree.py", line 175, in find_generation
    t_genid = self._lookup_int(t, key)
  File "/usr/lib/python2.7/dist-packages/obnamlib/clientmetadatatree.py", line 153, in _lookup_int
    return struct.unpack('!Q', tree.lookup(key))[0]
  File "/usr/lib/python2.7/dist-packages/larch/tree.py", line 150, in lookup
    node = self._get_node(node[k])
  File "/usr/lib/python2.7/dist-packages/larch/tree.py", line 119, in _get_node
    return self.node_store.get_node(node_id)
  File "/usr/lib/python2.7/dist-packages/larch/nodestore_disk.py", line 218, in get_node
    encoded = self.vfs.cat(name)
  File "/usr/lib/python2.7/dist-packages/obnamlib/repo.py", line 66, in cat
    repo=self.repo, toplevel=toplevel)
  File "/usr/lib/python2.7/dist-packages/obnamlib/hooks.py", line 109, in call
    return self.hooks[name].call_callbacks(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/obnamlib/hooks.py", line 73, in call_callbacks
    data = callback(data, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/obnamlib/plugins/compression_plugin.py", line 45, in toplevel_read_data
    return zlib.decompress(data)
error: Error -3 while decompressing data: incorrect data check
------------------------------------------------------------

Interestingly, 'obnam verify /home/sliedes/Maildir/.old.nilfs/'
reports "Verify did not find problems.". Hence I'm not sure if this is
actual data loss.

One thing that might be indicative that something else is wrong:
Should the uploaded counter of 'obnam backup' stay at 0 on an
incremental backup when nothing has changed in the directory tree? It
doesn't, instead it increases rather quickly to the gigabytes range
when running it on a 14 gigabyte directory tree, which seems excessive
for an incremental backup where there is nothing to do.

	Sami


-- System Information:
Debian Release: wheezy/sid
  APT prefers unstable
  APT policy: (500, 'unstable')
Architecture: amd64 (x86_64)

Kernel: Linux 3.1.6 (SMP w/8 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages obnam depends on:
ii  libc6             2.13-24
ii  python            2.7.2-9
ii  python-cliapp     0.23-1
ii  python-larch      0.26-1
ii  python-paramiko   1.7.7.1-2
ii  python-tracing    0.6-2
ii  python-ttystatus  0.15-1
ii  python2.6         2.6.7-4
ii  python2.7         2.7.2-9

obnam recommends no packages.

obnam suggests no packages.

-- no debconf information

[signature.asc (application/pgp-signature, inline)]

Message #10 received at submit@bugs.debian.org (full text, mbox, reply):

From: Lars Wirzenius <liw@liw.fi>

To: Sami Liedes <sliedes@cc.hut.fi>, 654198@bugs.debian.org

Cc: Debian Bug Tracking System <submit@bugs.debian.org>

Subject: Re: Bug#654198: obnam fsck: error: Error -3 while decompressing data: incorrect data check

Date: Fri, 6 Apr 2012 15:30:00 +0100

[Message part 1 (text/plain, inline)]

On Mon, Jan 02, 2012 at 01:31:56PM +0200, Sami Liedes wrote:
> error: Error -3 while decompressing data: incorrect data check

My best guess for this is that Obnam managed to write a partial file
to the repository when you interrupted it. This should no longer happen
in the current version.

> Interestingly, 'obnam verify /home/sliedes/Maildir/.old.nilfs/'
> reports "Verify did not find problems.". Hence I'm not sure if this is
> actual data loss.

This would indicate that at least some of the repository didn't get
corrupted. Indeed, it's probably just one or a few files.

> One thing that might be indicative that something else is wrong:
> Should the uploaded counter of 'obnam backup' stay at 0 on an
> incremental backup when nothing has changed in the directory tree? It
> doesn't, instead it increases rather quickly to the gigabytes range
> when running it on a 14 gigabyte directory tree, which seems excessive
> for an incremental backup where there is nothing to do.

The upload counter should show only data that's actually been uploaded.
I guess that the incremental backup caused more data to be uploaded
because of the way the repository got corrupted.

I hate to ask you to do this, but: if you try to do this again, does
it still happen?

-- 
All my predictions will turn out to be false

[signature.asc (application/pgp-signature, inline)]

Message #24 received at 654198-submitter@bugs.debian.org (full text, mbox, reply):

From: Lars Wirzenius <liw@liw.fi>

To: control@bugs.debian.org

Cc: 654198-submitter@bugs.debian.org

Subject: closing 654198

Date: Sun, 22 Apr 2012 15:32:46 +0100

close 654198 0.26-1
thanks

the corruption when obnam is terminated with control-c should be fixed
as of version 0.26-1, but I forgot to include the bug in the changelog.

-- 
All my predictions will turn out to be false

Message #29 received at 654198@bugs.debian.org (full text, mbox, reply):

From: Sami Liedes <sami.liedes@iki.fi>

To: Lars Wirzenius <liw@liw.fi>, 654198@bugs.debian.org, control@bugs.debian.org

Cc: control@bugs.debian.org, 654198-submitter@bugs.debian.org

Subject: Re: Bug#654198: still found

Date: Mon, 23 Apr 2012 00:33:57 +0300

[Message part 1 (text/plain, inline)]

found 654198 0.29-1
thanks

On Sun, Apr 22, 2012 at 03:32:46PM +0100, Lars Wirzenius wrote:
> close 654198 0.26-1
> thanks
> 
> the corruption when obnam is terminated with control-c should be fixed
> as of version 0.26-1, but I forgot to include the bug in the changelog.

Reopening per IRC discussion. I still get an assertion failure with
obnam+larch 0.29-1 if I interrupt obnam before the first checkpoint
(after 13.10 MiB), then run obnam fsck:

------------------------------------------------------------
$ obnam fsck
Checking 3/5: B-tree chunklistTraceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/cliapp/app.py", line 144, in _run
    self.process_args(args)
  File "/usr/lib/python2.7/dist-packages/obnamlib/app.py", line 157, in process_args
    cliapp.Application.process_args(self, args)
  File "/usr/lib/python2.7/dist-packages/cliapp/app.py", line 348, in process_args
    method(args[1:])
  File "/usr/lib/python2.7/dist-packages/obnamlib/plugins/fsck_plugin.py", line 293, in fsck
    for more in work.do() or []:
  File "/usr/lib/python2.7/dist-packages/obnamlib/plugins/fsck_plugin.py", line 241, in do
    forest = larch.open_forest(dirname=self.dirname, vfs=self.repo.fs)
  File "/usr/lib/python2.7/dist-packages/larch/forest.py", line 181, in open_forest
    assert 'key_size' in ns_temp.get_metadata_keys()
AssertionError
------------------------------------------------------------

After finishing the backup by rerunning the same obnam backup command,
obnam fsck seems to be happy.

	Sami

[signature.asc (application/pgp-signature, inline)]

Message #41 received at 654198-submitter@bugs.debian.org (full text, mbox, reply):

From: Lars Wirzenius <liw@liw.fi>

To: control@bugs.debian.org

Cc: 654198-submitter@bugs.debian.org

Subject: closing 654198

Date: Sun, 30 Dec 2012 17:12:13 +0100

close 654198 
thanks

As upstream, I've concluded that this is not easily fixable: until
the first generation finishes, the B-tree is in a bit of a
vulnerable state that is risky to try to fix. Thus, I'm closing
the bug because it's not fixable. (I do not like the wontfix state,
as it bloats the bug list.)

-- 
http://www.cafepress.com/trunktees -- geeky funny T-shirts
http://gtdfh.branchable.com/ -- GTD for hackers

Send a report that this bug log contains spam.