util-deb.lua /size: 10 Kb    last modification: 2025-02-21 11:03
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                    dataset[#dataset+1] = { real, total, count, name, source, line < 0 and 0 or line }
190                end
191            end
192        end
193    end
194    sort(dataset,function(a,b)
195        if a[1] == b[1] then
196            if a[2] == b[2] then
197                if a[3] == b[3] then
198                    if a[4] == b[4] then
199                        if a[5] == b[5] then
200                            return a[6] < b[6]
201                        else
202                            return a[5] < b[5]
203                        end
204                    else
205                        return a[4] < b[4]
206                    end
207                else
208                    return b[3] < a[3]
209                end
210            else
211                return b[2] < a[2]
212            end
213        else
214            return b[1] < a[1]
215        end
216    end)
217    if length > 50 then
218        length = 50
219    end
220    local fmt = string.formatters["%4.9k s  %3.3k %%  %4.9k s  %3.3k %%  %8i #  %-" .. length .. "s  %4i  %s"]
221    for i=1,#dataset do
222        local data   = dataset[i]
223        local real   = data[1]
224        local total  = data[2]
225        local count  = data[3]
226        local name   = data[4]
227        local source = data[5]
228        local line   = data[6]
229        calls     = calls + count
230        functions = functions + 1
231        name = gsub(name,"%s+"," ")
232        if #name > length then
233            name = sub(name,1,length)
234        end
235        printer(fmt(seconds(total),100*total/totaltime,seconds(real),100*real/realtime,count,name,line,source))
236    end
237    printer("")
238    printer(format("functions : %i", functions))
239    printer(format("calls     : %i", calls))
240    printer(format("overhead  : %f", seconds(overhead/1000)))
241
242 -- table.save("luatex-profile.lua",names)
243end
244
245local function getdebug()
246    if sethook and getinfo then
247        return
248    end
249    if not debug then
250        local okay
251        okay, debug = pcall(require,"debug")
252    end
253    if type(debug) ~= "table" then
254        return
255    end
256    getinfo = debug.getinfo
257    sethook = debug.sethook
258    if type(getinfo) ~= "function" then
259        getinfo = nil
260    end
261    if type(sethook) ~= "function" then
262        sethook = nil
263    end
264end
265
266function debugger.savestats(filename,threshold)
267    local f = io.open(filename,'w')
268    if f then
269        debugger.showstats(function(str) f:write(str,"\n") end,threshold)
270        f:close()
271    end
272end
273
274function debugger.enable()
275    getdebug()
276    if sethook and getinfo and nesting == 0 then
277        running = true
278        if initialize then
279            initialize()
280        end
281        sethook(hook,"cr")
282        local function dummy() end
283        local t = ticks()
284        for i=1,dummycalls do
285            dummy()
286        end
287        overhead = ticks() - t
288    end
289    if nesting > 0 then
290        nesting = nesting + 1
291    end
292end
293
294function debugger.disable()
295    if nesting > 0 then
296        nesting = nesting - 1
297    end
298    if sethook and getinfo and nesting == 0 then
299        sethook()
300    end
301end
302
303-- debugger.enable()
304--
305-- print(math.sin(1*.5))
306-- print(math.sin(1*.5))
307-- print(math.sin(1*.5))
308-- print(math.sin(1*.5))
309-- print(math.sin(1*.5))
310--
311-- debugger.disable()
312--
313-- print("")
314-- debugger.showstats()
315-- print("")
316-- debugger.showstats(print,3)
317--
318-- from the lua book:
319
320local function showtraceback(rep) -- from lua site / adapted
321    getdebug()
322    if getinfo then
323        local level = 2 -- we don't want this function to be reported
324        local reporter = rep or report
325        while true do
326            local info = getinfo(level, "Sl")
327            if not info then
328                break
329            elseif info.what == "C" then
330                reporter("%2i : %s",level-1,"C function")
331            else
332                reporter("%2i : %s : %s",level-1,info.short_src,info.currentline)
333            end
334            level = level + 1
335        end
336    end
337end
338
339debugger.showtraceback = showtraceback
340-- debug.showtraceback = showtraceback
341
342-- showtraceback()
343
344-- For now also here because we want it in mtxrun (taken from lmt file):
345
346if luac then
347
348    local show, dump = luac.print, string.dump
349
350    function luac.inspect(v)
351        if type(v) == "function" then
352            local ok, str = xpcall(dump,function() end,v)
353            if ok then
354                v = str
355            end
356        end
357        if type(v) == "string" then
358            show(v,true)
359        else
360            print(v)
361        end
362    end
363
364end
365