Re: out-of-control GC

[Linas Vepstas]

Hi Arne,

On Sun, Sep 10, 2017 at 11:50 AM, Arne Babenhauserheide <address@hidden>
wrote:

> Hi Linas,
>
>
> Linas Vepstas <address@hidden> writes:
>
> > To make this conversation less crazy, and more down-to-earth, here is a
> > demo that seems to spend most of its time in GC. Hard for me to to say
> that
> > this is "wrong", right now, but it illustrates the scandalous nature of
> the
> > problem.
>
> Do you have many string operations in your code?
>
> If I replace
>
>     (cons (format #f "~A" cnt) lis)
>
> with
>
>     (cons cnt lis)
>
> GC is down to ~20% (from around 130%).
>

That demo tried to capture the spirit of a more complex system. The cons
that I have is actually (cons (wrapper-for-some-c++-code foobar) lis)  or
maybe (cons (scheme-that-calls-other-scheme-that-calls-c++ foo) lis)  ...
but its not just cons -- it can also be for-each, map, or fold.

The actual printouts, in my instrumented code look like this:

guile-en-r> (avg-gc-cpu-time)
Elapsed: 4461. secs. Rate: 4.236 gc/min %cpu-GC: 280.8%  %cpu-use: 284.0%

guile-en-r> (avg-gc-cpu-time)
Elapsed: 1501. secs. Rate: 4.077 gc/min %cpu-GC: 280.4%  %cpu-use: 283.8%

guile-en-r> (gc-stats)

((gc-time-taken . 353452428102078) (heap-size . 6485340160) (heap-free-size
. 3497791488) (heap-total-allocated . 100778445248)
(heap-allocated-since-gc . 9248) (protected-objects . 7) (gc-times . 12894))

which suggests that the vast majority of time is spent in GC, and not in
either scheme/guile, or my wrapped c++ code.

4 gc's/minute means one every 15 seconds, which sounds reasonable, except
that RAM usage is so huge, that each GC takes many seconds to complete.  By
examining  heap-free-size before and after, there is almost no change --
i.e. there was very little to collect.   Hmm  .. perhaps I should monitor
that more closely, to see how true that really is ...

Anyway, this demo gives a scenario where gc seems to run too often.  I have
other scenarios where it does not run often enough -- I have one where the
working set is about 200MBytes, but guile happily grows to 10GB or 20GB RAM
over a few hours.  My solution for that other case is to manually GC
whenever gc-stats gets above 1GB, because I know a priori my working set is
smaller than that.

The overall message seems to be that gc either runs too often, or not often
enough.  Some sort of better planning is needed.

I'm motivated to explore this, as it actually impacts my work.

--linas

-- 
*"The problem is not that artificial intelligence will get too smart and
take over the world," computer scientist Pedro Domingos writes, "the
problem is that it's too stupid and already has." *