Subject: bug#19180: Weak tables harmful to GC?

From: [email-masked] (Ludovic Courtès)
Date: Tue, 31 Oct 2017 17:56:52 +0100

Heya!

Andy Wingo <[email-masked]> skribis:

> On Tue 31 Oct 2017 00:13, [email-masked] (Ludovic Courtès) writes:
>
>> I built libguile with the patch (I haven’t yet taken the time to rebuild
>> all of Guile).  It works, but unfortunately it still shows quick growth
>> of the heap on this example (<https://bugs.gnu.org/28590>):
>
> Fixed in attached patches (on top of the other one).  This was a race
> between the periodic vacuum process, which should run after GC via a
> finalizer, and the mutator.  If the mutator had the weak table lock, the
> vacuum would never be run.  Of course in the test below, the mutator
> usually has the table lock, so we ended up often skipping the vacuum,
> which causes the table size to grow, which causes the active heap size
> to grow, which causes the bytes-allocated-before-GC to increase, and
> which ultimately is a vicious circle.
>
> In my tests this patch fixes the issue, though the level at which the
> heap stabilizes can vary slightly as there's a bit of nondeterministic
> concurrency as the mutator and the vacuum process still race a bit.
> Right now for me it stabilizes at about 6.2M of heap.

Yes.  I can confirm that it fixes this issue.

One of my benchmarks is to ‘read’ the 26M file that contains the
CPS-as-sexps representation of gnu/packages/python.scm, with
source-location recording on (thus with a big source property table).

Compared to 2.2.2, execution time is almost divided by two; heap size is
usually 540M and 620M, whereas it varies between 560M and 920M with
2.2.2:

--8<---------------cut here---------------start------------->8---
ludo@ribbon ~/src/guix$ guile profile-cps-read.scm
clock utime stime cutime cstime gctime
 8.23 10.00  0.06   0.00   0.00   5.17

;;; (#<weak-table 1863537/3595271>)
with Guile 2.2.2:
heap-size from 2.53 MiB to 780.03 MiB
ludo@ribbon ~/src/guix$ guile profile-cps-read.scm
clock utime stime cutime cstime gctime
 8.29  9.94  0.04   0.00   0.00   4.97

;;; (#<weak-table 1820831/3595271>)
with Guile 2.2.2:
heap-size from 2.53 MiB to 660.36 MiB
ludo@ribbon ~/src/guix$ guile profile-cps-read.scm
clock utime stime cutime cstime gctime
 8.11  9.33  0.05   0.00   0.00   3.90

;;; (#<weak-table 1829710/3595271>)
with Guile 2.2.2:
heap-size from 2.53 MiB to 562.21 MiB
ludo@ribbon ~/src/guix$ guile profile-cps-read.scm
clock utime stime cutime cstime gctime
 8.23  9.90  0.08   0.00   0.00   5.22

;;; (#<weak-table 1828628/3595271>)
with Guile 2.2.2:
heap-size from 2.53 MiB to 918.09 MiB
ludo@ribbon ~/src/guix$ /data/src/guile-2.1/meta/guile profile-cps-read.scm
clock utime stime cutime cstime gctime
 4.68  6.71  0.02   0.00   0.00   3.88

;;; (#<weak-table 1799062/3595271>)
with Guile 2.2.2.17-8069-dirty:
heap-size from 1.89 MiB to 540.54 MiB
ludo@ribbon ~/src/guix$ /data/src/guile-2.1/meta/guile profile-cps-read.scm
clock utime stime cutime cstime gctime
 4.73  6.77  0.05   0.00   0.00   4.03

;;; (#<weak-table 1801035/3595271>)
with Guile 2.2.2.17-8069-dirty:
heap-size from 1.89 MiB to 620.22 MiB
ludo@ribbon ~/src/guix$ /data/src/guile-2.1/meta/guile profile-cps-read.scm
clock utime stime cutime cstime gctime
 4.69  6.80  0.06   0.00   0.00   3.94

;;; (#<weak-table 1796895/3595271>)
with Guile 2.2.2.17-8069-dirty:
heap-size from 1.89 MiB to 573.36 MiB
ludo@ribbon ~/src/guix$ /data/src/guile-2.1/meta/guile profile-cps-read.scm
clock utime stime cutime cstime gctime
 4.67  6.81  0.06   0.00   0.00   4.05

;;; (#<weak-table 1797102/3595271>)
with Guile 2.2.2.17-8069-dirty:
heap-size from 1.89 MiB to 547.39 MiB
--8<---------------cut here---------------end--------------->8---

Another benchmark is the ‘emit-bytecode’ procedure for this CPS, without
optimizations turned off (like ‘%lightweight-optimizations’ in Guix.)

The heap size after the ‘emit-bytecode’ call is still at 1.3G (338M
before the call), about the same as with 2.2.2.  That’s not surprising
because I think memory consumption comes from the data structures used
at that compilation stage, as discussed before.

The wall-clock time is ~45s, whereas it’s ~54s with 2.2.2.

In other news, I’ve rebuilt 2.2.2 + these patches with Guix, and
everything went fine (Guile processes seem to peak at ~150M resident
when compiling).

So, all the lights are green on my side!

Thanks a whole lot for coming up with this solution!

Ludo’.