bug#43389: 28.0.50; Emacs memory leaks

[Russell Adams]

On Thu, Sep 17, 2020 at 10:47:04PM +0200, Russell Adams wrote:
> From Emacs memory-usage package:
>
> Garbage collection stats:
> ((conses 16 1912248 251798) (symbols 48 54872 19) (strings 32 327552 81803) 
> (string-bytes 1 12344346) (vectors 16 158994) (vector-slots 8 2973919 339416) 
> (floats 8 992 4604) (intervals 56 182607 7492) (buffers 1000 195))
>
>  =>   29.2MB (+ 3.84MB dead) in conses
>       2.51MB (+ 0.89kB dead) in symbols
>       10.00MB (+ 2.50MB dead) in strings
>       11.8MB in string-bytes
>       2.43MB in vectors
>       22.7MB (+ 2.59MB dead) in vector-slots
>       7.75kB (+ 36.0kB dead) in floats
>       9.75MB (+  410kB dead) in intervals
>        190kB in buffers
>
> Total in lisp objects: 97.9MB (live 88.5MB, dead 9.36MB)

I had the memory leak occur again and this time I had the
glibc-malloc-trace-utils loaded and running from the start.

So my emacs grew to 8GB in RAM, and what was curious is if it was a
background task (not window focused on an emacsclient), then the
memory stayed the same. When I had the window focused, I could watch
the memory constantly increasing in htop a few megs at a time.

Garbage collection stats:
((conses 16 1749077 1176908)
 (symbols 48 47530 38)
 (strings 32 307123 144020)
 (string-bytes 1 10062511)
 (vectors 16 113172)
 (vector-slots 8 2105205 486800)
 (floats 8 709 1719)
 (intervals 56 174593 44804)
 (buffers 1000 71))

 =>     26.7MB (+ 18.0MB dead) in conses
        2.18MB (+ 1.78kB dead) in symbols
        9.37MB (+ 4.40MB dead) in strings
        9.60MB in string-bytes
        1.73MB in vectors
        16.1MB (+ 3.71MB dead) in vector-slots
        5.54kB (+ 13.4kB dead) in floats
        9.32MB (+ 2.39MB dead) in intervals
        69.3kB in buffers

Total in lisp objects:  103MB (live 75.0MB, dead 28.5MB)

Buffer ralloc memory usage:
47 buffers
3.36MB total ( 232kB in gaps)
      Size      Gap     Name

    926626      1504    AIS.org
    690050      1933    Personal.org
    553850      2000    Abuffer.org
    490398      3851    *Packages*
    215653      2000    KB.org
     76686      1708    X230.org
     59841      2123    Agenda.org
     51375      51076   *sly-events for sbcl*
     51060      1902    ASC.org
     44596      2000    Contacts.org
     36825      1792    *Messages*
     23882      2309    *org-caldav-debug*
     22867      2000    rgb.lisp
     14678      746     *sly-mrepl for sbcl*
      6640      1173    VirtualFCMap.lisp
      4096      2000     *code-converting-work*
      3409      16717    *http orgmode.org:443*
      1946      104     *Org Agenda*
      1528      2028     *http gaming.demosthenes.org*-491231
      1524      2028     *http gaming.demosthenes.org*-15349
      1518      2028     *http gaming.demosthenes.org*
      1276      1368    *sly-inferior-lisp for sbcl*
      1231      2026     *http gaming.demosthenes.org*-464306
      1208      825     *Help*
       679      1574    *Buffer Details*
       641      1975     *Agenda Commands*
       531      1494    *Calendar*
       324      2008     *http melpa.org:443*
       278      3775    *helm M-x*
       185      1838    *org caldav sync result*
       144      2000    *scratch*
        57      21434   *helm find files*
        44      5610     *icalendar-work*
        30      2000     *sly-fontify*
        21      2000    *log-edit-files*
        20      0        *pdf-info-query--escape*
        18      4077    *helm mini*
        12      8630     *code-conversion-work*
         5      4065     *Echo Area 1*
         0      2033     *Minibuf-1*
         0      20       *Minibuf-0*
         0      20       *server*
         0      4060     *Echo Area 0*
         0      61547    *sly-1*
         0      20       *sly-dds-1-1*
         0      20      *changes to ~/ASC/Software/Snaps/*
         0      20      *vc*

I started emacs with:

MTRACE_CTL_FILE=mtraceEMACS.mtr 
LD_PRELOAD=~/software/glibc-malloc-trace-utils/libmtrace.so ~/.local/bin/emacs 
--daemon >> ~/.config/emacs/emacs.log 2>&1

This created some huge files. By the time I reached 8GB in RAM, the
mtr file for the main process (I think) was 53 GB. I also have little mtrace
files littered everywhere in different project directories.

-rw-r--r--   1 adamsrl adamsrl  53G Nov 26 13:23 mtraceEMACS.mtr.15236
-rw-r--r--   1 adamsrl adamsrl 4.2G Nov 26 13:36 my.wl
-rw-r--r--   1 adamsrl adamsrl 1.3G Nov 26 13:50 mtraceEMACS.mtr.15236.allocs
-rw-r--r--   1 adamsrl adamsrl  32K Nov 26 13:55 
mtraceEMACS.mtr.15236.binnedallocs.log
-rw-r--r--   1 adamsrl adamsrl 6.0G Nov 26 15:12 vmrssout
-rw-r--r--   1 adamsrl adamsrl 6.0G Nov 26 15:12 vmout
-rw-r--r--   1 adamsrl adamsrl 8.6G Nov 26 15:12 idealrssout

I converted the mtraceEMACS.mtr.15236 to my.wl using trace2wl.

The trace_run command did this output:

% ~/software/glibc-malloc-trace-utils/trace_run ./my.wl vmout vmrssout 
idealrssout
11,757,635,230,744 cycles
4,532,472,554 usec wall time
5,966,752,470 usec across 3 threads
8,461,721,600 bytes Max RSS (218,308,608 -> 8,680,030,208)
Starting VmRSS 218308608 (bytes)
Starting VmSize 219549696 (bytes)
Starting MaxRSS 218308608 (bytes)
Ending VmRSS 8680030208 (bytes)
Ending VmSize 8903626752 (bytes)
Ending MaxRSS 8680030208 (bytes)
8,131,008 Kb Max Ideal RSS

sizeof ticks_t is 8
Avg malloc time:    145 in 422,186,832 calls
Avg calloc time: 12,538 in  1,164,584 calls
Avg realloc time:   566 in  3,294,165 calls
Avg free time:      110 in 449,397,629 calls
Total call time: 127,318,389,383 cycles

These files are impossible to share around, is there anything I can
run to extract anything else useful from them?

% ~/software/glibc-malloc-trace-utils/trace_statistics mtraceEMACS.mtr.15236
Min allocation size: 0
Max allocation size: 1603869
Mean allocation size: 128

I did follow the instructions for downsampling, but I haven't a clue
what to do in Octave. Is it worth posting those files?

I have the impression this is more about how often more RAM was
requested, and not the source of the call?

I should mention I'm present in #emacs and happy to discuss there.

------------------------------------------------------------------
Russell Adams                            RLAdams@AdamsInfoServ.com

PGP Key ID:     0x1160DCB3           http://www.adamsinfoserv.com/

Fingerprint:    1723 D8CA 4280 1EC9 557F  66E8 1154 E018 1160 DCB3