memory leak loading file multiple times

Bug #2020119 reported by Mahmood
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
SBCL
Incomplete
Undecided
Unassigned

Bug Description

i was trying to load the mnist dataset from a csv file (105mb) into sbcl when i found this frustrating memory leak
#+begin_src lisp
  (defun get-file (filename)
    (with-open-file (stream filename)
      (loop for line = (read-line stream nil)
            while line
            collect line)))
  (loop for j from 0 below 3
        do (defparameter a (get-file (pathname "/home/mahmooz/brain/notes/data/2c/cba5d6-f153-454d-9e49-004b56167fbb/mnist_train.csv"))))
#+end_src
i ran sbcl with 1gb heap size using ~sbcl --dynamic-space-size 1GB~
if i load the file only once, it works fine, twice or more it crashes
sbcl would crash with the following error:
#+begin_src lisp
    ,* Heap exhausted during garbage collection: 3696 bytes available, 7312 requested.
          Immobile Object Counts
   Gen layout fdefn symbol code Boxed Cons Raw Code SmMix Mixed LgRaw LgCode LgMix Waste% Alloc Trig Dirty GCs Mem-age
    1 0 0 0 0 0 26 9762 0 0 6 0 0 0 10.7 286734832 182768138 9794 1 1.4000
    2 252 3079 681 2072 82 102 22135 3 12 14 0 0 0 10.5 655347392 2000000 22156 0 1.2896
    3 0 0 0 0 0 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 0 0 0.0 0 2000000 0 0 0.0000
    5 0 0 0 0 0 0 0 0 0 0 0 0 0 0.0 0 2000000 0 0 0.0000
  fatal error encountered in SBCL pid 412660 tid 412660:
  GC invariant lost, file "gencgc.c", line 523

  Welcome to LDB, a low-level debugger for the Lisp runtime environment.
  (GC in progress, oldspace=1, newspace=2)
  ldb>
#+end_src
im on arch linux, more info:
#+begin_src bash
  ~ λ sbcl --version
  SBCL 2.3.3
  ~ λ uname -a
  Linux mahmooz 6.1.28-1-lts #1 SMP PREEMPT_DYNAMIC Thu, 11 May 2023 15:52:41 +0000 x86_64 GNU/Linux
#+end_src
also tried on sbcl versions 2.3.4 and 2.3.1, same error
although i did try running the same code in ~clisp~ and it worked flawlessly, and memory usage wasnt even noticable!
thanks in advance

Revision history for this message
Stas Boukarev (stassats) wrote :

I don't see a leak here, 1GB is not enough to hold 2x the contents of that file at the same time.

Changed in sbcl:
status: New → Incomplete
Revision history for this message
Stas Boukarev (stassats) wrote :

I actually tried this on clisp, 30 times, and it froze my computer by consuming all memory.

SBCL loads the file 30 times without a problem (as long as the dynamic space size is more than 1GB, that is).

Revision history for this message
Mahmood (mahmoodsheikh36) wrote :

this is odd, i just increased dynamic space to 2GB, increased the number of iterations from 2 to 4 and it crashed

Revision history for this message
Richard M Kreuter (kreuter) wrote :
Download full text (5.0 KiB)

Hi Mahmood,

tl;dr the simplest general solution here is to increase your dynamic-space-size; for this particular data set, you can also use a more space-efficient string representation.

It's not clear what exact steps you're taking; however, I've encountered heap exhaustion events similar to what you describe, and the ones I've seen aren't memory leaks, but explainable with some understanding of how SBCL works.

So let's use the following as a deterministic reproduction:

--
$ sbcl --dynamic-space-size 1024 --noinform --no-userinit --no-sysinit
* (defun create-test-file (file size-in-bytes bytes-per-line)
    (with-open-file (f file :direction :output :external-format :ascii
                            :if-exists :supersede :if-does-not-exist :create)
      (loop with line = (make-string (1- bytes-per-line) :initial-element #\a
                                     :element-type 'base-char)
            repeat (ceiling size-in-bytes bytes-per-line)
            do (write-line line f))
      (finish-output f)
      (file-length f)))
CREATE-TEST-FILE
* (defun get-file (file)
    (with-open-file (f file)
      (loop for line = (read-line f nil)
            while line
            collect line)))
GET-FILE
* (create-test-file "/tmp/foo.txt" (* 105 1024 1024) 80)
110100480
* (setq *print-length* 1)
1
* (get-file "/tmp/foo.txt")
("aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
 ...)
* (+ (length *) (reduce #'+ * :key #'length))
(+ (length *) (reduce #'+ * :key #'length))
110100480 ;; Ok, every byte is accounted for.
* (get-file "/tmp/foo.txt")
(get-file "/tmp/foo.txt")
Heap exhausted during garbage collection: 176 bytes available, 336 requested.
        Immobile Object Counts
--

However, it's also possible to demonstrate (in an artificial way) that GET-FILE /can/ run several times repeatedly within 1GB of dynamic space:

--
$ sbcl --dynamic-space-size 1024 --noinform --no-userinit --no-sysinit
;; Evaluate the DEFUN for GET-FILE, then
* (sb-ext:gc :full t)
NIL
* (time (progn (get-file "/tmp/foo.txt") nil))
Evaluation took:
  0.628 seconds of real time
  0.628505 seconds of total run time (0.429971 user, 0.198534 system)
  [ Run times consist of 0.369 seconds GC time, and 0.260 seconds non-GC time. ]
  100.16% CPU
  1,629,334,080 processor cycles
  525,666,560 bytes consed

NIL
* (time (loop repeat 100 do (sb-ext:gc :full t) (get-file "/tmp/foo.txt")))
Evaluation took:
  77.371 seconds of real time
  77.278278 seconds of total run time (50.084011 user, 27.194267 system)
  [ Run times consist of 47.966 seconds GC time, and 29.313 seconds non-GC time. ]
  99.88% CPU
  200,545,085,462 processor cycles
  52,567,797,248 bytes consed

NIL
--

So it seems that artificially forcing garbage collection appears to counterindicate a memory leak (at least a fast leak).

What's actually going on here? First, SBCL's STRING type uses 4 bytes of storage per character (IOW, it uses UTF-32 encoding). So 105MiB of pure ASCII text will require around 420MiB of dynamic space (more or less -- the lines GET-LINE produces don't contain the #\Linefeed character, but each string has some overhead and alignment requirements). And then ...

Read more...

Revision history for this message
Stas Boukarev (stassats) wrote :

2GB might be too little, 105MB with unicode strings will take 420MB, multiple by two, 840MB, then during the GC might have to use twice as much space, so 1680MB, and that just the strings.

And it can be more than 2x the size of the working set, as the gc might be triggered in the middle of the third iteration, so you'll have more than two files in memory.

Probably just set A to NIL before reading a new file, use base-strings, etc.

Revision history for this message
Mahmood (mahmoodsheikh36) wrote :

even if i increase the memory size, and even if i drop the assignment to the variable a, it would still crash after a enough iterations, in clisp it doesnt

Revision history for this message
Tomas Hlavaty (tomas-hlavaty) wrote : Re: [Bug 2020119] Re: memory leak loading file multiple times

On Thu 18 May 2023 at 18:59, Stas Boukarev <email address hidden> wrote:
> 2GB might be too little, 105MB with unicode strings will take 420MB,
> multiple by two

what is this "multiple by two"?

Revision history for this message
Stas Boukarev (stassats) wrote :

> what is this "multiple by two"?

After the first iteration A holds the file, and just before (setf a new-file) there are two files in memory.

Revision history for this message
Tomas Hlavaty (tomas-hlavaty) wrote :

On Fri 19 May 2023 at 12:06, Stas Boukarev <email address hidden> wrote:
>> what is this "multiple by two"?
>
> After the first iteration A holds the file, and just before (setf a new-
> file) there are two files in memory.

i see, not related to sbcl itself, thanks

Revision history for this message
Mahmood (mahmoodsheikh36) wrote :

> 2GB might be too little,
you're missing the point
i could use 10GB memory and it would still crash after an arbitrary number of iterations
the gc isnt properly working here, im not sure why
even if i drop the assignment to a variable and just load the file on each iteration into nothing (without assigning to anything) memory keeps going up until sbcl crashes

Revision history for this message
Stas Boukarev (stassats) wrote :

Doesn't happen here.

Revision history for this message
Tomas Hlavaty (tomas-hlavaty) wrote :

On Sat 20 May 2023 at 13:02, Mahmood <email address hidden> wrote:
> i could use 10GB memory and it would still crash after an arbitrary number of iterations
> the gc isnt properly working here, im not sure why
> even if i drop the assignment to a variable and just load the file on each iteration into nothing (without assigning to anything) memory keeps going up until sbcl crashes

iirc we've had problems with strings too
the conservative gc does not guarantee to reclaim everything

Revision history for this message
Mahmood (mahmoodsheikh36) wrote :

(defun get-file (filename)
  (with-open-file (stream filename)
                  (loop for line = (read-line stream nil)
                        while line
                        collect line)))
(loop for j from 0 below 30
      do (defparameter a (get-file (pathname "/home/mahmooz/brain/notes/data/2c/cba5d6-f153-454d-9e49-004b56167fbb/mnist_train.csv"))))

use the above code, the file is 105mb, start sbcl with 4GB memory using --dynamic-space-size 4GB, after some iterations sbcl crashes, if it doesnt happen for you, then idk

Revision history for this message
Stas Boukarev (stassats) wrote :

I have dynamic-space-size at 12GB.

Revision history for this message
Mahmood (mahmoodsheikh36) wrote :

ok maybe consider lowering it to 4gb? that'd make it crash quicker

Revision history for this message
Stas Boukarev (stassats) wrote :

If it crashes at lower dynamic space sizes then there's nothing that can be done about that.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.