2

How to do fine grain performance measurement with mixed latex, luatex code? Let's say there are two blocks of code, executed one after another. The first one is in plain latex, and the second is luatex. I would like to know the real overhead of adding the second piece of code. A test case that comes to mind is doing a vpack on an existing vbox that was not originally set to the the size of its contents. How expensive is a vpack compared to vbox creation? That's something I am actually interested in knowing, especially for huge vboxes for instance. Here's my the code that needs performance timer insertions (at marked locations):

(Note: Ignore "Natural height" value of tempvbox, its incorrect as the height exceeds tex limit. You can of course see a correct value by reducing the number of paragraphs in blindtext from 1000 to something small, though that will also reduce the accuracy of ratio of two time deltas in consideration.)

% >> lualatex <filename>.tex
\documentclass[notitlepage,letterpaper]{article}
\usepackage[english]{babel}
\usepackage{blindtext}
\usepackage{printlen}
\setlength\parindent{0pt}
\uselengthunit{in}

\begin{document}

% Time1
\newsavebox{\tempvbox}
\setbox\tempvbox=\vbox to 4in{{\hsize=4in \noindent\blindtext[1000]}}

% Time2
\directlua{
    tempvboxnatural = node.vpack(tex.getbox('tempvbox').head)
}%
% Time3

Set height of tempvbox: \directlua{tex.sprint("\csstring\%f  in",(tex.getbox('tempvbox').height/tex.sp('1in')))}

Natural Height of tempvbox: \directlua{tex.sprint("\csstring\%f  in",(tempvboxnatural.height/tex.sp('1in')))}

%Print Time2-Time1, and Time3-Time2 here
Time2-Time1: ??

Time3-Time2: ??

Partial contents of tempvbox:

\vsplit\tempvbox to 6in

\end{document}

Screenshot of output:

screenshot of compiled output

Improve this question
10
  • As a side question, why is substring ' in' not printed by tex.sprint in above code?
    – reportaman
    Sep 13, 2020 at 5:23
  • For the % sign, I'd use tex.sprint(-2, ...) and string.format() to format the string. Otherwise TeX might interpret some characters like %. tex.sprint(-2,string.format("\csstring\%f in",(tex.getbox('tempvbox').height....
    – topskip
    Sep 13, 2020 at 12:14
  • For the timing, you can os.gettimeofday() to get the current time. Just get the time at the beginning and then at the end and subtract both.
    – topskip
    Sep 13, 2020 at 12:17
  • 1
    @topskip I would recommend using os.clock over os.gettimeofday here because it is not influenced by changes to the system time.
    – Marcel Krüger
    Sep 13, 2020 at 13:33
  • 1
    @reportaman I guess that with "expl3 performance counters" you mean "l3benchmark"? That one currently uses os.clock on LuaTeX while all other engines use gettimeofday. To make it more uniform, the next release will unify this to always use gettimeofday (even under LuaTeX). I still think that os.clock is better (especially since CPU time is much more useful for most benchmarking) but in this case consistency was more important. (See my comment at github.com/latex3/latex3/pull/796#issuecomment-678357951 for more about that)
    – Marcel Krüger
    Sep 14, 2020 at 1:34

1 Answer 1

Reset to default
1

Based on suggestions of Marcel Krüger & Patrick Gundlach (topskip), with some addition & testing, here's the final code & observations:

For paragraphs that are few lines long (\blindtext[1]), vpack takes 2% to 10% of time taken by its respective vbox creation. As the number of lines increase (\blindtext[1000] or a loop with \blindtext[1]\par\blindtext[1]\par...), percentage time taken by vpack compared to vbox creation keeps decreasing (for \blindtext[1000] it is on the order of 0.01% of time taken for vbox creation). Either way, percentage wise vpack seems insignificant as one could expect vbox creation is O(n^2) complexity and vpack probably O(n) complexity.

\documentclass[notitlepage,letterpaper]{article}
\usepackage[english]{babel}
\usepackage{blindtext}
\usepackage{printlen}
\usepackage{tikz}
\setlength\parindent{0pt}
\uselengthunit{in}

\begin{document}

% Time1
\directlua{time1 = os.clock(); texio.write_nl("time = " .. time1)}
\newsavebox{\tempvbox}
\setbox\tempvbox=\vbox to 4in{{\hsize=4in \blindtext[1]}}

% Time2
\directlua{time2 = os.clock(); texio.write_nl("time = " .. time2)}
\directlua{
    tempvboxnatural = node.vpack(tex.getbox('tempvbox').head)
}%
% Time3
\directlua{time3 = os.clock(); texio.write_nl("time = " .. time3)}

\directlua{texio.write_nl("(time3-time2)*100/(time2-time1) = " .. (time3-time2)*100/(time2-time1) .. " \csstring\%" )}


Set height of tempvbox: \directlua{tex.sprint(-2,string.format("\csstring\%f  in",(tex.getbox('tempvbox').height/tex.sp('1in'))))}

Natural Height of tempvbox: \directlua{tex.sprint(-2,string.format("\csstring\%f  in",(tempvboxnatural.height/tex.sp('1in'))))}

%Print Time2-Time1, and Time3-Time2 here
Delta1 (Time2-Time1): \directlua{tex.sprint(time2-time1)}

Delta2 (Time3-Time2): \directlua{tex.sprint(time3-time2)}

(Delta2/Delta1)*100: \directlua{tex.sprint((time3-time2)*100/(time2-time1))} \%

Partial contents of tempvbox:

\vsplit\tempvbox to 6in

\end{document}

Screenshot:

Screenshot of compiled output

Improve this answer
1
  • 1
    Actually both are O(n), but the hpack is so fast that you are measuring other stuff instead. E.g. for the single paragraph version, the command which saves the timestamp, formats and prints it is an order of magnitude slower than then the vpack. Therefore this constant dominates your benchmark until you have quite a lot of paragraphs.
    – Marcel Krüger
    Sep 14, 2020 at 6:17

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.