13

we're using a toolchain based on texlive 2015 and I made a try replacing it with the new released version of texlive 2017. As testobject I used or current document (~650 pages). I found out that a complete latexmk run for generating the pdf-document is about 50% slower than before.

Well since mid 2015 there have been a lot of changes to the packages, the compiler and scripts etc. So I now looking for a way to find the culprit.

Is there a way (best practice) to get detailed information about the compilation run and how much time was used for the different compilation steps (package, font loading, idx, page, toc generation etc.)?

Our toolchain is based on lualatex as compiler and latexmk as build script as well as many ctan packages.

Bye Holger

P.S.: I also had a look at these threads but couldn't find any suitable answer for my situation.

Package loading speeds

Are there LaTeX performance profiling tools?

aronadaal
  • 553
  • You could use Lua to profile. Just print out the timestamps after the documentclass has been loaded, then at the end of the preamble and wherever you need it. – TeXnician Jul 13 '17 at 11:24
  • 4
    If this was your first run with TL 2017, you'd expect it to be slower. You either would have to clear cached fonts etc. or ensure that you have current caches for both runs. The initial run with LuaTeX is always going to be slow, similarly XeTeX. LuaTeX has also undergone a great many changes since 2015. – cfr Jul 13 '17 at 12:17
  • 3
    Latexmk has an option -time to display the time used for each processing step. Does that do what you want? – John Collins Jul 13 '17 at 14:29
  • @cfr: You're right and I payed attention to that. For each version of texlive I made two runs and I always took the time of the second run for comparison. – aronadaal Jul 14 '17 at 07:28
  • @JohnCollins: Thanks, I didn't know that there is this option. I tried it out but the result is not really useful. see the greped output https://pastebin.com/bVPnESZe – aronadaal Jul 14 '17 at 07:30
  • 1
    @aronadaal: There is something very strange about your output which shows exactly zero time for each processing step except makeindex. Is that really the case? Even for a minimal document, on my system latexmk -time shows a substantially nonzero processing time for a run of lualatex, about half a second. Are you sure you are running exactly the standard version of latexmk? What is your operating system? Also check the output of the run carefully to make sure there wasn't some error that caused the processing steps to abort. – John Collins Jul 14 '17 at 13:08
  • Timing processes, as I understand it, is tricky. You want a measure of e.g. CPU processing time rather than total clock time, because the CPU or CPUs will always be multi-tasking. But other things can affect how much time is used, so it is always difficult to get a genuine comparison. That said, significantly different processing times across a range of documents would suggest a substantive change of some kind. – cfr Jul 14 '17 at 17:05
  • @JohnCollins Also, the total time bears no relation to the sum of the mostly-zeroes, which seems odd, too. – cfr Jul 14 '17 at 17:08
  • @cfr The time reported by latexmk is from what Perl's standard function times reports, which is documented to be CPU time, and latexmk reports the sum of user and system time and of the times for child processes. The exactly zero values reported for runs of lualatex strongly contradict normal behavior of latexmk, so until that problem is solved, it's not possible to give a diagnosis of the @aronadaal's problem. – John Collins Jul 14 '17 at 19:59
  • 2
    This has been asked before on the LuaTeX mailing list (https://www.tug.org/pipermail/luatex/2017-June/006533.html). It is most probably the fault of bad compilation flags. Are you using LuaTeX on some exotic platform by any chance? – Henri Menke Jul 17 '17 at 07:22
  • Which operating system do you use? – samcarter_is_at_topanswers.xyz Dec 13 '17 at 21:43
  • Cygwin under Windows 7 & 10 – aronadaal Dec 13 '17 at 21:45

1 Answers1

5

Ok, some time has gone by since my post above. I had some time fiddling and investigating further but still no solution for this.

I setup two different Docker containers relying on Ubuntu; one container is setup with Texlive 2015, one with Texlive 2017. I tried again our large project (>800 pages), still with the same reproducible result.

Next I had a look at the following "minimal" lualatex example code with some math but nearly no additional packages. I modified the loop to get more load:

for t=0, 360, 0.01 do

The pdf file cannot be displayed in my pdf viewer anymore but this doesn't matter. The main insight from this test for me is, that the difference in compilation speed is still significant:

LuaTeX, Version 1.0.4 (TeX Live 2017/Debian)
real    0m11.008s
user    0m10.700s
sys     0m0.200s

LuaTeX, Version beta-0.80.0 (TeX Live 2015/Debian) (rev 5238)
real    0m4.124s
user    0m3.810s
sys     0m0.240s

I also had a look at the conversation on the LuaTeX mailing list. There may be a difference in setting the right compilation flags, but what a kind of strange discussion. We are users/editors and not maintainers or developers of these packages. Finding and setting the best compilation flags is something I except from the experts. Anyway. I will talk to the Debian texlive maintainer for more information.

aronadaal
  • 553