bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

[Tassilo Horn]

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


I use the current Emacs master branch and the marginalia package which
adds annotations to completion, e.g., the truncated value and docstrings
of variables when completing a variable name.  When I do C-h v l
(describe-variable, starting completion with initial input "l"), Emacs
immediately gets stuck, takes 100% CPU, and will hang there
indefinitely.

I've made a C and Lisp backtrace using GDB, attached to this report.

[-- Attachment #2: gdb.txt.gz --]
[-- Type: application/gzip, Size: 12172 bytes --]

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


I've played around a bit, and the issue happens when the variable
`load-history' is annotated.  At least I get the hang and 100% CPU also
when evaluating

  (marginalia-annotate-variable "load-history")

Looking at the marginalia code, I can see no evil, and indeed I can
un-marginaliarize the sample to

    (let ((print-escape-newlines t)
          (print-escape-control-characters t)
          (print-escape-multibyte t))
      (string-width (prin1-to-string load-history)))

which freezes my emacs in the same way.  Concretely, `prin1-to-string'
finishes and returns a 1.3 MB string and then `string-width' will run
indefinitely on that.  I've attached the prin1-ed value of my
load-history.

[-- Attachment #4: load-history-prin1ed.txt.gz --]
[-- Type: application/gzip, Size: 237409 bytes --]

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


I can't reproduce that with emacs -Q where my load-history after startup
has just 139 entries rather than about 600 with my configured emacs.
For the same reason, I haven't been able to check if the problem is also
there with emacs 27 because my ~/.emacs is full of emacs 28 stuff.

Daniel, I've Cc'ed you just because you might be able to find some
workaround in marginalia.
    

In GNU Emacs 28.0.50 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.29, cairo version 1.17.4)
 of 2021-06-04 built on thinkpad-t440p
Repository revision: 7b50ed553faa6de6d51bf07d12d106ca61ab3ac4
Repository branch: master
Windowing system distributor 'The X.Org Foundation', version 11.0.12101001
System Description: Arch Linux

Configured using:
 'configure --with-modules'

Configured features:
ACL CAIRO DBUS FREETYPE GIF GLIB GMP GNUTLS GPM GSETTINGS HARFBUZZ JPEG
JSON LCMS2 LIBOTF LIBSYSTEMD LIBXML2 M17N_FLT MODULES NOTIFY INOTIFY
PDUMPER PNG RSVG SECCOMP SOUND THREADS TIFF TOOLKIT_SCROLL_BARS X11 XDBE
XIM XPM GTK3 ZLIB

Important settings:
  value of $LC_MONETARY: de_DE.utf8
  value of $LC_NUMERIC: de_DE.utf8
  value of $LC_TIME: de_DE.utf8
  value of $LANG: en_US.UTF-8
  locale-coding-system: utf-8-unix

Major mode: Text

Minor modes in effect:
  global-aggressive-indent-mode: t
  diredfl-global-mode: t
  dynamic-completion-mode: t
  which-key-mode: t
  company-posframe-mode: t
  global-company-mode: t
  yas-global-mode: t
  yas-minor-mode: t
  global-git-commit-mode: t
  magit-auto-revert-mode: t
  vertico-mode: t
  marginalia-mode: t
  override-global-mode: t
  minibuffer-depth-indicate-mode: t
  recentf-mode: t
  pixel-scroll-mode: t
  save-place-mode: t
  savehist-mode: t
  show-paren-mode: t
  shell-dirtrack-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:
~/Repos/el/mu/build/mu4e/mu4e hides ~/Repos/el/mu/mu4e/mu4e
~/Repos/el/mu/build/mu4e/mu4e-main hides ~/Repos/el/mu/mu4e/mu4e-main
~/Repos/el/mu/build/mu4e/mu4e-view hides ~/Repos/el/mu/mu4e/mu4e-view
~/Repos/el/mu/build/mu4e/mu4e-org hides ~/Repos/el/mu/mu4e/mu4e-org
~/Repos/el/mu/build/mu4e/mu4e-lists hides ~/Repos/el/mu/mu4e/mu4e-lists
~/Repos/el/mu/build/mu4e/mu4e-actions hides ~/Repos/el/mu/mu4e/mu4e-actions
~/Repos/el/mu/build/mu4e/mu4e-utils hides ~/Repos/el/mu/mu4e/mu4e-utils
~/Repos/el/mu/build/mu4e/mu4e-context hides ~/Repos/el/mu/mu4e/mu4e-context
~/Repos/el/mu/build/mu4e/mu4e-draft hides ~/Repos/el/mu/mu4e/mu4e-draft
~/Repos/el/mu/build/mu4e/mu4e-message hides ~/Repos/el/mu/mu4e/mu4e-message
~/Repos/el/mu/build/mu4e/mu4e-compose hides ~/Repos/el/mu/mu4e/mu4e-compose
~/Repos/el/mu/build/mu4e/mu4e-view-common hides ~/Repos/el/mu/mu4e/mu4e-view-common
~/Repos/el/mu/build/mu4e/mu4e-view-old hides ~/Repos/el/mu/mu4e/mu4e-view-old
~/Repos/el/mu/build/mu4e/mu4e-view-gnus hides ~/Repos/el/mu/mu4e/mu4e-view-gnus
~/Repos/el/mu/build/mu4e/mu4e-headers hides ~/Repos/el/mu/mu4e/mu4e-headers
~/Repos/el/mu/build/mu4e/mu4e-mark hides ~/Repos/el/mu/mu4e/mu4e-mark
~/Repos/el/mu/build/mu4e/mu4e-icalendar hides ~/Repos/el/mu/mu4e/mu4e-icalendar
~/Repos/el/mu/build/mu4e/mu4e-speedbar hides ~/Repos/el/mu/mu4e/mu4e-speedbar
~/Repos/el/mu/build/mu4e/mu4e-contrib hides ~/Repos/el/mu/mu4e/mu4e-contrib
~/Repos/el/mu/build/mu4e/mu4e-proc hides ~/Repos/el/mu/mu4e/mu4e-proc
~/Repos/el/mu/build/mu4e/mu4e-meta hides ~/Repos/el/mu/mu4e/mu4e-meta
~/Repos/el/mu/build/mu4e/mu4e-vars hides ~/Repos/el/mu/mu4e/mu4e-vars
/home/horn/.emacs.d/elpa/transient-20210530.2252/transient hides /home/horn/Repos/el/emacs/lisp/transient

Features:
(shadow view bs emacsbug dired-aux company-oddmuse company-keywords
company-etags etags fileloop generator xref project company-gtags
company-dabbrev-code company-dabbrev company-files company-clang
company-capf company-cmake company-semantic company-template
company-bbdb paredit vc-mtn vc-hg vc-bzr vc-src vc-sccs vc-svn vc-cvs
vc-rcs debbugs-browse display-fill-column-indicator auto-package-update
finder-inf generic yaml-mode fish-mode cargo cargo-process rust-utils
rust-mode rust-rustfmt rust-playpen rust-compile compile rust-cargo
web-mode disp-table preview-latex auto-loads tex-site hl-todo
aggressive-indent rainbow-mode vc-git vc-dir ewoc vc vc-dispatcher
epa-file diredfl dired-x mu4e-alert time ht s mu4e-icalendar
gnus-icalendar org-capture org-refile icalendar diary-lib diary-loaddefs
mu4e mu4e-org mu4e-main mu4e-view mu4e-view-gnus mu4e-view-common
mu4e-headers mu4e-compose mu4e-context mu4e-draft mu4e-actions ido
rfc2368 mu4e-mark mu4e-proc mu4e-utils doc-view jka-compr image-mode
exif mu4e-lists mu4e-message flow-fill org ob ob-tangle ob-ref ob-lob
ob-table ob-exp org-macro org-footnote org-src ob-comint org-pcomplete
org-list org-faces org-entities org-version ob-emacs-lisp ob-core
ob-eval org-table ol org-keys org-compat org-macs org-loaddefs find-func
cal-menu calendar cal-loaddefs mule-util hl-line mu4e-vars mu4e-meta
smtpmail-multi smtpmail sendmail ecomplete completion auto-dictionary
flyspell ispell tramp-smb which-key highlight-parentheses
company-restclient know-your-http-well http-status-codes http-relations
http-methods http-headers restclient company-posframe posframe company
pcase yasnippet forge-list forge-commands forge-semi forge-bitbucket
buck forge-gogs gogs forge-gitea gtea forge-gitlab glab forge-github
ghub-graphql treepy gsexp ghub let-alist gnutls forge-notify
forge-revnote forge-pullreq forge-issue forge-topic forge-post
markdown-mode color thingatpt noutline outline forge-repo forge
forge-core forge-db closql emacsql-sqlite advice emacsql
emacsql-compiler magit-submodule magit-obsolete magit-blame magit-stash
magit-reflog magit-bisect magit-push magit-pull magit-fetch magit-clone
magit-remote magit-commit magit-sequence magit-notes magit-worktree
magit-tag magit-merge magit-branch magit-reset magit-files magit-refs
magit-status magit magit-repos magit-apply magit-wip magit-log
which-func imenu magit-diff smerge-mode diff diff-mode git-commit
log-edit pcvs-util add-log magit-core magit-autorevert autorevert
filenotify magit-margin magit-transient magit-process with-editor server
magit-mode transient magit-git magit-section magit-utils crm dash
visual-filename-abbrev debbugs soap-client url-http url-auth url-gw nsm
warnings rng-xsd rng-dt rng-util xsd-regexp bug-reference vertico
marginalia use-package-bind-key bind-key easy-mmode icomplete mb-depth
use-package-diminish ace-window avy alert log4e notifications gntp rx
tramp-cache tramp-sh recentf tree-widget pixel-scroll saveplace savehist
paren smiley gnus-art mm-uu mml2015 mm-view mml-smime smime dig gnus-sum
shr kinsoku svg dom gnus-group gnus-undo gnus-start gnus-dbus dbus xml
gnus-cloud nnimap nnmail mail-source utf7 netrc nnoo gnus-spec gnus-int
gnus-range message rmc puny dired dired-loaddefs rfc822 mml mml-sec epa
derived epg epg-config mm-decode mm-bodies mm-encode mail-parse rfc2231
mailabbrev gmm-utils mailheader gnus-win gnus wid-edit nnheader
gnus-util rmail rmail-loaddefs rfc2047 rfc2045 ietf-drums
text-property-search mm-util mail-prsvr mail-utils edmacro kmacro
doom-themes-ext-org doom-themes-ext-visual-bell face-remap
doom-vibrant-theme doom-themes doom-themes-base diminish cl-extra
help-mode use-package-ensure use-package-core tramp tramp-loaddefs
trampver tramp-integration files-x tramp-compat shell pcomplete comint
ansi-color ring parse-time iso8601 time-date ls-lisp format-spec info
package browse-url url url-proxy url-privacy url-expand url-methods
url-history url-cookie url-domsuf url-util mailcap url-handlers
url-parse auth-source cl-seq eieio eieio-core cl-macs eieio-loaddefs
password-cache json subr-x map url-vars seq byte-opt gv bytecomp
byte-compile cconv cl-loaddefs cl-lib iso-transl 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 tab-bar menu-bar rfn-eshadow isearch easymenu
timer select scroll-bar mouse jit-lock font-lock syntax font-core
term/tty-colors frame minibuffer 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 cl-preloaded nadvice button
loaddefs faces cus-face macroexp files window text-properties overlay
sha1 md5 base64 format env code-pages mule custom widget
hashtable-print-readable backquote threads dbusbind inotify lcms2
dynamic-setting system-font-setting font-render-setting cairo
move-toolbar gtk x-toolkit x multi-tty make-network-process emacs)

Memory information:
((conses 16 578262 70996)
 (symbols 48 44260 10)
 (strings 32 199185 6686)
 (string-bytes 1 6028236)
 (vectors 16 77469)
 (vector-slots 8 928820 30025)
 (floats 8 689 451)
 (intervals 56 1123 364)
 (buffers 992 16))

bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

[Eli Zaretskii]

> From: Tassilo Horn <thorn@fastmail.fm>
> Date: Sat, 05 Jun 2021 00:01:59 +0200
> 
> Looking at the marginalia code, I can see no evil, and indeed I can
> un-marginaliarize the sample to
> 
>     (let ((print-escape-newlines t)
>           (print-escape-control-characters t)
>           (print-escape-multibyte t))
>       (string-width (prin1-to-string load-history)))
> 
> which freezes my emacs in the same way.  Concretely, `prin1-to-string'
> finishes and returns a 1.3 MB string and then `string-width' will run
> indefinitely on that.

string-width on the current master has a design bug, which causes it
to be VERY slow on very long strings, if those strings don't include
newlines or similar characters.  I'm working on fixing that design
bug, but meanwhile: why does marginalia need to compute the width of
such very long strings? that sounds like a design bug in marginalia.
The simplest fix is not to compute string-width of any string whose
length is greater than, say, 300 characters.  Does that help in this
case?

bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

[Tassilo Horn]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli and Daniel,

>> Looking at the marginalia code, I can see no evil, and indeed I can
>> un-marginaliarize the sample to
>> 
>>     (let ((print-escape-newlines t)
>>           (print-escape-control-characters t)
>>           (print-escape-multibyte t))
>>       (string-width (prin1-to-string load-history)))
>> 
>> which freezes my emacs in the same way.  Concretely, `prin1-to-string'
>> finishes and returns a 1.3 MB string and then `string-width' will run
>> indefinitely on that.
>
> string-width on the current master has a design bug, which causes it
> to be VERY slow on very long strings, if those strings don't include
> newlines or similar characters.  I'm working on fixing that design
> bug, but meanwhile: why does marginalia need to compute the width of
> such very long strings? that sounds like a design bug in marginalia.
> The simplest fix is not to compute string-width of any string whose
> length is greater than, say, 300 characters.  Does that help in this
> case?

Yes, with this patch I can make the issue go away with no observable
difference in the things marginalia displays.

--8<---------------cut here---------------start------------->8---
diff -u --label /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el --label \#\<buffer\ marginalia.el\> /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el /tmp/buffer-content-yqLXyF
--- /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el
+++ #<buffer marginalia.el>
@@ -450,8 +450,12 @@
      ((marginalia--symbol-class sym) :face 'marginalia-type)
      ((let ((print-escape-newlines t)
             (print-escape-control-characters t)
-            (print-escape-multibyte t))
-        (prin1-to-string (if (boundp sym) (symbol-value sym) 'unbound)))
+            (print-escape-multibyte t)
+            (str-val (prin1-to-string
+                      (if (boundp sym)
+                          (symbol-value sym)
+                        'unbound))))
+        (substring str-val 0 (min (length str-val) 300)))
       :truncate (/ marginalia-truncate-width 3) :face 'marginalia-variable)
      ((documentation-property sym 'variable-documentation)
       :truncate marginalia-truncate-width :face 'marginalia-documentation))))

Diff finished.  Sat Jun  5 10:09:24 2021
--8<---------------cut here---------------end--------------->8---

Bye,
Tassilo

bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

[Tassilo Horn]

> Yes, with this patch I can make the issue go away with no observable
> difference in the things marginalia displays.
>
> diff -u --label /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el --label \#\<buffer\ marginalia.el\> /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el /tmp/buffer-content-yqLXyF
> --- /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el
> +++ #<buffer marginalia.el>
> @@ -450,8 +450,12 @@
>       ((marginalia--symbol-class sym) :face 'marginalia-type)
>       ((let ((print-escape-newlines t)
          ^^^
Ah, sorry, this ought to become a `let*' now.

>              (print-escape-control-characters t)
> -            (print-escape-multibyte t))
> -        (prin1-to-string (if (boundp sym) (symbol-value sym) 'unbound)))
> +            (print-escape-multibyte t)
> +            (str-val (prin1-to-string
> +                      (if (boundp sym)
> +                          (symbol-value sym)
> +                        'unbound))))
> +        (substring str-val 0 (min (length str-val) 300)))
>        :truncate (/ marginalia-truncate-width 3) :face 'marginalia-variable)
>       ((documentation-property sym 'variable-documentation)
>        :truncate marginalia-truncate-width :face 'marginalia-documentation))))

Bye,
Tassilo

bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

[Eli Zaretskii]

> From: Tassilo Horn <thorn@fastmail.fm>
> Cc: 48839@debbugs.gnu.org, mail@daniel-mendler.de
> Date: Sat, 05 Jun 2021 10:11:28 +0200
> 
> > string-width on the current master has a design bug, which causes it
> > to be VERY slow on very long strings, if those strings don't include
> > newlines or similar characters.  I'm working on fixing that design
> > bug, but meanwhile: why does marginalia need to compute the width of
> > such very long strings? that sounds like a design bug in marginalia.
> > The simplest fix is not to compute string-width of any string whose
> > length is greater than, say, 300 characters.  Does that help in this
> > case?
> 
> Yes, with this patch I can make the issue go away with no observable
> difference in the things marginalia displays.
> 
> --8<---------------cut here---------------start------------->8---
> diff -u --label /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el --label \#\<buffer\ marginalia.el\> /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el /tmp/buffer-content-yqLXyF
> --- /home/horn/.emacs.d/elpa/marginalia-20210530.158/marginalia.el
> +++ #<buffer marginalia.el>
> @@ -450,8 +450,12 @@
>       ((marginalia--symbol-class sym) :face 'marginalia-type)
>       ((let ((print-escape-newlines t)
>              (print-escape-control-characters t)
> -            (print-escape-multibyte t))
> -        (prin1-to-string (if (boundp sym) (symbol-value sym) 'unbound)))
> +            (print-escape-multibyte t)
> +            (str-val (prin1-to-string
> +                      (if (boundp sym)
> +                          (symbol-value sym)
> +                        'unbound))))
> +        (substring str-val 0 (min (length str-val) 300)))

Great, thanks.  (An alternative is to use the result of 'length' for
strings longer than 300 characters, or map 'char-width' on its
characters, adding the results.)

I will work on fixing string-width.

bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

[Eli Zaretskii]

> Date: Sat, 05 Jun 2021 11:39:16 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: mail@daniel-mendler.de, 48839@debbugs.gnu.org, Tassilo Horn <tsdh@gnu.org>
> I will work on fixing string-width.

Now done, please test.

bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

[Tassilo Horn]

Eli Zaretskii <eliz@gnu.org> writes:

>> Date: Sat, 05 Jun 2021 11:39:16 +0300
>> From: Eli Zaretskii <eliz@gnu.org>
>> Cc: mail@daniel-mendler.de, 48839@debbugs.gnu.org, Tassilo Horn <tsdh@gnu.org>
>> I will work on fixing string-width.
>
> Now done, please test.

Yes, works!

--8<---------------cut here---------------start------------->8---
(benchmark 100
           '(let ((print-escape-newlines t)
                  (print-escape-control-characters t)
                  (print-escape-multibyte t))
              (string-width (prin1-to-string load-history))))
;; "Elapsed time: 36.960925s (7.817438s in 100 GCs)"
--8<---------------cut here---------------end--------------->8---

Thanks for the quick fix.  Daniel also added a workaround (which is
probably still sensible even with your fix) to marginalia.

Bye,
Tassilo

bug#48839: 28.0.50; Emacs freezes and takes 100% CPU with C-h v l

[Eli Zaretskii]

> From: Tassilo Horn <tsdh@gnu.org>
> Cc: mail@daniel-mendler.de, 48839@debbugs.gnu.org
> Date: Sat, 05 Jun 2021 14:07:22 +0200
> 
> > Now done, please test.
> 
> Yes, works!
> 
> --8<---------------cut here---------------start------------->8---
> (benchmark 100
>            '(let ((print-escape-newlines t)
>                   (print-escape-control-characters t)
>                   (print-escape-multibyte t))
>               (string-width (prin1-to-string load-history))))
> ;; "Elapsed time: 36.960925s (7.817438s in 100 GCs)"
> --8<---------------cut here---------------end--------------->8---
> 
> Thanks for the quick fix.  Daniel also added a workaround (which is
> probably still sensible even with your fix) to marginalia.

Thanks for testing, I'm therefore closing this bug.