writeonce/docs/plan/compiler/2026-08-14-logwatcher-executable.md
shoney.arickathil d30ad04bd9 fix: a stopping program stops (executable plan, Task 4)
- blocking stdlib calls that PARK (net.accept, socket read/write,
  time.sleep, a child wait) no longer restart the syscall when the
  stop flag is set on an interruption: a server sitting in accept
  ignored SIGTERM and only `kill -9` ended it
- a stop is NOT a trap -- builtin.h's WO_SYS_STOPPED carries no error
  record and no catch handler sees it (`try` must not swallow
  SIGTERM); the VM unwinds the whole stack through the same drop
  machinery an uncaught trap uses, so nothing leaks on the way out
- wo_vm_call gained a third outcome (1 = stopped); the CLI maps it to
  the status the program's own `return 0` would have given, and a
  regular-file read keeps its plain EINTR retry -- it does not park
- an ASSIGNMENT was not an ownership boundary: `api_key =
  j.mcp.apiKey` moved the field pointer into the local, so the local
  aliased the record and the first unwind freed the same string twice
  (SIGSEGV in class_free). `let` copied a Text place, assignment now
  does too -- the same double free was latent on the normal exit path,
  hidden by the order the compiler happens to emit drops in
- log-watcher-accept is 7 checks: the seventh is the stop itself, with
  the hard kill demoted to a fallback whose use is the failure
- measured under ASan: mcp parked, mcp after traffic, watch and run
  all exit rc 0 with zero leaks; SIGINT behaves as SIGTERM
- gates: oop-accept ALL CRITERIA MET, oop-e2e 71/0, woc-test 565/0,
  wovm-test green, log-watcher 7/0

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-14 23:58:21 +02:00

257 lines
16 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

# log-watcher Executable Implementation Plan
> **Status: 🔄 in progress** (story iteration 7) — the sample compiles and its
> three modes run; this plan is everything still between "it runs" and "you can
> leave it running". Board: [00-status.md](../../00-status.md)
> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking.
>
> **Style rule (user convention):** concept, reason, and required behavior in words only; the executor writes the code.
**Spec:** [`docs/superpowers/specs/2026-08-01-systems-track-design.md`](../../superpowers/specs/2026-08-01-systems-track-design.md) (Part 1 verdict table, normative), amended by [`docs/superpowers/specs/2026-08-10-logwatcher-gap-closure-design.md`](../../superpowers/specs/2026-08-10-logwatcher-gap-closure-design.md).
**Goal:** `docs/examples/log-watcher` is **executable** — not merely compilable.
Each of its three modes runs indefinitely without growing, stops when told to,
and ships as one self-contained binary. Nothing else is in scope: every task
below exists because a measurement on the sample demanded it, and anything the
sample does not exercise is deferred by name in "Out of scope".
**Architecture:** the compiler front (`compiler/src/`), the VM's ownership
tables (`owner.ml` ↔ `emit.ml`) and the runtime's process surface
(`runtime/src/main.c`, `sysio.c`). No new language features — the four
compiler-side tasks are missing *ownership knowledge*, not missing grammar.
**Tech Stack:** OCaml stdlib (compiler), C11 libc (runtime), the conformance
corpus as regression, `scripts/log-watcher-accept.sh` as acceptance.
## Where this plan starts (measured 2026-08-14)
- `woc --emit docs/examples/log-watcher` → **0 diagnostics**, 35 KB image.
- `woc build …` → a **106 KB standalone binary** that runs its three modes.
- `just log-watcher` → **6 checks, 0 failures** (compile, watch alert, cron
schedule, MCP initialize / tools/list / 401).
- All four MCP tools answer with `isError:false`.
- **Under ASan, both long-running modes leak**: `watch` 128 bytes in 2
allocations; `run` over 1 MB across 6 allocations in eight seconds — the
1 MiB one is a single `fs.read_all` result.
- The sample uses **zero `@gc`**: 35 classes, none with the gc flag, 0 `RC_INC`
/ 0 `RC_DEC`, 78 `DROP`s. Deterministic ownership is the whole memory story
here, which is why the leaks above are compiler bugs, not collector gaps.
## Global Constraints
- **The sample is the test.** No new corpus fixtures for this plan (user
direction, 2026-08-14); `just oop-e2e` must stay green as a regression, and
`just log-watcher` is the acceptance gate.
- **No new language surface.** A task that finds itself wanting one has found a
defect report against this plan, not a feature — stop and ask.
- Every task ends with the sample rebuilt and `just log-watcher` green, and
with the ASan measurement re-run so the number moves in writing.
- Commits are local only; never push.
## File Structure
```
compiler/src/owner.ml stdlib return types; temporary-value drops (Tasks 1, 2)
compiler/src/emit.ml the drop sites those tables imply (Tasks 1, 2)
runtime/src/main.c argv container lifetime; stop-signal exit (Tasks 3, 4)
runtime/src/sysio.c blocking calls observing the stop flag (Task 4)
docs/examples/log-watcher/ mcp.wo: close what accept opened (Task 5)
scripts/log-watcher-accept.sh the soak check (Task 6)
```
### Task 1 ✅: The owner pass must know what a callee returns — and what a `Text` is
**Concept & reason:** `owner.ml`'s `expr_ty`/`resolve_callee` have no stdlib
table — `types.ml` and `emit.ml` each got one, the ownership pass did not. So a
binding whose value comes from `fs.read_all`, `fs.list`, `net.read`,
`json.encode`, `time.iso` or `proc.run` falls back to the `Scalar "Int"`
default, is classified **Copy**, and never gets a scope-end drop. That is the
1 MiB leak measured in `run` mode: `parse_file`'s `let content = try
fs.read_all(path, FILE_CAP) catch (e) nil` holds a fresh Text nobody frees.
The fix is to read the same `Types.stdlib_members` table the other two passes
read, including through a `try`'s arms, so the classification matches reality.
- [x] Failing measurement first: `run` 1 051 040 B in 24 allocations, `watch`
128 B in 2, both over eight seconds with a clean SIGTERM exit.
- [x] Teach the ownership pass what a callee returns — three tables it never
read: the stdlib members, the builtins, and a class's `static` members.
- [x] **`Text` is an owned heap value, not a scalar.** `oclass_of` grouped it
with Int/Bool, so no Text local was ever dropped; that, not the stdlib
table alone, was the leak. Making it Owned forces the language to answer
what a Text does at an ownership boundary, and the answer is uniform: it
is **copied** — into a container (push/set/`m[i] = v`), into a field
(SETF), out of a function (`return`), into a binding (`let s = other`),
and into a loop cursor. The source keeps its own value; a freshly built
Text stays the caller's and is dropped at the site. `WO_B_TEXT_COPY` is
the one new builtin this needed.
- [x] Runtime bug found by the same measurement: `fs.read_all`/`net.read`
allocate their cap and then relabel the buffer with the short length, but
`wo_str_free` sizes a block by its `len` (obj.h keeps no size headers) —
so a 1 MiB buffer wearing a 30-byte length went onto a 32-byte free list
and never came back. They now copy out at the true size and release the
buffer at the size it was taken.
- [x] Two regressions caught by the corpus and fixed in the same pass: a `@gc`
value read out of a container is a plain borrow (not an rc-counted
alias), and `push`'s `@gc` escape is keyed on "`push` is not a
user-declared fn" rather than on "the callee did not resolve" — which
stopped being true the moment builtins resolved.
- [x] Re-measured: **`run` 1 051 040 B → 2 112 B (24 → 19 allocations)**,
**`watch` 128 B → 64 B (2 → 1)**. Everything left is Task 2's projected
temporary and Task 3's argv container, by stack. `just oop-e2e` 71/0,
`just woc-test` 565/0, `wovm` unit gates green, `just log-watcher` 6/0.
### Task 2 ✅: A temporary whose field is projected must still be dropped
**Concept & reason:** `for e in parse_dir(self.cron_dir).entries` compiles to
"call, keep the record in a register, read its field, iterate" — and the record
itself is never dropped, because the drop tables only track *bindings*, not the
anonymous receiver a projection borrows from. The elements stay alive (the loop
is correct), the shell leaks, once per rescan. The same shape appears wherever a
call result is projected without a `let`. The temporary must be owned by the
statement that created it and dropped at that statement's end, after every use
of the projection.
- [x] Failing measurement: `run` 2 112 B in 19 allocations; the MCP mix
21 312 B in 63; per handler, `tools/list` 2 144 B, `get_running_crons`
2 624 B, `list_logs` 5 184 B, `tail_log` 2 752 B — and 2 requests to 6
grew `list_logs` from 5 to 13 allocations, so this was growth, not
residue.
- [x] The projection was one shape of six. Every one of them is the same
sentence — *a value this expression built, that nothing else owns* — and
each needed its own site because the drop tables only track bindings:
a call result compared against `nil` (`if parse_expr(s) == nil` abandoned
a whole schedule record and its five containers per cron line); an
argument a callee only **borrows** (`rpc_result(id, "…")`, a 1 KB string
per MCP request); a container read's copy (`tokens[0]` copies by rule,
and `let u = tokens[0]` was copying twice and abandoning the first); a
loop's iterable; the projected record itself; and any of those left
behind by a `return` taken from inside the statement that built them
(`check_path` returns out of `for p in self.allowed_paths()`).
- [x] Two lowering bugs found while measuring, both silent: an argument
register cannot be dropped **after** a `CALL` (the callee's frame
overlaps it — the value read back is the callee's leftovers), so the
reap moved into the stash slot `call_window` already emits before the
call; and a statement-owned temporary cannot live in a temp register (a
loop reclaims every temp for its body and the end-of-statement `DROP`
then released a loop counter), so it is parked in a local slot.
- [x] Re-measured: **`run` 2 112 B → 64 B**, identical at 8 s and 20 s;
**MCP mix 21 312 B / 63 → 64 B / 1**; every handler flat from 2 to 6
requests (`list_logs` 5 184 → 64, `tail_log` 2 752 → 64,
`get_running_crons` 2 624 → 64, `tools/list` 2 144 → 64); `watch` 64 B.
The remaining 64 bytes are Task 3's argv container, on every path. Gates:
`just oop-e2e` 71/0, `just woc-test` 565/0, `just wovm-test` green,
`just log-watcher` 6/0. The image grew 35 893 → 46 137 bytes — the drops
themselves.
### Task 3 ✅: The runtime's argv container has no owner
**Concept & reason:** program mode builds the `multi Text` of arguments in
`runtime/src/main.c` and hands it to the entry method, which borrows it. Nobody
frees it — ASan reports it on every run (64 bytes in 1 allocation, and since Task 2 it is the only leak the
sample reports in any mode). It is
bounded, so it is not the reason a daemon grows, but it is the runtime leaking
its own allocation, and it pollutes every future ASan reading of the sample.
The runtime owns that container and must release it after the entry returns,
before the heap is torn down.
- [x] Drop the argument container once the entry method has returned — one
site covers both invocation shapes (`self_rc` only picks the argv
offset, it does not build a second container), and it runs after a trap
too: the container outlives the unwind. `multi_free` recurses, so the
argument strings go with it.
- [x] **All three modes report ZERO leaks under ASan**: `watch` and `run` over
eight seconds with a clean SIGTERM exit, and the full MCP mix (four
tools, twice each) with a clean exit. Gates: `just oop-accept` ALL
CRITERIA MET, `just oop-e2e` 71/0, `just wovm-test` green,
`just log-watcher` 6/0.
### Task 4 ✅: A stopping program must actually stop
**Concept & reason:** `env.stopping()` installs SIGTERM/SIGINT handlers that set
a flag, and `net.accept`/`net.read` retry on `EINTR` — so a server parked in
`accept` never observes the flag and TERM does nothing; only `kill -9` ends it.
`watch` and `run` stop correctly today only because they sleep between polls.
A service that cannot be stopped is not executable in any operational sense
(no clean restart, no deploy, no supervisor integration). The decision to make
and record: when a blocking stdlib call is interrupted **and** the stop flag is
set, the runtime stops the program rather than restarting the syscall — the
exit is the entry's normal one, with the same status a clean `return 0` gives.
The alternative (surface the interruption to the source) is rejected here: it
would put a trap in the middle of every accept loop the language will ever
write, and the shard-actor runtime (iteration 8) replaces these blocking calls
with an event loop anyway.
- [x] Failing measurement: `mcp` mode ignored SIGTERM and needed `kill -9`.
- [x] The calls that genuinely PARK — `net.accept`, a socket read/write,
`time.sleep`, a child wait — no longer restart the syscall when the stop
flag is set on an interruption. They hand back `WO_SYS_STOPPED`
(builtin.h), which is **not** a trap code: no error record, no catch
handler sees it (a `try` must not be able to swallow SIGTERM), and the
VM unwinds the whole stack through the same drop machinery an uncaught
trap uses, so every live value is still released. `wo_vm_call` gained a
third outcome (1 = stopped) and the CLI maps it to the status the
program's own `return 0` would have produced. A regular-file read keeps
its plain retry — it does not park.
- [x] **Found and fixed while measuring: an assignment was not an ownership
boundary.** `api_key = j.mcp.apiKey` MOVED the field pointer into the
local, so the local aliased the record; the first stop unwind dropped
the record and then the alias, freeing the same string twice (a SIGSEGV
in `class_free`). `let` copied a Text place, assignment did not — it
does now. The same double free was latent on the normal exit path,
hidden only by the drop ORDER the compiler happens to emit.
- [x] `just log-watcher` is **7 checks** now: the seventh is the stop itself —
SIGTERM sent to a server parked in `accept` with no traffic coming, with
the hard kill demoted to a fallback whose use is the failure.
- [x] Re-measured, all under ASan: `mcp` stopped while parked (rc 0, zero
leaks), `mcp` stopped after serving traffic (rc 0, zero leaks), `watch`
and `run` stopped mid-poll (rc 0, zero leaks), and SIGINT behaves as
SIGTERM. Gates: `just oop-accept` ALL CRITERIA MET, `oop-e2e` 71/0,
`woc-test` 565/0, `wovm-test` green, `just log-watcher` 7/0.
### Task 5: The MCP server must close what it accepts
**Concept & reason:** `Mcp.serve` accepts a connection per request and never
calls `net.close` — the builtin exists, the sample does not use it. Every
request costs a descriptor; a long-lived server dies at the process limit. This
is the sample's own bug, and fixing it is in scope precisely because the sample
is the acceptance workload. The connection is a value the loop owns for one
iteration; it must be closed on every exit path from that iteration, including
the malformed-request path that answers 400.
- [ ] Failing measurement: descriptor count for the server process across a few
hundred requests.
- [ ] Close the connection on every path out of the serve loop's body.
- [ ] Re-measure: the descriptor count is flat.
### Task 6: Soak — the acceptance a daemon actually has to pass
**Concept & reason:** every check today is a few seconds long, which is exactly
the window in which a leak is invisible. The claim this plan exists to support
is "you can leave it running", and nothing verifies it. Add a soak mode to the
acceptance script: run each of the three modes under load for a fixed duration,
sample RSS and descriptor count at the start and the end, and fail when either
grows beyond a stated tolerance. Keep it opt-in (an environment variable or a
flag) so the default `just log-watcher` stays fast for the ordinary loop.
- [ ] Soak the three modes with a stated duration, load pattern and tolerance;
report the measured deltas whether it passes or fails.
- [ ] Run the soak against an ASan build once and record the result in the
status board's known-gaps section.
- [ ] `just log-watcher` (fast path) stays green and stays under a minute.
## Out of scope — deferred by name
- **`?T` forced handling, `pub(read)` write enforcement, `using`, `#if`,
reject-row diagnostics** (plan 8 Tasks 6–8's remainder). They make the
language *stricter*; they do not make this program run. Plan 8 stays open for
them behind this plan.
- **Anything `@gc`**: iteration 7b (inferred GC + incremental mark-sweep),
`set`'s `@gc` retention gap, iteration 4's `gc/held-cycle` leak. Measured:
the sample declares no `@gc` class and emits no `RC_INC`/`RC_DEC` at all, so
none of it can affect this workload.
- **json's `Bool` renders as `0`/`1`** and fractional numbers truncate — both
documented format consequences; the MCP client the sample targets reads them
fine.
- **Iterations 8–12** (shard-actor runtime, database engine, `@table`/query,
HTTP layer, fibers, blue-green) — unchanged, and unblocked by this plan.