summaryrefslogtreecommitdiff
path: root/Build/source/texk/web2c/texprofdir/texprofileman.tex
diff options
context:
space:
mode:
Diffstat (limited to 'Build/source/texk/web2c/texprofdir/texprofileman.tex')
-rw-r--r--Build/source/texk/web2c/texprofdir/texprofileman.tex442
1 files changed, 442 insertions, 0 deletions
diff --git a/Build/source/texk/web2c/texprofdir/texprofileman.tex b/Build/source/texk/web2c/texprofdir/texprofileman.tex
new file mode 100644
index 00000000000..4a6f5c2e2b0
--- /dev/null
+++ b/Build/source/texk/web2c/texprofdir/texprofileman.tex
@@ -0,0 +1,442 @@
+% Copyright 2017-2024 Martin Ruckert, Hochschule Muenchen, Lothstrasse 64, 80336 Muenchen
+%
+% Permission is hereby granted, free of charge, to any person obtaining a copy
+% of this software and associated documentation files (the "Software"), to deal
+% in the Software without restriction, including without limitation the rights
+% to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+% copies of the Software, and to permit persons to whom the Software is
+% furnished to do so, subject to the following conditions:
+%
+% The above copyright notice and this permission notice shall be
+% included in all copies or substantial portions of the Software.
+%
+% THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+% IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+% FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+% COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY,
+% WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT
+% OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+% THE SOFTWARE.
+%
+% Except as contained in this notice, the name of the copyright holders shall
+% not be used in advertising or otherwise to promote the sale, use or other
+% dealings in this Software without prior written authorization from the
+% copyright holders.
+\documentclass[a4paper,english]{article}
+\usepackage{a4wide}
+\usepackage{latex2man}
+
+\setVersion{1.0}
+\setDate{6-9-2024}
+
+\begin{document}
+\begin{Name}{1}{texprofile}{Martin Ruckert}{Displaying TeX profiles}{TeXprofile: Displaying TeX profiles}
+
+ \Prog{texprofile} - Displaying the profile data collected by \Prog{texprof}.
+\end{Name}
+
+\section{Synopsis}
+
+\Prog{texprofile} [Options] \Arg{inputfile}
+
+\section{Description}
+\Prog{texprofile} reads the binary \Arg{inputfile} as produced by
+\Prog{texprof}. The extension \File{.tprof} of the input file can be
+omitted. It analyses the data and presents the results in a variety of
+tables, either optimized for human readability or as CSV (comma
+separated values) files for further processing.
+
+The output is written to the standard output stream where it can be redirected
+to a file or viewed immediately.
+
+\section{Options}
+There are four types of options: general options, table options,
+selection options, and formatting options.
+
+The general options:
+\begin{description}
+\item[\Opt{-?} \Opt{-h} \Opt{--help}]
+ Display a short help text and exit the program.
+\item[\Opt{--version}]
+ Display the version information and exit.
+\end{description}
+
+The table options determine the tables that will be displayed.
+These options all use upper case letters.
+If no table option is given, only some global information is shown.
+
+\begin{description}
+\item[\Opt{-T}]
+ Show the table of the top 10 input lines.
+\item[\Opt{-G}]
+ Show the table of the macro call graph.
+\item[\Opt{-C}] Show the table of times per TeX command.
+\item[\Opt{-L}] Show the table of times per input line.
+\item[\Opt{-R}] Show the table of raw time stamps.
+\item[\Opt{-S}] Show the table of macro stack changes.
+\item[\Opt{-F}] Show the table of all input files.
+\item[\Opt{-M}] Show the table of all macros called.
+\item[\Opt{-A}] Show important tables (equal to -TGFC) tables.
+\item[\Opt{-N}] Do not show the table of global information.
+\end{description}
+
+The selection options allow to reduce the amount of data that is shown
+in the table by omitting table entries that contribute little to the
+overall runtime.
+
+\begin{description}
+\item[\OptArg{-p}{n}] Do not show information for table entries
+ with cumulative time below \Arg{n} percent. The default is 1.0 percent.
+\item[\OptArg{-t}{n}] Limit the number of input lines shown in the
+ table of the ``Top Ten'' to \Arg{n}. This option is only useful
+ with the \Opt{-T} option.
+\end{description}
+
+The formatting option determine the formatting of the information in the tables
+as well as the selection of information that is shown in the tables.
+
+\begin{description}
+\item[\Opt{-i}]
+ Add the macros file and line numbers after the macro name.
+ This option is useful to distinguish two macros that share
+ the same name.
+\item[\Opt{-m}]
+ Optimize output for machine readability. When optimized for human readability,
+ times are rounded and given in a short form adding a unit identifier:
+ s for seconds, ms for milliseconds, us for micro seconds, and ns for
+ nanoseconds. This format is inconvenient if you want to import the data
+ for example into a spread-sheet for further processing.
+ With the \Opt{-m} option times are simply given in nano seconds without units.
+ Similar the combined time for the total time used for a macro and the
+ time used as a sub-macro from the call graph is given in a single column
+ with a slash separating both numbers is nice for human readers.
+ With the \Opt{-m} option both numbers will simply be given in separate columns.
+
+\item[\Opt{-n}]
+ Show the time stamp numbers. This option is useful together with
+ the \Opt{-R} option, if you import the table into a database or spread-sheet.
+ If you sort the data by various properties into different
+ categories, the time stamp number can be used to keeping the entries
+ within a category sorted by time.
+
+\item[\Opt{-s}]
+ Show the changes of the macro stack.
+ This option is useful with the \Opt{-R} option if you want to see the changes
+ in the macro stack (see \Opt{-S}) together with the timing information in
+ a single table.
+\end{description}
+
+
+\section{Data Formats}
+\subsection{File Numbers}
+While \Prog{texprof} is running, every TeX input file is given a
+unique file number. The file name alone is often not unique because
+two files in different directories might have the same file
+name. Displaying the full file name with the complete path is however often
+not very
+convenient. So if you observe the same file name together with
+different file numbers, you can use the option \Opt{-F} to get a table of all
+file numbers and their full file names.
+
+But even within the same
+directory, TeX can read different files with the same name during one
+run: TeX can open a file for writing, write content to the file, close
+it, open it for reading, read it and close it again. Then TeX might
+repeat this process a second time, or multiple times, reusing the same
+file name over and over again. \Prog{texprof} will assign a new file
+number to this file each time it is opened for reading. So you can
+tell from the sequence of file numbers which one was the first, the
+second, or the third.
+
+Last not least, there are some special file
+numbers:
+\begin{description}
+\item[0 - unknown]
+ If the file is unknown, which should rarely happen,
+ the file number 0 is used.
+\item[1- system]
+ \Prog{texprof} will map
+ time intervals that are used to execute certain system routines
+ to the ``system'' pseudo file
+using the line numbers to identify the specific routine
+like producing the output DVI file (shipout), breaking
+a paragraph into lines (linebrk), or breaking the
+document into pages (buildpg). These times do not depend on the
+use of macros but simply on the size of the document.
+\item[2 - terminal]
+ TeX commands entered on the command line or interactively are mapped
+ to file number 2.
+\end{description}
+
+\subsection{Time}
+If the option \Opt{-m} is given times are given as nanoseconds.
+Otherwise, times are rounded to at most 4 digits precission and
+displayed with a unit: seconds (s), milliseconds (ms), microseconds
+(um), or nanoseconds (ns).
+
+\subsection{Macro Names}
+Macro names are shown with the leading backslash. Since macro names
+are often not unique, the command line option \Opt{-i} can be used to
+show after the macro name in square brackets the file number and the
+line number where the macro is defined. Unless two macros with the
+same name are defined in the same file and line this is sufficient to
+uniquely identify a macro. A macro defined with ``let'' results in a
+complet copy of the original macro. Therefore it will not reference
+the file and line of the ``let'' command but the same file and line as
+the original macro.
+
+\section{Examples}
+Let's assume that you issue the command \Prog{texprof} \Opt{-prof}
+\Arg{hello.tex}. This will run \Prog{texprof} on the input file
+\Arg{hello.tex} with option \Opt{-prof}. The program \Prog{texprof}
+will load the plain TeX format and then process \File{hello.tex} to
+produce \File{hello.log} and \File{hello.dvi}. It will execute
+exactly the same steps that TeX would execute if you had issued the
+command \Prog{tex} \Arg{hello.tex}.
+
+In addition to \File{hello.log} and \File{hello.dvi}, \Prog{texprof}
+will also produce the file \File{hello.tprof} containing time
+measurements made while \Prog{texprof} was running. The option
+\Opt{-prof} will switch on the gathering of timing data as soon as
+\Prog{texprof} enters its main control procedure; The file
+\File{hello.tprof} will contain a time measurement, called a time
+stamp, for every command that TeX executed while processing the input.
+A binary format is used to store all that data in a simple and compact
+form. Still the file \File{hello.tprof} might become very big.
+
+The program \Prog{texprofile} is used to extract and analyse the data
+contained in \File{hello.tprof} and produce useful output. Here are
+some examples:
+
+\begin{description}
+\item[\Prog{texprofile} \Arg{hello}]
+ Without further options \Prog{texprofile} will write some general
+ information to the standard output, like the total time measured,
+ the number of samples, the average time per sample, etc.
+ The general information is always given unless explicitely disabled
+ with the \Opt{-N} option or with the \Opt{-m} option.
+
+\item[\Prog{texprofile} \Opt{-T} \Arg{hello}]
+ With the option \Opt{-T}, \Prog{texprofile} will map each time stamp
+ to a specific line of input, add up the time intervalls for each input
+ line separately, and output a table showing the ten lines that have
+ the highest cummulative time.
+ The table has the following seven columns:
+ \begin{description}
+ \item[1. file]
+ The first column contains the input file number as explained above.
+ The input file name if shown in column 7.
+ \item[2. line]
+ The line number.
+ \item[3. percent]
+ The time spent in this line and file as a percentage of the total
+ time measured as given as part of the general information.
+ \item[4. absolute]
+ The absolute time spent in this line and file.
+ \item[5. count]
+ The number of times the execution path entered this line.
+ Note, that a
+ macro call usually redirects the execution path to another line
+ from where the execution will return after the macro call has completed.
+ Reentering the line after such an excursion to an other line will
+ cause this counter to be incremented. In summary, this counter might
+ reflect the number of partial executions of a line not the number
+ of full executions of the entire line.
+ \item[6. average]
+ The average time spent in the line is simply computed by dividing the
+ value in column 4 by the value in column 5.
+ \item[7. file]
+ The input file name. The corresponding file number is shown in column 1.
+ \end{description}
+
+\item[\Prog{texprofile} \Opt{-G} \Arg{hello}]
+ With the option \Opt{-G}, \Prog{texprofile} will map each time stamp
+ either to file input or to a macro body.
+ The table shown is divided into several sections, the first section
+ is devoted to file input, each of the following sections is devoted
+ to a specific macro.
+ \\
+ Each section starts with a header. The header of the
+ first section is ``File'' the header of a later section is the macro name.
+ \\
+ The first line after the header gives the total time spent in the section
+ in two different formats:
+ \begin{description}
+ \item[1. time]
+ Column 1 gives it as an absolut time.
+ \item[3. percentage]
+ Column 3 gives it as a percentage of the total time measured.
+ \end{description}
+ For the first section with the header ``File'', the absolute time
+ will be equal to the total time measured because \Prog{texprof}
+ did spent all the time processing the file \Arg{hello}.
+ And consequently the value in column 3 will be 100\%.
+ \\
+ To accomplish a task, a macro usually calls other
+ macros that we call child macros in the following.
+ The following lines in the table will give a breakdown
+ of the time shown in the first line.
+ The breakdown starts with a line showing the time spent in the section
+ excluding the time spent in child macros. It shows in column 4 the number
+ of times the macro was called.
+ \begin{description}
+ \item[1. time]
+ Column 1 gives the absolut time spent in the section excluding the time
+ spent in child macros
+ \item[3. percentage]
+ Column 3 gives the time from column 1 as a percentage of the total time
+ spent in this section as given in the previous line.
+ \item[4. count/total]
+ Column 4 gives the number of times the section was called.
+ \end{description}
+ The lines that follow in the table show the time spent in one of
+ the child macros. Column 2, 4, and 5 need some explanation.
+ \begin{description}
+ \item[2. loop]
+ The only case where column 2 is not empty is the case of a
+ recursive macro. A recursive macro is a macro that along the
+ chain of macro calls eventually calls itself creating a
+ recursive loop. At this point, a macro becomesits own descendant
+ and at the same time its own ancestor.
+ \\
+ Therefore \Prog{texprofile} maintains for each child macro two
+ accumulators for the elapsed time: For the time shown in
+ column 2 labeled ``loop'', \Prog{texprofile} adds up the time
+ differences observed at the return of a child macro. For the
+ time shown in the column labeled ``time'' and ``percent'', it
+ subtracts from the time differences observed at the return of a
+ child macro all those time differences that were already added
+ to one of the other lines in the time breakdown: the macro itself
+ or one of the other child macros.
+ So the times shown in column 1 of line 2 and the following lines
+ will add up to the time shown in column 1 of the line 1;
+ and the percentages shown in column 3 of line 2 and the following lines
+ will add up to 100\%.
+ The time shown in column 3 will show show the total time needed
+ to accomplish the sub task assigned to the respective child macro.
+ \item[4. count/total]
+ Column 4 shows two counts $n/m$ for the macro named in column 5.
+ $m$ is the total number of calls to the macro and $n$ is the number of
+ calls as a child macro in the current section. The number $n$ will
+ always be less or equal to $m$.
+
+ \item[5. child]
+ Column 5 shows the name of the child macro as explained above.
+ \end{description}
+\item[\Prog{texprofile} \Opt{-G} \Opt{-m} \Arg{hello}]
+ This table will contain the same data as the previous example
+ but this time the \Opt{-m} option will optimize the output for
+ machine readability.
+ \begin{itemize}
+ \item There are no column headers.
+ \item The times in column 1 ``time'' and column 2 ``loop''
+ are given in nanoseconds without a unit identifier.
+ \item The numbers $n/m$ in column 4 are now shown in two separate
+ columns 4 and 5; the macro name moves from column 5 to column 6.
+ \end{itemize}
+
+\item[\Prog{texprofile} \Opt{-F} \Arg{hello}]
+ With the option \Opt{-F}, \Prog{texprofile} outputs the table
+ of all of TeX's input files using 5 columns:
+ \begin{description}
+ \item[1. file] The file number as explained above.
+ \item[2. lines] The difference between the highest and the lowest
+ line number found in the profile data for this file. This is
+ usually only a subset of all the lines of the file.
+ \item[3. percent]
+ The percentage of the total time measured that is attibuted to the file.
+ \item[4. time]
+ The absolute time that is attibuted to the file.
+ \item[5. name]
+ The full file name of the file.
+ \end{description}
+\item[\Prog{texprofile} \Opt{-C} \Arg{hello}]
+ With the option \Opt{-C}, \Prog{texprofile} outputs the table
+ of all TeX commands executed while profiling
+ using 6 columns:
+ \begin{description}
+ \item[1. cmd] The command code used internaly by TeX.
+ Usually the same number is used by TeX for several
+ closely related tasks.
+ There is a special command code 101 which is used to
+ for the time that is spend on system routines that are
+ mapped to the system file as explained above.
+ \item[2. time]
+ The total time used for the command.
+ \item[3. percent]
+ The percentage of the total time measured used for the command.
+ \item[4. count]
+ The number of times this command was executed.
+ \item[5. average]
+ The average time needed to execute the command.
+ This is simpy the value in column 2 divided by the value in column 4.
+ \item[6. name]
+ A verbal description of the command or commands that share this
+ command code.
+ \end{description}
+\item[\Prog{texprofile} \Opt{-R} \Opt{-m} \Opt{-n} \Arg{hello}]
+ With the options \Opt{-R} \Opt{-m}, \Prog{texprofile} outputs the table
+ of raw time measurements as observed by \Prog{texprof} optimized for machine
+ readability. The option \Opt{-n} adds a column for the number
+ of each time measurements.
+ Because of the \Opt{-m} option, the table has no column headers.
+ The table has 7 columns:
+ \begin{description}
+ \item[1. number] The number of the time measurment.
+ These numbers are strictly increasing but not necessarily consecutive.
+ They can be used to keep the measurements sorted in the order in which
+ they were made.
+ \item[2. file] The file number as explained above.
+ \item[3. line] The line number as explained above.
+ \item[4. time] The time interval in nano seconds.
+ \item[5. command] The command name as given in column 6 of the previous example.
+ \item[6. level ] The nesting level of the macro call stack.
+ \item[7. macro] The macro name.
+ \end{description}
+ This table contains all the timing information gathered during the run
+ of \Prog{texprof}. Some information about macro calls is contained in
+ column 6. More information about macro calls could be added
+ by using the \Opt{-s} option. The information about macro returns
+ can be obtained from column 6.
+ The table can be imported to a spread-sheet or a database for further
+ analysis.
+\end{description}
+
+
+\section{Bugs}
+If the last command in a macro body is a macro call, we call this a tail call.
+If such a tail call reads ahead to scan the following input
+for possible arguments, the look-ahead mechaism of TeX might push further
+macros or new input files on TeX's input stack.
+These entries will remain on top of TeXprof's macro nesting stack,
+even if TeX backs up all these tokens on its input stack.
+This can cause an attribution of runtime to those entries as sub entries
+of the tail call. If this explanation sounds complicated to you, it is
+because the situation is indeed complicated.
+
+\section{See Also}
+ \Cmd{texprof}{1}
+
+
+\section{Version}
+Version: \Version\ of \Date
+\begin{description}
+\item[Copyright] \copyright\ 2024, Martin Ruckert,\\
+ Hochschule München, Lothstrasse 64, D-80335 München
+
+\item[Distribution]
+ \Prog{texprofile} is distributed with TeX Live.
+ More recent versions might be found on GitHub
+ \URL{https://github.com/ruckertm/HINT}.
+
+\item[License] This program can be redistributed and/or modified under the
+ terms of the MIT/X11 license.
+\end{description}
+
+\section{Author}
+\noindent
+Martin Ruckert \\
+Munich University of Applied Sciences \\
+Email: \Email{martin.ruckert@hm.edu} \\
+
+\end{document}