test(memory): pin that ORDINARY_DEGRADATIONS decides the log LEVEL (P1 follow-up)

P1 registered two healthy modes in `ORDINARY_DEGRADATIONS` — `hybrid` (the wired
success path) and `no_vector_space` (a space with nothing comparable to score) —
and the commit message claimed that meant "a healthy wired recall does not log a
warning every turn". Nothing tested it. Measured on 1309afe:

    M-a  delete 'hybrid'            → # tests 268  # pass 268  # fail 0
    M-b  delete 'no_vector_space'   → # tests 268  # pass 268  # fail 0
    M-ab delete both                → # tests 268  # pass 268  # fail 0

while the behaviour really broke (real apply(), debugLog=false):

    mutated hybrid recall → lines=[['warn', '... degraded=hybrid ... inject=138ch']]
    released hybrid recall → lines=[]

A false fault alarm on the happiest path, every single turn, and the suite green.

Why the existing tests could not see it: A3d/D3b assert the LABEL
(`hits.degraded === 'hybrid'`). Removing a member from the Set does not change any
label — it changes only whether `logRecallTurn` treats that label as a fault. The
defect lived exactly in the gap between "the label is right" and "the level is
right", and `grep ORDINARY_DEGRADATIONS test/` was empty. A claim in a commit
message with nothing behind it is the same failure mode as a guard that cannot
fail.

What this commit adds (test/memory-log.test.js only — lib/ untouched)

  L10    one group, three outcomes at the SAME verbosity (debugLog: false):
         `hybrid`               → zero lines
         `no_vector_space`      → zero lines
         `embed_error`          → exactly one line, type 'warn'   ← the control
         Each case asserts its own PRECONDITION first (the run really was
         `hybrid` / `no_vector_space`, and something was really injected), so a
         silent log cannot be confused with a build that never reached the route.
         Without the third case, "silent" would also be satisfied by a build that
         logs nothing at all — which is the original bug the log channel exists
         for (L4).
  L10†   real mutation: 'hybrid' removed from the Set → L10.1 red
  L11†   real mutation: 'no_vector_space' removed → L10.2 red
         Both via `withMutatedIndex` (copy the package, rewrite ONE anchor,
         `count === 1` self-check, import fresh). The mutant runs the SAME
         `assertLevelContract` body the released build passes — a criterion copied
         for the mutant can drift, a shared one cannot. The mutation then asserts
         the throw is `ERR_ASSERTION` AND that the message starts with the specific
         sub-assertion name, so an import failure cannot make it green for the
         wrong reason.
  L11    measured behaviour, pinned so nobody "fixes" it later: a fused recall
         whose candidates were ALL refused by `minScore` still reports `hybrid`
         with zero hits, and is still silent. `no_vector_space` is returned at
         exactly one place (`recall.js`, `vectorScores.size === 0`) and means
         "there was nothing to score" — never "everything was filtered". Collapsing
         the two would hide a threshold set too high behind a "fresh space" story.

Two fixture pitfalls found while writing this, both recorded in the test because
each one silently disarmed its own case:

  · `commit` embeds when an embedder is mounted, so the `no_vector_space` case has
    to write its block BEFORE the embedder appears. The first attempt mounted the
    embedder first, the space filled up, and the label came back `hybrid` — the
    assertion then failed for its own precondition rather than for the subject.
  · `StableMem.recall()` forwards only `topK`/`signal`, so a `minScore` passed
    there never reaches the scorer and L11's precondition would have passed on an
    unchanged result. It drives `recallBlocksHybrid` directly instead.

Not asserted, deliberately: `'no_embedder'`, `'aborted'` and `'vector_ready_unused'`
are also in the Set, but their silence is already carried by L1/L5 (no embedder)
and W11e/W12 elsewhere. Adding them here would inflate the group without covering a
new decision.

旁证 (not acceptance): npm test 272/272, npm run check 12/12, npm pack --dry-run
10 files / 75.3 kB. docs/ and README.md untouched.
This commit is contained in:
2026-11-05 00:51:17 +08:00
parent 1309afec93
commit 09be4de0eb

View File

@ -20,6 +20,14 @@
* identical with the summary on and off.
* L7 nothing is ever written to stdout (headless prints the ANSWER there) and
* the console fallback goes to `console.warn`, not `console.log`.
* L10 `ORDINARY_DEGRADATIONS` actually gates the level: the two healthy modes
* (`hybrid`, `no_vector_space`) are SILENT with `debugLog` off, while a
* real fault (`embed_error`) is a single `warn`. L10†/L11† mutate the set to
* prove those two assertions bite.
* L11 a fused recall whose candidates are ALL refused by `minScore` still
* reports `hybrid` with zero hits, and is still silent. `no_vector_space`
* means "there was nothing to score", never "everything was filtered" —
* collapsing the two would hide a threshold set too high.
*
* @module dsh-memory/test/memory-log
*/
@ -35,6 +43,7 @@ import { createUserMessage } from '@deepseek-ai/dsh-llm'
import { SystemPrompt } from '@deepseek-ai/dsh-system-prompt'
import { ToolRuntime } from '@deepseek-ai/dsh-tools'
import { apply as applyMemory, StableMem } from '../lib/index.js'
import { recallBlocksHybrid, segmentRecallBudget } from '../lib/recall.js'
import { BlockStore } from '../lib/store.js'
/**
@ -47,7 +56,7 @@ import { BlockStore } from '../lib/store.js'
*
* @param {object} config plugin config
*/
async function makeMem(config = {}) {
async function makeMemWith(apply, config = {}) {
const dir = mkdtempSync(join(tmpdir(), 'mlog-'))
const ctx = new Context()
new SystemPrompt(ctx, {})
@ -57,7 +66,7 @@ async function makeMem(config = {}) {
levels: { default: 3 },
export: (message) => records.push(message),
})
const mem = applyMemory(ctx, { path: join(dir, 'm.db'), ...config })
const mem = apply(ctx, { path: join(dir, 'm.db'), ...config })
return {
ctx,
mem,
@ -81,6 +90,20 @@ async function makeMem(config = {}) {
}
}
/**
* The same app, built by the module under test.
*
* Parameterised by `apply` so the ORDINARY_DEGRADATIONS mutants below can run the
* IDENTICAL criterion body against a mutated `lib/index.js`. A criterion that is
* copied for the mutant can drift from the real one; a criterion that is shared
* cannot.
*
* @param {object} [config] plugin config
*/
async function makeMem(config = {}) {
return makeMemWith(applyMemory, config)
}
/** A one-message human batch. */
function ask(text) {
return [createUserMessage({ content: [{ type: 'text', text }], source: { kind: 'user' } })]
@ -489,3 +512,274 @@ test('L8b: foreign loggers are not reprinted under this plugin’s prefix', asyn
await done()
}
})
// ══════════════════════════════════════════════════════════════════════════════
// L10 · ORDINARY_DEGRADATIONS must actually DECIDE the level
// ══════════════════════════════════════════════════════════════════════════════
//
// P1 added two healthy modes to `lib/recall.js` (`hybrid`, `no_vector_space`) and
// registered both in `ORDINARY_DEGRADATIONS`. Nothing tested that registration:
// `grep ORDINARY_DEGRADATIONS test/` was empty, and every P1-era assertion checked
// the LABEL (`hits.degraded === 'hybrid'`), never the LOG LEVEL. Deleting `'hybrid'`
// from the set therefore kept all 268 tests green while a healthy wired recall
// started emitting `warn` on every turn — a false fault alarm on the happiest path.
//
// The three cases below are deliberately in ONE group so the contrast is visible:
// two healthy modes must be silent, one real fault must speak, all at the same
// verbosity (`debugLog: false`, the shipping default).
/**
* An embedder whose vectors put every block and the query on the same axis.
*
* Deterministic and transport-free: "a vector exists in this space" is the only
* fact these cases need, and a real provider would add neither coverage nor
* determinism.
*
* @param {string} fingerprint
*/
function fixedEmbedder(fingerprint) {
return {
async embedText() { return [1, 0, 0] },
info: () => ({ fingerprint, dimension: 3 }),
}
}
const L10_SPACE = 'fp-l10'
/**
* Seed one block that carries a vector in the active space.
*
* The explicit vector+fingerprint pair goes through the documented
* `commit({ vector, fingerprint })` path, so the write is a normal store write
* rather than a fixture shortcut: `recallBlocksHybrid` sees a real row.
*
* @param {{mem: object}} app
* @param {string} text
*/
async function commitVectored(app, text) {
await app.mem.commit({ text, vector: [1, 0, 0], fingerprint: L10_SPACE })
}
/** The criterion, shared by the real module and every mutant. */
async function assertLevelContract(build) {
// ── (1) `hybrid` is silent at the default verbosity ─────────────────────
//
// Preconditions asserted, not assumed: the space really holds a comparable
// vector, the hit really carries a vector contribution, and the label really is
// `hybrid`. Without them a silent log would be indistinguishable from a build
// that never reached the vector route at all.
const hybridApp = await build({ embedder: fixedEmbedder(L10_SPACE) })
let hybridText
let hybridHits
try {
await commitVectored(hybridApp, '值班室分机号 4324')
hybridText = await hybridApp.mem.contextForStep(ask('值班室分机号是多少'))
hybridHits = hybridApp.mem.lastRecall
const emitted = hybridApp.lines()
assert.equal(hybridHits?.mode, 'hybrid', `precondition: the wired route must be labelled hybrid; got ${JSON.stringify(hybridHits)}`)
assert.notEqual(hybridText, '', 'precondition: the block must actually be recalled')
assert.deepEqual(
emitted,
[],
'L10.1: a HEALTHY wired recall must log nothing with debugLog off. ' +
'A `warn` here is a false fault alarm on the happiest path, every turn. ' +
`got ${JSON.stringify(emitted)}`,
)
} finally {
await hybridApp.done()
}
// ── (2) `no_vector_space` is silent too ─────────────────────────────────
//
// A configured embedder whose space holds no usable vector. This is a DATA
// state (fresh space), not a provider fault, so it must not warn either.
//
// ★ The block must be written while NO embedder is mounted, otherwise `commit`
// embeds it and the space is no longer empty — a fixture that quietly fills the
// space it is supposed to leave bare would make this case assert nothing (it did,
// on the first attempt: the label came back `hybrid`).
const emptyApp = await build({})
try {
await emptyApp.mem.commit({ text: '值班室分机号 4324' })
emptyApp.mem.embedder = fixedEmbedder('fp-l10-empty')
await emptyApp.mem.contextForStep(ask('值班室分机号是多少'))
const mode = emptyApp.mem.lastRecall?.mode
assert.equal(mode, 'no_vector_space', `precondition: an empty space must report no_vector_space; got ${mode}`)
assert.deepEqual(
emptyApp.lines(),
[],
'L10.2: `no_vector_space` is a standing data state, not a fault — it must not warn. ' +
`got ${JSON.stringify(emptyApp.lines())}`,
)
} finally {
await emptyApp.done()
}
// ── (3) `embed_error` DOES speak, at `warn`, exactly once ───────────────
//
// The control. Without it, "silent" could be satisfied by a build that never
// logs at all — which is the bug the whole log channel exists to fix (L4).
const faultApp = await build({ embedder: failingEmbedder })
try {
await faultApp.mem.commit({ text: '值班室分机号 4324' })
await faultApp.mem.contextForStep(ask('值班室分机号是多少'))
const recalled = faultApp.lines().filter((line) => line.text.startsWith('recall '))
assert.equal(recalled.length, 1, `L10.3: a fault must produce exactly one recall line; got ${JSON.stringify(recalled)}`)
assert.equal(recalled[0].type, 'warn', `L10.3: a fault is a warn; got ${recalled[0].type}`)
assert.match(recalled[0].text, /degraded=embed_error/, 'and names the fault')
} finally {
await faultApp.done()
}
}
test('L10: healthy modes are silent and faults warn — the same verbosity, three outcomes', async () => {
await assertLevelContract(makeMem)
})
// ══════════════════════════════════════════════════════════════════════════════
// L11 · `minScore` filtering everything is NOT `no_vector_space`
// ══════════════════════════════════════════════════════════════════════════════
//
// Measured behaviour (pinned because "everything was filtered out" looks like a
// bug to a future reader, and the tempting fix — call it `no_vector_space` — would
// erase the distinction between "there was nothing to score" and "the threshold is
// too high"). `no_vector_space` is returned at exactly one place,
// `recall.js`'s `vectorScores.size === 0`; a fused run that produced candidates
// and then gated them all keeps the `hybrid` label with `hits: []`.
test('L11: a fused recall gated to zero hits by minScore still reports hybrid, and stays silent', async () => {
const { mem, lines, done } = await makeMem({ embedder: fixedEmbedder(L10_SPACE) })
try {
await commitVectored({ mem }, '值班室分机号 4324')
const question = '值班室分机号是多少'
// ★ `minScore` is applied PER PATH against the RAW VECTOR score (V5), not
// against the fused 0.7. The block's vector score is 1.0, so the threshold
// that removes it has to exceed 1.0.
//
// ★ Driven through `recallBlocksHybrid` rather than `mem.recall`: the
// service method forwards only `topK`/`signal`, so a threshold passed there
// would never reach the scorer and this precondition would silently pass on an
// unchanged result.
const raw = await recallBlocksHybrid(mem.store, fixedEmbedder(L10_SPACE), question, {
topK: 3,
minScore: 1.5,
})
assert.deepEqual(
[...raw].map((hit) => hit.text),
[],
`precondition: the threshold must remove every candidate; got ${JSON.stringify(
[...raw].map((hit) => hit.text),
)}`,
)
assert.equal(
raw.degraded,
'hybrid',
`a gated recall is NOT an empty space: the vector route did score candidates. Got ${raw.degraded}`,
)
assert.equal(raw.degradedError, undefined, 'and it carries no error')
// The log decision is the subject of L10, so drive the real method with the
// real gated result. Nothing here is a stub: `logRecallTurn` is what the
// plugin calls on every turn.
mem.logRecallTurn({
query: question,
messages: ask(question),
raw,
segmented: segmentRecallBudget(raw, { topK: 3 }),
injected: '',
})
assert.deepEqual(
lines(),
[],
`L11: a hybrid recall with zero surviving hits must still be silent with debugLog off; got ${JSON.stringify(lines())}`,
)
} finally {
await done()
}
})
// ══════════════════════════════════════════════════════════════════════════════
// L10† / L11† · the mutations that make the two silent assertions bite
// ══════════════════════════════════════════════════════════════════════════════
/**
* Copy the package, rewrite ONE anchor in `lib/index.js`, import it fresh.
*
* Same shape as L4† (and the mutation discipline note in docs/phase-b-criteria.md):
* the anchor must occur exactly once, or the test fails loudly rather than
* silently asserting against unmutated source.
*
* @param {string} anchor exact source text, expected once
* @param {string} replacement
* @param {(apply: Function) => Promise<void>} body receives the mutated `apply`
*/
async function withMutatedIndex(anchor, replacement, body) {
const { readFileSync, writeFileSync, mkdtempSync, rmSync, cpSync } = await import('node:fs')
const { tmpdir } = await import('node:os')
const { join } = await import('node:path')
const { fileURLToPath, pathToFileURL } = await import('node:url')
const libDir = fileURLToPath(new URL('../lib/', import.meta.url))
const pkgRoot = fileURLToPath(new URL('..', import.meta.url))
const dir = mkdtempSync(join(tmpdir(), 'mlog-l8-'))
try {
cpSync(libDir, join(dir, 'lib'), { recursive: true })
cpSync(join(pkgRoot, 'package.json'), join(dir, 'package.json'))
try {
cpSync(join(pkgRoot, 'node_modules'), join(dir, 'node_modules'), {
recursive: true,
dereference: false,
})
} catch {
// A poetry-free install fails loudly in the body below, which is correct.
}
const target = join(dir, 'lib', 'index.js')
const source = readFileSync(target, 'utf8')
assert.equal(
source.split(anchor).length - 1,
1,
`mutation anchor must occur exactly once — did the set move?\n${anchor}`,
)
writeFileSync(target, source.replace(anchor, replacement))
const mod = await import(pathToFileURL(target).href)
await body((ctx, config) => mod.apply(ctx, config))
} finally {
rmSync(dir, { recursive: true, force: true })
}
}
for (const [name, removed, bites] of [
['L10\u2020', "'hybrid'", 'L10.1'],
['L11\u2020', "'no_vector_space'", 'L10.2'],
]) {
test(`${name}: removing ${removed} from ORDINARY_DEGRADATIONS turns ${bites} red`, async (t) => {
const anchor = " 'ok', 'hybrid', 'no_embedder', 'aborted', 'no_vector_space', 'vector_ready_unused',"
const replacement = [
' // MUTATED: one healthy mode de-registered',
" 'ok', 'no_embedder', 'aborted',",
removed === "'hybrid'" ? " 'no_vector_space', 'vector_ready_unused'," : " 'hybrid', 'vector_ready_unused',",
].join('\n')
await withMutatedIndex(anchor, replacement, async (apply) => {
// The SAME criterion body the unmutated build passes. It must throw, and the
// throw must be the assertion's own — a different error (a bad import, a
// missing node_modules) would make this test green for the wrong reason.
await assert.rejects(
() => assertLevelContract((config) => makeMemWith(apply, config)),
(error) => {
assert.equal(error.code, 'ERR_ASSERTION', `only the criterion may bite; got ${error.code}: ${error.message}`)
assert.ok(
String(error.message).startsWith(bites),
`the biting assertion must be ${bites}; got: ${String(error.message).split('\n')[0]}`,
)
t.diagnostic(`${name} RAW RED >>> ${String(error.message).split('\n')[0]}`)
return true
},
`${name}: with ${removed} de-registered, ${bites} must go red`,
)
})
})
}