garbage collection slowdown

garbage collection slowdown

[Han-Wen Nienhuys]

Hi folks,

after a long hiatus I have started getting involved with LilyPond
again, and one of the things I'd like to do is get LilyPond off GUILE
1.8. Experiments suggest that starting from GUILE 2.2, the execution
performance is on par with 1.8. There are 2 open issues:  caching byte
compiled files (which I haven't looked into yet), and GC.

Unfortunately, it looks like the adoption of the BDW GC library caused
a ~6x slowdown, causing an overall end-to-end slowdown of 50%.

I was wondering if you folks would have tips to further tune GC for
wall-time speed, and if there additional diagnostics to see if we're
doing something extraordinarily silly.

I already found the GC_free_space_divisor, but I already tuned to its
fastest value, 1.

--
Han-Wen Nienhuys - hanwenn@gmail.com - http://www.xs4all.nl/~hanwen

Re: garbage collection slowdown

[Arne Babenhauserheide]

Hi Han-Wen,

Han-Wen Nienhuys <hanwenn@gmail.com> writes:
> after a long hiatus I have started getting involved with LilyPond
> again, and one of the things I'd like to do is get LilyPond off GUILE
> 1.8.

That’s great! Thank you very much!

> Unfortunately, it looks like the adoption of the BDW GC library caused
> a ~6x slowdown, causing an overall end-to-end slowdown of 50%.

This might be the read-function which is slower in 2.2. You might want
to try to go directly to Guile 3, in which the read function should be
on par with the read in 1.8.

Best wishes,
Arne
-- 
Unpolitisch sein
heißt politisch sein
ohne es zu merken

Re: garbage collection slowdown

[Han-Wen Nienhuys]

(please CC replies directly to me; I am not on the guile-devel list.)

Arne mentioned

>This might be the read-function which is slower in 2.2. You might want
>to try to go directly to Guile 3, in which the read function should be
>on par with the read in 1.8.

I'd rather avoid making a jump to GUILE 3, as it's not in distributionsn yet.

Just to be extra clear: if I instrument Lily with

 (begin
   (display "gc time taken: ")
   (display (* 1.0 (/ (cdr (assoc 'gc-time-taken (gc-stats)))
internal-time-units-per-second)))
   (display "\n")))

this number increases from 0.3 to 1.7. Parsing and compiling the .scm
files  in our distribution has a GC overhead of 0.3 by itself on GUILE
2.2

The release notes for 2.0 say that

  "Switch to the Boehm-Demers-Weiser garbage collector .. It also
improves performance."

I am curious about the numbers that support this; can somebody point
me to them? From where I stand, it looks like a huge performance
regression.

On Tue, Jan 28, 2020 at 11:41 PM Han-Wen Nienhuys <hanwenn@gmail.com> wrote:
>
> Hi folks,
>
> after a long hiatus I have started getting involved with LilyPond
> again, and one of the things I'd like to do is get LilyPond off GUILE
> 1.8. Experiments suggest that starting from GUILE 2.2, the execution
> performance is on par with 1.8. There are 2 open issues:  caching byte
> compiled files (which I haven't looked into yet), and GC.
>
> Unfortunately, it looks like the adoption of the BDW GC library caused
> a ~6x slowdown, causing an overall end-to-end slowdown of 50%.
>
> I was wondering if you folks would have tips to further tune GC for
> wall-time speed, and if there additional diagnostics to see if we're
> doing something extraordinarily silly.
>
> I already found the GC_free_space_divisor, but I already tuned to its
> fastest value, 1.
>
> --
> Han-Wen Nienhuys - hanwenn@gmail.com - http://www.xs4all.nl/~hanwen



-- 
Han-Wen Nienhuys - hanwenn@gmail.com - http://www.xs4all.nl/~hanwen

Re: garbage collection slowdown

[Han-Wen Nienhuys]

On Tue, Jan 28, 2020 at 11:41 PM Han-Wen Nienhuys <hanwenn@gmail.com> wrote:
> Unfortunately, it looks like the adoption of the BDW GC library caused
> a ~6x slowdown, causing an overall end-to-end slowdown of 50%.
>
> I was wondering if you folks would have tips to further tune GC for
> wall-time speed, and if there additional diagnostics to see if we're
> doing something extraordinarily silly.

For the record, I managed to solve this, by scaling up the heap more
aggressively. See
https://codereview.appspot.com/561390043/diff/557260051/lily/score-engraver.cc

Ironically, this is the same problem scenario that led me to
refactoring the GUILE GC in ~2002, in
c8a1bdc460f892847d0fb3f1321cdeb305160bf8.

-- 
Han-Wen Nienhuys - hanwenn@gmail.com - http://www.xs4all.nl/~hanwen

Re: garbage collection slowdown

[Ludovic Courtès]

Hi Han-Wen,

Great to see you back here!

Han-Wen Nienhuys <hanwenn@gmail.com> skribis:

> On Tue, Jan 28, 2020 at 11:41 PM Han-Wen Nienhuys <hanwenn@gmail.com> wrote:
>> Unfortunately, it looks like the adoption of the BDW GC library caused
>> a ~6x slowdown, causing an overall end-to-end slowdown of 50%.
>>
>> I was wondering if you folks would have tips to further tune GC for
>> wall-time speed, and if there additional diagnostics to see if we're
>> doing something extraordinarily silly.
>
> For the record, I managed to solve this, by scaling up the heap more
> aggressively. See
> https://codereview.appspot.com/561390043/diff/557260051/lily/score-engraver.cc

Weird.  It would be interesting to see where the slowdown comes from.
Overall, my recollection of the 1.8 to 2.0 transition (where we
introduced libgc) is that GC was a bit faster, definitely not slower.

That said, does LilyPond happen to use lots of bignums and/or lots of
finalizers?  Finalizers, including those on bignums, end up being very
GC-intensive, as discussed in my recent message.  Perhaps that’s what’s
happening here, for instance if you create lots of SMOBs with a free
function.

Thanks,
Ludo’.

Re: garbage collection slowdown

[Han-Wen Nienhuys]

[-- Attachment #1: Type: text/plain, Size: 871 bytes --]

On Wed, Feb 5, 2020 at 5:23 PM Ludovic Courtès <ludo@gnu.org> wrote:

> Weird.  It would be interesting to see where the slowdown comes from.
> Overall, my recollection of the 1.8 to 2.0 transition (where we
> introduced libgc) is that GC was a bit faster, definitely not slower.
>
> That said, does LilyPond happen to use lots of bignums and/or lots of
> finalizers?  Finalizers, including those on bignums, end up being very
> GC-intensive, as discussed in my recent message.  Perhaps that’s what’s
> happening here, for instance if you create lots of SMOBs with a free
> function.
>

No, I think it's because in some phases of the program, there is a lot of
heap growth, with little garbage generation. This causes frequent
(expensive) GCs that don't reclaim anything.


-- 
Han-Wen Nienhuys - hanwenn@gmail.com - http://www.xs4all.nl/~hanwen

[-- Attachment #2: Type: text/html, Size: 1398 bytes --]

Re: garbage collection slowdown

[Mikael Djurfeldt]

[-- Attachment #1: Type: text/plain, Size: 1674 bytes --]

Den ons 5 feb. 2020 23:32Han-Wen Nienhuys <hanwenn@gmail.com> skrev:

>
>
> On Wed, Feb 5, 2020 at 5:23 PM Ludovic Courtès <ludo@gnu.org> wrote:
>
>> Weird.  It would be interesting to see where the slowdown comes from.
>> Overall, my recollection of the 1.8 to 2.0 transition (where we
>> introduced libgc) is that GC was a bit faster, definitely not slower.
>>
>> That said, does LilyPond happen to use lots of bignums and/or lots of
>> finalizers?  Finalizers, including those on bignums, end up being very
>> GC-intensive, as discussed in my recent message.  Perhaps that’s what’s
>> happening here, for instance if you create lots of SMOBs with a free
>> function.
>>
>
> No, I think it's because in some phases of the program, there is a lot of
> heap growth, with little garbage generation. This causes frequent
> (expensive) GCs that don't reclaim anything.
>

When programming dynamic vectors, it is common to adapt the size of newly
allocated chunks by letting them grow in proportion to vector size.

Could the frequency of GC be adapted similarly such that the balance
between GC and allocation is shifted towards allocation in phases with a
lot of heap growth?

More concretely, this could either be achieved by letting the newly
allocated chunks grow in proportion to allocated memory (as I think it was
in the 1.8 GC---don't know about now) or by choosing to not do a GC every
time, but instead directly allocate if running average of GC gain is small
compared to allocated memory.

Of course these are issues at research level...


>
> --
> Han-Wen Nienhuys - hanwenn@gmail.com - http://www.xs4all.nl/~hanwen
>

[-- Attachment #2: Type: text/html, Size: 3110 bytes --]

Re: garbage collection slowdown

[Ludovic Courtès]

Hi Mikael!

Mikael Djurfeldt <mikael@djurfeldt.com> skribis:

> Could the frequency of GC be adapted similarly such that the balance
> between GC and allocation is shifted towards allocation in phases with a
> lot of heap growth?

I guess we’ve been mostly “end users” of libgc, assuming the right
design decisions were made and not touching it much.  Overall it’s
worked quite well, which is why I’m surprised by what Han-Wen reports,
and I don’t feel like diving in libgc.  :-)

Thanks,
Ludo’.