Subject: Re: bug#49421: [PATCH] profiles: Optimise 'fonts-dir-file'.

From: Maxime Devos <[email-masked]>
Date: Thu, 15 Jul 2021 18:28:16 +0200

Ludovic Courtès schreef op wo 07-07-2021 om 18:52 [+0200]:
> Hi,
> 
> Maxime Devos <[email-masked]> skribis:
> 
> > These two patches should speed up profile generation
> > by optimising the 'fonts-dir-file' hook.  The first patch
> > is the most important; from the commit message:
> > 
> > ‘Only let the build G-exp refer to inputs that might actually
> > have fonts.  That way, if the list of fonts in the manifest
> > didn't change and the new manifest is built, the font files
> > will not be rebuilt.’
> > 
> > The second patch doesn't bring much.
> > 
> > To test, you can test whether things like ...
> > 
> > $ ./pre-inst-env guix environment --ad-hoc --pure lagrange -- lagrange
> > 
> > still work (lagrange is a graphical application using fonts).
> > Not sure what a good ‘benchmark’ would be.
> > 
> > Unfortunately, this does not help with the "guix package -i" case,
> > as in that case, the code doesn't have access to all the package objects,
> > and will have to satisfy itself with the store paths, in which case the
> > profile code pessimistically assumes the store item has fonts ...
> > 
> > I suppose this restriction could be lifted if/when the gs-fonts package
> > is renamed to font-ghostscript or something like that ...
> 
> Do you know what’s taking time in the ‘fonts-dir-file’ hook?
> (On my x86_64 laptop with SSD, it runs in 4.4s on a cold cache for a
> profile containing 14 font packages, and in 1.2s on a warm cache.)

I noticed ‘building fonts directories’ was taking long (9 minutes or so,
when using "guix package -r two packages that don't have fonts"),
so I took the opportunity to "strace" the process, though I was a little late.
Some statistics:

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 27,14    1,676551         117     14297           rename
 19,60    1,211012          13     90829         8 lstat
 18,34    1,133182          63     17787        15 statx
 11,80    0,729185          51     14297           link
  6,65    0,411065       68510         6           wait4
  5,08    0,313632          10     28651           chmod
  3,66    0,226258          14     15114           readlink
  2,18    0,134913           8     15193           utimensat
  1,78    0,110257          32      3431           rmdir
  0,91    0,056504           7      7370           getdents64
  0,82    0,050817           3     14295           getpid
  0,47    0,029074           7      3736           openat
  0,46    0,028547           8      3479      3428 unlink
  0,36    0,021940           5      3747           close
  0,26    0,016355           4      3704           fstat
  0,16    0,009752          10       898           lchown
  0,12    0,007242           4      1800           geteuid
  0,07    0,004203          62        67           read
  0,06    0,003512           3       900           getegid
  0,03    0,001959         326         6           clone
  0,02    0,001133          18        62           write
  0,01    0,000488           3       127         1 fcntl
  0,01    0,000451           3       136           lseek
  0,00    0,000197          14        14           mkdir
  0,00    0,000065          13         5           select
  0,00    0,000045           5         8           chown
  0,00    0,000044           7         6           brk
  0,00    0,000027          13         2           munmap
  0,00    0,000023          11         2           pipe
  0,00    0,000013           6         2           stat
  0,00    0,000007           7         1           futex
  0,00    0,000004           2         2           getuid
  0,00    0,000000           0         1           rt_sigreturn
------ ----------- ----------- --------- --------- ----------------
100,00    6,178457          25    239975      3452 total

And a part of the log:

<start of log>
lstat("/gnu/store/.links/[...]2i", {st_mode=S_IFLNK|0777, st_size=124, ...}) = 0
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", {st_mode=S_IFDIR|0555, st_size=4112, ...>
chmod("/gnu/store/[..]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", 040755) = 0
getpid()                                = 26371
link("/gnu/store/.links/[..]2i", "/gnu/store/.tmp-link-26371-632297102") = 0
rename("/gnu/store/.tmp-link-26371-632297102", "/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/2>
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", {st_mode=S_IFDIR|0755, st_size=4112, ...>
chmod("/gnu/store/[...]-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", 040555) = 0
utimensat(AT_FDCWD, "/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", [{tv_sec=1626363034, tv_ns>
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/2223.png", {st_mode=S_IFLNK|0777, st_size=>
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/2223.png", {st_mode=S_IFLNK|0777, st_size=>
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/2223.png", {st_mode=S_IFLNK|0777, st_size=>
readlink("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/2223.png", "/gnu/store/bf582s56ldb3y34p>
statx(AT_FDCWD, "/gnu/store/.links/[...]v3", AT_STATX_SYNC_AS_STAT|AT_SYMLINK_NOFOLLOW, 0, {stx_mask=STATX_ALL|>
lstat("/gnu/store/.links/[...]v3", {st_mode=S_IFLNK|0777, st_size=124, ...}) = 0
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", {st_mode=S_IFDIR|0555, st_size=4112, ...>
chmod("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", 040755) = 0
getpid()                                = 26371
link("/gnu/store/.links/[...]v3", "/gnu/store/.tmp-link-26371-114005693") = 0
rename("/gnu/store/.tmp-link-26371-114005693", "/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/2>
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", {st_mode=S_IFDIR|0755, st_size=4112, ...>
chmod("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", 040555) = 0
utimensat(AT_FDCWD, "/gnu/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", [{tv_sec=1626363034, tv_ns>
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/22CC.png", {st_mode=S_IFLNK|0777, st_size=>
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/22CC.png", {st_mode=S_IFLNK|0777, st_size=>
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/22CC.png", {st_mode=S_IFLNK|0777, st_size=>
readlink("/gnu/store/h6681qq9s5kqjvdzkhqhddqbjj3q48nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283/22CC.png", "/gnu/store/bf582s56ldb3y34p>
statx(AT_FDCWD, "/gnu/store/.links/[...]my", AT_STATX_SYNC_AS_STAT|AT_SYMLINK_NOFOLLOW, 0, {stx_mask=STATX_ALL|>
lstat("/gnu/store/.links/[...]my", {st_mode=S_IFLNK|0777, st_size=124, ...}) = 0
lstat("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", {st_mode=S_IFDIR|0555, st_size=4112, ...>
chmod("/gnu/store/[...]nm-fonts-dir/share/fonts/mathjax/HTML-CSS/TeX/png/AMS/Regular/283", 040755) = 0
getpid()                                = 26371
<end of log>

It seems like ‘duplication’ is taking a lot of time!
(See nix/libstore/optimise-store.cc and (guix store deduplication).)

> IIUC, the hook completes almost instantaneously when creating a profile
> without fonts because (null? fonts-dirs) is true.
> 
> In other cases, one option to speed things up (and possibly remove the
> hook’s dependency on mkfontdir) would be to create ‘fonts.dir’ and
> ‘fonts.scale’ in a build phase of each font package, *provided* there’s
> a cheap way to assemble several such files, such as mere concatenation.
> That way, the profile hook would only need to assemble these files as
> opposed to traversing all the font files.

Looking at ~/.guix-profile/share/fonts/truetype/fonts.dir,
it seems to be simply a list of entries lke

   DejaVuSans-Bold.ttf -misc-dejavu sans-bold-r-normal--0-0-0-0-p-0-koi8-ru

with additionally as first line the number of fonts.  It appears to be
sorted by font file name (DejaVuSans-Bold.ttf) though, though that only
seems to be to not depend on file system ordering.  Not quite _mere_
concatenation, but should be easy enough, I think.

(Likewise for fonts.scaale)

I would need to look at the code of "mkfontscale" and "mkfontdir" to be sure
though.

> Given that ‘fonts.dir’ and ‘fonts.scale’ are mere text files with one
> line per font, this approach looks doable.
> 
> WDYT?

That seems a good idea, reducing the amount of 'stat'ing, 'readdir'ing,
and 'read'ing (mkfontscale needs to actually read the font files)
which should help on spinning disks (and other disks, but on SSDs it's probably
less noticable).

> > From 4fe1e30e33c01be9fd17cf240732b3351c7b0fa4 Mon Sep 17 00:00:00 2001
> > From: Maxime Devos <[email-masked]>
> > Date: Mon, 5 Jul 2021 18:55:31 +0200
> > Subject: [PATCH 1/2] profiles: Optimise 'fonts-dir-file'.
> > 
> > Only let the build G-exp refer to inputs that might actually
> > have fonts.  That way, if the list of fonts in the manifest
> > didn't change and the new manifest is built, the font files
> > will not be rebuilt.
> > 
> > * guix/profiles.scm
> >   (fonts-dir-file)[has-fonts?]: New predicate.
> >   (fonts-dir-file)[relevant-inputs]: New variable.
> >   (fonts-dir-file)[build]: Use 'relevant-inputs' instead of
> >   'manifest-inputs'.
> > * doc/contributing.texi (Fonts): Note the 'fonts-' naming
> >   convention is technically important now.
> > * gnu/packages/ghostscript.scm (gs-fonts): Work-around the
> >   package name contravening the convention.
> 
> To me this approach should be a last resort because it relies on
> conventions and manual annotations, and it’s easy to forget these and
> get incorrect results (we could end up having to deal with reports like
> “I installed font X, why doesn’t in show up in the font list?”).

AFAIK, all font packages in Guix (except gs-fonts) are currently
correctly-named.  They aren't going to spontanuously rename theirselves.
So to me, the only potential problem seems to be _new_ font packages
ignoring the conventions.  But new packages should always be reviewed and
tested, so such reports don't seem plausible to me.

(Also, the manual annotation would go away once 'gs-fonts' is renamed.
I'll run "echo /gnu/store/*/share/fonts > atchie-fonts" though to see
if there are other packages not following the convention.)

> > +            ;; In the upstream 'guix' channel, font packages should
> > +            ;; be named font-SOMETHING.  But if another channel
> > +            ;; names its fonts differently but uses font-build-system,
> > +            ;; accepting that seems friendly.
> > +            (eq? 'font (build-system-name (package-build-system thing)))
> 
> In general ‘build-system-name’ shouldn’t be used; the name is meant to
> be a debugging aid.

I could do (eq? font-build-system (packag-build-system thing)) instead
or drop this clause.

> Thanks,
> Ludo’.