greghendershott / racket-mode

Emacs major and minor modes for Racket: edit, REPL, check-syntax, debug, profile, packages, and more.
https://www.racket-mode.com/
GNU General Public License v3.0
682 stars 93 forks source link

Racket built in json module - huge performance hit printing to repl #616

Closed bhrgunatha closed 2 years ago

bhrgunatha commented 2 years ago
racket-bug-report output
((alist-get 'racket-mode package-alist)
 #s(package-desc racket-mode
                 (20220422 1410)
                 "Racket editing, REPL, and more"
                 ((emacs
                   (25 1)))
                 nil nil "/home/bhrgunatha/.emacs.d/elpa/racket-mode-20220422.1410"
                 ((:url . "https://www.racket-mode.com/")
                  (:maintainer "Greg Hendershott")
                  (:authors
                   ("Greg Hendershott"))
                  (:commit . "db8b07a634b10db56ad7bb8c914fd2b9479b2ac5"))
                 nil))
((emacs-version "28.1")
 (system-type gnu/linux)
 (x-gtk-use-system-tooltips t)
 (major-mode racket-mode)
 (racket--el-source-dir "/home/bhrgunatha/.emacs.d/elpa/racket-mode-20220422.1410/")
 (racket--rkt-source-dir "/home/bhrgunatha/.emacs.d/elpa/racket-mode-20220422.1410/racket/")
 (racket-program "racket")
 (racket-command-timeout 10)
 (racket-path-from-emacs-to-racket-function UNDEFINED)
 (racket-path-from-racket-to-emacs-function UNDEFINED)
 (racket-browse-url-function racket-browse-url-using-temporary-file)
 (racket-documentation-search-location "https://docs.racket-lang.org/search/index.html?q=%s")
 (racket-xp-after-change-refresh-delay 1)
 (racket-xp-mode-lighter
  (:eval
   (racket--xp-mode-lighter)))
 (racket-xp-highlight-unused-regexp "^[^_]")
 (racket-repl-buffer-name-function nil)
 (racket-submodules-to-run
  ((main)))
 (racket-memory-limit 8192)
 (racket-error-context medium)
 (racket-repl-history-directory "~/.emacs.d/racket-mode/")
 (racket-history-filter-regexp "\\`\\s *\\'")
 (racket-images-inline t)
 (racket-imagemagick-props nil)
 (racket-images-keep-last 100)
 (racket-images-system-viewer "display")
 (racket-pretty-print t)
 (racket-use-repl-submit-predicate nil)
 (racket-pretty-print t)
 (racket-indent-curly-as-sequence t)
 (racket-indent-sequence-depth 0)
 (racket-pretty-lambda nil)
 (racket-smart-open-bracket-enable nil)
 (racket-module-forms "\\s(\\(?:module[*+]?\\|library\\)")
 (racket-logger-config
  ((cm-accomplice . warning)
   (GC . info)
   (module-prefetch . warning)
   (optimizer . info)
   (racket/contract . error)
   (racket-mode-debugger . info)
   (sequence-specialization . info)
   (* . fatal)))
 (racket-show-functions nil))
(enabled-minor-modes
 (all-the-icons-ivy-rich-mode)
 (auto-composition-mode)
 (auto-compression-mode)
 (auto-encryption-mode)
 (auto-fill-mode)
 (auto-save-mode)
 (company-mode)
 (delete-selection-mode)
 (display-fill-column-indicator-mode)
 (display-line-numbers-mode)
 (electric-indent-mode)
 (file-name-shadow-mode)
 (font-lock-mode)
 (global-company-mode)
 (global-display-fill-column-indicator-mode)
 (global-display-line-numbers-mode)
 (global-font-lock-mode)
 (global-hl-line-mode)
 (global-so-long-mode)
 (global-undo-tree-mode)
 (hs-minor-mode)
 (ivy-mode)
 (ivy-rich-mode)
 (line-number-mode)
 (menu-bar-mode)
 (minibuffer-depth-indicate-mode)
 (mouse-wheel-mode)
 (override-global-mode)
 (paredit-mode)
 (pcre-mode)
 (pdf-occur-global-minor-mode)
 (projectile-mode)
 (racket-xp-mode)
 (rainbow-delimiters-mode)
 (semantic-minor-modes-format)
 (shell-dirtrack-mode)
 (show-paren-mode)
 (tooltip-mode)
 (transient-mark-mode)
 (undo-tree-mode)
 (which-key-mode)
 (windmove-mode)
 (window-divider-mode)
 (yas-global-mode)
 (yas-minor-mode))
(disabled-minor-modes
 (abbrev-mode)
 (all-the-icons-ibuffer-mode)
 (auto-fill-function)
 (auto-save-visited-mode)
 (blink-cursor-mode)
 (buffer-face-mode)
 (buffer-read-only)
 (button-mode)
 (cl-old-struct-compat-mode)
 (column-number-mode)
 (company-search-mode)
 (compilation-minor-mode)
 (compilation-shell-minor-mode)
 (completion-in-region-mode)
 (context-menu-mode)
 (counsel-mode)
 (dash-fontify-mode)
 (defining-kbd-macro)
 (dired-hide-details-mode)
 (display-time-mode)
 (eldoc-mode)
 (electric-layout-mode)
 (electric-quote-mode)
 (global-dash-fontify-mode)
 (global-eldoc-mode)
 (global-prettify-symbols-mode)
 (global-semantic-highlight-edits-mode)
 (global-semantic-highlight-func-mode)
 (global-semantic-show-parser-state-mode)
 (global-semantic-show-unmatched-syntax-mode)
 (global-semantic-stickyfunc-mode)
 (global-visual-line-mode)
 (hl-line-mode)
 (horizontal-scroll-bar-mode)
 (ibuffer-auto-mode)
 (image-minor-mode)
 (indent-tabs-mode)
 (isearch-mode)
 (ivy-rich-project-root-cache-mode)
 (jit-lock-debug-mode)
 (lock-file-mode)
 (next-error-follow-minor-mode)
 (overwrite-mode)
 (paragraph-indent-minor-mode)
 (pdf-cache-prefetch-minor-mode)
 (pdf-isearch-active-mode)
 (pdf-isearch-batch-mode)
 (pdf-isearch-minor-mode)
 (pdf-misc-context-menu-minor-mode)
 (pdf-misc-menu-bar-minor-mode)
 (pdf-misc-minor-mode)
 (pdf-misc-size-indication-minor-mode)
 (pdf-occur-dired-minor-mode)
 (pdf-occur-ibuffer-minor-mode)
 (pdf-view-auto-slice-minor-mode)
 (pdf-view-dark-minor-mode)
 (pdf-view-midnight-minor-mode)
 (pdf-view-printer-minor-mode)
 (pdf-view-themed-minor-mode)
 (prettify-symbols-mode)
 (racket-smart-open-bracket-mode)
 (rxt--read-pcre-mode)
 (rxt-global-mode)
 (rxt-mode)
 (semantic-highlight-edits-mode)
 (semantic-highlight-func-mode)
 (semantic-mode)
 (semantic-show-parser-state-mode)
 (semantic-show-unmatched-syntax-mode)
 (semantic-stickyfunc-mode)
 (server-mode)
 (sh-electric-here-document-mode)
 (show-smartparens-global-mode)
 (show-smartparens-mode)
 (size-indication-mode)
 (smartparens-global-mode)
 (smartparens-global-strict-mode)
 (smartparens-mode)
 (smartparens-strict-mode)
 (so-long-minor-mode)
 (tab-bar-history-mode)
 (tab-bar-mode)
 (tablist-edit-column-minor-mode)
 (tablist-minor-mode)
 (temp-buffer-resize-mode)
 (text-scale-mode)
 (tool-bar-mode)
 (undo-tree-visualizer-selection-mode)
 (unify-8859-on-decoding-mode)
 (unify-8859-on-encoding-mode)
 (url-handler-mode)
 (use-hard-newlines)
 (view-mode)
 (visible-mode)
 (visual-line-mode)
 (xref-etags-mode))
#lang racket/base
(require json)
(define n1 '#hasheq((type . "NumericLiteral") (value . 1)))
(define n2 '#hasheq((type . "NumericLiteral") (value . 1)))
(define n3 '#hasheq((type . "NumericLiteral") (value . 1)))
(time (jsexpr->string (list n1 n2 n3)))

M-x racket-run

Repl displays

cpu time: 0 real time: 0 gc time: 0
"[{\"type\":\"NumericLiteral\"

then a delay of about 8-10 seconds followed by the rest of the ouput

,\"value\":1},{\"type\":\"NumericLiteral\",\"value\":1},{\"type\":\"NumericLiteral\",\"value\":1}]"

The following

#lang racket/base
(require json)

(define v1 '#hasheq((expression . #hasheq((type . "NumericLiteral") (value . 1))) (type . "BlockStatement")))
(define v2 '#hasheq((expression . #hasheq((type . "NumericLiteral") (value . 2))) (type . "BlockStatement")))
(define v3 '#hasheq((expression . #hasheq((type . "NumericLiteral") (value . 3))) (type . "BlockStatement")))
(time (jsexpr->string (list v1 v2 v3)))

M-x racket-run

This time Repl displays

cpu time: 0 real time: 0 gc time: 0
"[{

then emacs becomes total unresponsive for about 2 or 3 minutes - I'm using a server which hits 25% (on 1 on 4 processors), but not the background racket process, just the emacs server - followed by:

\"expression\":{\"type\":\"NumericLiteral\",\"value\":1},\"type\":\"BlockStatement\"},{\"expression\":{\"type\":\"NumericLiteral\",\"value\":2},\"type\":\"BlockStatement\"},{\"expression\":{\"type\":\"NumericLiteral\",\"value\":3},\"type\":\"BlockStatement\"}]"   

Both of these execute instantaneously in DrRacket, so I feel it's probably not the json library.

Edit: I discoverd this using emacs 29 with native compilation, but to report the bug switched to the official Arch linux emacs 28.1 package - compiled without native compilation.

greghendershott commented 2 years ago

Wow! That is... very strange and surprising.

I can reproduce this, even with Emacs 25.2.

I tried setting racket-pretty-print to nil instead of t, but it still happens.

greghendershott commented 2 years ago

An even more minimal example seems to be:

#lang racket/base
"[{\"type\":\"NumericLiteral\",\"value\":1},{\"type\":\"NumericLiteral\",\"value\":1},{\"type\":\"NumericLiteral\",\"value\":1}]"
greghendershott commented 2 years ago

Ah. In the racket-repl-mode buffer, if I M-x font-lock-mode, then it displays instantly.

Same for you?

It seems to be related to font-locking ("syntax highlighting", in non-Emacs-ese :smile:) this as a Racket value.

racket-mode (edit) buffers and racket-repl-mode share a lot of font-lock code. I can't seem to produce a similar problem in a racket-mode buffer. This might be an interaction of font-lock code that works fine in such buffers, with additional font-locking that is being done in the REPL. I'll take a deeper look...

greghendershott commented 2 years ago

This seems related to a compilation-mode regexp we set, which tries to match file:line:col in error messages. It seems to be attempting to match this, taking way too long to fail.

Strengthening the pattern to require whitespace at the start would fail faster, but I'm not sure if there was some good reason I didn't use that in the pattern before. So I want to ponder this... but not too long -- this is such a nasty behavior, I'm inclined to merge something faster, even if I need to revisit this and re-fix it differently.

bhrgunatha commented 2 years ago

I confirm turning off font-lock-mode results in immediate response. Applying 0e72bed fixes the problem for me. Thanks.

greghendershott commented 2 years ago

@bhrgunatha Thanks for trying that and confirming. I'm about to merge a slightly different change, which should still work for you. (The more I looked at the regexp, the more I thought it needed to be improved in a few more ways. Then I felt like it was a good opportunity to add some unit tests around this.)