latex got slower with updates

[jjachimowicz]

After updating MiKTeX our existing document generation got around 2 times slower than before. After a lot of trials with installation of older versions, it seems that that the generation is fine in MiKTeX 20.6.29, but gets slower in of the version or versions after. I managed to create a fairly simple .tex file for reproduction (loading more packages than needed to get longer execution times):

\documentclass[a4paper]{book}

\usepackage{babel}
\usepackage{graphicx}
\usepackage{amsmath}
\usepackage{amssymb}
\usepackage[latin1]{inputenc}
\usepackage{layout}

\begin{document}

\chapter{somename}

\end{document}

If I run this in latex (latex myfile.tex -time-statistics) I get the following results:

1. In MiKTeX 21.3 (with all the latest updates):
   gross execution time: 778 ms
   user mode: 765 ms, kernel mode: 140 ms, total: 905
2. In MiKTeX 20.12 (out of the box, no updates):
   gross execution time: 633 ms
   user mode: 593 ms, kernel mode: 93 ms, total: 686
3. In MiKTeX 20.6.29 (out of the box, no updates):
   gross execution time: 256 ms
   user mode: 296 ms, kernel mode: 93 ms, total: 389

Of course the exact values for each run are not identical +-50ms, but the overall picture is the same: 20.12 is a slightly faster and 20.6.29 is much faster. That's similar to what we see when running our normal .tex files, but in our case the documents are much bigger and the performance impact is more problematic.

The performance difference seems the same also for the sample2e, where it gets around 2 times faster when switching from 21.3 (200ms) to 20.6.29 (100ms).

With every installation I'm also removing the miktex folders in user's AppData folder. Also tried experimenting with all users vs single user installation, but this doesn't influence the results.

miktex-report.txt
time.21.3.txt
time.20.12.txt
time.20.6.29.txt
The last 2 logs (20.12 and 20.6.29) contain information about not checking updates, but in that case it's justified. I rely on what is in the package to get older (faster) code. If I run the updates I get upgraded to 21.3 and get the exact same (slower) execution time.

[u-fischer]

you should test without loading all these files to identify how much the changes in latex itself (which contains now more code, more hooks and the shipout has changed too) and how much e.g. the file loading in miktex contribute to the slow down.
The file loading code in latex is larger now too (and so can be part of the slow down), but will change in the next latex release.

Side remark: you should switch to utf8, latin1 is really no longer up-to-date (and not supported everywhere).

[jjachimowicz]

You mean to skip all the packages and do just this:

\documentclass[a4paper]{book}

\begin{document}

\chapter{some name}

\end{document}

?

With that I get more or less something like:
In MiKTeX 20.6.29 (shows LaTeX2e <2020-02-02> patch level 5 / L3 programming layer <2020-06-18> in log):
gross execution time: 90 ms
user mode: 171 ms, kernel mode: 46 ms, total: 217

In MiKTeX 21.3 (shows LaTeX2e <2020-10-01> patch level 4 / L3 programming layer <2021-02-18> in log):
gross execution time: 146 ms
user mode: 281 ms, kernel mode: 109 ms, total: 390

Not sure if this means miktex or latex is a problem or both? It's still proportionally around 2 times slower.

[edocevoli]

If I use the --recorder option, I get this .fls file:

PWD C:\Users\cs\Desktop\782
INPUT C:\Users\cs\AppData\Local\MiKTeX\miktex\data\le\pdftex\latex.fmt
INPUT test.tex
OUTPUT test.log
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\bk10.clo
INPUT C:\Program Files\MiKTeX\tex\latex\base\bk10.clo
INPUT C:\Program Files\MiKTeX\tex\latex\base\bk10.clo
INPUT C:\Program Files\MiKTeX\tex\latex\base\bk10.clo
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT .\test.aux
INPUT test.aux
INPUT test.aux
OUTPUT test.aux
INPUT C:\Program Files\MiKTeX\fonts\tfm\public\cm\cmr17.tfm
INPUT C:\Program Files\MiKTeX\fonts\tfm\public\cm\cmbx12.tfm
INPUT C:\Program Files\MiKTeX\fonts\tfm\public\cm\cmbx12.tfm
OUTPUT test.dvi
INPUT test.aux

This would explain the performance degradation.

@jjachimowicz: can you repeat your test and then compare the .fls files?

[jjachimowicz]

Hi @edocevoli, indeed the amount INPUTs grows significantly.

In 20.6.29 it was all much shorter

PWD B:\miktex
INPUT C:\Users\svcBuild\AppData\Local\MiKTeX\miktex\data\le\pdftex\latex.fmt
INPUT myfile.tex
OUTPUT myfile.log
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\bk10.clo
INPUT C:\Program Files\MiKTeX\tex\latex\base\bk10.clo
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT C:\Program Files\MiKTeX\tex\latex\l3backend\l3backend-dvips.def
INPUT myfile.aux
INPUT myfile.aux
OUTPUT myfile.aux
INPUT C:\Program Files\MiKTeX\fonts\tfm\public\cm\cmr17.tfm
INPUT C:\Program Files\MiKTeX\fonts\tfm\public\cm\cmbx12.tfm
INPUT C:\Program Files\MiKTeX\fonts\tfm\public\cm\cmbx12.tfm
OUTPUT myfile.dvi
INPUT myfile.aux

In 20.6.29 there are 2 entries for "INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls", in 20.12 I get 10 entries like this and in 21.3 I get 11 entries. Same increase for l3backend-dvips.def. For bk10.clo it grows from 2 entries to 4.

I've attached the output .fls files.

myfile.20.6.29.fls.txt
myfile.20.12.fls.txt
myfile.21.3.fls.txt

[u-fischer]

@edocevoli I saw that and we are looking at it.

[edocevoli]

Is this still an issue? If so, we can reopen this ticket. But I think the performance issue has been "fixed" in the course of development.

[jjachimowicz]

Hi @edocevoli, I have now pulled all the possible updates for my Windows MiKTeX version and the issue is still there. I see some improvement in my real life documents, but it's not near the speed of MiKTeX 20.6.29. Originally I had generation times around 20s, then 55s when reporting this ticket and now I have something like 45s.

Moreover the amount of INPUT's I get with --recorder option is still exactly the same as you posted on April 24th. So I don't see an improvement here. Wasn't that supposed to be the reason?

[edocevoli]

The number of INPUTs is not under my control. LaTeX opens these files. This does not look nice:

INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls
INPUT C:\Program Files\MiKTeX\tex\latex\base\book.cls

But it cannot be avoided by MiKTeX.

Can I assume you used the same LaTeX version when you ran the tests?

[edocevoli]

I come to the conclusion that this is not a MiKTeX-specific issue. Comparing MiKTeX and TeX Live execution times by running time latex mytest:

real    0m0.677s
user    0m0.000s
sys     0m0.015s

real    0m0.747s
user    0m0.000s
sys     0m0.015s

[jjachimowicz]

@edocevoli have you tried comparing on Windows as I do? I tried comparing MiKTeX vs Tex Live on Windows and I get significantly different results (tried on few simple documents):
Measure-Command { latex myfile.tex } | select TotalMilliseconds
Gives:

• 653,1275 ms for MiKTeX 21.7
• 265,7214 ms for TeX Live 2021/W32TeX (reports the same LaTeX)

I also added the --recorder and both produce this big amount of INPUT for book.cls and others. So it's not the INPUT.

[edocevoli]

Yes, on Windows. I used a Cygwin bash shell.