GNU bug report logs - #36687
guix gc: error: executing SQLite statement: database disk image is malformed

Previous Next

Package: guix;

Reported by: Chris Marusich <cmmarusich <at> gmail.com>

Date: Tue, 16 Jul 2019 07:42:01 UTC

Severity: normal

To reply to this bug, email your comments to 36687 AT debbugs.gnu.org.

Toggle the display of automated, internal messages from the tracker.

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to bug-guix <at> gnu.org:
bug#36687; Package guix. (Tue, 16 Jul 2019 07:42:02 GMT) Full text and rfc822 format available.

Acknowledgement sent to Chris Marusich <cmmarusich <at> gmail.com>:
New bug report received and forwarded. Copy sent to bug-guix <at> gnu.org. (Tue, 16 Jul 2019 07:42:02 GMT) Full text and rfc822 format available.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Chris Marusich <cmmarusich <at> gmail.com>
To: bug-guix <at> gnu.org
Subject: guix gc: error: executing SQLite statement: database disk image is
 malformed
Date: Tue, 16 Jul 2019 00:41:09 -0700
[Message part 1 (text/plain, inline)]
Hi,

My disk was filling up, so I tried to run "guix gc", but I got an error
instead:

--8<---------------cut here---------------start------------->8---
$ guix gc -C 25GiB
...
deleting `/gnu/store/n0gyzfw77ik35ld9d0d4737w88f11m4b-profile.drv'
deleting `/gnu/store/fl7w0dlki7c906isiiflf9ka4c49zcmi-ca-certificate-bundle.drv'
deleting `/gnu/store/ipn4xvvb3wrbx4lhzwdyyylvj42vyg6f-xdg-desktop-database.drv'
guix gc: error: executing SQLite statement: database disk image is malformed
--8<---------------cut here---------------end--------------->8---

What does this mean?  How concerned should I be?  How can I fix it?  I
looked for existing bug reports, but I didn't find anything.  I haven't
tried running the command a second time.

FYI, I was building one package using my Guix installation via "guix
build --cores=1", and another package using a Guix checkout via
"./pre-inst-env guix build --cores", when I decided to run this "guix
gc" command in another shell.  I don't know if that matters.  My
expectation is that I can run GC even when building software, thanks to
the guix-daemon's safe concurrent garbage collection algorithm.

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

Information forwarded to bug-guix <at> gnu.org:
bug#36687; Package guix. (Tue, 16 Jul 2019 12:45:01 GMT) Full text and rfc822 format available.

Message #8 received at 36687 <at> debbugs.gnu.org (full text, mbox):

From: Ricardo Wurmus <rekado <at> elephly.net>
To: cmmarusich <at> gmail.com
Cc: 36687 <at> debbugs.gnu.org
Subject: Re: bug#36687: guix gc: error: executing SQLite statement: database
 disk image is malformed
Date: Tue, 16 Jul 2019 14:44:09 +0200
Chris Marusich <cmmarusich <at> gmail.com> writes:

> My disk was filling up, so I tried to run "guix gc", but I got an error
> instead:
>
> --8<---------------cut here---------------start------------->8---
> $ guix gc -C 25GiB
> ...
> deleting `/gnu/store/n0gyzfw77ik35ld9d0d4737w88f11m4b-profile.drv'
> deleting `/gnu/store/fl7w0dlki7c906isiiflf9ka4c49zcmi-ca-certificate-bundle.drv'
> deleting `/gnu/store/ipn4xvvb3wrbx4lhzwdyyylvj42vyg6f-xdg-desktop-database.drv'
> guix gc: error: executing SQLite statement: database disk image is malformed
> --8<---------------cut here---------------end--------------->8---
>
> What does this mean?

I think this means that the database has been corrupted.

> FYI, I was building one package using my Guix installation via "guix
> build --cores=1", and another package using a Guix checkout via
> "./pre-inst-env guix build --cores", when I decided to run this "guix
> gc" command in another shell.  I don't know if that matters.

I don’t think this is related.

> My expectation is that I can run GC even when building software,
> thanks to the guix-daemon's safe concurrent garbage collection
> algorithm.

That’s correct.

--
Ricardo





Information forwarded to bug-guix <at> gnu.org:
bug#36687; Package guix. (Fri, 19 Jul 2019 05:31:02 GMT) Full text and rfc822 format available.

Message #11 received at 36687 <at> debbugs.gnu.org (full text, mbox):

From: Chris Marusich <cmmarusich <at> gmail.com>
To: Ricardo Wurmus <rekado <at> elephly.net>
Cc: 36687 <at> debbugs.gnu.org
Subject: Re: bug#36687: guix gc: error: executing SQLite statement: database
 disk image is malformed
Date: Thu, 18 Jul 2019 22:30:11 -0700
[Message part 1 (text/plain, inline)]
Ricardo Wurmus <rekado <at> elephly.net> writes:

> Chris Marusich <cmmarusich <at> gmail.com> writes:
>
>> My disk was filling up, so I tried to run "guix gc", but I got an error
>> instead:
>>
>> --8<---------------cut here---------------start------------->8---
>> $ guix gc -C 25GiB
>> ...
>> deleting `/gnu/store/n0gyzfw77ik35ld9d0d4737w88f11m4b-profile.drv'
>> deleting `/gnu/store/fl7w0dlki7c906isiiflf9ka4c49zcmi-ca-certificate-bundle.drv'
>> deleting `/gnu/store/ipn4xvvb3wrbx4lhzwdyyylvj42vyg6f-xdg-desktop-database.drv'
>> guix gc: error: executing SQLite statement: database disk image is malformed
>> --8<---------------cut here---------------end--------------->8---
>>
>> What does this mean?
>
> I think this means that the database has been corrupted.

I ran it a second time.  It printed more messages, but curiously it
errored out after saying that it deleted another
xdg-desktop-database.drv:

--8<---------------cut here---------------start------------->8---
$ guix gc -C 25GiB
...
deleting `/gnu/store/d5z2lazx11qz571mwy59gwlqxidj0h4r-gtk-im-modules.drv'
deleting `/gnu/store/gc36aax38fs194ll5s17j8a8l8arm09a-gtk-icon-themes.drv'
deleting `/gnu/store/hbxvgm2pc6f6jn2fai30izc7f5kd25qd-gtk-im-modules.drv'
deleting `/gnu/store/hrc7yacy4ckmp3zi5pgmzd5ciqzv40ih-xdg-desktop-database.drv'
guix gc: error: executing SQLite statement: database disk image is malformed
--8<---------------cut here---------------end--------------->8---

I ran it a third time, and it printed:

--8<---------------cut here---------------start------------->8---
$ guix gc -C 25GiB
finding garbage collector roots...
deleting garbage...
deleting `/gnu/store/1dqflkm3029ncacx5vl9r95ldfcfs3m0-pugixml-1.9.drv'
guix gc: error: executing SQLite statement: database disk image is malformed
--8<---------------cut here---------------end--------------->8---

I ran it a fourth time, and it printed:

--8<---------------cut here---------------start------------->8---
$ guix gc -C 25GiB
...
deleting `/gnu/store/w0nbsjjb1pj9pi1aim1qcbjq93zss9pn-libwpd-0.10.2.drv'
deleting `/gnu/store/ywdgn73h9kdfcvs6cr1nfjqqj245p788-librevenge-0.0.4.drv'
deleting `/gnu/store/ryawkapgxirj6yp54zb5vak027xxk2i1-cppunit-1.14.0.drv'
deleting `/gnu/store/g2p20iss1r58r4ch2qggzyqn9d5q4kaf-cppunit-1.14.0.tar.gz.drv'
guix gc: error: executing SQLite statement: database disk image is malformed
--8<---------------cut here---------------end--------------->8---

I wonder what has brought my installation into this state.  I can't
think of a way to fix it since I don't even know what caused it, so I
will probably re-install Guix to work around the issue, but before I do
that, is there anything we can check to understand why the database
corruption has occurred?

For the record, I do sometimes abruptly power off my machine, and it
does rarely abruptly crash (I think I have reported this when it occurs,
but I can't be sure).  In such cases, when booting, I see messages
telling me that the system is recovering the journal from my ext4 file
system, and I do not recall ever seeing an error from that process, but
who knows what mischief I've been causing to my system over the years.

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

Information forwarded to bug-guix <at> gnu.org:
bug#36687; Package guix. (Fri, 19 Jul 2019 08:05:02 GMT) Full text and rfc822 format available.

Message #14 received at 36687 <at> debbugs.gnu.org (full text, mbox):

From: Ricardo Wurmus <rekado <at> elephly.net>
To: Chris Marusich <cmmarusich <at> gmail.com>
Cc: 36687 <at> debbugs.gnu.org
Subject: Re: bug#36687: guix gc: error: executing SQLite statement: database
 disk image is malformed
Date: Fri, 19 Jul 2019 10:04:02 +0200
Chris Marusich <cmmarusich <at> gmail.com> writes:

> is there anything we can check to understand why the database
> corruption has occurred?
[…]
> For the record, I do sometimes abruptly power off my machine, and it
> does rarely abruptly crash (I think I have reported this when it occurs,
> but I can't be sure).

This can be a cause of corruption.

Have you manually run fsck on the unmounted disk yet?

-- 
Ricardo





Information forwarded to bug-guix <at> gnu.org:
bug#36687; Package guix. (Sat, 03 Aug 2019 09:12:02 GMT) Full text and rfc822 format available.

Message #17 received at 36687 <at> debbugs.gnu.org (full text, mbox):

From: Chris Marusich <cmmarusich <at> gmail.com>
To: Ricardo Wurmus <rekado <at> elephly.net>
Cc: Mike Gerwitz <mtg <at> gnu.org>, 36687 <at> debbugs.gnu.org
Subject: Re: bug#36687: guix gc: error: executing SQLite statement: database
 disk image is malformed
Date: Sat, 03 Aug 2019 02:11:22 -0700
[Message part 1 (text/plain, inline)]
Ricardo Wurmus <rekado <at> elephly.net> writes:

> Chris Marusich <cmmarusich <at> gmail.com> writes:
>
>> is there anything we can check to understand why the database
>> corruption has occurred?
> […]
>> For the record, I do sometimes abruptly power off my machine, and it
>> does rarely abruptly crash (I think I have reported this when it occurs,
>> but I can't be sure).
>
> This can be a cause of corruption.
>
> Have you manually run fsck on the unmounted disk yet?

Yes, I have.  The file system containing the database is my root file
system, and it is ext4.  On my system, Guix runs e2fsck on the root file
system automatically on each boot [1].  However, just to be sure, I ran
it manually on the unmounted device with the -f option to force a check.
It reported the following (I've copied this output by hand):

--8<---------------cut here---------------start------------->8---
root <at> spaceship ~# e2fsck -f /dev/mapper/home
e2fsck 1.45.2 (27-May-2019)
Pass 1: Checking inodes, blocks, and sizes
Inode 290237 extent tree (at level 2) could be narrower.  Optimize<y>? yes
Inode 291644 extent tree (at level 2) could be narrower.  Optimize<y>? yes
Inode 446822 extent tree (at level 1) could be narrower.  Optimize<y>? yes
Inode 3016396 extent tree (at level 2) could be narrower.  Optimize<y>? yes
Pass 1E: Optimizing extent trees
Pass 2: Checking directory structure
Problem in HTREE directory inode 12451844: block #21606 has bad min hash
Invalid HTREE directory inode 12451844 (/gnu/store/.links).  Clear HTree index<y>? yes
Pass 3: Checking directory connectivity
Pass 3A: Optimizing directories
Pass 4: Checking reference counts
Pass 5: Checking group summary information

root: ***** FILE SYSTEM WAS MODIFIED *****
root: 1761282/14000128 files (0.4% non-contiguous), 50020294/55985664 blocks
root <at> spaceship ~# echo $?
1
--8<---------------cut here---------------end--------------->8---

Unfortunately, when I rebooted and tried "guix gc", the same problem as
before occurred.

I saw that Mike Gerwitz encountered the same error, so I thought I would
try his work-around [2].  Before proceeding, I stopped guix-daemon
("sudo herd stop guix-daemon") and verified that no processes were
accessing the database file ("sudo fuser db.sqlite").  Then I made a
backup of my entire /var/guix directory.

I dumped the database to SQL and recreated it like so:

  sudo sqlite3 db.sqlite .dump > /tmp/db.sqlite.dump
  sudo rm db.sqlite
  sudo sqlite3 db.sqlite < /tmp/db.sqlite.dump

This succeeded without errors or warnings, and it reduced the size of
the db.sqlite file from 145 MiB to 49 MiB.  Although Mike's dump ended
with a "ROLLBACK" and needed to be manually modified, mine ended with a
"COMMIT" and did not require manual modification.

I then started guix-daemon ("sudo herd start guix-daemon") and attempted
to run "guix gc -C 1GiB", which succeeded.  I followed that up with
another "guix gc -C 40GiB", which also succeeded.

The sqlite documentation says that this method of dumping and recreating
the database is supported [3], so I think it's a valid work-around.
However, you never know...  Dumping and restoring the database file
obviously changed it, so even if the restored database is "equivalent"
to the original, it's still conceivable that the difference might cause
a problem somehow.  After all, obviously it was different enough that
guix-daemon stopped failing.  But maybe I'm being too pessimistic.

In any case, it's notable that guix-daemon claimed the database was
corrupt, even though sqlite3 didn't complain about it.  Since the size
was reduced, I suppose sqlite3 cleaned it up or optimized it somehow.
Maybe in doing so, it fixed something that guix-daemon didn't know how
to handle?  That's just a guess.

It's concerning that this "corruption" has occurred for two different
people recently.  We might want to check the Nix bug reports to see if
they've encountered a bug like this.  I did a (very) cursory search and
found only this possibly similar, but possibly unrelated issue:

https://github.com/NixOS/nixpkgs/issues/3958

It may be worth looking harder before diving too deeply into debugging.

If you can think of anything I can do to drill into the files or debug
this more, please let me know.  If the database files do not contain
sensitive information, I would also be willing to share them with you
for further debugging.

Footnotes: 
[1]  https://git.savannah.gnu.org/cgit/guix.git/tree/gnu/build/linux-boot.scm?id=afb986e77cd669c2f21953f501f7893237730ca7#n383

[2]  https://lists.gnu.org/archive/html/help-guix/2019-08/msg00012.html

[3]  https://sqlite.org/cli.html#dump

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

Information forwarded to bug-guix <at> gnu.org:
bug#36687; Package guix. (Sat, 03 Aug 2019 13:08:02 GMT) Full text and rfc822 format available.

Message #20 received at 36687 <at> debbugs.gnu.org (full text, mbox):

From: Mike Gerwitz <mtg <at> gnu.org>
To: Chris Marusich <cmmarusich <at> gmail.com>
Cc: Ricardo Wurmus <rekado <at> elephly.net>, 36687 <at> debbugs.gnu.org
Subject: Re: bug#36687: guix gc: error: executing SQLite statement: database
 disk image is malformed
Date: Sat, 03 Aug 2019 09:06:54 -0400
[Message part 1 (text/plain, inline)]
Sorry I hadn't seen this bug report; it was opened after I researched
this issue a couple months ago and I didn't bother checking since.

Here's the thread I posted to help-guix: <87lfwbuj27.fsf <at> gnu.org>.

-- 
Mike Gerwitz
Free Software Hacker+Activist | GNU Maintainer & Volunteer
GPG: D6E9 B930 028A 6C38 F43B  2388 FEF6 3574 5E6F 6D05
https://mikegerwitz.com
[signature.asc (application/pgp-signature, inline)]

Information forwarded to bug-guix <at> gnu.org:
bug#36687; Package guix. (Sat, 16 Nov 2019 23:31:02 GMT) Full text and rfc822 format available.

Message #23 received at 36687 <at> debbugs.gnu.org (full text, mbox):

From: Chris Marusich <cmmarusich <at> gmail.com>
To: Chris Marusich <cmmarusich <at> gmail.com>
Cc: Ricardo Wurmus <rekado <at> elephly.net>, 36687 <at> debbugs.gnu.org
Subject: Re: bug#36687: guix gc: error: executing SQLite statement: database
 disk image is malformed
Date: Sat, 16 Nov 2019 15:30:09 -0800
[Message part 1 (text/plain, inline)]
Chris Marusich <cmmarusich <at> gmail.com> writes:

> I wonder what has brought my installation into this state.  I can't
> think of a way to fix it since I don't even know what caused it, so I
> will probably re-install Guix to work around the issue

I re-installed Guix to work around the issue.

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

Information forwarded to bug-guix <at> gnu.org:
bug#36687; Package guix. (Sat, 30 Dec 2023 02:27:01 GMT) Full text and rfc822 format available.

Message #26 received at 36687 <at> debbugs.gnu.org (full text, mbox):

From: pkill9 <pkill9 <at> runbox.com>
To: 36687 <at> debbugs.gnu.org
Subject: guix gc: error: executing SQLite statement: database disk image is
 malformed
Date: Sat, 30 Dec 2023 02:25:49 +0000
[Message part 1 (text/plain, inline)]
Hi, I fixed this issue using sqlite3's built-in recover command:

sudo mv /var/guix/db/db.sqlite /var/guix/db/db.sqlite.bak
sqlite3 /var/guix/db/db.sqlite.bak ".recover" | sudo sqlite3 
/var/guix/db/db.sqlite

Solution was found at 
<https://stackoverflow.com/questions/18259692/how-to-recover-a-corrupt-sqlite3-database/57872238#57872238>

[Message part 2 (text/html, inline)]

This bug report was last modified 1 year and 164 days ago.

Previous Next


GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.