feat(stdlib): add Log.* — levelled, structured logging (#15)
All checks were successful
docs / build-and-deploy (push) Successful in 2s
All checks were successful
docs / build-and-deploy (push) Successful in 2s
A Log.* namespace: five levels (trace/debug/info/warn/error), a runtime threshold, and structured key=value fields, so games get something better than scattered print calls and release builds can go quiet without touching call sites. - Log.trace/debug/info/warn/error(msg, [k, v]...) -> stderr, "[LEVEL] msg k=v" - Log.set_level(n) show only level >= n (0 = all default, 5 silences all) - Log.level() read the current threshold Fields accept strings, ints, and longs (numbers formatted automatically); the level tag is chosen at compile time so a filtered-out level costs only a comparison. Writes to stderr, never touching the simulation — no effect on determinism/replays. v1 is the console sink; rotating-file and in-engine overlay sinks are noted as follow-ups. - examples/library/logging.ludic: asserts the set_level/level threshold round-trip and that every level (with mixed-type fields) runs without faulting; the stderr gating itself was verified by hand (warn/error emit, lower levels suppressed). Wired into `x test` (now 53 passed). - docs: a new Log section + per-symbol pages; inventory and coverage pass. - seed regenerated; `x bootstrap-cfree` fixpoint holds. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
parent
a4f1494a04
commit
031b138f84
17 changed files with 11166 additions and 10404 deletions
11
docs/language/log/_section.md
Normal file
11
docs/language/log/_section.md
Normal file
|
|
@ -0,0 +1,11 @@
|
|||
---
|
||||
id: log
|
||||
title: Log
|
||||
order: 6
|
||||
---
|
||||
|
||||
Levelled, structured logging — the default way to answer "what is my game doing?" and "why did that break?", and a real step up from scattering <code>print</code> calls through your code. Each message carries a level, from <a href="log-trace"><code>trace</code></a> (most verbose) through <a href="log-debug"><code>debug</code></a>, <a href="log-info"><code>info</code></a>, and <a href="log-warn"><code>warn</code></a> to <a href="log-error"><code>error</code></a>, and a runtime threshold set with <a href="log-set_level"><code>Log.set_level</code></a> decides which ones actually appear — so a development build can be chatty and a release build quiet, without touching the call sites.
|
||||
|
||||
Messages go to standard error, kept separate from a program's real stdout, tagged with their level. Beyond the message you can pass **structured fields** as trailing key/value pairs — <code>Log.warn("missing texture", "path", p, "id", n)</code> prints <code>[WARN] missing texture path=... id=...</code> — cheap to write and easy to grep. Numeric values (int, long) are formatted for you; the level tag is chosen at compile time, so a filtered-out level costs only a threshold comparison at runtime.
|
||||
|
||||
Logging never touches the simulation — it writes to stderr and returns — so it has no effect on gameplay determinism or replays. This first version ships the console (stderr) sink; a rotating-file sink and an in-engine overlay sink are planned follow-ups.
|
||||
27
docs/language/log/log-debug.md
Normal file
27
docs/language/log/log-debug.md
Normal file
|
|
@ -0,0 +1,27 @@
|
|||
---
|
||||
id: log-debug
|
||||
name: Log.debug
|
||||
category: log
|
||||
kind: namespace-method
|
||||
tokens: Log.debug
|
||||
sig: Log.debug(msg, [key, value]...) -> void
|
||||
tip: Log at the debug level (1) — development detail.
|
||||
order: 2
|
||||
ns: Log
|
||||
member: debug
|
||||
---
|
||||
|
||||
Logs <code>msg</code> at the **debug** level (1) — development-time detail that is useful while building a feature but noise in a shipped game. It prints on stderr as <code>[DEBUG] msg</code> with any structured <code>key=value</code> fields, when the <a href="log-set_level"><code>Log.set_level</code></a> threshold is 1 or lower. Reach for it to trace state transitions, loaded assets, or the values feeding a calculation you are not yet sure of.
|
||||
|
||||
Parameters:
|
||||
- `msg` — the message string
|
||||
- `key, value...` — optional trailing pairs; values may be strings or numbers
|
||||
|
||||
```ludic
|
||||
program Debug {
|
||||
entry {
|
||||
Log.set_level(1)
|
||||
Log.debug("player state", "hp", 100, "phase", "combat")
|
||||
}
|
||||
}
|
||||
```
|
||||
26
docs/language/log/log-error.md
Normal file
26
docs/language/log/log-error.md
Normal file
|
|
@ -0,0 +1,26 @@
|
|||
---
|
||||
id: log-error
|
||||
name: Log.error
|
||||
category: log
|
||||
kind: namespace-method
|
||||
tokens: Log.error
|
||||
sig: Log.error(msg, [key, value]...) -> void
|
||||
tip: Log at the error level (4) — a failure.
|
||||
order: 5
|
||||
ns: Log
|
||||
member: error
|
||||
---
|
||||
|
||||
Logs <code>msg</code> at the **error** level (4), the highest — a real failure the game could not handle cleanly: a save that would not write, a required asset that could not load. It prints on stderr as <code>[ERROR] msg</code> with any structured <code>key=value</code> fields, and shows at every threshold except one set above 4. Error is the level you almost always want visible, including in release builds.
|
||||
|
||||
Parameters:
|
||||
- `msg` — the message string
|
||||
- `key, value...` — optional trailing pairs; values may be strings or numbers
|
||||
|
||||
```ludic
|
||||
program Error {
|
||||
entry {
|
||||
Log.error("save failed", "path", "slot1.sav", "code", 5)
|
||||
}
|
||||
}
|
||||
```
|
||||
26
docs/language/log/log-info.md
Normal file
26
docs/language/log/log-info.md
Normal file
|
|
@ -0,0 +1,26 @@
|
|||
---
|
||||
id: log-info
|
||||
name: Log.info
|
||||
category: log
|
||||
kind: namespace-method
|
||||
tokens: Log.info
|
||||
sig: Log.info(msg, [key, value]...) -> void
|
||||
tip: Log at the info level (2) — normal operation.
|
||||
order: 3
|
||||
ns: Log
|
||||
member: info
|
||||
---
|
||||
|
||||
Logs <code>msg</code> at the **info** level (2) — the normal-operation milestones you want to see in a running game: a level loaded, a match started, a save written. It prints on stderr as <code>[INFO] msg</code> with any structured <code>key=value</code> fields, when the <a href="log-set_level"><code>Log.set_level</code></a> threshold is 2 or lower. Info is a sensible default level for a development build.
|
||||
|
||||
Parameters:
|
||||
- `msg` — the message string
|
||||
- `key, value...` — optional trailing pairs; values may be strings or numbers
|
||||
|
||||
```ludic
|
||||
program Info {
|
||||
entry {
|
||||
Log.info("level loaded", "name", "cavern", "entities", 42)
|
||||
}
|
||||
}
|
||||
```
|
||||
24
docs/language/log/log-level.md
Normal file
24
docs/language/log/log-level.md
Normal file
|
|
@ -0,0 +1,24 @@
|
|||
---
|
||||
id: log-level
|
||||
name: Log.level
|
||||
category: log
|
||||
kind: namespace-method
|
||||
tokens: Log.level
|
||||
sig: Log.level() -> int
|
||||
tip: The current logging threshold.
|
||||
order: 7
|
||||
ns: Log
|
||||
member: level
|
||||
---
|
||||
|
||||
Returns the current logging threshold — the minimum level that <a href="log-set_level"><code>Log.set_level</code></a> last set (0 by default). Use it to branch on how verbose logging is: skip building an expensive debug string when it would be dropped anyway, or show an in-game indicator that verbose logging is on. The levels are <code>trace</code> 0 through <code>error</code> 4.
|
||||
|
||||
```ludic
|
||||
program Level {
|
||||
entry {
|
||||
print(Log.level()) # 0
|
||||
Log.set_level(2)
|
||||
print(Log.level()) # 2
|
||||
}
|
||||
}
|
||||
```
|
||||
27
docs/language/log/log-set_level.md
Normal file
27
docs/language/log/log-set_level.md
Normal file
|
|
@ -0,0 +1,27 @@
|
|||
---
|
||||
id: log-set_level
|
||||
name: Log.set_level
|
||||
category: log
|
||||
kind: namespace-method
|
||||
tokens: Log.set_level
|
||||
sig: Log.set_level(n) -> void
|
||||
tip: Show only messages at level n or above (0 = all).
|
||||
order: 6
|
||||
ns: Log
|
||||
member: set_level
|
||||
---
|
||||
|
||||
Sets the logging threshold: only messages whose level is <code>n</code> or higher are written; everything below is silently dropped. The levels are <code>trace</code> 0, <code>debug</code> 1, <code>info</code> 2, <code>warn</code> 3, <code>error</code> 4, so <code>set_level(3)</code> shows only warnings and errors, and the default of <code>0</code> shows everything. Set it once at startup — low in development, high (3, or 5 to silence all) for release — and every call site adjusts automatically. Read the current value back with <a href="log-level"><code>Log.level</code></a>.
|
||||
|
||||
Parameters:
|
||||
- `n` — the minimum level to show (0–4; use 5 to silence every level)
|
||||
|
||||
```ludic
|
||||
program Quiet {
|
||||
entry {
|
||||
Log.set_level(3) # warnings and errors only
|
||||
Log.info("startup") # dropped
|
||||
Log.warn("low memory") # shown
|
||||
}
|
||||
}
|
||||
```
|
||||
27
docs/language/log/log-trace.md
Normal file
27
docs/language/log/log-trace.md
Normal file
|
|
@ -0,0 +1,27 @@
|
|||
---
|
||||
id: log-trace
|
||||
name: Log.trace
|
||||
category: log
|
||||
kind: namespace-method
|
||||
tokens: Log.trace
|
||||
sig: Log.trace(msg, [key, value]...) -> void
|
||||
tip: Log at the trace level (0) — the most verbose.
|
||||
order: 1
|
||||
ns: Log
|
||||
member: trace
|
||||
---
|
||||
|
||||
Logs <code>msg</code> at the **trace** level (0), the most verbose — the fine-grained "I am here, this is the value" tracing you turn on only when hunting a specific problem. It appears on stderr as <code>[TRACE] msg</code>, followed by any structured <code>key=value</code> fields, but only when the threshold set by <a href="log-set_level"><code>Log.set_level</code></a> is 0. Because trace is usually filtered out, keep the calls wherever they help; a disabled level costs only a comparison.
|
||||
|
||||
Parameters:
|
||||
- `msg` — the message string
|
||||
- `key, value...` — optional trailing pairs; values may be strings or numbers
|
||||
|
||||
```ludic
|
||||
program Trace {
|
||||
entry {
|
||||
Log.set_level(0)
|
||||
Log.trace("spawned entity", "id", 7, "at", "cave")
|
||||
}
|
||||
}
|
||||
```
|
||||
26
docs/language/log/log-warn.md
Normal file
26
docs/language/log/log-warn.md
Normal file
|
|
@ -0,0 +1,26 @@
|
|||
---
|
||||
id: log-warn
|
||||
name: Log.warn
|
||||
category: log
|
||||
kind: namespace-method
|
||||
tokens: Log.warn
|
||||
sig: Log.warn(msg, [key, value]...) -> void
|
||||
tip: Log at the warn level (3) — something looks wrong.
|
||||
order: 4
|
||||
ns: Log
|
||||
member: warn
|
||||
---
|
||||
|
||||
Logs <code>msg</code> at the **warn** level (3) — something is wrong but the game recovered: a missing asset fell back to a placeholder, a value was clamped, a deprecated path was taken. It prints on stderr as <code>[WARN] msg</code> with any structured <code>key=value</code> fields, when the <a href="log-set_level"><code>Log.set_level</code></a> threshold is 3 or lower. Warnings are a good level to keep on in release builds so player bug reports capture them.
|
||||
|
||||
Parameters:
|
||||
- `msg` — the message string
|
||||
- `key, value...` — optional trailing pairs; values may be strings or numbers
|
||||
|
||||
```ludic
|
||||
program Warn {
|
||||
entry {
|
||||
Log.warn("missing texture, using placeholder", "path", "rock.png")
|
||||
}
|
||||
}
|
||||
```
|
||||
28
examples/library/logging.ludic
Normal file
28
examples/library/logging.ludic
Normal file
|
|
@ -0,0 +1,28 @@
|
|||
# logging.ludic — Log.* levels, the threshold gate, and structured fields. Log
|
||||
# lines go to stderr, which the test harness does not capture, so this program
|
||||
# asserts the stdout-observable contract: the threshold round-trips through
|
||||
# set_level/level, and every level method (with mixed string/number fields) runs
|
||||
# without faulting. The run raises the level above `error` first so the suite's
|
||||
# output stays clean; the actual stderr sink and its gating are demonstrated in
|
||||
# the docs and verified by hand. Running it prints: 0 5 2 1
|
||||
program Logging {
|
||||
entry {
|
||||
print(Log.level()) # 0 — everything shown by default
|
||||
|
||||
Log.set_level(5) # above error: silence the console for this run
|
||||
print(Log.level()) # 5
|
||||
|
||||
# every level builds its line (including numeric fields, which are formatted
|
||||
# for you) and is threshold-gated; none writes at level 5.
|
||||
Log.trace("entering frame", "n", 10)
|
||||
Log.debug("state", "hp", 100, "phase", "combat")
|
||||
Log.info("level loaded", "name", "cavern", "entities", 42)
|
||||
Log.warn("missing texture, using placeholder", "path", "rock.png")
|
||||
Log.error("save failed", "code", 5)
|
||||
|
||||
Log.set_level(2) # info and above
|
||||
print(Log.level()) # 2
|
||||
|
||||
print(1) # sentinel: reached the end without crashing
|
||||
}
|
||||
}
|
||||
|
|
@ -28,6 +28,7 @@ var g_uses_hashrt: bool = false # Hash.of/fnv1a/crc32 was emitted -> emit the b
|
|||
var g_uses_cryptort: bool = false # Crypto.* was emitted -> emit the SHA-256 / HMAC runtime
|
||||
var g_uses_uuidrt: bool = false # Uuid.* was emitted -> emit the UUID runtime (needs the crypto CSPRNG)
|
||||
var g_uses_noisert: bool = false # Noise.* was emitted -> emit the fixed-point noise runtime
|
||||
var g_uses_logrt: bool = false # Log.* was emitted -> emit the log level register + console sink
|
||||
var g_uses_datert: bool = false # Date.*/DateTime.* was emitted -> emit the civil<->epoch conversions
|
||||
var g_uses_longstr: bool = false # string(long) / interpolating a long was emitted -> emit fn_long_str
|
||||
|
||||
|
|
|
|||
|
|
@ -107,6 +107,7 @@ function emit_program() -> void {
|
|||
if g_uses_cryptort { emit_crypto_prelude() } # @fn_sha256_hex / @fn_hmac_sha256_hex + constant-time compare + CSPRNG
|
||||
if g_uses_uuidrt { emit_uuid_prelude() } # @fn_uuid_v4 / @fn_uuid_v7 / parse / equals (over the crypto CSPRNG)
|
||||
if g_uses_noisert { emit_noise_prelude() } # @fn_noise_value2/perlin2/simplex2/fbm2/cellular2 (Q16.16)
|
||||
if g_uses_logrt { emit_log_prelude() } # @L_log_level + @fn_log_emit (levelled stderr sink)
|
||||
if g_uses_datert { emit_datetime_prelude() } # @fn_days_from_civil / @fn_civil_from_days conversions
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -243,6 +243,10 @@ function emit_ns_call(ns: pointer, meth: pointer, e: Node) -> Val {
|
|||
if is_noise_ns(meth) { return emit_noise_ns(meth, e) }
|
||||
perr(`unknown builtin Noise.{meth}`)
|
||||
}
|
||||
if (ns == "Log") {
|
||||
if is_log_ns(meth) { return emit_log_ns(meth, e) }
|
||||
perr(`unknown builtin Log.{meth}`)
|
||||
}
|
||||
if (ns == "Vector") {
|
||||
if is_vector_ns(meth) { return emit_vector_ns(meth, e) }
|
||||
perr(`unknown builtin Vector.{meth}`)
|
||||
|
|
|
|||
87
selfhost/emit_log.ludic
Normal file
87
selfhost/emit_log.ludic
Normal file
|
|
@ -0,0 +1,87 @@
|
|||
# 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, a long
|
||||
# and an int are converted the same way the `string(...)` builtin does.
|
||||
function log_stringify(v: Val) -> pointer {
|
||||
if (llty(v.ty) == "ptr") { return v.code }
|
||||
if (llty(v.ty) == "i64") { g_uses_longstr = true; return emit_bind(`call ptr @fn_long_str(i64 {v.code})`) }
|
||||
g_uses_intstr = true
|
||||
return emit_bind(`call ptr @fn_int_str(i32 {v.code})`)
|
||||
}
|
||||
|
||||
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
|
||||
# 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, val(log_stringify(msg), "string"))
|
||||
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, val(log_stringify(k), "string"))
|
||||
line = emit_str_op("+", line, val(emit_str_const("="), "string"))
|
||||
line = emit_str_op("+", line, val(log_stringify(v), "string"))
|
||||
i = i + 2
|
||||
}
|
||||
emit(` call void @fn_log_emit(i32 {lvl}, ptr {line.code})\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). @fn_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 @fn_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 = load ptr, ptr @__stderrp\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")
|
||||
}
|
||||
21244
selfhost/ludicc.seed.ll
21244
selfhost/ludicc.seed.ll
File diff suppressed because it is too large
Load diff
|
|
@ -429,5 +429,14 @@
|
|||
"noise-cellular2",
|
||||
"noise-cellular2_id",
|
||||
"noise-unit"
|
||||
],
|
||||
"log": [
|
||||
"log-trace",
|
||||
"log-debug",
|
||||
"log-info",
|
||||
"log-warn",
|
||||
"log-error",
|
||||
"log-set_level",
|
||||
"log-level"
|
||||
]
|
||||
}
|
||||
|
|
|
|||
|
|
@ -31,6 +31,7 @@ function selfhost_frags() -> []pointer {
|
|||
push(f, "selfhost/emit_crypto.ludic")
|
||||
push(f, "selfhost/emit_uuid.ludic")
|
||||
push(f, "selfhost/emit_noise.ludic")
|
||||
push(f, "selfhost/emit_log.ludic")
|
||||
push(f, "selfhost/emit_list.ludic")
|
||||
push(f, "selfhost/emit_ease.ludic")
|
||||
push(f, "selfhost/emit_collide.ludic")
|
||||
|
|
|
|||
|
|
@ -102,6 +102,7 @@ function cmd_test() -> int {
|
|||
feat_case("library/crypto", "", "1 2 3 4 5 6 7 8 9", "crypto.ludic (Crypto SHA-256/HMAC/base64 KAT + CSPRNG shape)")
|
||||
feat_case("library/uuid", "", "1 2 3 4 5 6 7 8 9 10", "uuid.ludic (Uuid v4/v7 format, version/variant, parse/equals)")
|
||||
feat_case("library/noise", "", "1 2 3 4 5 6 7 8 9 10 11", "noise.ludic (Noise value/perlin/simplex/fbm/cellular determinism + range)")
|
||||
feat_case("library/logging", "", "0 5 2 1", "logging.ludic (Log levels, set_level/level threshold, structured fields)")
|
||||
|
||||
# issue #9: the Time/Date/Duration/Clock stdlib, driven from its own `entry`.
|
||||
net_case("lang/offline_rewards", "13 650 2026-08-30 0")
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue