bug#51787: GC takes more than 9 hours on berlin

["Ludovic Courtès" <ludo@gnu.org>]

Hello!

Mathieu Othacehe <othacehe@gnu.org> skribis:

> On berlin, the daily GC command is still running whereas it was started
> 9 hours ago.

Some data points:

  • I deployed on berlin the new daemon featuring the faster “deleting
    unused links” phase from <https://issues.guix.gnu.org/24937> on
    Nov. 20.

    However, that part runs after the GC lock has been released, so it’s
    not really relevant (but it is relevant to I/O load and GC
    efficiency.)

  • When discussing together with Chris Baines yesterday on IRC, we
    found that the sqlite WAL file was 8 GiB.  I later ran:

      PRAGMA wal_checkpoint(TRUNCATE);

    which emptied it immediately.  However, GC time wasn’t particularly
    different today.

  • ‘db.sqlite’ weighs in at 19 GiB (!) so perhaps there’s something to
    do, like the “VACUUM” thing maybe.  Chris?

  • Stracing the session’s guix-daemon process during GC suggests that
    most of the time goes into I/O from ‘db.sqlite’.  It’s not
    surprising because that GC phase is basically about browsing the
    database, but it does seem to take a little too long for each store
    item.

  • I haven’t checked recently but I recall that ‘guix gc --list-roots’
    (or its C++ counterpart, ‘findRoots’) would take ages on berlin
    because of all the GC roots Cuirass registers.  It may be that an
    hour or so goes into enumerating GC roots.

Collecting garbage,
Ludo’.