#1070150 texlive-latex-extra: performance regression under emulation with 2023.20240207-1

#1070150#5
Date:
2024-04-30 22:19:38 UTC
From:
To:
Dear Maintainer,

Since the 2023.20240207-1 release, there is a major performance regression when
running the tex-common postinst hook in an arm64 chroot on amd64 host.

This was not the case with 2022.20230122-3.

When running the hook with the 2023.20240207, this step takes around 3 hours.

I'm guessing that this is related to enabling lua on aarch64 finally, but I'm
not familiar at all with latex and how to get the smallest possible test case to
show the issue.

A way to reproduce the issue would be to install debootstrap, qemu-user-static
and systemd-nspawn and then run apt-get install texlive-latex-extra

On an arm64 host (VM on an original M1 Macbook Air), this is fine

sudo debootstrap --arch arm64 stable stable
sudo systemd-nspawn -D stable
time apt-get install texlive-latex-extra -y

real   1m4.121s
user   0m52.893s
system 0m6.116s

(due to the t64 transition, testing is currentl unable to debootstrap)

sudo debootstrap --arch arm64 sid sid
sudo systemd-nspawn -D sid
time apt-get install texlive-latex-extra -y

real 1m24.647s
user 1m14.897s
sys  0m6.558s

In the qemu emulated build however,

sudo debootstrap --arch arm64 stable stable
sudo systemd-nspawn -D stable
time apt-get install texlive-latex-extra -y

real 13m14.171s
user 13m26.363s
sys  0m53.424s

texlive-latex-recommended: 2022.20230122-3

sudo debootstrap --arch arm64 sid sid
sudo systemd-nspawn -D sid
time apt-get install texlive-latex-extra -y

real 181m11.687s
user 181m43.534s
sys  1m5.422s

texlive-latex-recommended: 2023.20240207-1


So the version of latex in stable took less than 15 minutes to install, but the
version in testing and unstable both take 2 1/2 hours!  I did also test
2024.20240313.70630+ds-1 from experimental and it also takes the 2 1/2 hours.

Currently, we are working around this by forcing our package list to not install
any of the latex packages, but it would be nice to be able to have the packages
installed instead of telling end users to install them manually.

If you need me to do more testing or any sort of additional information, please
let me know!

#1070150#10
Date:
2024-05-01 04:22:01 UTC
From:
To:
Ouch, that hurts.

If you suspect lua, then could you please run (as root or via sudo)
	time fmtutil-sys --byengine luatex
	time fmtutil-sys --byengine luajittex
and let us see the times there?

Sorry, no Debian system around anymore.

Nor that.

Can you show the *actual* output?

And, maybe install moreutils and run it through ts

	apt-get install texlive-latex-extra -y | ts

That would give a hint which part is taking so much time.

Best regards

Norbert

#1070150#15
Date:
2024-05-01 19:34:54 UTC
From:
To:
Just a wee bit :)
My mail client is failing hard at keeping the formatting so the full
log is attached.  Running these 2 commands starts at line 1959 in the
log.

Yep, sorry about that, I wasn't sure how to add an attachment with
reportbug, my apologies! Log is attached, with the below command being
run at the start, the above commands after.

#1070150#20
Date:
2024-05-01 20:46:17 UTC
From:
To:
do that while I was still logging, so here is the fmtutil-sys --byengine
luatex | ts output:

root@sid:~# time fmtutil-sys --byengine luajittex | ts
May 01 14:26:13 fmtutil: fmtutil is using the following fmtutil.cnf
files (in precedence order):
May 01 14:26:13 fmtutil:   /usr/share/texmf/web2c/fmtutil.cnf
May 01 14:26:13 fmtutil: /usr/share/texlive/texmf-dist/web2c/fmtutil.cnf
May 01 14:26:13 fmtutil: fmtutil is using the following fmtutil.cnf file
for writing changes:
May 01 14:26:13 fmtutil:   /etc/texmf/web2c/fmtutil.cnf
May 01 14:26:13 fmtutil [INFO]: writing formats under /var/lib/texmf/web2c
May 01 14:26:13 fmtutil [INFO]: Did not find entry for
byengine=luajittex skipped
May 01 14:26:13 fmtutil [INFO]: not selected formats: 17
May 01 14:26:13 fmtutil [INFO]: total formats: 17
May 01 14:26:13 fmtutil [INFO]: exiting with status 0

real    0m9.009s
user    0m10.184s
sys     0m0.156s
root@sid:~# time fmtutil-sys --byengine luatex | ts
May 01 14:26:46 fmtutil: fmtutil is using the following fmtutil.cnf
files (in precedence order):
May 01 14:26:46 fmtutil:   /usr/share/texmf/web2c/fmtutil.cnf
May 01 14:26:46 fmtutil: /usr/share/texlive/texmf-dist/web2c/fmtutil.cnf
May 01 14:26:46 fmtutil: fmtutil is using the following fmtutil.cnf file
for writing changes:
May 01 14:26:46 fmtutil:   /etc/texmf/web2c/fmtutil.cnf
May 01 14:26:46 fmtutil [INFO]: writing formats under /var/lib/texmf/web2c
May 01 14:26:46 fmtutil [INFO]: --- remaking luatex with luatex
May 01 14:26:46 fmtutil: running `luatex -ini   -jobname=luatex
-progname=luatex luatex.ini' ...
May 01 14:26:47 This is LuaTeX, Version 1.17.0 (TeX Live 2023/Debian) 
(INITEX)
May 01 14:26:47  restricted system commands enabled.
May 01 14:26:47
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/luatex.ini
May 01 14:26:47
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/luatexconfig.tex
May 01 14:26:47 (/var/lib/texmf/tex/generic/tex-ini-files/pdftexconfig.tex))
May 01 14:26:47
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/luatexiniconfig.tex)
May 01 14:26:47
(/usr/share/texlive/texmf-dist/tex/generic/unicode-data/load-unicode-data.tex
May 01 14:26:47
May 01 14:26:47 load-unicode-data.tex v1.17 (2023-09-18)
May 01 14:26:47 Reading Unicode data
May 01 14:26:47 # UnicodeData-15.1.0.txt
May 01 14:26:47 # Modified 2023-09-18 08:45:00 GMT [JAW]
May 01 14:28:20 )
(/usr/share/texlive/texmf-dist/tex/luatex/hyph-utf8/etex.src
May 01 14:28:20 (/usr/share/texlive/texmf-dist/tex/plain/base/plain.tex
May 01 14:28:21 Preloading the plain format: codes, registers,
parameters, fonts, more fonts,
May 01 14:28:21 macros, math definitions, output routines, hyphenation
May 01 14:28:21 (/usr/share/texlive/texmf-dist/tex/generic/hyphen/hyphen.tex
May 01 14:28:21 [skipping from \patterns to end-of-file...]))
May 01 14:28:21 (/usr/share/texlive/texmf-dist/tex/plain/etex/etexdefs.lib
May 01 14:28:21 Skipping module "grouptypes"; Loading module
"interactionmodes";
May 01 14:28:21 Skipping module "nodetypes"; Skipping module "iftypes";)
May 01 14:28:21 (/var/lib/texmf/tex/generic/config/language.def
May 01 14:28:21
(/usr/share/texlive/texmf-dist/tex/generic/hyphen/hyphen.tex))
May 01 14:28:21 Augmenting the Plain TeX definitions: \tracingall;
May 01 14:28:21 Adding new e-TeX definitions: \eTeX, \loggingall,
\tracingnone,
May 01 14:28:21 register allocation; extended register allocation;
May 01 14:28:21 Recycling: \addlanguage, \@nswer (not defined), \@sk,
\b@dresponsetrue,
May 01 14:28:21 \b@dresponsefalse, \ch@ckforyn, \mayber@cycle,
\et@xabort, \et@xbuf,
May 01 14:28:21 \et@xfmtsrc, \et@xfilehdr, \et@xinf, \et@xpatterns,
\l@ngdefnfile, \n@xt,
May 01 14:28:21 \p@rse (not defined), \pr@mpt (not defined), \pr@mptloop
(not defined),
May 01 14:28:21 \forcer@cycle, \usef@llback, \usef@llbacktrue,
\usef@llbackfalse,
May 01 14:28:21 Retaining: \et@xerr, \et@xinput, \et@xlibhdr, \et@xmsg,
\et@xtoks, \et@xwarn,
May 01 14:28:21 \et@xl@@d, \et@xl@ad, \et@xload, \et@xlang, \et@xhash,
\eTeX, \etexhdrchk,
May 01 14:28:29 \etexstatus, \module, \uselanguage, \r@tain, \r@cycle,))
May 01 14:28:29 Beginning to dump on file luatex.fmt
May 01 14:28:29  (format=luatex 2024.5.1)
May 01 14:28:29 3389 strings using 10306 bytes
May 01 14:28:29 68809 memory locations dumped; current usage is 149&7701
May 01 14:28:29 1883 multiletter control sequences
May 01 14:28:29 \font\nullfont=nullfont
May 01 14:28:29 \font\tenrm=cmr10
May 01 14:28:29 \font\preloaded=cmr9
May 01 14:28:29 \font\preloaded=cmr8
May 01 14:28:29 \font\sevenrm=cmr7
May 01 14:28:29 \font\preloaded=cmr6
May 01 14:28:29 \font\fiverm=cmr5
May 01 14:28:29 \font\teni=cmmi10
May 01 14:28:29 \font\preloaded=cmmi9
May 01 14:28:29 \font\preloaded=cmmi8
May 01 14:28:29 \font\seveni=cmmi7
May 01 14:28:29 \font\preloaded=cmmi6
May 01 14:28:29 \font\fivei=cmmi5
May 01 14:28:29 \font\tensy=cmsy10
May 01 14:28:29 \font\preloaded=cmsy9
May 01 14:28:29 \font\preloaded=cmsy8
May 01 14:28:29 \font\sevensy=cmsy7
May 01 14:28:29 \font\preloaded=cmsy6
May 01 14:28:29 \font\fivesy=cmsy5
May 01 14:28:29 \font\tenex=cmex10
May 01 14:28:29 \font\preloaded=cmss10
May 01 14:28:29 \font\preloaded=cmssq8
May 01 14:28:29 \font\preloaded=cmssi10
May 01 14:28:29 \font\preloaded=cmssqi8
May 01 14:28:29 \font\tenbf=cmbx10
May 01 14:28:29 \font\preloaded=cmbx9
May 01 14:28:29 \font\preloaded=cmbx8
May 01 14:28:29 \font\sevenbf=cmbx7
May 01 14:28:29 \font\preloaded=cmbx6
May 01 14:28:29 \font\fivebf=cmbx5
May 01 14:28:29 \font\tentt=cmtt10
May 01 14:28:29 \font\preloaded=cmtt9
May 01 14:28:29 \font\preloaded=cmtt8
May 01 14:28:29 \font\preloaded=cmsltt10
May 01 14:28:29 \font\tensl=cmsl10
May 01 14:28:29 \font\preloaded=cmsl9
May 01 14:28:29 \font\preloaded=cmsl8
May 01 14:28:29 \font\tenit=cmti10
May 01 14:28:29 \font\preloaded=cmti9
May 01 14:28:29 \font\preloaded=cmti8
May 01 14:28:29 \font\preloaded=cmti7
May 01 14:28:29 \font\preloaded=cmu10
May 01 14:28:29 \font\preloaded=cmmib10
May 01 14:28:29 \font\preloaded=cmbsy10
May 01 14:28:29 \font\preloaded=cmcsc10
May 01 14:28:29 \font\preloaded=cmssbx10
May 01 14:28:29 \font\preloaded=cmdunh10
May 01 14:28:29 \font\preloaded=cmr7 at 14.51799pt
May 01 14:28:29 \font\preloaded=cmtt10 at 14.4pt
May 01 14:28:29 \font\preloaded=cmssbx10 at 14.4pt
May 01 14:28:29 \font\preloaded=manfnt
May 01 14:28:29 50 preloaded fonts
May 01 14:28:29 warning  (pdf backend): no pages of output.
May 01 14:28:29 Transcript written on luatex.log.
May 01 14:28:29 fmtutil [INFO]: log file copied to:
/var/lib/texmf/web2c/luatex/luatex.log
May 01 14:28:29 fmtutil [INFO]: /var/lib/texmf/web2c/luatex/luatex.fmt
installed.
May 01 14:28:30 fmtutil [INFO]: --- remaking dvilualatex-dev with luatex
May 01 14:28:31 fmtutil: running `luatex -ini -jobname=dvilualatex-dev
-progname=dvilualatex-dev dvilualatex.ini' ...
May 01 14:28:31 This is LuaTeX, Version 1.17.0 (TeX Live 2023/Debian) 
(INITEX)
May 01 14:28:31  restricted system commands enabled.
May 01 14:28:31
(/usr/share/texlive/texmf-dist/tex/latex/tex-ini-files/dvilualatex.ini
May 01 14:28:31
(/usr/share/texlive/texmf-dist/tex/latex/tex-ini-files/lualatex.ini
May 01 14:28:31
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/luatexconfig.tex
May 01 14:28:31 (/var/lib/texmf/tex/generic/tex-ini-files/pdftexconfig.tex))
May 01 14:28:31 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/latex.ltx
May 01 14:28:31
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/texsys.cfg)
May 01 14:28:31 ./texsys.aux found
May 01 14:28:31
May 01 14:28:31
May 01 14:28:31 \@currdir set to: ./.
May 01 14:28:31
May 01 14:28:31
May 01 14:28:31 Assuming \openin and \input
May 01 14:28:31 have the same search path.
May 01 14:28:31
May 01 14:28:31
May 01 14:28:31 Defining UNIX/DOS style filename parser.
May 01 14:28:31
May 01 14:28:46 catcodes, registers, parameters,
May 01 14:28:46 LaTeX2e <2024-06-01> pre-release-0 (develop 2024-5-1 branch)
May 01 14:28:46 (/usr/share/texlive/texmf-dist/tex/latex/l3kernel/expl3.ltx
May 01 14:51:15
(/usr/share/texlive/texmf-dist/tex/latex/l3kernel/expl3-code.tex)) hacks,
May 01 14:51:19 document commands, control, par, spacing, files, font
encodings, lengths,
May 01 14:51:19 ====================================
May 01 14:51:19
May 01 14:51:19 Local config file fonttext.cfg used
May 01 14:51:19
May 01 14:51:19 ====================================
May 01 14:51:19
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/fonttext.cfg
May 01 14:51:20
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/fonttext.ltx
May 01 14:51:20 === Don't modify this file, use a .cfg file instead ===
May 01 14:51:20
May 01 14:51:20
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/omlenc.def)
May 01 14:51:20
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/omsenc.def)
May 01 14:51:20
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/ot1enc.def)
May 01 14:51:20 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/t1enc.def)
May 01 14:51:20
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/ts1enc.def)
May 01 14:51:21 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/tuenc.def)
May 01 14:51:21 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/tulmr.fd)
May 01 14:51:21 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/tulmss.fd)
May 01 14:51:21 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/tulmtt.fd)
May 01 14:51:21 (/usr/share/texmf/tex/latex/lm/ts1lmr.fd)
May 01 14:51:21 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/t1cmr.fd)
May 01 14:51:21 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/ot1cmr.fd)
May 01 14:51:21
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/ot1cmss.fd)
May 01 14:51:21
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/ot1cmtt.fd)))
May 01 14:51:21 ====================================
May 01 14:51:21
May 01 14:51:21 Local config file fontmath.cfg used
May 01 14:51:21
May 01 14:51:21 ====================================
May 01 14:51:21
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/fontmath.cfg
May 01 14:51:21
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/fontmath.ltx
May 01 14:51:21 === Don't modify this file, use a .cfg file instead ===
May 01 14:51:21
May 01 14:51:21 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/omlcmm.fd)
May 01 14:51:21
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/omscmsy.fd)
May 01 14:51:21
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/omxcmex.fd)
May 01 14:51:23 (/usr/share/texlive/texmf-dist/tex/latex-dev/base/ucmr.fd)))
May 01 14:51:23 ====================================
May 01 14:51:23
May 01 14:51:23 Local config file preload.cfg used
May 01 14:51:23
May 01 14:51:23 =====================================
May 01 14:51:23
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/preload.cfg
May 01 14:51:24
(/usr/share/texlive/texmf-dist/tex/latex-dev/base/preload.ltx)) page nos.,
May 01 14:51:26 x-ref, environments, center, verbatim, math definitions,
boxes, title,
May 01 14:51:27 sectioning, contents, floats, footnotes, index,
bibliography, output,
May 01 14:51:28  Unicode character data,
May 01 14:51:28
(/usr/share/texlive/texmf-dist/tex/generic/unicode-data/load-unicode-data.tex
May 01 14:51:28
May 01 14:51:28 load-unicode-data.tex v1.17 (2023-09-18)
May 01 14:51:28 Reading Unicode data
May 01 14:51:28 # UnicodeData-15.1.0.txt
May 01 14:51:28 # Modified 2023-09-18 08:45:00 GMT [JAW]
May 01 14:53:01 )
May 01 14:53:01 ===========================================
May 01 14:53:01 Local configuration file hyphen.cfg used
May 01 14:53:01 ===========================================
May 01 14:53:01 (/usr/share/texlive/texmf-dist/tex/generic/babel/hyphen.cfg
May 01 14:53:01
(/usr/share/texlive/texmf-dist/tex/generic/babel/luababel.def)
May 01 14:53:02
(/usr/share/texlive/texmf-dist/tex/generic/hyphen/hyphen.tex))
May 01 14:53:02
(/usr/share/texlive/texmf-dist/tex/latex-dev/firstaid/latex2e-first-aid-for-ext
May 01 14:53:04 ernal-files.ltx)
May 01 14:53:45 )))
May 01 14:53:45 Beginning to dump on file dvilualatex-dev.fmt
May 01 14:53:45  (format=dvilualatex-dev 2024.5.1)
May 01 14:53:45 23452 strings using 413602 bytes
May 01 14:53:45 3882563 memory locations dumped; current usage is 204&494787
May 01 14:53:45 22115 multiletter control sequences
May 01 14:53:45 \font\nullfont=nullfont
May 01 14:53:45 \font\OMX/cmex/m/n/10=cmex10
May 01 14:53:45 \font\tenln=line10
May 01 14:53:45 \font\tenlnw=linew10
May 01 14:53:45 \font\tencirc=lcircle10
May 01 14:53:45 \font\tencircw=lcirclew10
May 01 14:53:45 \font\OT1/cmr/m/n/5=cmr5
May 01 14:53:45 \font\OT1/cmr/m/n/7=cmr7
May 01 14:53:45 \font\OT1/cmr/m/n/10=cmr10
May 01 14:53:45 \font\OML/cmm/m/it/5=cmmi5
May 01 14:53:45 \font\OML/cmm/m/it/7=cmmi7
May 01 14:53:45 \font\OML/cmm/m/it/10=cmmi10
May 01 14:53:45 \font\OMS/cmsy/m/n/5=cmsy5
May 01 14:53:45 \font\OMS/cmsy/m/n/7=cmsy7
May 01 14:53:45 \font\OMS/cmsy/m/n/10=cmsy10
May 01 14:53:45 14 preloaded fonts
May 01 14:53:45 No pages of output.
May 01 14:53:45 Transcript written on dvilualatex-dev.log.
May 01 14:53:46 fmtutil [INFO]: log file copied to:
/var/lib/texmf/web2c/luatex/dvilualatex-dev.log
May 01 14:53:46 fmtutil [INFO]:
/var/lib/texmf/web2c/luatex/dvilualatex-dev.fmt installed.
May 01 14:53:47 fmtutil [INFO]: --- remaking dvilualatex with luatex
May 01 14:53:47 fmtutil: running `luatex -ini -jobname=dvilualatex
-progname=dvilualatex dvilualatex.ini' ...
May 01 14:53:48 This is LuaTeX, Version 1.17.0 (TeX Live 2023/Debian) 
(INITEX)
May 01 14:53:48  restricted system commands enabled.
May 01 14:53:48
(/usr/share/texlive/texmf-dist/tex/latex/tex-ini-files/dvilualatex.ini
May 01 14:53:48
(/usr/share/texlive/texmf-dist/tex/latex/tex-ini-files/lualatex.ini
May 01 14:53:48
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/luatexconfig.tex
May 01 14:53:48 (/var/lib/texmf/tex/generic/tex-ini-files/pdftexconfig.tex))
May 01 14:53:48 (/usr/share/texlive/texmf-dist/tex/latex/base/latex.ltx
May 01 14:53:48 (/usr/share/texlive/texmf-dist/tex/latex/base/texsys.cfg)
May 01 14:53:48 ./texsys.aux found
May 01 14:53:48
May 01 14:53:48
May 01 14:53:48 \@currdir set to: ./.
May 01 14:53:48
May 01 14:53:48
May 01 14:53:48 Assuming \openin and \input
May 01 14:53:48 have the same search path.
May 01 14:53:48
May 01 14:53:48
May 01 14:53:48 Defining UNIX/DOS style filename parser.
May 01 14:53:48
May 01 14:54:02 catcodes, registers, parameters,
May 01 14:54:02 LaTeX2e <2023-11-01> patch level 1
May 01 14:54:02 (/usr/share/texlive/texmf-dist/tex/latex/l3kernel/expl3.ltx
May 01 15:16:22
(/usr/share/texlive/texmf-dist/tex/latex/l3kernel/expl3-code.tex)) hacks,
May 01 15:16:27 document commands, control, par, spacing, files, font
encodings, lengths,
May 01 15:16:27 ====================================
May 01 15:16:27
May 01 15:16:27 Local config file fonttext.cfg used
May 01 15:16:27
May 01 15:16:27 ====================================
May 01 15:16:27 (/usr/share/texlive/texmf-dist/tex/latex/base/fonttext.cfg
May 01 15:16:27 (/usr/share/texlive/texmf-dist/tex/latex/base/fonttext.ltx
May 01 15:16:27 === Don't modify this file, use a .cfg file instead ===
May 01 15:16:27
May 01 15:16:27 (/usr/share/texlive/texmf-dist/tex/latex/base/omlenc.def)
May 01 15:16:27 (/usr/share/texlive/texmf-dist/tex/latex/base/omsenc.def)
May 01 15:16:27 (/usr/share/texlive/texmf-dist/tex/latex/base/ot1enc.def)
May 01 15:16:27 (/usr/share/texlive/texmf-dist/tex/latex/base/t1enc.def)
May 01 15:16:27 (/usr/share/texlive/texmf-dist/tex/latex/base/ts1enc.def)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/tuenc.def)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/tulmr.fd)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/tulmss.fd)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/tulmtt.fd)
May 01 15:16:28 (/usr/share/texmf/tex/latex/lm/ts1lmr.fd)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/t1cmr.fd)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/ot1cmr.fd)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/ot1cmss.fd)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/ot1cmtt.fd)))
May 01 15:16:28 ====================================
May 01 15:16:28
May 01 15:16:28 Local config file fontmath.cfg used
May 01 15:16:28
May 01 15:16:28 ====================================
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/fontmath.cfg
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/fontmath.ltx
May 01 15:16:28 === Don't modify this file, use a .cfg file instead ===
May 01 15:16:28
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/omlcmm.fd)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/omscmsy.fd)
May 01 15:16:28 (/usr/share/texlive/texmf-dist/tex/latex/base/omxcmex.fd)
May 01 15:16:30 (/usr/share/texlive/texmf-dist/tex/latex/base/ucmr.fd)))
May 01 15:16:30 ====================================
May 01 15:16:30
May 01 15:16:30 Local config file preload.cfg used
May 01 15:16:30
May 01 15:16:30 =====================================
May 01 15:16:30 (/usr/share/texlive/texmf-dist/tex/latex/base/preload.cfg
May 01 15:16:31
(/usr/share/texlive/texmf-dist/tex/latex/base/preload.ltx)) page nos.,
x-ref,
May 01 15:16:32 environments, center, verbatim, math definitions, boxes,
title, sectioning,
May 01 15:16:34 contents, floats, footnotes, index, bibliography, output,
May 01 15:16:34  Unicode character data,
May 01 15:16:34
(/usr/share/texlive/texmf-dist/tex/generic/unicode-data/load-unicode-data.tex
May 01 15:16:34
May 01 15:16:34 load-unicode-data.tex v1.17 (2023-09-18)
May 01 15:16:34 Reading Unicode data
May 01 15:16:34 # UnicodeData-15.1.0.txt
May 01 15:16:34 # Modified 2023-09-18 08:45:00 GMT [JAW]
May 01 15:18:05 )
May 01 15:18:05 ===========================================
May 01 15:18:05 Local configuration file hyphen.cfg used
May 01 15:18:05 ===========================================
May 01 15:18:05 (/usr/share/texlive/texmf-dist/tex/generic/babel/hyphen.cfg
May 01 15:18:05
(/usr/share/texlive/texmf-dist/tex/generic/babel/luababel.def)
May 01 15:18:06
(/usr/share/texlive/texmf-dist/tex/generic/hyphen/hyphen.tex))
May 01 15:18:06
(/usr/share/texlive/texmf-dist/tex/latex/firstaid/latex2e-first-aid-for-externa
May 01 15:18:08 l-files.ltx)
May 01 15:18:48 )))
May 01 15:18:48 Beginning to dump on file dvilualatex.fmt
May 01 15:18:48  (format=dvilualatex 2024.5.1)
May 01 15:18:48 23452 strings using 413590 bytes
May 01 15:18:48 3882727 memory locations dumped; current usage is 204&494422
May 01 15:18:48 22115 multiletter control sequences
May 01 15:18:48 \font\nullfont=nullfont
May 01 15:18:48 \font\OMX/cmex/m/n/10=cmex10
May 01 15:18:48 \font\tenln=line10
May 01 15:18:48 \font\tenlnw=linew10
May 01 15:18:48 \font\tencirc=lcircle10
May 01 15:18:48 \font\tencircw=lcirclew10
May 01 15:18:48 \font\OT1/cmr/m/n/5=cmr5
May 01 15:18:48 \font\OT1/cmr/m/n/7=cmr7
May 01 15:18:48 \font\OT1/cmr/m/n/10=cmr10
May 01 15:18:48 \font\OML/cmm/m/it/5=cmmi5
May 01 15:18:48 \font\OML/cmm/m/it/7=cmmi7
May 01 15:18:48 \font\OML/cmm/m/it/10=cmmi10
May 01 15:18:48 \font\OMS/cmsy/m/n/5=cmsy5
May 01 15:18:48 \font\OMS/cmsy/m/n/7=cmsy7
May 01 15:18:48 \font\OMS/cmsy/m/n/10=cmsy10
May 01 15:18:48 14 preloaded fonts
May 01 15:18:48 No pages of output.
May 01 15:18:48 Transcript written on dvilualatex.log.
May 01 15:18:50 fmtutil [INFO]: log file copied to:
/var/lib/texmf/web2c/luatex/dvilualatex.log
May 01 15:18:50 fmtutil [INFO]:
/var/lib/texmf/web2c/luatex/dvilualatex.fmt installed.
May 01 15:18:50 fmtutil [INFO]: --- remaking dviluatex with luatex
May 01 15:18:51 fmtutil: running `luatex -ini   -jobname=dviluatex
-progname=dviluatex dviluatex.ini' ...
May 01 15:18:52 This is LuaTeX, Version 1.17.0 (TeX Live 2023/Debian) 
(INITEX)
May 01 15:18:52  restricted system commands enabled.
May 01 15:18:52
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/dviluatex.ini
May 01 15:18:52
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/luatex.ini
May 01 15:18:52
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/luatexconfig.tex
May 01 15:18:52 (/var/lib/texmf/tex/generic/tex-ini-files/pdftexconfig.tex))
May 01 15:18:52
(/usr/share/texlive/texmf-dist/tex/generic/tex-ini-files/luatexiniconfig.tex)
May 01 15:18:52
(/usr/share/texlive/texmf-dist/tex/generic/unicode-data/load-unicode-data.tex
May 01 15:18:52
May 01 15:18:52 load-unicode-data.tex v1.17 (2023-09-18)
May 01 15:18:52 Reading Unicode data
May 01 15:18:52 # UnicodeData-15.1.0.txt
May 01 15:18:52 # Modified 2023-09-18 08:45:00 GMT [JAW]
May 01 15:20:23 )
(/usr/share/texlive/texmf-dist/tex/luatex/hyph-utf8/etex.src
May 01 15:20:23 (/usr/share/texlive/texmf-dist/tex/plain/base/plain.tex
May 01 15:20:23 Preloading the plain format: codes, registers,
parameters, fonts, more fonts,
May 01 15:20:23 macros, math definitions, output routines, hyphenation
May 01 15:20:23 (/usr/share/texlive/texmf-dist/tex/generic/hyphen/hyphen.tex
May 01 15:20:23 [skipping from \patterns to end-of-file...]))
May 01 15:20:23 (/usr/share/texlive/texmf-dist/tex/plain/etex/etexdefs.lib
May 01 15:20:23 Skipping module "grouptypes"; Loading module
"interactionmodes";
May 01 15:20:23 Skipping module "nodetypes"; Skipping module "iftypes";)
May 01 15:20:23 (/var/lib/texmf/tex/generic/config/language.def
May 01 15:20:24
(/usr/share/texlive/texmf-dist/tex/generic/hyphen/hyphen.tex))
May 01 15:20:24 Augmenting the Plain TeX definitions: \tracingall;
May 01 15:20:24 Adding new e-TeX definitions: \eTeX, \loggingall,
\tracingnone,
May 01 15:20:24 register allocation; extended register allocation;
May 01 15:20:24 Recycling: \addlanguage, \@nswer (not defined), \@sk,
\b@dresponsetrue,
May 01 15:20:24 \b@dresponsefalse, \ch@ckforyn, \mayber@cycle,
\et@xabort, \et@xbuf,
May 01 15:20:24 \et@xfmtsrc, \et@xfilehdr, \et@xinf, \et@xpatterns,
\l@ngdefnfile, \n@xt,
May 01 15:20:24 \p@rse (not defined), \pr@mpt (not defined), \pr@mptloop
(not defined),
May 01 15:20:24 \forcer@cycle, \usef@llback, \usef@llbacktrue,
\usef@llbackfalse,
May 01 15:20:24 Retaining: \et@xerr, \et@xinput, \et@xlibhdr, \et@xmsg,
\et@xtoks, \et@xwarn,
May 01 15:20:24 \et@xl@@d, \et@xl@ad, \et@xload, \et@xlang, \et@xhash,
\eTeX, \etexhdrchk,
May 01 15:20:31 \etexstatus, \module, \uselanguage, \r@tain, \r@cycle,)))
May 01 15:20:31 Beginning to dump on file dviluatex.fmt
May 01 15:20:31  (format=dviluatex 2024.5.1)
May 01 15:20:31 3394 strings using 10325 bytes
May 01 15:20:31 68809 memory locations dumped; current usage is 149&7701
May 01 15:20:31 1883 multiletter control sequences
May 01 15:20:31 \font\nullfont=nullfont
May 01 15:20:31 \font\tenrm=cmr10
May 01 15:20:31 \font\preloaded=cmr9
May 01 15:20:31 \font\preloaded=cmr8
May 01 15:20:31 \font\sevenrm=cmr7
May 01 15:20:31 \font\preloaded=cmr6
May 01 15:20:31 \font\fiverm=cmr5
May 01 15:20:31 \font\teni=cmmi10
May 01 15:20:31 \font\preloaded=cmmi9
May 01 15:20:31 \font\preloaded=cmmi8
May 01 15:20:31 \font\seveni=cmmi7
May 01 15:20:31 \font\preloaded=cmmi6
May 01 15:20:31 \font\fivei=cmmi5
May 01 15:20:31 \font\tensy=cmsy10
May 01 15:20:31 \font\preloaded=cmsy9
May 01 15:20:32 \font\preloaded=cmsy8
May 01 15:20:32 \font\sevensy=cmsy7
May 01 15:20:32 \font\preloaded=cmsy6
May 01 15:20:32 \font\fivesy=cmsy5
May 01 15:20:32 \font\tenex=cmex10
May 01 15:20:32 \font\preloaded=cmss10
May 01 15:20:32 \font\preloaded=cmssq8
May 01 15:20:32 \font\preloaded=cmssi10
May 01 15:20:32 \font\preloaded=cmssqi8
May 01 15:20:32 \font\tenbf=cmbx10
May 01 15:20:32 \font\preloaded=cmbx9
May 01 15:20:32 \font\preloaded=cmbx8
May 01 15:20:32 \font\sevenbf=cmbx7
May 01 15:20:32 \font\preloaded=cmbx6
May 01 15:20:32 \font\fivebf=cmbx5
May 01 15:20:32 \font\tentt=cmtt10
May 01 15:20:32 \font\preloaded=cmtt9
May 01 15:20:32 \font\preloaded=cmtt8
May 01 15:20:32 \font\preloaded=cmsltt10
May 01 15:20:32 \font\tensl=cmsl10
May 01 15:20:32 \font\preloaded=cmsl9
May 01 15:20:32 \font\preloaded=cmsl8
May 01 15:20:32 \font\tenit=cmti10
May 01 15:20:32 \font\preloaded=cmti9
May 01 15:20:32 \font\preloaded=cmti8
May 01 15:20:32 \font\preloaded=cmti7
May 01 15:20:32 \font\preloaded=cmu10
May 01 15:20:32 \font\preloaded=cmmib10
May 01 15:20:32 \font\preloaded=cmbsy10
May 01 15:20:32 \font\preloaded=cmcsc10
May 01 15:20:32 \font\preloaded=cmssbx10
May 01 15:20:32 \font\preloaded=cmdunh10
May 01 15:20:32 \font\preloaded=cmr7 at 14.51799pt
May 01 15:20:32 \font\preloaded=cmtt10 at 14.4pt
May 01 15:20:32 \font\preloaded=cmssbx10 at 14.4pt
May 01 15:20:32 \font\preloaded=manfnt
May 01 15:20:32 50 preloaded fonts
May 01 15:20:32 No pages of output.
May 01 15:20:32 Transcript written on dviluatex.log.
May 01 15:20:32 fmtutil [INFO]: log file copied to:
/var/lib/texmf/web2c/luatex/dviluatex.log
May 01 15:20:32 fmtutil [INFO]:
/var/lib/texmf/web2c/luatex/dviluatex.fmt installed.
May 01 15:20:32 fmtutil [INFO]: successfully rebuilt formats: 4
May 01 15:20:32 fmtutil [INFO]: not selected formats: 13
May 01 15:20:32 fmtutil [INFO]: total formats: 17
May 01 15:20:32 fmtutil [INFO]: exiting with status 0

real    53m55.118s
user    53m50.186s
sys     0m1.374s

#1070150#25
Date:
2024-05-01 21:17:55 UTC
From:
To:
On 01.05.2024 22:46, Steev Klimaszewski wrote:

Hi,

Noticed that too, that loading this file takes quite long. In Debian
stable (on a Rasbpi4) it are just a few seconds. In a chroot (Debian
unstable / experimental) it takes longer, but still not the 30 minutes I
see in your log. There is no difference between pdflatex and lualatex.

H,

#1070150#30
Date:
2024-05-01 22:42:31 UTC
From:
To:
Hi Hilmar,
Correct, when run on the same host architecture, it's fine.  The issue
comes in when running on an amd64 host, and in an arm64 chroot.  So,
e.g. running an arm64 docker container on amd64, or running an arm64
systemd-nspawn container on an amd64 host.  While, yes, qemu-user
emulation is slow (single threaded iirc?) stable takes 13 minutes to
do this, testing/unstable/experimental take significantly longer as
mentioned.

#1070150#35
Date:
2024-05-01 23:44:37 UTC
From:
To:
Hi all,

at Debian they got a report that loading expl3.ltx when building formats
is **extremely** slow when running under emulations:

1070150@bugs.debian.org

Running fmtutil output through ts (timestamp utility from moreutils):

May 01 14:28:46 LaTeX2e <2024-06-01> pre-release-0 (develop 2024-5-1 branch)
May 01 14:28:46 (/usr/share/texlive/texmf-dist/tex/latex/l3kernel/expl3.ltx
May 01 14:51:15 (/usr/share/texlive/texmf-dist/tex/latex/l3kernel/expl3-code.tex)) hacks,
May 01 14:51:19 document commands, control, par, spacing, files, font encodings, lengths,

That is 23 **minutes** to load expl3-code.tex. Ok, the file is nearly 4k
lines, but still, 23 minutes seems to be excessive.

Any ideas?

Please keep the Cc

Best regards

Norbert

#1070150#40
Date:
2024-05-02 05:48:39 UTC
From:
To:
Hi Norbert,

I don't think that this is TeX-related. From a Fedora 39 x86_64 host:

    $ podman run --arch arm64 --rm -it --pull always debian:stable /bin/bash

    $ apt update && \
      apt install -y moreutils && \
      apt install -y --download-only python3-minimal
    [...]

    $ time apt install -y python3-minimal | ts
    May 02 05:27:51 Reading package lists...
    May 02 05:27:52 Building dependency tree...
    May 02 05:27:52 Reading state information...
    May 02 05:27:52 The following additional packages will be installed:
    May 02 05:27:52   ca-certificates krb5-locales libexpat1 libgpm2 libgssapi-krb5-2 libk5crypto3
    May 02 05:27:52   libkeyutils1 libkrb5-3 libkrb5support0 libncursesw6 libnsl2
    May 02 05:27:52   libpython3.11-minimal libpython3.11-stdlib libreadline8 libsqlite3-0 libssl3
    May 02 05:27:52   libtirpc-common libtirpc3 media-types openssl python3.11 python3.11-minimal
    May 02 05:27:52   readline-common
    May 02 05:27:52 Suggested packages:
    May 02 05:27:52   gpm krb5-doc krb5-user python3.11-venv python3.11-doc binutils
    May 02 05:27:52   binfmt-support readline-doc
    May 02 05:27:53 The following NEW packages will be installed:
    May 02 05:27:53   ca-certificates krb5-locales libexpat1 libgpm2 libgssapi-krb5-2 libk5crypto3
    May 02 05:27:53   libkeyutils1 libkrb5-3 libkrb5support0 libncursesw6 libnsl2
    May 02 05:27:53   libpython3.11-minimal libpython3.11-stdlib libreadline8 libsqlite3-0 libssl3
    May 02 05:27:53   libtirpc-common libtirpc3 media-types openssl python3-minimal python3.11
    May 02 05:27:53   python3.11-minimal readline-common
    [...]
    May 02 05:28:40 done.

    real	0m52.253s
    user	0m51.889s
    sys	0m7.453s

    $ exit

    $ podman run --arch arm64 --rm --pull always -it debian:sid /bin/bash

    $ apt update && \
      apt install -y moreutils && \
      apt install -y --download-only python3-minimal
    [...]

    $ time apt install -y python3-minimal | ts
    May 02 05:29:22 Reading package lists...
    May 02 05:29:26 Building dependency tree...
    May 02 05:29:26 Reading state information...
    May 02 05:29:30 Installing:
    May 02 05:29:30   python3-minimal
    May 02 05:29:30
    May 02 05:29:30 Installing dependencies:
    May 02 05:29:30   ca-certificates libpython3.11-minimal media-types        readline-common
    May 02 05:29:30   libexpat1       libpython3.11-stdlib  openssl
    May 02 05:29:30   libgpm2         libreadline8t64       python3.11
    May 02 05:29:30   libncursesw6    libsqlite3-0          python3.11-minimal
    May 02 05:29:30
    May 02 05:29:30 Suggested packages:
    May 02 05:29:30   gpm python3.11-venv python3.11-doc binutils binfmt-support readline-doc
    [...]
    May 02 05:32:56 done.

    real	3m52.398s
    user	3m54.177s
    sys	0m7.514s

    $ exit

Thanks,
-- Max

#1070150#45
Date:
2024-05-02 08:44:40 UTC
From:
To:
Hi Max,

sorry, but I don't understand!!

Your data:
[...]
[...]

That is a 4 times increase, ok, this does a lot of things. IN
particular, apt uses fsync a lot.

But what I measured in the emails is *only* the loading of one text
file, without IO ops.

Best regards

Norbert

#1070150#50
Date:
2024-05-02 10:16:19 UTC
From:
To:
Hi Norbert,

I noticed that everything seemed much slower when trying to install the
TeX in the container, so I thought that it might be that the entire
system is slower, not just TeX.

   $ sudo strace -ffe read fmtutil-sys --byfmt lualatex 2>&1 | wc -l
   21440

But I've done some further testing, and my initial guess was completely
wrong (sorry). This *does* appear to be an issue particular to the
Debian TeX binaries. Using the attached file "factorial.tex" (you can
change the "10000" inside the file to "1000" if you're impatient), on my
host system I get:

   $ time luatex --ini ./factorial.tex
   This is LuaTeX, Version 1.17.0 (TeX Live 2023)  (INITEX)
    restricted system commands enabled.
   (./factorial.tex)
   No pages of output.
   Transcript written on factorial.log.

   real    0m3.952s
   user    0m3.921s
   sys     0m0.030s

and inside an arm64 sid container I get:

   $ apt install --no-install-recommends texlive-binaries
   $ wget 'https://ftp.math.utah.edu/pub/tex/historic/systems/texlive/2023/tlnet-final/archive/luatex.aarch64-linux.tar.xz'
   $ tar xf luatex.aarch64-linux.tar.xz
   $ cd bin/aarch64-linux

   $ time luatex --ini ~/factorial.tex
   This is LuaTeX, Version 1.17.0 (TeX Live 2023/Debian)  (INITEX)
   (/root/factorial.tex)
   No pages of output.
   Transcript written on factorial.log.

   real	17m49.488s
   user	17m49.395s
   sys	0m0.016s

   $ time ./luatex --ini ~/factorial.tex
   warning: kpathsea: configuration file texmf.cnf not found [...]
   This is LuaTeX, Version 1.17.0 (TeX Live 2023)  (INITEX)
   (/root/factorial.tex)
   No pages of output.
   Transcript written on factorial.log.

   real	0m42.353s
   user	0m42.319s
   sys	0m0.021s

Last year, there was a similar problem where the main TeX Live LuaTeX
binaries were compiled with full debug symbols, but that was a ~50%
slowdown, not a 25x slowdown. See the thread starting at

https://tug.org/pipermail/luatex/2023-August/007853.html

or some more detailed benchmarks at

https://tug.org/pipermail/luatex/2023-August/007875.html
https://tug.org/pipermail/luatex/2023-August/007864.html

Looking through the build logs

https://tests.reproducible-builds.org/debian/rbuild/unstable/amd64/texlive-bin_2023.20230311.66589-9.rbuild.log.gz

it looks like the LuaTeX binaries were compiled with "-g -O2", but
running "readelf" and "objdump" shows that they're stripped, so I don't
think that that's the issue here.

And this issue appears to affect all engines: I also tried testing with
pdfTeX (comment out the \directlua line, and add the --etex command line
flag), and for 1000 iterations I got:

   Debian Sid    arm64  LuaTeX: 0m15.392s
   Debian Sid    arm64  pdfTeX: 0m7.914s
   TeX Live 2023 arm64  LuaTeX: 0m0.737s
   TeX Live 2023 x86_64 pdfTeX: 0m0.156s
   TeX Live 2023 x86_64 LuaTeX: 0m0.156s

I'm not sure what's going on here, but hopefully this gives you some
clues.

Thanks,
-- Max

#1070150#55
Date:
2024-05-02 13:17:30 UTC
From:
To:
On 01.05.2024 00:19, Steev Klimaszewski wrote:

Hi all,

I assume this is important, further the package needs to be corrected.

H.

#1070150#66
Date:
2024-05-02 20:47:41 UTC
From:
To:
    it looks like the LuaTeX binaries were compiled with "-g -O2", but
    running "readelf" and "objdump" shows that they're stripped, so I
    don't think that that's the issue here.

FWIW, it's my understanding that what matters for execution speed is not
the presence or absence of debug symbols (-g), but whether optimization
was enabled (-O2 or similar).

   Debian Sid    arm64  LuaTeX: 0m15.392s
   Debian Sid    arm64  pdfTeX: 0m7.914s
   TeX Live 2023 arm64  LuaTeX: 0m0.737s
   TeX Live 2023 x86_64 pdfTeX: 0m0.156s
   TeX Live 2023 x86_64 LuaTeX: 0m0.156s

Not sure whether to conclude it's arm-specific or sid-specific or both
from those numbers, but I suppose a few more runs would show.

LuaTeX 2024 could be getting slowed down a bit by the additional access
checking, I suppose, but there were no significant changes in pdfteX in
2024, so that can't be the whole explanation.

FWIW, building lualatex.fmt on my x86_64-linux (Rocky Linux 9.3) home
machine, with the TL luahbtex binary, took about six seconds.
Rebuilding all the formats took about 80 seconds, last time it happened.

Best,
Karl

#1070150#71
Date:
2024-05-03 07:51:24 UTC
From:
To:
From my testing, it seems specific to arm64 under qemu.  armhf/armel
do not seem to have the same load times at all.
From digging through our build server, the change occurred in Debian
testing sometime between the 15th and the 30th of November.  I have
the list of the 1122 packages that were changed in that time, and have
been slowing working through it to weed out the packages that
definitely couldn't cause the issue (not installed/won't be
installed), but it's slower going than I would like.  There is
definitely another performance regression, but none seem as severe as
this one which in our builds adds almost 3 hours to the time.
Unfortunately, I'm not at all experienced with LaTeX, and we're only
pulling the dependency in by happistance of something else depending
on it to generate pdf reports.  The main reason I suspected it is
that, according to the packaging changelog, arm64 enabled lua support
in the above timeframe.  As Max pointed out, sid is now much slower
than stable, so it could be something completely different is causing
this to manifest.