feat(perf): indbygget profiler — måler alle indgange (hooks, update, GUI), logger top-6 pr. minut ved > 2 ms

2026-09-26 11:19:35 +02:00
parent 0fca6e8a9a
commit 8a18187103
4 changed files with 169 additions and 0 deletions
@@ -0,0 +1,121 @@
+-- AD Profiler
+-- Måler Smart Pickups indgange (AutoDrive-hooks, update-løkken, GUI) i spillet: kald, samlet tid og det
+-- værste enkeltkald pr. minut, plus det værste frame i alt. Tager noget over REPORT_MIN_MS, skrives top-listen
+-- i log.txt ("ADSmartPickup: profil …"), så et hak kan føres tilbage til præcis hvilken del der gjorde det.
+-- Indpakningen sker på modul-tabellernes felter; hooksene slår funktionerne op ved hvert kald, så de måles.
+
+ADProfiler = {}
+
+ADProfiler.WINDOW_MS = 60000
+ADProfiler.REPORT_MIN_MS = 2
+ADProfiler.TOP = 6
+ADProfiler.stats = {}
+ADProfiler.frameMs = 0
+ADProfiler.worstFrameMs = 0
+ADProfiler.windowStart = nil
+ADProfiler.depth = 0
+ADProfiler.installed = false
+
+function ADProfiler.clock()
+    local ok, ms = pcall(function() return netGetTime() end)
+    if ok and type(ms) == "number" then return ms end
+    return nil
+end
+
+local function record(name, started, ...)
+    local finished = ADProfiler.clock()
+    ADProfiler.depth = ADProfiler.depth - 1
+    if started ~= nil and finished ~= nil then
+        local spent = finished - started
+        local stat = ADProfiler.stats[name]
+        if stat == nil then
+            stat = {calls = 0, total = 0, max = 0}
+            ADProfiler.stats[name] = stat
+        end
+        stat.calls = stat.calls + 1
+        stat.total = stat.total + spent
+        if spent > stat.max then stat.max = spent end
+        -- kun yderste måling tæller i frame-summen (indlejrede måles også hver for sig)
+        if ADProfiler.depth == 0 then ADProfiler.frameMs = ADProfiler.frameMs + spent end
+    end
+    return ...
+end
+
+-- Pak tbl[key] ind under navnet name (gør intet hvis funktionen ikke findes).
+function ADProfiler.wrap(tbl, key, name)
+    if type(tbl) ~= "table" or type(tbl[key]) ~= "function" then return end
+    local original = tbl[key]
+    tbl[key] = function(...)
+        ADProfiler.depth = ADProfiler.depth + 1
+        return record(name, ADProfiler.clock(), original(...))
+    end
+end
+
+-- Kaldes én gang pr. frame fra ADSmartPickup:update: afslutter frame-summen og rapporterer pr. minut.
+function ADProfiler.frame(now)
+    if ADProfiler.frameMs > ADProfiler.worstFrameMs then ADProfiler.worstFrameMs = ADProfiler.frameMs end
+    ADProfiler.frameMs = 0
+    -- (en fejl i en indpakket funktion springer record over; dybden nulstilles derfor hvert frame)
+    ADProfiler.depth = 0
+    ADProfiler.windowStart = ADProfiler.windowStart or now
+    if now - ADProfiler.windowStart < ADProfiler.WINDOW_MS then return end
+    ADProfiler.report()
+    ADProfiler.windowStart = now
+end
+
+function ADProfiler.report()
+    local rows = {}
+    for name, stat in pairs(ADProfiler.stats) do
+        table.insert(rows, {name = name, stat = stat})
+    end
+    table.sort(rows, function(a, b) return a.stat.max > b.stat.max end)
+    local worst = rows[1] ~= nil and rows[1].stat.max or 0
+    if worst >= ADProfiler.REPORT_MIN_MS or ADProfiler.worstFrameMs >= ADProfiler.REPORT_MIN_MS then
+        local parts = {}
+        for index = 1, math.min(ADProfiler.TOP, #rows) do
+            local stat = rows[index].stat
+            table.insert(parts, string.format("%s max %.1f ms (%d kald, i alt %.0f ms)", rows[index].name, stat.max, stat.calls, stat.total))
+        end
+        Logging.info("ADSmartPickup: profil sidste minut — værste frame %.1f ms: %s", ADProfiler.worstFrameMs, table.concat(parts, "; "))
+    end
+    ADProfiler.stats = {}
+    ADProfiler.worstFrameMs = 0
+end
+
+-- Indpak alle kendte indgange. Kaldes én gang efter at hooksene er installeret.
+function ADProfiler.install()
+    if ADProfiler.installed then return end
+    ADProfiler.installed = true
+    local targets = {
+        {ADUnloadWait, "beforeUpdate", "aflæsning/Wait (pr. vogn)"},
+        {ADUnloadWait, "adoptOrphans", "genoptag ventende"},
+        {ADUnloadWait, "releaseInactive", "slip standsede"},
+        {ADOutbound, "beforeLoadUpdate", "udkørsel pålæsning (pr. vogn)"},
+        {ADOutbound, "beforeUnloadUpdate", "udkørsel aflæsning (pr. vogn)"},
+        {ADOutbound, "beforeLoadFinished", "udkørsel runde"},
+        {ADOutbound, "choosePickup", "udkørsel turvalg"},
+        {ADOutbound, "holdSupplyVehicle", "forsyning hold"},
+        {ADOutbound, "releaseInactive", "udkørsel slip"},
+        {ADLoadSwap, "tryFromWait", "læs-bytte fra Wait"},
+        {ADSmartPickup, "shouldWaitForLoading", "vent ved pålæsning"},
+        {ADSmartPickup, "choosePickup", "forsyning kildevalg"},
+        {ADSmartPickup, "findSupplyPickup", "forsyning kildesøgning"},
+        {ADRunsController, "applyVehicleNames", "traktornavne"},
+        {ADFieldJobs, "tick", "markarbejde tick"},
+        {ADFields, "scanStep", "markscanning"},
+        {ADFieldWork, "follow", "markarbejde sæt"},
+        {ADFieldWork, "dispatch", "markarbejde udsendelse"},
+        {ADFieldWork, "getRigs", "markflåde"},
+        {ADBuildings, "list", "bygningsliste"},
+        {ADSources, "getFarmInventory", "gårdens lagre"},
+        {ADWaitPool, "hasRouteTo", "rutetjek"},
+        {ADWaitPool, "hasRouteBothWays", "rutetjek frem+tilbage"},
+    }
+    for _, target in ipairs(targets) do
+        ADProfiler.wrap(target[1], target[2], target[3])
+    end
+    if SmartPickupFrame ~= nil then
+        ADProfiler.wrap(SmartPickupFrame, "refreshLive", "menu opdatering")
+        ADProfiler.wrap(SmartPickupFrame, "rebuild", "menu genopbygning")
+    end
+end