GNU bug report logs - #46212
ci.guix.gnu.org narinfos with excessive NarSize

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 46212 in the body.
You can then email your comments to 46212 AT debbugs.gnu.org in the normal way.

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

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

From: Christopher Baines <mail <at> cbaines.net>
To: bug-guix <at> gnu.org
Subject: ci.guix.gnu.org narinfos with excessive NarSize
Date: Sun, 31 Jan 2021 14:47:42 +0000

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

I noticed through the Guix Data Service that some narinfo files from
ci.guix.gnu.org have an excessive NarSize.

These are the three that I've found, but there could be more.


/gnu/store/qln574djfgl8h9glij9id8jips7nnrlw-flightgear-2018.3.5
NarSize: 18446744072099351584

/gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1
NarSize: 18446744071612438544

/gnu/store/wd9z64xpck56xzf52jwlpg8vb610b0ym-repeat-masker-4.1.1
NarSize: 18446744071612438544


There's additional information on IRC: http://logs.guix.gnu.org/guix/2021-01-31.log#152751

Cc'ing Mathieu in case this is related to the new offloading mechanism.

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

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Sun, 31 Jan 2021 16:20:38 +0100

Christopher Baines <mail <at> cbaines.net> skribis:

> /gnu/store/qln574djfgl8h9glij9id8jips7nnrlw-flightgear-2018.3.5
> NarSize: 18446744072099351584
>
> /gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1
> NarSize: 18446744071612438544
>
> /gnu/store/wd9z64xpck56xzf52jwlpg8vb610b0ym-repeat-masker-4.1.1
> NarSize: 18446744071612438544

The key point here is that ‘narSize’ in the database is negative:

--8<---------------cut here---------------start------------->8---
sqlite> select * from validpaths where path = '/gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1';
43262123|/gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1|sha256:33328e16d8d83dcf1a6e031598dbc517aff18e6c7ccd55f7894102bab55fcdb9|1611849907|/gnu/store/rr532q5fmwj1gafdgk6nhxg9khnbsw3z-repeat-masker-4.1.1.drv|-2097113072
--8<---------------cut here---------------end--------------->8---

The actual nar size in this case is just above 2³¹ so most likely we’re
seeing a signed integer wrapping error.

I believe this is a very recent regression (the registration data for
the item above is Jan. 28th); we have older store items with a correct
‘narSize’, such as
<https://ci.guix.gnu.org/nm6w84c9zj3yiylal3dk1sqzxq11sjzw.narinfo>.

Thoughts?

Ludo’.

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Mon, 01 Feb 2021 10:15:56 +0100

Ludovic Courtès <ludo <at> gnu.org> skribis:

> The key point here is that ‘narSize’ in the database is negative:

With commit 13a7d2a538b00aa0a8cf9b999f1a4ff3e5959af9, ‘register-items’ &
co. will now detect invalid nar size values early on.

Ludo’.

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

From: Christopher Baines <mail <at> cbaines.net>
To: 46212 <at> debbugs.gnu.org
Subject: Re: ci.guix.gnu.org narinfos with excessive NarSize
Date: Mon, 01 Feb 2021 19:57:06 +0000

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

Christopher Baines <mail <at> cbaines.net> writes:

> I noticed through the Guix Data Service that some narinfo files from
> ci.guix.gnu.org have an excessive NarSize.
>
> These are the three that I've found, but there could be more.
>
>
> /gnu/store/qln574djfgl8h9glij9id8jips7nnrlw-flightgear-2018.3.5
> NarSize: 18446744072099351584
>
> /gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1
> NarSize: 18446744071612438544
>
> /gnu/store/wd9z64xpck56xzf52jwlpg8vb610b0ym-repeat-masker-4.1.1
> NarSize: 18446744071612438544

Guix gives the following error when it encounters one of these bad
narinfos:

  error: integer expected from stream

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

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Tue, 02 Feb 2021 22:48:27 +0100

Christopher Baines <mail <at> cbaines.net> skribis:

> Christopher Baines <mail <at> cbaines.net> writes:
>
>> I noticed through the Guix Data Service that some narinfo files from
>> ci.guix.gnu.org have an excessive NarSize.
>>
>> These are the three that I've found, but there could be more.
>>
>>
>> /gnu/store/qln574djfgl8h9glij9id8jips7nnrlw-flightgear-2018.3.5
>> NarSize: 18446744072099351584
>>
>> /gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1
>> NarSize: 18446744071612438544
>>
>> /gnu/store/wd9z64xpck56xzf52jwlpg8vb610b0ym-repeat-masker-4.1.1
>> NarSize: 18446744071612438544
>
> Guix gives the following error when it encounters one of these bad
> narinfos:
>
>   error: integer expected from stream

I guess ‘guix substitute --query’ reads the narinfo, passes the negative
integer as is to the daemon (for ‘query-path-info’ RPCs), which
rightfully complains.

It would be nice for ‘guix publish’ to not emit broken narinfos, and
perhaps we can also add extra checks in the (guix narinfo) reader.

Ludo’.

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Mathieu Othacehe <othacehe <at> gnu.org>
Cc: 46212 <at> debbugs.gnu.org, Christopher Baines <mail <at> cbaines.net>
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Fri, 19 Feb 2021 16:11:14 +0100

Hi Mathieu,

Did you eventually find out where the negative size comes from?

  https://issues.guix.gnu.org/46212

What should we do in your opinion with database entries that have a
negative size?

Thanks,
Ludo’.

Ludovic Courtès <ludo <at> gnu.org> skribis:

> Christopher Baines <mail <at> cbaines.net> skribis:
>
>> /gnu/store/qln574djfgl8h9glij9id8jips7nnrlw-flightgear-2018.3.5
>> NarSize: 18446744072099351584
>>
>> /gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1
>> NarSize: 18446744071612438544
>>
>> /gnu/store/wd9z64xpck56xzf52jwlpg8vb610b0ym-repeat-masker-4.1.1
>> NarSize: 18446744071612438544
>
> The key point here is that ‘narSize’ in the database is negative:
>
> sqlite> select * from validpaths where path = '/gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1';
> 43262123|/gnu/store/qhix6afvy2a6n7hlx4qgdns461p8kdnv-repeat-masker-4.1.1|sha256:33328e16d8d83dcf1a6e031598dbc517aff18e6c7ccd55f7894102bab55fcdb9|1611849907|/gnu/store/rr532q5fmwj1gafdgk6nhxg9khnbsw3z-repeat-masker-4.1.1.drv|-2097113072
>
> The actual nar size in this case is just above 2³¹ so most likely we’re
> seeing a signed integer wrapping error.
>
> I believe this is a very recent regression (the registration data for
> the item above is Jan. 28th); we have older store items with a correct
> ‘narSize’, such as
> <https://ci.guix.gnu.org/nm6w84c9zj3yiylal3dk1sqzxq11sjzw.narinfo>.
>
> Thoughts?
>
> Ludo’.

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

From: Mathieu Othacehe <othacehe <at> gnu.org>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: 46212 <at> debbugs.gnu.org, Christopher Baines <mail <at> cbaines.net>
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Mon, 22 Feb 2021 09:59:45 +0100

Hey Ludo,

> Did you eventually find out where the negative size comes from?
>
>   https://issues.guix.gnu.org/46212
>
> What should we do in your opinion with database entries that have a
> negative size?

I didn't look closely to this problem yet. However, I fixed an issue
with locales in the remote building mechanism that caused publish server
crashes:
https://lists.gnu.org/archive/html/bug-guix/2021-02/msg00231.html.

That's maybe somehow related.

Thanks,

Mathieu

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Mathieu Othacehe <othacehe <at> gnu.org>
Cc: 46212 <at> debbugs.gnu.org, Christopher Baines <mail <at> cbaines.net>
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Mon, 22 Feb 2021 14:03:03 +0100

Hi,

Mathieu Othacehe <othacehe <at> gnu.org> skribis:

>> Did you eventually find out where the negative size comes from?
>>
>>   https://issues.guix.gnu.org/46212
>>
>> What should we do in your opinion with database entries that have a
>> negative size?
>
> I didn't look closely to this problem yet. However, I fixed an issue
> with locales in the remote building mechanism that caused publish server
> crashes:
> https://lists.gnu.org/archive/html/bug-guix/2021-02/msg00231.html.

Hmm I don’t think so.

The bug here is likely due to 32-bit signed integer wrapping.  That can
only happen in C code, so to me possible culprits would be
guile-simple-zmq or the layer above it (if there’s a binary protocol
involved) or the postgresql interface.  Only a vague intuition, though.

Ludo’.

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

From: Mathieu Othacehe <othacehe <at> gnu.org>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: 46212 <at> debbugs.gnu.org, Christopher Baines <mail <at> cbaines.net>
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Wed, 24 Feb 2021 11:26:27 +0100

Hey,

> The bug here is likely due to 32-bit signed integer wrapping.  That can
> only happen in C code, so to me possible culprits would be
> guile-simple-zmq or the layer above it (if there’s a binary protocol
> involved) or the postgresql interface.  Only a vague intuition, though.

Hmm, looks like you're right! There's a memory corruption in the
remote-server process that's really hard to reproduce. I suspect the ZMQ
library or its Guile bindings.

I'm trying to valgrind the process to identify the issue, without much
success for now.

Thanks,

Mathieu

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Sun, 21 Mar 2021 15:38:58 +0100

Hi there!

Christopher Baines <mail <at> cbaines.net> skribis:

> Guix gives the following error when it encounters one of these bad
> narinfos:
>
>   error: integer expected from stream

I get this while attempting to install flightgear from
12c17b46f1464db5591572754c814c845a2057ad.

It has the scary NarSize:

--8<---------------cut here---------------start------------->8---
$ wget -qO - https://ci.guix.gnu.org/k094mjy3m1cyh85vd27l2gn0w5ikscya.narinfo | head -9
StorePath: /gnu/store/k094mjy3m1cyh85vd27l2gn0w5ikscya-flightgear-2018.3.5
URL: nar/gzip/k094mjy3m1cyh85vd27l2gn0w5ikscya-flightgear-2018.3.5
Compression: gzip
FileSize: 1797450320
URL: nar/lzip/k094mjy3m1cyh85vd27l2gn0w5ikscya-flightgear-2018.3.5
Compression: lzip
FileSize: 1605734577
NarHash: sha256:0bwyhvqr7l5sk6fckymj41bivm6ws09aid8lg6lg0bmy513kn0aw
NarSize: 18446744072099352280
--8<---------------cut here---------------end--------------->8---

The nar was baked on March 17th:

--8<---------------cut here---------------start------------->8---
ludo <at> berlin ~$ ls -l /var/cache/guix/publish/lzip/k094mjy3m1cyh85vd27l2gn0w5ikscya-flightgear-2018.3.5.narinfo
-rw-r--r-- 2 guix-publish guix-publish 2232 Mar 17 22:20 /var/cache/guix/publish/lzip/k094mjy3m1cyh85vd27l2gn0w5ikscya-flightgear-2018.3.5.narinfo
--8<---------------cut here---------------end--------------->8---

The nar size is indeed negative again:

--8<---------------cut here---------------start------------->8---
ludo <at> berlin ~$ sudo sqlite3 /var/guix/db/db.sqlite
SQLite version 3.28.0 2019-04-16 19:49:53
Enter ".help" for usage hints.
sqlite> select * from validpaths where path='/gnu/store/k094mjy3m1cyh85vd27l2gn0w5ikscya-flightgear-2018.3.5';
45484766|/gnu/store/k094mjy3m1cyh85vd27l2gn0w5ikscya-flightgear-2018.3.5|sha256:5c013b4728be2ef0a87914b5a812d0dcd41d5720b2fac99c99bad093f1869e2f|1615825221|/gnu/store/r995zx36fm4k4r1mwyy22mg2syjdc0fj-flightgear-2018.3.5.drv|-1610199336
--8<---------------cut here---------------end--------------->8---

Registration date is:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> (date->string (time-utc->date (make-time time-utc 0 1615825221) 3600))
$11 = "Mon Mar 15 17:20:21+0100 2021"
--8<---------------cut here---------------end--------------->8---

Right now berlin is running guix-1.2.0-13.a53f711, which AFAICS includes
the narsize bound checking added in 13a7d2a538b00aa0a8cf9b999f1a4ff3e5959af9.

This only ensures that narsize is positive.  Could it be that wrapping
happens in sqlite itself?  Or could it be that Cuirass itself uses an
older version of (guix store database)?

Ludo’.

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Sun, 21 Mar 2021 15:55:01 +0100

Ludovic Courtès <ludo <at> gnu.org> skribis:

> I get this while attempting to install flightgear from
> 12c17b46f1464db5591572754c814c845a2057ad.

Ah ha!  A newer flightgear, baked today, doesn’t have this problem (from
commit 3c74dbb35f1ea0f43b02fd81e5afd24608f71c45):

--8<---------------cut here---------------start------------->8---
$ wget -qO - https://ci.guix.gnu.org/58rpdzfh42xqq36dg25cgxzfw0alsm7w.narinfo | head -12
StorePath: /gnu/store/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5
URL: nar/gzip/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5
Compression: gzip
FileSize: 1797450279
URL: nar/lzip/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5
Compression: lzip
FileSize: 1605732816
URL: nar/zstd/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5
Compression: zstd
FileSize: 1668702713
NarHash: sha256:09804lw134f16k4pwwm8jpwiy9dvr4hjvz64wx74bl8g1jjf9i9w
NarSize: 2684767960
--8<---------------cut here---------------end--------------->8---

And on berlin:

--8<---------------cut here---------------start------------->8---
ludo <at> berlin ~$ sudo sqlite3 /var/guix/db/db.sqlite
Password: 
SQLite version 3.28.0 2019-04-16 19:49:53
Enter ".help" for usage hints.
sqlite> select * from validpaths where path='/gnu/store/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5';
45741398|/gnu/store/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5|sha256:3cc5e4a40c0fd1454ee7c4fc2d21c9bb251ff995a8727ec934c1911138250025|1616252839|/gnu/store/rzcviskbmy0x4hz15dki4a2aci9wrjxv-flightgear-2018.3.5.drv|2684767960
--8<---------------cut here---------------end--------------->8---

Registration date:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> (date->string (time-utc->date (make-time time-utc 0 1616252839) 3600))
$15 = "Sat Mar 20 16:07:19+0100 2021"
--8<---------------cut here---------------end--------------->8---

Could it be that the bug was fixed in the meantime?  Or that this one
was, say, built directly via Guix whereas the other one was built
through Cuirass?  Mystery!

Ludo’.

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Sun, 21 Mar 2021 15:55:29 +0100

Ludovic Courtès <ludo <at> gnu.org> skribis:

> I get this while attempting to install flightgear from
> 12c17b46f1464db5591572754c814c845a2057ad.

Ah ha!  A newer flightgear, baked today, doesn’t have this problem (from
commit 3c74dbb35f1ea0f43b02fd81e5afd24608f71c45):

--8<---------------cut here---------------start------------->8---
$ wget -qO - https://ci.guix.gnu.org/58rpdzfh42xqq36dg25cgxzfw0alsm7w.narinfo | head -12
StorePath: /gnu/store/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5
URL: nar/gzip/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5
Compression: gzip
FileSize: 1797450279
URL: nar/lzip/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5
Compression: lzip
FileSize: 1605732816
URL: nar/zstd/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5
Compression: zstd
FileSize: 1668702713
NarHash: sha256:09804lw134f16k4pwwm8jpwiy9dvr4hjvz64wx74bl8g1jjf9i9w
NarSize: 2684767960
--8<---------------cut here---------------end--------------->8---

And on berlin:

--8<---------------cut here---------------start------------->8---
ludo <at> berlin ~$ sudo sqlite3 /var/guix/db/db.sqlite
Password: 
SQLite version 3.28.0 2019-04-16 19:49:53
Enter ".help" for usage hints.
sqlite> select * from validpaths where path='/gnu/store/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5';
45741398|/gnu/store/58rpdzfh42xqq36dg25cgxzfw0alsm7w-flightgear-2018.3.5|sha256:3cc5e4a40c0fd1454ee7c4fc2d21c9bb251ff995a8727ec934c1911138250025|1616252839|/gnu/store/rzcviskbmy0x4hz15dki4a2aci9wrjxv-flightgear-2018.3.5.drv|2684767960
--8<---------------cut here---------------end--------------->8---

Registration date:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> (date->string (time-utc->date (make-time time-utc 0 1616252839) 3600))
$15 = "Sat Mar 20 16:07:19+0100 2021"
--8<---------------cut here---------------end--------------->8---

Could it be that the bug was fixed in the meantime?  Or that this one
was, say, built directly via Guix whereas the other one was built
through Cuirass?  Mystery!

Ludo’.

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

From: Mathieu Othacehe <othacehe <at> gnu.org>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: 46212 <at> debbugs.gnu.org, Christopher Baines <mail <at> cbaines.net>
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Mon, 29 Mar 2021 09:45:50 +0200

Hey,

> Could it be that the bug was fixed in the meantime?  Or that this one
> was, say, built directly via Guix whereas the other one was built
> through Cuirass?  Mystery!

That's strange. There's nothing really special about how Cuirass builds
its stuff. It's a plain "build-derivations" call in the "cuirass
remote-worker" process. This process only builds stuff and report it
using (simple-zmq).

A memory corruption in that module also seems unlikely, as there are
almost 30 instances of this process running nicely for days.

Thanks,

Mathieu

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

From: Brendan Tildesley <btild <at> mailbox.org>
To: "46212 <at> debbugs.gnu.org" <46212 <at> debbugs.gnu.org>
Cc: "ludo <at> gnu.org" <ludo <at> gnu.org>
Subject: ci.guix.gnu.org narinfos with excessive NarSize
Date: Wed, 7 Apr 2021 11:09:24 +0200 (CEST)

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

I just had the same bug with flightgear as Ludo.

Running `guix build flightgear', guix showed it was downloading substitute information, and then errored with

guix build: error: integer expected from stream

Possibly helpful strace info:

write(14, "\36\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0?\0\0\0\0\0\0\0/gnu/store/ssdka48kwx9f2z54j63mjxvn6bg502mm-flightgear-2018.3.5\0@\0\0\0\0\0\0\0/gnu/store/pr6xy604hg7yhcinnlymrkc958kl0bnn-openscenegraph-3.4.1<\0\0\0\0\0\0\0/gnu/store/g8g4paw3q3z8hkl441ddhdn0in54gi3f-simgear-2018.3.5\0\0\0\0", 232) = 232
read(14, "ptxc\0\0\0\0", 8)             = 8
read(14, "\34\0\0\0\0\0\0\0", 8)        = 8
read(14, "integer expected from stream\0\0\0\0", 32) = 32
read(14, "\1", 1)                       = 1
read(14, "\0\0\0\0\0\0\0", 7)           = 7
close(14)

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

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

From: Christopher Baines <mail <at> cbaines.net>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Fri, 11 Jun 2021 13:04:10 +0100

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

Christopher Baines <mail <at> cbaines.net> writes:

> I noticed through the Guix Data Service that some narinfo files from
> ci.guix.gnu.org have an excessive NarSize.

Since I've scanned all the narinfos for a recent revision, I thought I'd
update this issue with the broken narinfos that ci.guix.gnu.org is
currently serving (just for a recent revision):

  /gnu/store/s18pfbv3a9sf61rh29m1i8vdznwjlny7-repeat-masker-4.1.1
  /gnu/store/4lm1wa8m9n84vh29d6pa3ygy29iwyz2v-flightgear-2018.3.5
  /gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5

I think there were safeguards put in place to avoid bad data making it's
way in to the store database? If so, maybe the store item could be gc'd
on berlin, and the cached narinfos deleted, and that would clean things
up?

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

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Fri, 18 Jun 2021 11:48:31 +0200

Christopher Baines <mail <at> cbaines.net> skribis:

> Christopher Baines <mail <at> cbaines.net> writes:
>
>> I noticed through the Guix Data Service that some narinfo files from
>> ci.guix.gnu.org have an excessive NarSize.
>
> Since I've scanned all the narinfos for a recent revision, I thought I'd
> update this issue with the broken narinfos that ci.guix.gnu.org is
> currently serving (just for a recent revision):
>
>   /gnu/store/s18pfbv3a9sf61rh29m1i8vdznwjlny7-repeat-masker-4.1.1
>   /gnu/store/4lm1wa8m9n84vh29d6pa3ygy29iwyz2v-flightgear-2018.3.5
>   /gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5

This is what I get for the last one:

--8<---------------cut here---------------start------------->8---
sqlite> select * from validpaths where path = '/gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5';
48732920|/gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5|sha256:86426115e1f49835a24612ae89a180e87ac835332b4e83d19ecbd43211336cd2|1623360391|/gnu/store/722yyaa1qvkaakn6p7ywwr4dnm5wmddz-flightgear-2018.3.5.drv|-1610199336
--8<---------------cut here---------------end--------------->8---

The registration date is:

--8<---------------cut here---------------start------------->8---
scheme@(guile-user)> ,use(srfi srfi-19)
scheme@(guile-user)> (date->string (time-utc->date (make-time time-utc 0 1623360391)) "~1" )
$164 = "2021-06-10"
--8<---------------cut here---------------end--------------->8---

> I think there were safeguards put in place to avoid bad data making it's
> way in to the store database?

I thought so too (commit 13a7d2a538b00aa0a8cf9b999f1a4ff3e5959af9)!
So we must be using another code path.

Mathieu, these store items get registered via an RPC, or via (guix store
database)?

Thanks,
Ludo’.

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Tobias Geerinckx-Rice <me <at> tobias.gr>
Cc: 51983-done <at> debbugs.gnu.org, 46212 <at> debbugs.gnu.org
Subject: Re: bug#51983: guix build: error: integer expected from stream
Date: Thu, 25 Nov 2021 00:24:24 +0100

Hi,

Tobias Geerinckx-Rice <me <at> tobias.gr> skribis:

> Tobias Geerinckx-Rice via Bug reports for GNU Guix 写道：
>> substitute: updating substitutes from
>> 'https://ci.guix.gnu.org'... 100.0%
>> guix build: error: integer expected from stream:
>> 18446744071924943736
>
> And it is indeed specific to querying ci.guix.

This reminds me of:

  https://issues.guix.gnu.org/46212

and indeed:

--8<---------------cut here---------------start------------->8---
$ guix build flightgear -n --no-grafts
substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
substitute: updating substitutes from 'https://bayfront.guix.gnu.org'... 100.0%
guix build: error: integer expected from stream
$ guix describe
Generacio 195	Nov 22 2021 00:37:58	(nuna)
  guix 24aa7b3
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: 24aa7b3c21309b63cc6e8e18d6417d2cddccf6c6
--8<---------------cut here---------------end--------------->8---

The ‘NarSize’ field is still broken on ci.guix:

--8<---------------cut here---------------start------------->8---
$ wget -qO - https://ci.guix.gnu.org/ashmi6vr9d0k03z9q6ncbb2wf36p9nyk.narinfo |grep Size
FileSize: 1876560180
FileSize: 1715771086
FileSize: 1753645085
NarSize: 18446744072093825552
$ wget -qO - https://bordeaux.guix.gnu.org/ashmi6vr9d0k03z9q6ncbb2wf36p9nyk.narinfo |grep Size
FileSize: 1715771086
NarSize: 2679241232
--8<---------------cut here---------------end--------------->8---

and again the database on berlin has a negative size:

--8<---------------cut here---------------start------------->8---
$ sudo sqlite3 /var/guix/db/db.sqlite
SQLite version 3.32.3 2020-06-18 14:00:33
Enter ".help" for usage hints.
sqlite> select * from validpaths where path = '/gnu/store/ashmi6vr9d0k03z9q6ncbb2wf36p9nyk-flightgear-2020.3.11';
56551239|/gnu/store/ashmi6vr9d0k03z9q6ncbb2wf36p9nyk-flightgear-2020.3.11|sha256:1c68105efd8ee4677085a2cecaa5859f1f5f213d52e213ef4949384717dc493a|1636968959|/gnu/store/xvyar43mcfw0r7jfm1x0a2i9rhnsdh87-flightgear-2020.3.11.drv|-1615726064
--8<---------------cut here---------------end--------------->8---

[Time passes…]

OK, this one is now fixed by commit
1eb40a6dc4917f5a2e915f8b31b750dba3d378c6m, which means you now get:

--8<---------------cut here---------------start------------->8---
$ guix build flightgear --no-grafts  -n
1,715.8 MB would be downloaded:
   /gnu/store/ashmi6vr9d0k03z9q6ncbb2wf36p9nyk-flightgear-2020.3.11
guix build: warning: at least 18,446,744,072,093.8 MB needed but only 4,753.4 MB available in /gnu/store
--8<---------------cut here---------------end--------------->8---

Fun, no?  :-)

Also, after substitution, the size in the store database would be the
wrong one, so ‘guix size’ would keep telling you it’s this big.  Not
great but harmless as the nar size is used for UI purposes only.

Ludo’.

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Thu, 25 Nov 2021 00:28:57 +0100

Hi,

Ludovic Courtès <ludo <at> gnu.org> skribis:

> This is what I get for the last one:
>
> sqlite> select * from validpaths where path = '/gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5';
> 48732920|/gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5|sha256:86426115e1f49835a24612ae89a180e87ac835332b4e83d19ecbd43211336cd2|1623360391|/gnu/store/722yyaa1qvkaakn6p7ywwr4dnm5wmddz-flightgear-2018.3.5.drv|-1610199336
>
>
> The registration date is:
>
> scheme@(guile-user)> ,use(srfi srfi-19)
> scheme@(guile-user)> (date->string (time-utc->date (make-time time-utc 0 1623360391)) "~1" )
> $164 = "2021-06-10"
>
>> I think there were safeguards put in place to avoid bad data making it's
>> way in to the store database?
>
> I thought so too (commit 13a7d2a538b00aa0a8cf9b999f1a4ff3e5959af9)!
> So we must be using another code path.

At last I found the culprit (me! :-)).  This is fixed by commit
f9b1bb916c284bea00dd5549a43e0894b219d650.

The reason ci.guix would experience it and not bayfront is because the
Cuirass worker mechanism relies on substitutes to retrieve files from a
worker, and this is how it would end up storing a negative size.

We’ll have to upgrade the ‘guix’ package and deploy it on berlin.  I
don’t think it’s easily feasible to fix existing entries in the store
database and (more importantly) narinfos so I’d just leave them around;
the bogus nar size propagates but it’s harmless and doesn’t prevent
substitution.

Thoughts?

Ludo’.

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

From: Christopher Baines <mail <at> cbaines.net>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Thu, 25 Nov 2021 08:42:25 +0000

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

Ludovic Courtès <ludo <at> gnu.org> writes:

> Hi,
>
> Ludovic Courtès <ludo <at> gnu.org> skribis:
>
>> This is what I get for the last one:
>>
>> sqlite> select * from validpaths where path = '/gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5';
>> 48732920|/gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5|sha256:86426115e1f49835a24612ae89a180e87ac835332b4e83d19ecbd43211336cd2|1623360391|/gnu/store/722yyaa1qvkaakn6p7ywwr4dnm5wmddz-flightgear-2018.3.5.drv|-1610199336
>>
>>
>> The registration date is:
>>
>> scheme@(guile-user)> ,use(srfi srfi-19)
>> scheme@(guile-user)> (date->string (time-utc->date (make-time time-utc 0 1623360391)) "~1" )
>> $164 = "2021-06-10"
>>
>>> I think there were safeguards put in place to avoid bad data making it's
>>> way in to the store database?
>>
>> I thought so too (commit 13a7d2a538b00aa0a8cf9b999f1a4ff3e5959af9)!
>> So we must be using another code path.
>
> At last I found the culprit (me! :-)).  This is fixed by commit
> f9b1bb916c284bea00dd5549a43e0894b219d650.

Awesome :)

> The reason ci.guix would experience it and not bayfront is because the
> Cuirass worker mechanism relies on substitutes to retrieve files from a
> worker, and this is how it would end up storing a negative size.
>
> We’ll have to upgrade the ‘guix’ package and deploy it on berlin.  I
> don’t think it’s easily feasible to fix existing entries in the store
> database and (more importantly) narinfos so I’d just leave them around;
> the bogus nar size propagates but it’s harmless and doesn’t prevent
> substitution.
>
> Thoughts?

I thought this did prevent substitution, at least I have problems:

→ guix build --substitute-urls=https://ci.guix.gnu.org /gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5
substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
guix build: error: integer expected from stream

Maybe the database could be queried to find the affected items, then
they could be GC'd?

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

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: Mathieu Othacehe <othacehe <at> gnu.org>, 46212 <at> debbugs.gnu.org
Subject: Re: bug#46212: ci.guix.gnu.org narinfos with excessive NarSize
Date: Fri, 26 Nov 2021 11:11:40 +0100

Hi!

Christopher Baines <mail <at> cbaines.net> skribis:

> I thought this did prevent substitution, at least I have problems:
>
> → guix build --substitute-urls=https://ci.guix.gnu.org /gnu/store/q6qa5s2z2l20q25qpxyfv1wni5wwhk24-flightgear-2018.3.5
> substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
> guix build: error: integer expected from stream

This one is fixed here:

  https://issues.guix.gnu.org/51983

We have yet to update the ‘guix’ package though.

> Maybe the database could be queried to find the affected items, then
> they could be GC'd?

We could do that, but then /var/cache/guix/publish would needed to be
cleaned up as well.  It’s a bit tedious doable.  (I don’t plan to work
on it right now because I’m trying to focus on other things.)

Thanks,
Ludo’.

Previous Next

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