summaryrefslogtreecommitdiff
path: root/Master/texmf-dist/tex/context/base/mkxl/trac-inf.lmt
diff options
context:
space:
mode:
Diffstat (limited to 'Master/texmf-dist/tex/context/base/mkxl/trac-inf.lmt')
-rw-r--r--Master/texmf-dist/tex/context/base/mkxl/trac-inf.lmt425
1 files changed, 425 insertions, 0 deletions
diff --git a/Master/texmf-dist/tex/context/base/mkxl/trac-inf.lmt b/Master/texmf-dist/tex/context/base/mkxl/trac-inf.lmt
new file mode 100644
index 00000000000..ebcd21e07af
--- /dev/null
+++ b/Master/texmf-dist/tex/context/base/mkxl/trac-inf.lmt
@@ -0,0 +1,425 @@
+if not modules then modules = { } end modules ['trac-inf'] = {
+ version = 1.001,
+ comment = "companion to trac-inf.mkiv",
+ author = "Hans Hagen, PRAGMA-ADE, Hasselt NL",
+ copyright = "PRAGMA ADE / ConTeXt Development Team",
+ license = "see context related readme files"
+}
+
+-- As we want to protect the global tables, we no longer store the timing
+-- in the tables themselves but in a hidden timers table so that we don't
+-- get warnings about assignments. This is more efficient than using rawset
+-- and rawget.
+
+local type, tonumber, select = type, tonumber, select
+local format, lower, find, gsub, rep = string.format, string.lower, string.find, string.gsub, string.rep
+local concat = table.concat
+local clock = os.gettimeofday or os.clock -- should go in environment
+
+local setmetatableindex = table.setmetatableindex
+local serialize = table.serialize
+local formatters = string.formatters
+
+statistics = statistics or { }
+local statistics = statistics
+
+statistics.enable = true
+statistics.threshold = 0.01
+
+local statusinfo, n, registered, timers = { }, 0, { }, { }
+
+setmetatableindex(timers,function(t,k)
+ local v = { timing = 0, loadtime = 0, offset = 0 }
+ t[k] = v
+ return v
+end)
+
+local function hastiming(instance)
+ return instance and timers[instance]
+end
+
+local function resettiming(instance)
+ timers[instance or "notimer"] = { timing = 0, loadtime = 0, offset = 0 }
+end
+
+local ticks = clock
+local seconds = function(n) return n or 0 end
+
+ticks = lua.getpreciseticks
+seconds = lua.getpreciseseconds
+
+local function starttiming(instance,reset)
+ local timer = timers[instance or "notimer"]
+ local it = timer.timing
+ if reset then
+ it = 0
+ timer.loadtime = 0
+ end
+ if it == 0 then
+ timer.starttime = ticks()
+ if not timer.loadtime then
+ timer.loadtime = 0
+ end
+ end
+ timer.timing = it + 1
+end
+
+local function stoptiming(instance)
+ local timer = timers[instance or "notimer"]
+ local it = timer.timing
+ if it > 1 then
+ timer.timing = it - 1
+ else
+ local starttime = timer.starttime
+ if starttime and starttime > 0 then
+ local stoptime = ticks()
+ local loadtime = stoptime - starttime
+ timer.stoptime = stoptime
+ timer.loadtime = timer.loadtime + loadtime
+ timer.timing = 0
+ timer.starttime = 0
+ end
+ end
+end
+
+local function benchmarktimer(instance)
+ local timer = timers[instance or "notimer"]
+ local it = timer.timing
+ if it > 1 then
+ timer.timing = it - 1
+ else
+ local starttime = timer.starttime
+ if starttime and starttime > 0 then
+ timer.offset = ticks() - starttime
+ else
+ timer.offset = 0
+ end
+ end
+end
+
+local function elapsed(instance)
+ if type(instance) == "number" then
+ return instance
+ else
+ local timer = timers[instance or "notimer"]
+ return timer and seconds(timer.loadtime - 2*(timer.offset or 0)) or 0
+ end
+end
+
+local function currenttime(instance)
+ if type(instance) == "number" then
+ return instance
+ else
+ local timer = timers[instance or "notimer"]
+ local it = timer.timing
+ if it > 1 then
+ -- whatever
+ else
+ local starttime = timer.starttime
+ if starttime and starttime > 0 then
+ return seconds(timer.loadtime + ticks() - starttime - 2*(timer.offset or 0))
+ end
+ end
+ return 0
+ end
+end
+
+local function elapsedtime(instance)
+ return format("%0.3f",elapsed(instance))
+end
+
+local function elapsedindeed(instance)
+ return elapsed(instance) > statistics.threshold
+end
+
+local function elapsedseconds(instance,rest) -- returns nil if 0 seconds
+ if elapsedindeed(instance) then
+ return format("%0.3f seconds %s", elapsed(instance),rest or "")
+ end
+end
+
+statistics.hastiming = hastiming
+statistics.resettiming = resettiming
+statistics.starttiming = starttiming
+statistics.stoptiming = stoptiming
+statistics.currenttime = currenttime
+statistics.elapsed = elapsed
+statistics.elapsedtime = elapsedtime
+statistics.elapsedindeed = elapsedindeed
+statistics.elapsedseconds = elapsedseconds
+statistics.benchmarktimer = benchmarktimer
+
+-- general function .. we might split this module
+
+function statistics.register(tag,fnc)
+ if statistics.enable and type(fnc) == "function" then
+ -- second load can overload:
+ local rt = registered[tag] or (#statusinfo + 1)
+ statusinfo[rt] = { tag, fnc }
+ registered[tag] = rt
+ if #tag > n then n = #tag end
+ end
+end
+
+local report = logs.reporter("mkiv lua stats")
+
+function statistics.show()
+ if statistics.enable then
+ -- this code will move
+ local register = statistics.register
+ register("used platform", function()
+ return format("%s, type: %s, binary subtree: %s",
+ os.platform or "unknown",os.type or "unknown", environment.texos or "unknown")
+ end)
+ register("used engine", function()
+ return format("%s version: %s, functionality level: %s, format id: %s, compiler: %s",
+ LUATEXENGINE, LUATEXVERSION, LUATEXFUNCTIONALITY, LUATEXFORMATID, status.used_compiler)
+ end)
+ register("tex properties", function()
+ local t = status.gethashstate()
+ local l = status.getlookupstate()
+ local m = status.gettexstate()
+ return format("%s hash slots used of %s, %s control sequences, approximate memory usage: %i MB",
+ t.top, t.max, l.ptr, m.approximate // (1024 * 1024))
+ end)
+ register("callbacks", statistics.callbacks)
+ -- so far
+ register("lua properties",function()
+ -- local hash = lua.gethashchars()
+ local mask = load([[τεχ = 1]]) and "utf" or "ascii"
+ -- return format("engine: %s %s, used memory: %s, hash chars: min(%i,40), symbol mask: %s (%s)",
+ return format("engine: %s %s, used memory: %s, symbol mask: %s (%s)",
+ "lua", LUAVERSION, statistics.memused(), mask, mask == "utf" and "τεχ" or "tex")
+ end)
+ register("runtime",statistics.runtime)
+ logs.newline() -- initial newline
+ for i=1,#statusinfo do
+ local s = statusinfo[i]
+ local r = s[2]()
+ if r then
+ report("%s: %s",s[1],r)
+ end
+ end
+ -- logs.newline() -- final newline
+ statistics.enable = false
+ end
+end
+
+function statistics.memused() -- no math.round yet -)
+ local round = math.round or math.floor
+ local luastate = status.getluastate()
+ return format("%s MB, ctx: %s MB, max: %s MB",
+ round(collectgarbage("count")//1024),
+ round(luastate.state_bytes//1048576),
+ luastate.state_bytes_max and round(luastate.state_bytes_max//1048576) or "unknown"
+ )
+end
+
+starttiming(statistics)
+
+function statistics.formatruntime(runtime) -- indirect so it can be overloaded and
+ return format("%s seconds", runtime) -- indeed that happens in cure-uti.lua
+end
+
+function statistics.runtime()
+ stoptiming(statistics)
+ -- stoptiming(statistics) -- somehow we can start the timer twice, but where
+ local runtime = lua.getruntime and lua.getruntime() or elapsedtime(statistics)
+ return statistics.formatruntime(runtime)
+end
+
+local report = logs.reporter("system")
+
+function statistics.timed(action,all)
+ starttiming("run")
+ action()
+ stoptiming("run")
+ local runtime = tonumber(elapsedtime("run"))
+ if all then
+ local alltime = tonumber(lua.getruntime and lua.getruntime() or elapsedtime(statistics))
+ if alltime and alltime > 0 then
+ report("total runtime: %0.3f seconds of %0.3f seconds",runtime,alltime)
+ return
+ end
+ end
+ report("total runtime: %0.3f seconds",runtime)
+end
+
+-- goodie
+
+function statistics.tracefunction(base,tag,...)
+ for i=1,select("#",...) do
+ local name = select(i,...)
+ local stat = { }
+ local func = base[name]
+ setmetatableindex(stat,function(t,k) t[k] = 0 return 0 end)
+ base[name] = function(n,k,v) stat[k] = stat[k] + 1 return func(n,k,v) end
+ statistics.register(formatters["%s.%s"](tag,name),function() return serialize(stat,"calls") end)
+ end
+end
+
+-- now here
+
+status.iocodes = setmetatableindex(tex.getiovalues(), function() return "unknown" end)
+
+local report = logs.reporter("system")
+
+function statistics.showusage(when)
+ local s = status.list()
+ local c = status.getcallbackstate() -- status.callbacks
+ local m = mplib.getcallbackstate()
+ local b = backends.getcallbackstate()
+ --
+ local estatus = s.expandstate
+ local tstatus = s.texstate
+ local lstatus = s.luastate
+ local rstatus = s.readstate
+ --
+ local pstatus = logs.private.getpagetiming()
+ --
+ local iocode = status.iocodes[rstatus.iocode]
+ --
+ local mpinstances, mpmemory = metapost.getstatistics(true)
+ --
+ report("")
+ if when == "finish" then
+ report("status after finishing run")
+ else
+ report("status after shipping out page %s",tex.getcount("realpageno"))
+ end
+ report("")
+ local list = {
+ "stringstate", "poolstate", "hashstate", "lookupstate",
+ "nodestate", "extrastate", "tokenstate",
+ "bufferstate", "inputstate", "filestate",
+ "neststate", "parameterstate", "savestate",
+ "fontstate", "languagestate", "markstate", "sparsestate",
+ }
+ local fields = { "max", "min", "set", "stp", false, "mem", "all", false, "ini", "ptr", "top" }
+ local line = rep("-",190)
+ do
+ local t = { }
+ for i=1,#list do
+ t[i] = gsub(list[i],"state","")
+ end
+ report("%w%s",2,line)
+ report("%w%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s",5,unpack(t))
+ report("%w%s",2,line)
+ end
+ for i=1,#fields do
+ local f = fields[i]
+ if f then
+ local t = { }
+ for i=1,#list do
+ local n = s[list[i]][f]
+ t[i] = n < 0 and formatters["%w"](11) or formatters["%11i"](n)
+ end
+ report(" %3s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s",f,unpack(t))
+ else
+ report("")
+ end
+ end
+ report("%w%s",2,line)
+ report("")
+ report(" current input type : %s", iocode)
+ if iocode == "file" then
+ report(" current file name : %s", rstatus.filename or "")
+ report(" current line number : %s", rstatus.linenumber)
+ end
+ report("")
+ report(" approximate memory : %s (%s MB)", tstatus.approximate, tstatus.approximate // 1048576)
+ report("")
+ report(" expansion depth : min: %s, max: %s, set: %s, top: %s", estatus.min, estatus.max, estatus.set, estatus.top)
+ report("")
+ report(" luabytecode registers : %s", lstatus.bytecodes)
+ report(" luabytecode bytes : %s (%s MB)", lstatus.bytecode_bytes, lstatus.bytecode_bytes // 1048576)
+ report(" luastate bytes now : %s (%s MB)", lstatus.state_bytes, lstatus.state_bytes // 1048576)
+ report(" luastate bytes max : %s (%s MB)", lstatus.state_bytes_max, lstatus.state_bytes_max // 1048576)
+ report("")
+ report(" file callbacks : %s", c.file)
+ report(" saved callbacks : %s", c.saved)
+ report(" direct callbacks : %s", c.direct)
+ report(" function callbacks : %s", c["function"])
+ report(" value callbacks : %s", c.value)
+ report(" message callbacks : %s", c.message)
+ report(" bytecode callbacks : %s", c.bytecode)
+ report("")
+ report(" mp instances : %s", mpinstances)
+ report(" mp estimated memory : %s (%s MB)", mpmemory, mpmemory // 1048576)
+ report(" mp file callbacks : %s", m.file)
+ report(" mp text callbacks : %s", m.text)
+ report(" mp script callbacks : %s", m.script)
+ report(" mp log callbacks : %s", m.log)
+ report("")
+ report(" total callbacks : %s", c.count)
+ report(" mp total callbacks : %s", m.count)
+ report(" backend callbacks : %s", b.count)
+ report("")
+ report(" page numbers : realpage %s, userpage %s, subpage %s",pstatus.page.real,pstatus.page.user,pstatus.page.sub)
+ report(" page timing : total %0.03f, page %0.03f, average %0.03f",pstatus.time.elapsed,pstatus.time.page,pstatus.time.average)
+ report("")
+end
+
+function statistics.showmemory(when)
+ local s = status.list()
+ --
+ report("")
+ report("memory configuration")
+ report("")
+ local list = {
+ "stringstate", "poolstate", "hashstate", "lookupstate",
+ "nodestate", "tokenstate",
+ "bufferstate", "inputstate", "filestate",
+ "neststate", "parameterstate", "savestate",
+ "fontstate", "languagestate", "markstate",
+ }
+ local fields = { "max", "min", "set", "stp" }
+ local line = rep("-",168)
+ do
+ local t = { }
+ for i=1,#list do
+ t[i] = gsub(list[i],"state","")
+ end
+ report("%w%s",2,line)
+ report("%w%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s",5,unpack(t))
+ report("%w%s",2,line)
+ end
+ for i=1,#fields do
+ local f = fields[i]
+ if f then
+ local t = { }
+ for i=1,#list do
+ local n = s[list[i]][f]
+ t[i] = n < 0 and formatters["%w"](11) or formatters["%11i"](n)
+ end
+ report(" %3s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s%11s",f,unpack(t))
+ else
+ report("")
+ end
+ end
+ report("%w%s",2,line)
+ report("")
+end
+
+local registered = false
+local enabled = false
+
+trackers.register("system.usage", function(v)
+ if v and not registered then
+ logs.private.enablepagetiming()
+ if v ~= "summary" then
+ luatex.registerpageactions(function()
+ if enabled then
+ statistics.showusage("page")
+ end
+ end)
+ end
+ luatex.registerstopactions(function()
+ if enabled then
+ statistics.showusage("finish")
+ end
+ end)
+ registered = true
+ end
+ enabled = v
+end)