☰
PGF/TikZ Manual

The TikZ and PGF Packages
Manual for version 3.1.10

Libraries

67 Profiler Library

by Christian Feuersänger

  • TikZ Library profiler

    • \usepgflibrary{profiler} % and plain and pure pgf
    \usepgflibrary[profiler] % Cont and pure pgf
    \usetikzlibrary{profiler} % and plain when using TikZ
    \usetikzlibrary[profiler] % Cont when using TikZ

    A library to simplify the optimization of runtime speed of programs.

    It relies on the pdftex primitive \pdfelapsedtime13 to count (fractional) seconds and counts total time and self time for macro invocations.

13 The primitive is emulated in lua.

67.1 Overview

The intended audience for this library are people writing code which should be optimized. It is certainly not useful for the end-user.

The work flow for the optimization is simple: the preamble contains configuration commands like


\usepgflibrary{profiler}
\pgfprofilenewforenvironment{tikzpicture}
\pgfprofilenewforcommand{\pgfkeys}1}

and then, the time between \begin{tikzpicture} and \end{tikzpicture} and the time required to call \pgfkeys will be collected.

At the end, a short usage summary like


pgflibraryprofiler(main job) {total time=1.07378sec; (100.0122%) self time=0.034sec; (3.1662%)}
pgflibraryprofiler(tikzpicture) {total time=1.03978sec; (96.84601%) self time=1.00415sec; (93.52722%)}
pgflibraryprofiler(pgfkeys) {total time=0.03563sec; (3.31726%) self time=0.03563sec; (3.31726%)}

will be provided in the log file, furthermore, the same information is available in a text table called \jobname.profiler.⟨datetime⟩.dat which is of the form:


profilerentry totaltime[s] totaltime[percent] selftime[s] selftime[percent]
main job 1.07378 100.0122 0.034 3.1662
tikzpicture 1.03978 96.84601 1.00415 93.52722
pgfkeys 0.03563 3.31726 0.03563 3.31726

Here, the totaltime means the time used for all invocations of the respective profiler entry (one row in the table). The selftime measures time which is not already counted for in another profiler entry which has been invoked within the current one. The example above is not very exciting: the main job consists only of several (quite complex) pictures and nothing else. Thus, its total time is large. However, the self time is very small because the tikzpictures are counted separately, and they have been invoked within the main job. The \pgfkeys control sequence has been invoked within the tikzpicture, that’s why the selftime for the tikzpicture is a little bit smaller than its totaltime.

67.2 Requirements

The library works with pdftex and luatex. Furthermore, it requires a more or less recent version of pdftex which supports the \pdfelapsedtime directive.

67.3 Defining Profiler Entries

Unlike profilers for C/C++ or java, this library doesn’t extract information about every macro automatically, nor does it collect information for each of them. Instead, every profiler entry needs to be defined explicitly. Only defined profiler entries will be processed.

  • \pgfprofilenew{⟨name⟩}

    • Defines a new profiler entry named ⟨name⟩.

    This updates a set of internal registers used to track the profiler entry. The ⟨name⟩ can be arbitrary, it doesn’t need to be related to any macro.

    The actual job of counting seconds is accomplished using \pgfprofilestart{⟨name⟩} followed eventually by the command \pgfprofileend{⟨name⟩}.

    It doesn’t hurt if \pgfprofilenew is called multiple times with the same name.

  • \pgfprofilenewforcommand[⟨profiler entry name⟩]{⟨\macro⟩}{⟨arguments⟩}

    • Defines a new profiler entry which will measure the time spent in ⟨\macro⟩. This calls \pgfprofilenew and replaces the current definition of ⟨\macro⟩ with a new one.

    If [⟨profiler entry name⟩] has been provided, this defines the argument for \pgfprofilenew. It is allowed to use the same name for multiple commands; in this case, they are treated as if it where the same command. If the optional argument is not used, the profiler entry will be called ‘ \pgfprofilecs⟨macro⟩’ (⟨macro⟩ without backslash) where \pgfprofilecs is predefined to be .

    The replacement macro will collect all required arguments, start counting, invoke the original macro definition and stop counting.

    The following macro types are supported within \pgfprofilenewforcommand:

    • • commands which take one (optional) argument in square brackets followed by one optional argument which has to be delimited by curly braces (use an empty argument for ⟨arguments⟩ in this case),

    • • commands which take one (optional) argument in square brackets and exactly ⟨arguments⟩ arguments afterwards.

    Take a look at \pgfprofilenewforcommandpattern in case you have more complicated commands.

    Note that the library can’t detect if a command has been redefined somewhere.

  • \pgfprofilenewforcommandpattern[⟨profiler entry name⟩]{⟨\macro⟩}{⟨argument pattern⟩}{⟨invocation pattern⟩}

    • A variant of \pgfprofilenewforcommand which can be used with arbitrary ⟨argument patterns⟩. Example:


    \def\mymacro#1\to#2\in#3{ ... }
    \pgfprofilenewforcommandpattern{\mymacro}{#1\to#2\in#3}{{#1}\to{#2}\in{#3}}

    Note that \pgfprofilenewforcommand is a special case of \pgfprofilenewforcommandpattern:


    \def\mymacro#1#2{ ... }
    \pgfprofilenewforcommand\macro{2}
    \pgfprofilenewforcommandpattern{\mymacro}{#1#2}{{#1}{#2}}

    Thus, ⟨argument pattern⟩ is a copy-paste from the definition of your command. The ⟨invocation pattern⟩ is used by the profiler library to invoke the original command, so it is closely related to ⟨argument pattern⟩, but it needs extra curly braces around each argument.

    The behavior of \pgfprofilenewforcommandpattern is the same as discussed above: it defines a new profiler entry which will measure the time spent in ⟨\macro⟩. The details about this definition has already been described. Note that up to one optional argument in square brackets is also checked automatically.

    If you like to profile a command which doesn’t match here for whatever reasons, you’ll have to redefine it manually and insert \pgfprofilestart and \pgfprofileend in appropriate places.

  • \pgfprofileshowinvocationsfor{⟨profiler entry name⟩}

    • Enables verbose output for every invocation of ⟨profiler entry name⟩.

    This is only available for profiler entries for commands (those created by \pgfprofilenewforcommand for example). It will also show all given arguments.

  • \pgfprofileshowinvocationsexpandedfor{⟨profiler entry name⟩}

    • A variant of \pgfprofileshowinvocationsfor which will expand all arguments for ⟨profiler entry name⟩ before showing them. The invocation as such is not affected by this expansion.

    This expansion (with \edef) might yield unrecoverable errors for some commands. Handle with care.

  • \pgfprofilenewforenvironment[⟨profiler entry name⟩]{⟨environment name⟩}

    • Defines a new profiler entry which measures time spent in the environment ⟨environment name⟩.

    This calls \pgfprofilenew and handles the begin/end of the environment automatically.

    The argument for \pgfprofilenew is ⟨profiler entry name⟩, or, if this optional argument is not used, it is ‘ \pgfprofileenv⟨environment name⟩’ where \pgfprofileenv is predefined as . Again, it is permitted to use the same ⟨profiler entry name⟩ multiple times to merge different commands into one output section.

  • \pgfprofilestart{⟨profiler entry name⟩}

    • Starts (or resumes) timing of ⟨profiler entry name⟩. The argument must have been declared in the preamble using \pgfprofilenew.

    Nested calls of \pgfprofilestart with the same argument will be ignored.

    The invocation of this command doesn’t change the environment: it doesn’t introduce any groups nor does it modify the token list.

  • \pgfprofileend{⟨profiler entry name⟩}

    • Stops (or interrupts) timing of ⟨profiler entry name⟩.

    This command finishes a preceding call to \pgfprofilestart.

  • \pgfprofilepostprocess

    • For , this command is installed automatically in \end{document}. It stops all running timings, evaluates them and returns the result into the logfile. Furthermore, it generates a text table called \jobname.profiler.⟨YYYY⟩-⟨MM⟩-⟨DD⟩_⟨HH⟩h_⟨MM⟩m.dat with the same information.

    Note that the profiler library predefines two profiler entries, namely main job which counts time from the beginning of the document until \pgfprofilepostprocess and preamble which counts time from the beginning of the document until \begin{document}.

  • \pgfprofilesetrel{⟨profiler entry name⟩} (initially main job)

    • Sets the profiler entry whose total time will be used to compute all other relative times. Thus, ⟨profiler entry name⟩ will use \(100\%\) of the total time per definition, all other relative times are relative to this one.

  • \pgfprofileifisrunning{⟨profiler entry name⟩}{⟨true code⟩}{⟨false code⟩}

    • Invokes {⟨true code⟩} if {⟨profiler entry name⟩} is currently running and {⟨false code⟩} otherwise.