DramaticShapeVoxelMod archival mirror · read-only
lib/Perf.lua

Perf.lua

lib/Perf.lua11.9 KB10064435507585a1
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353
-- Voxel world mode: the instrumentation core.
--
-- Ships DARK. Every entry point is one boolean test away from doing
-- nothing, and the boolean is false unless a run explicitly asks for
-- measurement (DS_PERF in the environment, or a ds_perf.flag file in the
-- save directory for a device that has no environment to set). A mod that
-- measures itself in every player's session is a mod that costs every
-- player the measurement, so the default has to be off and the off path
-- has to be free.
--
-- What it measures, and why those three things:
--
--   * LABELS -- named spans (a bake, a mesh build, a shader compile),
--     accumulated as {n, total, max}. `max` is the one that matters: a
--     bake that costs 40ms ONCE is a visible hitch, and an average hides
--     it completely.
--   * FRAMES -- a ring of the last N whole-frame times, stamped once per
--     rendered frame. Frame time is the only number the player actually
--     experiences; every label total is a hypothesis about which frames.
--   * COUNTERS -- plain integers a caller bumps (sun-pass redraws, atlas
--     rebakes). Cheaper than a span when the question is "how often",
--     not "how long".
--
-- Spans are wall time, and on a GPU that means submission time, not
-- completion time -- the driver is free to finish the work later. So a
-- GPU-side saving shows up in the FRAME numbers rather than in the label
-- for the pass that caused it, and both are reported.

local Perf = {}

local clock = (love and love.timer and love.timer.getTime) or os.clock

-- Read through pcall: the loader's sandbox does not hand a mod `os`, and
-- instrumentation must never be the reason the mod fails to load. Same
-- shape as OverworldBattle's DS_BATTLE_DEBUG probe.
local function envFlag(name)
  local ok, value = pcall(function() return os.getenv(name) end)
  if not ok then return nil end
  if value == nil or value == "" or value == "0" then return nil end
  return value
end

local function flagFile()
  if not (love and love.filesystem and love.filesystem.getInfo) then
    return false
  end
  local ok, info = pcall(love.filesystem.getInfo, "ds_perf.flag")
  return ok and info ~= nil
end

Perf.enabled = (envFlag("DS_PERF") ~= nil) or flagFile()

Perf.labels = {}      -- label -> { n, total, max }
Perf.order = {}       -- insertion order, so a report reads chronologically
Perf.counters = {}    -- name -> integer
Perf.frames = {}      -- ring of frame times, seconds
Perf.frameCount = 0
Perf.RING = 4096

-- The segment a frame belongs to ("map:ROUTE_1:first"). A benchmark
-- names the phase it is driving; every frame and every label span
-- recorded while that name is set is attributed to it, which is what
-- turns "the walk was slow" into "the walk was slow ONLY on the frames
-- right after ROUTE_1 came into view".
Perf.segment = nil
Perf.segments = {}    -- name -> { frames = {}, labels = {}, order = {} }

local function segmentEntry()
  local name = Perf.segment
  if not name then return nil end
  local s = Perf.segments[name]
  if not s then
    s = { name = name, frames = {}, labels = {}, order = {} }
    Perf.segments[name] = s
    Perf.segments[#Perf.segments + 1] = s   -- array half preserves order
  end
  return s
end

function Perf.setSegment(name)
  Perf.segment = name
  if name then segmentEntry() end
end

-- ---------------------------------------------------------------- spans
--
-- Call shape at the measured site:
--
--   local t0 = Perf.now()
--   ... the work ...
--   Perf.add("TerrainAtlas.staticAtlas", t0)
--
-- When disabled, now() returns nil and add() returns on the nil -- two
-- function calls and a branch, no table touched, no string built. Sites
-- that would run thousands of times a frame (per draw call, per vertex)
-- are still too hot for that and are deliberately NOT instrumented; the
-- frame ring covers them in aggregate.

function Perf.now()
  if not Perf.enabled then return nil end
  return clock()
end

local function bump(store, order, label, dt)
  local s = store[label]
  if not s then
    s = { n = 0, total = 0, max = 0 }
    store[label] = s
    order[#order + 1] = label
  end
  s.n = s.n + 1
  s.total = s.total + dt
  if dt > s.max then s.max = dt end
end

function Perf.add(label, t0)
  if t0 == nil then return end
  local dt = clock() - t0
  bump(Perf.labels, Perf.order, label, dt)
  local seg = segmentEntry()
  if seg then bump(seg.labels, seg.order, label, dt) end
end

-- Wrap a function in a table, in place. Used by drivers to instrument
-- module internals they do not own; the mod's own code calls now()/add()
-- directly so the label is visible at the site.
function Perf.wrap(tbl, name, label)
  local orig = tbl and tbl[name]
  if not orig then return false end
  tbl[name] = function(...)
    if not Perf.enabled then return orig(...) end
    local t0 = clock()
    local a, b, c, d = orig(...)
    Perf.add(label or name, t0)
    return a, b, c, d
  end
  return true
end

-- ------------------------------------------------------------- counters

function Perf.count(name, by)
  if not Perf.enabled then return end
  Perf.counters[name] = (Perf.counters[name] or 0) + (by or 1)
end

-- --------------------------------------------------------------- frames
--
-- Called once per RENDERED frame (the endFrame seam), not once per
-- logic update: a scripted run can step the game many times per render,
-- and a frame the player never saw cannot have hitched for them.

local lastFrame = nil

function Perf.frame()
  if not Perf.enabled then return end
  local t = clock()
  if lastFrame then
    local dt = t - lastFrame
    local n = Perf.frameCount + 1
    Perf.frameCount = n
    Perf.frames[(n - 1) % Perf.RING + 1] = dt
    local seg = segmentEntry()
    if seg then seg.frames[#seg.frames + 1] = dt end
  end
  lastFrame = t
end

-- Discard the pending frame stamp: after a long blocking operation the
-- next frame delta would include it and libel the renderer.
function Perf.resync()
  lastFrame = Perf.enabled and clock() or nil
end

-- ------------------------------------------------------------ reporting

local function percentile(sorted, p)
  local n = #sorted
  if n == 0 then return 0 end
  local i = math.ceil(p * n)
  if i < 1 then i = 1 end
  if i > n then i = n end
  return sorted[i]
end

-- Frame statistics in MILLISECONDS. p95/p99 rather than the average
-- because smoothness is a tail property: a run that averages 9ms and
-- spikes to 60ms four times reads as stuttering, and its average reads
-- as fine.
function Perf.frameStats(list)
  local src = list or Perf.frames
  local sorted = {}
  for i = 1, #src do sorted[i] = src[i] * 1000 end
  table.sort(sorted)
  local n = #sorted
  local total = 0
  for i = 1, n do total = total + sorted[i] end
  local over16, over33 = 0, 0
  for i = 1, n do
    if sorted[i] > 16.7 then over16 = over16 + 1 end
    if sorted[i] > 33.3 then over33 = over33 + 1 end
  end
  return {
    n = n,
    avg = n > 0 and total / n or 0,
    p50 = percentile(sorted, 0.50),
    p95 = percentile(sorted, 0.95),
    p99 = percentile(sorted, 0.99),
    worst = n > 0 and sorted[n] or 0,
    over16 = over16,
    over33 = over33,
  }
end

function Perf.reset()
  Perf.labels, Perf.order = {}, {}
  Perf.counters = {}
  Perf.frames, Perf.frameCount = {}, 0
  Perf.segments = {}
  Perf.segment = nil
  lastFrame = nil
end

local function sortedLabels(store, order)
  local out = {}
  for _, lbl in ipairs(order) do out[#out + 1] = lbl end
  table.sort(out, function(a, b) return store[a].total > store[b].total end)
  return out
end

function Perf.printReport(title)
  print(("[perf] ==== %s ===="):format(tostring(title or "report")))
  local f = Perf.frameStats()
  print(("[perf] frames n=%d avg=%.2fms p50=%.2f p95=%.2f p99=%.2f worst=%.2f  >16.7ms=%d  >33.3ms=%d")
    :format(f.n, f.avg, f.p50, f.p95, f.p99, f.worst, f.over16, f.over33))
  for _, seg in ipairs(Perf.segments) do
    local s = Perf.frameStats(seg.frames)
    print(("[perf] seg %-28s n=%4d avg=%6.2f p95=%6.2f p99=%6.2f worst=%7.2f >16.7=%3d >33.3=%3d")
      :format(seg.name, s.n, s.avg, s.p95, s.p99, s.worst, s.over16, s.over33))
  end
  print("[perf] ---- labels (ms, sorted by total) ----")
  for _, lbl in ipairs(sortedLabels(Perf.labels, Perf.order)) do
    local s = Perf.labels[lbl]
    print(("[perf] %-46s n=%6d total=%9.1f max=%8.2f")
      :format(lbl, s.n, s.total * 1000, s.max * 1000))
  end
  local names = {}
  for k in pairs(Perf.counters) do names[#names + 1] = k end
  table.sort(names)
  if #names > 0 then print("[perf] ---- counters ----") end
  for _, k in ipairs(names) do
    print(("[perf] %-46s %d"):format(k, Perf.counters[k]))
  end
end

-- ------------------------------------------------------------------ json
--
-- Hand-rolled rather than pulled from the engine: the report has to be
-- readable by a diff tool between two runs, and that means stable key
-- ORDER, which a generic serializer does not promise.

local function q(s)
  return '"' .. tostring(s):gsub('[%c"\\]', function(c)
    if c == '"' then return '\\"' end
    if c == "\\" then return "\\\\" end
    return ("\\u%04x"):format(c:byte())
  end) .. '"'
end

local function num(x)
  return ("%.4f"):format(x)
end

local function statsJson(f)
  return ("{\"n\":%d,\"avg\":%s,\"p50\":%s,\"p95\":%s,\"p99\":%s,\"worst\":%s,\"over16\":%d,\"over33\":%d}")
    :format(f.n, num(f.avg), num(f.p50), num(f.p95), num(f.p99),
            num(f.worst), f.over16, f.over33)
end

local function labelsJson(store, order)
  local parts = {}
  for _, lbl in ipairs(sortedLabels(store, order)) do
    local s = store[lbl]
    parts[#parts + 1] = ("%s:{\"n\":%d,\"total\":%s,\"max\":%s}")
      :format(q(lbl), s.n, num(s.total * 1000), num(s.max * 1000))
  end
  return "{" .. table.concat(parts, ",") .. "}"
end

function Perf.toJson(meta)
  local parts = {}
  parts[#parts + 1] = "{"
  parts[#parts + 1] = "\"meta\":{"
  local m = {}
  for k, v in pairs(meta or {}) do
    m[#m + 1] = q(k) .. ":" .. (type(v) == "number" and num(v) or q(v))
  end
  table.sort(m)
  parts[#parts + 1] = table.concat(m, ",") .. "},"
  parts[#parts + 1] = "\"frames\":" .. statsJson(Perf.frameStats()) .. ","
  parts[#parts + 1] = "\"segments\":{"
  local segs = {}
  for _, seg in ipairs(Perf.segments) do
    segs[#segs + 1] = q(seg.name) .. ":{\"frames\":"
      .. statsJson(Perf.frameStats(seg.frames))
      .. ",\"labels\":" .. labelsJson(seg.labels, seg.order) .. "}"
  end
  parts[#parts + 1] = table.concat(segs, ",") .. "},"
  parts[#parts + 1] = "\"labels\":" .. labelsJson(Perf.labels, Perf.order) .. ","
  local cs = {}
  for k, v in pairs(Perf.counters) do cs[#cs + 1] = q(k) .. ":" .. v end
  table.sort(cs)
  parts[#parts + 1] = "\"counters\":{" .. table.concat(cs, ",") .. "}"
  parts[#parts + 1] = "}"
  return table.concat(parts, "")
end

-- Written through love.filesystem (the save directory) rather than io:
-- a driver run and an Android session both have one, and neither is
-- guaranteed a writable working directory.
function Perf.write(name, meta)
  local body = Perf.toJson(meta)
  if love and love.filesystem then
    pcall(love.filesystem.createDirectory, "ds_bench")
    local ok = pcall(love.filesystem.write, "ds_bench/" .. name .. ".json", body)
    if ok then
      print("[perf] wrote " .. tostring(love.filesystem.getSaveDirectory())
            .. "/ds_bench/" .. name .. ".json")
      return true
    end
  end
  print("[perf] JSON " .. name .. ": " .. body)
  return false
end

-- ----------------------------------------------------------- draw stats
--
-- love.graphics.getStats() resets per frame, so it is only meaningful
-- read at the END of a frame -- which is where Perf.frame() runs.

function Perf.drawStats()
  if not (love and love.graphics and love.graphics.getStats) then return end
  local s = love.graphics.getStats()
  Perf.count("stat.drawcalls", s.drawcalls or 0)
  Perf.count("stat.canvasswitches", s.canvasswitches or 0)
  Perf.count("stat.shaderswitches", s.shaderswitches or 0)
  Perf.count("stat.frames", 1)
  Perf.texturememory = s.texturememory
  Perf.canvases = s.canvases
  Perf.images = s.images
end

return Perf