1 files changed, 30 insertions, 33 deletions

diff --git a/tex/context/base/mkiv/trac-log.lua b/tex/context/base/mkiv/trac-log.lua
index 1471bd4c7..206af5668 100644
--- a/tex/context/base/mkiv/trac-log.lua
+++ b/tex/context/base/mkiv/trac-log.lua
@@ -405,6 +405,15 @@ if runningtex then
     setlogfile  = ignore
     settimedlog = ignore
 
+ -- settimedlog = function()
+ --     local localtime = os.localtime
+ --     local writeline = write_nl
+ --     write_nl = function(f,...)
+ --         writeline(f,localtime() .. " | " .. concat { ... })
+ --     end
+ --     settimedlog = ignore
+ -- end
+
 else
 
     local report_yes, subreport_yes, status_yes
@@ -758,7 +767,7 @@ if tex then
     local report      = logs.reporter("pages") -- not needed but saves checking when we grep for it
     local texgetcount = tex and tex.getcount
 
-    local real, user, sub
+    local real, user, sub = 0, 0, 0
 
     function logs.start_page_number()
         real = texgetcount("realpageno")
@@ -766,47 +775,35 @@ if tex then
         sub  = texgetcount("subpageno")
     end
 
-    local timing    = false
-    local starttime = nil
-    local lasttime  = nil
+    local timing   = false
+    local lasttime = nil
 
     trackers.register("pages.timing", function(v) -- only for myself (diagnostics)
-        starttime = os.clock() -- todo: use other timer
-        timing    = true
+        timing = ""
     end)
 
     function logs.stop_page_number() -- the first page can includes the initialization so we omit this in average
         if timing then
-            local elapsed, average
-            local stoptime = os.clock()
+            local elapsed = statistics.currenttime(statistics)
+            local average, page
             if not lasttime or real < 2 then
-                elapsed   = stoptime
-                average   = stoptime
-                starttime = stoptime
-            else
-                elapsed  = stoptime - lasttime
-                average  = (stoptime - starttime) / (real - 1)
-            end
-            lasttime = stoptime
-            if real <= 0 then
-                report("flushing page, time %0.04f / %0.04f",elapsed,average)
-            elseif user <= 0 then
-                report("flushing realpage %s, time %0.04f / %0.04f",real,elapsed,average)
-            elseif sub <= 0 then
-                report("flushing realpage %s, userpage %s, time %0.04f / %0.04f",real,user,elapsed,average)
+                average = elapsed
+                page    = elapsed
             else
-                report("flushing realpage %s, userpage %s, subpage %s, time %0.04f / %0.04f",real,user,sub,elapsed,average)
+                average = elapsed / (real - 1)
+                page    = elapsed - lasttime
             end
+            lasttime = elapsed
+            timing   = formatters[", total %0.03f, page %0.03f, average %0.03f"](elapsed,page,average)
+        end
+        if real <= 0 then
+            report("flushing page%s",timing)
+        elseif user <= 0 then
+            report("flushing realpage %s%s",real,timing)
+        elseif sub <= 0 then
+            report("flushing realpage %s, userpage %s%s",real,user,timing)
         else
-            if real <= 0 then
-                report("flushing page")
-            elseif user <= 0 then
-                report("flushing realpage %s",real)
-            elseif sub <= 0 then
-                report("flushing realpage %s, userpage %s",real,user)
-            else
-                report("flushing realpage %s, userpage %s, subpage %s",real,user,sub)
-            end
+            report("flushing realpage %s, userpage %s, subpage %s%s",real,user,sub,timing)
         end
         logs.flush()
     end
@@ -1031,7 +1028,7 @@ end
 
 if tex and tex.error then
     function logs.texerrormessage(...) -- for the moment we put this function here
-        tex.error(format(...), { })
+        tex.error(format(...))
     end
 else
     function logs.texerrormessage(...)