Closed anildigital closed 4 years ago
gonewest818
commented
4 years ago 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?
anildigital
commented
4 years ago @gonewest818 yes.. this was recent... like from last month
anildigital
commented
4 years ago @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
gonewest818
commented
4 years ago 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]
anildigital
commented
4 years ago 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.
gonewest818
commented
4 years ago Would you be willing to try testing the version available on MELPA stable (which is dimmer 0.4.2, before that most recent bugfix)?
anildigital
commented
4 years ago 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, editingHi, 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.
anildigital
commented
4 years ago @gonewest818 okay thanks! It was a serious bug that affected my month's productivity. I switching to stable version now.
gonewest818
commented
4 years ago Well, I mean, let’s test the stable version and see. If that fixes performance for you then at least it narrows down the debugging.
On Apr 24, 2020, at 11:26 AM, Anil Wadghule notifications@github.com wrote:
@gonewest818 https://github.com/gonewest818 okay thanks! It was a serious bug that affected my month's productivity. I switching to stable version now.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/gonewest818/dimmer.el/issues/45#issuecomment-619174198, or unsubscribe https://github.com/notifications/unsubscribe-auth/AASYZ5UAVYTL4IKEZXURXTDROHKVVANCNFSM4MNSAMNA.
gonewest818
commented
4 years ago 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/
edmz
commented
4 years ago - 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.
gonewest818
commented
4 years ago 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.
edmz
commented
4 years ago gonewest818
commented
4 years ago 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.
edmz
commented
4 years ago This is no frustration at all. Glad to help. Dimmer is quite useful.
I’m curious about something, and I ask this with ignorance, why does the number of buffers matter when dimming just the visible buffers?
On Wed, May 6, 2020 at 8:05 PM Neil Okamoto notifications@github.com wrote:
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.
— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/gonewest818/dimmer.el/issues/45#issuecomment-624970256, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAEUNE6S47PBS7S7KVE6LDRQICPPANCNFSM4MNSAMNA .
-- Eduardo
gonewest818
commented
4 years ago 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!
purcell
commented
4 years ago Seeing this too - I had thought it was due to some tramp buffers I had open. Thanks for looking into it.
gonewest818
commented
4 years ago 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.
edmz
commented
4 years ago I'm running it right now. Will let you know how it behaves. I still have my 300+ buffers :)
gonewest818
commented
4 years ago 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
gonewest818
commented
4 years ago 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).
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