Skip to content

fix(tune-out): resume a tune-out on record whose channel isn't registered at the start - #916

Open
tel-0s wants to merge 1 commit into
mainfrom
fix/tune-out-resume-late-channels
Open

tel-0s wants to merge 1 commit into
mainfrom
fix/tune-out-resume-late-channels

Conversation

@tel-0s

@tel-0s tel-0s commented Oct 30, 2026

Copy link
Copy Markdown
Contributor

Found by nissa-seru's house reviewing #844 (the second of the two defects main has too, in their comment there): resumeActiveEpochs() walked listActive(), which read only the channels registered when create() called it once. A channel its MCPL server registers later — as discord-mcpl does, from a task that waits on the policy exchange or a grace timer — kept a tune-out whose end time passed while the process was down on record with no dump and no end timer, its held rows undelivered; one whose end time was still ahead got no end timer.

listActive() now reads the registry's record (tuneOutsOnRecord), filled by the start's replay of the lifecycle log before any channel registers. A cancel needs nothing of the registration (it reads the tune-out's state and the held rows, names the channel through nameShown, records the end in the lifecycle log — as an end timer already does for a removed server's tune-out). enter()/enterAllExcept() and the start's pruning read the same list, so a later hold no longer moves the subconscious's window start past a tune-out whose channel isn't registered. The two lists an agent reads — check's channels and a refusal's "Connected channels tuned out now" — keep to registered channels through listConnected(), the old walk, as their docs say.

Tests: test/tune-out-resume-late-channels.test.ts (3, on the real ChannelRegistry over a JsStore, no channel registered at the start): an expired tune-out is cancelled at the start with each held message shown once and its end on record for a fresh registry; a future end time gets its timer at the start and ends at that time after the channel registers; the window start stays at it through the resume, a later enter and a later all-except hold. All three fail on main; switching any one of the four record readers back to listConnected() fails at least one. Four stand-in registries answer tuneOutsOnRecord. Tune-out files 254 pass / 0 fail; full suite 9499 tests, 9450 pass, 0 fail, 49 platform skips (macOS).

The first defect in that comment — the cancel recording the epoch's end before its dump — was already fixed on main by #909 (test/tune-out-cancel-order.test.ts has the scenario); the review had read 4a45766f, before it.

Written by an Opus agent under FableDendrite's direction; reviewed and pushed by FableDendrite.

🤖 Generated with Claude Code

…ered at the start

resumeActiveEpochs() walked listActive(), which read the tune-outs of the
channels registered then, and create() calls it once. A channel its MCPL
server registers only after the coordinator starts, as discord-mcpl does
from a task that waits on the policy exchange or a grace timer, was left
out: a tune-out of it whose end time passed while the process was down
stayed on record with no dump and no end timer, and one whose end time
was still ahead got no end timer, so it ended only when cancelled. Its
held rows keep their tuneOut stamp, so nothing delivered them.

listActive() now reads the registry's record (tuneOutsOnRecord), which
the start's replay of the lifecycle log fills before any channel
registers. A cancel needs nothing of the channel's registration: it reads
the tune-out's state and the held rows, shows the channel by nameShown,
which names an unregistered channel too, and records the end in the
lifecycle log, as an end timer already does for a tune-out whose server
was removed. So at the start a tune-out past its end time is cancelled,
its dump stored and its end recorded, whether or not its channel is
registered yet; one past its wake budget is cancelled too; and one still
running has its cadence and end timer armed. The subconscious's window
starts at it, and the start's pruning keeps its last look. enter() and
enterAllExcept() read the same list for the window's start, so a later
hold no longer moves the start past a tune-out whose channel isn't
registered, such as one whose server was removed.

The two lists an agent reads keep to the channels registered now, through
listConnected(), the old walk: check's channels, and a cancel refusal's
"Connected channels tuned out now", whose doc already says why (a
removed server's tune-out is in neither that list nor channelsNamed).

Four test files' stand-in registries answer tuneOutsOnRecord from the
state they already keep.

Tests, on macOS, Node 26.5.0, built, against the sibling chronicle and
context-manager trees at their feat/presentation heads:
test/tune-out-resume-late-channels.test.ts (new, 3 tests, on the real
ChannelRegistry over a JsStore, with no channel registered at the start):
a tune-out past its end time is cancelled at the start, its dump showing
each held message once and its end on record for a new registry; one
whose end time is ahead is in force a millisecond before it and ended at
it, after its channel registers, its dump stored; and the subconscious's
window starts at it at the start, at a later tune-out and at a later
all-except hold, and its last look is kept. Red-first on main 48f26ce:
all 3 fail (no dump; still in force at its end time; no anchor). Removals:
each of the four readers of the record, given listConnected() on its own,
fails at least one test: the start's walk fails all 3, enter()'s,
enterAllExcept()'s and the pruning's the third. The cancel refusal given
the record fails tune-out-messages' removed-server test; check() given it
fails none, as no test checks a tune-out of an unregistered channel
there. Not tested here: a tune-out of an unregistered channel past its
wake budget at the start, which the same walk cancels. The 23 tune-out
files (tune-out-*, all-except-*, admission-e2e, deferred-import-boot):
254 pass, 0 fail; on main, 251 pass in 22. The full suite, built and run
as npm test runs it: 9499 tests, 9450 pass, 0 fail, 49 skipped; on main
48f26ce, 9496, 9447 pass, 0 fail, 49 skipped, the difference being the
3 new tests.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@github-actions github-actions Bot left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Automated review

Recommendation: merge and fast-follow. 2 medium severity findings can be fixed after the merge.

Reviewed commit 9704133 with claude-opus-5-5, by reading the code. It did not run the code or look at the checks.

Does this change belong in the project?

It fits the project. This fits. It is a bug fix to the existing tune-out coordinator: tune-outs on record are now resumed at startup even when their channel registers later.

5 reasons with sources

It reads the registry's existing record API, stays inside the coordinator, and comes with the tests and changelog fragment the contributing guide asks for.

  • It fixes the existing tune-out feature and adds no new scope. The coordinator already resumes active epochs at startup. Before this change, resumeActiveEpochs() only looked at channels registered at that moment, so a tune-out whose channel registered later never got its end handled. The change keeps the same job and widens the list it reads. (src/tune-out/coordinator.ts)
  • It reuses a registry API that already exists instead of adding a second record of tune-outs. ChannelRegistry.tuneOutsOnRecord() already exists, and src/framework.ts already calls it. The coordinator now reads the registry's record of tune-outs instead of keeping its own, so the registry stays the owner of that state. (src/mcpl/channel-registry.ts)
  • What the agent sees stays limited to connected channels, as the existing docs say. check and the cancel refusal message now use listConnected(), which is the old walk over registered channels. That keeps the documented promise that this text speaks only of connected channels. (src/tune-out/coordinator.ts (notTunedOut doc comment))
  • It follows CONTRIBUTING's rules for behavior changes. It adds a changelog.d/*.fixed.md fragment and a new test file that the author says fails on main. The description reports test counts as numbers and declares the AI authorship. (CONTRIBUTING.md (What a PR should contain; Changelog))
  • The review's findings about removed servers and listPolicyEpochs are defects for the code reviewer, not a conflict with any project design document. None of the documents I was pointed to say how a removed server's tune-out should affect the subconscious's window. The changelog fragment states the new behavior openly, so a maintainer can see it and decide. (README.md / CONTRIBUTING.md)

Findings

1 finding of medium or high severity, see the inline comment:

1 finding about lines the diff does not show:

  • Medium severity. listPolicyEpochs still lists only registered channels' tune-outs, while the coordinator now treats every recorded one as in force. src/framework.ts:11504-11520
Details of this finding
  • Medium severity, src/framework.ts:11504-11520. listPolicyEpochs still lists only registered channels' tune-outs, while the coordinator now treats every recorded one as in force. listPolicyEpochs() describes itself as returning the "Policy epochs currently in force (tune-out holds)". It still walks channelRegistry.listChannelsRaw(), the same walk this PR replaced in the coordinator's listActive. After this change, a tune-out whose channel isn't registered yet, or whose server was removed, has its cadence and end timers armed at the start and holds the subconscious's window anchor, but listPolicyEpochs leaves it out. The operator view therefore reports no epoch while one is active and will fire its end, dump its backlog and wake the resident. This parallel path should read tuneOutsOnRecord() too, or the difference should be stated in its doc.
1 more finding, less severe
  • Low severity, test coverage, test/tune-out-resume-late-channels.test.ts:98-117. No test checks that the cadence promised in the changelog is armed for a tune-out whose channel isn't registered. The changelog fragment says a still-running tune-out whose channel isn't registered "has its end timer and cadence armed" at the start. The second test only checks the end timer: it ticks to expiresAtMs and asserts the cancel. It never makes a held message arrive after handleRegister and advances by cadenceSeconds, so it does not check that the resumed cadence wakes the subconscious. Nothing in the suite would catch a regression where resumeActiveEpochs skips startCadence for such channels. Add a case that records a held message after registration and asserts the subconscious is invoked at the next cadence tick.

For a deeper review by several readers and a judge, which takes longer, a maintainer can comment /review deep.

Comment on lines +547 to +553
/** Every tune-out on record, its channel registered now or not: a channel
* its server registers only after the start, or whose server was removed,
* still holds what its tune-out diverted, and the tune-out's end time
* still releases it, which a cancel does without the channel. */
private listActive(): Array<{ serverId: string; channelId: string; params: TuneOutParams }> {
return this.channelRegistry.tuneOutsOnRecord().map(({ serverId, channelId, params }) => ({ serverId, channelId, params }));
}

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Medium severity. A removed server's open-ended tune-out now pins the subconscious window, and the agent can neither see it nor cancel it.

listActive() now returns every tune-out in tuneOutsOnRecord(), including those whose server was removed and never comes back. resumeActiveEpochs (line 459), enter (line 678) and enterAllExcept (line 1030) all take the oldest startedAtSequence from this list and pass it to setSubconsciousAnchor. A tune-out with no expiresAtMs on a removed server never ends: check() and notTunedOut now read listConnected(), so the agent is never shown it, and cancel_tuneout finds channels through channelsNamed, which only covers registered channels (the comment at lines 2111-2114 says so). The subconscious's window start therefore stays at that tune-out's start across every restart and every later hold, so the window keeps growing, and nothing an agent can do resets it. Before this change such a tune-out stopped holding the anchor. Either cap or expire unreachable tune-outs, or give the agent or operator a way to see and end them.

@nissa-seru

Copy link
Copy Markdown
Contributor

Take a tune-out whose end time passes while the process is down, while a later tune-out is still in force. With this pull request merged into #844's head, the subconscious's turns after the restart show the messages the first tune-out's dump left out. At this pull request's head they don't. At main they don't either, where the server registers its channels before the start's resume. We ran one restart case through AgentFramework.create, with its real store and subconscious, at three heads, and with this pull request merged into #844's head.

The case. Tune-out A on channel a has a 120-second end and backlogCap: 1, and holds three messages. Then tune-out B on channel b starts, with no end. The framework stops and is created again over the same store, with Date.now moved two hours on, so A is past its end time and B is still in force. A stand-in model records every request, and the probe prints which messages each request after the restart carries.

What the subconscious's turns after the restart show. These are the turns that carry A's cancel notice. A's dump shows only its newest message, and all three of A's messages are in the store after the restart.

head channels registered A at the start the subconscious's window start A's two messages the dump left out
main 48f26ce56c before the start's resume cancelled moves to B's start not shown
main 48f26ce56c after create() returns left on record; no request after the restart stays at A's start no turn
this pull request, 9704133265 either way cancelled moves to B's start not shown
#844, c7011d5c7a before the start's resume cancelled stays at A's start shown
#844, c7011d5c7a after create() returns left on record; no request after the restart stays at A's start no turn
#844, c7011d5c7a, with this pull request merged either way cancelled stays at A's start shown

An unheld message stored before both tune-outs started is in the store and in none of the subconscious's requests, at every head.

This pull request merges into #844's head c7011d5c7a with no conflicts. With it merged, A is cancelled at the start whatever the registration's timing, and the window start stays at A's start. So the turns that carry A's cancel notice show both of the messages the dump left out.

The runs were on Linux with Node 24.22.2 and membrane 0.8.0. main and this pull request ran with chronicle 0.5.1 and context-manager 0.24.1. The runs on #844's head used anima-research/chronicle#62 at 932673ebd5 and anima-research/context-manager#350 at faf038a17b, packed with their versions set to 0.6.0 and 0.25.0.

The probe, test/zz-i1-anchor.probe.test.ts
// Probe, not part of any change: at a restart, a channel tune-out whose end
// time passed while the process was down is cancelled, and a later tune-out
// survives. Prints what the subconscious's turns after the restart are shown
// of the expired tune-out's held rows, and of unheld rows before and between
// the two tune-outs' starts. Run once with the channels registered as the
// server's connection initializes, and once with them registered after the
// framework has started.
import { test } from 'node:test';
import assert from 'node:assert/strict';
import { mkdtempSync, rmSync } from 'node:fs';
import { tmpdir } from 'node:os';
import { join } from 'node:path';
import { once } from 'node:events';
import { WebSocketServer, type WebSocket } from 'ws';
import type { AddressInfo } from 'node:net';
import { AgentFramework } from '../src/framework.js';
import { MockMembrane, MockYieldingStream, createMockResponse } from './helpers/mock-membrane.js';

const SUB_PROMPT = 'You are the Subconscious. Report briefly.';
const TS = '2026-09-30T00:00:00Z';
const AMBIENT = ['chat:ambient', 'chat:from-human'];
const ok = () => createMockResponse([{ type: 'text', text: 'ok' }]);
const channel = (id: string) => ({ id, type: 'discord', label: id, initiallyOpen: true, metadata: { channelType: 'guild_text' } });
const MARKS = ['PRE-ANCHOR', 'A-ONE', 'A-TWO', 'A-THREE', 'MID-ROW', 'B-ONE'];

function rig() {
  const wss = new WebSocketServer({ port: 0, host: '127.0.0.1' });
  let socket: WebSocket | undefined;
  let next = 1000;
  let registerOnInit: string[] = [];
  const replies = new Map<number, (v: unknown) => void>();
  wss.on('connection', (ws) => {
    socket = ws;
    ws.on('message', (bytes) => {
      const m = JSON.parse(String(bytes));
      if (!m.method) { replies.get(m.id)?.(m); replies.delete(m.id); return; }
      const reply = (result: unknown) => ws.send(JSON.stringify({ jsonrpc: '2.0', id: m.id, result }));
      if (m.method === 'initialize') {
        reply({ protocolVersion: '2024-11-05', capabilities: { tools: {}, experimental: { mcpl: {
          version: '0.5', pushEvents: true, inferenceRequest: true,
          channels: { incoming: true, register: true, lifecycle: true, publish: true },
          featureSets: { doc: { description: 'doc', uses: ['pushEvents'] } },
        } } }, serverInfo: { name: 'editor', version: '1' } });
      } else if (m.method === 'notifications/initialized') {
        if (registerOnInit.length > 0) {
          ws.send(JSON.stringify({ jsonrpc: '2.0', id: next++, method: 'channels/register', params: { channels: registerOnInit.map(channel) } }));
        }
      } else if (m.method === 'featureSets/update') reply({ accepted: true });
      else if (m.method === 'tools/list') reply({ tools: [] });
      else if (m.id !== undefined) reply({});
    });
  });
  const send = (method: string, params: unknown): Promise<unknown> => new Promise((resolve) => {
    const id = next++;
    replies.set(id, resolve);
    socket!.send(JSON.stringify({ jsonrpc: '2.0', id, method, params }));
  });
  return { wss, send, setRegisterOnInit: (ids: string[]) => { registerOnInit = ids; } };
}

async function eventually(predicate: () => boolean, what: string): Promise<void> {
  const deadline = performance.now() + 30_000;
  while (!predicate()) { assert(performance.now() < deadline, `${what} did not happen within 30 s`); await new Promise((r) => setTimeout(r, 10)); }
}

type Internals = {
  tuneOutCoordinator: { enter: (s: string, c: string, o: Record<string, number>, src: string) => { ok: boolean; params?: { epochId: string; startedAtSequence: number }; error?: string } };
  channelRegistry: { listChannelsRaw: () => unknown[]; getDesiredState: (s: string, c: string) => string | null; getTuneOutState: (s: string, c: string) => { params: { epochId: string; startedAtSequence: number; expiresAtMs?: number } } | null };
  subconsciousStrategy?: { getAnchor?: () => unknown } | null;
};

async function scenario(label: string, early: boolean): Promise<void> {
  const dir = mkdtempSync(join(tmpdir(), 'i1-probe-'));
  const { wss, send, setRegisterOnInit } = rig();
  await once(wss, 'listening');
  const url = `ws://127.0.0.1:${(wss.address() as AddressInfo).port}`;
  const membrane = new MockMembrane();
  (membrane as unknown as { streamYielding: unknown }).streamYielding = (request: unknown) => {
    membrane.calls.push(request as never);
    return new MockYieldingStream([ok()]);
  };
  const create = () => AgentFramework.create({
    storePath: join(dir, 'store'), membrane: membrane.asMembrane(),
    agents: [{ name: 'agent', model: 'test', systemPrompt: 'test' }], modules: [],
    subconscious: { enabled: true, systemPrompt: SUB_PROMPT },
    mcplServers: [{ id: 'editor', url, enabledFeatureSets: ['doc'] }],
  } as never);
  const incoming = (channelId: string, messageId: string, text: string) => send('channels/incoming', {
    messages: [{ channelId, messageId, timestamp: TS, author: { id: 'U1', name: 'antra' }, tags: AMBIENT, content: [{ type: 'text', text }] }],
  });
  const realNow = Date.now;
  let current: { stop: () => Promise<void> } | null = null;
  try {
    // Before the restart.
    let fw = await create();
    current = fw;
    let i = fw as unknown as Internals;
    await send('channels/register', { channels: ['a', 'b', 'c'].map(channel) });
    await eventually(() => ['a', 'b', 'c'].every((id) => i.channelRegistry.getDesiredState('editor', id) === 'open'), 'channels open');
    await incoming('c', 'c0', 'PRE-ANCHOR unheld row before both tune-outs');
    await fw.runUntilIdle();
    const a = i.tuneOutCoordinator.enter('editor', 'a', { cadenceSeconds: 3600, maxWakes: 50, backlogCap: 1, durationSeconds: 120 }, 'agent-tool');
    assert.ok(a.ok, `enter a: ${a.error ?? ''}`);
    for (const [id, t] of [['a1', 'A-ONE held'], ['a2', 'A-TWO held'], ['a3', 'A-THREE held']]) await incoming('a', id, t);
    await fw.runUntilIdle();
    await incoming('c', 'c1', 'MID-ROW unheld row between the two starts');
    await fw.runUntilIdle();
    const b = i.tuneOutCoordinator.enter('editor', 'b', { cadenceSeconds: 3600, maxWakes: 50, backlogCap: 10 }, 'agent-tool');
    assert.ok(b.ok, `enter b: ${b.error ?? ''}`);
    await incoming('b', 'b1', 'B-ONE held');
    await fw.runUntilIdle();
    const aState = i.channelRegistry.getTuneOutState('editor', 'a')!.params;
    const bState = i.channelRegistry.getTuneOutState('editor', 'b')!.params;
    console.log(`[probe ${label}] before restart: a starts at ${aState.startedAtSequence}, ends ${new Date(aState.expiresAtMs!).toISOString()}; b starts at ${bState.startedAtSequence}; subconscious anchor ${JSON.stringify(i.subconsciousStrategy?.getAnchor?.())}`);
    await fw.stop();
    current = null;

    // The restart, two hours later by Date.now.
    Date.now = () => realNow() + 2 * 3600_000;
    setRegisterOnInit(early ? ['a', 'b', 'c'] : []);
    const callsBefore = membrane.calls.length;
    current = null;
    fw = await create();
    current = fw;
    i = fw as unknown as Internals;
    const registeredAtStart = ['a', 'b'].map((id) => `${id}:${i.channelRegistry.getDesiredState('editor', id)}`).join(' ');
    const aAfterStart = i.channelRegistry.getTuneOutState('editor', 'a');
    console.log(`[probe ${label}] after create: desired states ${registeredAtStart}; a's tune-out ${aAfterStart ? 'still on record' : 'ended'}; subconscious anchor ${JSON.stringify(i.subconsciousStrategy?.getAnchor?.())}`);
    if (!early) {
      await send('channels/register', { channels: ['a', 'b', 'c'].map(channel) });
      await eventually(() => i.channelRegistry.listChannelsRaw().length >= 3, 'channels registered after the restart');
    }
    await fw.runUntilIdle();
    await new Promise((r) => setTimeout(r, 200));
    await fw.runUntilIdle();
    console.log(`[probe ${label}] after the turns: a's tune-out ${i.channelRegistry.getTuneOutState('editor', 'a') ? 'still on record' : 'ended'}; subconscious anchor ${JSON.stringify(i.subconsciousStrategy?.getAnchor?.())}`);
    const inStore = JSON.stringify(fw.getAgent('agent')!.getContextManager().getAllMessages());
    console.log(`[probe ${label}] in the store after the restart: ${MARKS.map((m) => `${m}:${inStore.includes(m) ? 'yes' : 'no'}`).join(' ')}`);
    const after = membrane.calls.slice(callsBefore).map((r) => JSON.stringify(r));
    after.forEach((s, n) => {
      const who = s.includes(SUB_PROMPT) ? 'subconscious' : 'resident';
      const report = /tune-out cancelled|tuned out .*cancel|cancelled \(/i.test(s);
      const marks = MARKS.map((m) => `${m}:${s.includes(m) ? 'yes' : 'no'}`).join(' ');
      console.log(`[probe ${label}] request ${n + 1} after the restart, ${who}${report ? ', carries a cancel notice' : ''}: ${marks}`);
    });
    if (after.length === 0) console.log(`[probe ${label}] no model request after the restart`);
  } finally {
    await current?.stop().catch(() => {});
    Date.now = realNow;
    for (const c of wss.clients) c.terminate();
    await new Promise<void>((r) => wss.close(() => r()));
    rmSync(dir, { recursive: true, force: true });
  }
}

test('I1 probe: channels registered as the connection initializes', { timeout: 120_000 }, async () => { await scenario('early', true); });
test('I1 probe: channels registered after the start', { timeout: 120_000 }, async () => { await scenario('late', false); });

— Fern-2426

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants