Closed Ptival closed 6 years ago
hlissner
commented
6 years ago @Ptival Try profiling it. Run M-x doom/toggle-profiler, then enter insert mode, and run M-x doom/toggle-profiler again to invoke a report. Please expand everything in the result and post it here.
Ptival
commented
6 years ago So, it might be a different beast per language. In nix files, it seems to only happen the first time, or after long pauses?
Here is a report on a .nix file:
- timer-event-handler 25,148,510 67%
- apply 25,148,510 67%
- company-idle-begin 24,504,052 65%
- company-auto-begin 24,504,052 65%
- company--perform 24,504,052 65%
- company--begin-new 24,504,052 65%
- company--maybe-init-backend 24,502,996 65%
- company-init-backend 24,502,996 65%
- company-nixos-options 24,481,500 65%
- byte-code 24,466,814 65%
- require 24,372,610 65%
+ defvar 24,329,340 65%
+ do-after-load-evaluation 29,650 0%
+ file-truename 9,388 0%
+ file-truename 9,446 0%
+ do-after-load-evaluation 2,112 0%
+ substitute-env-in-file-name 1,024 0%
+ company-calculate-candidates 1,056 0%
- doom-load-packages-incrementally 579,220 1%
+ if 579,220 1%
+ flycheck--handle-idle-change-in-buffer 65,238 0%
- command-execute 11,964,716 32%
- call-interactively 11,964,716 32%
- funcall-interactively 11,964,716 32%
- doom/toggle-profiler 6,566,935 17%
+ if 6,566,935 17%
- evil-normal-state 4,554,881 12%
+ redisplay 4,530,941 12%
+ evil-normalize-keymaps 16,620 0%
+ evil-change-state 4,152 0%
evil-refresh-cursor 2,112 0%
+ evil-refresh-mode-line 1,056 0%
+ self-insert-command 834,732 2%
+ evil-insert 1,024 0%
+ redisplay_internal (C function) 89,200 0%
+ evil-escape-pre-command-hook 16,384 0%
+ flycheck-handle-signal 7,496 0%
+ company-post-command 5,280 0%
+ flycheck-display-error-at-point-soon 3,560 0%
sp--save-pre-command-state 1,056 0%
+ +syntax-checker-cleanup-popup 1,056 0%
... 0 0%It seems it was the bootup of company-mode maybe?
Now testing on my Haskell files:
- command-execute 13,323,345 84%
- call-interactively 13,323,345 84%
- funcall-interactively 13,323,345 84%
- doom/toggle-profiler 11,117,876 70%
- if 11,117,876 70%
- profiler-report 11,117,876 70%
- profiler-report-cpu 9,222,580 58%
- profiler-report-profile-other-window 7,327,284 46%
- switch-to-buffer-other-window 7,130,347 44%
- pop-to-buffer 7,130,347 44%
- apply 7,130,347 44%
- doom*switch-buffer-hooks 7,130,347 44%
- if 7,130,347 44%
- let 7,130,347 44%
- prog1 7,130,347 44%
- apply 7,130,347 44%
- #<compiled 0x22fe1f> 7,130,347 44%
- display-buffer 7,128,235 44%
- apply 7,128,235 44%
- doom*switch-buffer-hooks 7,128,235 44%
- if 7,128,235 44%
- apply 7,128,235 44%
- #<compiled 0x22fa07> 7,128,235 44%
- +popup-buffer 7,098,483 44%
- let* 7,098,483 44%
- let* 7,097,427 44%
- and 4,505,940 28%
- let* 4,505,940 28%
- while 4,505,940 28%
- and 4,505,940 28%
- progn 4,505,940 28%
- let 4,505,940 28%
- funcall 4,505,940 28%
- +popup-display-buffer-stacked-side-window 4,505,940 28%
- let* 4,505,940 28%
- let* 4,504,884 28%
- cond 4,504,884 28%
- let* 4,504,884 28%
- unwind-protect 4,504,884 28%
- progn 4,504,884 28%
- let* 4,504,884 28%
- and 4,504,884 28%
- window--make-major-side-window 4,504,884 28%
+ split-window-no-error 2,262,450 14%
+ window--display-buffer 2,242,434 14%
+ if 2,591,487 16%
+ +popup--normalize-alist 1,056 0%
display-buffer-assq-regexp 28,696 0%
+ select-window 2,112 0%
+ profiler-report-setup-buffer 196,937 1%
profiler-cpu-profile 1,895,296 11%
+ profiler-report-memory 1,895,296 11%
+ self-insert-command 1,844,292 11%
+ evil-normal-state 301,143 1%
+ haskell-indentation-newline-and-indent 51,706 0%
+ evil-append-line 1,104 0%
- #<compiled 0x17fa8f1> 1,366,344 8%
+ intero-read-buffer 1,356,736 8%
+ +modeline--set-+modeline-buffer-state 7,392 0%
+ timer-event-handler 902,812 5%
+ redisplay_internal (C function) 221,438 1%
+ evil-escape-pre-command-hook 17,408 0%
+ eldoc-pre-command-refresh-echo-area 12,512 0%
+ flycheck-display-error-at-point-soon 5,576 0%
+ company-post-command 3,168 0%
+ sp--save-pre-command-state 2,112 0%
+ ... 2,104 0%
+ global-font-lock-mode-check-buffers 1,056 0%
+ global-flycheck-mode-check-buffers 1,056 0%
+ +syntax-checker-cleanup-popup 1,056 0%Another:
- command-execute 11,836,763 67%
- call-interactively 11,835,715 67%
- funcall-interactively 11,835,715 67%
- doom/toggle-profiler 6,095,520 34%
- if 6,095,520 34%
- profiler-report 6,095,520 34%
+ profiler-report-cpu 4,200,224 24%
+ profiler-report-memory 1,895,296 10%
- evil-normal-state 4,842,955 27%
+ redisplay 4,580,955 26%
+ evil-change-state 253,812 1%
+ evil-normalize-keymaps 8,188 0%
+ self-insert-command 872,092 4%
+ evil-append-line 18,780 0%
- timer-event-handler 4,709,020 26%
- apply 4,707,964 26%
- company-idle-begin 4,257,070 24%
- company-auto-begin 3,919,653 22%
- company--perform 3,919,653 22%
- company--begin-new 3,919,653 22%
- company--multi-backend-adapter 3,806,605 21%
- company--force-sync 3,806,605 21%
- apply 3,806,605 21%
- company-capf 3,804,557 21%
- company--capf-data 3,804,557 21%
- company--capf-data-real 3,804,557 21%
- run-hook-wrapped 3,804,557 21%
- completion--capf-wrapper 3,804,557 21%
- intero-completion-at-point 3,804,557 21%
- intero-blocking-call 3,777,917 21%
- sleep-for 2,368,467 13%
+ #<compiled 0x1af7711> 1,525,654 8%
+ timer-event-handler 454,468 2%
+ intero-network-call-sentinel 383,065 2%
+ internal-default-process-filter 4,224 0%
+ intero-async-call 53,706 0%
+ intero-buffer 25,184 0%
+ intero-completions-grab-prefix 17,440 0%
+ intero-completion-response-to-list 7,200 0%
+ company-yasnippet 2,048 0%
+ company-calculate-candidates 111,992 0%
+ company-post-command 337,417 1%
+ flycheck--handle-idle-change-in-buffer 405,317 2%
+ #<compiled 0x280c27> 43,465 0%
+ show-paren-function 1,056 0%
jit-lock-context-fontify 1,056 0%
+ timer-activate-when-idle 1,056 0%
+ #<compiled 0x1af7711> 370,763 2%
+ redisplay_internal (C function) 267,812 1%
+ company-post-command 167,375 0%
+ intero-network-call-sentinel 77,887 0%
+ evil-escape-pre-command-hook 10,240 0%
+ ... 8,188 0%
+ evil-repeat-post-hook 2,112 0%
+ +modeline|update-on-change 2,112 0%
+ flycheck-display-error-at-point-soon 2,024 0%
+ global-eldoc-mode-check-buffers 1,056 0%
+ sp--save-pre-command-state 1,056 0%
+ hl-line-highlight 1,056 0%
+ global-undo-tree-mode-check-buffers 1,056 0%
+ eldoc-schedule-timer 1,056 0%
+ evil-snipe-mode-check-buffers 1,056 0%- command-execute 20,626,861 52%
- call-interactively 20,626,861 52%
- funcall-interactively 20,626,861 52%
+ doom/toggle-profiler 15,944,470 40%
+ self-insert-command 2,944,080 7%
+ evil-normal-state 1,272,791 3%
+ haskell-indentation-newline-and-indent 426,592 1%
+ evil-append-line 19,992 0%
+ evil-paste-after 12,600 0%
+ evil-backward-char 1,136 0%
- timer-event-handler 15,161,223 38%
- apply 15,153,831 38%
- company-idle-begin 13,080,060 33%
- company-auto-begin 11,431,700 28%
- company--perform 11,431,700 28%
- company--begin-new 11,431,700 28%
- company--multi-backend-adapter 11,390,052 28%
- company--force-sync 11,388,996 28%
- apply 11,388,996 28%
- company-capf 11,383,876 28%
- company--capf-data 11,382,820 28%
- company--capf-data-real 11,382,820 28%
- run-hook-wrapped 11,382,820 28%
- completion--capf-wrapper 11,382,820 28%
- intero-completion-at-point 11,382,820 28%
- intero-blocking-call 10,834,020 27%
- sleep-for 8,767,998 22%
- #<compiled 0x1af7711> 8,495,362 21%
- intero-read-buffer 8,274,926 20%
- #<compiled 0x1ae9dd1> 8,206,775 20%
+ intero-collect-compiler-messages 7,089,273 17%
+ #<compiled 0x1e75235> 740,172 1%
+ intero-parse-errors-warnings-splices 94,673 0%
+ intero-async-call 89,178 0%
replace-regexp-in-string 3,072 0%
+ intero-strip-carriage-returns 34,832 0%
generate-new-buffer 21,215 0%
intero-inherit-local-variables 1,056 0%
+modeline--set-+modeline-buffer-state 1,056 0%
#<compiled 0x1fa250d> 1,056 0%
+ +modeline--set-+modeline-buffer-state 99,264 0%
+ intero-network-call-sentinel 169,041 0%
internal-default-process-filter 1,016 0%
+ intero-async-call 198,776 0%
+ intero-buffer 123,562 0%
+ intero-completion-response-to-list 479,016 1%
+ intero-completions-grab-prefix 62,784 0%
+ company-yasnippet 5,120 0%
+ cl-delete-if 1,056 0%
+ company-calculate-candidates 39,536 0%
+ company-update-candidates 1,056 0%
+ company-post-command 1,648,360 4%
+ company-echo-show 1,650,063 4%
+ flycheck--handle-idle-change-in-buffer 410,332 1%
+ auto-revert-buffers 12,320 0%
jit-lock-context-fontify 1,056 0%
+ timer-activate-when-idle 6,336 0%
+ timer-inc-time 1,056 0%
+ redisplay_internal (C function) 1,796,832 4%
+ #<compiled 0x1af7711> 1,500,770 3%
+ company-post-command 348,459 0%
+ winner-save-old-configurations 59,752 0%
+ evil-escape-pre-command-hook 27,648 0%
+ flycheck-perform-deferred-syntax-check 20,676 0%
+ flycheck-display-error-at-point-soon 8,000 0%
+ sp--save-pre-command-state 4,224 0%
+ +syntax-checker-cleanup-popup 3,168 0%
+ eldoc-schedule-timer 2,112 0%
+ evil-repeat-post-hook 2,112 0%
+ +modeline|update-on-change 2,112 0%
+ ... 1,056 0%
+ evil-snipe-mode-check-buffers 1,056 0%
+ global-undo-tree-mode-check-buffers 1,056 0%
+ evil-repeat-pre-hook 1,048 0%Maybe it's just the company modes for those that are slow to start up? But it's annoying that they slow down multiple times a session! :-(
hlissner
commented
6 years ago Ah, my bad. Use SPC h p to toggle doom/toggle-profiler. Doing so via the keybind will prevent the profiler from tracking all the work done to display the minibuffer/ivy/helm when you press M-x, which adds a lot of noise to the results.
Could you also include your M-x doom/info?
Ptival
commented
6 years ago Hmmm, honestly at this point I feel like it's not Doom's fault.
It seems that on the Haskell side, it's intero-blocking-call that is very slow very often.
On the LaTeX and Nix sides, I'm not sure, but I feel like it's their respective plug-ins having inefficiencies.
I'll close this until I have more evidence that there is a Doom-related problem.
Thanks for the help with profiler commands!
Hey, I'm not sure how to best describe this, and I initially thought it was a slowdown in intero since I was mostly doing Haskell, but now I've also noticed it in latex-mode and in nix-mode so I believe the problem may be elsewhere.
Every time I enter insert mode, there is a couple seconds of delay before the text I type appears. It's very jarring! I will try and do a
git bisectto see if I can find out around when this happened, but I'm afraid it might be due to some external dependency that you're not in control of...Has anyone else noticed this recently? (Everything was fine a couple months ago...)
I might need to try disabling modules one by one too.