bug#34809: 27.0.50; Too small number of samples in (benchmark-run-compiled …)

bug#34809: 27.0.50; Too small number of samples in (benchmark-run-compiled …)

[Konstantin Kharlamov]

Result of (benchmark-run-compiled …) has suspiciously unevenly
distributed numbers. E.g. it might give all 100% to garbage collector,
as if no other code was ran. This was found as part of thread about slow
lexical-binding, and I was asked to report it.¹

1: http://lists.gnu.org/archive/html/help-gnu-emacs/2019-03/msg00056.html

# Steps to reproduce (in terms of terminal commands):
     1. wget 
https://gitlab.freedesktop.org/libinput/libinput/raw/9a2d6f55b1276da11dd9b2c4c8e22a405576dfea/src/libinput.h
     2. emacs -Q --eval "(progn (find-file \"./libinput.h\")
(profiler-start 'cpu) (benchmark-run-compiled 10
(c-font-lock-fontify-region 0 (point-max))) (profiler-report))"

## Expected:
    Some of percentages should be inside cc-mode code.

## Actual:
     - ...           1 100%
        Automatic GC 1 100%

---------------

In GNU Emacs 27.0.50 (build 7, x86_64-pc-linux-gnu, GTK+ Version 3.24.3)
  of 2019-02-18 built on constantine-N61Ja
Repository revision: e6f8ddbb3b8f99c73b2be66bb1e691d4757c3b12
Repository branch: master
Windowing system distributor 'The X.Org Foundation', version 11.0.12003000
System Description: Arch Linux

Recent messages:
Wrote /tmp/test.sh
Quit
Mark saved where search started [2 times]
Quit [2 times]
Mark saved where search started [6 times]
Saving file /home/constantine/Projects/geary/meson.build...
Wrote /home/constantine/Projects/geary/meson.build
Saving file /home/constantine/Projects/geary/meson.build...
Wrote /home/constantine/Projects/geary/meson.build
Unable to load color "" [4 times]

Configured using:
  'configure --prefix=/usr --sysconfdir=/etc --libexecdir=/usr/lib
  --localstatedir=/var --mandir=/usr/share/man --with-gameuser=:games
  --with-sound=alsa --with-xft --with-modules
  --enable-link-time-optimization --with-x-toolkit=gtk3 --without-gconf
  --without-gsettings --without-gpm --without-m17n-flt --with-xwidgets
  --without-compress-install 'CFLAGS=-march=native -O3 -pipe
  -fno-stack-protector -fweb -fno-semantic-interposition
  -fmerge-all-constants -floop-nest-optimize -ftree-vectorize'
  LDFLAGS=-Wl,-O3,--sort-common,--as-needed,-z,relro'

Configured features:
XPM JPEG TIFF GIF PNG RSVG IMAGEMAGICK SOUND DBUS GLIB NOTIFY INOTIFY
ACL GNUTLS LIBXML2 FREETYPE LIBOTF XFT ZLIB TOOLKIT_SCROLL_BARS GTK3 X11
XDBE XIM MODULES THREADS XWIDGETS LIBSYSTEMD JSON PDUMPER LCMS2 GMP

Important settings:
   value of $LC_TIME: ru_RU.UTF-8
   value of $LANG: ru_RU.UTF-8
   value of $XMODIFIERS: @im=none
   locale-coding-system: utf-8-unix

Major mode: Meson

Minor modes in effect:
   diff-auto-refine-mode: t
   delete-selection-mode: t
   highlight-numbers-mode: t
   global-color-identifiers-mode: t
   winum-mode: t
   global-highlight-symbol-mode: t
   highlight-symbol-mode: t
   global-highlight-parentheses-mode: t
   highlight-parentheses-mode: t
   smartparens-global-mode: t
   smartparens-mode: t
   yas-global-mode: t
   yas-minor-mode: t
   global-company-mode: t
   company-mode: t
   global-semanticdb-minor-mode: t
   global-semantic-idle-scheduler-mode: t
   semantic-mode: t
   global-evil-surround-mode: t
   evil-surround-mode: t
   global-undo-tree-mode: t
   undo-tree-mode: t
   shell-dirtrack-mode: t
   evil-mode: t
   evil-local-mode: t
   show-paren-mode: t
   tooltip-mode: t
   global-eldoc-mode: t
   electric-indent-mode: t
   mouse-wheel-mode: t
   file-name-shadow-mode: t
   global-font-lock-mode: t
   font-lock-mode: t
   blink-cursor-mode: t
   auto-composition-mode: t
   auto-encryption-mode: t
   auto-compression-mode: t
   column-number-mode: t
   line-number-mode: t
   transient-mark-mode: t

Load-path shadows:
/home/constantine/.emacs.d/lisp/idomenu hides 
/home/constantine/.emacs.d/elpa/idomenu-20141123.1320/idomenu
/home/constantine/.emacs.d/lisp/auto-complete-config hides 
/home/constantine/.emacs.d/elpa/auto-complete-20170124.1845/auto-complete-config
/home/constantine/.emacs.d/lisp/popup hides 
/home/constantine/.emacs.d/elpa/popup-20160709.729/popup
/home/constantine/.emacs.d/elpa/cmake-mode-20160928.505/cmake-mode hides 
/usr/share/emacs/site-lisp/cmake-mode

Features:
(shadow mail-extr emacsbug message rmc puny rfc822 mml mml-sec epa epg
gnus-util rmail rmail-loaddefs mm-decode mm-bodies mm-encode mail-parse
rfc2231 mailabbrev gmm-utils mailheader sendmail rfc2047 rfc2045
ietf-drums mm-util mail-prsvr mail-utils emms-source-file locate emms
emms-compat completion dos-w32 find-cmd grep find-dired quail po
semantic/ia semantic/senator semantic/bovine/make
semantic/decorate/include semantic/bovine/make-by make-mode sort
smerge-mode omnisharp omnisharp-server-installation
omnisharp-format-actions omnisharp-solution-actions
omnisharp-helm-integration helm-grep helm-regexp helm-utils helm-help
helm helm-source eieio-compat helm-multi-match helm-lib async
omnisharp-settings omnisharp-navigation-actions
omnisharp-current-symbol-actions omnisharp-auto-complete-actions
omnisharp-server-actions omnisharp-http-utils omnisharp-utils
omnisharp-server-management f shut-up s popup dired dired-loaddefs
flycheck-haskell haskell-cabal haskell-utils flycheck-irony
irony-diagnostics irony irony-iotask csharp-mode vc vc-dispatcher
meson-mode sh-script smie executable warnings rng-xsd xsd-regexp
rng-cmpct rng-nxml rng-valid rng-loc rng-uri rng-parse nxml-parse
rng-match rng-dt rng-util rng-pttrn nxml-ns nxml-mode nxml-outln
nxml-rap smartparens-html sgml-mode dom nxml-util nxml-enc xmltok align
dabbrev tabify cua-base time-date benchmark debug backtrace
semantic/tag-write semantic/analyze/complete semantic/db-typecache
semantic/edit profiler semantic/decorate/mode semantic/decorate pulse
macrostep-c cmacexp macrostep pp disass cl-print misearch multi-isearch
derived cc-langs cc-bytecomp compile vc-git diff-mode eieio-opt speedbar
sb-image dframe face-remap semantic/tag-file semantic/bovine/c hideif
cc-mode cc-fonts cc-guess cc-menus cc-cmds cc-styles cc-align cc-engine
cc-vars cc-defs semantic/bovine/c-by semantic/lex-spp
semantic/bovine/gcc semantic/dep semantic/bovine semantic/analyze/refs
semantic/db-find semantic/db-ref semantic/analyze semantic/sort
semantic/scope semantic/analyze/fcn semantic/db-ebrowse semantic/db-file
data-debug cedet-files ebrowse ebuff-menu view help-fns radix-tree
company-c-headers delsel highlight-numbers parent-mode
color-identifiers-mode smartparens-python python tramp-sh tramp
tramp-loaddefs trampver tramp-compat ucs-normalize parse-time
format-spec winum smartparens-markdown markdown-mode color noutline
outline highlight-symbol easy-mmode cl highlight-parentheses
sp-sublimelike smartparens-config smartparens-text smartparens idomenu
imenu smex ido emvil yasnippet-snippets yasnippet elec-pair
company-oddmuse company-keywords company-etags etags fileloop generator
xref project company-gtags company-dabbrev-code company-dabbrev
company-files company-capf company-cmake company-xcode company-clang
company-semantic company-eclim company-template company-bbdb company
pcase semantic/db-mode semantic/db eieio-base semantic/idle
semantic/format ezimage semantic/tag-ls semantic/find semantic/ctxt
semantic/util-modes semantic/util semantic semantic/tag semantic/lex
semantic/fw mode-local cedet evil-surround evil evil-integration
undo-tree diff evil-maps evil-commands flyspell ispell evil-jumps
evil-command-window evil-types evil-search evil-ex shell pcomplete
comint ansi-color evil-macros evil-repeat evil-states evil-core advice
evil-common windmove thingatpt rect evil-digraphs evil-vars ring edmacro
kmacro flycheck cl-extra find-func help-mode rx subr-x dash paren
xfrp_find_replace_pairs mule-util slime-autoloads info package easymenu
epg-config url-handlers url-parse auth-source cl-seq eieio eieio-core
cl-macs eieio-loaddefs password-cache json map url-vars seq byte-opt gv
bytecomp byte-compile cconv cl-loaddefs cl-lib cyril-util tooltip eldoc
electric uniquify ediff-hook vc-hooks lisp-float-type mwheel term/x-win
x-win term/common-win x-dnd tool-bar dnd fontset image regexp-opt fringe
tabulated-list replace newcomment text-mode elisp-mode lisp-mode
prog-mode register page menu-bar rfn-eshadow isearch timer select
scroll-bar mouse jit-lock font-lock syntax facemenu font-core
term/tty-colors frame cl-generic cham georgian utf-8-lang misc-lang
vietnamese tibetan thai tai-viet lao korean japanese eucjp-ms cp51932
hebrew greek romanian slovak czech european ethiopic indian cyrillic
chinese composite charscript charprop case-table epa-hook jka-cmpr-hook
help simple abbrev obarray minibuffer cl-preloaded nadvice loaddefs
button faces cus-face macroexp files text-properties overlay sha1 md5
base64 format env code-pages mule custom widget hashtable-print-readable
backquote threads dbusbind inotify lcms2 dynamic-setting
font-render-setting xwidget-internal move-toolbar gtk x-toolkit x
multi-tty make-network-process emacs)

Memory information:
((conses 16 1633368 479628)
  (symbols 48 39156 1)
  (strings 32 274763 56100)
  (string-bytes 1 6430133)
  (vectors 16 136848)
  (vector-slots 8 2305379 286688)
  (floats 8 345 1563)
  (intervals 56 35311 106)
  (buffers 992 63))

bug#34809: 27.0.50; Too small number of samples in (benchmark-run-compiled …)

[Glenn Morris]

What Linux kernel version?

See https://debbugs.gnu.org/34235 and etc/PROBLEMS.

bug#34809: 27.0.50; Too small number of samples in (benchmark-run-compiled …)

[Konstantin Kharlamov]

Thanks, updating to linux 5.0 fixes the problem!

On Пн, Mar 11, 2019 at 02:24:23, Glenn Morris <rgm@gnu.org> wrote:
> 
> What Linux kernel version?
> 
> See https://debbugs.gnu.org/34235 and etc/PROBLEMS.

bug#34809: 27.0.50; Too small number of samples in (benchmark-run-compiled …)

[Eli Zaretskii]

> From: Konstantin Kharlamov <hi-angel@yandex.ru>
> Date: Mon, 11 Mar 2019 00:19:45 +0300
> 
> Result of (benchmark-run-compiled …) has suspiciously unevenly
> distributed numbers. E.g. it might give all 100% to garbage collector,
> as if no other code was ran. This was found as part of thread about slow
> lexical-binding, and I was asked to report it.¹
> 
> 1: http://lists.gnu.org/archive/html/help-gnu-emacs/2019-03/msg00056.html
> 
> # Steps to reproduce (in terms of terminal commands):
>      1. wget 
> https://gitlab.freedesktop.org/libinput/libinput/raw/9a2d6f55b1276da11dd9b2c4c8e22a405576dfea/src/libinput.h
>      2. emacs -Q --eval "(progn (find-file \"./libinput.h\")
> (profiler-start 'cpu) (benchmark-run-compiled 10
> (c-font-lock-fontify-region 0 (point-max))) (profiler-report))"
> 
> ## Expected:
>     Some of percentages should be inside cc-mode code.
> 
> ## Actual:
>      - ...           1 100%
>         Automatic GC 1 100%

Not reproducible on my system (I get a reasonable profile, with over
100 lines, which points to font-lock-fontify-keywords-region and
c-find-decl-spots as two likely bottlenecks).

So I think Glenn is right, and this has something to do with your
kernel.

bug#34809: 27.0.50; Too small number of samples in (benchmark-run-compiled …)

[Konstantin Kharlamov]

Thanks for testing! The bug can be closed since, as I mentioned in 
prev. mail, updating to kernel 5.0 fixes it.

В Пн, мар 11, 2019 at 9:20 ПП (PM), Eli Zaretskii 
<eliz@gnu.org> написал:
>>  From: Konstantin Kharlamov <hi-angel@yandex.ru>
>>  Date: Mon, 11 Mar 2019 00:19:45 +0300
>> 
>>  Result of (benchmark-run-compiled …) has suspiciously unevenly
>>  distributed numbers. E.g. it might give all 100% to garbage 
>> collector,
>>  as if no other code was ran. This was found as part of thread about 
>> slow
>>  lexical-binding, and I was asked to report it.¹
>> 
>>  1: 
>> http://lists.gnu.org/archive/html/help-gnu-emacs/2019-03/msg00056.html
>> 
>>  # Steps to reproduce (in terms of terminal commands):
>>       1. wget
>>  
>> https://gitlab.freedesktop.org/libinput/libinput/raw/9a2d6f55b1276da11dd9b2c4c8e22a405576dfea/src/libinput.h
>>       2. emacs -Q --eval "(progn (find-file \"./libinput.h\")
>>  (profiler-start 'cpu) (benchmark-run-compiled 10
>>  (c-font-lock-fontify-region 0 (point-max))) (profiler-report))"
>> 
>>  ## Expected:
>>      Some of percentages should be inside cc-mode code.
>> 
>>  ## Actual:
>>       - ...           1 100%
>>          Automatic GC 1 100%
> 
> Not reproducible on my system (I get a reasonable profile, with over
> 100 lines, which points to font-lock-fontify-keywords-region and
> c-find-decl-spots as two likely bottlenecks).
> 
> So I think Glenn is right, and this has something to do with your
> kernel.