ludic/selfhost/backend/stdlib/emit_log.ludic
Orkuncakilkaya a8d54e9878 fence (25.1): every allocation goes through the fence - sites, frame judging, census, callers
Every allocation the compiler emits goes through @lp_malloc/@lp_calloc/@lp_realloc/@lp_free, and a
Ludic-level one first stores its site (function, file, line, kind) in @lp_site. Off, that is one load
and a predictable branch (30 M allocations: 0.87-0.91 s against 0.87-0.90 s on leaks2).

On (the default in a headless build, and windowed under R3D_DEV), tracking starts at the first frame
on its own and judging once R3D_ALLOC_WARM frames in a row kept nothing (600) or R3D_ALLOC_WARM_MAX
after (re)start; Mem.play()/Mem.rewarm() sends a load back to its warm-up. A judged frame that ends
holding more than it began with is reported by site with its callers (the unwinder, taken only once
judging) and fails the run with exit 86 (R3D_ALLOC_FENCE=off|count|warn|fail). R3D_ALLOC_CENSUS
writes the totals and top sites at exit. The build's defaults are --fence=, --fence-warm=,
--fence-census= or a fence line in the program's package.ludic; the environment overrides them.

The runtime is IR (emit_fence_ir.ludic, generated from a template); tracking is a side table in one
calloc'd region, so no block carries a header and pointers crossing to natives stay safe. Examples
alloc_fence, alloc_fence_leak and alloc_fence_auto with cases in ludic-dev test; reseeded.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-09-28 15:35:29 +03:00

102 lines
5 KiB
Text

# emit_log.ludic — the Log.* namespace: levelled, structured logging, the default
# way to answer "what is my game doing?" and "why did that break?" — better than
# scattered `print` calls. Lines go to standard error (so they never pollute a
# program's real stdout) with a level tag and optional structured key=value
# fields, gated by a runtime threshold so release builds can go quiet.
#
# Log.trace(msg, [k, v]...) most verbose level 0
# Log.debug(msg, [k, v]...) development detail level 1
# Log.info(msg, [k, v]...) normal operation level 2
# Log.warn(msg, [k, v]...) something looks wrong level 3
# Log.error(msg, [k, v]...) a failure level 4
# Log.set_level(n) show only level >= n (0 = all, the default)
# Log.level() the current threshold -> int
#
# Structured fields are optional trailing key/value pairs appended as ` key=value`;
# values may be strings, ints, or longs (numbers are formatted for you), so
# `Log.warn("missing texture", "path", p, "id", n)` is cheap to write and easy to
# grep. The level tag is chosen at compile time from the method name, so a
# disabled level costs only the threshold comparison at runtime.
#
# Determinism: logging writes to stderr and never touches the simulation, so it
# has no effect on gameplay or replays. This v1 ships the console (stderr) sink;
# file-with-rotation and in-engine overlay sinks are planned follow-ups.
function is_log_ns(meth: pointer) -> bool {
if (meth == "trace") or (meth == "debug") or (meth == "info") { return true }
if (meth == "warn") or (meth == "error") { return true }
if (meth == "set_level") or (meth == "level") { return true }
return false
}
# format any value as a string for a log field: a string passes through (fresh if it was), a long
# and an int are converted the same way the `string(...)` builtin does, into text freed once joined
function log_stringify(v: Val) -> Val {
if (llty(v.ty) == "ptr") {
let s = val(v.code, "string")
s.fresh = v.fresh
return s
}
if (llty(v.ty) == "i64") { g_uses_longstr = true; return fresh_val(emit_bind(`call ptr @lp_long_str(i64 {v.code})`), "string") }
g_uses_intstr = true
return fresh_val(emit_bind(`call ptr @lp_int_str(i32 {v.code})`), "string")
}
function emit_log_ns(meth: pointer, e: Node) -> Val {
g_uses_logrt = true
if (meth == "set_level") { # raise/lower the threshold
let n = emit_expr(e.kids[0])
emit(` store i32 {n.code}, ptr @L_log_level\n`)
return val("0", "void")
}
if (meth == "level") { # read the current threshold
return val(emit_bind("load i32, ptr @L_log_level"), "int")
}
# a level method: tag + numeric level chosen at compile time from the name.
var lvl = "2"; var pfx = "[INFO] "
if (meth == "trace") { lvl = "0"; pfx = "[TRACE] " }
if (meth == "debug") { lvl = "1"; pfx = "[DEBUG] " }
if (meth == "warn") { lvl = "3"; pfx = "[WARN] " }
if (meth == "error") { lvl = "4"; pfx = "[ERROR] " }
g_uses_str = true
# below the threshold nothing is built: the message and its fields are made, written and freed
# only for a line that is shown (every call once left its whole line behind, shown or not)
let cur = emit_bind("load i32, ptr @L_log_level")
let on = emit_bind(`icmp sge i32 {lvl}, {cur}`)
let lon = lbl("logon")
let lend = lbl("logend")
emit(` br i1 {on}, label %{lon}, label %{lend}\n`)
emit(`{lon}:\n`)
# line = "[LEVEL] " + msg, then " key=value" for each trailing pair
var line = val(emit_str_const(pfx), "string")
let msg = emit_expr(e.kids[0])
line = emit_str_op("+", line, log_stringify(msg))
var i = 1
while (i + 1) < len(e.kids) {
let k = emit_expr(e.kids[i])
let v = emit_expr(e.kids[i + 1])
line = emit_str_op("+", line, val(emit_str_const(" "), "string"))
line = emit_str_op("+", line, log_stringify(k))
line = emit_str_op("+", line, val(emit_str_const("="), "string"))
line = emit_str_op("+", line, log_stringify(v))
i += 2
}
emit(` call void @lp_log_emit(i32 {lvl}, ptr {line.code})\n`)
emit(` call void @lp_free(ptr {line.code})\n`)
emit(` br label %{lend}\n`)
emit(`{lend}:\n`)
return val("0", "void")
}
# emit_log_prelude — the log level register and the console sink, emitted once per
# program that uses Log.* (g_uses_logrt). @lp_log_emit checks the threshold and,
# if the message is at or above it, writes the line + newline to stderr.
function emit_log_prelude() -> void {
emith("@L_log_level = global i32 0\n")
emith("@.log_nl = private unnamed_addr constant [2 x i8] c\"\\0A\\00\"\n")
emith("define void @lp_log_emit(i32 %lvl, ptr %s) {\n")
emith("entry:\n %th = load i32, ptr @L_log_level\n %skip = icmp slt i32 %lvl, %th\n br i1 %skip, label %done, label %go\n")
emith(`go:\n %e = {stdstream_rhs(2)}\n %n = call i64 @strlen(ptr %s)\n`)
emith(" %w = call i64 @fwrite(ptr %s, i64 1, i64 %n, ptr %e)\n %w2 = call i64 @fwrite(ptr @.log_nl, i64 1, i64 1, ptr %e)\n br label %done\n")
emith("done:\n ret void\n}\n")
}