Fontification is too inefficient #1177

Closed
mrkkrp opened this Issue Feb 22, 2016 · 13 comments

Projects

None yet

4 participants

@mrkkrp
Contributor
mrkkrp commented Feb 22, 2016

Haskell mode currently has inefficient fontification:

- redisplay_internal (C function)                                5604  78%
 - jit-lock-function                                             5473  76%
  - jit-lock-fontify-now                                         5465  76%
   - jit-lock--run-functions                                     5463  76%
    - run-hook-wrapped                                           5463  76%
     - #<compiled 0xf8e011>                                      5463  76%
      - font-lock-fontify-region                                 5463  76%
       - font-lock-default-fontify-region                        5454  76%
        - font-lock-fontify-keywords-region                      4574  64%
         + #<lambda 0x2e9b41e>                                   4321  60%
         + eval                                                   101   1%
           whitespace-trailing-regexp                              10   0%
        - font-lock-fontify-syntactically-region                  827  11%
         + syntax-propertize                                      706   9%
           syntax-ppss                                              3   0%
        - font-lock-unfontify-region                                3   0%
           font-lock-default-unfontify-region                       3   0%
 + eval                                                           128   1%
   file-remote-p                                                    3   0%
+ command-execute                                                 778  10%
- ...                                                             680   9%
   Automatic GC                                                   676   9%
 + flycheck-buffer-automatically                                    4   0%
  sml/generate-position-help                                       18   0%
+ timer-event-handler                                              16   0%
+ flycheck-display-error-at-point-soon                             11   0%
+ undo-auto--add-boundary                                           7   0%
+ yas--post-command-handler                                         4   0%
  internal-timer-start-idle                                         4   0%
  delete-selection-pre-hook                                         3   0%

Try it yourself — set quite high frequency of key repeat on OS level and hold a key when is Haskell mode. You will see that dislay update is sporadic (well, of course you should turn off Smartparens and Flyspell, because they skyrocket typing latency). Compare with Emacs Lisp mode where characters appear continuously.

My understanding is that the higher time spent in GC the “slower” the experience. In Emacs lisp mode 5% of time is spent in GC even with aggressive indent enabled. Here we have 10 % and it turns out it's quite high already. In markdown mode it's 20% and it's unbearable (under certain conditions).

Why this matters? Typing with little latency in responsive editor is a joy. In Emacs, many packages use hooks that are executed after every key press (there are a number of them) plus some modes have inefficient fontification that actually makes “advanced” Emacs setup slower than some IDEs. It can get really slow. Web-based Atom text editor feels faster. In Haskell mode when everything sums up, it lags when I type fast.

Now I decided that I either switch to different text editor or make my Emacs as fast as it is when it's vanilla. I would really like to succeed in the latter.

And here is an article for you:

https://pavelfatin.com/typing-with-pleasure/

@geraldus
Contributor

@mrkkrp hi! Performance is my idea fix, I always want to make things faster. Recently, I have read few articles and increased GC threshold, byte-complied my .emacs and disables linum-mode everywhere. And I noticed that haskell-mode is slower than, say elisp mode also. And both of them are much much slower than fundamental mode. Honestly, I though about benchmarking haskell-mode fontyfication, but comparing to you I have much little experience in this direction. Thank you for some stats. Now, when the issue is obvious I see only one way: try to fix it. Can you help with this? We need more information and stats to understand what parts of code are most fragile.

And about mentioned article, man, it's huge, I'd better make some contributions rather than wasting time to read it :D can you summarize?

@mrkkrp
Contributor
mrkkrp commented Feb 22, 2016

and increased GC threshold

I recently found that although some recommend this, it's not a very good idea because the higher threshold you have the longer GC actually takes. With default setup GC is so fast that you won't actually notice while increased gc-cons-threshold can cause obvious lags. It makes sense to temporarily increase the value during start-up, but I don't see much difference either.

but comparing to you I have much little experience in this direction

Oh come on, I have no special experience with this. I'm sure that reading manual and some experimentation can give insights and it's certainly possible to hightlight Haskell syntax efficiently.

Can you help with this? We need more information and stats to understand what parts of code are most fragile.

I'll first try to eliminate the need in Smartparens and figure out how to use Flyspell to check words that I type without activating flyspell-mode. This will take some time. These things combined are much worse than haskell-mode fontification problems. Once these problems are solved, I might take interest in improving Haskell mode in this aspect, but honestly I don't think I will get to it anytime soon, because I have limited time for this sort of thing.

And about mentioned article, man, it's huge, I'd better make some contributions rather than wasting time to read it :D can you summarize?

Well, basically it says that latency is bad. Even when you don't perceive it consciously, it can spoil your experience with editor.

@geraldus
Contributor

it's not a very good idea because the higher threshold you have the longer GC actually takes

Yep, I've found similar precautions, but I didn't see any lags though I have quite performant hardware. For now I have threshold set to 100MiB

Flyspell to check words

Oh, I really missing spell check in Emacs for ages and still haven't any chance to read something about this issue (I thought about spell checking last evening) :D

Recently, my restless mind made to install NeoVim, Vim and read few articles comparing Atom and other editors/IDEs performance to Emacs, finally I've installed Emacs pretest version of Emacs 25 (namely 26.0.91.1), I have reinstalled all packages from MELPA and recompiled few other local packages I use, reconsidered to set scroll amount to 3 lines and disable linum mode, I noticed slight better performance comparing to Emacs 24. And there are a lot of small improvements here and there in Emacs 25 so now I can not wait its official stable release :D

As for issue subject, I also have very limited time and believe so do most of us. Currently I would be glad to eliminate as much old issues as possible. Then we can concentrate on tokenizer improvements, I hope we will be able to have a robust, reliable tokenizer, which will help to improve and speed up such things as indentation (this will be huge win if we success) and fontifycation.

@gracjan
Contributor
gracjan commented Feb 22, 2016

@mrkkrp, the only part of efficiency that we have control over hides behind this line:

         + #<lambda 0x2e9b41e>                                   4321  60%

As you see we need some help getting more detailed information.

As I see you are on a crusade for efficiency in a couple of Emacs packages. Will you create a package or at least a methodology to measure font-lock efficiency? That would be really good.

@gracjan
Contributor
gracjan commented Feb 22, 2016

Note also that it looks like this for me:

    + #<compiled 0x43399a9d>                                   19,536   0%

@mrkkrp: We need more help in reproducing this issue.

@mrkkrp
Contributor
mrkkrp commented Feb 22, 2016

Interesting. Did you try without any config or with some config? I tired with most part of my config enabled expept for Smartparens and Flyspell.

Also note that it's not really important how much percents rendering funtion gets (well, from my experience), it's time spent in GC somehow correlates with typing experience. Anyway, it would be much more helpful if you posted full profiling report.

@gracjan
Contributor
gracjan commented Feb 22, 2016

Here you go:

- ...                                                              36  59%
   Automatic GC                                                    36  59%
+ timer-event-handler                                              18  29%
- redisplay_internal (C function)                                   7  11%
 - jit-lock-function                                                5   8%
  - jit-lock-fontify-now                                            5   8%
   - funcall                                                        5   8%
    - #<compiled 0x43aa961d>                                        5   8%
     - run-hook-with-args                                           5   8%
      - font-lock-fontify-region                                    5   8%
       - font-lock-default-fontify-region                           5   8%
        - font-lock-fontify-syntactically-region                    4   6%
         - syntax-propertize                                        3   4%
          - haskell-syntax-propertize                               3   4%
           - save-excursion                                         3   4%
            - let                                                   3   4%
             - while                                                2   3%
              - let                                                 2   3%
               - haskell-lexeme-looking-at-token                    2   3%
                - let                                               2   3%
                 - or                                               2   3%
                    and                                             2   3%
 + #<compiled 0x40831d3b>                                           1   1%
 + linum-after-scroll                                               1   1%
@gracjan
Contributor
gracjan commented Feb 22, 2016

Another run:

CPU samples:

- redisplay_internal (C function)                                  24  55%
 - jit-lock-function                                               16  37%
  - jit-lock-fontify-now                                           15  34%
   - funcall                                                       13  30%
    - #<compiled 0x43bf188d>                                       13  30%
     - run-hook-with-args                                          13  30%
      - font-lock-fontify-region                                   13  30%
       - font-lock-default-fontify-region                          13  30%
        + font-lock-fontify-syntactically-region                    8  18%
        - font-lock-fontify-keywords-region                         4   9%
         - eval                                                     4   9%
          - cl-case                                                 4   9%
           - let                                                    3   6%
            - cond                                                  3   6%
             - when                                                 3   6%
              - if                                                  3   6%
                 member                                             3   6%
           - #<compiled 0x40c6dde1>                                 1   2%
              mapcar                                                1   2%
 + eval                                                             5  11%
   file-remote-p                                                    2   4%
 + linum-after-scroll                                               1   2%
- ...                                                              13  30%
   Automatic GC                                                    12  27%
 + run-mode-hooks                                                   1   2%
+ timer-event-handler                                               6  13%

Bytes:

+ timer-event-handler                                       7,635,908  63%
- redisplay_internal (C function)                           4,477,790  36%
 - jit-lock-function                                        3,514,106  29%
  - jit-lock-fontify-now                                    3,491,226  28%
   - funcall                                                3,478,778  28%
    - #<compiled 0x43e607d5>                                3,478,778  28%
     - run-hook-with-args                                   3,478,778  28%
      - font-lock-fontify-region                            3,478,778  28%
       - font-lock-default-fontify-region                   3,478,778  28%
        - font-lock-fontify-keywords-region                 2,290,414  18%
         - eval                                               786,704   6%
          - cl-case                                           777,344   6%
           - let                                              482,824   3%
            - cond                                            463,064   3%
             - when                                           463,064   3%
              - if                                            439,144   3%
                 member                                       331,552   2%
               + and                                          107,592   0%
              haskell-lexeme-classify-by-first-char            11,440   0%
           - #<compiled 0x40c6dde1>                           234,200   1%
              mapcar                                          153,920   1%
          - unless                                              9,360   0%
           - if                                                 1,040   0%
              member                                            1,040   0%
        + font-lock-fontify-syntactically-region            1,187,324   9%
        + font-lock-unfontify-region                            1,040   0%
   file-remote-p                                              526,872   4%
 + eval                                                       392,172   3%
 + #<compiled 0x40831d3b>                                      30,096   0%
 + linum-after-scroll                                          13,504   0%
  ...                                                               0   0%

Code that tests produces those:

(defvar the-test-counter 0)
(defvar the-test-buffer nil)

(defun insert-thing ()
  (when (equal 0 the-test-counter)
    (profiler-start 'cpu+mem))
  (cl-incf the-test-counter)
  (if (< the-test-counter 100)
      (progn
        (run-at-time 0.01 nil #'insert-thing)
        (insert "x"))
    (profiler-report)
    (profiler-stop)))

(defun do-the-test ()
  "Test font lock speed"
  (interactive)
  (setq the-test-counter 0)
  (setq the-test-buffer (current-buffer))
  (run-at-time 0.01 nil #'insert-thing))
@mrkkrp
Contributor
mrkkrp commented Feb 22, 2016

59% of cycles spent in GC is not very good anyway. I don't really think this stuff is interesting read for /r/haskell, but well…

@Fanael
Contributor
Fanael commented Feb 23, 2016

I recently found that although some recommend this, it's not a very good idea because the higher threshold you have the longer GC actually takes. With default setup GC is so fast that you won't actually notice while increased gc-cons-threshold can cause obvious lags.

Nonsense. Emacs GC is your average naïve mark-and-sweep, where collections take time proportional to the total heap size. The default gc-cons-threshold is so small (800 KB, I think) that any potential benefit from having to scan and throw away less garbage is dwarfed by the time spent scanning live objects, and by the fact that collections are much more frequent than they are with a reasonably sized GC threshold.

While there's obviously a limit where increasing gc-cons-threshold only makes GC pauses more annoying, it's probably in the range of hundreds of MBs on modern hardware. Typical values I find people using, like 20-50 MB, are very likely not big enough to be detrimental.

@mrkkrp
Contributor
mrkkrp commented Feb 23, 2016

@Fanael, As with many things, I think it's about golden mean, which depends on your hardware. What I said is not something I made up, but my actual experience from tests I performed. Yes, default value is likely to be too small, and it's OK to increase it to 8 MB I think, but too big values can make situation worse. I also think that your argumentation would look even better without attacking people with “nonsense” claims.

@gracjan
Contributor
gracjan commented Feb 23, 2016

I find efficiency stuff very interesting and that is why I shared with both /r/haskell and /r/emacs. I suffer fontification sluggishness (or a similar problem) in org-mode and it annoys me to no end.

We should not let haskell-mode be annoying at character typing level, because how will we be able to provide great user experience with more advanced functions if we fail at such a basic level?

@gracjan
Contributor
gracjan commented Feb 23, 2016

This particular problem seems to be in your configuration only, so I'm closing this particular issue in favor of more general approach described in #1181.

@gracjan gracjan closed this Feb 23, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment