util-deb.lua /size: 9 Kb    last modification: 2020-07-01 14:35
1if not modules then modules = { } end modules ['util-deb'] = {
2    version   = 1.001,
3    comment   = "companion to luat-lib.mkiv",
4    author    = "Hans Hagen, PRAGMA-ADE, Hasselt NL",
5    copyright = "PRAGMA ADE / ConTeXt Development Team",
6    license   = "see context related readme files"
7}
8
9-- the <anonymous> tag is kind of generic and used for functions that are not
10-- bound to a variable, like node.new, node.copy etc (contrary to for instance
11-- node.has_attribute which is bound to a has_attribute local variable in mkiv)
12
13local type, next, tostring, tonumber = type, next, tostring, tonumber
14local format, find, sub, gsub = string.format, string.find, string.sub, string.gsub
15local insert, remove, sort = table.insert, table.remove, table.sort
16local setmetatableindex = table.setmetatableindex
17
18utilities          = utilities or { }
19local debugger     = utilities.debugger or { }
20utilities.debugger = debugger
21
22local report       = logs.reporter("debugger")
23
24local ticks        = os.gettimeofday or os.clock
25local seconds      = function(n) return n or 0 end
26local overhead     = 0
27local dummycalls   = 10*1000
28local nesting      = 0
29local names        = { }
30
31local initialize = false
32
33if lua.getpreciseticks then
34
35    initialize = function()
36        ticks      = lua.getpreciseticks
37        seconds    = lua.getpreciseseconds
38        initialize = false
39    end
40
41elseif not (FFISUPPORTED and ffi) then
42
43    -- we have no precise timer
44
45elseif os.type == "windows" then
46
47    initialize = function()
48        local kernel = ffilib("kernel32","system") -- no checking
49        if kernel then
50            local tonumber = ffi.number or tonumber
51            ffi.cdef[[
52                int QueryPerformanceFrequency(int64_t *lpFrequency);
53                int QueryPerformanceCounter(int64_t *lpPerformanceCount);
54            ]]
55            local target = ffi.new("__int64[1]")
56            ticks = function()
57                if kernel.QueryPerformanceCounter(target) == 1 then
58                    return tonumber(target[0])
59                else
60                    return 0
61                end
62            end
63            local target = ffi.new("__int64[1]")
64            seconds = function(ticks)
65                if kernel.QueryPerformanceFrequency(target) == 1 then
66                    return ticks / tonumber(target[0])
67                else
68                    return 0
69                end
70            end
71        end
72        initialize = false
73    end
74
75elseif os.type == "unix" then
76
77    -- for the values: echo '#include <time.h>' > foo.h; gcc -dM -E foo.h
78
79    initialize = function()
80        local C        = ffi.C
81        local tonumber = ffi.number or tonumber
82        ffi.cdef [[
83            /* what a mess */
84            typedef int clk_id_t;
85            typedef enum { CLOCK_REALTIME, CLOCK_MONOTONIC, CLOCK_PROCESS_CPUTIME_ID } clk_id;
86            typedef struct timespec { long sec; long nsec; } ctx_timespec;
87            int clock_gettime(clk_id_t timerid, struct timespec *t);
88        ]]
89        local target = ffi.new("ctx_timespec[?]",1)
90        local clock  = C.CLOCK_PROCESS_CPUTIME_ID
91        ticks = function ()
92            C.clock_gettime(clock,target)
93            return tonumber(target[0].sec*1000000000 + target[0].nsec)
94        end
95        seconds = function(ticks)
96            return ticks/1000000000
97        end
98        initialize = false
99    end
100
101end
102
103setmetatableindex(names,function(t,name)
104    local v = setmetatableindex(function(t,source)
105        local v = setmetatableindex(function(t,line)
106            local v = { total = 0, count = 0, nesting = 0 }
107            t[line] = v
108            return v
109        end)
110        t[source] = v
111        return v
112    end)
113    t[name] = v
114    return v
115end)
116
117local getinfo = nil
118local sethook = nil
119
120local function hook(where)
121    local f = getinfo(2,"nSl")
122    if f then
123        local source = f.short_src
124        if not source then
125            return
126        end
127        local line = f.linedefined or 0
128        local name = f.name
129        if not name then
130            local what = f.what
131            if what == "C" then
132                name = "<anonymous>"
133            else
134                name = f.namewhat or what or "<unknown>"
135            end
136        end
137        local data = names[name][source][line]
138        if where == "call" then
139            local nesting = data.nesting
140            if nesting == 0 then
141                data.count = data.count + 1
142                insert(data,ticks())
143                data.nesting = 1
144            else
145                data.nesting = nesting + 1
146            end
147        elseif where == "return" then
148            local nesting = data.nesting
149            if nesting == 1 then
150                local t = remove(data)
151                if t then
152                    data.total = data.total + ticks() - t
153                end
154                data.nesting = 0
155            else
156                data.nesting = nesting - 1
157            end
158        end
159    end
160end
161
162function debugger.showstats(printer,threshold)
163    local printer   = printer or report
164    local calls     = 0
165    local functions = 0
166    local dataset   = { }
167    local length    = 0
168    local realtime  = 0
169    local totaltime = 0
170    local threshold = threshold or 0
171    for name, sources in next, names do
172        for source, lines in next, sources do
173            for line, data in next, lines do
174                local count = data.count
175                if count > threshold then
176                    if #name > length then
177                        length = #name
178                    end
179                    local total = data.total
180                    local real  = total
181                    if real > 0 then
182                        real = total - (count * overhead / dummycalls)
183                        if real < 0 then
184                            real = 0
185                        end
186                        realtime = realtime + real
187                    end
188                    totaltime = totaltime + total
189                    if line < 0 then
190                        line = 0
191                    end
192                 -- if name = "a" then
193                 --     -- weird name
194                 -- end
195                    dataset[#dataset+1] = { real, total, count, name, source, line }
196                end
197            end
198        end
199    end
200    sort(dataset,function(a,b)
201        if a[1] == b[1] then
202            if a[2] == b[2] then
203                if a[3] == b[3] then
204                    if a[4] == b[4] then
205                        if a[5] == b[5] then
206                            return a[6] < b[6]
207                        else
208                            return a[5] < b[5]
209                        end
210                    else
211                        return a[4] < b[4]
212                    end
213                else
214                    return b[3] < a[3]
215                end
216            else
217                return b[2] < a[2]
218            end
219        else
220            return b[1] < a[1]
221        end
222    end)
223    if length > 50 then
224        length = 50
225    end
226    local fmt = string.formatters["%4.9k s  %3.3k %%  %4.9k s  %3.3k %%  %8i #  %-" .. length .. "s  %4i  %s"]
227    for i=1,#dataset do
228        local data   = dataset[i]
229        local real   = data[1]
230        local total  = data[2]
231        local count  = data[3]
232        local name   = data[4]
233        local source = data[5]
234        local line   = data[6]
235        calls     = calls + count
236        functions = functions + 1
237        name = gsub(name,"%s+"," ")
238        if #name > length then
239            name = sub(name,1,length)
240        end
241        printer(fmt(seconds(total),100*total/totaltime,seconds(real),100*real/realtime,count,name,line,source))
242    end
243    printer("")
244    printer(format("functions : %i", functions))
245    printer(format("calls     : %i", calls))
246    printer(format("overhead  : %f", seconds(overhead/1000)))
247
248 -- table.save("luatex-profile.lua",names)
249end
250
251local function getdebug()
252    if sethook and getinfo then
253        return
254    end
255    if not debug then
256        local okay
257        okay, debug = pcall(require,"debug")
258    end
259    if type(debug) ~= "table" then
260        return
261    end
262    getinfo = debug.getinfo
263    sethook = debug.sethook
264    if type(getinfo) ~= "function" then
265        getinfo = nil
266    end
267    if type(sethook) ~= "function" then
268        sethook = nil
269    end
270end
271
272function debugger.savestats(filename,threshold)
273    local f = io.open(filename,'w')
274    if f then
275        debugger.showstats(function(str) f:write(str,"\n") end,threshold)
276        f:close()
277    end
278end
279
280function debugger.enable()
281    getdebug()
282    if sethook and getinfo and nesting == 0 then
283        running = true
284        if initialize then
285            initialize()
286        end
287        sethook(hook,"cr")
288        local function dummy() end
289        local t = ticks()
290        for i=1,dummycalls do
291            dummy()
292        end
293        overhead = ticks() - t
294    end
295    if nesting > 0 then
296        nesting = nesting + 1
297    end
298end
299
300function debugger.disable()
301    if nesting > 0 then
302        nesting = nesting - 1
303    end
304    if sethook and getinfo and nesting == 0 then
305        sethook()
306    end
307end
308
309-- debugger.enable()
310--
311-- print(math.sin(1*.5))
312-- print(math.sin(1*.5))
313-- print(math.sin(1*.5))
314-- print(math.sin(1*.5))
315-- print(math.sin(1*.5))
316--
317-- debugger.disable()
318--
319-- print("")
320-- debugger.showstats()
321-- print("")
322-- debugger.showstats(print,3)
323--
324-- from the lua book:
325
326local function showtraceback(rep) -- from lua site / adapted
327    getdebug()
328    if getinfo then
329        local level = 2 -- we don't want this function to be reported
330        local reporter = rep or report
331        while true do
332            local info = getinfo(level, "Sl")
333            if not info then
334                break
335            elseif info.what == "C" then
336                reporter("%2i : %s",level-1,"C function")
337            else
338                reporter("%2i : %s : %s",level-1,info.short_src,info.currentline)
339            end
340            level = level + 1
341        end
342    end
343end
344
345debugger.showtraceback = showtraceback
346-- debug.showtraceback = showtraceback
347
348-- showtraceback()
349