ci.guix.gnu.org narinfos with excessive NarSize

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.

severity 46212 important

quit

Christopher Baines <mail@cbaines.net> skribis:

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

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’.

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

With commit 13a7d2a538b00aa0a8cf9b999f1a4ff3e5959af9, ‘register-items’ &

co. will now detect invalid nar size values early on.

Ludo’.

Christopher Baines <mail@cbaines.net> writes:

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

narinfos:

error: integer expected from stream

Christopher Baines <mail@cbaines.net> skribis:

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’.

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@gnu.org> skribis:

Hey Ludo,

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:

That's maybe somehow related.

Thanks,

Mathieu

Hi,

Mathieu Othacehe <othacehe@gnu.org> skribis:

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’.

Hey,

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

Hi there!

Christopher Baines <mail@cbaines.net> skribis:

I get this while attempting to install flightgear from

12c17b46f1464db5591572754c814c845a2057ad.

It has the scary NarSize:

The nar was baked on March 17th:

The nar size is indeed negative again:

Registration date is:

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’.

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

Ah ha! A newer flightgear, baked today, doesn’t have this problem (from

commit 3c74dbb35f1ea0f43b02fd81e5afd24608f71c45):

And on berlin:

Registration date:

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’.

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

Ah ha! A newer flightgear, baked today, doesn’t have this problem (from

commit 3c74dbb35f1ea0f43b02fd81e5afd24608f71c45):

And on berlin:

Registration date:

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’.

Hey,

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

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)

Christopher Baines <mail@cbaines.net> writes:

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?

Christopher Baines <mail@cbaines.net> skribis:

This is what I get for the last one:

The registration date is:

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’.

Hi,

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

This reminds me of:

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

and indeed:

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

and again the database on berlin has a negative size:

[Time passes…]

OK, this one is now fixed by commit

1eb40a6dc4917f5a2e915f8b31b750dba3d378c6m, which means you now get:

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’.

Hi,

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

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’.

close 46212

quit

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

Awesome :)

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?

Hi!

Christopher Baines <mail@cbaines.net> skribis:

This one is fixed here:

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

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

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’.