diff options
Diffstat (limited to 'graphics/pgf/base/doc/pgfmanual-en-library-profiler.tex')
-rw-r--r-- | graphics/pgf/base/doc/pgfmanual-en-library-profiler.tex | 242 |
1 files changed, 242 insertions, 0 deletions
diff --git a/graphics/pgf/base/doc/pgfmanual-en-library-profiler.tex b/graphics/pgf/base/doc/pgfmanual-en-library-profiler.tex new file mode 100644 index 0000000000..6e5200a9fe --- /dev/null +++ b/graphics/pgf/base/doc/pgfmanual-en-library-profiler.tex @@ -0,0 +1,242 @@ +% Copyright 2019 by Christian Feuersaenger +% +% This file may be distributed and/or modified +% +% 1. under the LaTeX Project Public License and/or +% 2. under the GNU Free Documentation License. +% +% See the file doc/generic/pgf/licenses/LICENSE for more details. + + +\section{Profiler Library} + +{\noindent {\emph{by Christian Feuersänger}}} + +\begin{pgflibrary}{profiler} + A library to simplify the optimization of runtime speed of \TeX\ programs. + + It relies on the |pdftex| primitive + \declareandlabel{\pdfelapsedtime}\footnote{The primitive is emulated in + lua\TeX.} to count (fractional) seconds and counts total time and self time + for macro invocations. +\end{pgflibrary} + + +\subsection{Overview} + +The intended audience for this library are people writing \TeX\ code which +should be optimized. It is certainly \emph{not} useful for the end-user. + +The work flow for the optimization is simple: the preamble contains +configuration commands like +% +\begin{codeexample}[code only] +\usepgflibrary{profiler} +\pgfprofilenewforenvironment{tikzpicture} +\pgfprofilenewforcommand{\pgfkeys}{1} +\end{codeexample} +% +\noindent 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 +% +\begin{codeexample}[code only, tikz syntax=false] + pgflibraryprofiler(main job) {total time=1.07378sec; (100.0122%) self time=0.034sec; (3.1662%)} + pgflibraryprofiler(<ENV>tikzpicture) {total time=1.03978sec; (96.84601%) self time=1.00415sec; (93.52722%)} + pgflibraryprofiler(<CS>pgfkeys) {total time=0.03563sec; (3.31726%) self time=0.03563sec; (3.31726%)} +\end{codeexample} +% +\noindent will be provided in the log file, furthermore, the same information +is available in a text table called |\jobname.profiler.|\meta{datetime}|.dat| +which is of the form: +% +\begin{codeexample}[code only, tikz syntax=false] +profilerentry totaltime[s] totaltime[percent] selftime[s] selftime[percent] +main job 1.07378 100.0122 0.034 3.1662 +<ENV>tikzpicture 1.03978 96.84601 1.00415 93.52722 +<CS>pgfkeys 0.03563 3.31726 0.03563 3.31726 +\end{codeexample} +% +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 |tikzpicture|s 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|. + + +\subsection{Requirements} + +The library works with |pdftex| and |luatex|. Furthermore, it requires a more +or less recent version of |pdftex| which supports the |\pdfelapsedtime| +directive. + + +\subsection{Defining Profiler Entries} + +Unlike profilers for C/C++ or java, this library doesn't extract information +about every \TeX\ 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. + +\begin{command}{\pgfprofilenew\marg{name}} + Defines a new profiler entry named \meta{name}. + + This updates a set of internal registers used to track the profiler entry. + The \meta{name} can be arbitrary, it doesn't need to be related to any + \TeX\ macro. + + The actual job of counting seconds is accomplished using + |\pgfprofilestart|\marg{name} followed eventually by the command + |\pgfprofileend|\marg{name}. + + It doesn't hurt if |\pgfprofilenew| is called multiple times with the same + name. +\end{command} + +\begin{command}{\pgfprofilenewforcommand\oarg{profiler entry name}\marg{\textbackslash macro}\marg{arguments}} + Defines a new profiler entry which will measure the time spent in + \meta{\textbackslash macro}. This calls |\pgfprofilenew| and replaces the + current definition of \meta{\textbackslash macro} with a new one. + + If \oarg{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 + `\declareandlabel{\pgfprofilecs}\meta{macro}' (\meta{macro} without + backslash) where |\pgfprofilecs| is predefined to be |<CS>|. + + 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|: + % + \begin{itemize} + \item 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 \meta{arguments} in this + case), + \item commands which take one (optional) argument in square brackets + and \emph{exactly} \meta{arguments} arguments afterwards. + \end{itemize} + + 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. +\end{command} + +\begin{command}{\pgfprofilenewforcommandpattern\oarg{profiler entry name}\marg{\textbackslash macro}\marg{argument pattern}\marg{invocation pattern}} + A variant of |\pgfprofilenewforcommand| which can be used with arbitrary + \meta{argument patterns}. Example: + % +\begin{codeexample}[code only] +\def\mymacro#1\to#2\in#3{ ... } +\pgfprofilenewforcommandpattern{\mymacro}{#1\to#2\in#3}{{#1}\to{#2}\in{#3}} +\end{codeexample} + + Note that |\pgfprofilenewforcommand| is a special case of + |\pgfprofilenewforcommandpattern|: + % +\begin{codeexample}[code only] +\def\mymacro#1#2{ ... } +\pgfprofilenewforcommand\macro{2} +\pgfprofilenewforcommandpattern{\mymacro}{#1#2}{{#1}{#2}} +\end{codeexample} + % + Thus, \meta{argument pattern} is a copy-paste from the definition of your + command. The \meta{invocation pattern} is used by the |profiler| library to + invoke the \emph{original} command, so it is closely related to + \meta{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 + \meta{\textbackslash 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. +\end{command} + +\begin{command}{\pgfprofileshowinvocationsfor\marg{profiler entry name}} + Enables verbose output for \emph{every} invocation of \meta{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. +\end{command} + +\begin{command}{\pgfprofileshowinvocationsexpandedfor\marg{profiler entry name}} + A variant of |\pgfprofileshowinvocationsfor| which will expand all + arguments for \meta{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. +\end{command} + +\begin{command}{\pgfprofilenewforenvironment\oarg{profiler entry name}\marg{environment name}} + Defines a new profiler entry which measures time spent in the environment + \meta{environment name}. + + This calls |\pgfprofilenew| and handles the begin/end of the environment + automatically. + + The argument for |\pgfprofilenew| is \meta{profiler entry name}, or, if + this optional argument is not used, it is + `\declareandlabel{\pgfprofileenv}\meta{environment name}' where + |\pgfprofileenv| is predefined as |<ENV>|. Again, it is permitted to use + the same \meta{profiler entry name} multiple times to merge different + commands into one output section. +\end{command} + +\begin{command}{\pgfprofilestart\marg{profiler entry name}} + Starts (or resumes) timing of \meta{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 \TeX\ groups nor does it modify the token list. +\end{command} + +\begin{command}{\pgfprofileend\marg{profiler entry name}} + Stops (or interrupts) timing of \meta{profiler entry name}. + + This command finishes a preceding call to |\pgfprofilestart|. +\end{command} + +\begin{command}{\pgfprofilepostprocess} + For \LaTeX, 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.|\meta{YYYY}|-|\meta{MM}|-|\meta{DD}|_|\meta{HH}|h_|\meta{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}|. +\end{command} + +\begin{command}{\pgfprofilesetrel\marg{profiler entry name} (initially main job)} + Sets the profiler entry whose total time will be used to compute all other + relative times. Thus, \meta{profiler entry name} will use $100\%$ of the + total time per definition, all other relative times are relative to this + one. +\end{command} + +\begin{command}{\pgfprofileifisrunning\marg{profiler entry name}\marg{true code}\marg{false code}} + Invokes \marg{true code} if \marg{profiler entry name} is currently running + and \marg{false code} otherwise. +\end{command} |