How to measure frame rate in fps?

How to measure frame rate in fps?

[Jimmy Yuen Ho Wong]

Hi everyone,

I've gotten into a discussion with isort's author about how fast
editors can actually render text. I was just wondering if there are
any built-in facilities that can measure framerate in FPS in emacs?

Thanks,

Jimmy Yuen Ho Wong

Re: How to measure frame rate in fps?

[Arthur Miller]

Jimmy Yuen Ho Wong <wyuenho@gmail.com> writes:

> Hi everyone,
>
> I've gotten into a discussion with isort's author about how fast
> editors can actually render text.

FPS is not necessary the measure of how fast you can render text. Sure
it directly affects fps, but fps is more complex than just how fast text
is rendered. It is also affected by how fast your hardware and OS can
swap frames, how your OS multitasks processes etc. When you read
benchmarks at sites like Tomshardware, notice that they use different
games and applications to measure the performance. They really are
concerned with how the underlaying hardware and OS perform in that
particular game and application. Different games will result with
different number of FPS. So FPS is just a relative measure for the
application at hand.

How fast text can be rendered on any computer depends on the hardware of
course and how efficiently code used to render text use that
hardware. Most "normal" applications like text processors will use
whatever the OS provides. I guess you have to ask Mr. Eliz & Co for the
details about how Emacs renders text, or look at the source.

Anyway, you could create small app to some teoretical speed of how much
text you could render on your own computer with your choice of the
library. "Theoretical" because it is really difficult to get 
reliable measure when it comes to just rendering speed on modern
computers since cpus run at variable speed to save the energy, OSs are
scheduling processes and stuff at they will, data has to be send over
the bus to gpu if there is one, and so on. 

For the Emacs I don't think you can get a meaningful measure "out of the
box" since Emacs run in a blocking event qeue, which means Emacs does
nothing unless there is input. Maybe you could construct a test and
render a considerably big piece of text in an empty buffer and take the
time, repeat several times and take mean time, to give you some feel of
howa fast it happends, but I am not sure how reliably you could do this
in Emacs.

I don't think it matters much either. Most CPUs can render "enough" text,
fast enough that it really isn't important. What does it matter if one
can render 10 billion characters at 144 fps, if one can display only few
hundreds or max few thousands at the time on the screen? Who
cares. Consider a Ferrari vs a Volvo. Sure, Ferrari is faster, but Volvo
will do the jobb 99% of the time for 99% of the people.

Re: How to measure frame rate in fps?

[Eli Zaretskii]

> From: Jimmy Yuen Ho Wong <wyuenho@gmail.com>
> Date: Mon, 31 May 2021 14:03:17 +0100
> 
> I've gotten into a discussion with isort's author about how fast
> editors can actually render text. I was just wondering if there are
> any built-in facilities that can measure framerate in FPS in emacs?

Emacs doesn't work at a fixed "frame rate".  It attempts to optimize
each update of the screen as much as possible, so the actual time to
perform a single update of a window depends on how much stuff on the
screen needs to be changed since the previous redisplay cycle.  As
result, you will find that the redisplay time could vary by a factor
of 10 if not more, depending on what changed in the editor's internal
state.  Moreover, the first phase of redisplay, the one that
determines what needs to be redrawn, might decide to redraw something,
but the second phase, which actually writes to the glass, can decide
that nothing needs to be redrawn.  I don't know how to quantify the
speed of "redrawing" when nothing is actually redrawn, although some
CPU cycles are expended.

That said, you can measure the time it takes to redisplay after some
change using the "M-x benchmark" command to time the function
'redisplay'.  You just need to remember to include some command that
would affect the display, or else redisplay will do very little and
redraw nothing.  For example:

  C-u 100 M-x benchmark RET (progn (scroll-up) (redisplay)) RET

or

  C-u 100 M-x benchmark RET (progn (insert "a") (redisplay)) RET

(The former is better tried in a buffer that has more than 100
screenfuls of text.)

Then subtract the time it takes to run the same benchmark, but without
the "(redisplay)" part, divide the result by 100, and you get the time
it takes to redisplay a single window.

Re: How to measure frame rate in fps?

[Dmitry Gutov]

On 01.06.2021 14:43, Eli Zaretskii wrote:
> You just need to remember to include some command that
> would affect the display, or else redisplay will do very little and
> redraw nothing.

Speaking of redisplay redrawing nothing, as long as tool-bar-mode is on, 
my GTK3 build (with -Q even) evaluates (benchmark 1 '(redisplay)) to a 
sequence of results like this:

Elapsed time: 0.040924s
Elapsed time: 0.026343s
Elapsed time: 0.023473s
Elapsed time: 0.025162s
Elapsed time: 0.030074s
Elapsed time: 0.041305s (0.026917s in 1 GCs)
Elapsed time: 0.031169s
Elapsed time: 0.020957s
Elapsed time: 0.034885s
Elapsed time: 0.035338s
Elapsed time: 0.030864s

and with tool-bar-mode off:

Elapsed time: 0.007189s
Elapsed time: 0.006181s
Elapsed time: 0.007358s
Elapsed time: 0.004177s
Elapsed time: 0.007754s
Elapsed time: 0.007557s

Not so noticeable if it just happens once, but easily affects the 
performance of code which performs "virtual" redisplay, such as 
posn-at-point.

Sometimes the effect disappears (even with tool-bar-mode on), but to 
bring it back I only had to call (redisplay t) once.

Re: How to measure frame rate in fps?

[Eli Zaretskii]

> Cc: emacs-devel@gnu.org
> From: Dmitry Gutov <dgutov@yandex.ru>
> Date: Tue, 1 Jun 2021 17:18:09 +0300
> 
> On 01.06.2021 14:43, Eli Zaretskii wrote:
> > You just need to remember to include some command that
> > would affect the display, or else redisplay will do very little and
> > redraw nothing.
> 
> Speaking of redisplay redrawing nothing, as long as tool-bar-mode is on, 
> my GTK3 build (with -Q even) evaluates (benchmark 1 '(redisplay)) to a 
> sequence of results like this:
> 
> Elapsed time: 0.040924s
> Elapsed time: 0.026343s
> Elapsed time: 0.023473s
> Elapsed time: 0.025162s
> Elapsed time: 0.030074s
> Elapsed time: 0.041305s (0.026917s in 1 GCs)
> Elapsed time: 0.031169s
> Elapsed time: 0.020957s
> Elapsed time: 0.034885s
> Elapsed time: 0.035338s
> Elapsed time: 0.030864s
> 
> and with tool-bar-mode off:
> 
> Elapsed time: 0.007189s
> Elapsed time: 0.006181s
> Elapsed time: 0.007358s
> Elapsed time: 0.004177s
> Elapsed time: 0.007754s
> Elapsed time: 0.007557s

I know very little about the cost of the GTK tool bar redrawing: the
code is in gtkutil.c, and it's full of GTK API calls.  Maybe the above
times are explained and justified by that, I don't know.

I also am not sure the above faithfully reflects what happens in Real
Life when Emacs has nothing to redisplay: I think you get the tool-bar
redisplay triggered because the evaluation of the benchmark call
causes it somehow.  How did you evaluate it, exactly?

> Not so noticeable if it just happens once, but easily affects the 
> performance of code which performs "virtual" redisplay, such as 
> posn-at-point.

How do you deduce that posn-at-point triggers redisplay of the GTK
tool bar?  It shouldn't, AFAIR.  posn-at-point and its ilk only
simulate display of text, they don't care about window's and frame's
decorations.

Re: How to measure frame rate in fps?

[Dmitry Gutov]

On 01.06.2021 17:43, Eli Zaretskii wrote:

> I know very little about the cost of the GTK tool bar redrawing: the
> code is in gtkutil.c, and it's full of GTK API calls.  Maybe the above
> times are explained and justified by that, I don't know.

Sometimes the times are high like this, sometimes they are lower. Could 
be it's another GTK bug, and there's nothing we can do, but it's 
probably a bug *somewhere*.

> I also am not sure the above faithfully reflects what happens in Real
> Life when Emacs has nothing to redisplay: I think you get the tool-bar
> redisplay triggered because the evaluation of the benchmark call
> causes it somehow.  How did you evaluate it, exactly?

Either using M-:, or with M-x benchmark like you suggested (only without 
prefix argument, to measure just 1 iteration). The results are similar.

>> Not so noticeable if it just happens once, but easily affects the
>> performance of code which performs "virtual" redisplay, such as
>> posn-at-point.
> 
> How do you deduce that posn-at-point triggers redisplay of the GTK
> tool bar?  It shouldn't, AFAIR.  posn-at-point and its ilk only
> simulate display of text, they don't care about window's and frame's
> decorations.

You're right, posn-at-point shows me different timings. Often enough as 
high as 12-15ms, which is not great for a low latency display, but the 
numbers don't seem to be tied to tool-bar-mode being on.

But we end up calling `redisplay` explicitly on a different code path in 
Company (when a backend talks to an external process, basically), so 
it's still affected by how long that takes.

Re: How to measure frame rate in fps?

[Eli Zaretskii]

> Cc: wyuenho@gmail.com, emacs-devel@gnu.org
> From: Dmitry Gutov <dgutov@yandex.ru>
> Date: Tue, 1 Jun 2021 18:00:35 +0300
> 
> > I also am not sure the above faithfully reflects what happens in Real
> > Life when Emacs has nothing to redisplay: I think you get the tool-bar
> > redisplay triggered because the evaluation of the benchmark call
> > causes it somehow.  How did you evaluate it, exactly?
> 
> Either using M-:, or with M-x benchmark like you suggested (only without 
> prefix argument, to measure just 1 iteration). The results are similar.

Yes, that figures: entering the minibuffer triggers a more thorough
redisplay than usual: we redisplay the menu bar, the tool bar, and
several other things as result, for reasons that should be obvious.

Try C-x C-e instead after typing the sexp in *scratch.  In that
scenario, I don't expect the tool bar to be redrawn.

> > How do you deduce that posn-at-point triggers redisplay of the GTK
> > tool bar?  It shouldn't, AFAIR.  posn-at-point and its ilk only
> > simulate display of text, they don't care about window's and frame's
> > decorations.
> 
> You're right, posn-at-point shows me different timings. Often enough as 
> high as 12-15ms, which is not great for a low latency display, but the 
> numbers don't seem to be tied to tool-bar-mode being on.

If you want me to take a look at those 15ms cases, I suggest to file a
bug report with the details and a recipe.

Re: How to measure frame rate in fps?

[Dmitry Gutov]

On 01.06.2021 18:35, Eli Zaretskii wrote:

> Yes, that figures: entering the minibuffer triggers a more thorough
> redisplay than usual: we redisplay the menu bar, the tool bar, and
> several other things as result, for reasons that should be obvious.
> 
> Try C-x C-e instead after typing the sexp in *scratch.  In that
> scenario, I don't expect the tool bar to be redrawn.

Thanks, that's a better methodology.

I still see long-ish redisplays in my "real world" scenario, with 
timings like

Elapsed time: 0.003500s
Elapsed time: 0.026936s
Elapsed time: 0.024454s
Elapsed time: 0.024453s

on redisplay with tool-bar-mode on and

Elapsed time: 0.005239s
Elapsed time: 0.005562s
Elapsed time: 0.014864s
Elapsed time: 0.014525s
Elapsed time: 0.005216s
Elapsed time: 0.014419s
Elapsed time: 0.015004s
Elapsed time: 0.010501s
Elapsed time: 0.013163s

with it off (both measured with 'benchmark-progn' injected in some 
working code), but none of that with 'emacs -Q'.

Perhaps those are to be expected (even though the Emacs frame doesn't 
change much, the scenario involves 1 or 2 network calls).

>>> How do you deduce that posn-at-point triggers redisplay of the GTK
>>> tool bar?  It shouldn't, AFAIR.  posn-at-point and its ilk only
>>> simulate display of text, they don't care about window's and frame's
>>> decorations.
>>
>> You're right, posn-at-point shows me different timings. Often enough as
>> high as 12-15ms, which is not great for a low latency display, but the
>> numbers don't seem to be tied to tool-bar-mode being on.
> 
> If you want me to take a look at those 15ms cases, I suggest to file a
> bug report with the details and a recipe.

With updated testing approach, I don't see those timings with 
posn-at-point anymore, thanks.

The only repro I still see is the one described above, in the "complex" 
scenario. Not sure if it's worth reporting, or if the numbers simply 
look correct.

Re: How to measure frame rate in fps?

[Eli Zaretskii]

> Cc: wyuenho@gmail.com, emacs-devel@gnu.org
> From: Dmitry Gutov <dgutov@yandex.ru>
> Date: Wed, 2 Jun 2021 00:31:37 +0300
> 
> With updated testing approach, I don't see those timings with 
> posn-at-point anymore, thanks.
> 
> The only repro I still see is the one described above, in the "complex" 
> scenario. Not sure if it's worth reporting, or if the numbers simply 
> look correct.

Maybe run Emacs under 'perf' and see which GTK API call(s) take(s)
most of those milliseconds?

Re: How to measure frame rate in fps?

[Dmitry Gutov]

On 02.06.2021 05:29, Eli Zaretskii wrote:
> Maybe run Emacs under 'perf' and see which GTK API call(s) take(s)
> most of those milliseconds?

I'm not sure if I've been doing it right, but the gtk functions seem to 
be taking pretty much none of the runtime:

    0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_widget_get_direction
    0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_widget_get_type 

    0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_style_context_get_property
    0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_get_event_widget
    0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_style_context_get_type
    0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_toolbar_get_type

The leaders looked like:

   28,52%  emacs         emacs                       [.] mark_object 

    6,87%  emacs         emacs                       [.] assq_no_quit 

    3,45%  emacs         emacs                       [.] mark_char_table 

    3,37%  emacs         emacs                       [.] sweep_strings 

    2,84%  emacs         emacs                       [.] boyer_moore 

    1,82%  emacs         emacs                       [.] 
pdumper_marked_p_impl
    1,80%  emacs         emacs                       [.] 
re_match_2_internal
    1,69%  emacs         emacs                       [.] 
lookup_char_property
    1,57%  emacs         emacs                       [.] 
set_buffer_internal_2
    1,54%  emacs         emacs                       [.] eval_sub 

    1,42%  emacs         emacs                       [.] Fassq 

    1,41%  emacs         emacs                       [.] sweep_conses 

    1,33%  emacs         emacs                       [.] sweep_vectors 

    1,02%  emacs         emacs                       [.] exec_byte_code 

    0,97%  emacs         emacs                       [.] mark_vectorlike 

    0,95%  emacs         emacs                       [.] next_interval 

    0,92%  emacs         emacs                       [.] find_interval 

    0,79%  emacs         libc-2.31.so                [.] 
__memmove_avx_unaligned_erms
    0,64%  emacs         emacs                       [.] 
pdumper_set_marked_impl
    0,62%  emacs         libc-2.31.so                [.] malloc 

    0,62%  emacs         emacs                       [.] Fcons 

    0,61%  emacs         libc-2.31.so                [.] _int_malloc 

    0,58%  emacs         emacs                       [.] 
gui_produce_glyphs
    0,52%  emacs         emacs                       [.] list_length 

    0,49%  emacs         emacs                       [.] Ffuncall 

    0,46%  emacs         emacs                       [.] Fcdr 

    0,42%  emacs         libpthread-2.31.so          [.] 
__pthread_mutex_unlock
    0,40%  emacs         emacs                       [.] 
scan_sexps_forward
    0,40%  emacs         libpthread-2.31.so          [.] 
__pthread_mutex_lock
    0,38%  emacs         emacs                       [.] 
allocate_vectorlike
    0,36%  emacs         libcairo.so.2.11600.0       [.] 
cairo_scaled_font_text_to_glyphs
    0,36%  emacs         emacs                       [.] 
composition_compute_stop_pos
    0,35%  emacs         emacs                       [.] 
bidi_resolve_explicit
    0,35%  emacs         emacs                       [.] 
get_next_display_element
    0,35%  emacs         emacs                       [.] Fplist_get 

    0,34%  emacs         libc-2.31.so                [.] _int_free 

    0,33%  emacs         emacs                       [.] Faref 

    0,33%  emacs         emacs                       [.] 
move_it_in_display_line_to
    0,32%  emacs         emacs                       [.] 
balance_an_interval
    0,32%  emacs         emacs                       [.] get_keymap 

    0,29%  emacs         emacs                       [.] 
do_symval_forwarding
    0,28%  emacs         emacs                       [.] 
set_default_internal
    0,26%  emacs         emacs                       [.] hash_lookup 

    0,26%  emacs         emacs                       [.] 
vectorlike_nbytes
    0,25%  emacs         emacs                       [.] 
rpl_re_compile_pattern
    0,25%  emacs         emacs                       [.] json_to_lisp 

    0,25%  emacs         emacs                       [.] 
bidi_level_of_next_char
    0,24%  emacs         libc-2.31.so                [.] 
malloc_consolidate
    0,23%  emacs         emacs                       [.] 
bidi_resolve_weak
    0,23%  emacs         emacs                       [.] 
find_automatic_composition
    0,23%  emacs         emacs                       [.] grow_specpdl 

    0,23%  emacs         emacs                       [.] mark_compiled 

Re: How to measure frame rate in fps?

[Eli Zaretskii]

> Cc: wyuenho@gmail.com, emacs-devel@gnu.org
> From: Dmitry Gutov <dgutov@yandex.ru>
> Date: Sun, 6 Jun 2021 05:09:09 +0300
> 
> On 02.06.2021 05:29, Eli Zaretskii wrote:
> > Maybe run Emacs under 'perf' and see which GTK API call(s) take(s)
> > most of those milliseconds?
> 
> I'm not sure if I've been doing it right, but the gtk functions seem to 
> be taking pretty much none of the runtime:
> 
>     0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_widget_get_direction
>     0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_widget_get_type 
> 
>     0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_style_context_get_property
>     0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_get_event_widget
>     0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_style_context_get_type
>     0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_toolbar_get_type

Yes, looks like that.  Strange, since you did say disabling the tool
bar makes a prominent difference.

> The leaders looked like:
> 
>    28,52%  emacs         emacs                       [.] mark_object 
> 
>     6,87%  emacs         emacs                       [.] assq_no_quit 
> 
>     3,45%  emacs         emacs                       [.] mark_char_table 
> 
>     3,37%  emacs         emacs                       [.] sweep_strings 
> 
>     2,84%  emacs         emacs                       [.] boyer_moore 

Three out of 5 of the above mean Emacs spends a large proportion of
the time (35%) doing GC.  I'm not sure I understand why should Emacs
perform GC while being idle: do you have some timers running, perhaps?
If this is "emacs -Q", what happens if you disable blink-cursor-mode
and global-eldoc-mode?

>     0,25%  emacs         emacs                       [.] json_to_lisp 

Any idea why this is here?

(I think "perf report" supports output in the form of a call-tree,
where functions are shown with their callers?  That allows to better
understand what high-level processing is running in Emacs than just
looking at the profile sorted by percents.)

Re: How to measure frame rate in fps?

[Dmitry Gutov]

On 06.06.2021 09:11, Eli Zaretskii wrote:

>> I'm not sure if I've been doing it right, but the gtk functions seem to
>> be taking pretty much none of the runtime:
>>
>>      0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_widget_get_direction
>>      0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_widget_get_type
>>
>>      0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_style_context_get_property
>>      0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_get_event_widget
>>      0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_style_context_get_type
>>      0,00%  emacs  libgtk-3.so.0.2404.16  [.] gtk_toolbar_get_type
> 
> Yes, looks like that.  Strange, since you did say disabling the tool
> bar makes a prominent difference.

A noticeable difference in the speed of (redisplay), as measured by 
benchmark-progn, in the middle of a more complex process.

>> The leaders looked like:
>>
>>     28,52%  emacs         emacs                       [.] mark_object
>>
>>      6,87%  emacs         emacs                       [.] assq_no_quit
>>
>>      3,45%  emacs         emacs                       [.] mark_char_table
>>
>>      3,37%  emacs         emacs                       [.] sweep_strings
>>
>>      2,84%  emacs         emacs                       [.] boyer_moore
> 
> Three out of 5 of the above mean Emacs spends a large proportion of
> the time (35%) doing GC.  I'm not sure I understand why should Emacs
> perform GC while being idle: do you have some timers running, perhaps?
> If this is "emacs -Q", what happens if you disable blink-cursor-mode
> and global-eldoc-mode?

No, I'm not measuring while idle. Like I said, those redisplays are in 
the middle of the "complex" scenario mentioned previously.

Since the code path that calls (redisplay) in Company is only triggered 
when talking to an external process (or, more generally, when the 
backend does something that allows a timer to run), to test this I 
repeatedly exercise completion using an external service, talking to it 
via HTTP/JSON.

>>      0,25%  emacs         emacs                       [.] json_to_lisp
> 
> Any idea why this is here?

...so both JSON decoding and GC being among the hot spots are totally 
expected.

> (I think "perf report" supports output in the form of a call-tree,
> where functions are shown with their callers?  That allows to better
> understand what high-level processing is running in Emacs than just
> looking at the profile sorted by percents.)

Let me know if you still need some of the calls expanded this way.

Re: How to measure frame rate in fps?

[Eli Zaretskii]

> Cc: wyuenho@gmail.com, emacs-devel@gnu.org
> From: Dmitry Gutov <dgutov@yandex.ru>
> Date: Sun, 6 Jun 2021 15:00:50 +0300
> 
> > Three out of 5 of the above mean Emacs spends a large proportion of
> > the time (35%) doing GC.  I'm not sure I understand why should Emacs
> > perform GC while being idle: do you have some timers running, perhaps?
> > If this is "emacs -Q", what happens if you disable blink-cursor-mode
> > and global-eldoc-mode?
> 
> No, I'm not measuring while idle. Like I said, those redisplays are in 
> the middle of the "complex" scenario mentioned previously.

Then I don't see how this is relevant to the issue with the GTK tool
bar making "do-nothing" redisplays more expensive.  The above is a
completely different scenario; depending on what exactly was Emacs
doing in this scenario, redrawing of the GTK tool bar could indeed
account for an insignificant percentage of the CPU time.

> Since the code path that calls (redisplay) in Company is only triggered 
> when talking to an external process (or, more generally, when the 
> backend does something that allows a timer to run), to test this I 
> repeatedly exercise completion using an external service, talking to it 
> via HTTP/JSON.

And what are you trying to investigate or establish with profiling
this scenario?  Maybe I simply don't understand what you wanted to
demonstrate.

> >>      0,25%  emacs         emacs                       [.] json_to_lisp
> > 
> > Any idea why this is here?
> 
> ...so both JSON decoding and GC being among the hot spots are totally 
> expected.

Sure.

Re: How to measure frame rate in fps?

[Dmitry Gutov]

On 06.06.2021 15:36, Eli Zaretskii wrote:

> Then I don't see how this is relevant to the issue with the GTK tool
> bar making "do-nothing" redisplays more expensive.  The above is a
> completely different scenario; depending on what exactly was Emacs
> doing in this scenario, redrawing of the GTK tool bar could indeed
> account for an insignificant percentage of the CPU time.

In my scenario the observable window configuration doesn't change 
between redisplays (though, of course, "current buffer" is switched 
multiple times under the covers, to send request and parse/receive 
response), and the values of point (again, during redisplay), are only 1 
character position apart.

So if there is some caching of the toolbar contents, I don't see why it 
wouldn't work. I'm also not sure how rendering it can take 10-15 extra 
milliseconds, but for all I know this could be normal.

>> Since the code path that calls (redisplay) in Company is only triggered
>> when talking to an external process (or, more generally, when the
>> backend does something that allows a timer to run), to test this I
>> repeatedly exercise completion using an external service, talking to it
>> via HTTP/JSON.
> 
> And what are you trying to investigate or establish with profiling
> this scenario?  Maybe I simply don't understand what you wanted to
> demonstrate.

That toolbar being enabled has a somewhat unexpected effect on redisplay 
performance.

Re: How to measure frame rate in fps?

[Eli Zaretskii]

> Cc: wyuenho@gmail.com, emacs-devel@gnu.org
> From: Dmitry Gutov <dgutov@yandex.ru>
> Date: Sun, 6 Jun 2021 19:48:17 +0300
> 
> On 06.06.2021 15:36, Eli Zaretskii wrote:
> 
> > Then I don't see how this is relevant to the issue with the GTK tool
> > bar making "do-nothing" redisplays more expensive.  The above is a
> > completely different scenario; depending on what exactly was Emacs
> > doing in this scenario, redrawing of the GTK tool bar could indeed
> > account for an insignificant percentage of the CPU time.
> 
> In my scenario the observable window configuration doesn't change 
> between redisplays (though, of course, "current buffer" is switched 
> multiple times under the covers, to send request and parse/receive 
> response), and the values of point (again, during redisplay), are only 1 
> character position apart.

First, that nothing changes on the glass doesn't mean redisplay isn't
working, because it isn't (always) omniscient.

More importantly, I no longer understand what are we discussing.
AFAIU, you have some scenario where Emacs is performing some
non-trivial processing, and where in your opinion redisplay should not
have changed anything on display.  Is that correct?  If so, please
take me from this point and explain what is the issue you see.

> So if there is some caching of the toolbar contents, I don't see why it 
> wouldn't work. I'm also not sure how rendering it can take 10-15 extra 
> milliseconds, but for all I know this could be normal.

The 10-15 milliseconds was measured in a different situation, AFAIU:
an idle "emacs -Q".  Is that correct?

> > And what are you trying to investigate or establish with profiling
> > this scenario?  Maybe I simply don't understand what you wanted to
> > demonstrate.
> 
> That toolbar being enabled has a somewhat unexpected effect on redisplay 
> performance.

I don't think I understand how you conclude this.  I see no traces of
redisplay functions in the profile you have shown.

Re: How to measure frame rate in fps?

[Stefan Monnier]

> So if there is some caching of the toolbar contents, I don't see why it
> wouldn't work. I'm also not sure how rendering it can take 10-15 extra
> milliseconds, but for all I know this could be normal.

Maybe we could get a better picture of what's going on by comparing
profiles with and without toolbar.

But I suspect that the various between profiles is large enough without
any configuration changes that we'd need to compare like 10 profiles
with toolbar against 10 profiles without toolbar before we can start to
(maybe) see a pattern emerge.


        Stefan

Re: How to measure frame rate in fps?

[Dmitry Gutov]

On 06.06.2021 20:19, Eli Zaretskii wrote:
>> Cc: wyuenho@gmail.com, emacs-devel@gnu.org
>> From: Dmitry Gutov <dgutov@yandex.ru>
>> Date: Sun, 6 Jun 2021 19:48:17 +0300
>>
>> On 06.06.2021 15:36, Eli Zaretskii wrote:
>>
>>> Then I don't see how this is relevant to the issue with the GTK tool
>>> bar making "do-nothing" redisplays more expensive.  The above is a
>>> completely different scenario; depending on what exactly was Emacs
>>> doing in this scenario, redrawing of the GTK tool bar could indeed
>>> account for an insignificant percentage of the CPU time.
>>
>> In my scenario the observable window configuration doesn't change
>> between redisplays (though, of course, "current buffer" is switched
>> multiple times under the covers, to send request and parse/receive
>> response), and the values of point (again, during redisplay), are only 1
>> character position apart.
> 
> First, that nothing changes on the glass doesn't mean redisplay isn't
> working, because it isn't (always) omniscient.

Of course.

> More importantly, I no longer understand what are we discussing.
> AFAIU, you have some scenario where Emacs is performing some
> non-trivial processing, and where in your opinion redisplay should not
> have changed anything on display.  Is that correct?  If so, please
> take me from this point and explain what is the issue you see.

I have one scenario, which I run with toolbar disabled, then enabled, 
then disabled, then enabled again. With a (benchmark-progn ...) wrapped 
around a (redisplay) call, to note how long it really takes in practice.

I'm saying that the buffer, or other window configuration, don't change 
at those points, so the toolbar likely doesn't need to be re-rendered, 
and so the extra overhead is surprising. And that the toolbar taking 
10-15ms to re-render isn't great either in any case.

>> So if there is some caching of the toolbar contents, I don't see why it
>> wouldn't work. I'm also not sure how rendering it can take 10-15 extra
>> milliseconds, but for all I know this could be normal.
> 
> The 10-15 milliseconds was measured in a different situation, AFAIU:
> an idle "emacs -Q".  Is that correct?

It's the difference, computed very roughly. Let me show you the contents 
of the Messages buffer. The times printed are reported by the 
(benchmark-progn (redisplay)) form:

Elapsed time: 0.000250s
Elapsed time: 0.020975s
Elapsed time: 0.021575s
Elapsed time: 0.018466s
Elapsed time: 0.019960s
Elapsed time: 0.019763s
Elapsed time: 0.018882s
Elapsed time: 0.017270s
Elapsed time: 0.021255s
Elapsed time: 0.008013s
Elapsed time: 0.027652s
Elapsed time: 0.025234s
Elapsed time: 0.016007s
Elapsed time: 0.020156s
Elapsed time: 0.019670s
Elapsed time: 0.016077s
Elapsed time: 0.009564s
Elapsed time: 0.007729s
Elapsed time: 0.010654s
Elapsed time: 0.015931s
Elapsed time: 0.005864s
Tool-Bar mode enabled
Elapsed time: 0.002618s
Elapsed time: 0.029224s
Elapsed time: 0.012488s
Elapsed time: 0.035648s
Elapsed time: 0.034038s
Elapsed time: 0.029158s
Elapsed time: 0.032658s
Elapsed time: 0.031887s
Elapsed time: 0.034134s
Elapsed time: 0.032638s
Elapsed time: 0.033091s
Elapsed time: 0.033695s
Elapsed time: 0.032838s
Elapsed time: 0.023070s
Elapsed time: 0.033654s
Elapsed time: 0.016566s
Elapsed time: 0.028871s
Elapsed time: 0.012279s
Elapsed time: 0.026500s
Elapsed time: 0.027658s
Elapsed time: 0.032699s
Elapsed time: 0.013483s
Elapsed time: 0.030350s
Elapsed time: 0.030031s
Elapsed time: 0.045297s
Elapsed time: 0.025866s
Elapsed time: 0.032220s
Elapsed time: 0.012934s
Elapsed time: 0.032216s
Elapsed time: 0.031713s
Elapsed time: 0.030811s
Elapsed time: 0.013024s
Elapsed time: 0.032237s
Elapsed time: 0.012812s
Elapsed time: 0.021457s
Elapsed time: 0.025366s
Elapsed time: 0.032519s
Elapsed time: 0.025441s
Elapsed time: 0.031464s
Elapsed time: 0.012804s
Elapsed time: 0.012951s
Elapsed time: 0.034065s
Elapsed time: 0.032018s
Elapsed time: 0.033917s
Elapsed time: 0.030410s
Elapsed time: 0.012490s
Elapsed time: 0.034950s
Elapsed time: 0.032683s
Elapsed time: 0.012379s
Elapsed time: 0.017438s
Elapsed time: 0.036289s
Mark set
Quit
Tool-Bar mode disabled
Elapsed time: 0.000336s
Elapsed time: 0.004768s
Elapsed time: 0.018090s
Elapsed time: 0.016751s
Elapsed time: 0.015772s
Elapsed time: 0.006628s
Elapsed time: 0.017676s
Elapsed time: 0.015837s
Elapsed time: 0.021333s
Elapsed time: 0.019190s
Elapsed time: 0.018478s
Elapsed time: 0.018915s
Elapsed time: 0.014479s
Elapsed time: 0.005889s
Elapsed time: 0.022493s
Elapsed time: 0.011403s
Elapsed time: 0.011022s
Elapsed time: 0.020275s
Elapsed time: 0.006469s
Elapsed time: 0.019499s
Elapsed time: 0.005800s
Elapsed time: 0.004827s
Elapsed time: 0.008394s
Elapsed time: 0.029546s
Elapsed time: 0.007446s
Elapsed time: 0.008475s
Elapsed time: 0.008290s
Elapsed time: 0.000402s
Elapsed time: 0.004851s
Elapsed time: 0.019022s
Elapsed time: 0.020623s
Elapsed time: 0.005188s
Elapsed time: 0.021102s
Elapsed time: 0.019203s
Elapsed time: 0.005724s
Elapsed time: 0.019243s
Elapsed time: 0.018614s
Elapsed time: 0.021920s
Elapsed time: 0.019716s
Tool-Bar mode enabled
Elapsed time: 0.002532s
Elapsed time: 0.013393s
Elapsed time: 0.011731s
Elapsed time: 0.033731s
Elapsed time: 0.012756s
Elapsed time: 0.030029s
Elapsed time: 0.011511s
Elapsed time: 0.033465s
Elapsed time: 0.022545s
Elapsed time: 0.023758s
Elapsed time: 0.019158s
Elapsed time: 0.015410s
Elapsed time: 0.039764s
Elapsed time: 0.034458s
Elapsed time: 0.033955s
Elapsed time: 0.029793s
Elapsed time: 0.016531s
Elapsed time: 0.034445s
Elapsed time: 0.024124s
Elapsed time: 0.029344s
Elapsed time: 0.016216s
Elapsed time: 0.031835s
Elapsed time: 0.018600s
Elapsed time: 0.026698s
Elapsed time: 0.013067s
Elapsed time: 0.029260s
Elapsed time: 0.029213s
Elapsed time: 0.013516s
Elapsed time: 0.032331s
Quit [2 times]

Re: How to measure frame rate in fps?

[Dmitry Gutov]

On 06.06.2021 21:10, Stefan Monnier wrote:
>> So if there is some caching of the toolbar contents, I don't see why it
>> wouldn't work. I'm also not sure how rendering it can take 10-15 extra
>> milliseconds, but for all I know this could be normal.
> 
> Maybe we could get a better picture of what's going on by comparing
> profiles with and without toolbar.

That's what I have been comparing.

I can try and produce the corresponding pref recordings. Will that 
really help? Do I post them raw?

> But I suspect that the various between profiles is large enough without
> any configuration changes that we'd need to compare like 10 profiles
> with toolbar against 10 profiles without toolbar before we can start to
> (maybe) see a pattern emerge.

My current reproduction scenario itself is fairly heavy, so it's no 
surprise if the functions are not at the top of the list.

Re: How to measure frame rate in fps?

[Eli Zaretskii]

> Cc: wyuenho@gmail.com, emacs-devel@gnu.org
> From: Dmitry Gutov <dgutov@yandex.ru>
> Date: Mon, 7 Jun 2021 02:31:50 +0300
> 
> I have one scenario, which I run with toolbar disabled, then enabled, 
> then disabled, then enabled again. With a (benchmark-progn ...) wrapped 
> around a (redisplay) call, to note how long it really takes in practice.
> 
> I'm saying that the buffer, or other window configuration, don't change 
> at those points, so the toolbar likely doesn't need to be re-rendered, 
> and so the extra overhead is surprising. And that the toolbar taking 
> 10-15ms to re-render isn't great either in any case.

But in the profile you showed we didn't see any evidence of
significant CPU usage by functions that redraw the GTK toolbar.  So
I'm not sure the overhead is due to redrawing the toolbar, although it
might be _triggered_ by the presence of the toolbar.

> It's the difference, computed very roughly. Let me show you the contents 
> of the Messages buffer. The times printed are reported by the 
> (benchmark-progn (redisplay)) form:

How do you reconcile this with the 00.00% that GTK functions took?

Can you see what does 'perf' say about functions from gtkutil.c that
are related to toolbar redisplay?