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

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?!

• PNG inclusion may take time: “Embedding PNG images in the general case requires pdfTeX to uncompress the pixel array and to recompress it to the PDF requirements; this process often takes a noticeable amount of time” (from the manual). In particular, interlaced PNGs or use of gamma correction will trigger this process. If the fast copy feature is used, you see a message PNG copy in the log file. – egreg Nov 2 '14 at 10:47
• You can use the draft option, so that no images are included, only the bounding boxes. – Juri Robl Nov 2 '14 at 13:12
• you can't make a timer within tex but each time it ships out a page it puts [1] [2] [3] ... etc into the log file so you can see which pages are slow if you watch the terminal output – David Carlisle Nov 2 '14 at 13:34
• @DavidCarlisle: thanks, I noticed those page numbers but I wondered if it would not be possible to add at least a time stamp with the current time to each of those page numbers (to filter them out of the log later for analysis) – MostlyHarmless Nov 2 '14 at 19:40
• Do you really need to run latexmk every time? Why compile multiple times to get everything resolved when you are still working on a draft? I mostly compile a single time when drafting (and I don't necessarily compile at all if it is not especially visual). It sounds as if you are compiling to perfection every time and that seems quite unnecessary. – cfr Nov 11 '14 at 2:44

You could build your timer with \pdfelapsedtime:

\usepackage{atbegshi}
\newcommand\showtimer{%
\message{^^Jtimer: \the\numexpr\the\pdfelapsedtime*1000/65536\relax}%
\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

• in my setup, this also prints a :\relax into the line, but it helps me a lot seeing which pages take the most time!! Thank you so much! – MostlyHarmless Nov 11 '14 at 11:00
• @Martin Ah yes, I should never even add a colon without testing it... – Robert Nov 12 '14 at 2:04
• I tried that and in general it works, but I'm not yet sure how to interpret the results... are you sure that the cited time corresponds exactly to the page in [n] or could it be the processing time of page [n+1] or [n-1]? – MostlyHarmless Dec 17 '14 at 9:58
• @Martin you're right, see update. – Robert Dec 17 '14 at 18:19
• @Martin it wasn't really wrong before, only not precise enough about the difference between tex "outputting" a page in contrast to processing its contents. – Robert Dec 17 '14 at 20:16

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.

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}
\protected\def\pdfresettimer{\directlua{pdfelapsedtimer_basetime = os.clock()}}
\protected\def\pdfelapsedtime{\numexpr\directlua{tex.print(math.floor((os.clock()-pdfelapsedtimer_basetime)*65536+0.5))}\relax}
\newcommand\showtimer{%
\message{^^Jtimer: \the\numexpr\the\pdfelapsedtime*1000/65536\relax}%
\pdfresettimer}
\AtBeginDocument{\showtimer}
\AtBeginShipout {\showtimer}


or perhaps even simpler, just these three lines in preamble

\directlua{pdfelapsedtimer_basetime=os.clock()}
\protected\def\pdfelapsedtime{\numexpr\directlua{tex.print(math.floor((os.clock()-pdfelapsedtimer_basetime)))}\relax}
\newcommand{\logtimer}[1]{ \message{^^JMYTIMER: #1 --  \the\numexpr\the\pdfelapsedtime\relax ^^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