Re: Time to merge scratch/correct-warning-pos into master, perhaps?

[Alan Mackenzie <acm@muc.de>]

Hello, David.

On Sun, Feb 20, 2022 at 06:35:25 +0100, David Engster wrote:
> > I seem to have a default setting of 4kHz.  This was enough to get several
> > thousand hits in each build ("old" and "new") running the test suite.  As
> > I wrote in my post just now to Eli, the results came up contrary to what
> > was expected - the "old" build, running the simple EQ spent more time in
> > it than the "new" build running the complicated EQ.  Possibly I've made
> > some silly mistake in the measurements.

> Hi Alan,

> Are you comparing builds directly before/after the merge of the
> correct-warnings branch?

Yes.

> The first thing to check would be if EQ is actually called the same
> amount of times in both builds. You can do this with 'perf' by using
> user-space probes ('uprobes'). Just as an example, with './emacs'
> being your emacs binary,

>   perf probe -x ./emacs redisplay

> would insert a uprobe at redisplay, and with

>   perf record -e probe_emacs:redisplay ./emacs

> you can save the events. Just to show how flexible this system is:

>   perf stat -e probe_emacs:redisplay -a -I 1000

> would continuously show you the number of times redisplay is called each
> second.

I tried that with EQ on the new build.  I aborted the run when perf.data
had reached 29 GB.  ;-).  I then tried again with just making
test/lisp/calc/calc-tests.log.  That gave a file around 1 GB, which gave
me the number of times EQ was called.

Then I temporarily lost interest.  I'll try the same on the old build
soon.

> Anyway, measuring things around ~1% with perf can be quite noisy. For
> doing exact timings, you can also insert 'uretprobes' which are called
> when a function returns, and then you can calculate how long each call
> took from the timestamps. In the above example,

>    perf probe -x ./emacs 'redisplay%return'

> will insert a return probe for 'redisplay', then use

>    perf record -e 'probe_emacs:*' ./emacs

> and use 'perf script' to display the timestamps.

Maybe I'll try that later.

> I don't think there's something built-in to display durations between
> uprobe/uretprobe, so a little bit of coding is needed to calculate
> that from the output. Of course, these timings will usually be
> increased by the probe instrumentations, but for relative comparisons,
> they should be fine.

Thanks!

> -David

-- 
Alan Mackenzie (Nuremberg, Germany).