Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Stefan Monnier]

>     Speed up loaddefs-generate on slow disks
[...]
> @@ -522,11 +522,15 @@ If INCLUDE-PACKAGE-VERSION, include package version data."
>                       (byte-compile-info
>                        (concat "Scraping files for loaddefs"))
>                       0 (length files) nil 10))
> +          (output-time
> +           (file-attribute-modification-time (file-attributes output-file)))
>            (file-count 0))
>        (dolist (file files)
>          (progress-reporter-update progress (setq file-count (1+ file-count)))
>          (when (or (not updating)
> -                  (file-newer-than-file-p file output-file))
> +                  (time-less-p output-time
> +                               (file-attribute-modification-time
> +                                (file-attributes file))))
>            (setq defs (nconc
>  		      (loaddefs-generate--parse-file
>                         file output-file

I'm really surprised this is faster, even on slow disks.
Does anyone have a idea of why that is?

Maybe `file-newer-than-file-p` should accept a time value for one of the
two file names so we can speed this up further by refraining from
constructing a whole `file-attributes` only to reduce it down to
a single boolean?


        Stefan

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Stefan Monnier <monnier@iro.umontreal.ca> writes:

> I'm really surprised this is faster, even on slow disks.
> Does anyone have a idea of why that is?

I didn't actually benchmark it -- either way is fast on my laptop.  But
the old autoloads code did it with time-less-p, and Eli said that it was
faster, so...  Perhaps Eli can report back whether it made a difference
or not.

> Maybe `file-newer-than-file-p` should accept a time value for one of the
> two file names so we can speed this up further by refraining from
> constructing a whole `file-attributes` only to reduce it down to
> a single boolean?

There's a longer discussion about these issues (i.e., reworking the
functions in this area to be more efficient in these respects) in the
bug tracker somewhere.  Paul had a bunch of ideas that I think we should
pursue.  I forget which bug# -- perhaps Paul remembers; added to the CCs.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Eli Zaretskii]

> From: Lars Ingebrigtsen <larsi@gnus.org>
> Cc: emacs-devel@gnu.org, Paul Eggert <eggert@cs.ucla.edu>
> Date: Thu, 02 Jun 2022 17:20:43 +0200
> 
> Stefan Monnier <monnier@iro.umontreal.ca> writes:
> 
> > I'm really surprised this is faster, even on slow disks.
> > Does anyone have a idea of why that is?

Isn't that clear?  file-newer-than-file-p calls 'stat' for both files,
and one of them is a loop invariant AFAIU.  Taking its time outside
the loop speeds up things (but perhaps not on GNU/Linux).

> I didn't actually benchmark it -- either way is fast on my laptop.  But
> the old autoloads code did it with time-less-p, and Eli said that it was
> faster, so...  Perhaps Eli can report back whether it made a difference
> or not.

It did -- for the better.  Thanks.

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Eli Zaretskii]

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: Lars Ingebrigtsen <larsi@gnus.org>
> Date: Thu, 02 Jun 2022 11:10:32 -0400
> 
> Maybe `file-newer-than-file-p` should accept a time value for one of the
> two file names so we can speed this up further

Yes, I think that would be good.

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Stefan Monnier]

Eli Zaretskii [2022-06-02 19:16:00] wrote:
>> > I'm really surprised this is faster, even on slow disks.
>> > Does anyone have a idea of why that is?
> Isn't that clear?  file-newer-than-file-p calls 'stat' for both files,
> and one of them is a loop invariant AFAIU.  Taking its time outside
> the loop speeds up things (but perhaps not on GNU/Linux).

Under GNU/Linux, I'd expect `stat` to be significantly faster than
`file-attributes` (and the extra `stat` on the loop-invariant file
should be especially fast since it should be as close as it gets w.r.t
the caches (both OS-level and CPU-level)).

>> I didn't actually benchmark it -- either way is fast on my laptop.  But
>> the old autoloads code did it with time-less-p, and Eli said that it was
>> faster, so...  Perhaps Eli can report back whether it made a difference
>> or not.
> It did -- for the better.  Thanks.

This suggests that the kind of change I suggested would make it even
a bit faster, tho it should reduce the run time by less than 50%
under Windows (because the time to do the `stat`s is apparently already
>50% of the total).


        Stefan

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Eli Zaretskii]

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: Lars Ingebrigtsen <larsi@gnus.org>,  emacs-devel@gnu.org,
>   eggert@cs.ucla.edu
> Date: Thu, 02 Jun 2022 21:18:57 -0400
> 
> Eli Zaretskii [2022-06-02 19:16:00] wrote:
> >> > I'm really surprised this is faster, even on slow disks.
> >> > Does anyone have a idea of why that is?
> > Isn't that clear?  file-newer-than-file-p calls 'stat' for both files,
> > and one of them is a loop invariant AFAIU.  Taking its time outside
> > the loop speeds up things (but perhaps not on GNU/Linux).
> 
> Under GNU/Linux, I'd expect `stat` to be significantly faster than
> `file-attributes` (and the extra `stat` on the loop-invariant file
> should be especially fast since it should be as close as it gets w.r.t
> the caches (both OS-level and CPU-level)).

Yes, when 'stat' is a syscall.  On Windows, we issue at least 6
syscalls, more so if the file is on a networked volume.

> >> I didn't actually benchmark it -- either way is fast on my laptop.  But
> >> the old autoloads code did it with time-less-p, and Eli said that it was
> >> faster, so...  Perhaps Eli can report back whether it made a difference
> >> or not.
> > It did -- for the better.  Thanks.
> 
> This suggests that the kind of change I suggested would make it even
> a bit faster, tho it should reduce the run time by less than 50%
> under Windows (because the time to do the `stat`s is apparently already
> >50% of the total).

I don't know how you deduce the 50% figure.  Look at w32.c:stat_worker
to see what we do on Windows to faithfully emulate 'stat' -- I have no
idea how this compares with the time required to cons a Lisp data
structure from the data, but it can well be that consing is much
faster.  The only sure way is to benchmark both alternatives.

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Stefan Monnier]

>> This suggests that the kind of change I suggested would make it even
>> a bit faster, tho it should reduce the run time by less than 50%
>> under Windows (because the time to do the `stat`s is apparently already
>> >50% of the total).
>
> I don't know how you deduce the 50% figure.

The old code performed 2*N `stat`s.
The new current code performs N times `time-less-p` and
`file-attributes`, which is N `stat`s plus N times some overhead.
The proposed new functionality would reduce this to more or less just
N `stat`s so it would save us the "some overhead".

Because the old code is slower than the current code, we know that

    2*stat > stat + overhead

thus `stat > overhead`.  So `overhead` is less than 50% of `stat + overhead`.


        Stefan

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Eli Zaretskii]

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: larsi@gnus.org,  emacs-devel@gnu.org,  eggert@cs.ucla.edu
> Date: Fri, 03 Jun 2022 08:21:32 -0400
> 
> >> This suggests that the kind of change I suggested would make it even
> >> a bit faster, tho it should reduce the run time by less than 50%
> >> under Windows (because the time to do the `stat`s is apparently already
> >> >50% of the total).
> >
> > I don't know how you deduce the 50% figure.
> 
> The old code performed 2*N `stat`s.
> The new current code performs N times `time-less-p` and
> `file-attributes`, which is N `stat`s plus N times some overhead.
> The proposed new functionality would reduce this to more or less just
> N `stat`s so it would save us the "some overhead".
> 
> Because the old code is slower than the current code, we know that
> 
>     2*stat > stat + overhead
> 
> thus `stat > overhead`.  So `overhead` is less than 50% of `stat + overhead`.

You evidently assume something about "the change you suggested",
because it is not just trivial modifications of what we do now: it
will have new "overhead" that is not part of the existing "overhead".

So it is still a guess in my eyes, and guesses related to CPU
profiles are many times wrong.

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Stefan Monnier]

> You evidently assume something about "the change you suggested",
> because it is not just trivial modifications of what we do now: it
> will have new "overhead" that is not part of the existing "overhead".

All I'm saying is that the part that we may gain is (apparently, under
Windows) at most 50%.  That still leaves open the possibility that it
ends up making the code slower :-)


        Stefan

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Eli Zaretskii]

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: larsi@gnus.org,  emacs-devel@gnu.org,  eggert@cs.ucla.edu
> Date: Fri, 03 Jun 2022 09:09:48 -0400
> 
> > You evidently assume something about "the change you suggested",
> > because it is not just trivial modifications of what we do now: it
> > will have new "overhead" that is not part of the existing "overhead".
> 
> All I'm saying is that the part that we may gain is (apparently, under
> Windows) at most 50%.

Ah, okay.  I agree with "at most 50%".

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

[-- Attachment #1: Type: text/plain, Size: 646 bytes --]

It was suggested that it might be interesting to see how our build times
have developed over time, so I had my build machine run a "make
bootstrap" each Monday going back to 2018 with this snappy one liner:

d=0; while [ $d -lt 1400 ]; do dat=`date -u -d "last Monday - $d days"`; git checkout master; git checkout `git rev-list -1 --before="$dat" HEAD`; git clean -xf;  echo $dat >> /tmp/clog; { time make -j32 2>/dev/null ; }  2>>/tmp/clog; d=$(($d + 7)); done

I ran this three times and picked the median build time for each date,
and viola:  https://quimby.gnus.org/circus/stats-emacs/build-times.html

Or if you prefer it in picture form:


[-- Attachment #2: Type: image/png, Size: 84237 bytes --]

[-- Attachment #3: Type: text/plain, Size: 313 bytes --]


This is with -j32, so it's quite susceptible to perturbations depending
on whether somebody did something to make the Makefile more or less
multithreaded.  Which mostly explains the sudden dip at the end there,
because the build is now more parallel than ever.  So it's useful to
compare with actual CPU usage:


[-- Attachment #4: Type: image/png, Size: 86878 bytes --]

[-- Attachment #5: Type: text/plain, Size: 657 bytes --]


Which is less noisy and perhaps tells us more.

Now, it's natural for Emacs build times to creep up (one might think),
as we're adding more...  stuff.  But there's discontinuities in the
chart, and I think we can say that something happened in the weeks
before Feb 7 2019, Sep 5 2019, May 26 2021, Feb 24 2022 and Apr 7 2022
that might be useful to look into.  (Zooming on the chart on the web
page gives you the dates, if somebody wants to investigate.  And also
why it seems like we're oscillating between 930 and 1150 seconds the
past few months.)

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Lars Ingebrigtsen <larsi@gnus.org> writes:

>> Maybe `file-newer-than-file-p` should accept a time value for one of the
>> two file names so we can speed this up further by refraining from
>> constructing a whole `file-attributes` only to reduce it down to
>> a single boolean?
>
> There's a longer discussion about these issues (i.e., reworking the
> functions in this area to be more efficient in these respects) in the
> bug tracker somewhere.  Paul had a bunch of ideas that I think we should
> pursue.  I forget which bug# -- perhaps Paul remembers; added to the CCs.

It's bug#55163, but to recap shortly (hehe) for new readers:

Our time functions return time values on a very inefficient format (a
four-element list), and we want to move (long term) to a more efficient
format (which is a single cons cell).  But we can't just change the
output from our current time functions, because that breaks a lot of
callers.  But we can introduce new functions that only return the
efficient format.

My point in bug#55163 is that we should see this as an opportunity to
overhaul functions in this area in general, and `file-attributes' is one
of those.  For instance, we could have a new function `file-attribute'
where you specify the data you actually want, like
(file-attribute file :modtime), and it'd just return that value.  (Or
more values if you say (file-attribute file :modtime :directoryp) etc.)

If we had that, our loop here would have been

(time-less-p output-time (file-attribute file :modtime))

and it would be maximally fast and efficient.

So I don't think we should touch `file-newer-than-file-p' in any way,
but instead wait for this new set of functions (which should be created
in one go so that everything fits together, and not piecemeal).

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Mattias Engdegård]

4 juni 2022 kl. 14.30 skrev Lars Ingebrigtsen <larsi@gnus.org>:

> I ran this three times and picked the median build time for each date,
> and viola:  https://quimby.gnus.org/circus/stats-emacs/build-times.html

Thank you! I picked a few edges that looked like transitions to a higher plateau and tried to find the culprit in the logs, but it's really hard. There are many commits and nothing obvious stands out.

Things that might make it easier (speculating here):

* add commit hashes to the points in the graphs because Git dates are a bit ambiguous: are they author or commit date, what time of day are we talking about, what time zone, etc
* higher resolutions for selected periods (requires more build runs). Ideally one per commit but that would require vast amounts of time and be very noisy (many botched builds), but perhaps one per day?

I'm ashamed to admit that I looked for effects of my own attempts at speeding things up, but they were so intermingled with other changes that hard conclusions were difficult. (Mattias giveth, Alan taketh away.)

It would be very useful if we could have an automatic (or semi-automatic) daily build monitoring performance like this, perhaps even running benchmarks.

Selecting good benchmarks is hard; the elisp-benchmarks in ELPA were made by Andrea for his compilation efforts and are nigh-useless for anything else, unfortunately. I've written my own suites but again they are only useful for what measuring very specific aspects.

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Mattias Engdegård <mattiase@acm.org> writes:

> Thank you! I picked a few edges that looked like transitions to a
> higher plateau and tried to find the culprit in the logs, but it's
> really hard. There are many commits and nothing obvious stands out.

Darn.

> Things that might make it easier (speculating here):
>
> * add commit hashes to the points in the graphs because Git dates are
> a bit ambiguous: are they author or commit date, what time of day are
> we talking about, what time zone, etc

I don't know either, really, but my loop is basically doing:

git checkout `git rev-list -1 --before="Mon 30 May 2022 12:00:00 AM UTC" HEAD`

And I don't think that's ambiguous for git -- it'll check out the same
revision every time, I think?  But I may well be wrong.

> * higher resolutions for selected periods (requires more build
> runs). Ideally one per commit but that would require vast amounts of
> time and be very noisy (many botched builds), but perhaps one per day?

I can do that, but it'll take one week to run for the same time period
(since I need to run each day three times to pick a median build time --
otherwise it's too noisy).

But perhaps I could run it daily in periods of specific interest?

> It would be very useful if we could have an automatic (or
> semi-automatic) daily build monitoring performance like this, perhaps
> even running benchmarks.

Yes, indeed.  But the build servers we have seem to struggle with
building Emacs even normally -- they seem to be woefully
under-provisioned, and I'd guess that any timing data from them would
just be noise.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Mattias Engdegård <mattiase@acm.org> writes:

> I picked a few edges that looked like transitions to a
> higher plateau and tried to find the culprit in the logs, but it's
> really hard.

What made it even harder was that my dates in the plot were one month
off.  😠  I'd forgotten that JS months start at 0, not 1; sorry.

So I've now corrected that, and I've also run the build daily for the
last three months:

  https://quimby.gnus.org/circus/stats-emacs/build-times.html

Which makes the oscillation between 120/140 seconds build time over the
last few months even more obvious.

Bizarrely enough, the CPU time seems to be oscillating in inverse?  

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Alan Mackenzie]

Hello, Lars.

On Mon, Jun 06, 2022 at 13:26:14 +0200, Lars Ingebrigtsen wrote:
> Mattias Engdegård <mattiase@acm.org> writes:

> > I picked a few edges that looked like transitions to a
> > higher plateau and tried to find the culprit in the logs, but it's
> > really hard.

> What made it even harder was that my dates in the plot were one month
> off.  😠  I'd forgotten that JS months start at 0, not 1; sorry.

> So I've now corrected that, and I've also run the build daily for the
> last three months:

>   https://quimby.gnus.org/circus/stats-emacs/build-times.html

I get just a blank page, there.  It seems the data can only be seen with
the use of non-free javascript, and that from Google.  Such javascript
doesn't run on my machine.  Is this really a good way to present data?

> Which makes the oscillation between 120/140 seconds build time over the
> last few months even more obvious.

> Bizarrely enough, the CPU time seems to be oscillating in inverse?  

> -- 
> (domestic pets only, the antidote for overdose, milk.)
>    bloggy blog: http://lars.ingebrigtsen.no

-- 
Alan Mackenzie (Nuremberg, Germany).

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Alan Mackenzie <acm@muc.de> writes:

> I get just a blank page, there.  It seems the data can only be seen with
> the use of non-free javascript, and that from Google.  Such javascript
> doesn't run on my machine.  Is this really a good way to present data?

I posted images previously in this thread exactly for that reason.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> Which makes the oscillation between 120/140 seconds build time over the
> last few months even more obvious.
>
> Bizarrely enough, the CPU time seems to be oscillating in inverse?  

It seems like "git clean -xf" doesn't clean ignored files, despite the
manual saying that it does?  At least there's a whole bunch of files
left over in the Emacs directory after running it.

So I'm re-running these benchmarks from a fresh checkout each time.  New
charts incoming in 24 hours.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Mattias Engdegård]

6 juni 2022 kl. 14.08 skrev Lars Ingebrigtsen <larsi@gnus.org>:

> It seems like "git clean -xf" doesn't clean ignored files, despite the
> manual saying that it does?  At least there's a whole bunch of files
> left over in the Emacs directory after running it.
> 
> So I'm re-running these benchmarks from a fresh checkout each time.  New
> charts incoming in 24 hours.

Thank you! Would it be possible to get commit hashes in the resulting data?
And the data in table form (TSV, CSV etc)?

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Andreas Schwab]

On Jun 06 2022, Lars Ingebrigtsen wrote:

> It seems like "git clean -xf" doesn't clean ignored files, despite the
> manual saying that it does?  At least there's a whole bunch of files
> left over in the Emacs directory after running it.

Try git clean -dfx.

-- 
Andreas Schwab, schwab@linux-m68k.org
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510  2552 DF73 E780 A9DA AEC1
"And now for something completely different."

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Andreas Schwab <schwab@linux-m68k.org> writes:

> Try git clean -dfx.

Thanks; that made /info/* finally go away.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Mattias Engdegård <mattiase@acm.org> writes:

> Thank you! Would it be possible to get commit hashes in the resulting data?
> And the data in table form (TSV, CSV etc)?

Sure; restarted it now and logging the commit hashes, too.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: master afc0bfd380: Speed up loaddefs-generate on slow disks

[Lars Ingebrigtsen]

Mattias Engdegård <mattiase@acm.org> writes:

>> So I'm re-running these benchmarks from a fresh checkout each time.  New
>> charts incoming in 24 hours.
>
> Thank you! Would it be possible to get commit hashes in the resulting data?
> And the data in table form (TSV, CSV etc)?

It took a bit longer, but I've now regenerated the data, and new charts
are here:

https://quimby.gnus.org/circus/stats-emacs/build-times.html

And the data is here:

https://quimby.gnus.org/circus/stats-emacs/build-times.csv

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no