Closed Gastove closed 4 years ago
Can you do profiling in your env? https://www.gnu.org/software/emacs/manual/html_node/elisp/Profiling.html
Happy to. I'll give that a go later in the day and report back. Thanks!
Bad modline in F# Mode:
Finally got around to profiling.
I remembered Autoloads, updated to the most current versions, and ran emacs like so:
$ emacs -Q -l ~/Code/orary/elpa/dash-20200524.1947/dash-autoloads.el -l ~/Code/orary/elpa/s-20180406.808/s-autoloads.el -l ~/C
ode/orary/elpa/f-20191110.1357/f-autoloads.el -l ~/Code/orary/elpa/shrink-path-20190208.1335/shrink-path-autoloads.el -l ~/Cod
e/orary/elpa/all-the-icons-20200527.1304/all-the-icons-autoloads.el -l ~/Code/orary/elpa/memoize-20200103.2036/memoize-autoloads.el -l ~/Code/orary/elpa/doom-modeline-20200621.1350/doom-modeline-autoloads.el -L ~/Code/open-source/emacs-fsharp-mode/ -l ~/Code/open-source/emacs-fsharp-mode/fsharp-mode.el
I did the same incantation as before:
(require 'doom-modeline)
(doom-modeline-mode 1)
(require 'fsharp-mode)
Started the profiler, opened an F# buffer, let it run for twenty or thirty seconds, then generated the reports.
Memory:
- command-execute 5,923,260,906 99%
- call-interactively 5,923,258,794 99%
- byte-code 5,376,960,776 90%
- read-extended-command 5,376,322,174 90%
- completing-read 5,376,322,174 90%
- completing-read-default 5,376,322,174 90%
- read-from-minibuffer 5,376,303,876 90%
- command-execute 3,228,339,766 54%
- call-interactively 3,228,339,766 54%
- funcall-interactively 3,228,339,478 54%
- minibuffer-complete 3,228,336,358 54%
- completion-in-region 3,228,336,358 54%
- completion--in-region 3,228,336,358 54%
- #<compiled -0x1e4822082579616b> 3,228,336,358 54%
- apply 3,228,336,358 54%
- #<compiled -0x2b916bf0e8d967> 3,228,336,358 54%
- completion--in-region-1 3,228,336,358 54%
- completion--do-completion 3,228,336,358 54%
- minibuffer-completion-help 3,228,304,340 54%
- temp-buffer-window-show 3,228,268,050 54%
- display-buffer 3,228,268,050 54%
- display-buffer-at-bottom 2,691,205,678 45%
- window--display-buffer 2,148,437,460 36%
- fit-window-to-buffer 2,148,120,593 36%
- apply 2,148,120,593 36%
- doom-modeline-redisplay 2,148,109,415 36%
- redisplay 2,148,109,255 36%
+ redisplay_internal (C function) 174,683 0%
+ #<compiled -0x1dfe7d2720b1bc3a> 11,178 0%
+ #<compiled 0x4336cf9d113258c> 310,222 0%
window-parameter 2,699 0%
display-buffer-record-window 1,056 0%
+ walk-window-tree 536,973,424 9%
+ split-window-no-error 5,790,570 0%
+ display-buffer-reuse-window 537,062,372 9%
+ completion-all-completions 31,120 0%
+ temp-buffer-window-setup 2,112 0%
+ message 2,048 0%
+ completion-try-completion 27,976 0%
+ minibuffer-hide-completions 2,890 0%
+ completion--field-metadata 1,152 0%
+ self-insert-command 1,048 0%
+ redisplay_internal (C function) 115,232 0%
+ minibuffer-inactive-mode 5,026 0%
+ timer-event-handler 512 0%
+ undo-auto--undoable-change 80 0%
+ find-file-read-args 638,602 0%
+ funcall-interactively 546,298,018 9%
+ redisplay_internal (C function) 726,267 0%
+ timer-event-handler 14,304 0%
internal-timer-start-idle 2,696 0%
jit-lock--antiblink-post-command 2,400 0%
+ ... 1,218 0%
+ undo-auto--add-boundary 1,056 0%
CPU:
- command-execute 2653 91%
- call-interactively 2653 91%
- byte-code 2237 77%
- find-file-read-args 1347 46%
- read-file-name 1347 46%
- read-file-name-default 1347 46%
- completing-read 1347 46%
- completing-read-default 1347 46%
- read-from-minibuffer 1320 45%
- command-execute 1276 44%
- call-interactively 1276 44%
- funcall-interactively 1276 44%
- minibuffer-complete 1274 44%
- completion-in-region 1274 44%
- completion--in-region 1274 44%
- #<compiled -0x1e4822082579616b> 1274 44%
- apply 1274 44%
- #<compiled -0x2b916bf0e8d967> 1274 44%
- completion--in-region-1 1274 44%
- completion--do-completion 1272 43%
- minibuffer-completion-help 1254 43%
- temp-buffer-window-show 1245 43%
- display-buffer 1245 43%
- display-buffer-at-bottom 1036 35%
- window--display-buffer 826 28%
+ fit-window-to-buffer 823 28%
+ #<compiled 0x4336cf9d113258c> 3 0%
+ walk-window-tree 209 7%
+ split-window-no-error 1 0%
+ display-buffer-reuse-window 209 7%
+ completion-all-completions 8 0%
+ completion-try-completion 15 0%
+ minibuffer-hide-completions 1 0%
+ pos-visible-in-window-p 1 0%
self-insert-command 1 0%
+ redisplay_internal (C function) 5 0%
+ timer-event-handler 3 0%
+ minibuffer-inactive-mode 2 0%
+ undo-auto--add-boundary 1 0%
internal-timer-start-idle 1 0%
rfn-eshadow-update-overlay 1 0%
+ read-extended-command 890 30%
+ funcall-interactively 416 14%
+ ... 228 7%
+ redisplay_internal (C function) 11 0%
I didn't expand everything fully, just to try and keep the list shorter, but I can re-run and re-expand as needed :+1:
According to the CPU usage, it's not related to doom-modeline
. Obviously completion consumes lots of CPU resources. You should check your configurations.
@Gastove I have actually run in to this same issue as well last night. I never had the issue before, but now that I am on emacs27 doom-modeline makes fsharp buffers very slow to navigate. Deactivating the buffer position and size entries alone on the line seems to recover a lot of the normal mode cursor responsiveness. FSAC itself is definitely sower for me now than before (inserting lag), but there is definitely something funky going on between fsharp-mode and doom-modeline.
This is my current bandaid:
(add-hook 'fsharp-mode-hook '(lambda () (column-number-mode -1) (line-number-mode -1)))
The bad insert mode lag caused by the connection to fsac server continues to trouble me, but that is a separate issue. :sweat_smile:
It's wired that column and line number slow down the emacs. Can you expand the items related to doom-modeline and paste here?
It's wired that column and line number slow down the emacs. Can you expand the items related to doom-modeline and paste here?
I'm sorry I'm not quite sure what you're asking. I'll gladly provide more that might help to diagnose this weird problem. I'm curious to hear whether the same changes fix things for Gastove. Like he describes, this is only an issue in fsharp-mode for me, line-number and column-number modes don't seem to cause an issue elsewhere. The problem also seems to be present when using the doom-modeline alternative (modeline +light) which uses the same modes.
@geoffder I mean profiling and dig out the bottleneck. Refer to https://www.gnu.org/software/emacs/manual/html_node/elisp/Profiling.html.
For this profile I turned off the language server and simply moved the cursor back and forth over lines and columns. Movement was very laggy as it usually is with comlumn-number-mode and line-number-mode active.
CPU:
- redisplay_internal (C function) 13 56%
- eval 13 56%
- centaur-tabs-line 10 43%
- centaur-tabs-current-tabset 10 43%
- centaur-tabs-buffer-tabs 10 43%
- centaur-tabs-buffer-update-groups 10 43%
- cl-mapcar 10 43%
- mapcar 10 43%
- #<compiled 0x1562cda6b965> 1 4%
centaur-tabs-buffer-groups 1 4%
- doom-modeline-format--main 2 8%
- format-mode-line 2 8%
eval 2 8%
- command-execute 9 39%
- call-interactively 9 39%
- funcall-interactively 9 39%
- evil-previous-line 7 30%
- evil-line-move 7 30%
- previous-line 7 30%
- line-move 7 30%
- line-move-1 7 30%
- #<compiled 0x1562ce291fc9> 1 4%
- line-move-finish 1 4%
line-move-to-column 1 4%
- doom/toggle-profiler 1 4%
- if 1 4%
profiler-stop 1 4%
- evil-next-line 1 4%
- evil-line-move 1 4%
- next-line 1 4%
- line-move 1 4%
line-move-1 1 4%
- timer-event-handler 1 4%
- apply 1 4%
#<compiled 0x1ff2e8d5c9fd> 1 4%
- ... 0 0%
Automatic GC 0 0%
Memory:
- command-execute 4,267,299 94%
- call-interactively 4,267,299 94%
- funcall-interactively 4,267,299 94%
- doom/toggle-profiler 3,464,479 76%
- if 3,464,479 76%
profiler-report 3,463,848 76%
profiler-start 631 0%
- evil-previous-line 492,420 10%
- evil-line-move 492,420 10%
- previous-line 492,420 10%
- line-move 492,420 10%
- line-move-1 492,260 10%
- #<compiled 0x1562ce258645> 880 0%
- line-move-finish 880 0%
line-move-to-column 880 0%
- evil-next-line 310,320 6%
- evil-line-move 310,320 6%
- next-line 310,320 6%
- line-move 310,320 6%
- line-move-1 310,320 6%
- #<compiled 0x1562ce418d11> 880 0%
- line-move-finish 880 0%
line-move-to-column 880 0%
- evil-backward-char 80 0%
- evil-expand 80 0%
- apply 80 0%
- evil-transform 80 0%
- apply 80 0%
- evil-line-expand 80 0%
- evil-move-end-of-line 80 0%
- move-end-of-line 80 0%
line-move 80 0%
- redisplay_internal (C function) 257,540 5%
- eval 257,540 5%
- doom-modeline-format--main 114,430 2%
- format-mode-line 71,294 1%
- eval 71,294 1%
doom-modeline-segment--major-mode 15,294 0%
doom-modeline-segment--vcs 8,128 0%
doom-modeline-segment--checker 3,048 0%
doom-modeline-segment--debug 1,016 0%
doom-modeline-segment--buffer-position 20,292 0%
- doom-modeline-segment--buffer-info 15,964 0%
doom-modeline-update-buffer-file-state-icon 11,900 0%
doom-modeline-segment--vcs 15,300 0%
doom-modeline-segment--major-mode 15,294 0%
- doom-modeline-segment--modals 8,128 0%
- doom-modeline--modal-icon 5,080 0%
- doom-modeline-icon 3,048 0%
doom-modeline-propertize-icon 2,032 0%
- apply 1,016 0%
all-the-icons-material 1,016 0%
doom-modeline-segment--checker 3,048 0%
doom-modeline-segment--debug 2,032 0%
- flycheck-maybe-display-error-at-point-soon 3,784 0%
- flycheck-overlays-at 3,784 0%
- flycheck-filter-overlays 1,064 0%
seq-filter 1,064 0%
- timer-event-handler 80 0%
- apply 80 0%
- #<compiled 0x1562cd6e7c71> 80 0%
- lsp-ui-sideline--run 80 0%
- lsp-ui-sideline--diagnostics 80 0%
- flycheck-overlay-errors-in 80 0%
flycheck-overlays-in 80 0%
... 0 0%
Then I repeated moving back and forth around in the buffer with the modes off (though I probably moved more in around the same amount of time due to the lack of lag, so it isn't the most controlled experiment.
CPU (line-number-mode and column-number-mode off):
- command-execute 44 56%
- call-interactively 44 56%
- funcall-interactively 43 55%
- evil-previous-line 28 35%
- evil-line-move 28 35%
- previous-line 28 35%
- line-move 28 35%
line-move-1 28 35%
- evil-next-line 14 17%
- evil-line-move 14 17%
- next-line 14 17%
- line-move 14 17%
line-move-1 14 17%
- doom/toggle-profiler 1 1%
- if 1 1%
profiler-report 1 1%
- sp--save-pre-command-state 11 14%
- sp-point-in-string 10 12%
- sp--syntax-ppss 9 11%
syntax-ppss 9 11%
- redisplay_internal (C function) 9 11%
- jit-lock-function 9 11%
- jit-lock-fontify-now 9 11%
- jit-lock--run-functions 9 11%
- run-hook-wrapped 9 11%
- #<compiled 0x1562cdc38b19> 9 11%
- highlight-indent-guides--guide-region 8 10%
- font-lock-fontify-region 5 6%
- font-lock-default-fontify-region 5 6%
- font-lock-fontify-keywords-region 5 6%
- #<compiled 0x1ff2e8d292f5> 3 3%
- eval 3 3%
- prettify-symbols--compose-symbol 2 2%
- prettify-symbols-default-compose-p 2 2%
syntax-ppss 2 2%
hl-fill-column--find 1 1%
syntax-ppss 2 2%
- font-lock-fontify-region 1 1%
- font-lock-default-fontify-region 1 1%
font-lock-fontify-keywords-region 1 1%
- timer-event-handler 6 7%
- apply 6 7%
- show-paren-function 4 5%
- apply 4 5%
- ad-Advice-show-paren-function 4 5%
syntax-after 1 1%
#<compiled 0x1ff2e8d5c9fd> 2 2%
- evil-escape-pre-command-hook 2 2%
evil-escape-p 1 1%
- lsp-ui-sideline 2 2%
- run-with-idle-timer 2 2%
- timer-activate-when-idle 1 1%
- timer--activate 1 1%
timer--time-less-p 1 1%
- hl-line-highlight 1 1%
hl-line-move 1 1%
whitespace-post-command-hook 1 1%
- which-key--hide-popup 1 1%
which-key--hide-buffer-side-window 1 1%
- evil--jump-hook 1 1%
- evil-get-command-property 1 1%
- evil-has-command-property-p 1 1%
evil-get-command-properties 1 1%
- ... 0 0%
Automatic GC 0 0%
Memory (column and line modes off):
- command-execute 4,898,967 84%
- call-interactively 4,898,967 84%
- funcall-interactively 4,898,967 84%
- doom/toggle-profiler 3,795,359 65%
- if 3,795,359 65%
profiler-report 3,794,728 65%
profiler-start 631 0%
- evil-previous-line 803,080 13%
- evil-line-move 803,080 13%
- previous-line 803,080 13%
- line-move 800,968 13%
- line-move-1 799,752 13%
- #<compiled 0x1562cda8ea99> 5,976 0%
- line-move-finish 1,840 0%
line-move-to-column 1,840 0%
- evil-next-line 269,160 4%
- evil-line-move 269,160 4%
- next-line 269,160 4%
- line-move 269,160 4%
- line-move-1 269,000 4%
- #<compiled 0x1562cdf244c9> 2,000 0%
- line-move-finish 2,000 0%
line-move-to-column 2,000 0%
- evil-backward-char 8,488 0%
- evil-expand 8,488 0%
- apply 8,488 0%
- evil-transform 8,488 0%
- apply 8,488 0%
- evil-line-expand 8,488 0%
- evil-move-end-of-line 6,376 0%
- move-end-of-line 6,376 0%
- line-move 6,376 0%
line-move-1 4,136 0%
evil-concat-plists 1,056 0%
- evil-forward-char 7,304 0%
- evil-expand 7,304 0%
- apply 7,304 0%
- evil-transform 7,304 0%
- apply 7,304 0%
- evil-line-expand 3,168 0%
apply 2,112 0%
- redisplay_internal (C function) 641,601 11%
- jit-lock-function 640,545 11%
- jit-lock-fontify-now 640,545 11%
- jit-lock--run-functions 634,513 10%
- run-hook-wrapped 630,377 10%
- #<compiled 0x1562cdc38b19> 630,377 10%
- highlight-indent-guides--guide-region 409,484 7%
- font-lock-fontify-region 298,372 5%
- font-lock-default-fontify-region 298,372 5%
- font-lock-fontify-keywords-region 296,260 5%
- #<compiled 0x1ff2e8d292f5> 50,224 0%
- eval 40,720 0%
- prettify-symbols--compose-symbol 35,440 0%
- prettify-symbols-default-compose-p 7,392 0%
syntax-ppss 7,392 0%
- compose-region 4,224 0%
encode-composition-components 1,056 0%
highlight-indent-guides--column-keyword-matcher 12,408 0%
hl-fill-column--find 8,448 0%
- #<lambda 0x1173951b4> 7,168 0%
hl-todo--search 7,168 0%
- font-lock-fontify-syntactically-region 2,112 0%
syntax-ppss 1,056 0%
syntax-ppss 18,744 0%
- highlight-indent-guides--get-prev-guides 14,736 0%
highlight-indent-guides--get-guides 7,168 0%
highlight-indent-guides--calc-guides 5,040 0%
highlight-indent-guides--guide-line 3,168 0%
- font-lock-fontify-region 210,421 3%
- font-lock-default-fontify-region 210,421 3%
- font-lock-fontify-keywords-region 203,117 3%
- #<lambda 0x1173951b4> 7,360 0%
hl-todo--search 7,360 0%
hl-fill-column--find 2,176 0%
- #<compiled 0x1ff2e8d292f5> 1,056 0%
eval 1,056 0%
- font-lock-unfontify-region 5,192 0%
font-lock-default-unfontify-region 1,056 0%
- font-lock-fontify-syntactically-region 2,112 0%
syntax-ppss 2,112 0%
- run-with-timer 6,032 0%
- apply 6,032 0%
- run-at-time 6,032 0%
timer-relative-time 1,056 0%
- timer-set-time 504 0%
timer--time-setter 504 0%
- timer-activate 336 0%
- timer--activate 336 0%
timer--time-less-p 336 0%
- #<compiled 0x1ff2e8de8763> 1,056 0%
- apply 1,056 0%
- redisplay--pre-redisplay-functions 1,056 0%
- run-hook-with-args 1,056 0%
redisplay--update-region-highlight 1,056 0%
- winner-save-old-configurations 145,200 2%
- winner-remember 145,200 2%
winner-win-data 2,112 0%
- flycheck-maybe-display-error-at-point-soon 30,512 0%
- flycheck-overlays-at 29,456 0%
- flycheck-filter-overlays 17,728 0%
seq-filter 17,728 0%
- evil-normal-post-command 26,540 0%
- evil-adjust-cursor 26,540 0%
- evil-move-end-of-line 26,540 0%
- move-end-of-line 26,540 0%
- line-move 26,540 0%
line-move-1 26,540 0%
- timer-event-handler 24,248 0%
- apply 22,136 0%
- #<compiled 0x1562cdf24639> 21,080 0%
- lsp-ui-sideline--run 16,944 0%
- lsp--capability 16,544 0%
- lsp--server-capabilities 16,544 0%
- apply 16,544 0%
lsp-merge 16,544 0%
- lsp-ui-sideline--diagnostics 400 0%
- flycheck-overlay-errors-in 400 0%
flycheck-overlays-in 400 0%
- #<compiled 0x1ff2e8d5c9fd> 1,056 0%
jit-lock-context-fontify 1,056 0%
- timer-activate-when-idle 2,112 0%
- timer--activate 2,112 0%
timer--time-less-p 2,112 0%
- lsp-ui-sideline 15,664 0%
- run-with-idle-timer 7,392 0%
- timer-activate-when-idle 5,280 0%
- timer--activate 5,280 0%
timer--time-less-p 5,280 0%
- timer-set-idle-time 2,112 0%
timer--time-setter 2,112 0%
- evil-escape-pre-command-hook 15,356 0%
- evil-escape-p 15,356 0%
evil-escape--is-magit-buffer 15,356 0%
- sp--save-pre-command-state 10,472 0%
- sp-point-in-string 10,472 0%
- sp--syntax-ppss 10,472 0%
syntax-ppss 10,472 0%
- jit-lock--antiblink-post-command 5,192 0%
syntax-ppss 5,192 0%
- flycheck-popup-tip-delete-popup 3,168 0%
remove-hook 3,168 0%
- prettify-symbols--post-command-hook 2,112 0%
- #<compiled 0x1ff2e8d50b79> 1,056 0%
remove 1,056 0%
- internal-echo-keystrokes-prefix 1,056 0%
run-hook-wrapped 1,056 0%
... 0 0%
I didn't see any clue here. Only centaur-tabs-line
and evil-line-move
took lots of CPU resources.
- redisplay_internal (C function) 13 56%
- eval 13 56%
- centaur-tabs-line 10 43%
- centaur-tabs-current-tabset 10 43%
- centaur-tabs-buffer-tabs 10 43%
- centaur-tabs-buffer-update-groups 10 43%
- cl-mapcar 10 43%
- mapcar 10 43%
- #<compiled 0x1562cda6b965> 1 4%
centaur-tabs-buffer-groups 1 4%
- doom-modeline-format--main 2 8%
- format-mode-line 2 8%
eval 2 8%
- command-execute 9 39%
- call-interactively 9 39%
- funcall-interactively 9 39%
- evil-previous-line 7 30%
- evil-line-move 7 30%
- previous-line 7 30%
- line-move 7 30%
- line-move-1 7 30%
- #<compiled 0x1562ce291fc9> 1 4%
- line-move-finish 1 4%
line-move-to-column 1 4%
- doom/toggle-profiler 1 4%
- if 1 4%
profiler-stop 1 4%
- evil-next-line 1 4%
- evil-line-move 1 4%
- next-line 1 4%
- line-move 1 4%
line-move-1 1 4%
- timer-event-handler 1 4%
- apply 1 4%
#<compiled 0x1ff2e8d5c9fd> 1 4%
- ... 0 0%
Automatic GC 0 0%
Good catch, I hadn't really thought of that difference between the tests with column-number-mode and line-number-mode on and off respectively, since it didn't really make sense to me for there for centaur-tabs to be involved at all. I went ahead and tested out turning centaur-tabs-mode off, and I can confirm that it made laggy navigation AND insertion go away while in fsharp mode (with fsac server running).
It actually gets stranger, as after diving in to centaur-tabs configuration to see what part seems to be causing the trouble, I found that disabling the use of all-the-icons by centaur-tabs solved the issue. Again, this is not a problem in any other modes, so I just set the relevant option to nil in only fsharp buffers like so:
(add-hook 'fsharp-mode-hook '(lambda () (setq-local centaur-tabs-set-icons nil)))
I did notice that the icon displayed for fsharp is incorrect (it used to be as expected in the past I think, but I can't remember for sure). Image of icon displayed is attached for reference.
I guess when the centaur tab line is being redrawn, the fact that a proper fsharp icon is missing from the all-the-icons lookup, is leading to this Arch Linux looking icon being put in (which somehow is an expensive operation?).
cc @ema2159 to help on centuar-tabs
.
@geoffder I wonder if fsharp-mode spawns and/or modifies temporal buffers constantly. I've seen this problem with Lisp REPLs for example, but looking better now, I don't think this is the case since centaur-tabs-buffer-update-groups
is not being called that many times which usually happens when this type of errors occur. The icons thing is a possibility, although it may be a quite strange bug. Which icon is rendered in doom-modeline?
I had a feeling that it was something to do with the fsharp-mode causing constant changes of some kind as you suggest, but I'm not too familiar with the inner workings of a lot of this stuff yet. I don't actually have any mode related icons being rendered in my modeline, just the name of the major-mode.
I have a little update from playing around a bit since making the above fix (turning off all-the-icons in centaur-tabs for only fsharp-mode buffers). I opened up magit and began editing a commit message (thus not in an fsharp-mode buffer), the "E A" icon of course reappeared in the tab line, and with it the grindingly slow insert mode bug. So, now I am wondering whether it is an fsharp-mode interaction after all. Maybe it is just centred around this missing / stand-in icon behaviour.
I've had the same issue in F# buffers and I'm 99% it has to do with the icon. Simply turning off the major mode icon with (setq doom-modeline-major-mode-icon nil)
solves it for me.
Describe If I use
doom-modeline
andfsharp-mode
together, Emacs slows way, way down. This does not happen with other major modes, and the problem immediately vanishes when I deactivatedoom-modeline
.Steps and Expected In general, I've been delighted by
doom-modeline
-- it's sharp looking, integrates well with many things, and has, on the whole, been charming. But, recently, I went to work on an F# project and found Emacs almost unuseably slow. Debugging revealed the problem to be some interaction betweenfsharp-mode
anddoom-modeline
, but I haven't the faintest clue what it could be.I was able to reproduce this by using this
emacs -Q
:(I do apologize that that's a bit inelegant.)
Once loaded, I evaluated the following lisp:
I then opened an F# file. In particular, I noted that scrolling lines was astonishingly slow.
Environment:
Additional context Nothing leaps to mind, but I'm happy to provide any other info that might help!