Dimmer mode makes experience Emacs very slow on macOS when Command + tab is used to switch apps
anildigital opened this issue · 24 comments
It takes 74% just to show or render the emacs. So for every alternate Command + tab switch on macOS, I see it takes 3-4 seconds for Emacs to appear. Overall experience becomes very slow when you are working and switching tabs.
Here is Emacs profiler report
https://gist.github.com/3711f7b00a223b6c1c1b5bd16c1ae589
WIth bug
https://www.loom.com/share/fa1fc5ffb84b4b64aeb6d1c2cebef287
With dimmer removed
https://www.loom.com/share/fa1fc5ffb84b4b64aeb6d1c2cebef287
Interesting. Did this change recently for you?
Can you leave dimmer in place but turn off the the focus handling in your configuration (setq dimmer-watch-frame-focus-events nil) and see what performance you get?
@gonewest818 yes.. this was recent... like from last month
@gonewest818 (setq dimmer-watch-frame-focus-events nil) kind of fixes. Not sure if the performance is as good as without dimmer-mode. Here is profile report https://gist.github.com/anildigital/cbe37f9e64604f4e994ba774e6b2593f
Ok, thanks for doing that test. That second profile shows only 34 samples (0.034 seconds) in dimmer. Most of the rest of the time is really spent in counsel/ivy and I have a similar timing in my profiles here... I don't see anything remarkable there.
But getting back to your first profile with dimmer in place... I changed dimmer's focus handling about a month ago (issue #43) because it was doing handle-focus-in incorrectly in certain specific cases. What's unusual is that your first profile shows a large (about 1.5 seconds) amount of time spent in the handle-focus-out(!) case and I wouldn't expect that recent fix to affect focus-out.
How is your buffer switching performance? Have you felt a change there? Do you have a very large number of buffers, a theme with a very large number of faces, any dimmer-buffer-exclusion-predicates or dimmer-prevent-dimming-predicates?
[edit: typo]
Buffer switching performance was very poor as well. I have 10-15 different Elixir Phoenix projects where I have lsp-mode with Elixir-LS. I also use Desktop mode so I have like 50-60 buffers open. But only recently I felt slowness. Earlier things were OK I guess. I also use Treemacs for every project.
Would you be willing to try testing the version available on MELPA stable (which is dimmer 0.4.2, before that most recent bugfix)?
I am using dimmer 0.4.2. The last profiler logs I sent was with 0.4.2
;; Filename: dimmer.el
;; Author: Neil Okamoto
;; Version: 0.4.2
;; Package-Version: 20200329.35
;; Package-Requires: ((emacs "25.1"))
;; URL: https://github.com/gonewest818/dimmer.el
;; Keywords: faces, editing
Hi, ok so actually that's the snapshot version. Where it says "Package-Version: 20200329.35", the datestamp means that's the latest snapshot from MELPA (https://melpa.org/packages/dimmer-20200329.35.el).
If you install dimmer from the MELPA stable repo, you'll see "Package-Version: 0.4.2" (https://stable.melpa.org/packages/dimmer-0.4.2.el) which means it's a tagged release.
So, something like
(depends-on "dimmer" :archive "melpa-stable")
should get you the stable version... ? Sorry about that.
@gonewest818 okay thanks! It was a serious bug that affected my month's productivity. I switching to stable version now.
Unfortunately, I can't see the issue here so I'll tag the issue "need repro" for now.
Also, just now on Reddit r/emacs there is this question which sounds similar: https://www.reddit.com/r/emacs/comments/getq8g/upgraded_to_27091_on_macos_app_switching_to_emacs/
- command-execute 8717 96%
- call-interactively 8717 96%
- funcall-interactively 8717 96%
- handle-focus-out 8645 95%
- #<compiled 0x1ffd2878bbad> 8645 95%
- apply 8645 95%
- dimmer-after-focus-change-handler 8645 95%
- let 8645 95%
- if 8645 95%
- dimmer-dim-all 8645 95%
- mapc 8645 95%
- #<lambda 0x221d247d09d5af> 8645 95%
- dimmer-dim-buffer 8645 95%
- save-current-buffer 8640 95%
- if 8634 95%
- let 8634 95%
- while 8576 94%
- let 8510 94%
- dimmer-face-color 8153 90%
- let 8038 88%
- face-foreground 3283 36%
face-attribute 3232 35%
- face-background 2926 32%
face-attribute 2889 31%
- if 1677 18%
- progn 1452 16%
- setq 1448 16%
- plist-put 1427 15%
- dimmer-cached-compute-rgb 1404 15%
- let 1394 15%
or 30 0%
- and 186 2%
- color-defined-p 106 1%
- display-graphic-p 20 0%
framep-on-display 10 0%
or 19 0%
- if 311 3%
- progn 310 3%
- setq 310 3%
+ cons 291 3%
setq 13 0%
+ dimmer-filtered-face-list 42 0%
dimmer--dbg 1 0%
- handle-focus-in 72 0%
I used the tagged release version and things got noticeable better, but it still lagged sometimes. There is definitely a difference between it being activated and not.
What theme are you using? How many buffers do you have in your current session?
The TL;DR of my notes below is that dimmer is spending a lot of time in what should be a simple hash table lookup of face attributes, and the best hypothesis I can come up with is maybe you have a much much larger number of faces?
Quick breakdown of that profile:
- dimmer-face-color 8153 90%
That's 8 seconds overall in dimmer, which is basically an eternity.
- face-foreground 3283 36%
face-attribute 3232 35%
- face-background 2926 32%
face-attribute 2889 31%
Those face-* functions are part of the emacs distribution, and so 3283+2926 = 6209 milliseconds are spent simply extracting the foreground and background attributes for all faces (in all buffers). No color calculations are being done yet ... this is literally just walking through all the colors in your theme.
Next,
- if 1677 18%
- progn 1452 16%
- setq 1448 16%
- plist-put 1427 15%
- dimmer-cached-compute-rgb 1404 15%
- let 1394 15%
or 30 0%
That's where the actual color value calculations are done (if they haven't been calculated and cached already). What's mysterious is that all of this is more than 10 times slower than what's happening on my laptop.
- I have 350 buffers opened.
- The theme I'm using is doom-vibrant
- I don't recall installing fonts on my computer, except for the all-the-icons one and fira code. Does this answer your question about faces?
Yes, thank you. 350 buffers is probably the root cause, as I don't keep that many open at a time. I have a pretty decent idea what's happening and over the next few days I'll see about fixing.
If you tried the tagged release in MELPA stable, what I'm going to try to do is get back to roughly that level of performance ... and since you said that is still lagging, then I suggest I do this fix first and then look at some new profile reports once it's in place.
Sound good? I'm really sorry to cause you this frustration, and I appreciate your help testing and profiling this.
Well, it's a long story but I recently made a change that processes every buffer instead of only the visible buffers. That was mostly to keep the code simpler, but clearly what I need to do is the more complicated version of things... Hold on a bit while I look into that!
Seeing this too - I had thought it was due to some tramp buffers I had open. Thanks for looking into it.
Ok: - there's a candidate fix for this in the 'focus-fix' branch. I just pushed it a few minutes ago, and I'm running it locally as well... Maybe a solid 5 minutes of testing so far... :)
Before I merge the change I'll "stress test" with larger numbers of buffers, and I'll keep it in place for the rest of the day/week/whatever to make sure I haven't broken anything. I'll post timing results here.
I'm running it right now. Will let you know how it behaves. I still have my 300+ buffers :)
With 300 buffers open, 10 of them visible, and this is the profile for 3 switches between emacs and another app:
- command-execute 322 91%
- call-interactively 322 91%
- funcall-interactively 322 91%
- counsel-M-x 322 91%
- ivy-read 307 87%
+ read-from-minibuffer 47 13%
+ ivy--reset-state 5 1%
+ ivy-call 2 0%
counsel--M-x-externs 15 4%
- ... 19 5%
Automatic GC 9 2%
- dimmer-after-focus-change-handler 5 1%
- let 5 1%
- if 5 1%
- dimmer-dim-all 5 1%
- mapc 5 1%
- #<lambda 0x22080983b12429> 5 1%
- dimmer-dim-buffer 5 1%
- save-current-buffer 5 1%
- if 5 1%
- let 5 1%
- while 5 1%
- let 5 1%
- dimmer-face-color 5 1%
- let 5 1%
+ face-background 2 0%
- if 2 0%
- progn 1 0%
- setq 1 0%
- plist-put 1 0%
+ dimmer-cached-compute-rgb 1 0%
+ and 1 0%
+ face-foreground 1 0%
- let* 5 1%
+ if 5 1%
- timer-event-handler 5 1%
+ apply 5 1%
+ redisplay_internal (C function) 4 1%
flyspell-post-command-hook 1 0%
I can say that the problems disappeared while using the version from that branch
Ok, I merged this to master. Thanks for your feedback, profiling, and testing.
The next MELPA build runs in 15 minutes and takes about an hour (although, if the builds run in alphabetical order (do they?) then the new dimmer will be ready sooner than that).