[Sbcl-help] Making GC more parsimoniuos of memory

[Tim Josling]

Hi

I have been happily using SBCL for many years. Currently I have a very
memory intensive application due to a large amount of data that I need
to access at array speeds.

I have set the memory limit at 30Gib. This then also required setting
max_map_count on my linux x86_64 system. But when I get to around
13-16GiB used I start to get out of memory errors. These errors (see
below) seem to occur during garbage collection.

CL-USER> (SOFTWARE-VERSION)
"4.4.0-93-generic"
CL-USER> (SB-SYS:GET-MACHINE-VERSION)
"Intel(R) Core(TM) i7-4770K CPU @ 3.50GHz"
CL-USER> (UIOP/OS:LISP-VERSION-STRING)
"1.3.1.debian" (i.e. "Ubuntu 16.04.3 LTS")

From which it appears that the GC only works when I have ~double the
used memory available.

Error message:

Heap exhausted during garbage collection: 0 bytes available, 64 requested.
Gen StaPg UbSta LaSta LUbSt Boxed Unboxed LB LUB !move Alloc
Waste Trig WP GCs Mem-age
0: 0 0 0 0 0 0 0 0 0 0
0 322122547 0 0 0.0000
1: 0 0 0 0 0 0 0 0 0 0
0 322122547 0 0 0.0000
2: 0 0 0 0 0 0 0 0 0 0
0 322122547 0 0 0.0000
3: 0 0 0 0 0 0 0 0 0 0
0 322122547 0 0 0.0000
4: 0 0 0 0 0 0 0 0 0 0
0 322122547 0 0 0.0000
5: 464103 469060 0 0 361072 212395 674 489 84
18593210400 236265440 14033953987 0 4 0.7375
6: 0 0 0 0 1617 226 0 0 0 60391424
0 2000000 1496 0 0.0000
Total bytes allocated = 31920187456
Dynamic-space-size bytes = 32212254720
GC control variables:
*GC-INHIBIT* = true
*GC-PENDING* = false
*STOP-FOR-GC-PENDING* = false
fatal error encountered in SBCL pid 4769(tid 140735199704832):
Heap exhausted, game over.

Previous (room nil) output

Breakdown for dynamic space:
7,476,526,208 bytes for 467,282,888 cons objects.
4,455,227,040 bytes for 58,096,093 simple-character-string objects.
1,096,192,816 bytes for 11,402,878 simple-vector objects.
744,423,712 bytes for 3,038,413 other objects.
13,772,369,776 bytes for 539,820,272 dynamic objects (space total.)

Breakdown for read-only space:
4,944 bytes for 4 code objects.
4,944 bytes for 4 read-only objects (space total.)

(Dynamic allowed is 32,212,254,720 bytes 30.0d0 Gib
SBCL command from slime;
("sbcl" "--dynamic-space-size" "30720" "--disable-ldb" "--lose-on-corruption"))

I put in reasonably frequent (gc :full t) which doesn't solve the
problem. I could increase the memory and spill into swap but this
makes the program run extremely slowly (10X slower) and it already
takes too long.

I could do work to compress the data and so forth to make it fit but I
would rather not. Or buy a bigger PC.

I have looked at/tried the gc parameters and nothing seems to help.

So my questions are:

1. Does this sound right that the GC falls apart when the memory
available is not roughly >= 2 times memory used?

2. Is there anything I can do to make the GC more sparing in its
memory use or more tolerant or memory shortage, even at the cost of
slower running?

3. Is there some problem with (mem) that causes it to burn vast
amounts of memory?

Tim Josling

------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Sbcl-help mailing list
Sbcl...@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/sbcl-help

[Liam Healy]

Is this a stop-and-copy algorithm, which can use only half the available heap?
https://en.wikipedia.org/wiki/Cheney%27s_algorithm


Liam

[Tim Josling]

On Fri, Jan 5, 2018 at 9:34 AM, Liam Healy <l...@healy.washington.dc.us> wrote:

Is this a stop-and-copy algorithm, which can use only half the available heap?
https://en.wikipedia.org/wiki/Cheney%27s_algorithm

Liam

On X86 the algorithm used is gencgc (alternative cheney seems to be used on some other platforms. Cheney is stop-and-copy).

The algo used is a bit obscure to me so far. They refer to a paper (67 pp) for guidance. The paper refers to both mark-and-sweep and stop-and-copy so that doesn't help.

It seems that stop-and-copy does 'waste' 50% of allocated memory, i.e. it can only be used for GC, thought they suggest more complex algos can avoid this.

http://wiki.c2.com/?StopAndCopy

Without claiming this is definitive, code like this (gencgc.c) looks like mark and sweep

        execute_full_mark_phase();

        execute_full_sweep_phase();

So it is a bit of a mystery. 

> 3. Is there some problem with (mem) that causes it to burn vast
> amounts of memory?

Also please ignore the above stray text from my email.

Tim

[Douglas Katzman via Sbcl-help]

gencgc is primarily stop-and-copy with a little bit of mark-and-sweep, but it does not stop-and-copy the entire heap on every collection cycle, only on those cycles for which you specify ":full t" which is exactly what you said you're doing.

If the amount of actually-live stuff is X megabytes, then you will very likely need 2X megabytes to do a full collection.

Try removing the ":full t" and see if letting the GC figure out what to do decreases the memory requirement.

[Tim Josling]

Forgot to send this to the main list. 

Also, here is where I ended up:

0. I added a post GC hook to display memory status. This helped to see what was happening. 

1. I removed *all* GC calls. This seemed to allow memory to be recovered without needing vast amounts of storage.

2. I set the memory at 48GiB = physical memory * 1.5.

3. I made some changes to reduce memory demands and consing. 

Result is that things run OK. For now. 

However the next phase is going to be more memory intensive. I am having a look into replacing the GC algorithm with something more economical of memory, even if slower in theory, but it doesn't look simple. Also to provide a GC algorithm that turns off GC. Most programs I run would probably run better without all the overheads of GC, and do not need it. (I remember switching off the GC in the gcc compiler and the self-build ran 15% faster. I will post on the dev list though before I start coding though.

Tim

---------- Forwarded message ----------
From: Tim Josling <tim.j...@gmail.com>
Date: Fri, Jan 5, 2018 at 2:25 PM
Subject: Re: [Sbcl-help] Making GC more parsimoniuos of memory
To: Douglas Katzman <do...@google.com>

Thank you.

tldr: It does not always fail near 50%, it depends. That seems to be worst case, sometimes can get to 70-80%. Changing GC calls produces strange results; seems o last longest with no user initiated GC in my testing. If you do lots of GCs it migrates storage up and triggers full GC sooner, it seems  Overall it looks hard to fix.

It failed during automatically generated GC not my (gc :full t). 

Test program below fails at about 9 GiB with 12GiB allowed with no GC calls by me.

I verified GC would recover very little (< 100Kib), in an earlier run - see commented out code. So the usage is about 8GiB.

;;; -*- lisp -*-

(proclaim '(optimize (debug 3) (speed 0) (safety 3)))

(in-package :common-lisp-user)

;; m-- slime, pick sbcl12g

(defun mem (&key (verbose nil)) ;; :default t

  (room verbose)

  (let ((ms (dynamic-space-size))

         (k 1024.0))

    (format t "~%Dynamic allowed ~:D bytes ~:D Gib~%" ms (/ ms (expt k 3))))

  (format t "~%GC Time ~F Secs~%" (/ *gc-run-time* 1d0 internal-time-units-per-second)))

(defun test-mem ()

    (let ((acc nil)

           (ct 0))

      (loop do

           (if (zerop (mod ct 100000))

               (progn

                 (format t "ct ~:D~%" ct)

                 (mem)

                 ;;(gc :full t)

                 ;;(mem)

                 ))

           (push (list ct ct ct ct ct ct ct ct) acc)

           (incf ct))))

         

.... prior printouts per 100k allocations ...

         

ct 62,600,000

Dynamic space usage is:   9,094,730,288 bytes.

Read-only space usage is:      4,944 bytes.

Static space usage is:         3,168 bytes.

Control stack usage is:        8,960 bytes.

Binding stack usage is:        1,072 bytes.

Control and binding stack usage is for the current thread only.

Garbage collection is currently enabled.

Dynamic allowed 12,884,901,888 bytes 12.0 Gib

GC Time 16.04 Secs

ct 62,700,000

Dynamic space usage is:   9,109,145,760 bytes.

Read-only space usage is:      4,944 bytes.

Static space usage is:         3,168 bytes.

Control stack usage is:        8,960 bytes.

Binding stack usage is:        1,072 bytes.

Control and binding stack usage is for the current thread only.

Garbage collection is currently enabled.

Dynamic allowed 12,884,901,888 bytes 12.0 Gib

GC Time 16.04 Secs

Heap exhausted during garbage collection: 0 bytes available, 16 requested.

 Gen StaPg   UbSta LaSta LUbSt   Boxed Unboxed   LB   LUB  !move  Alloc  Waste     Trig              WP      GCs  Mem-age

   0:           0           0         0        0           0              0     0        0          0                   0          0 128849018            0  0  0.0000

   1: 243604 208698         0        0 117833            20     0        0        10 3861230528 576576 128849018           0   0  1.0000

   2: 327932 327929         0        0 162979            95     0        0        75 5343028864 579968     2000000 162903   0  0.0000

   3:           0           0         0        0           0              0     0        0          0                   0           0     2000000           0   0  0.0000

   4:           0           0         0        0           0              0     0        0          0                   0           0     2000000           0   0  0.0000

   5:           0           0         0        0           0              0     0        0          0                   0           0     2000000           0   0  0.0000

   6:           0           0         0        0     1617          226     0        0          0     60391424           0     2000000     1498   0  0.0000

   Total bytes allocated    = 12883572112

   Dynamic-space-size bytes = 12884901888

GC control variables:

   *GC-INHIBIT* = true

   *GC-PENDING* = true

   *STOP-FOR-GC-PENDING* = false

fatal error encountered in SBCL pid 31607(tid 140736484964096):

Heap exhausted, game over.

Process inferior-lisp<1> exited abnormally with code 1

"Bytes allocated" vastly exceeds bytes used. I suspect probably due to page granularity and generations.

With (gc) (no parameters) every 100k allocations it fails at about 7GiB. 

ct 49,300,000

Dynamic space usage is:   7,177,709,872 bytes.

Read-only space usage is:      4,944 bytes.

Static space usage is:         3,168 bytes.

Control stack usage is:        8,960 bytes.

Binding stack usage is:        1,072 bytes.

Control and binding stack usage is for the current thread only.

Garbage collection is currently enabled.

Dynamic allowed 12,884,901,888 bytes 12.0 Gib

GC Time 28.208 Secs

mem done (shows we are not in my GC)

Heap exhausted during garbage collection: 0 bytes available, 16 requested.

 Gen StaPg UbSta LaSta LUbSt Boxed Unboxed LB   LUB  !move  Alloc  Waste   Trig    WP  GCs Mem-age

   0:     0     0     0     0     0     0     0     0     0        0     0 128849018    0   0  0.0000

   1:     0     0     0     0     0     0     0     0     0        0     0 128849018    0   0  0.0000

   2:     0     0     0     0     0     0     0     0     0        0     0 128849018    0   0  0.0000

   3: 263458 260841     0     0 217573    79     0     0    67 7131176352 844384 4379801370    0   1  1.3942

   4: 393215 67862     0     0 173715     6     0     0     0 5692389760 99968  2000000    0   0  0.0000

   5:     0     0     0     0     0     0     0     0     0        0     0  2000000    0   0  0.0000

   6:     0     0     0     0  1617   226     0     0     0 60391424     0  2000000 1495   0  0.0000

   Total bytes allocated    = 12883957536

   Dynamic-space-size bytes = 12884901888

GC control variables:

   *GC-INHIBIT* = true

   *GC-PENDING* = false

   *STOP-FOR-GC-PENDING* = false

fatal error encountered in SBCL pid 32292(tid 140736484964096):

Heap exhausted, game over.

Does not look easy to fix/change/make optional.

Tim