performance issue with TeX Live

performance issue with TeX Live

[Emmanuel Beffara]

Hello Guix devel,

I am facing a severe performance issue with TeX Live: compilation of any
document is an order of magnitude slower with a Guix installed system as
compared to a manual installation. Is anyone confronted to this phenomenon, or
is there a way to fix this ?

I suspect the problem comes from kpathsea, but I may be misinterpeting my
observations. The fact is that there is an enormous amount of file accesses
for any compilation.

As an experiment, I compared two installations.

- One is a pure Guix installation, managed with `guix home`, that contains a
  rather large collection of packages that I include through a custom package:

    (define-public texlive-scheme-eb
      (package
	(name "texlive-scheme-eb")
	(version (number->string %texlive-revision))
	(source #f)
	(build-system trivial-build-system)
	(arguments (list #:builder #~(mkdir #$output)))
	(propagated-inputs
	  (list texlive-scheme-medium
		texlive-collection-fontsextra
		texlive-collection-latexextra
		texlive-collection-pictures))
	(home-page "https://www.tug.org/texlive/")
	(synopsis "EB's custom installation scheme")
	(description "This my a TeX Live scheme with what I use.")
	(license (license:fsf-free "https://www.tug.org/texlive/copying.html"))))

- The other is manual, I set up a container with

     $ guix shell --container -F --network --share=$HOME/opt=/opt bash coreutils curl grep gzip ncurses perl sed tar wget

  in which I installed TeX Live using `install-tl` as found on
  <https://tug.org/texlive/>, in the folder `/opt` exposed in the container.
  I installed the same package set by selecting the medium scheme in
  `install-tl` and installing the collections above with the provided `tlmgr`.

On my machine (a rather recent and powerful Dell Latitude 7410 with 16GiB RAM
and 12 cores), I observe the following timings:

- For a minimal LaTeX document (title, author and one word of body text)
  running `time pdflatex doc.tex` I get the following timings in the Guix
  version:

    real    0m4,288s
    user    0m3,140s
    sys     0m1,148s

  and in the manual version:

    real    0m0.773s
    user    0m0.729s
    sys     0m0.044s

- For a small beamer slideshow with nothing exotic (474 source lines, 17
  slides, no tikz graphics or anything), I get the following timings in the
  Guix version:

    real    1m0,122s
    user    0m14,337s
    sys     0m44,279s

  and in the manual version:

    real    0m4.554s
    user    0m4.446s
    sys     0m0.108s

I tried doing `strace` on the pdflatex calls to investigate further and it
appears that the behaviours of the two versions are largely different.
Counting the number of system calls of each kind gives the following, for the
most frequent calls:

- minimal document, Guix version:

   112860 newfstatat
    10491 getdents64
     5247 openat
     5246 close
     4397 access
     3141 read

- minimal document, manual version:

     2772 read
       90 openat
       72 access
       64 close
       64 newfstatat
       60 getdents64

- slideshow, Guix version:

  2831722 getdents64
  1538560 newfstatat
  1498287 access
  1415296 openat
  1415295 close
     4283 read

- slideshow, Guix version:

     3913 read
     1288 getdents64
     1136 access
      960 openat
      925 close
      920 newfstatat

So apparently no file hash is used in the Guix version and a large part of the
`texmf-dist` folder is browsed, probably several times.

-- 
Emmanuel

Re: performance issue with TeX Live

[Olivier Dion]

On Tue, 12 Sep 2023, Emmanuel Beffara <manu@beffara.org> wrote:
> Hello Guix devel,
>
> I am facing a severe performance issue with TeX Live: compilation of any
> document is an order of magnitude slower with a Guix installed system as
> compared to a manual installation. Is anyone confronted to this phenomenon, or
> is there a way to fix this ?

I had a similar issue not long ago.  I think recent patches fix this and
now it is smooth as before.

-- 
Olivier Dion
oldiob.dev

Re: performance issue with TeX Live

[Emmanuel Beffara]

De Olivier Dion le 12/09/2023 à 19:11:
> On Tue, 12 Sep 2023, Emmanuel Beffara <manu@beffara.org> wrote:
> > Hello Guix devel,
> >
> > I am facing a severe performance issue with TeX Live: compilation of any
> > document is an order of magnitude slower with a Guix installed system as
> > compared to a manual installation. Is anyone confronted to this phenomenon, or
> > is there a way to fix this ?
> 
> I had a similar issue not long ago.  I think recent patches fix this and
> now it is smooth as before.

Apparently no. I did a pull and reconfigure and the behaviour is the same as I
described.

    $ guix describe
    Generation 53   Sep 12 2023 20:49:03    (current)
      guix 4cb2e08
	repository URL: https://git.savannah.gnu.org/git/guix.git
	branch: master
	commit: 4cb2e08b8eb1acc824b72ec17b483d7d85b5af68

Running my compilations in a pure environment with

    guix shell --pure texlive-scheme-medium texlive-collection-...

leads to the same behaviour, and the same with --container. Not sure how to
investigate this further.

-- 
Emmanuel

Re: performance issue with TeX Live

[Nicolas Goaziou]

Hello,

Emmanuel Beffara <manu@beffara.org> writes:

> I am facing a severe performance issue with TeX Live: compilation of any
> document is an order of magnitude slower with a Guix installed system as
> compared to a manual installation. Is anyone confronted to this phenomenon, or
> is there a way to fix this ?

I also experienced a noticeable slowdown; I don't know how to fix it yet.

> I tried doing `strace` on the pdflatex calls to investigate further and it
> appears that the behaviours of the two versions are largely different.
> Counting the number of system calls of each kind gives the following, for the
> most frequent calls:
>
> - minimal document, Guix version:
>
>    112860 newfstatat
>     10491 getdents64
>      5247 openat
>      5246 close
>      4397 access
>      3141 read
>
> - minimal document, manual version:
>
>      2772 read
>        90 openat
>        72 access
>        64 close
>        64 newfstatat
>        60 getdents64
>
> - slideshow, Guix version:
>
>   2831722 getdents64
>   1538560 newfstatat
>   1498287 access
>   1415296 openat
>   1415295 close
>      4283 read
>
> - slideshow, Guix version:
>
>      3913 read
>      1288 getdents64
>      1136 access
>       960 openat
>       925 close
>       920 newfstatat
>
> So apparently no file hash is used in the Guix version and a large part of the
> `texmf-dist` folder is browsed, probably several times.

A ls-R file is generated during profile creation (see
`texlive-font-maps' function in "guix/profiles.scm") but it seems it is
not read.

It may be interesting to compare location and contents of the ls-R files
in both installations.

Regards,
-- 
Nicolas Goaziou

Re: performance issue with TeX Live

[Emmanuel Beffara]

Hello,

De Nicolas Goaziou le 13/09/2023 à 14:39:
> Emmanuel Beffara <manu@beffara.org> writes:
> 
> > I am facing a severe performance issue with TeX Live: compilation of any
> > document is an order of magnitude slower with a Guix installed system as
> > compared to a manual installation. Is anyone confronted to this phenomenon, or
> > is there a way to fix this ?
> 
> I also experienced a noticeable slowdown; I don't know how to fix it yet.
[...]
> A ls-R file is generated during profile creation (see
> `texlive-font-maps' function in "guix/profiles.scm") but it seems it is
> not read.
> 
> It may be interesting to compare location and contents of the ls-R files
> in both installations.

I tried to explore this but I see no reason why the ls-R files would be
ignored and I don't know how to explore this further. I do want to contribute
to a solution, because right now texlive is practically unusable in Guix.

-- 
Emmanuel

Re: performance issue with TeX Live

[Nicolas Goaziou]

Hello,

Emmanuel Beffara <manu@beffara.org> writes:

> De Nicolas Goaziou le 13/09/2023 à 14:39:

>> It may be interesting to compare location and contents of the ls-R files
>> in both installations.
>
> I tried to explore this but I see no reason why the ls-R files would be
> ignored

I spent some time exploring this, but I cannot tell either. Though, it
is plausible that the problem is related to ls-R files, or, more
accurately, the reason why they are not read.

Note that those files are not installed in every tree. For example
`texlive-updmap.cfg' doesn't create any so, IIUC, any TeX Live tree used
as a build input require to navigate the file system.

I also tried to tweak TEXMFDBS and TEXMF values in "texmf.cnf" from
"texlive-libkpathsea" package, but couldn't find a sweet spot.

At the moment, I'm running out of ideas, and time.

> I do want to contribute to a solution, because right now texlive is
> practically unusable in Guix.

FWIW, I use modular TeX Live regularly, so "unusable" is probably a bit
strong. However, I agree the current situation is frustrating.

Regards,
-- 
Nicolas Goaziou

Re: performance issue with TeX Live

[Emmanuel Beffara]

De Nicolas Goaziou le 09/10/2023 à 16:03:
> Emmanuel Beffara <manu@beffara.org> writes:
> > I do want to contribute to a solution, because right now texlive is
> > practically unusable in Guix.
> 
> FWIW, I use modular TeX Live regularly, so "unusable" is probably a bit
> strong. However, I agree the current situation is frustrating.

Ok, "unusable" may be an overstatement. But when compiling a simple document
takes one or two minutes, it certainly changes the workflow (in particular,
adjusting a slideshow at the last minute becomes a stressful experience, this
is what triggered my message above…)

-- 
Emmanuel

Re: performance issue with TeX Live

[Ricardo Wurmus]

Emmanuel Beffara <manu@beffara.org> writes:

> De Nicolas Goaziou le 09/10/2023 à 16:03:
>> Emmanuel Beffara <manu@beffara.org> writes:
>> > I do want to contribute to a solution, because right now texlive is
>> > practically unusable in Guix.
>> 
>> FWIW, I use modular TeX Live regularly, so "unusable" is probably a bit
>> strong. However, I agree the current situation is frustrating.
>
> Ok, "unusable" may be an overstatement. But when compiling a simple document
> takes one or two minutes […]

Oh, that sounds bad.  I only ever use pretty small collections of TeX
Live packages, so I never noticed.

In the past we used to create a union directory and generated a
configuration file to only search for packages in that single directory
instead of searching a large number of directories.  I wonder if we
could do something like that.

-- 
Ricardo

Re: performance issue with TeX Live

[Maxim Cournoyer]

Hi,

Emmanuel Beffara <manu@beffara.org> writes:

> Hello,
>
> De Nicolas Goaziou le 13/09/2023 à 14:39:
>> Emmanuel Beffara <manu@beffara.org> writes:
>> 
>> > I am facing a severe performance issue with TeX Live: compilation of any
>> > document is an order of magnitude slower with a Guix installed system as
>> > compared to a manual installation. Is anyone confronted to this phenomenon, or
>> > is there a way to fix this ?
>> 
>> I also experienced a noticeable slowdown; I don't know how to fix it yet.
> [...]
>> A ls-R file is generated during profile creation (see
>> `texlive-font-maps' function in "guix/profiles.scm") but it seems it is
>> not read.
>> 
>> It may be interesting to compare location and contents of the ls-R files
>> in both installations.
>
> I tried to explore this but I see no reason why the ls-R files would be
> ignored and I don't know how to explore this further. I do want to contribute
> to a solution, because right now texlive is practically unusable in Guix.

Have you tried tracing execution with strace?  Maybe try 'strace -e
file -f -s800 $texlive-cmd' and confirm whether the ls-R file gets used;
if it does, you could then introspect said file to see if it provides
what is being looked up or not.

-- 
Thanks,
Maxim

Re: performance issue with TeX Live

[Emmanuel Beffara]

Hello,

De Maxim Cournoyer le 14/10/2023 à 18:06:
> > I tried to explore this but I see no reason why the ls-R files would be
> > ignored and I don't know how to explore this further. I do want to contribute
> > to a solution, because right now texlive is practically unusable in Guix.
> 
> Have you tried tracing execution with strace?  Maybe try 'strace -e
> file -f -s800 $texlive-cmd' and confirm whether the ls-R file gets used;
> if it does, you could then introspect said file to see if it provides
> what is being looked up or not.

I did try strace, that is how I observed that apparently all installed files
are stated (with newfstatat) several times in each compilation.

The ls-R file is actually read:

    $ grep /ls-R log
    28308 access("/run/current-system/profile/share/texmf-dist/../texmf-dist/ls-R", R_OK) = 0
    28308 newfstatat(AT_FDCWD, "/run/current-system/profile/share/texmf-dist/../texmf-dist/ls-R", {st_mode=S_IFREG|0444, st_size=4053996, ...}, 0) = 0
    28308 openat(AT_FDCWD, "/run/current-system/profile/share/texmf-dist/../texmf-dist/ls-R", O_RDONLY) = 3

but aparently its contents are not taken into account.

-- 
Emmanuel

Re: performance issue with TeX Live

[Maxim Cournoyer]

Hi,

Emmanuel Beffara <manu@beffara.org> writes:

> Hello,
>
> De Maxim Cournoyer le 14/10/2023 à 18:06:
>> > I tried to explore this but I see no reason why the ls-R files would be
>> > ignored and I don't know how to explore this further. I do want to contribute
>> > to a solution, because right now texlive is practically unusable in Guix.
>> 
>> Have you tried tracing execution with strace?  Maybe try 'strace -e
>> file -f -s800 $texlive-cmd' and confirm whether the ls-R file gets used;
>> if it does, you could then introspect said file to see if it provides
>> what is being looked up or not.
>
> I did try strace, that is how I observed that apparently all installed files
> are stated (with newfstatat) several times in each compilation.
>
> The ls-R file is actually read:
>
>     $ grep /ls-R log
>     28308 access("/run/current-system/profile/share/texmf-dist/../texmf-dist/ls-R", R_OK) = 0
>     28308 newfstatat(AT_FDCWD,
> "/run/current-system/profile/share/texmf-dist/../texmf-dist/ls-R",
> {st_mode=S_IFREG|0444, st_size=4053996, ...}, 0) = 0
>     28308 openat(AT_FDCWD,
> "/run/current-system/profile/share/texmf-dist/../texmf-dist/ls-R",
> O_RDONLY) = 3
>
> but aparently its contents are not taken into account.

My next question would be; how is this ls-R file produced in Guix?
Does it matches the expectations of upstream for producing such file?
If it does, it seems like we have some interesting topic (i.e. bug) to
engage with upstream for a resolution.

-- 
Thanks,
Maxim

Re: performance issue with TeX Live

[Emmanuel Beffara]

De Maxim Cournoyer le 16/10/2023 à 15:46:
> My next question would be; how is this ls-R file produced in Guix?

That I do not know, but I would assume mktexlsr is called at some point when
building the profile.

> Does it matches the expectations of upstream for producing such file?

I don't know about those expectations, but after a quick look at the file in
Guix and in Debian, they look really similar. The only noticable difference is
that in Debian's file, the entries are sorted alphabetically in each folder
and the subfolders are browsed in alphabetical order.

-- 
Emmanuel

Re: performance issue with TeX Live

[Maxim Cournoyer]

Hi Emmanuel,

Emmanuel Beffara <manu@beffara.org> writes:

> De Maxim Cournoyer le 16/10/2023 à 15:46:
>> My next question would be; how is this ls-R file produced in Guix?
>
> That I do not know, but I would assume mktexlsr is called at some point when
> building the profile.
>
>> Does it matches the expectations of upstream for producing such file?
>
> I don't know about those expectations, but after a quick look at the file in
> Guix and in Debian, they look really similar. The only noticable difference is
> that in Debian's file, the entries are sorted alphabetically in each folder
> and the subfolders are browsed in alphabetical order.

That may be enough of a difference to explain the lookup failure?  If
the lookup code expects things to appear in alphabetical order, it may
determine a lack of match early if that's not the case.

Perhaps worth trying to reproduce it as closely to see if it improves on
things.

-- 
Thanks,
Maxim