The plugin shipped with zero console.* and zero ctx.logger calls, so a
production recall failure left no trace: `degraded` is a return value the
caller sees once, and the injected text is only visible if the model quotes
it. Everything below is observability — no scoring, no DDL, no docs/README,
no new dependencies.
## The line
One summary per recall turn, covering the four fact groups asked for:
recall query=<n>ch hits=<n> topK=<n> zeroHit=yes|no
budget budget=<n> source=explicit|host|fallback kept=<n> singleHitOverBudget=yes|no
degrade degraded=<mode> skipped=<n> skippedDim=<n> err=<summary>
inject inject=<n>ch
`query` is LENGTH ONLY (code points, so CJK is not double-counted). The query
is the user's own message and a memory log is the last place it should be
copied; length beside `hits` is enough to tell "searched nothing" from
"searched the skill catalog".
`source` reads straight off segmentRecallBudget's own decision, and `kept` is
the post-slice count, so the line cannot disagree with what was injected.
`inject` is measured AFTER rendering, i.e. the exact string contextForStep
returns — not a re-derived estimate.
## Level policy (and why it is not always info)
· fault — degraded not in {ok,no_embedder,aborted,vector_ready_unused}
-> warn, emitted EVEN WITH debugLog OFF. A failed search is the per-turn
event where absence of evidence is not evidence of absence.
· zero injection -> debug (the commonest case on the shipping default must
cost nothing at normal verbosity, but still be one greppable line).
· otherwise -> info, only when debugLog is true.
`no_embedder` and `aborted` are deliberately NOT faults: the former is the
shipping configuration, the latter a deliberate stop. This is the same
judgement W11e already made for the model-facing notice — a constant warning
trains the reader to skip the channel.
## Logger source, and why ctx.logger alone was not enough
Source is ctx.logger('dsh-memory'); if the cordis build has no logger service
the code falls back to a console.warn/console.error shim (debug/info also go
to warn — stdout is never written, since `dsh --profile headless` prints the
ANSWER on stdout, so a line there is not noise but a corrupted answer).
★ Measured, and the reason this change installs its own sink: cordis ships
exactly ONE default exporter, an in-memory ring buffer
(cordis/lib/index.js:594-603), and no dsh bundle adds a terminal one. Calling
ctx.logger.info(...) in a real profile therefore writes to a buffer nobody
drains — the plugin would have looked instrumented while a headless run still
printed nothing. installStderrSink registers a scoped exporter on that same
service: it filters by message.name (the exporters map is process-wide, so
without the name check it would reprint every other plugin's warnings under
this prefix) and by severity, then renders with Logger.format and writes to
stderr. Disposal rides on ctx.effect inside LoggerService.exporter.
Two robustness details, both earned the hard way:
· the whole line travels as ONE `%s` argument — Logger.format expands
%s/%d/%o in the format string, so a provider error containing `%s` would
otherwise truncate the rest of the line (verified: "50% off %s" came out
"50% off undefined NaN");
· err is flattened to one line and cut at 80 chars — a log line must stay a
line;
· every logging path is wrapped, because a throwing logger would turn an
observability feature into a recall outage.
## Verification
test/memory-log.test.js (L1–L8b, 12 tests) pins: default is silent; the
summary carries all four fact groups in exactly ONE line; the query text
never appears; explicit/host/fallback source naming; a fault warns with
debugLog off; a zero-injection turn is debug not info; log-on equals log-off
for both the injected text and lastRecall; stdout is never written; the line
reaches stderr; foreign loggers are not reprinted. L4† is a real mutation —
it patches lib/index.js on a copy and asserts L4 goes red — because a guard
that cannot fail is not a guard (the W11d† lesson).
Self-tested in a real headless profile (dsh 0.2.1-rc.2, llmsproxy), same
question, only debugLog differing. Answer stayed "4471" on stdout in both:
debugLog=true dsh-memory: info: recall query=21ch hits=1 topK=3 zeroHit=no
| budget=838860 source=host kept=1 singleHitOverBudget=no
| degraded=no_embedder skipped=0 skippedDim=0 err=-
| inject=144ch
debugLog=false (no dsh-memory line; stderr carry only node's
ExperimentalWarning)
zero-hit turn dsh-memory: debug: recall ... zeroHit=yes ... inject=0ch
fault, OFF dsh-memory: warn: recall ... degraded=embed_error
err=fetch failed | inject=290ch <- speaks without opt-in
npm test: 237 tests, 237 pass, 0 fail (the W11d†ctx failure is gone — see
below). npm run check: 12/12 checkpoints.
## One test edit, forced by the caller change
W11d†ctx's mutation anchor was `const hits = await this.recall(query, { signal })`,
which no longer exists: contextForStep now rebinds as `const raw` because the
hits it renders come out of segmentRecallBudget (the preceding commit's work,
not this one). The anchor moves to the `raw` binding it would sit beside. The
mutation still flips W11d; only the anchor text changed.
jianf
783a7f87bb