Page by page compilation time

Question

I am trying to locate the bottlenecks in compilation for a very large document.

The accepted answer to this Question addresses the problem in a neat way but the method only works for pdflatex (and not for LuaTeX and XeTeX) because the \pdfelapsedtime primitive is only available in pdflatex.

However this Question creates a \pdfelapsedtime analogue for LuaTex.

The question is how to do in XeTeX

Answer 1

Since XeTeX does not have timekeeping capabilities, the shell escape feature is left. The disadvantage is the large overhead of running external programs with duration variations.

The following example runs with plain and LaTeX formats. It is written for Perl under Linux and requires the -shell-escape switch:

xetex -shell-escape test
xelatex -shell-escape test

The interface is (macros names are prefixed with xetk):

• \xetkresettimer is similar to \pdfresettimer the timer is reset.

• \xetksetelapsedtime gets the current time difference to the last call of \xetkresettimer.

• \xetkelapsedtime contains the time in seconds as decimal number, set by \xetksetelapsedtime.

File test.tex:

\catcode`\@=11 % \makeatletter

\newread\xetk@pipe
\def\xetk@resetargs{}

\def\xetkresettimer{%
  \begingroup
    % the end of line character must be disabled,
    % otherwise it could add active characters, ...
    \endlinechar=-1 %
    \openin\xetk@pipe="|perl -e '%
      use Time::HiRes qw[gettimeofday];%
      @t=gettimeofday;%
      print qq[@t]%
    '"\relax
    \global\read\xetk@pipe to\xetk@resetargs
    \closein\xetk@pipe
  \endgroup
}
\xetkresettimer
\wlog{XeTeX timekeeping initialization: \xetk@resetargs}
\def\xetkelapsedtime{0}

\edef\xetksetelapsedtime{%
  \begingroup
    \endlinechar=-1 %
    \openin\xetk@pipe="|perl -e '%
      use Time::HiRes qw[tv_interval];%
      print tv_interval(\string\@ARGV)%
    ' -- \noexpand\xetk@resetargs"\relax
    \global\read\xetk@pipe to\noexpand\xetkelapsedtime
    \closein\xetk@pipe
  \endgroup
}

%%% Testing

\def\test{%
  \xetkresettimer
  \xetksetelapsedtime
  \immediate\write16{* Elapsed time: \xetkelapsedtime\space s}%
}

\test
\test
\test
\test
\test

\csname @@end\endcsname\end % end job

Macro \test resets the timer (external program is called), does nothing and calls again the external program to get the time difference:

* Elapsed time: 0.032371 s
* Elapsed time: 0.032007 s
* Elapsed time: 0.035123 s
* Elapsed time: 0.032473 s
* Elapsed time: 0.033759 s