TEXPROFILE(1)

🎀 TEXPROFILE(1) 🎀 — Displaying TeX profiles, bestie edition

okay so listen. texprofile is the little sister program to texprof, and she is literally the one who takes all that raw timing data and makes it make sense. Let's go 💅

---

✨ NAME ✨

texprofile — displaying the profile data collected by texprof. 🦋

---

🌸 SYNOPSIS 🌸

texprofile [Options] inputfile

---

💖 DESCRIPTION 💖

So texprofile reads the binary inputfile that texprof made for you. And guess what — you can totally leave off the .tprof extension on the input file, it does not care, it will figure it out. 🫶

Then it analyses all that data and serves the results up in a whole bunch of tables. You can get them formatted for human eyes (pretty, readable, cute) or as CSV (comma separated values) files when you wanna keep processing the numbers somewhere else.

The output goes to the standard output stream, so you can redirect it into a file or just vibe with it right there on screen. ✨

---

👑 OPTIONS 👑

There are four types of options, and yes we are doing all of them:

• general options
• table options
• selection options
• formatting options

🌈 The general options

• -?, -h, --help — shows you a short help text and then dips out of the program.
• --version — shows the version information and then dips out. 👋

🔥 The table options

These decide which tables show up. Heads up: they all use upper case letters. And if you give no table option at all, you only get some global information, that's it. 🙈

• -T — show the table of the top 10 input lines.
• -G — show the table of the macro call graph.
• -C — show the table of times per TeX command.
• -L — show the table of times per input line.
• -R — show the table of raw time stamps.
• -S — show the table of macro stack changes.
• -F — show the table of all input files.
• -M — show the table of all macros called.
• -A — show important tables (equal to -TGFC tables).
• -N — do not show the table of global information.

🦋 The selection options

These ones let you shrink the data down by dropping table entries that barely contribute to the overall runtime. Lowkey ruthless, highkey useful. ✂️

• -pn — do not show information for table entries with cumulative time below n percent. The default is 1.0 percent.
• -tn — limit the number of input lines shown in the table of the ``Top Ten'' to n. This option is only useful with the -T option.

💅 The formatting option

These control how the info inside the tables is formatted, plus which info actually shows up in them.

• -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. (sneaky little twins, we see you 👀)
• -m — optimize output for machine readability. So when it's 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 -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 -m option both numbers will simply be given in separate columns.
• -n — show the time stamp numbers. This option is useful together with the -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.
• -s — show the changes of the macro stack. This option is useful with the -R option if you want to see the changes in the macro stack (see -S) together with the timing information in a single table.

---

🧚 DATA FORMATS 🧚

🍓 FILE NUMBERS

While texprof is running, every TeX input file gets a unique file number. And bestie, here's why that matters: the file name alone is often not unique, because two files in different directories might have the same file name. But 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 -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. 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. Iconic detective work honestly. 🔍

Last not least, there are some special file numbers:

• 0 - unknown — if the file is unknown, which should rarely happen, the file number 0 is used.
• 1 - system — 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.
• 2 - terminal — TeX commands entered on the command line or interactively are mapped to file number 2.

⭐ TIME ⭐

If the option -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).

💜 MACRO NAMES

Macro names are shown with the leading backslash. Since macro names are often not unique, the command line option -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. 😭 (copy-paste behavior fr fr)

---

🌟 EXAMPLES 🌟

Let's assume that you issue the command texprof -prof hello.tex. This will run texprof on the input file hello.tex with option -prof. The program texprof will load the plain TeX format and then process hello.tex to produce hello.log and hello.dvi. It will execute exactly the same steps that TeX would execute if you had issued the command tex hello.tex. 🫶

In addition to hello.log and hello.dvi, texprof will also produce the file hello.tprof containing time measurements made while texprof was running. The option -prof will switch on the gathering of timing data as soon as texprof enters its main control procedure; The 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 hello.tprof might become very big. 💀 (she thicc)

The program texprofile is used to extract and analyse the data contained in hello.tprof and produce useful output. Here are some examples:

• texprofile hello — Without further options 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 -N option or with the -m option.
• texprofile -T hello — With the option -T, 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:
  1. file — The first column contains the input file number as explained above. The input file name if shown in column 7.
  2. line — The line number.
  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.
  4. absolute — The absolute time spent in this line and file.
  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.
  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.
  7. file — The input file name. The corresponding file number is shown in column 1.
• texprofile -G hello — With the option -G, 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:

1. time — Column 1 gives it as an absolut time.
3. percentage — Column 3 gives it as a percentage of the total time measured.

For the first section with the header File, the absolute time is gonna be exactly equal to the total time measured, because texprof literally spent all of that time processing the file hello. So bestie, column 3 is gonna say 100%. Every single time. No notes. 💅

Now here's the thing — to actually get a task done, a macro usually calls other macros, and from here on we're calling those child macros. 🫶 The lines below that first one in the table? That's the breakdown of the time shown in the first line. And that breakdown starts with a line showing the time spent in the section excluding the time spent in child macros, with column 4 showing how many times the macro was called.

1. time — Column 1 gives the absolute time spent in the section, excluding the time spent in child macros.
2. 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.
3. count/total — Column 4 gives the number of times the section was called.

The lines that follow in the table show the time spent in one of the child macros. Columns 2, 4, and 5 need some explaining, so let's get into it. 🧚

1. loop — The only case where column 2 isn't empty is a recursive macro. A recursive macro is a macro that, along the chain of macro calls, eventually calls itself — creating a recursive loop. At that point the macro becomes its own descendant and at the same time its own ancestor. Iconic, honestly. 😭 So texprofile keeps two accumulators of elapsed time for each child macro: for the time shown in column 2 (labeled loop), texprofile adds up the time differences observed at the return of a child macro. For the time shown in the columns 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 in column 1 of line 2 and the lines after it will add up to the time in column 1 of line 1, and the percentages in column 3 of line 2 and the lines after it will add up to 100%. The time in column 3 shows the total time needed to accomplish the sub-task assigned to that respective child macro.
2. 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. And n will always be less than or equal to m.
3. child — Column 5 shows the name of the child macro, as explained above.

---

texprofile -G -m hello

This table is gonna have the same data as the previous example, except this time the -m option optimizes the output for machine readability. ✨

• There are no column headers.
• The times in column 1 time and column 2 loop are given in nanoseconds, with no unit identifier.
• The numbers n/m in column 4 are now shown in two separate columns, 4 and 5; and the macro name moves from column 5 over to column 6.

texprofile -F hello

With the -F option, texprofile outputs the table of all of TeX's input files, using 5 columns:

1. file — The file number, as explained above.
2. lines — The difference between the highest and the lowest line number found in the profile data for this file. Usually this is only a subset of all the lines in the file.
3. percent — The percentage of the total time measured that is attributed to the file.
4. time — The absolute time that is attributed to the file.
5. name — The full file name of the file.

texprofile -C hello

With the -C option, texprofile outputs the table of all TeX commands executed while profiling, using 6 columns:

1. cmd — The command code used internally by TeX. Usually the same number is used by TeX for several closely related tasks. There's a special command code 101, which is used for the time spent on system routines that are mapped to the system file, as explained above.
2. time — The total time used for the command.
3. percent — The percentage of the total time measured used for the command.
4. count — The number of times this command was executed.
5. average — The average time needed to execute the command. This is simply the value in column 2 divided by the value in column 4.
6. name — A verbal description of the command or commands that share this command code.

texprofile -R -m -n hello

With the options -R -m, texprofile outputs the table of raw time measurements as observed by texprof, optimized for machine readability. The -n option adds a column for the number of each time measurement. And because of the -m option, the table has no column headers. It has 7 columns:

1. number — The number of the time measurement. 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.
2. file — The file number, as explained above.
3. line — The line number, as explained above.
4. time — The time interval in nanoseconds.
5. command — The command name, as given in column 6 of the previous example.
6. level — The nesting level of the macro call stack.
7. macro — The macro name.

This table contains all the timing information gathered during the run of texprof. Some information about macro calls is contained in column 6. More information about macro calls could be added by using the -s option. The information about macro returns can be obtained from column 6. And this table can be imported into a spreadsheet or a database for further analysis. 🍓

---

💀 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 mechanism of TeX might push further macros or new input files onto 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.

And if this explanation sounds complicated to you, that's because the situation is indeed complicated. 😭 Not a vibe, but there it is.

---

👀 SEE ALSO 👀

• texprof(1)

---

🌈 VERSION 🌈

Version: 1.1 of 28-1-2025

Copyright

(C)2024, Martin Ruckert, Hochschule München, Lothstrasse 64, D-80335 München

Distribution

texprofile is distributed with TeX Live. More recent versions might be found on GitHub at https://github.com/ruckertm/HINT.

License

This program can be redistributed and/or modified under the terms of the MIT/X11 license.

---

👑 AUTHOR 👑

Martin Ruckert Munich University of Applied Sciences Email: martin.ruckert@hm.edu

---

And that's a wrap, bestie 🎀 this page is from Version 1.1, dated 28-1-2025, and the footer calls it Displaying TeX profiles — 28-1-2025, TEXPROFILE(1). Go read the profile tables, they're giving data. 💖✨