From b2c10135056be4af1a52ed8ef7b3f1f4017dccc0 Mon Sep 17 00:00:00 2001 From: Hans Hagen Date: Tue, 25 Aug 2020 20:19:49 +0200 Subject: 2020-08-25 19:59:00 --- tex/context/base/mkiv/cont-new.mkiv | 2 +- tex/context/base/mkiv/context.mkiv | 2 +- tex/context/base/mkiv/context.mkxl | 2 +- tex/context/base/mkiv/file-job.lua | 2 +- tex/context/base/mkiv/luat-cnf.lua | 3 + tex/context/base/mkiv/luat-cod.lmt | 9 +++ tex/context/base/mkiv/mult-ini.lua | 4 +- tex/context/base/mkiv/node-snp.lmt | 4 + tex/context/base/mkiv/page-lay.mkiv | 1 - tex/context/base/mkiv/status-files.pdf | Bin 28122 -> 28100 bytes tex/context/base/mkiv/status-lua.pdf | Bin 255951 -> 256148 bytes tex/context/base/mkiv/trac-deb.lmt | 2 +- tex/context/base/mkiv/trac-inf.lmt | 132 +++++++++++++++++++-------------- tex/context/base/mkiv/trac-log.lua | 34 +++++++-- tex/context/base/mkiv/trac-set.lua | 71 ++++++++++-------- 15 files changed, 167 insertions(+), 101 deletions(-) (limited to 'tex/context/base/mkiv') diff --git a/tex/context/base/mkiv/cont-new.mkiv b/tex/context/base/mkiv/cont-new.mkiv index 3fd088f87..40c3c3272 100644 --- a/tex/context/base/mkiv/cont-new.mkiv +++ b/tex/context/base/mkiv/cont-new.mkiv @@ -13,7 +13,7 @@ % \normalend % uncomment this to get the real base runtime -\newcontextversion{2020.08.25 07:58} +\newcontextversion{2020.08.25 19:56} %D This file is loaded at runtime, thereby providing an excellent place for hacks, %D patches, extensions and new features. There can be local overloads in cont-loc diff --git a/tex/context/base/mkiv/context.mkiv b/tex/context/base/mkiv/context.mkiv index 6273e59e6..092b16960 100644 --- a/tex/context/base/mkiv/context.mkiv +++ b/tex/context/base/mkiv/context.mkiv @@ -45,7 +45,7 @@ %D {YYYY.MM.DD HH:MM} format. \edef\contextformat {\jobname} -\edef\contextversion{2020.08.25 07:58} +\edef\contextversion{2020.08.25 19:56} %D Kind of special: diff --git a/tex/context/base/mkiv/context.mkxl b/tex/context/base/mkiv/context.mkxl index aab78dd9a..5c6ded5c9 100644 --- a/tex/context/base/mkiv/context.mkxl +++ b/tex/context/base/mkiv/context.mkxl @@ -29,7 +29,7 @@ %D {YYYY.MM.DD HH:MM} format. \edef\contextformat {\jobname} -\edef\contextversion{2020.08.25 07:58} +\edef\contextversion{2020.08.25 19:56} %D Kind of special: diff --git a/tex/context/base/mkiv/file-job.lua b/tex/context/base/mkiv/file-job.lua index 1197bb1ac..97e223387 100644 --- a/tex/context/base/mkiv/file-job.lua +++ b/tex/context/base/mkiv/file-job.lua @@ -972,7 +972,7 @@ function document.setcommandline() -- has to happen at the tex end in order to e end if arguments.usage then - directives.enable("system.usage") + trackers.enable("system.usage") end if arguments.batchmode then diff --git a/tex/context/base/mkiv/luat-cnf.lua b/tex/context/base/mkiv/luat-cnf.lua index 910ee5989..ebce83ca8 100644 --- a/tex/context/base/mkiv/luat-cnf.lua +++ b/tex/context/base/mkiv/luat-cnf.lua @@ -38,6 +38,7 @@ texconfig.stack_size = 100000 texconfig.buffer_size = 10000000 texconfig.token_size = 10000000 texconfig.node_size = 20000000 +texconfig.max_pool = 10000000 else @@ -60,6 +61,7 @@ local variablenames = CONTEXTLMTXMODE > 0 and { hash_extra = true, nest_size = true, max_strings = true, + max_pool = true, param_size = true, save_size = true, stack_size = true, @@ -67,6 +69,7 @@ local variablenames = CONTEXTLMTXMODE > 0 and { properties_size = true, token_size = true, node_size = true, + buffer_size = true, } or { error_line = false, half_error_line = false, diff --git a/tex/context/base/mkiv/luat-cod.lmt b/tex/context/base/mkiv/luat-cod.lmt index 802a89fc1..9b7564483 100644 --- a/tex/context/base/mkiv/luat-cod.lmt +++ b/tex/context/base/mkiv/luat-cod.lmt @@ -31,6 +31,8 @@ texconfig.node_size = 20000000 texconfig.max_print_line = 100000 texconfig.max_strings = 500000 +texconfig.max_pool = 10000000 + texconfig.hash_extra = 200000 texconfig.expand_depth = 10000 @@ -173,6 +175,13 @@ environment.jitsupported = JITSUPPORTED environment.initex = INITEXMODE environment.initexmode = INITEXMODE +-- if INITEXMODE then +-- -- we have about that amount so we preallocate then which gives less +-- -- reallocations (we're talking tiny record so no real gain) +-- lua.setbytecode(1024,nil) +-- -- but we don't want to lie about the amount either so ... +-- end + if not environment.luafilechunk then function environment.luafilechunk(filename) diff --git a/tex/context/base/mkiv/mult-ini.lua b/tex/context/base/mkiv/mult-ini.lua index d1271815c..ef04fb622 100644 --- a/tex/context/base/mkiv/mult-ini.lua +++ b/tex/context/base/mkiv/mult-ini.lua @@ -391,8 +391,8 @@ implement { } local function gss(s) - contextsprint(vrbcatcodes,getsetupstring(s)) - end + contextsprint(vrbcatcodes,getsetupstring(s)) +end implement { -- will b eoverloaded name = "getsetupstring", diff --git a/tex/context/base/mkiv/node-snp.lmt b/tex/context/base/mkiv/node-snp.lmt index a8d467956..d058a142a 100644 --- a/tex/context/base/mkiv/node-snp.lmt +++ b/tex/context/base/mkiv/node-snp.lmt @@ -38,6 +38,7 @@ function snapshots.takesample(comment) memories = { pool = status.getpoolstate(), hash = status.gethashstate(), + lookup = status.getlookupstate(), node = status.getnodestate(), token = status.gettokenstate(), buffer = status.getbufferstate(), @@ -47,6 +48,9 @@ function snapshots.takesample(comment) parameter = status.getparameterstate(), save = status.getsavestate(), expand = status.getexpandstate(), + read = status.getreadstate(), + font = status.getfontstate(), + language = status.getlanguagestate(), }, } end diff --git a/tex/context/base/mkiv/page-lay.mkiv b/tex/context/base/mkiv/page-lay.mkiv index 53e95460a..bec9dc7ce 100644 --- a/tex/context/base/mkiv/page-lay.mkiv +++ b/tex/context/base/mkiv/page-lay.mkiv @@ -1365,7 +1365,6 @@ \fetchruntimecommand \showsetups \f!page_run \fetchruntimecommand \showmargins \f!page_run \fetchruntimecommand \showgrid \f!page_run -\fetchruntimecommand \showusage \f!page_run \glet\page_grids_add_to_box\gobbleoneargument \glet\page_grids_add_to_one\gobbleoneargument diff --git a/tex/context/base/mkiv/status-files.pdf b/tex/context/base/mkiv/status-files.pdf index 1447eccbf..41c6c2f60 100644 Binary files a/tex/context/base/mkiv/status-files.pdf and b/tex/context/base/mkiv/status-files.pdf differ diff --git a/tex/context/base/mkiv/status-lua.pdf b/tex/context/base/mkiv/status-lua.pdf index da76fabf6..5d19ce520 100644 Binary files a/tex/context/base/mkiv/status-lua.pdf and b/tex/context/base/mkiv/status-lua.pdf differ diff --git a/tex/context/base/mkiv/trac-deb.lmt b/tex/context/base/mkiv/trac-deb.lmt index 42f6d183c..381fce073 100644 --- a/tex/context/base/mkiv/trac-deb.lmt +++ b/tex/context/base/mkiv/trac-deb.lmt @@ -419,7 +419,7 @@ local function showerror(lmxname) local linenumber = tonumber(readstate.linenumber) or 0 local errorcontext = "" if not filename then - filename = status.iocodes and status.iocodes[readstate.iocode] or 'unknown' + filename = status.iocodes[readstate.iocode] errorcontext = 'error in filename' else errorcontext = tracers.showlines(filename,linenumber,offset) diff --git a/tex/context/base/mkiv/trac-inf.lmt b/tex/context/base/mkiv/trac-inf.lmt index c7a4c3c34..1729c87e5 100644 --- a/tex/context/base/mkiv/trac-inf.lmt +++ b/tex/context/base/mkiv/trac-inf.lmt @@ -12,7 +12,7 @@ if not modules then modules = { } end modules ['trac-inf'] = { -- and rawget. local type, tonumber, select = type, tonumber, select -local format, lower, find = string.format, string.lower, string.find +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 @@ -209,9 +209,9 @@ 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")/1000), - round(luastate.state_bytes/1000000), - luastate.state_bytes_max and round(luastate.state_bytes_max/1000000) or "unknown" + round(collectgarbage("count")//1024), + round(luastate.state_bytes//1048576), + luastate.state_bytes_max and round(luastate.state_bytes_max//1048576) or "unknown" ) end @@ -260,14 +260,7 @@ end -- now here -status.iocodes = status.iocodes or { [0] = - "terminal input", - "lua input", - "scan token input", - "scan token eof input", - "tex macro", - "file input", -} +status.iocodes = setmetatableindex(tex.getiovalues(), function() return "unknown" end) local report = logs.reporter("usage") @@ -277,19 +270,14 @@ function statistics.showusage(when) local m = mplib.getcallbackstate() local b = backends.getcallbackstate() -- - local pool = s.poolstate - local hash = s.hashstate - local node = s.nodestate - local token = s.tokenstate - local buffer = s.bufferstate - local input = s.inputstate - local file = s.filestate - local nest = s.neststate - local parameter = s.parameterstate - local save = s.savestate - local expand = s.expandstate - local tstatus = s.texstate - local lstatus = s.luastate + 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] -- report("") if when == "finish" then @@ -298,53 +286,83 @@ function statistics.showusage(when) report("status after shipping out page %s",tex.getcount("realpageno")) end report("") - report(" current file name : %s", s.filename or "") - report(" current input type : %s", status.iocodes[s.iocode] or 'unknown') - report(" current line number : %s", s.linenumber) + local list = { + "stringstate", "poolstate", + "hashstate", "lookupstate", + "nodestate", "tokenstate", + "bufferstate", "inputstate", "filestate", + "neststate", "parameterstate", "savestate", + "fontstate", "languagestate", + } + local fields = { "max", "min", "set", "stp", false, "mem", "all", false, "ini", "ptr", "top" } + local line = rep("-",172) + do + local t = { } + for i=1,#list do + t[i] = gsub(list[i],"state","") + end + report("%w%s",2,line) + report("%w%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s",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"](12) or formatters["%12i"](n) + end + report(" %3s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s%12s",f,unpack(t)) + else + report("") + end + end + report("%w%s",2,line) report("") - report(" string memory : min: %s, max: %s, set: %s, mem: %s, top: %s, use: %s, cnt: %s", pool .min, pool .max, pool .set, pool .mem, pool .top, pool .use, pool.cnt) - report(" hash memory : min: %s, max: %s, set: %s, mem: %s, top: %s, use: %s, cnt: %s", hash .min, hash .max, hash .set, hash .mem, hash .top, hash .use, hash.cnt) - report(" node memory : min: %s, max: %s, set: %s, mem: %s, top: %s, use: %s, cnt: %s", node .min, node .max, node .set, node .mem, node .top, node .use, node.cnt) - report(" token memory : min: %s, max: %s, set: %s, mem: %s, top: %s, use: %s", token .min, token .max, token .set, token .mem, token .top, token.use) - report(" buffer size : min: %s, max: %s, set: %s, mem: %s, top: %s", buffer .min, buffer .max, buffer .set, buffer .mem, buffer .top) - report(" input stack : min: %s, max: %s, set: %s, mem: %s, top: %s", input .min, input .max, input .set, input .mem, input .top) - report(" input files : min: %s, max: %s, set: %s, mem: %s, top: %s", file .min, file .max, file .set, file .mem, file .top) - report(" nest stack : min: %s, max: %s, set: %s, mem: %s, top: %s", nest .min, nest .max, nest .set, nest .mem, nest .top) - report(" parameter stack : min: %s, max: %s, set: %s, mem: %s, top: %s", parameter.min, parameter.max, parameter.set, parameter.mem, parameter.top) - report(" save stack : min: %s, max: %s, set: %s, mem: %s, top: %s", save .min, save .max, save .set, save .mem, save .top) + 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", tstatus.approximate) + report(" approximate memory : %s (%s MB)", tstatus.approximate, tstatus.approximate // 1048576) report("") - report(" expansion depth : min: %s, max: %s, set: %s, top: %s", expand.min, expand.max, expand.set, expand.top) + report(" expansion depth : min: %s, max: %s, set: %s, top: %s", estatus.min, estatus.max, estatus.set, estatus.top) report("") - report(" luabytecode bytes : %s in %s registers", lstatus.bytecode_bytes, lstatus.bytecodes) - report(" luastate bytes : %s of %s", lstatus.state_bytes, lstatus.state_bytes_max or "unknown") + 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(" 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(" total callbacks : %s", c.count) - report(" backend callbacks : %s", b.count) + 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(" 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(" total callbacks : %s", c.count) + report(" mp total callbacks : %s", m.count) + report(" backend callbacks : %s", b.count) report("") - report(" mp total callbacks : %s", m.count) + 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 local registered = false local enabled = false -directives.register("system.usage", function(v) +trackers.register("system.usage", function(v) if v and not registered then + logs.private.enablepagetiming() luatex.registerpageactions(function() if enabled then statistics.showusage("page") end end) luatex.registerstopactions(function() if enabled then statistics.showusage("finish") end end) registered = true diff --git a/tex/context/base/mkiv/trac-log.lua b/tex/context/base/mkiv/trac-log.lua index 4917c0ec8..4fbab5cdc 100644 --- a/tex/context/base/mkiv/trac-log.lua +++ b/tex/context/base/mkiv/trac-log.lua @@ -804,14 +804,22 @@ if tex then end local timing = false + local usage = false local lasttime = nil - trackers.register("pages.timing", function(v) -- only for myself (diagnostics) - timing = "" - end) + logs.private = { + enablepagetiming = function() + usage = true + end, + getpagetiming = function() + return type(usage) == "table" and usage + end, + } + + trackers.register("pages.timing", function() timing = "" end) function logs.stop_page_number() -- the first page can includes the initialization so we omit this in average - if timing then + if timing or usage then local elapsed = statistics.currenttime(statistics) local average, page if not lasttime or real < 2 then @@ -822,7 +830,23 @@ if tex then page = elapsed - lasttime end lasttime = elapsed - timing = formatters[", total %0.03f, page %0.03f, average %0.03f"](elapsed,page,average) + if timing then + timing = formatters[", total %0.03f, page %0.03f, average %0.03f"](elapsed,page,average) + end + if usage then + usage = { + page = { + real = real, + user = user, + sub = sub, + }, + time = { + elapsed = elapsed, + page = page, + average = average, + } + } + end end if real <= 0 then report("flushing page%s",timing) diff --git a/tex/context/base/mkiv/trac-set.lua b/tex/context/base/mkiv/trac-set.lua index 960c4ef84..85a1155f1 100644 --- a/tex/context/base/mkiv/trac-set.lua +++ b/tex/context/base/mkiv/trac-set.lua @@ -33,7 +33,7 @@ local data = { } local trace_initialize = false -- only for testing during development local frozen = true -- this needs checking -function setters.initialize(filename,name,values) -- filename only for diagnostics +local function initialize_setter(filename,name,values) -- filename only for diagnostics local setter = data[name] if setter then -- trace_initialize = true @@ -81,8 +81,8 @@ end -- user interface code local function set(t,what,newvalue) - local data = t.data - if not data.frozen then + local data = t.data -- somehow this can be nil + if data and not data.frozen then local done = t.done if type(what) == "string" then what = settings_to_hash(what) -- inefficient but ok @@ -120,7 +120,7 @@ end local function reset(t) local data = t.data - if not data.frozen then + if data and not data.frozen then for name, functions in sortedthash(data) do for i=1,#functions do functions[i](false) @@ -144,7 +144,7 @@ local function disable(t,what) end end -function setters.register(t,what,...) +local function register_setter(t,what,...) local data = t.data what = lower(what) local functions = data[what] @@ -182,26 +182,27 @@ function setters.register(t,what,...) return false -- so we can use it in an assignment end -function setters.enable(t,what) +local function enable_setter(t,what) local e = t.enable t.enable, t.done = enable, { } + set(t,what,true) enable(t,what) t.enable, t.done = e, { } end -function setters.disable(t,what) +local function disable_setter(t,what) local e = t.disable t.disable, t.done = disable, { } disable(t,what) t.disable, t.done = e, { } end -function setters.reset(t) +local function reset_setter(t) t.done = { } reset(t) end -function setters.list(t) -- pattern +local function list_setter(t) -- pattern local list = table.sortedkeys(t.data) local user, system = { }, { } for l=1,#list do @@ -215,8 +216,8 @@ function setters.list(t) -- pattern return user, system end -function setters.show(t) - local list = setters.list(t) +local function show_setter(t) + local list = list_setter(t) t.report() for k=1,#list do local name = list[k] @@ -253,44 +254,52 @@ end -- we could make this into a module but we also want the rest avaliable -local enable, disable, register, list, show = setters.enable, setters.disable, setters.register, setters.list, setters.show - -function setters.report(setter,fmt,...) +local function report_setter(setter,fmt,...) print(formatters["%-15s : %s\n"](setter.name,formatters[fmt](...))) end -local function default(setter,name) +local function setter_default(setter,name) local d = setter.data[name] return d and d.default end -local function value(setter,name) +local function setter_value(setter,name) local d = setter.data[name] return d and (d.value or d.default) end -function setters.new(name) -- we could use foo:bar syntax (but not used that often) +local function new_setter(name) -- we could use foo:bar syntax (but not used that often) local setter -- we need to access it in setter itself setter = { data = allocate(), -- indexed, but also default and value fields name = name, - report = function(...) setters.report (setter,...) end, - enable = function(...) enable (setter,...) end, - disable = function(...) disable (setter,...) end, - reset = function(...) reset (setter,...) end, -- can be dangerous - register = function(...) register(setter,...) end, - list = function(...) return list (setter,...) end, - show = function(...) show (setter,...) end, - default = function(...) return default (setter,...) end, - value = function(...) return value (setter,...) end, + report = function(...) report_setter (setter,...) end, + enable = function(...) enable_setter (setter,...) end, + disable = function(...) disable_setter (setter,...) end, + reset = function(...) reset_setter (setter,...) end, -- can be dangerous + register = function(...) register_setter(setter,...) end, + list = function(...) return list_setter (setter,...) end, + show = function(...) show_setter (setter,...) end, + default = function(...) return setter_default (setter,...) end, + value = function(...) return setter_value (setter,...) end, } data[name] = setter return setter end -trackers = setters.new("trackers") -directives = setters.new("directives") -experiments = setters.new("experiments") +setters.enable = enable_setter +setters.disable = disable_setter +setters.report = report_setter +setters.register = register_setter +setters.list = list_setter +setters.show = show_setter +setters.reset = reset_setter +setters.new = new_setter +setters.initialize = initialize_setter + +trackers = new_setter("trackers") +directives = new_setter("directives") +experiments = new_setter("experiments") local t_enable, t_disable = trackers .enable, trackers .disable local d_enable, d_disable = directives .enable, directives .disable @@ -361,12 +370,12 @@ if environment then if engineflags then local list = engineflags["c:trackers"] or engineflags["trackers"] if type(list) == "string" then - setters.initialize("commandline flags","trackers",settings_to_hash(list)) + initialize_setter("commandline flags","trackers",settings_to_hash(list)) -- t_enable(list) end local list = engineflags["c:directives"] or engineflags["directives"] if type(list) == "string" then - setters.initialize("commandline flags","directives", settings_to_hash(list)) + initialize_setter("commandline flags","directives", settings_to_hash(list)) -- d_enable(list) end end -- cgit v1.2.3