diff options
Diffstat (limited to 'tex/context/base/mkiv/util-deb.lua')
| -rw-r--r-- | tex/context/base/mkiv/util-deb.lua | 264 |
1 files changed, 216 insertions, 48 deletions
diff --git a/tex/context/base/mkiv/util-deb.lua b/tex/context/base/mkiv/util-deb.lua index ee732b3b5..57e015386 100644 --- a/tex/context/base/mkiv/util-deb.lua +++ b/tex/context/base/mkiv/util-deb.lua @@ -12,87 +12,255 @@ if not modules then modules = { } end modules ['util-deb'] = { local debug = require "debug" -local getinfo = debug.getinfo -local type, next, tostring = type, next, tostring -local format, find = string.format, string.find -local is_boolean = string.is_boolean +local getinfo, sethook = debug.getinfo, debug.sethook +local type, next, tostring, tonumber = type, next, tostring, tonumber +local format, find, sub, gsub = string.format, string.find, string.sub, string.gsub +local insert, remove, sort = table.insert, table.remove, table.sort +local setmetatableindex = table.setmetatableindex utilities = utilities or { } local debugger = utilities.debugger or { } utilities.debugger = debugger -local counters = { } +local report = logs.reporter("debugger") + +local ticks = os.gettimeofday or os.clock +local seconds = function(n) return n or 0 end +local overhead = 0 +local dummycalls = 10*1000 +local nesting = 0 local names = { } -local report = logs.reporter("debugger") +local initialize = false --- one +if not (FFISUPPORTED and ffi) then -local function hook() - local f = getinfo(2) -- "nS" - if f then - local n = "unknown" - if f.what == "C" then - n = f.name or '<anonymous>' - if not names[n] then - names[n] = format("%42s",n) + -- we have no precise timer + +elseif os.type == "windows" then + + initialize = function() + local kernel = ffilib("kernel32","system") -- no checking + if kernel then + local tonumber = ffi.number or tonumber + ffi.cdef[[ + int QueryPerformanceFrequency(int64_t *lpFrequency); + int QueryPerformanceCounter(int64_t *lpPerformanceCount); + ]] + local target = ffi.new("__int64[1]") + ticks = function() + if kernel.QueryPerformanceCounter(target) == 1 then + return tonumber(target[0]) + else + return 0 + end end - else - -- source short_src linedefined what name namewhat nups func - n = f.name or f.namewhat or f.what - if not n or n == "" then - n = "?" + local target = ffi.new("__int64[1]") + seconds = function(ticks) + if kernel.QueryPerformanceFrequency(target) == 1 then + return ticks / tonumber(target[0]) + else + return 0 + end + end + end + initialize = false + end + +elseif os.type == "unix" then + + -- for the values: echo '#include <time.h>' > foo.h; gcc -dM -E foo.h + + initialize = function() + local C = ffi.C + local tonumber = ffi.number or tonumber + ffi.cdef [[ + /* what a mess */ + typedef int clk_id_t; + typedef enum { CLOCK_REALTIME, CLOCK_MONOTONIC, CLOCK_PROCESS_CPUTIME_ID } clk_id; + typedef struct timespec { long sec; long nsec; } ctx_timespec; + int clock_gettime(clk_id_t timerid, struct timespec *t); + ]] + local target = ffi.new("ctx_timespec[?]",1) + local clock = C.CLOCK_PROCESS_CPUTIME_ID + ticks = function () + C.clock_gettime(clock,target) + return tonumber(target[0].sec*1000000000 + target[0].nsec) + end + seconds = function(ticks) + return ticks/1000000000 + end + initialize = false + end + +end + +setmetatableindex(names,function(t,name) + local v = setmetatableindex(function(t,source) + local v = setmetatableindex(function(t,line) + local v = { total = 0, count = 0 } + t[line] = v + return v + end) + t[source] = v + return v + end) + t[name] = v + return v +end) + +local function hook(where) + local f = getinfo(2,"nSl") + if f then + local source = f.short_src + if not source then + return + end + local line = f.linedefined or 0 + local name = f.name + if not name then + local what = f.what + if what == "C" then + name = "<anonymous>" + else + name = f.namewhat or what or "<unknown>" end - if not names[n] then - names[n] = format("%42s : % 5i : %s",n,f.linedefined or 0,f.short_src or "unknown source") + end + local data = names[name][source][line] + if where == "call" then + data.count = data.count + 1 + insert(data,ticks()) + elseif where == "return" then + local t = remove(data) + if t then + data.total = data.total + ticks() - t end end - counters[n] = (counters[n] or 0) + 1 end end -function debugger.showstats(printer,threshold) -- hm, something has changed, rubish now - printer = printer or report - threshold = threshold or 0 - local total, grandtotal, functions = 0, 0, 0 - local dataset = { } - for name, count in next, counters do - dataset[#dataset+1] = { name, count } +function debugger.showstats(printer,threshold) + local printer = printer or report + local calls = 0 + local functions = 0 + local dataset = { } + local length = 0 + local wholetime = 0 + local threshold = threshold or 0 + for name, sources in next, names do + for source, lines in next, sources do + for line, data in next, lines do + local count = data.count + if count > threshold then + if #name > length then + length = #name + end + local total = data.total + local real = total + if real > 0 then + real = total - (count * overhead / dummycalls) + if real < 0 then + real = 0 + end + wholetime = wholetime + real + end + if line < 0 then + line = 0 + end + -- if name = "a" then + -- -- weird name + -- end + dataset[#dataset+1] = { real, total, count, name, source, line } + end + end + end end - table.sort(dataset,function(a,b) return a[2] == b[2] and b[1] > a[1] or a[2] > b[2] end) - for i=1,#dataset do - local d = dataset[i] - local name = d[1] - local count = d[2] - if count > threshold and not find(name,"for generator") then -- move up - printer(format("%8i %s\n", count, names[name])) - total = total + count + sort(dataset,function(a,b) + if a[1] == b[1] then + if a[2] == b[2] then + if a[3] == b[3] then + if a[4] == b[4] then + if a[5] == b[5] then + return a[6] < b[6] + else + return a[5] < b[5] + end + else + return a[4] < b[4] + end + else + return b[3] < a[3] + end + else + return b[2] < a[2] + end + else + return b[1] < a[1] end - grandtotal = grandtotal + count + end) + if length > 50 then + length = 50 + end + local fmt = string.formatters["%4.9k %4.9k %3.3k %8i %-" .. length .. "s %4i %s"] + for i=1,#dataset do + local data = dataset[i] + local real = data[1] + local total = data[2] + local count = data[3] + local name = data[4] + local source = data[5] + local line = data[6] + local percent = real / wholetime + calls = calls + count functions = functions + 1 + name = gsub(name,"%s+"," ") + if #name > length then + name = sub(name,1,length) + end + printer(fmt(seconds(total),seconds(real),percent,count,name,line,source)) end - printer("\n") - printer(format("functions : % 10i\n", functions)) - printer(format("total : % 10i\n", total)) - printer(format("grand total: % 10i\n", grandtotal)) - printer(format("threshold : % 10i\n", threshold)) + printer("") + printer(format("functions : %i", functions)) + printer(format("calls : %i", calls)) + printer(format("overhead : %f", seconds(overhead/1000))) + + -- table.save("luatex-profile.lua",names) end function debugger.savestats(filename,threshold) local f = io.open(filename,'w') if f then - debugger.showstats(function(str) f:write(str) end,threshold) + debugger.showstats(function(str) f:write(str,"\n") end,threshold) f:close() end end function debugger.enable() - debug.sethook(hook,"c") + if nesting == 0 then + running = true + if initialize then + initialize() + end + sethook(hook,"cr") + local function dummy() end + local t = ticks() + for i=1,dummycalls do + dummy() + end + overhead = ticks() - t + end + if nesting > 0 then + nesting = nesting + 1 + end end function debugger.disable() - debug.sethook() - -- counters[debug.getinfo(2,"f").func] = nil + if nesting > 0 then + nesting = nesting - 1 + end + if nesting == 0 then + sethook() + end end -- debugger.enable() |