From d01f43973c57dcd308c0d685088ab477db2fee12 Mon Sep 17 00:00:00 2001 From: Reuben Brooks Date: Tue, 21 Jul 2026 18:16:15 -0500 Subject: [PATCH] fix(fasl): replay per-form value echo on a warm load hit (#40) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `(load FILE)` prints each top-level form's evaluated value (klambda/load.kl shen.eval-and-print / shen.work-through) before returning `loaded`. On a warm FASL-cache hit boot.lua returned `loaded` straight out of fasl_replay without re-running the kernel `load`, so that echo was dropped: `(load ...)` stdout depended on cache state — a cross-port divergence (shen-rust/shen-go always echo) and an intra-port nondeterminism (cold != warm). Capture the echo faithfully instead of re-deriving it. During a miss, the per-form echo is the only pr to (stoutput) that fires while inside shen.load-help with rec.in_chunk false (the form's own (output ...) side effects fire with in_chunk true and already replay via the chunk). Record those bytes as a new "e" record in stream order, right after each form's "c" chunk, and re-pr them on replay. Interleaving with side-effect output is preserved for free, and going through the live `pr` keeps *hush* gating at replay time (a -q hit stays silent, like a -q cold load). The cosmetic "run time"/"typechecked in N inferences" banners are emitted by `load` OUTSIDE shen.load-help, so rec.echoing excludes them — they stay dropped by design (per-run timing noise breaks cross-port comparison). FASL_FORMAT bumped 3 -> 4 (old caches miss and recompile cleanly). Verified: warm == cold == shen-rust == shen-go for the probe (raw and tc paths); -q hit stays silent; kernel tests 134/134; port specs 489/489 (cli_spec grows a #40 regression that drives a private-dir miss -> hit). Co-Authored-By: Claude Opus 4.8 --- boot.lua | 63 ++++++++++++++++++++++++++++++++++++++++++++--- test/cli_spec.lua | 41 ++++++++++++++++++++++++++++++ 2 files changed, 100 insertions(+), 4 deletions(-) diff --git a/boot.lua b/boot.lua index b40ab55..ce7dd9b 100644 --- a/boot.lua +++ b/boot.lua @@ -473,12 +473,17 @@ end -- base (compiled bytecode hard-codes KDATA indices); a mismatch is a miss, -- never an error. -- --- Known fasl-style degrades: a replayed load does not echo per-form values/ --- types or the "run time"/"typechecked in N inferences" banners, and --- (destroy ...) at the REPL between loads is not in the key. +-- A replayed load reproduces the per-form value/type echo: the bytes +-- shen.eval-and-print / shen.work-through write to (stoutput) are captured as +-- "e" records during the miss and re-pr'd (in stream order, after each form's +-- chunk) on replay, so warm-hit stdout matches cold. Still dropped by design: +-- the cosmetic "run time"/"typechecked in N inferences" banners (they are +-- emitted by `load` OUTSIDE shen.load-help and would add per-run timing noise). +-- Known: (destroy ...) at the REPL between loads is not in the key. -- SHEN_FASL=off disables; SHEN_FASL_DIR overrides ~/.cache/shen-lua-fasl; -- SHEN_FASL_DEBUG=1 logs hits/misses to stderr. -local FASL_FORMAT = "SHENFASL3" -- 3: added "pc" (shen.compile-prolog) records +local FASL_FORMAT = "SHENFASL4" -- 4: added "e" (per-form value/type echo) + -- records; 3: "pc" (shen.compile-prolog) local FASL_STACK = {} local FASL_ROLL = 2166136261 local FASL_DEBUG = os.getenv("SHEN_FASL_DEBUG") == "1" @@ -525,6 +530,7 @@ end -- | D\n (declare ...) from assumetypes -- | M\n shen.record-macro (fn rebuilt by name) -- | P\n (put ... *property-vector*) +-- | E\n #bytes\n bytes per-form value/type echo (stoutput) -- | G\n }* (set ...) outside any chunk -- narity\n {ar SP name\n}* kbase\n nkdata\n entries gensym\n local function fasl_write(path, rec, arity0) @@ -560,6 +566,11 @@ local function fasl_write(path, rec, arity0) kdata_ser(r.x, parts) kdata_ser(r.pointer, parts) kdata_ser(r.y, parts) + elseif r.k == "e" then + -- raw echo bytes, length-prefixed (may contain newlines / non-ASCII); + -- mirrors the "C" chunk framing — no trailing separator, the next + -- record's kind letter starts immediately after the bytes. + parts[#parts+1] = "E\n" .. #r.bytes .. "\n" .. r.bytes else -- "g" parts[#parts+1] = "G\n" kdata_ser(r.name, parts) @@ -633,6 +644,11 @@ local function fasl_read(path) elseif k == "P" then local v = de_n(3); if not v then return nil end recs[i] = { k = "p", x = v[1], pointer = v[2], y = v[3] } + elseif k == "E" then + local len = tonumber(line() or "") + if not len or pos + len - 1 > #data then return nil end + recs[i] = { k = "e", bytes = data:sub(pos, pos + len - 1) } + pos = pos + len elseif k == "G" then local v = de_n(2); if not v then return nil end recs[i] = { k = "g", name = v[1], val = v[2] } @@ -689,6 +705,10 @@ local function fasl_replay(cached) P.F["shen.compile-prolog"](r.name, r.rules) elseif r.k == "p" then P.F["put"](r.x, r.pointer, r.y, P.GLOBALS["*property-vector*"]) + elseif r.k == "e" then + -- re-emit the per-form echo through the live `pr` so replay-time *hush* + -- still gates it (a -q hit stays silent, exactly as a -q cold load). + P.F["pr"](r.bytes, P.GLOBALS["*stoutput*"]) else -- "g" P.F["set"](r.name, r.val) end @@ -793,6 +813,41 @@ local function install_fasl() return { k = "g", name = name, val = val } end) + -- Per-form value/type echo (klambda/load.kl: shen.eval-and-print on the raw + -- path, shen.work-through on the tc path) is a pr to (stoutput) that happens + -- AFTER the form's eval-kl chunk has run and returned — i.e. with in_chunk + -- false, unlike the form's own (output ...) side-effects (in_chunk true, and + -- reproduced by re-running the chunk). Record those echo bytes as "e" records + -- in stream order so replay re-emits them right after each chunk. We scope + -- capture to the span of shen.load-help via rec.echoing, which excludes the + -- "run time"/"typechecked in N inferences" banners that `load` prints outside + -- load-help (those stay dropped by design). The bytes are captured even under + -- *hush* (the string is computed regardless; pr just doesn't write it), so a + -- miss recorded under -q still replays correctly to a non-hushed hit. + do + local orig_load_help = F["shen.load-help"] + F["shen.load-help"] = function(...) + local rec = P.FASL_REC + if not rec then return orig_load_help(...) end + local saved = rec.echoing + rec.echoing = true + local ok, res = pcall(orig_load_help, ...) + rec.echoing = saved + if not ok then error(res, 0) end + return res + end + local orig_pr = F["pr"] + F["pr"] = function(s, st) + local rec = P.FASL_REC + if rec and rec.echoing and not rec.in_chunk + and type(s) == "string" and st == P.GLOBALS["*stoutput*"] then + rec.n = rec.n + 1 + rec[rec.n] = { k = "e", bytes = s } + end + return orig_pr(s, st) + end + end + local orig_load = F["load"] F["load"] = function(fname) if type(fname) ~= "string" then return orig_load(fname) end diff --git a/test/cli_spec.lua b/test/cli_spec.lua index 3a27717..50af9dd 100644 --- a/test/cli_spec.lua +++ b/test/cli_spec.lua @@ -245,5 +245,46 @@ do "-q (*hush*) does NOT silence pr to *sterror* — diagnostics still write") end +-- --------------------------------------------------------------------------- +-- Warm FASL-cache hit reproduces the per-form value echo (pyrex41/shen-lua#40). +-- `(load FILE)` prints each top-level form's evaluated value (klambda/load.kl +-- shen.eval-and-print) before returning `loaded`. That echo used to be DROPPED +-- on a warm fasl hit — so `(load ...)` stdout depended on cache state, a +-- cross-port divergence (shen-rust/shen-go always echo) and an intra-port +-- nondeterminism. A hit now re-emits the recorded echo, so warm == cold. We use +-- a private SHEN_FASL_DIR so the first run is a guaranteed miss and the second a +-- guaranteed hit, independent of the developer's ~/.cache state. +-- --------------------------------------------------------------------------- +do + local fdir = os.tmpname(); os.remove(fdir) -- fresh, empty fasl dir + local fpath = os.tmpname() .. ".shen" + local h = io.open(fpath, "w") + h:write('"ECHO_PROBE"\n(+ 40 2)\n(define cli-echo-fn -> ok)\n'); h:close() + local expr = sh_quote('(load "' .. fpath .. '")') + -- `env` prefix (not a bare VAR=val) so it composes with the `timeout` wrapper. + local base = "env SHEN_FASL_DIR=" .. sh_quote(fdir) .. " " + + run(base .. SHEN .. " -e " .. expr) -- miss: populate + local warm, wcode = run(base .. "SHEN_FASL_DEBUG=1 " .. SHEN .. " -e " .. expr) + + check(wcode == 0, "#40: warm (load) hit exits 0") + check(warm:find("hit ", 1, true) ~= nil, + "#40: second run is a fasl HIT (replay path exercised)") + check(warm:find('"ECHO_PROBE"', 1, true) ~= nil, + "#40: warm fasl hit echoes the string form value") + check(warm:find("42", 1, true) ~= nil, + "#40: warm fasl hit echoes the numeric form value") + check(warm:find("(fn cli-echo-fn)", 1, true) ~= nil, + "#40: warm fasl hit echoes the define form value") + check(warm:find("loaded", 1, true) ~= nil, + "#40: warm fasl hit still returns loaded") + -- The cosmetic per-run "run time" banner must STAY dropped on a hit (only the + -- value echo comes back) — restoring it would re-inject per-run timing noise. + check(warm:find("run time:", 1, true) == nil, + "#40: warm fasl hit keeps the cosmetic run-time banner dropped") + + os.remove(fpath); os.execute("rm -rf " .. sh_quote(fdir)) +end + io.write(string.format("cli_spec: %d pass, %d fail\n", npass, nfail)) os.exit(nfail == 0 and 0 or 1)