Re: Existing redisplay profiling tool?

[Yuan Fu <casouri@gmail.com>]

> On Sep 14, 2024, at 12:10 PM, Eli Zaretskii <eliz@gnu.org> wrote:
> 
>> From: Yuan Fu <casouri@gmail.com>
>> Date: Sat, 14 Sep 2024 11:20:15 -0700
>> 
>> I’m doing some optimization for tree-sitter font-lock, and want to measure the difference in a real editing session (rather than fontifying the whole buffer 10 times). I’m sure there’s some tool for measuring time spent in redisplay some where, but couldn’t find anything poking around.
> 
> How about using the scrolling benchmark through xdisp.c while
> profiling?
> 
> (defun scroll-up-benchmark ()
>  (interactive)
>  (let ((oldgc gcs-done)
>        (oldtime (float-time)))
>    (condition-case nil (while t (scroll-up) (redisplay))
>      (error (message "GCs: %d Elapsed time: %f seconds"
>                      (- gcs-done oldgc) (- (float-time) oldtime))))))
> 
> Evaluate the above, then turn on profiling, then type
> "M-x scroll-up-benchmark RET" with point at beginning
> of buffer that visits xdisp.c under c-ts-mode.

Thanks! I’m hoping to measure the perceived responsiveness when typing text in the buffer, so here’s what I came up with:

(let ((prev-time (current-time))
      (measurements nil))
  (dotimes (_ 100)
    (insert "s")
    (redisplay)
    (push (float-time (time-subtract (current-time) prev-time))
          measurements)
    (setq prev-time (current-time)))
  (message "Average time: %f"
           (/ (apply #'+ measurements) (length measurements))))

Do you think this accurately measures the redisplay time between each keystroke? (Obviously this doesn’t take account of post-command-hook, I only want to measure repose & redisplay here.)

If that’s an accurate measurements, then my optimization doesn’t make any significant difference :-)
In xdisp.c, inserting 100 “s” takes about 17.8ms per “keystroke” on average. With optimization it’s about 16.7ms, not much difference.

Obviously the time differs depending on where are you inserting the “s”, but I tried a few places (close to beginning of buffer, close to end, inside a function, outside a function, etc), and the measurements doesn’t vary too much (12–16ms with optimization on)

I also measured a base performance by enabling fundamental-mode in xdisp.c. It takes about 2.2ms between each “keystroke”.

In a very small file, the average time between each “keystroke” is 3.2ms and 3.5ms, for optimized and unoptimized run respectively.

Finally, c-mode in xdisp.c takes about 10.7ms per “keystroke” ;-)

I guess the takeaway is a) my new optimization doesn’t do anything, and b) tree-sitter font-lock doesn’t add human-perceivable latency when typing.

Yuan

My measurements:

xdisp.c:
optimization off: Average time: 0.017755 -> 17.8ms
optimization  on: Average time: 0.016701 -> 16.7ms
fundamental mode: Average time: 0.002188 -> 2.2ms

optimization on w/ post-command-hook: Average time: 0.033086 -> 33.1ms


small file:
optimization  on: Average time: 0.003207 -> 3.2ms
optimization off: Average time: 0.003473 -> 3.5ms

optimization on w/ post-command-hook: Average time: 0.013553 -> 13.6ms

c-mode:
xdisp.c : Average time: 0.010691 -> 10.7ms
small file: Average time: 0.005141 -> 5.1ms