pdflatex - how to find bottleneck of long compiling time for my document

Question

I'm having (again/still) a very large LateX document which I'm working on.

>340 pages
many graphics (mostly included pdf, but also some PNG or others)
many tables (also longtables)
resulting PDF is >18 MB in size
many references and citations

Compilation takes between 2 and 7 minutes normally. I'm using latexmk for complete compiling, so the given times normally is for several latex runs in total.

Nevertheless I'd like to speed up the process of recompiling and try to find the bottlenecks. When I see the console output, it seems to hang at some points where compiling takes longer.

Is there a way to analyze which steps takes how much time and thus find those 20% of the things which might cause 80% of the compiling time?

E. g. can I print the duration it takes to process each page and so see which pages take the most time to build?

Pareto rules:

Thanks to @Robert 's answer, I now have the compiling times of each page and

indeed it is about 20 pages of the 340 which take more than 50% of the compiling time!
2 pages even need about 20 s for compiling!
none of  those "slow pages" seems to include PNG images

Very strange, I'll have to dig deeper - maybe cross references or fixme remarks are the problem?!

Robert · Accepted Answer

You could build your timer with pdfelapsedtime:

usepackage{atbegshi}
newcommandshowtimer{%
  message{^^Jtimer: thenumexprthepdfelapsedtime*1000/65536relax}%
  pdfresettimer}
AtBeginDocument{showtimer}
AtBeginShipout {showtimer}

would print the time it took (in milliseconds) for each page to be output 
(here p. 231 took 103ms, p. 232 took 44ms):

timer: 103 [231] 
timer: 44 [232]

Note that due to the asynchronous nature of tex's output routine, this isn't completely exact: firstly, the page breaker usually only kicks in after a paragraph break, so that material that will actually end up on the next page (or even pages for very long paragraphs) has already been processed; secondly, inserts (floats, footnotes) may have been processed already earlier -- for example, split footnotes or floats that didn't fit on the previous page(s). So the numbers may actually measure the processing time both of material from previous and from later pages.

For evaluation you can extract those lines:

grep '^timer:' filename.log > Compiletime.txt

Emil Vatai · Answer

Have you tried the typeout{msg} command.

http://www.personal.ceu.hu/tex/termio.htm

It might not be the nicest solution but with some cleverly placed typeout commands, you might find what you are looking for.

And if I remember correctly, there is a comment package to comment out large parts of your (La)Tex code.

Aubrey Blumsohn · Answer

Here is a version that works in LuaLatex if anyone is interested. Not sure if there might be a better Lua method but here is one:
usepackage{atbegshi}

directlua{pdfelapsedtimer_basetime=0}
protecteddefpdfresettimer{directlua{pdfelapsedtimer_basetime = os.clock()}}
protecteddefpdfelapsedtime{numexprdirectlua{tex.print(math.floor((os.clock()-pdfelapsedtimer_basetime)*65536+0.5))}relax}
newcommandshowtimer{%
  message{^^Jtimer: thenumexprthepdfelapsedtime*1000/65536relax}%
  pdfresettimer}
AtBeginDocument{showtimer}
AtBeginShipout {showtimer}

or perhaps even simpler, just these three lines in preamble
directlua{pdfelapsedtimer_basetime=os.clock()}
protecteddefpdfelapsedtime{numexprdirectlua{tex.print(math.floor((os.clock()-pdfelapsedtimer_basetime)))}relax}
newcommand{logtimer}[1]{ message{^^JMYTIMER: #1 --  thenumexprthepdfelapsedtimerelax ^^J}}

and then lines of code like so at appropriate points
logtimer{Before the big picture}

logtimer{Before chapter 7}

logtimer{After the sqiggly graph}

Then grep for MYTIMER in log

pdflatex - how to find bottleneck of long compiling time for my document

3 Answers

Add your own answers!

Ask a Question