bug#64772: TeXlive (specifically LuaLaTeX) has become terribly slow

bug#64772: TeXlive (specifically LuaLaTeX) has become terribly slow

[Malte Frank Gerdes]

Hi,

i'm building a small document with LuaLaTeX, for that i have use the
following manifest

--8<---------------cut here---------------start------------->8---
(specifications->manifest
  (list
    "texlive-amsmath"
    "texlive-todonotes"
    "texlive-xpatch"
    "texlive-collection-luatex"
    "texlive-collection-basic"
    "texlive-latexmk"
    "texlive-scheme-basic"
    "texlive-biber"
    "texlive-booktabs"
    "texlive-microtype"
    "texlive-koma-script"
    "texlive-lipsum"
    "texlive-pgfplots"
    "texlive-biblatex"))
--8<---------------cut here---------------end--------------->8---

This command takes quite a long time
--8<---------------cut here---------------start------------->8---
guix time-machine --commit=21b718f4d6c3ded8ef50d12f6e9ae6474f74620f \
       shell --manifest=guix.scm -- latexmk -lualatex -auxdir=.tex-cache main
--8<---------------cut here---------------end--------------->8---

To be precise:
--8<---------------cut here---------------start------------->8---
        Command being timed: "guix shell -m guix.scm -- latexmk -lualatex -auxdir=.tex-cache main"
        User time (seconds): 14.60
        System time (seconds): 87.58
        Percent of CPU this job got: 99%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 1:43.18
        Average shared text size (kbytes): 0
        Average unshared data size (kbytes): 0
        Average stack size (kbytes): 0
        Average total size (kbytes): 0
        Maximum resident set size (kbytes): 179368
        Average resident set size (kbytes): 0
        Major (requiring I/O) page faults: 0
        Minor (reclaiming a frame) page faults: 118914
        Voluntary context switches: 2146
        Involuntary context switches: 3693
        Swaps: 0
        File system inputs: 462280
        File system outputs: 6584
        Socket messages sent: 0
        Socket messages received: 0
        Signals delivered: 0
        Page size (bytes): 4096
        Exit status: 0
--8<---------------cut here---------------end--------------->8---

Running `latexmk -lualatex -auxdir=.tex-cache main` takes under 10
seconds.  These times are for fresh builds, i.e. the intermediate files
have been removed.  Still even recompilation is many times slower with
guix provided LuaLaTeX than it is on Arch.  I should also note, that
using the modular TeX packages actually helps here, with the full
TeXlive package the compilation time is nearly twice as much.

Another thing i noticed is, that a directory with the following
structure gets created:

--8<---------------cut here---------------start------------->8---
{
└── gnu
    └── store
        └── 3wsicprhgxhcncaf5mv26wwbhhh8p6yj-profile
            └── share
                └── texmf-dist
                    └── luatex-cache
                        └── generic
                            ├── fonts
                            │   └── otl
                            │       ├── lmroman10-italic.lua
                            │       ├── lmroman10-italic.luc
                            │       ├── lmroman10-regular.lua
                            │       ├── lmroman10-regular.luc
                            │       ├── lmroman12-regular.lua
                            │       ├── lmroman12-regular.luc
                            │       ├── lmroman17-regular.lua
                            │       ├── lmroman17-regular.luc
                            │       ├── lmromanslant10-regular.lua
                            │       ├── lmromanslant10-regular.luc
                            │       ├── lmsans10-bold.lua
                            │       ├── lmsans10-bold.luc
                            │       ├── lmsans10-regular.lua
                            │       └── lmsans10-regular.luc
                            └── names
                                ├── luaotfload-lookup-cache.lua
                                ├── luaotfload-lookup-cache.luc
                                ├── luaotfload-names.lua.gz
                                └── luaotfload-names.luc.gz

11 directories, 18 files
--8<---------------cut here---------------end--------------->8---

This is obviously for caching purposes, but (seemingly random) having a
folder named '{' in your working directory certainly is confusing.


mfg

bug#64772: TeXlive (specifically LuaLaTeX) has become terribly slow

[Wojtek Kosior via Bug reports for GNU Guix]

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

Hi,

I think I know what causes a subdirectory of '{' to be used for caches
— the 'share/texmf-dist/web2c/texmf.cnf' file in the
texlive-libkpathsea package has a

    TEXMFROOT = {$GUIX_TEXMF}/..

line. It's a "runtime path configuration file for kpathsea" and in
general it supports brace expansion. However, in this case something
goes wrong. Maybe the expansion is only triggered when there's at least
one comma in between the braces? Idk. Btw, Guix uses ":" and not a
comma as path separator in 'GUIX_TEXMF' variable and I have no idea
whether kpathsea's brace expansion allows ":" to be used instead of ",".

Still, I'm pretty sure it is this line that causes the '{' directory
problem — I tried running lualatex after bind-mounting a modified
texmf.cnf over the one in the store. I replaced that line with

    TEXMFROOT = $GUIX_TEXMF/..

and no '{' was created this time. Of course, it only worked because
GUIX_TEXMF was holding just one path — a general solution would need to
be different. Just in case, this is the part of texlive-kpathsea
definition in gnu/packages/tex.scm that prepares 'texmf.cnf':

```
          (add-after 'unpack 'customize-texmf.cnf
            ;; The default "texmf.cnf" file is provided by this package.
            ;; Every variable of interest is set relatively to the GUIX_TEXMF
            ;; environment variable defined via a search path below.
            ;;
            ;; This phase must happen before the `configure' phase, because
            ;; the value of the TEXMFCNF variable (modified along with the
            ;; SELFAUTOLOC reference below) is used at compile time to
            ;; generate "paths.h" file.
            (lambda _
              (substitute* "texk/kpathsea/texmf.cnf"
                (("^TEXMFROOT = .*")
                 "TEXMFROOT = {$GUIX_TEXMF}/..\n")
                (("^TEXMF = .*")
                 "TEXMF = {$GUIX_TEXMF}\n")
                (("\\$SELFAUTOLOC(/share/texmf-dist/web2c)" _ suffix)
                 (string-append #$output suffix))
                ;; Don't truncate lines.
                (("^error_line = .*$") "error_line = 254\n")
                (("^half_error_line = .*$") "half_error_line = 238\n")
                (("^max_print_line = .*$") "max_print_line = 1000\n"))))

```

Unfortunately, changes to 'texmf.cnf' don't affect the running time of
lualatex — it's still terribly slow

Wojtek

-- (sig_start)
website: https://koszko.org/koszko.html
fingerprint: E972 7060 E3C5 637C 8A4F  4B42 4BC5 221C 5A79 FD1A
follow me on Fediverse: https://friendica.me/profile/koszko/profile

♥ R29kIGlzIHRoZXJlIGFuZCBsb3ZlcyBtZQ== | ÷ c2luIHNlcGFyYXRlZCBtZSBmcm9tIEhpbQ==
✝ YnV0IEplc3VzIGRpZWQgdG8gc2F2ZSBtZQ== | ? U2hhbGwgSSBiZWNvbWUgSGlzIGZyaWVuZD8=
-- (sig_end)

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 228 bytes --]

bug#64772: TeXlive (specifically LuaLaTeX) has become terribly slow

[Wojtek Kosior via Bug reports for GNU Guix]

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

I ran lualatex under strace, additionally prepending the time to each
line of output. The new (i.e. after tex-team-next merge this July)
lualatex has *a lot* of lines like this in the output

--8<---------------cut here---------------start------------->8---
Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.lua", R_OK) = -1 ENOENT (No such file or directory)
Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.luatex", R_OK) = -1 ENOENT (No such file or directory)
Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.luc", R_OK) = -1 ENOENT (No such file or directory)
Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.luctex", R_OK) = -1 ENOENT (No such file or directory)
Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.texlua", R_OK) = -1 ENOENT (No such file or directory)
Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.texluc", R_OK) = -1 ENOENT (No such file or directory)
Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.tlu", R_OK) = -1 ENOENT (No such file or directory)
--8<---------------cut here---------------end--------------->8---

The "old" lualetex (i.e. one from before the merge) does not produce
these under strace.

This test has been done (in case anyone's wondering) *after*
bind-mounting the texmf.cnf of texlive-kpathsea as explained in my
previous message.

Hopefully, this will help someone solve this

Wojtek

-- (sig_start)
website: https://koszko.org/koszko.html
fingerprint: E972 7060 E3C5 637C 8A4F  4B42 4BC5 221C 5A79 FD1A
follow me on Fediverse: https://friendica.me/profile/koszko/profile

♥ R29kIGlzIHRoZXJlIGFuZCBsb3ZlcyBtZQ== | ÷ c2luIHNlcGFyYXRlZCBtZSBmcm9tIEhpbQ==
✝ YnV0IEplc3VzIGRpZWQgdG8gc2F2ZSBtZQ== | ? U2hhbGwgSSBiZWNvbWUgSGlzIGZyaWVuZD8=
-- (sig_end)


On Thu, 27 Jul 2023 00:21:42 +0200 Wojtek Kosior <koszko@koszko.org> wrote:

> Hi,
> 
> I think I know what causes a subdirectory of '{' to be used for caches
> — the 'share/texmf-dist/web2c/texmf.cnf' file in the
> texlive-libkpathsea package has a
> 
>     TEXMFROOT = {$GUIX_TEXMF}/..
> 
> line. It's a "runtime path configuration file for kpathsea" and in
> general it supports brace expansion. However, in this case something
> goes wrong. Maybe the expansion is only triggered when there's at least
> one comma in between the braces? Idk. Btw, Guix uses ":" and not a
> comma as path separator in 'GUIX_TEXMF' variable and I have no idea
> whether kpathsea's brace expansion allows ":" to be used instead of ",".
> 
> Still, I'm pretty sure it is this line that causes the '{' directory
> problem — I tried running lualatex after bind-mounting a modified
> texmf.cnf over the one in the store. I replaced that line with
> 
>     TEXMFROOT = $GUIX_TEXMF/..
> 
> and no '{' was created this time. Of course, it only worked because
> GUIX_TEXMF was holding just one path — a general solution would need to
> be different. Just in case, this is the part of texlive-kpathsea
> definition in gnu/packages/tex.scm that prepares 'texmf.cnf':
> 
> ```
>           (add-after 'unpack 'customize-texmf.cnf
>             ;; The default "texmf.cnf" file is provided by this package.
>             ;; Every variable of interest is set relatively to the GUIX_TEXMF
>             ;; environment variable defined via a search path below.
>             ;;
>             ;; This phase must happen before the `configure' phase, because
>             ;; the value of the TEXMFCNF variable (modified along with the
>             ;; SELFAUTOLOC reference below) is used at compile time to
>             ;; generate "paths.h" file.
>             (lambda _
>               (substitute* "texk/kpathsea/texmf.cnf"
>                 (("^TEXMFROOT = .*")
>                  "TEXMFROOT = {$GUIX_TEXMF}/..\n")
>                 (("^TEXMF = .*")
>                  "TEXMF = {$GUIX_TEXMF}\n")
>                 (("\\$SELFAUTOLOC(/share/texmf-dist/web2c)" _ suffix)
>                  (string-append #$output suffix))
>                 ;; Don't truncate lines.
>                 (("^error_line = .*$") "error_line = 254\n")
>                 (("^half_error_line = .*$") "half_error_line = 238\n")
>                 (("^max_print_line = .*$") "max_print_line = 1000\n"))))
> 
> ```
> 
> Unfortunately, changes to 'texmf.cnf' don't affect the running time of
> lualatex — it's still terribly slow
> 
> Wojtek
> 
> -- (sig_start)
> website: https://koszko.org/koszko.html
> fingerprint: E972 7060 E3C5 637C 8A4F  4B42 4BC5 221C 5A79 FD1A
> follow me on Fediverse: https://friendica.me/profile/koszko/profile
> 
> ♥ R29kIGlzIHRoZXJlIGFuZCBsb3ZlcyBtZQ== | ÷ c2luIHNlcGFyYXRlZCBtZSBmcm9tIEhpbQ==
> ✝ YnV0IEplc3VzIGRpZWQgdG8gc2F2ZSBtZQ== | ? U2hhbGwgSSBiZWNvbWUgSGlzIGZyaWVuZD8=
> -- (sig_end)

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 228 bytes --]

bug#64772: TeXlive (specifically LuaLaTeX) has become terribly slow

[Nicolas Goaziou]

Hello,

Wojtek Kosior via Bug reports for GNU Guix <bug-guix@gnu.org> writes:

> I ran lualatex under strace, additionally prepending the time to each
> line of output. The new (i.e. after tex-team-next merge this July)
> lualatex has *a lot* of lines like this in the output
>
> --8<---------------cut here---------------start------------->8---
> Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.lua", R_OK) = -1 ENOENT (No such file or directory)
> Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.luatex", R_OK) = -1 ENOENT (No such file or directory)
> Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.luc", R_OK) = -1 ENOENT (No such file or directory)
> Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.luctex", R_OK) = -1 ENOENT (No such file or directory)
> Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.texlua", R_OK) = -1 ENOENT (No such file or directory)
> Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.texluc", R_OK) = -1 ENOENT (No such file or directory)
> Thu Jul 27 09:31:56 PM CEST 2023: access("/home/urz/.guix-home/profile/share/texmf-dist/scripts/context/lua/lualatexquotejobname/lua.tlu", R_OK) = -1 ENOENT (No such file or directory)
> --8<---------------cut here---------------end--------------->8---
>
> The "old" lualetex (i.e. one from before the merge) does not produce
> these under strace.

Could you try adding a phase doing the following to texlive-luatex?

--8<---------------cut here---------------start------------->8---
(substitute* (string-append #$output "/share/texmf-dist/web2c/texmfcnf.lua")
                  (("selfautodir:") #$output)
                  (("selfautoparent:") (string-append #$output "/share/")))
--8<---------------cut here---------------end--------------->8---

The files above are probably generated, and I don't know when.

> This test has been done (in case anyone's wondering) *after*
> bind-mounting the texmf.cnf of texlive-kpathsea as explained in my
> previous message.

I suggest to drop this "fix" for now.

Regards,
-- 
Nicolas Goaziou

bug#64772: TeXlive (specifically LuaLaTeX) has become terribly slow

[Wojtek Kosior via Bug reports for GNU Guix]

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

> Could you try adding a phase doing the following to texlive-luatex?
> 
> --8<---------------cut here---------------start------------->8---
> (substitute* (string-append #$output "/share/texmf-dist/web2c/texmfcnf.lua")
>                   (("selfautodir:") #$output)
>                   (("selfautoparent:") (string-append #$output "/share/")))
> --8<---------------cut here---------------end--------------->8---

Actually, I've been using the `lualatex` command from the `texlive`
package. I now see I my reports might have been confusing as I didn't
mention that. I apologize :(

Although `lualatex` from `texlive` has been slow for me, now, when
using `guix shell texlive-collection-latex` with guix
76e041f9eef85bb039c5251d3350c62ee2066883, I get a rather satisfactory
time (below 4s on old Lenovo T400) when compiling this test doc

--8<---------------cut here---------------start------------->8---
\documentclass{article}
\title{somedoc}
\begin{document}

aaa

\end{document}
--8<---------------cut here---------------end--------------->8---

These tons of `ENOENT` are still there in strace's output, tho.

Back to your snippet — if you still think it's worth trying (to see if
it gets rid of the ENOENTs), I'll try it and report later.

> The files above are probably generated, and I don't know when.

Although I know a lot less about TeX than you, I can at least say that
they are not actually "needed" — no package in my store (not even the
entire nicely-working texlive from before the merge) had a directory
named "lualatexquotejobname". Neither of the following commands yielded
anything

--8<---------------cut here---------------start------------->8---
find /gnu/store/  -mindepth 1 -maxdepth 1 -name *texlive* -type d -exec find '{}' -name lualatexquotejobname -type d \;
find ~/.texlive2021/ -name lualatexquotejobname -type d
find ~/.texlive2023/ -name lualatexquotejobname -type d
--8<---------------cut here---------------end--------------->8---

> I suggest to drop this "fix" for now.

OK

Best,
Wojtek

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 228 bytes --]

bug#64772: TeXlive (specifically LuaLaTeX) has become terribly slow

[Wojtek Kosior via Bug reports for GNU Guix]

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

> Back to your snippet — if you still think it's worth trying (to see if
> it gets rid of the ENOENTs), I'll try it and report later.

Starting from guix 3bb3fddb5c6e79056172e5858cdc0ee0b6b8cfaa, I tried
adding this

--8<---------------cut here---------------start------------->8---
#:phases
#~(modify-phases %standard-phases
    (add-after 'install 'customize-texmfcnf.lua
      (lambda _
        (substitute* (string-append #$output "/share/texmf-dist/web2c/texmfcnf.lua")
          (("selfautodir:") #$output)
          (("selfautoparent:") (string-append #$output "/share/"))))))))
--8<---------------cut here---------------end--------------->8---

to `texlive-luatex` as suggested. I verified manually that the file in
the resulting package actually got the paths substituted. I then ran

--8<---------------cut here---------------start------------->8---
guix shell -D guix -- path/to/pre-inst-env guix shell texlive-collection-latex less coreutils grep findutils which strace -C
strace lualatex minimal.tex > strace.txt 2>&1
grep -E 'lualatexquotejobname.*ENOENT' strace.txt | wc -l
--8<---------------cut here---------------end--------------->8---

and got 9138

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 228 bytes --]

bug#64772: TeXlive (specifically LuaLaTeX) has become terribly slow

[Nicolas Goaziou via Bug reports for GNU Guix]

Hello,

Malte Frank Gerdes <malte.f.gerdes@gmail.com> writes:

> i'm building a small document with LuaLaTeX, for that i have use the
> following manifest
>
> --8<---------------cut here---------------start------------->8---
> (specifications->manifest
>   (list
>     "texlive-amsmath"
>     "texlive-todonotes"
>     "texlive-xpatch"
>     "texlive-collection-luatex"
>     "texlive-collection-basic"
>     "texlive-latexmk"
>     "texlive-scheme-basic"
>     "texlive-biber"
>     "texlive-booktabs"
>     "texlive-microtype"
>     "texlive-koma-script"
>     "texlive-lipsum"
>     "texlive-pgfplots"
>     "texlive-biblatex"))
> --8<---------------cut here---------------end--------------->8---
>
>
> This command takes quite a long time
>
> --8<---------------cut here---------------start------------->8---
> guix time-machine --commit=21b718f4d6c3ded8ef50d12f6e9ae6474f74620f \
>        shell --manifest=guix.scm -- latexmk -lualatex -auxdir=.tex-cache main
> --8<---------------cut here---------------end--------------->8---
>
>
> To be precise:
>
> --8<---------------cut here---------------start------------->8---
>         Command being timed: "guix shell -m guix.scm -- latexmk -lualatex -auxdir=.tex-cache main"
>         User time (seconds): 14.60
>         System time (seconds): 87.58
>         Percent of CPU this job got: 99%
>         Elapsed (wall clock) time (h:mm:ss or m:ss): 1:43.18
>         Average shared text size (kbytes): 0
>         Average unshared data size (kbytes): 0
>         Average stack size (kbytes): 0
>         Average total size (kbytes): 0
>         Maximum resident set size (kbytes): 179368
>         Average resident set size (kbytes): 0
>         Major (requiring I/O) page faults: 0
>         Minor (reclaiming a frame) page faults: 118914
>         Voluntary context switches: 2146
>         Involuntary context switches: 3693
>         Swaps: 0
>         File system inputs: 462280
>         File system outputs: 6584
>         Socket messages sent: 0
>         Socket messages received: 0
>         Signals delivered: 0
>         Page size (bytes): 4096
>         Exit status: 0
> --8<---------------cut here---------------end--------------->8---
>
>
> Running `latexmk -lualatex -auxdir=.tex-cache main` takes under 10
> seconds.  These times are for fresh builds, i.e. the intermediate files
> have been removed.  Still even recompilation is many times slower with
> guix provided LuaLaTeX than it is on Arch.  I should also note, that
> using the modular TeX packages actually helps here, with the full
> TeXlive package the compilation time is nearly twice as much.
>
> Another thing i noticed is, that a directory with the following
> structure gets created:
>
> --8<---------------cut here---------------start------------->8---
> {
> └── gnu
>     └── store
>         └── 3wsicprhgxhcncaf5mv26wwbhhh8p6yj-profile
>             └── share
>                 └── texmf-dist
>                     └── luatex-cache
>                         └── generic
>                             ├── fonts
>                             │   └── otl
>                             │       ├── lmroman10-italic.lua
>                             │       ├── lmroman10-italic.luc
>                             │       ├── lmroman10-regular.lua
>                             │       ├── lmroman10-regular.luc
>                             │       ├── lmroman12-regular.lua
>                             │       ├── lmroman12-regular.luc
>                             │       ├── lmroman17-regular.lua
>                             │       ├── lmroman17-regular.luc
>                             │       ├── lmromanslant10-regular.lua
>                             │       ├── lmromanslant10-regular.luc
>                             │       ├── lmsans10-bold.lua
>                             │       ├── lmsans10-bold.luc
>                             │       ├── lmsans10-regular.lua
>                             │       └── lmsans10-regular.luc
>                             └── names
>                                 ├── luaotfload-lookup-cache.lua
>                                 ├── luaotfload-lookup-cache.luc
>                                 ├── luaotfload-names.lua.gz
>                                 └── luaotfload-names.luc.gz
>
> 11 directories, 18 files
> --8<---------------cut here---------------end--------------->8---
>
> This is obviously for caching purposes, but (seemingly random) having a
> folder named '{' in your working directory certainly is confusing.

Both issues reported here are now fixed. Thank you.

Regards,
-- 
Nicolas Goaziou