Merge pull request #4268 from myk002/myk_overlay_timers

[overlay] add perf timers

plugins/lua/overlay.lua

@@ -12,6 +12,39 @@ local GLOBAL_KEY = 'OVERLAY'
 
 local DEFAULT_X_POS, DEFAULT_Y_POS = -2, -2
 
+local timers = {}
+local timers_start_ms = dfhack.getTickCount()
+function reset_timers()
+    timers = {}
+    timers_start_ms = dfhack.getTickCount()
+end
+function print_timers()
+    local elapsed = dfhack.getTickCount() - timers_start_ms
+    local sum = 0
+    for _,timer in pairs(timers) do
+        sum = sum + timer
+    end
+    if elapsed <= 0 then elapsed = 1 end
+    if sum <= 0 then sum = 1 end
+    local sorted = {}
+    for name,timer in pairs(timers) do
+        table.insert(sorted, {name=name, ms=timer})
+    end
+    table.sort(sorted, function(a, b) return a.ms > b.ms end)
+    for _, elem in ipairs(sorted) do
+        print(('%45s %8d ms  %6.2f%% overlay  %6.2f%% overall'):format(
+            elem.name, elem.ms, (elem.ms * 100) / sum, (elem.ms * 100) / elapsed
+        ))
+    end
+    print()
+    print(('elapsed time: %10d ms (%dm %ds)'):format(
+        elapsed, elapsed // 60000, (elapsed % 60000) // 1000
+    ))
+    print(('widget time:  %10d ms (%.2f%% of elapsed time)'):format(
+        sum, (sum * 100) / elapsed
+    ))
+end
+
 -- ---------------- --
 -- state and config --
 -- ---------------- --
@@ -413,7 +446,9 @@ end
 local function detect_frame_change(widget, fn)
     local frame = widget.frame
     local w, h = frame.w, frame.h
+    local now_ms = dfhack.getTickCount()
     local ret = fn()
+    timers[widget.name] = (timers[widget.name] or 0) + (dfhack.getTickCount() - now_ms)
     if w ~= frame.w or h ~= frame.h then
         widget:updateLayout()
     end