unofficial mirror of bug-gnu-emacs@gnu.org 
 help / color / mirror / code / Atom feed
* bug#41194: 28.0.50; [feature/native-comp] fibn benchmark exhausts memory
@ 2020-05-11 20:47 Kévin Le Gouguec
  2020-06-09 22:24 ` Andrea Corallo
  0 siblings, 1 reply; 9+ messages in thread
From: Kévin Le Gouguec @ 2020-05-11 20:47 UTC (permalink / raw)
  To: 41194

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

As detailed in bug#41077, I compiled the feature/native-comp branch[1]
on a low-end-ish laptop[2], blacklisting char-fold.el since native
compilation took too much memory for this file.

As reported there, I get appreciable speedups on the benchmarks
distributed in the elisp-benchmarks ELPA package, except for one
specific test: fibn.  When native-compiled (with any value of
comp-speed), this test makes Emacs abort with the message:

> Memory exhausted--use C-x s then exit and restart Emacs

I've plotted some graphs showing fibn's memory consumption for every
value of comp-speed, as well as for emacs master[3] (where all 3
iterations run to completion):


[-- Attachment #2: fibn.pdf --]
[-- Type: application/pdf, Size: 81262 bytes --]

[-- Attachment #3: Type: text/plain, Size: 716 bytes --]


See [4] for the methodology, source material and logs.  Out of curiosity
I've disassembled the compiled functions in fibn.el for comp-speed 2;
I'm not fluent enough in assembly to spot anything obviously wrong[5].


Let me know if there are things you would like me to try out in order to
investigate this.  


[1] Commit 92cf4bb8cc3da81f4877a734b9e9089ac4b89e85.

[2] Samsung NC10, 2GB RAM, 2GB HDD swap, on Debian Buster.

[3] Commit 9d8fc3a598090da518fcdd5c0503ed0f7faa41a9.

[4] .eln files compiled with:

    (dotimes (i 4) (rename-file (let ((comp-speed i)) (native-compile "fibn.el"))
                                (format "fibn-%d.eln" i)))

    Script used to collect measurements on branch native-comp:

[-- Attachment #4: repro.sh --]
[-- Type: application/x-shellscript, Size: 690 bytes --]

[-- Attachment #5: Type: text/plain, Size: 59 bytes --]


    Script used to collect measurements on branch master:

[-- Attachment #6: master.sh --]
[-- Type: application/x-shellscript, Size: 469 bytes --]

[-- Attachment #7: Type: text/plain, Size: 37 bytes --]


    Script used to plot the graphs:

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #8: plot.py --]
[-- Type: text/x-python, Size: 2291 bytes --]

#!/usr/bin/env python3

from datetime import datetime, timedelta
from pathlib import Path
import re

import matplotlib
from matplotlib import pyplot
from matplotlib.ticker import EngFormatter


MONITOR_RE = re.compile('\n'.join((
    '(?P<time>.+)',
    r' *(?P<seconds>\d+) +(?P<vsz>\d+) +(?P<rss>\d+) +(?P<args>.+)',
    ' *(?P<memheader>.+)',
    'Mem: *(?P<memvalues>.+)',
    'Swap: *(?P<swapvalues>.+)',
    ''
)), flags=re.MULTILINE)


def list_snapshots(monitor_log):
    snapshots = []

    for match in MONITOR_RE.finditer(monitor_log):
        md = match.groupdict()

        memkeys = md['memheader'].split()
        memvalues = md['memvalues'].split()
        swapvalues = md['swapvalues'].split()

        snapshot = {
            'time': datetime.strptime(md['time'], '%Y-%m-%d-%H:%M:%S'),
            'uptime': int(md['seconds']),
            'vsz': int(md['vsz'])*1024,
            'rss': int(md['rss'])*1024,
            'process': md['args'],
            'mem': {memkeys[i]: int(val)*1024 for i, val in enumerate(memvalues)},
            'swap': {memkeys[i]: int(val)*1024 for i, val in enumerate(swapvalues)}
        }

        snapshots.append(snapshot)

    return snapshots


def graph_logs(f, title):
    snapshots = list_snapshots(Path(f).read_text())

    x0 = snapshots[0]['time']
    xs = tuple((s['time']-x0).seconds for s in snapshots)
    vsz = tuple(s['vsz'] for s in snapshots)
    rss = tuple(s['rss'] for s in snapshots)
    memavail = tuple(s['mem']['available'] for s in snapshots)
    swapused = tuple(s['swap']['used'] for s in snapshots)

    fig, axes = pyplot.subplots()
    axes.plot(xs, vsz, label='VSZ (process)')
    axes.plot(xs, rss, label='RSS (process)')
    axes.plot(xs, memavail, label='available memory (system)', linewidth=0.5)
    axes.plot(xs, swapused, label='used swap (system)')

    axes.set_xlim(0, (snapshots[-1]['time']-x0).seconds)
    axes.set_xlabel('seconds')
    axes.set_ylim(0)
    axes.yaxis.set_major_formatter(EngFormatter(unit='B'))
    axes.legend()
    axes.set_title(title)

    pyplot.savefig(f.replace('.log', '.pdf'))
    pyplot.show()


matplotlib.use('TkAgg')

for i in range(4):
    graph_logs(f'fibn-{i}.log', f'fibn test with comp-speed {i}')

graph_logs('fibn-master.log', 'fibn test with emacs master')

[-- Attachment #9: Type: text/plain, Size: 19 bytes --]


    Measurements:

[-- Attachment #10: measurements.tgz --]
[-- Type: application/x-compressed-tar, Size: 18291 bytes --]

[-- Attachment #11: Type: text/plain, Size: 27 bytes --]


    Logs for native-comp:

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #12: repro.log --]
[-- Type: text/x-log, Size: 5050 bytes --]

+ elisp_benchmarks=/home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el
+ gccemacs=/home/peniblec/Downloads/sources/emacs-meta/feature/native-comp/src/emacs
+ for i in {0..3}
+ sudo swapoff -a
+ sudo swapon -a
++ dirname /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el
+ cd /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks
+ ln -sf fibn-0.eln fibn.eln
+ out=fibn-0.log
+ set +x
+ /home/peniblec/Downloads/sources/emacs-meta/feature/native-comp/src/emacs -Q -batch -l /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el -eval '(elisp-benchmarks-run "fibn\\.")'
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble-no-cons...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-rec...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn (native compiled elisp)...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/inclist...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/listlen-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/pidigits...
Iteration number: 1
Running fibn...
Memory exhausted--use C-x s then exit and restart Emacs
+ for i in {0..3}
+ sudo swapoff -a
+ sudo swapon -a
++ dirname /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el
+ cd /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks
+ ln -sf fibn-1.eln fibn.eln
+ out=fibn-1.log
+ set +x
+ /home/peniblec/Downloads/sources/emacs-meta/feature/native-comp/src/emacs -Q -batch -l /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el -eval '(elisp-benchmarks-run "fibn\\.")'
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble-no-cons...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-rec...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn (native compiled elisp)...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/inclist...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/listlen-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/pidigits...
Iteration number: 1
Running fibn...
Memory exhausted--use C-x s then exit and restart Emacs
+ for i in {0..3}
+ sudo swapoff -a
+ sudo swapon -a
++ dirname /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el
+ cd /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks
+ ln -sf fibn-2.eln fibn.eln
+ out=fibn-2.log
+ set +x
+ /home/peniblec/Downloads/sources/emacs-meta/feature/native-comp/src/emacs -Q -batch -l /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el -eval '(elisp-benchmarks-run "fibn\\.")'
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble-no-cons...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-rec...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn (native compiled elisp)...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/inclist...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/listlen-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/pidigits...
Iteration number: 1
Running fibn...
Memory exhausted--use C-x s then exit and restart Emacs
+ for i in {0..3}
+ sudo swapoff -a
+ sudo swapon -a
++ dirname /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el
+ cd /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks
+ ln -sf fibn-3.eln fibn.eln
+ out=fibn-3.log
+ set +x
+ /home/peniblec/Downloads/sources/emacs-meta/feature/native-comp/src/emacs -Q -batch -l /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el -eval '(elisp-benchmarks-run "fibn\\.")'
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble-no-cons...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-rec...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn (native compiled elisp)...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/inclist...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/listlen-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/pidigits...
Iteration number: 1
Running fibn...
Memory exhausted--use C-x s then exit and restart Emacs

[-- Attachment #13: Type: text/plain, Size: 22 bytes --]


    Logs for master:

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #14: master.log --]
[-- Type: text/x-log, Size: 1575 bytes --]

+ elisp_benchmarks=/home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el
+ emacs=/home/peniblec/Downloads/sources/emacs/src/emacs
+ sudo swapoff -a
+ sudo swapon -a
+ out=fibn-master.log
+ set +x
+ /home/peniblec/Downloads/sources/emacs/src/emacs -Q -batch -l /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/elisp-benchmarks.el -eval '(elisp-benchmarks-run "fibn\\.")'
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble-no-cons...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/bubble...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-rec...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/fibn...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/inclist...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/listlen-tc...
Loading /home/peniblec/.emacs.d/elpa/elisp-benchmarks-1.1/benchmarks/pidigits...
Iteration number: 1
Running fibn...
Iteration number: 2
Running fibn...
Iteration number: 3
Running fibn...
* Results

  | test  | non-gc avg (s) | gc avg (s) | gcs avg | tot avg (s) | tot avg err (s) |
  |-------+----------------+------------+---------+-------------+-----------------|
  | fibn  |         283.13 |     247.25 |    4425 |      530.37 |            3.03 |
  |-------+----------------+------------+---------+-------------+-----------------|
  | total |         283.13 |     247.25 |    4425 |      530.37 |            3.03 |


[-- Attachment #15: Type: text/plain, Size: 5 bytes --]


[5]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #16: elb-fibn.s --]
[-- Type: text/x-asm, Size: 4813 bytes --]

000015e0 <F656c622d6669626e_elb_fibn_0>:
    15e0:	e8 f7 01 00 00       	call   17dc <__x86.get_pc_thunk.ax>
    15e5:	05 1b 2a 00 00       	add    $0x2a1b,%eax
    15ea:	55                   	push   %ebp
    15eb:	57                   	push   %edi
    15ec:	56                   	push   %esi
    15ed:	53                   	push   %ebx
    15ee:	83 ec 4c             	sub    $0x4c,%esp
    15f1:	8b 88 f4 ff ff ff    	mov    -0xc(%eax),%ecx
    15f7:	8b a8 f8 ff ff ff    	mov    -0x8(%eax),%ebp
    15fd:	8d 44 24 20          	lea    0x20(%esp),%eax
    1601:	89 4c 24 1c          	mov    %ecx,0x1c(%esp)
    1605:	8b 09                	mov    (%ecx),%ecx
    1607:	89 44 24 18          	mov    %eax,0x18(%esp)
    160b:	8d 44 24 38          	lea    0x38(%esp),%eax
    160f:	89 4c 24 04          	mov    %ecx,0x4(%esp)
    1613:	89 4c 24 14          	mov    %ecx,0x14(%esp)
    1617:	89 44 24 10          	mov    %eax,0x10(%esp)
    161b:	8d 74 26 00          	lea    0x0(%esi,%eiz,1),%esi
    161f:	90                   	nop
    1620:	8b 44 24 14          	mov    0x14(%esp),%eax
    1624:	83 ec 08             	sub    $0x8,%esp
    1627:	89 44 24 28          	mov    %eax,0x28(%esp)
    162b:	8b 44 24 68          	mov    0x68(%esp),%eax
    162f:	89 44 24 2c          	mov    %eax,0x2c(%esp)
    1633:	8b 45 00             	mov    0x0(%ebp),%eax
    1636:	ff 74 24 20          	pushl  0x20(%esp)
    163a:	6a 02                	push   $0x2
    163c:	ff 90 90 12 00 00    	call   *0x1290(%eax)
    1642:	83 c4 10             	add    $0x10,%esp
    1645:	85 c0                	test   %eax,%eax
    1647:	0f 84 b3 00 00 00    	je     1700 <F656c622d6669626e_elb_fibn_0+0x120>
    164d:	8b 7c 24 1c          	mov    0x1c(%esp),%edi
    1651:	8b 44 24 64          	mov    0x64(%esp),%eax
    1655:	83 ec 08             	sub    $0x8,%esp
    1658:	89 44 24 30          	mov    %eax,0x30(%esp)
    165c:	8b 47 0c             	mov    0xc(%edi),%eax
    165f:	8b 77 08             	mov    0x8(%edi),%esi
    1662:	89 44 24 34          	mov    %eax,0x34(%esp)
    1666:	8d 54 24 30          	lea    0x30(%esp),%edx
    166a:	8b 45 00             	mov    0x0(%ebp),%eax
    166d:	52                   	push   %edx
    166e:	6a 02                	push   $0x2
    1670:	ff 90 78 12 00 00    	call   *0x1278(%eax)
    1676:	8b 1f                	mov    (%edi),%ebx
    1678:	bf 06 00 00 00       	mov    $0x6,%edi
    167d:	89 44 24 18          	mov    %eax,0x18(%esp)
    1681:	83 c4 10             	add    $0x10,%esp
    1684:	8d 44 24 30          	lea    0x30(%esp),%eax
    1688:	89 44 24 0c          	mov    %eax,0xc(%esp)
    168c:	eb 32                	jmp    16c0 <F656c622d6669626e_elb_fibn_0+0xe0>
    168e:	66 90                	xchg   %ax,%ax
    1690:	89 7c 24 3c          	mov    %edi,0x3c(%esp)
    1694:	83 ec 08             	sub    $0x8,%esp
    1697:	8b 45 00             	mov    0x0(%ebp),%eax
    169a:	89 f7                	mov    %esi,%edi
    169c:	89 74 24 40          	mov    %esi,0x40(%esp)
    16a0:	ff 74 24 18          	pushl  0x18(%esp)
    16a4:	6a 02                	push   $0x2
    16a6:	ff 90 7c 12 00 00    	call   *0x127c(%eax)
    16ac:	89 44 24 14          	mov    %eax,0x14(%esp)
    16b0:	89 d8                	mov    %ebx,%eax
    16b2:	e8 89 fa ff ff       	call   1140 <add1.constprop.0>
    16b7:	8b 74 24 14          	mov    0x14(%esp),%esi
    16bb:	83 c4 10             	add    $0x10,%esp
    16be:	89 c3                	mov    %eax,%ebx
    16c0:	8b 44 24 08          	mov    0x8(%esp),%eax
    16c4:	89 5c 24 30          	mov    %ebx,0x30(%esp)
    16c8:	83 ec 08             	sub    $0x8,%esp
    16cb:	89 44 24 3c          	mov    %eax,0x3c(%esp)
    16cf:	8b 45 00             	mov    0x0(%ebp),%eax
    16d2:	ff 74 24 14          	pushl  0x14(%esp)
    16d6:	6a 02                	push   $0x2
    16d8:	ff 90 90 12 00 00    	call   *0x1290(%eax)
    16de:	83 c4 10             	add    $0x10,%esp
    16e1:	85 c0                	test   %eax,%eax
    16e3:	75 ab                	jne    1690 <F656c622d6669626e_elb_fibn_0+0xb0>
    16e5:	8b 44 24 14          	mov    0x14(%esp),%eax
    16e9:	e8 52 fa ff ff       	call   1140 <add1.constprop.0>
    16ee:	89 44 24 14          	mov    %eax,0x14(%esp)
    16f2:	e9 29 ff ff ff       	jmp    1620 <F656c622d6669626e_elb_fibn_0+0x40>
    16f7:	8d b4 26 00 00 00 00 	lea    0x0(%esi,%eiz,1),%esi
    16fe:	66 90                	xchg   %ax,%ax
    1700:	8b 44 24 04          	mov    0x4(%esp),%eax
    1704:	83 c4 4c             	add    $0x4c,%esp
    1707:	5b                   	pop    %ebx
    1708:	5e                   	pop    %esi
    1709:	5f                   	pop    %edi
    170a:	5d                   	pop    %ebp
    170b:	c3                   	ret    
    170c:	8d 74 26 00          	lea    0x0(%esi,%eiz,1),%esi


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #17: elb-fibn-entry.s --]
[-- Type: text/x-asm, Size: 1126 bytes --]

00001710 <F656c622d6669626e2d656e747279_elb_fibn_entry_0>:
    1710:	e8 20 fa ff ff       	call   1135 <__x86.get_pc_thunk.dx>
    1715:	81 c2 eb 28 00 00    	add    $0x28eb,%edx
    171b:	83 ec 24             	sub    $0x24,%esp
    171e:	8b 82 f4 ff ff ff    	mov    -0xc(%edx),%eax
    1724:	8b 48 10             	mov    0x10(%eax),%ecx
    1727:	89 4c 24 0c          	mov    %ecx,0xc(%esp)
    172b:	8b 48 14             	mov    0x14(%eax),%ecx
    172e:	8b 40 18             	mov    0x18(%eax),%eax
    1731:	89 4c 24 10          	mov    %ecx,0x10(%esp)
    1735:	89 44 24 14          	mov    %eax,0x14(%esp)
    1739:	8b 82 f8 ff ff ff    	mov    -0x8(%edx),%eax
    173f:	8d 54 24 0c          	lea    0xc(%esp),%edx
    1743:	8b 00                	mov    (%eax),%eax
    1745:	52                   	push   %edx
    1746:	6a 03                	push   $0x3
    1748:	ff 90 40 0d 00 00    	call   *0xd40(%eax)
    174e:	83 c4 2c             	add    $0x2c,%esp
    1751:	c3                   	ret    
    1752:	8d b4 26 00 00 00 00 	lea    0x0(%esi,%eiz,1),%esi
    1759:	8d b4 26 00 00 00 00 	lea    0x0(%esi,%eiz,1),%esi


^ permalink raw reply	[flat|nested] 9+ messages in thread
end of thread, other threads:[~2020-06-14 21:45 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-05-11 20:47 bug#41194: 28.0.50; [feature/native-comp] fibn benchmark exhausts memory Kévin Le Gouguec
2020-06-09 22:24 ` Andrea Corallo
2020-06-10  7:55   ` Kévin Le Gouguec
2020-06-13 15:00     ` Andrea Corallo
2020-06-13 18:17       ` Kévin Le Gouguec
2020-06-14 15:19       ` Kévin Le Gouguec
2020-06-14 16:19         ` Andrea Corallo
2020-06-14 20:47           ` Kévin Le Gouguec
2020-06-14 21:45             ` Andrea Corallo

Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/emacs.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).