30

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

MostlyHarmless
  • 12,160
  • 4
    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 02 '14 at 10:47
  • I read that already, but did not find any "PNG copy" in the log file. Should I better use another format than PNG for bitmap graphics? Where can I find more information about the best solution to include pixel graphics in a pdflatex document? – MostlyHarmless Nov 02 '14 at 10:51
  • 1
    You can use the draft option, so that no images are included, only the bounding boxes. – Juri Robl Nov 02 '14 at 13:12
  • 5
    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 02 '14 at 13:34
  • 1
    @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 02 '14 at 19:40
  • @JuriRobl: I used the draft option, but with latexmk it still takes at least 2 minutes (sometimes even more) to compile the document in draft mode. In addition to that, for writing/editing I'd like to see the graphics when I'm working on the text which is related to them... – MostlyHarmless Nov 02 '14 at 19:41
  • 1
    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 02:44
  • 1
    Also, a document that long should be split with parts \include or \input or whatever-ed. That way, you can just compile the bit you are working on rather than the whole thing. (You aren't making changes to all 300 pages at once, I take it.) – cfr Nov 11 '14 at 02:45
  • @cfr: good points. Yes, I should reduce perfection and compiling time by avoiding latexmk for each compilation. The document IS already split in parts, but I hesitate to compile include only the one I'm working on, because they are cross-referenced and inter-related and I'm currently moving content from one part to the other, etc. ... But I'll question my working approach and try to make it easier. – MostlyHarmless Nov 11 '14 at 09:33
  • 1
    @Martin How do you insert the "fixme remarks"? I suggest to make a MWE using the blindtext package and a lot of those remarks and compare the time without remarks to the compiling time with all the remarks. – Keks Dose Nov 11 '14 at 15:16

3 Answers3

20

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
Robert
  • 14,181
  • 1
  • 52
  • 77
  • 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
  • 2
    @Martin Ah yes, I should never even add a colon without testing it... – Robert Nov 12 '14 at 02: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 09:58
  • 1
    @Martin you're right, see update. – Robert Dec 17 '14 at 18:19
  • thanks a lot for your help! Could you explain me, how the analysis changed and what was wrong before? – MostlyHarmless Dec 17 '14 at 20:03
  • 1
    @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
3

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.

Emil Vatai
  • 156
2

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\pdfelapsedtime1000/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

Aubrey Blumsohn
  • 4,117