[NTG-context] save runtime information

[NTG-context] save runtime information

[Thomas A. Schmitz]

Hi,

a couple of years ago, I asked whether it was possible to typeset the 
information about runtime that I get at the end of the context run. Hans 
provided an answer 
(https://www.mail-archive.com/ntg-context@ntg.nl/msg90554.html):

> it's in the log file:
> 
> local data    = io.loaddata("oeps.log") or ""
> 
> local pattern = "> runtime: ([%d%.]+) seconds, ([%d]+) processed pages, ([%d]+) shipped pages, ([%d%.]+) pages/second"
> 
> 
> local r, n, s, p = string.match(data,pattern)
> 
> print(r,n,s,p)

The information I get this way is inaccurate. The runtime (in seconds) I 
see at the end of the run on the terminal:

5.635

vs. the value I get with the code:

0.660260200500488

I'm not sure whether something has changed with lmtx or if this was the 
case before (the log file is being written to during the run, so this 
may explain the difference?). So my question from then still stands: is 
it possible to extract the real runtime somehow? I would like to write 
it to a different file at the end of the run. What would be the best way 
to do this?

All best

Thomas


___________________________________________________________________________________
If your question is of interest to others as well, please add an entry to the Wiki!

maillist : ntg-context@ntg.nl / https://mailman.ntg.nl/mailman3/lists/ntg-context.ntg.nl
webpage  : https://www.pragma-ade.nl / https://context.aanhet.net (mirror)
archive  : https://github.com/contextgarden/context
wiki     : https://wiki.contextgarden.net
___________________________________________________________________________________

[NTG-context] Re: save runtime information

[Hans Hagen]

On 11/19/2024 11:38 PM, Thomas A. Schmitz wrote:
> Hi,
> 
> a couple of years ago, I asked whether it was possible to typeset the 
> information about runtime that I get at the end of the context run. Hans 
> provided an answer (https://www.mail-archive.com/ntg-context@ntg.nl/ 
> msg90554.html):
> 
>> it's in the log file:
>>
>> local data    = io.loaddata("oeps.log") or ""
>>
>> local pattern = "> runtime: ([%d%.]+) seconds, ([%d]+) processed 
>> pages, ([%d]+) shipped pages, ([%d%.]+) pages/second"
>>
>>
>> local r, n, s, p = string.match(data,pattern)
>>
>> print(r,n,s,p)
> 
> The information I get this way is inaccurate. The runtime (in seconds) I 
> see at the end of the run on the terminal:
> 
> 5.635
> 
> vs. the value I get with the code:
> 
> 0.660260200500488
> 
> I'm not sure whether something has changed with lmtx or if this was the 
> case before (the log file is being written to during the run, so this 
> may explain the difference?). So my question from then still stands: is 
> it possible to extract the real runtime somehow? I would like to write 
> it to a different file at the end of the run. What would be the best way 
> to do this?

Ah, you're trying to locate bottlenecks ... you need to register timing 
pretty late, like this:

\startluacode
luatex.wrapup (
     function()
         --
         print("saving runtime in foo.txt")
         io.savedata("foo.txt",statistics.elapsedtime(lua.getruntime()))
         --
         local t = {
             runtime = statistics.elapsedtime(lua.getruntime()),
             mytime  = statistics.elapsedtime("foo"),
         }
         print("saving runtime in foo.lua")
         table.save("foo.lua",t)
         --
     end
)
\stopluacode

\starttext

% it's showtime:

runtime : \cldcontext {
     io.loaddata("foo.txt")
}

mytime: \cldcontext {
     ( table.load("foo.lua") or { } ).mytime
}

% let's waste some time:

\ctxlua{statistics.starttiming("foo")}
\dorecurse{500}{
     \glyphxscale\numexpr1000-#1\relax
     \samplefile{knuthmath}
     \blank
}
\ctxlua{statistics.stoptiming("foo")}

\stoptext

Wikifying a better example probably takes more time than this run,

Hans


-----------------------------------------------------------------
                                           Hans Hagen | PRAGMA ADE
               Ridderstraat 27 | 8061 GH Hasselt | The Netherlands
        tel: 038 477 53 69 | www.pragma-ade.nl | www.pragma-pod.nl
-----------------------------------------------------------------
___________________________________________________________________________________
If your question is of interest to others as well, please add an entry to the Wiki!

maillist : ntg-context@ntg.nl / https://mailman.ntg.nl/mailman3/lists/ntg-context.ntg.nl
webpage  : https://www.pragma-ade.nl / https://context.aanhet.net (mirror)
archive  : https://github.com/contextgarden/context
wiki     : https://wiki.contextgarden.net
___________________________________________________________________________________

[NTG-context] Re: save runtime information

[Thomas A. Schmitz]

Thank you, Hans! I am playing with it right now and will try to add a 
simple example to the wiki. For the time being, I just want to keep some 
sort of statistics around, also to measure performance of my computers 
and servers. Since the log file will be read and written to by other 
programs as well, I'm keeping it very simple, in a text format, so I 
simplify your code a bit, maybe that's a good starting point for others 
on the wiki to elaborate.

All best

Thomas

On 11/20/24 9:10 AM, Hans Hagen wrote:
> Ah, you're trying to locate bottlenecks ... you need to register timing 
> pretty late, like this:
> 
> \startluacode
> luatex.wrapup (
>      function()
>          --
>          print("saving runtime in foo.txt")
>          io.savedata("foo.txt",statistics.elapsedtime(lua.getruntime()))
>          --
>          local t = {
>              runtime = statistics.elapsedtime(lua.getruntime()),
>              mytime  = statistics.elapsedtime("foo"),
>          }
>          print("saving runtime in foo.lua")
>          table.save("foo.lua",t)
>          --
>      end
> )
> \stopluacode
> 
> \starttext
> 
> % it's showtime:
> 
> runtime : \cldcontext {
>      io.loaddata("foo.txt")
> }
> 
> mytime: \cldcontext {
>      ( table.load("foo.lua") or { } ).mytime
> }
> 
> % let's waste some time:
> 
> \ctxlua{statistics.starttiming("foo")}
> \dorecurse{500}{
>      \glyphxscale\numexpr1000-#1\relax
>      \samplefile{knuthmath}
>      \blank
> }
> \ctxlua{statistics.stoptiming("foo")}
> 
> \stoptext
> 
> Wikifying a better example probably takes more time than this run,
> 
> Hans


-- 
Prof. Dr. Thomas A. Schmitz
Institut für Klassische und Romanische Philologie
Universität Bonn
Rabinstr. 8
53111 Bonn
http://www.philologie.uni-bonn.de/de/personal/schmitz
___________________________________________________________________________________
If your question is of interest to others as well, please add an entry to the Wiki!

maillist : ntg-context@ntg.nl / https://mailman.ntg.nl/mailman3/lists/ntg-context.ntg.nl
webpage  : https://www.pragma-ade.nl / https://context.aanhet.net (mirror)
archive  : https://github.com/contextgarden/context
wiki     : https://wiki.contextgarden.net
___________________________________________________________________________________