diff --git a/changelog.d/resume-finished-turn.fixed.md b/changelog.d/resume-finished-turn.fixed.md new file mode 100644 index 000000000..2bb00840a --- /dev/null +++ b/changelog.d/resume-finished-turn.fixed.md @@ -0,0 +1 @@ +A turn that finished while the plugin was not listening (a plugin reload, or a crash right after DSH recorded the end) is no longer picked up as "restarted while you were working" and repeated: the durable Session log decides, and only a turn the restart really cut is resumed. diff --git a/changelog.d/resume-note-kept.fixed.md b/changelog.d/resume-note-kept.fixed.md new file mode 100644 index 000000000..2b4d32916 --- /dev/null +++ b/changelog.d/resume-note-kept.fixed.md @@ -0,0 +1 @@ +A restart's pickup no longer loses the work it was about to resume when a delivery fails or the app stops during the pickup: the inflight notes stay until each turn or queued message is handed over successfully ([#747](https://github.com/ThinkFlowLab/FlyBot/issues/747)). diff --git a/core/src/host/resume.js b/core/src/host/resume.js index 0293d8c5d..4fd6a9902 100644 --- a/core/src/host/resume.js +++ b/core/src/host/resume.js @@ -142,7 +142,7 @@ export function install(rt) { case 'turn/start': { const owner = rt.groupOwners.get(id) const botId = owner?.botId ?? rt.chatOwners.get(id) - update(id, () => ({ botId, ...(owner ? { roomId: owner.roomId } : {}), since: event.time ?? Date.now(), ...originNote(id) })) + update(id, () => ({ botId, ...(owner ? { roomId: owner.roomId } : {}), since: event.time ?? Date.now(), ...(event.data?.turn !== undefined ? { turn: event.data.turn } : {}), ...originNote(id) })) break } case 'user/message': { @@ -159,7 +159,9 @@ export function install(rt) { case 'turn/end': { // DSH stops every turn as it shuts down; that one is picked up at the next start. const reason = event.data?.reason - if (reason?.kind === 'aborted' && reason.reason?.kind === 'disposed') break + // DSH stopping every turn as it shuts down, or the format layer recording a restart as + // `interrupted`: that one is picked up at the next start, so its note stays. + if ((reason?.kind === 'aborted' && reason.reason?.kind === 'disposed') || reason?.kind === 'interrupted') break update(id, () => undefined) break } @@ -206,11 +208,50 @@ export function install(rt) { && current(item.args) !== undefined && taken?.has(item.args.exchangeId) !== true) if (fresh.length === 0) return const target = current(fresh[0].args) + // No Session to open yet: every item stays noted (seeded by resumeAll) for the next start. const agent = await rt.resolveAgent(target) const waiting = new Set([...(agent.inbox?.nextStep ?? []), ...(agent.inbox?.nextTurn ?? [])].map(message => message.source?.exchangeId)) - for (const { args } of fresh) { + const failed = [] + for (const item of fresh) { + const { args } = item if (waiting.has(args.exchangeId) || taken?.has(args.exchangeId) === true) continue - await rt.deliver({ ...args, sessionId: current(args), steer: false, resent: true }) + try { + await rt.deliver({ ...args, sessionId: current(args), steer: false, resent: true }) + } catch { + // The delivery wrapper dropped its note; put it back so the next start retries it. + failed.push(item) + } + } + if (failed.length > 0) { + queued = { ...queued, [sessionId]: [...(queued[sessionId] ?? []), ...failed].slice(-QUEUED_MAX) } + persist() + rt.warn('ds-bot: %d message(s) for %s were not sent again; kept for the next start', failed.length, sessionId) + } + } + + // Did the noted turn really end while nobody was listening (a plugin reload, or a crash after + // DSH appended its end)? The durable Session log is the truth: a turn that finished ends + // `completed` (or `blocked` / `max-tokens` / `forked`, or is aborted by the user / hook / parent); + // only `interrupted`, an abort caused by `disposed` and a missing end describe work a restart + // cut. A note from a build before this change has no `turn`, so it keeps the old behaviour. + async function endedNormally(sessionId, record) { + if (!Number.isInteger(record.turn) || typeof ctx.sessionController?.page !== 'function') return false + try { + const agent = await rt.resolveAgent(sessionId) + const seq = Number(agent?.session?.seq) + const page = await ctx.sessionController.page({ + address: { kind: 'session', sessionId }, + ...(Number.isFinite(seq) && seq > 0 ? { throughSeq: seq - 1 } : {}), + maxMessages: 200, + }, AbortSignal.timeout(5000)) + const end = (page?.records ?? []).map(entry => entry?.event) + .filter(event => event?.type === 'turn/end' && event.data?.turn === record.turn).at(-1) + const reason = end?.data?.reason + if (reason === undefined) return false + if (reason.kind === 'aborted') return ['user', 'parent', 'hook'].includes(reason.reason?.kind) + return ['completed', 'blocked', 'max-tokens', 'forked'].includes(reason.kind) + } catch { + return false } } @@ -219,26 +260,40 @@ export function install(rt) { if (rt.readOnly() !== undefined) return const { turns: noted, queued: dropped } = interrupted interrupted = { turns: {}, queued: {} } - // Taken up now, so another restart does not pick them up twice. - persist() + // Keep everything still owed in the live notes until its pickup succeeds: clearing the file + // first meant one failed delivery (or a crash during the pickup) lost the note for good. + turns = { ...noted } + queued = { ...dropped } // Agents and inboxes are read before anything wakes their Sessions. const cut = [] for (const [sessionId, record] of Object.entries(noted)) { const first = firstTurn.get(sessionId) - if (first === 'turn/end') continue - // Still running: noted again, as if it had started here. - if (first === undefined && (await rt.resolveAgent(sessionId).catch(() => undefined))?.status === 'running') update(sessionId, () => record) - else cut.push([sessionId, record]) + // `turn/end` is the noted turn ending here; `turn/start` means another turn began, so the + // noted one must have ended too (a turn cannot start until the previous one ends). + if (first === 'turn/end' || first === 'turn/start') { update(sessionId, () => undefined); continue } + // Still running: the note stays, as if it had started here. + if (first === undefined && (await rt.resolveAgent(sessionId).catch(() => undefined))?.status === 'running') continue + // Finished while this plugin was not listening: do not repeat work that is already done. + if (await endedNormally(sessionId, record)) { update(sessionId, () => undefined); continue } + cut.push([sessionId, record]) } firstTurn = undefined for (const [sessionId, list] of Object.entries(dropped)) { - if (!Array.isArray(list)) continue + if (!Array.isArray(list)) { delete queued[sessionId]; continue } await resendQueued(sessionId, list).catch(error => rt.warn('ds-bot: sending again what %s was sent failed: %s', sessionId, error)) } taken = undefined for (const [sessionId, record] of cut) { - await resumeTurn(sessionId, record).catch(error => rt.warn('ds-bot: picking up the turn of %s failed: %s', sessionId, error)) + // Dropped just before the pickup so a resumed turn writes its own note; put back when the + // pickup failed before any new turn was noted, so the next start tries again. + update(sessionId, () => undefined) + try { await resumeTurn(sessionId, record) } + catch (error) { + if (turns[sessionId] === undefined) update(sessionId, () => record) + rt.warn('ds-bot: picking up the turn of %s failed: %s', sessionId, error) + } } + persist() } ctx.effect(() => { diff --git a/core/test/follow-through.test.js b/core/test/follow-through.test.js index 8704795ef..c276a9ecb 100644 --- a/core/test/follow-through.test.js +++ b/core/test/follow-through.test.js @@ -27,9 +27,13 @@ const seed = () => ({ // One DS Bot host on `home`; a second start on the same home is a restart. // Hosts by home: a home is removed only after its hosts stopped and their writes landed. const started = new Map() +// The durable Session log per home (what DSH keeps across a plugin reload or a restart). +const durable = new Map() async function start(home) { const ctx = fakeContext() + const log = durable.get(home) ?? [] + durable.set(home, log) const agents = new Map() const agentOf = (sessionId) => { if (!agents.has(sessionId)) { @@ -43,7 +47,13 @@ async function start(home) { Object.assign(ctx, { llm: { listProviders: () => [], listModels: async () => [], resolveModelInfo: async () => ({}) }, workspaceRegistry: { get: () => undefined, resolveByPath: async () => undefined, create: async path => ({ id: 'w1', path }), archiveSession: async () => {} }, - sessionController: { create: async () => ({ sessionId: 's1' }), resolveAgent: async sessionId => ({ agent: agentOf(sessionId) }), selectModel: async () => {} }, + sessionController: { + create: async () => ({ sessionId: 's1' }), + resolveAgent: async sessionId => ({ agent: agentOf(sessionId) }), + selectModel: async () => {}, + // What the durable log holds for a Session (newest page; the test keeps all of it). + page: async ({ address } = {}) => ({ records: log.filter(entry => entry.id === address?.sessionId).map(entry => ({ event: entry.event })), hasMore: false }), + }, sessionTitle: { rename: async () => {} }, sessions: { flush: async () => {} }, }) @@ -53,15 +63,19 @@ async function start(home) { apply(ctx, { home }) let seq = 0 const emit = (id, type, data) => { + const event = { type, seq: ++seq, data } + log.push({ id, event }) for (const listener of ctx.listeners.get('session/event') ?? []) { - if (listener.length >= 2) listener({ id }, { type, seq: ++seq, data }) + if (listener.length >= 2) listener({ id }, event) } } + // Durable only: an event DSH wrote while no FlyBot host was listening. + const record = (id, type, data) => { log.push({ id, event: { type, seq: ++seq, data } }) } const tool = (name, args, sessionId, exec = {}) => ctx.registeredTools.get(name).execute(args, { agent: { id: sessionId }, ...exec }) const askApproval = sessionId => ctx.listeners.get('approval/request')[0]({ agent: { session: { id: sessionId } }, toolName: 'pwsh', reason: 'escalate sandbox' }, () => 'from-dsh') const call = async (endpoint, payload) => (await route.fetch(new Request('http://localhost/api/bot', { method: 'POST', body: JSON.stringify({ endpoint, payload }) }))).json() await tool('list_bots', {}, 'a') - const host = { ctx, agentOf, emit, tool, call, askApproval, stop: () => ctx.dispose() } + const host = { ctx, agentOf, emit, record, tool, call, askApproval, stop: () => ctx.dispose() } started.set(home, [...(started.get(home) ?? []), host]) return host } @@ -72,6 +86,7 @@ const freshHome = (t) => { t.after(async () => { await Promise.all((started.get(home) ?? []).map(host => host.stop())) started.delete(home) + durable.delete(home) rmSync(home, { recursive: true, force: true, maxRetries: 5, retryDelay: 20 }) }) return home @@ -195,6 +210,63 @@ test('when only DS Bot restarts, a turn still running or finished meanwhile is n assert.deepEqual([third.agentOf('b').calls[0].source.exchangeId, third.agentOf('a').calls.length], ['x1', 0]) }) +test('a turn that finished while the plugin was not listening is not picked up', async (t) => { + t.mock.timers.enable({ apis: ['setTimeout'] }) + const home = freshHome(t) + const first = await start(home) + run(first, 'a', 1, { content: [{ type: 'text', text: 'hello' }], source: { kind: 'user' } }) + await settle(() => inflight(home).a !== undefined) + // The turn ends while no FlyBot host is listening (a plugin reload, or a crash after DSH + // appended the end). Only the durable log knows; the note stays in inflight.json. + first.record('a', 'turn/end', { turn: 1, reason: { kind: 'completed' } }) + await first.stop() + const second = await start(home) + t.mock.timers.tick(3000) + await new Promise(resolve => setImmediate(resolve)) + assert.equal(second.agentOf('a').calls.length, 0, 'the finished turn is not repeated') +}) + +test('a turn the restart truly cut (interrupted in the durable log) is still picked up', async (t) => { + t.mock.timers.enable({ apis: ['setTimeout'] }) + const home = freshHome(t) + const first = await start(home) + run(first, 'a', 1, { content: [{ type: 'text', text: 'hello' }], source: { kind: 'user' } }) + await settle(() => inflight(home).a !== undefined) + first.record('a', 'turn/end', { turn: 1, reason: { kind: 'interrupted' } }) + await first.stop() + const second = await start(home) + t.mock.timers.tick(3000) + await settle(() => second.agentOf('a').calls.length === 1) + assert.match(text(second.agentOf('a').calls[0]), /restarted while you were working/) +}) + +test('a pickup that fails keeps its note for the next start', async (t) => { + t.mock.timers.enable({ apis: ['setTimeout'] }) + const home = freshHome(t) + const first = await start(home) + run(first, 'a', 1, { content: [{ type: 'text', text: 'hello' }], source: { kind: 'user' } }) + await settle(() => inflight(home).a !== undefined) + await first.stop() + + // The second start cannot open the Session: the note must survive, not be cleared first. + const second = await start(home) + const resolve = second.ctx.sessionController.resolveAgent + second.ctx.sessionController.resolveAgent = async id => { + if (id === 'a') throw new Error('the Session is not ready yet') + return resolve(id) + } + t.mock.timers.tick(3000) + await settle(() => inflight(home).a !== undefined) + assert.ok(inflight(home).a, 'the failed pickup is still noted') + await second.stop() + + // The third start picks it up. + const third = await start(home) + t.mock.timers.tick(3000) + await settle(() => third.agentOf('a').calls.length === 1) + assert.match(text(third.agentOf('a').calls[0]), /restarted while you were working/) +}) + test('a finished turn leaves nothing to pick up', async (t) => { t.mock.timers.enable({ apis: ['setTimeout'] }) const home = freshHome(t) diff --git a/docs/subsystems/core-host.md b/docs/subsystems/core-host.md index 8cc815493..0268566d0 100644 --- a/docs/subsystems/core-host.md +++ b/docs/subsystems/core-host.md @@ -223,6 +223,7 @@ Work a member hands a Bot with `message_bot` from its group Session runs in a hi - A friend's Bot @-mentioned in a group never has its reply delivered back into that group (it lands in the friend's Bot's own chat), so the host posts one receipt line into the room per mention (`src/host/hooks.js` `mentionReceipt`, source role `mention`) and the client renders it as a muted event line (`src/client/cells.js`) (#80, #81). The role stays outside the room's round trigger (`groups.js` `opens`) and outside `RELAY_ROLES`, so the receipt opens no round and folds no turns. When that friend's Bot is already a current participant of the room, `sendUserMentions` skips the 1:1 `bot.send` entirely (#143): the human line in the room is the delivery, and Chief's grant is not consulted. A friend's line Bot Social attests they typed themselves (#227) arrives as `remoteChats.deliver({ human: true, ownerName })`: the message source carries `typedBy`, `turns.js` `claimTrigger` records the turn in `state.remoteTypedTurns[sessionId][turn]` (capped at 400 per Session, dropped with the part), `channel.js` publishes it as `roster.remoteTypedTurns` (narrowed per owner in `authz.js`), and the client draws that turn's reply as the person (`typedBy` in `src/client/text.js`, `PersonMessage` in `cells.js`). The flag is never derived from text. A failed 1:1 remote-chat send (`remote-chat.js` `forward` / `notSentLine`) is one short English line with a next step, never a raw `Bot Social send_as_member: …` preview. A local Bot's answer to a friend's Bot (`turns.js` `answer` → `flybotReplyRemote`, `role: 'reply'`, `via: 'auto-reply'`) that the send chain refuses is logged with its reason (#272): a `deny` resolves, it does not throw. - `deliver()` (`src/host/delivery.js`) copies a cleaned, plugin-attested `remote.typedBy` onto the message `source.remote` for a friend's line to a local Bot; the client uses it to draw the person (#233 follow-up). - A friend's line in a Bot's own chat (#420): `deliver()` (`noteFriendLine`) stamps the receiving Bot with `friendLineAt` (published in the roster, so the save moves the revision) and keeps the senders seen per Bot in `state.remoteContacts[botId][handle]` (host only, capped at 200, dropped with the Bot). A sender's first line carries `source.remote.firstContact`. Group lines, and re-deliveries (`deferred`, `resumed`, `retried`, `resent`), stamp nothing. Covered by `core/test/flybot.test.js`. +- **Pickup after a restart** (`resume.js`): every running Bot turn and every delivered-but-not-taken message is noted in `inflight.json`. At the next start a noted turn is picked up once only if a restart really cut it: the durable Session log's `turn/end` for that turn is `interrupted` (or an abort caused by `disposed`, or there is no end). A turn that finished while this plugin was not listening — `completed`, `blocked`, `max-tokens`, `forked`, or aborted by the user / hook / parent — is not repeated; a `turn/start` seen after the start means the noted turn ended too. Notes from a build before the record carried `turn` keep the old behaviour. A pickup is confirmed before its note is dropped: the notes read at start are seeded into the live `turns`/`queued` (so the file keeps everything still owed), a turn's note is removed just before its pickup and put back if the pickup fails before a new turn notes itself, and a queued message whose resend fails is kept for the next start; a crash or a failed delivery during the pickup no longer loses the work. Covered by `core/test/follow-through.test.js`. - A repeated Bot-to-Bot line becomes one turn (#641): `deliver()` keys the last 60 s of Bot-to-Bot text by sender + recipient Session + the text with its whitespace collapsed (`DEDUPE_MS`, `duplicateDelivery`), drops a repeat before it is recorded as an exchange or handed to the Session, and journals the drop as `delivery: dedupe -> ` in the host warning log. The key includes the Session, so the same line to another Session (a group copy, another Bot) is its own delivery; `deferred` / `resumed` / `retried` / `resent` carry on a message the Session already has and are never judged, and a friend's line, the user's own message and a group round are not Bot-to-Bot. Routing (parent and direct children) and the existing unread-queue refusal are unchanged, and the map is process-local and capped at 500 entries. Covered by `core/test/repeated-delivery.test.js`. - **A part moves before it is committed** (`parts.js` `moveOn`): the handoff package is written to the fresh Session first, then the Bot's `sessionId` / `room.sessions` and the new segment are saved (a failed save restores the old state and archives the fresh Session), and the move is marked done only after the stopped turn's input and the old inbox messages are forwarded. A failure at any point leaves the old part current and hands that input on there; a switch that never starts (no place, another switch, a read-only host) lets the step continue instead of rejecting its messages, which DSH has already taken out of the inbox. Covered by `core/test/work-dir.test.js`. diff --git a/patches/ds-bot/0001-core-fixes.patch b/patches/ds-bot/0001-core-fixes.patch index 6652cbbd5..77be8ea6c 100644 --- a/patches/ds-bot/0001-core-fixes.patch +++ b/patches/ds-bot/0001-core-fixes.patch @@ -3260,7 +3260,7 @@ diff --git a/src/host/resume.js b/src/host/resume.js const owner = rt.groupOwners.get(id) const botId = owner?.botId ?? rt.chatOwners.get(id) - update(id, () => ({ botId, ...(owner ? { roomId: owner.roomId } : {}), since: event.time ?? Date.now() })) -+ update(id, () => ({ botId, ...(owner ? { roomId: owner.roomId } : {}), since: event.time ?? Date.now(), ...originNote(id) })) ++ update(id, () => ({ botId, ...(owner ? { roomId: owner.roomId } : {}), since: event.time ?? Date.now(), ...(event.data?.turn !== undefined ? { turn: event.data.turn } : {}), ...originNote(id) })) break } case 'user/message': { @@ -3270,6 +3270,17 @@ diff --git a/src/host/resume.js b/src/host/resume.js if (event.data?.source?.kind !== SOURCE_KIND) break // turns.js, installed earlier, has already claimed the turn's trigger. const info = rt.live.get(id)?.info +@@ -151,7 +151,9 @@ export function install(rt) { + case 'turn/end': { + // DSH stops every turn as it shuts down; that one is picked up at the next start. + const reason = event.data?.reason +- if (reason?.kind === 'aborted' && reason.reason?.kind === 'disposed') break ++ // DSH stopping every turn as it shuts down, or the format layer recording a restart as ++ // `interrupted`: that one is picked up at the next start, so its note stays. ++ if ((reason?.kind === 'aborted' && reason.reason?.kind === 'disposed') || reason?.kind === 'interrupted') break + update(id, () => undefined) + break + } @@ -173,17 +173,17 @@ export function install(rt) { // A turn already picked up once and cut off again stays stopped: a restart loop // must not run it forever. @@ -3291,6 +3302,108 @@ diff --git a/src/host/resume.js b/src/host/resume.js } // A hard stop keeps the inbox, which the Session runs once it wakes; only what DSH +@@ -198,11 +198,50 @@ export function install(rt) { + && current(item.args) !== undefined && taken?.has(item.args.exchangeId) !== true) + if (fresh.length === 0) return + const target = current(fresh[0].args) ++ // No Session to open yet: every item stays noted (seeded by resumeAll) for the next start. + const agent = await rt.resolveAgent(target) + const waiting = new Set([...(agent.inbox?.nextStep ?? []), ...(agent.inbox?.nextTurn ?? [])].map(message => message.source?.exchangeId)) +- for (const { args } of fresh) { ++ const failed = [] ++ for (const item of fresh) { ++ const { args } = item + if (waiting.has(args.exchangeId) || taken?.has(args.exchangeId) === true) continue +- await rt.deliver({ ...args, sessionId: current(args), steer: false, resent: true }) ++ try { ++ await rt.deliver({ ...args, sessionId: current(args), steer: false, resent: true }) ++ } catch { ++ // The delivery wrapper dropped its note; put it back so the next start retries it. ++ failed.push(item) ++ } ++ } ++ if (failed.length > 0) { ++ queued = { ...queued, [sessionId]: [...(queued[sessionId] ?? []), ...failed].slice(-QUEUED_MAX) } ++ persist() ++ rt.warn('ds-bot: %d message(s) for %s were not sent again; kept for the next start', failed.length, sessionId) ++ } ++ } ++ ++ // Did the noted turn really end while nobody was listening (a plugin reload, or a crash after ++ // DSH appended its end)? The durable Session log is the truth: a turn that finished ends ++ // `completed` (or `blocked` / `max-tokens` / `forked`, or is aborted by the user / hook / parent); ++ // only `interrupted`, an abort caused by `disposed` and a missing end describe work a restart ++ // cut. A note from a build before this change has no `turn`, so it keeps the old behaviour. ++ async function endedNormally(sessionId, record) { ++ if (!Number.isInteger(record.turn) || typeof ctx.sessionController?.page !== 'function') return false ++ try { ++ const agent = await rt.resolveAgent(sessionId) ++ const seq = Number(agent?.session?.seq) ++ const page = await ctx.sessionController.page({ ++ address: { kind: 'session', sessionId }, ++ ...(Number.isFinite(seq) && seq > 0 ? { throughSeq: seq - 1 } : {}), ++ maxMessages: 200, ++ }, AbortSignal.timeout(5000)) ++ const end = (page?.records ?? []).map(entry => entry?.event) ++ .filter(event => event?.type === 'turn/end' && event.data?.turn === record.turn).at(-1) ++ const reason = end?.data?.reason ++ if (reason === undefined) return false ++ if (reason.kind === 'aborted') return ['user', 'parent', 'hook'].includes(reason.reason?.kind) ++ return ['completed', 'blocked', 'max-tokens', 'forked'].includes(reason.kind) ++ } catch { ++ return false + } + } + +@@ -211,26 +211,40 @@ export function install(rt) { + if (rt.readOnly() !== undefined) return + const { turns: noted, queued: dropped } = interrupted + interrupted = { turns: {}, queued: {} } +- // Taken up now, so another restart does not pick them up twice. +- persist() ++ // Keep everything still owed in the live notes until its pickup succeeds: clearing the file ++ // first meant one failed delivery (or a crash during the pickup) lost the note for good. ++ turns = { ...noted } ++ queued = { ...dropped } + // Agents and inboxes are read before anything wakes their Sessions. + const cut = [] + for (const [sessionId, record] of Object.entries(noted)) { + const first = firstTurn.get(sessionId) +- if (first === 'turn/end') continue +- // Still running: noted again, as if it had started here. +- if (first === undefined && (await rt.resolveAgent(sessionId).catch(() => undefined))?.status === 'running') update(sessionId, () => record) +- else cut.push([sessionId, record]) ++ // `turn/end` is the noted turn ending here; `turn/start` means another turn began, so the ++ // noted one must have ended too (a turn cannot start until the previous one ends). ++ if (first === 'turn/end' || first === 'turn/start') { update(sessionId, () => undefined); continue } ++ // Still running: the note stays, as if it had started here. ++ if (first === undefined && (await rt.resolveAgent(sessionId).catch(() => undefined))?.status === 'running') continue ++ // Finished while this plugin was not listening: do not repeat work that is already done. ++ if (await endedNormally(sessionId, record)) { update(sessionId, () => undefined); continue } ++ cut.push([sessionId, record]) + } + firstTurn = undefined + for (const [sessionId, list] of Object.entries(dropped)) { +- if (!Array.isArray(list)) continue ++ if (!Array.isArray(list)) { delete queued[sessionId]; continue } + await resendQueued(sessionId, list).catch(error => rt.warn('ds-bot: sending again what %s was sent failed: %s', sessionId, error)) + } + taken = undefined + for (const [sessionId, record] of cut) { +- await resumeTurn(sessionId, record).catch(error => rt.warn('ds-bot: picking up the turn of %s failed: %s', sessionId, error)) ++ // Dropped just before the pickup so a resumed turn writes its own note; put back when the ++ // pickup failed before any new turn was noted, so the next start tries again. ++ update(sessionId, () => undefined) ++ try { await resumeTurn(sessionId, record) } ++ catch (error) { ++ if (turns[sessionId] === undefined) update(sessionId, () => record) ++ rt.warn('ds-bot: picking up the turn of %s failed: %s', sessionId, error) ++ } + } ++ persist() + } + + ctx.effect(() => { diff --git a/src/host/schedules.js b/src/host/schedules.js --- a/src/host/schedules.js +++ b/src/host/schedules.js @@ -5245,6 +5358,132 @@ diff --git a/test/connectors.test.js b/test/connectors.test.js + assert.equal(github.ok, false) + assert.match(github.error.message, /no apps to pick/) +}) +diff --git a/test/follow-through.test.js b/test/follow-through.test.js +--- a/test/follow-through.test.js ++++ b/test/follow-through.test.js +@@ -27,9 +27,13 @@ const seed = () => ({ + // One DS Bot host on `home`; a second start on the same home is a restart. + // Hosts by home: a home is removed only after its hosts stopped and their writes landed. + const started = new Map() ++// The durable Session log per home (what DSH keeps across a plugin reload or a restart). ++const durable = new Map() + + async function start(home) { + const ctx = fakeContext() ++ const log = durable.get(home) ?? [] ++ durable.set(home, log) + const agents = new Map() + const agentOf = (sessionId) => { + if (!agents.has(sessionId)) { +@@ -43,7 +43,13 @@ async function start(home) { + Object.assign(ctx, { + llm: { listProviders: () => [], listModels: async () => [], resolveModelInfo: async () => ({}) }, + workspaceRegistry: { get: () => undefined, resolveByPath: async () => undefined, create: async path => ({ id: 'w1', path }), archiveSession: async () => {} }, +- sessionController: { create: async () => ({ sessionId: 's1' }), resolveAgent: async sessionId => ({ agent: agentOf(sessionId) }), selectModel: async () => {} }, ++ sessionController: { ++ create: async () => ({ sessionId: 's1' }), ++ resolveAgent: async sessionId => ({ agent: agentOf(sessionId) }), ++ selectModel: async () => {}, ++ // What the durable log holds for a Session (newest page; the test keeps all of it). ++ page: async ({ address } = {}) => ({ records: log.filter(entry => entry.id === address?.sessionId).map(entry => ({ event: entry.event })), hasMore: false }), ++ }, + sessionTitle: { rename: async () => {} }, + sessions: { flush: async () => {} }, + }) +@@ -53,15 +53,19 @@ async function start(home) { + apply(ctx, { home }) + let seq = 0 + const emit = (id, type, data) => { ++ const event = { type, seq: ++seq, data } ++ log.push({ id, event }) + for (const listener of ctx.listeners.get('session/event') ?? []) { +- if (listener.length >= 2) listener({ id }, { type, seq: ++seq, data }) ++ if (listener.length >= 2) listener({ id }, event) + } + } ++ // Durable only: an event DSH wrote while no FlyBot host was listening. ++ const record = (id, type, data) => { log.push({ id, event: { type, seq: ++seq, data } }) } + const tool = (name, args, sessionId, exec = {}) => ctx.registeredTools.get(name).execute(args, { agent: { id: sessionId }, ...exec }) + const askApproval = sessionId => ctx.listeners.get('approval/request')[0]({ agent: { session: { id: sessionId } }, toolName: 'pwsh', reason: 'escalate sandbox' }, () => 'from-dsh') + const call = async (endpoint, payload) => (await route.fetch(new Request('http://localhost/api/bot', { method: 'POST', body: JSON.stringify({ endpoint, payload }) }))).json() + await tool('list_bots', {}, 'a') +- const host = { ctx, agentOf, emit, tool, call, askApproval, stop: () => ctx.dispose() } ++ const host = { ctx, agentOf, emit, record, tool, call, askApproval, stop: () => ctx.dispose() } + started.set(home, [...(started.get(home) ?? []), host]) + return host + } +@@ -72,6 +72,7 @@ const freshHome = (t) => { + t.after(async () => { + await Promise.all((started.get(home) ?? []).map(host => host.stop())) + started.delete(home) ++ durable.delete(home) + rmSync(home, { recursive: true, force: true, maxRetries: 5, retryDelay: 20 }) + }) + return home +@@ -195,6 +195,63 @@ test('when only DS Bot restarts, a turn still running or finished meanwhile is n + assert.deepEqual([third.agentOf('b').calls[0].source.exchangeId, third.agentOf('a').calls.length], ['x1', 0]) + }) + ++test('a turn that finished while the plugin was not listening is not picked up', async (t) => { ++ t.mock.timers.enable({ apis: ['setTimeout'] }) ++ const home = freshHome(t) ++ const first = await start(home) ++ run(first, 'a', 1, { content: [{ type: 'text', text: 'hello' }], source: { kind: 'user' } }) ++ await settle(() => inflight(home).a !== undefined) ++ // The turn ends while no FlyBot host is listening (a plugin reload, or a crash after DSH ++ // appended the end). Only the durable log knows; the note stays in inflight.json. ++ first.record('a', 'turn/end', { turn: 1, reason: { kind: 'completed' } }) ++ await first.stop() ++ const second = await start(home) ++ t.mock.timers.tick(3000) ++ await new Promise(resolve => setImmediate(resolve)) ++ assert.equal(second.agentOf('a').calls.length, 0, 'the finished turn is not repeated') ++}) ++ ++test('a turn the restart truly cut (interrupted in the durable log) is still picked up', async (t) => { ++ t.mock.timers.enable({ apis: ['setTimeout'] }) ++ const home = freshHome(t) ++ const first = await start(home) ++ run(first, 'a', 1, { content: [{ type: 'text', text: 'hello' }], source: { kind: 'user' } }) ++ await settle(() => inflight(home).a !== undefined) ++ first.record('a', 'turn/end', { turn: 1, reason: { kind: 'interrupted' } }) ++ await first.stop() ++ const second = await start(home) ++ t.mock.timers.tick(3000) ++ await settle(() => second.agentOf('a').calls.length === 1) ++ assert.match(text(second.agentOf('a').calls[0]), /restarted while you were working/) ++}) ++ ++test('a pickup that fails keeps its note for the next start', async (t) => { ++ t.mock.timers.enable({ apis: ['setTimeout'] }) ++ const home = freshHome(t) ++ const first = await start(home) ++ run(first, 'a', 1, { content: [{ type: 'text', text: 'hello' }], source: { kind: 'user' } }) ++ await settle(() => inflight(home).a !== undefined) ++ await first.stop() ++ ++ // The second start cannot open the Session: the note must survive, not be cleared first. ++ const second = await start(home) ++ const resolve = second.ctx.sessionController.resolveAgent ++ second.ctx.sessionController.resolveAgent = async id => { ++ if (id === 'a') throw new Error('the Session is not ready yet') ++ return resolve(id) ++ } ++ t.mock.timers.tick(3000) ++ await settle(() => inflight(home).a !== undefined) ++ assert.ok(inflight(home).a, 'the failed pickup is still noted') ++ await second.stop() ++ ++ // The third start picks it up. ++ const third = await start(home) ++ t.mock.timers.tick(3000) ++ await settle(() => third.agentOf('a').calls.length === 1) ++ assert.match(text(third.agentOf('a').calls[0]), /restarted while you were working/) ++}) ++ + test('a finished turn leaves nothing to pick up', async (t) => { + t.mock.timers.enable({ apis: ['setTimeout'] }) + const home = freshHome(t) diff --git a/test/group-status.test.js b/test/group-status.test.js --- a/test/group-status.test.js +++ b/test/group-status.test.js diff --git a/patches/ds-bot/topics.json b/patches/ds-bot/topics.json index 6b95a9c3d..7f8777789 100644 --- a/patches/ds-bot/topics.json +++ b/patches/ds-bot/topics.json @@ -47,7 +47,8 @@ "test/prompt.test.js", "src/client/browser-pane.js", "src/client/pane-width.js", - "src/client/panes.js" + "src/client/panes.js", + "test/follow-through.test.js" ], "0002-flybot-api-host": [ "index.js",