Timings for 'make check' with and without symbols with position

Timings for 'make check' with and without symbols with position

[Alan Mackenzie]

Hello Emacs.

I'm starting a new thread about this, since the old one (Subject: Time
to merge scratch/correct-warning-pos into master, perhaps?) has become
long, and we've drifted from the original topic.

Using perf, I've measured the difference in run time for 'make check'
between two comparable versions of Emacs, one with symbols with
position ("new"), the other without ("old").  They were both built
without native compilation, and their configurations were identical.
'make check' had already been run once, to compile (almost) all of the
test .elc files.

Short summary: The new build is slower than the old by 12.6%.  perf
counted 419k samples on the new, 372k samples on the old.

What is taking the extra time is largely the garbage collection:  I
filtered perf's output successively for the strings "mark" and "sweep",
and include those functions with at least 0.1% of the run time.

For "old":
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 20.38%  emacs     emacs              [.] mark_object
  3.36%  emacs     emacs              [.] pdumper_marked_p_impl
  2.98%  emacs     emacs              [.] mark_char_table
  1.22%  emacs     emacs              [.] pdumper_set_marked_impl
  1.03%  emacs     emacs              [.] mark_vectorlike
  0.28%  emacs     emacs              [.] mark_compiled
  0.11%  emacs     emacs              [.] mark_interval_tree_1

  0.80%  emacs  emacs  [.] sweep_strings
  0.69%  emacs  emacs  [.] sweep_conses
  0.32%  emacs  emacs  [.] sweep_vectors
  0.12%  emacs  emacs  [.] sweep_intervals
--------
 31.29%  total
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;

For "new":
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 23.17%  emacs  emacs         [.] mark_object
  3.97%  emacs  emacs         [.] pdumper_marked_p_impl
  3.79%  emacs  emacs         [.] mark_char_table
  1.46%  emacs  emacs         [.] pdumper_set_marked_impl
  1.22%  emacs  emacs         [.] mark_vectorlike
  0.32%  emacs  emacs         [.] mark_compiled

  0.76%  emacs  emacs  [.] sweep_strings
  0.66%  emacs  emacs  [.] sweep_conses
  0.42%  emacs  emacs  [.] sweep_vectors
  0.10%  emacs  emacs  [.] sweep_intervals
--------
 35.87%  total
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;

Increasing the new build's 35.87% by 12.6%, to give a fair comparison
with the old build, gives us 40.40%.  More precisely, the new build's
garbage collection took 40.40% of the old build's run time.

Thus garbage collection accounts for 40.40% - 31.29% = 9.11% of the
12.6% difference between the old and new builds.

Clearly, any attempt to speed up the new build will involve optimising
the garbage collection somehow.

-- 
Alan Mackenzie (Nuremberg, Germany).

Re: Timings for 'make check' with and without symbols with position

[Eli Zaretskii]

> Date: Sat, 26 Feb 2022 16:39:05 +0000
> Cc: David Engster <deng@randomsample.de>, Eli Zaretskii <eliz@gnu.org>,
>   larsi@gnus.org, mattiase@acm.org, gregory@heytings.org,
>   Óscar Fuentes <ofv@wanadoo.es>
> From: Alan Mackenzie <acm@muc.de>
> 
> Short summary: The new build is slower than the old by 12.6%.  perf
> counted 419k samples on the new, 372k samples on the old.
> 
> What is taking the extra time is largely the garbage collection:  I
> filtered perf's output successively for the strings "mark" and "sweep",
> and include those functions with at least 0.1% of the run time.

Thanks.  Any idea why there will be more GC in the new version?  Or
are you saying the number of GC calls was the same, but each GC cycle
took a bit longer?  If so, how does symbols-with-pos affect GC?

Re: Timings for 'make check' with and without symbols with position

[Alan Mackenzie]

Hello, Eli.

On Sat, Feb 26, 2022 at 18:55:06 +0200, Eli Zaretskii wrote:
> > Date: Sat, 26 Feb 2022 16:39:05 +0000
> > Cc: David Engster <deng@randomsample.de>, Eli Zaretskii <eliz@gnu.org>,
> >   larsi@gnus.org, mattiase@acm.org, gregory@heytings.org,
> >   Óscar Fuentes <ofv@wanadoo.es>
> > From: Alan Mackenzie <acm@muc.de>
> > 
> > Short summary: The new build is slower than the old by 12.6%.  perf
> > counted 419k samples on the new, 372k samples on the old.
> > 
> > What is taking the extra time is largely the garbage collection:  I
> > filtered perf's output successively for the strings "mark" and "sweep",
> > and include those functions with at least 0.1% of the run time.

> Thanks.  Any idea why there will be more GC in the new version?

Char-tables seem to have something to do with it.  The perf output for
mark_char_table increase from 2.98% to 3.79%.  Adding the 12.6% factor
onto the 3.79% gives us 4.27%.  That's a factor of ~1.5 increase.

I'm still slogging through the detailed output for mark_char_table,
which is not easy in the optimised build.  I suspect that somehow,
somewhere, symbols with position have got themselves into a char-table,
and they take (a lot) longer to process than bare symbols (for which
mark_char_table is optimised).  I've not yet managed to find such a
char-table though.

> Or are you saying the number of GC calls was the same, but each GC
> cycle took a bit longer?

I've tried to get an output of gcs-done at the end of the batch emacs
invocation in make check, but not yet managed it.  Maybe later.

> If so, how does symbols-with-pos affect GC?

I don't yet have a hypothesis for this.

-- 
Alan Mackenzie (Nuremberg, Germany).

Re: Timings for 'make check' with and without symbols with position

[Eli Zaretskii]

> Date: Sun, 27 Feb 2022 12:15:14 +0000
> From: Alan Mackenzie <acm@muc.de>
> Cc: ofv@wanadoo.es, deng@randomsample.de, mattiase@acm.org, emacs-devel@gnu.org,
>  gregory@heytings.org, larsi@gnus.org
> 
> Char-tables seem to have something to do with it.  The perf output for
> mark_char_table increase from 2.98% to 3.79%.  Adding the 12.6% factor
> onto the 3.79% gives us 4.27%.  That's a factor of ~1.5 increase.
> 
> I'm still slogging through the detailed output for mark_char_table,
> which is not easy in the optimised build.  I suspect that somehow,
> somewhere, symbols with position have got themselves into a char-table,
> and they take (a lot) longer to process than bare symbols (for which
> mark_char_table is optimised).  I've not yet managed to find such a
> char-table though.

We do have a few char-tables whose slots are symbols or include
symbols.  unicode-category-table is one, for example;
composition-function-table is another.

Thanks for working on this.

Re: Timings for 'make check' with and without symbols with position

[Alan Mackenzie]

Hello, Eli.

On Sun, Feb 27, 2022 at 14:34:24 +0200, Eli Zaretskii wrote:
> > Date: Sun, 27 Feb 2022 12:15:14 +0000
> > From: Alan Mackenzie <acm@muc.de>
> > Cc: ofv@wanadoo.es, deng@randomsample.de, mattiase@acm.org, emacs-devel@gnu.org,
> >  gregory@heytings.org, larsi@gnus.org

> > Char-tables seem to have something to do with it.  The perf output for
> > mark_char_table increase from 2.98% to 3.79%.  Adding the 12.6% factor
> > onto the 3.79% gives us 4.27%.  That's a factor of ~1.5 increase.

> > I'm still slogging through the detailed output for mark_char_table,
> > which is not easy in the optimised build.  I suspect that somehow,
> > somewhere, symbols with position have got themselves into a char-table,
> > and they take (a lot) longer to process than bare symbols (for which
> > mark_char_table is optimised).  I've not yet managed to find such a
> > char-table though.

> We do have a few char-tables whose slots are symbols or include
> symbols.  unicode-category-table is one, for example;
> composition-function-table is another.

I've instrumented mark_char_table to try and detect symbols with
position, but got no hits.

I similarly instrumented mark_vectorlike, but the only hits I got there
seemed to be when a compilation was in progress.

So elucidation eludes me, so far.  I'll need to look at it in some other
fashion (suggestions welcome).

-- 
Alan Mackenzie (Nuremberg, Germany).