From c61a65adbd23acb3d54b8465120cd159ad6ae437 Mon Sep 17 00:00:00 2001 From: Danyang Chen Date: Mon, 9 Nov 2026 11:04:18 +0800 Subject: [PATCH] fix(decisions): unique temp file per writer, and no write in a read-only window MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Written-by: Chief Fixes #2724 Owner: Dev Reviewer: Reviewer `record()` wrote every decision through one fixed `decisions.jsonl.tmp` next to the log, so two writers on the same home renamed each other's file away and one decision vanished with `ENOENT`; and `record()` never consulted `rt.readOnly()`, so a read-only window still wrote the log and trimmed it. The temp name now carries the pid and a `randomUUID()`, the way `store.js`, `secrets.js`, `journal.js` and `memory.js` already name theirs, and `record()`/`trim()` return without touching the file when the host is read-only. Ran at this tip (extracted `main` tarball at `1a0c8993f95eb896b52a76ffec4a9f24db9212b2`, no git on this box): - baseline copy + the new test only: `node --import ./test/harness-resolve.mjs --test --test-concurrency=4 test/decisions-race.test.js` -> `# tests 3 / # pass 0 / # fail 3` (case A: `a decision was not written: ... ENOENT ... rename '.../decisions.jsonl.tmp'` x5; cases B/C: the read-only window recorded and trimmed anyway) - fixed tree: same command plus `test/decisions.test.js` -> `# tests 13 / # pass 13 / # fail 0` - the issue's two-process repro, 20 concurrent pairs -> `pairs=20 warnedPairs=0 missingLines=0 logLines=2000 tmpLeft=0` - `node scripts/ds-bot-patches.mjs check` -> `10 patches apply cleanly in order`, `core/ equals ds-bot/ + patches/ds-bot/`; `patches/ds-bot/files/` mirrors byte-identical to `core/` - `oxlint` 0 errors; `node .github/scripts/changelog.mjs check` 10 fragments well formed; `node .github/scripts/check-mojibake.mjs --check` 0 U+FFFD - not run: the full `core/ npm test` (it starts one process per test file on this 192-core box and hangs — tracked in #2725), and the smoke test (no `index.js` or `src/host/`-wide change beyond `decisions.js`) `docs/subsystems/core-host.md` records the read-only rule next to the decisions store it owns. --- changelog.d/2724-decisions-tmp.fixed.md | 1 + core/src/host/decisions.js | 33 ++++- core/test/decisions-race.test.js | 137 ++++++++++++++++++ core/test/decisions.test.js | 68 ++++----- docs/subsystems/core-host.md | 5 +- patches/ds-bot/files/src/host/decisions.js | 33 ++++- .../ds-bot/files/test/decisions-race.test.js | 137 ++++++++++++++++++ patches/ds-bot/files/test/decisions.test.js | 68 ++++----- 8 files changed, 394 insertions(+), 88 deletions(-) create mode 100644 changelog.d/2724-decisions-tmp.fixed.md create mode 100644 core/test/decisions-race.test.js create mode 100644 patches/ds-bot/files/test/decisions-race.test.js diff --git a/changelog.d/2724-decisions-tmp.fixed.md b/changelog.d/2724-decisions-tmp.fixed.md new file mode 100644 index 000000000..b316864d0 --- /dev/null +++ b/changelog.d/2724-decisions-tmp.fixed.md @@ -0,0 +1 @@ +The decision log no longer shares one temp file between writers: the trim stages the retained log at `decisions.jsonl...tmp` and renames it over the log, so two hosts of one team folder cannot take each other's temp away and report a write that never landed — the `a decision was not written: … ENOENT …` warning, and the trim that was lost with it, are gone ([#2724](https://github.com/ThinkFlowLab/FlyBot/issues/2724)). A read-only window, the second host of one team folder, now writes nothing at all: `record_decision` there appends no line, trims nothing, fires no `decision` event, and answers `Not recorded: this window is read-only, …` instead of claiming a record that is not on disk. diff --git a/core/src/host/decisions.js b/core/src/host/decisions.js index 6b6b94bb5..f24703c68 100644 --- a/core/src/host/decisions.js +++ b/core/src/host/decisions.js @@ -8,6 +8,7 @@ // default install behaves exactly as before. The log is local text, one JSON line per entry; the // same entry is fired on the activity feed as `decision` so a consumer (Timeline, an audit view) // can show it without reading the file. +import { randomUUID } from 'node:crypto' import { appendFile, open, readFile, stat } from 'node:fs/promises' import { dirname, join } from 'node:path' import { cut } from './text.js' @@ -35,6 +36,13 @@ export function install(rt) { } const { home } = rt const path = join(home, 'decisions.jsonl') + // One writer per home (`home-lock`): the second host of one team folder is read-only, and it reads + // the log a writer left instead of writing one of its own. `rt.readOnly()` names that other host + // (#2724); its absence is what makes this window the writer. + const readOnly = () => rt.readOnly() !== undefined + // The host's own sentence when a record was refused for being read-only, so the answer can give + // the reason the window asks the reader to act on. + let readonlyReason = '' // One append at a time, and a failure is a warning, never a turn failure (the log is a side // record, not part of the Bot's work). let writing = Promise.resolve() @@ -49,7 +57,7 @@ export function install(rt) { // (#2103): a link left there would take the retained log and then become the log. One refusal is // said once, the same way the leaf is. let refusedTemp = false - let trimRefused = false + let trimRefused = '' const leafWritable = async () => { if (await fileKind(path) !== 'other') return true if (!refusedLeaf) { @@ -63,7 +71,9 @@ export function install(rt) { // file so a reader never sees a half-trimmed log. The Bot side stays append-only; this is the // host's own housekeeping. async function trim() { - trimRefused = false + trimRefused = '' + // The trim is a write like the append, so a read-only window leaves the log as it found it. + if (readOnly()) return linesOnDisk ?? 0 let text try { text = await readFile(path, 'utf8') } catch (error) { if (error?.code === 'ENOENT') return 0; throw error } const lines = text.split('\n').filter(Boolean) @@ -78,9 +88,12 @@ export function install(rt) { kept.reverse() const next = kept.length > 0 ? `${kept.join('\n')}\n` : '' if (next !== text) { - const tmp = `${path}.tmp` + // The temp name belongs to this write alone: one fixed `decisions.jsonl.tmp` was a name every + // writer on the home shared, so one writer's rename took the other's temp away and that write + // failed with ENOENT mid-chain (#2724). Same shape as the other atomic writers. + const tmp = `${path}.${process.pid}.${randomUUID()}.tmp` if (!tempWritable(tmp)) { - trimRefused = true + trimRefused = tmp if (!refusedTemp) { refusedTemp = true rt.warn('ds-bot: the decision log was not trimmed: %s is not a plain file of its own', tmp) @@ -96,6 +109,13 @@ export function install(rt) { function record(entry) { const line = `${JSON.stringify(entry)}\n` writing = writing.then(async () => { + // A read-only window writes nothing: the log belongs to the home's writer, and this window + // shows what that writer left (#2724). + const reason = rt.readOnly() + if (reason !== undefined) { + readonlyReason = reason ?? '' + return 'readonly' + } if (!await leafWritable()) return 'refused' // What a Bot considered and rejected is its own reasoning, so the log and its folder are // private (#2697). `appendFile`'s mode applies when the append creates the file. @@ -164,9 +184,12 @@ export function install(rt) { // A refused leaf drops the line, so the answer and the feed say the same thing: nothing was // recorded. A write that failed for another reason keeps its old shape (a warning, an answer). if (wrote === 'refused') return 'Not recorded: the decision log is not a plain file of its own.' + // The read-only window is not a failure — it is the window the host chose — so the answer says + // what the host said, and the entry is not announced on the feed it never reached (#2724). + if (wrote === 'readonly') return ['Not recorded: this window is read-only, so the decision log was not written.', readonlyReason].filter(Boolean).join(' ') // The feed payload drops the id to a safe shape and adds the live botId (a consumer keys by it). rt.fireFeed?.('decision', { botId, option, choice, ...(why ? { why } : {}), time: entry.time }) - if (wrote === 'untrimmed') return `Written: ${choice} "${option}"${why ? ` — ${why}` : ''} — the log was not trimmed: ${path}.tmp is not a plain file of its own.` + if (wrote === 'untrimmed') return `Written: ${choice} "${option}"${why ? ` — ${why}` : ''} — the log was not trimmed: ${trimRefused} is not a plain file of its own.` return `Recorded: ${choice} "${option}"${why ? ` — ${why}` : ''}.` }, })) diff --git a/core/test/decisions-race.test.js b/core/test/decisions-race.test.js new file mode 100644 index 000000000..3d2c7995d --- /dev/null +++ b/core/test/decisions-race.test.js @@ -0,0 +1,137 @@ +// #2724: the decision log's atomic write named its temp file with one fixed name for every writer, +// so two writers on one home met on `/decisions.jsonl.tmp`. One writer's trim renamed the +// other's temp away, the other write then failed with ENOENT mid-chain — the trim was lost and the +// caller was still told `Recorded: …`. And `record()` never asked `rt.readOnly()`, so the second, +// read-only host of one team folder wrote the log it must only read. +// +// Two writers and a read-only one, over the real module: the store and the home lock are not part of +// what these cases judge, so the runtime facts `install()` asks for are the ones supplied here. +import assert from 'node:assert/strict' +import { mkdtempSync, readFileSync, readdirSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { test } from 'node:test' +import { install } from '../src/host/decisions.js' + +const KEPT = 2_000 +const SITUATION = 'The Bot team in /data/example is open in another dsh (Web or Desktop, pid 4242). This window shows the team but cannot change it; close the other one and reload.' + +const line = n => `${JSON.stringify({ time: 1_000 + n, bot: 'a', botName: 'Chief', option: `kept ${n}`, choice: 'used' })}\n` +const seed = () => Array.from({ length: KEPT }, (_, i) => line(i)).join('') + +function writer(home, { readOnly } = {}) { + const tools = new Map() + const warnings = [] + const feed = [] + install({ + home, + config: { decisions: true }, + ctx: { tools: { register: tool => tools.set(tool.name, tool) } }, + warn: (...args) => warnings.push(args.join(' ')), + load: async () => {}, + selfOf: id => id, + botOf: () => ({ id: 'a', name: 'Chief' }), + fireFeed: (kind, payload) => feed.push({ kind, payload }), + readOnly: () => readOnly, + }) + return { + warnings, + feed, + run: args => tools.get('record_decision').execute(args, { agent: { id: 'a' } }), + } +} + +function home(t) { + const dir = mkdtempSync(join(tmpdir(), 'ds-bot-decisions-race-')) + t.after(() => rmSync(dir, { recursive: true, force: true, maxRetries: 5 })) + return dir +} + +const optionsOnDisk = path => readFileSync(path, 'utf8').split('\n').filter(Boolean).map(text => JSON.parse(text).option) + +// Both writers trim, so both take the temp path the fixed name gave to every writer on the home. +// Five pairs, because a single pair can meet or miss the collision window depending on timing: the +// answer is that no pair of them fails, over the same log, one after the other. +test('#2724: two writers on one home both record their decision, and no write fails on a shared temp name', async (t) => { + const dir = home(t) + const log = join(dir, 'decisions.jsonl') + writeFileSync(log, seed()) + const one = writer(dir) + const two = writer(dir) + + const recorded = [] + for (let pair = 0; pair < 5; pair++) { + const [first, second] = await Promise.all([ + one.run({ option: `writer one, pair ${pair}`, choice: 'used' }), + two.run({ option: `writer two, pair ${pair}`, choice: 'rejected' }), + ]) + recorded.push([first, second]) + } + + const warnings = [...one.warnings, ...two.warnings] + assert.deepEqual(warnings.filter(text => /a decision was not written/.test(text)), [], + `no write may fail on the temp name, got: ${warnings.join(' | ')}`) + for (const [first, second] of recorded) { + assert.match(first, /^Recorded:/, `the first writer is told its decision is on disk, got: ${first}`) + assert.match(second, /^Recorded:/, `the second writer is told its decision is on disk, got: ${second}`) + } + + const kept = optionsOnDisk(log) + for (let pair = 0; pair < 5; pair++) { + assert.ok(kept.includes(`writer one, pair ${pair}`), `writer one's pair ${pair} is in the log`) + assert.ok(kept.includes(`writer two, pair ${pair}`), `writer two's pair ${pair} is in the log`) + } + assert.ok(kept.length <= KEPT, `the log stays bounded at ${KEPT} lines, got ${kept.length}`) + assert.deepEqual(readdirSync(dir).filter(name => name.endsWith('.tmp')), [], 'no temp file is left behind') +}) + +// The second host of one team folder is read-only. `record_decision` there must read the log and +// write nothing: no append, no trim, no feed event, and an answer that says so. +test('#2724: a read-only window records nothing, changes no byte and says why', async (t) => { + const dir = home(t) + const log = join(dir, 'decisions.jsonl') + const before = seed() + writeFileSync(log, before) + const only = writer(dir, { readOnly: SITUATION }) + + const answer = await only.run({ option: 'Delete the whole repo', choice: 'rejected', why: 'destructive' }) + + assert.equal(readFileSync(log, 'utf8'), before, 'the log keeps its bytes: nothing was appended or trimmed') + assert.doesNotMatch(answer, /^Recorded:/, 'the answer does not claim a record') + assert.match(answer, /read-only/, 'the answer says the window is read-only') + assert.ok(answer.includes(SITUATION), `the answer names the host's own reason, got: ${answer}`) + assert.deepEqual(only.feed, [], 'a decision that is not on disk is not announced on the feed') + assert.deepEqual(only.warnings, [], 'a read-only window has nothing to warn about') +}) + +// `rt.readOnly()`'s contract is the one the chat index reads (#2711): any value but `undefined` +// means this window is not the writer. A host that states no sentence still records nothing. +test('#2724: a read-only window with no host sentence still writes nothing', async (t) => { + const dir = home(t) + const log = join(dir, 'decisions.jsonl') + const before = seed() + writeFileSync(log, before) + const only = writer(dir, { readOnly: '' }) + + const answer = await only.run({ option: 'Ship without the tests', choice: 'rejected' }) + + assert.equal(readFileSync(log, 'utf8'), before, 'the log keeps its bytes') + assert.match(answer, /^Not recorded: this window is read-only/, `the answer refuses and says why, got: ${answer}`) + assert.match(answer, /written\.$/, 'no dangling space where the host sentence would be') + assert.deepEqual(only.feed, [], 'nothing is announced on the feed') +}) + +// The same window over a log that is over its bound: the trim is a write too, so the read-only +// window leaves the oversized log as it is instead of bounding it. +test('#2724: a read-only window does not trim an oversized log', async (t) => { + const dir = home(t) + const log = join(dir, 'decisions.jsonl') + const before = seed() + writeFileSync(log, before) + const only = writer(dir, { readOnly: SITUATION }) + + for (let i = 0; i < 3; i++) assert.match(await only.run({ option: `oversized ${i}`, choice: 'used' }), /read-only/) + + assert.equal(readFileSync(log, 'utf8'), before, 'the log is still the file the writer left') + assert.deepEqual(readdirSync(dir).filter(name => name.endsWith('.tmp')), [], 'no temp file was written') +}) diff --git a/core/test/decisions.test.js b/core/test/decisions.test.js index 90f9d74f6..62683f328 100644 --- a/core/test/decisions.test.js +++ b/core/test/decisions.test.js @@ -1,5 +1,5 @@ import assert from 'node:assert/strict' -import { existsSync, linkSync, lstatSync, mkdtempSync, readFileSync, readlinkSync, rmSync, symlinkSync, writeFileSync } from 'node:fs' +import { existsSync, linkSync, lstatSync, mkdtempSync, readFileSync, readdirSync, readlinkSync, rmSync, symlinkSync, writeFileSync } from 'node:fs' import { tmpdir } from 'node:os' import { join } from 'node:path' import { test } from 'node:test' @@ -132,9 +132,11 @@ test('a linked decision log is refused, not written through', async (t) => { }) // Housekeeping writes a temp name beside the log and renames it over the log, so the temp name is a -// place this code writes (#2103). A link left there must be refused before the write, not taken: -// otherwise the retained log is written through it and the log itself becomes a link. -test('#2103: a linked temp name does not take the trim; the log stays a plain file', async (t) => { +// place this code writes (#2103) — but it is the writing host's own name now, `...tmp` +// like the resume notes (#2724), not the fixed `/decisions.jsonl.tmp` every writer on the home +// shared. A link planted at that old name is not a name this code takes: it keeps its bytes and its +// target, the trim bounds the log, and the log itself stays a plain file. +test('#2724: the trim writes its own temp name, so a link at the old fixed name is left alone', async (t) => { const line = (n) => `${JSON.stringify({ time: 1_000 + n, bot: 'a', botName: 'Chief', option: `kept ${n}`, choice: 'used' })}\n` const full = (n) => Array.from({ length: n }, (_, i) => line(i)).join('') @@ -147,44 +149,34 @@ test('#2103: a linked temp name does not take the trim; the log stays a plain fi writeFileSync(target, before) const log = join(home, 'decisions.jsonl') writeFileSync(log, full(2_000)) - symlinkSync(target, `${log}.tmp`) + const planted = `${log}.tmp` + symlinkSync(target, planted) const warnings = [] ctx.logger.warn = (...args) => warnings.push(args.join(' ')) const first = await tool('record_decision', { option: 'Trigger the trim', choice: 'used' }) const second = await tool('record_decision', { option: 'Trigger it again', choice: 'rejected' }) - assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the temp link is not written through') - assert.equal(lstatSync(log).isSymbolicLink(), false, 'the log is still a plain file, not the link') + assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the planted link is not written through') + assert.equal(lstatSync(planted).isSymbolicLink(), true, 'the planted link is still there') + assert.equal(readlinkSync(planted), target, 'the planted link still names the same file') + assert.equal(lstatSync(log).isSymbolicLink(), false, 'the log is a plain file of its own') const lines = readFileSync(log, 'utf8').split('\n').filter(Boolean) - assert.equal(lines.length, 2_002, 'the refused trim leaves the log as it was, plus the two new lines') + assert.equal(lines.length, 2_000, 'the trim bounds the log at KEPT lines') for (const lineText of lines) assert.doesNotThrow(() => JSON.parse(lineText), 'every line stays a valid entry') assert.equal(JSON.parse(lines.at(-1)).option, 'Trigger it again') - assert.doesNotMatch(first, /^Recorded:/, 'the answer does not claim a clean record when the trim was refused') - assert.doesNotMatch(second, /^Recorded:/) - assert.equal(warnings.length, 1, 'one warning for the temp name, not one per record') - assert.match(warnings[0], /decisions\.jsonl\.tmp/) - assert.match(warnings[0], /not a plain file/) - - // The healthy path is untouched: with a normal temp name the trim still bounds the log. - const healthy = await boot({ decisions: true }) - t.after(healthy.stop) - const plain = join(healthy.home, 'decisions.jsonl') - writeFileSync(plain, full(2_000)) - const healthyWarnings = [] - healthy.ctx.logger.warn = (...args) => healthyWarnings.push(args.join(' ')) - assert.match(await healthy.tool('record_decision', { option: 'Trim normally', choice: 'used' }), /^Recorded:/) - const kept = readFileSync(plain, 'utf8').split('\n').filter(Boolean) - assert.equal(kept.length, 2_000, 'the trim keeps the newest KEPT lines') - assert.equal(JSON.parse(kept.at(-1)).option, 'Trim normally') - assert.equal(existsSync(`${plain}.tmp`), false, 'the healthy trim renames its temp name away') - assert.deepEqual(healthyWarnings, []) + assert.match(first, /^Recorded:/, 'the trim went through, so the answer is clean') + assert.match(second, /^Recorded:/) + assert.deepEqual(warnings, [], 'nothing is refused: the planted name is not one this code writes') + const leftovers = readdirSync(home).filter(name => name.endsWith('.tmp') && name !== 'decisions.jsonl.tmp') + assert.deepEqual(leftovers, [], 'the trim renames its own temp name away') }) -// The trim's temp name can be a hard link, which `lstat` reports as a plain file: the retained log -// would be written into the inode the other name holds. It is refused before the write, warned -// once, and the log keeps its lines. -test('#P-hardlink: a hard link at the trim temp name does not take the trim', async (t) => { +// The temp name is a leaf like the log itself (temp-name sweep): a hard link there is a plain file to +// `lstat` while the write would land in the inode the other name holds. The guard still refuses that, +// and a hard link at the old fixed name is no way to reach it: the outside bytes stay, and the log is +// bounded by a temp name of its own. +test('#2724: a hard link at the old fixed temp name does not take the trim', async (t) => { const line = (n) => `${JSON.stringify({ time: 1_000 + n, bot: 'a', botName: 'Chief', option: `kept ${n}`, choice: 'used' })}\n` const full = (n) => Array.from({ length: n }, (_, i) => line(i)).join('') @@ -197,20 +189,20 @@ test('#P-hardlink: a hard link at the trim temp name does not take the trim', as writeFileSync(target, before) const log = join(home, 'decisions.jsonl') writeFileSync(log, full(2_000)) - linkSync(target, `${log}.tmp`) + const planted = `${log}.tmp` + linkSync(target, planted) const warnings = [] ctx.logger.warn = (...args) => warnings.push(args.join(' ')) const first = await tool('record_decision', { option: 'Trigger the trim', choice: 'used' }) assert.equal(readFileSync(target, 'utf8'), before, 'the shared inode keeps its bytes') - assert.equal(lstatSync(target).nlink, 2, 'the outside file still carries the temp name') + assert.equal(lstatSync(target).nlink, 2, 'the outside file still carries the planted name') const lines = readFileSync(log, 'utf8').split('\n').filter(Boolean) - assert.equal(lines.length, 2_001, 'the refused trim leaves the log as it was, plus the new line') - assert.doesNotMatch(first, /^Recorded:/, 'the answer does not claim a clean record') - assert.equal(warnings.length, 1, 'one warning for the temp name') - assert.match(warnings[0], /decisions\.jsonl\.tmp/) - assert.match(warnings[0], /not a plain file/) + assert.equal(lines.length, 2_000, 'the trim bounds the log at KEPT lines') + assert.equal(JSON.parse(lines.at(-1)).option, 'Trigger the trim') + assert.match(first, /^Recorded:/, 'the trim went through, so the answer is clean') + assert.deepEqual(warnings, []) }) // #2159: a hard link at the log is a plain file to `lstat` while its bytes are also a name outside diff --git a/docs/subsystems/core-host.md b/docs/subsystems/core-host.md index 1aeadaf0e..de4cd0445 100644 --- a/docs/subsystems/core-host.md +++ b/docs/subsystems/core-host.md @@ -261,8 +261,9 @@ The host's own files carry the user's content — a Bot's memory and the memory ### Decisions a Bot records (#396) -- `src/host/decisions.js` gives a Bot one small tool, `record_decision({ option, choice, why })` (`choice` is `used` or `rejected`), so a "considered and rejected" choice a reviewer cannot otherwise see is written down. The host appends one JSON line per decision to `/decisions.jsonl` (bounded on disk at the newest 2000 lines and 1 MB, trimmed by the host as it appends; a read parses at most 1 MB; one write at a time; a write failure is a warning, never a turn failure) and fires the entry on the activity feed as `decision`. A Bot has no tool to edit or delete a past entry. The log is one leaf file beside the home, so a write asks the leaf first ([#2089](https://github.com/ThinkFlowLab/FlyBot/issues/2089)): when `decisions.jsonl` is a link, a hard link or anything other than a plain file of its own — the line is dropped, the refusal is one warning, and the tool answers `Not recorded: the decision log is not a plain file of its own.` instead of reporting a line that is not on disk, while an absent file is still created. The temp name the housekeeping lands through is asked the same way ([#2103](https://github.com/ThinkFlowLab/FlyBot/issues/2103)): `/decisions.jsonl.tmp` is written and then renamed over the log, so when it is a link, a hard link (`nlink > 1`, whose bytes another name also holds) or anything other than a plain file of its own, the trim is refused instead of carrying the retained log out through it and putting the link where the log belongs; the line just appended stays, the log simply grows past its bound, the refusal is one warning, and the tool answers `Written: … — the log was not trimmed: …` rather than `Recorded:`. A normal temp name trims exactly as before. -- **Opt-in** (`config.decisions`): with the flag off the tool is not registered, nothing is written and no event is fired, so a default install is unchanged. A key, token or password in the text is refused (`looksSecret`), so the log needs no secret. Tests: `core/test/decisions.test.js`. +- `src/host/decisions.js` gives a Bot one small tool, `record_decision({ option, choice, why })` (`choice` is `used` or `rejected`), so a "considered and rejected" choice a reviewer cannot otherwise see is written down. The host appends one JSON line per decision to `/decisions.jsonl` (bounded on disk at the newest 2000 lines and 1 MB, trimmed by the host as it appends; a read parses at most 1 MB; one write at a time; a write failure is a warning, never a turn failure) and fires the entry on the activity feed as `decision`. A Bot has no tool to edit or delete a past entry. The log is one leaf file beside the home, so a write asks the leaf first ([#2089](https://github.com/ThinkFlowLab/FlyBot/issues/2089)): when `decisions.jsonl` is a link, a hard link or anything other than a plain file of its own — the line is dropped, the refusal is one warning, and the tool answers `Not recorded: the decision log is not a plain file of its own.` instead of reporting a line that is not on disk, while an absent file is still created. The temp name the housekeeping lands through is the writing host's own ([#2103](https://github.com/ThinkFlowLab/FlyBot/issues/2103), [#2724](https://github.com/ThinkFlowLab/FlyBot/issues/2724)): `/decisions.jsonl...tmp`, named the way the resume notes name theirs, is written and then renamed over the log. One fixed `decisions.jsonl.tmp` was a name every writer on the home shared, so two writers met on it: one writer's rename took the other's temp away, that write failed with `ENOENT` mid-chain, the trim was lost and the caller was still told `Recorded: …`. The temp name is asked like the leaf — when it is a link, a hard link (`nlink > 1`, whose bytes another name also holds) or anything other than a plain file of its own, the trim is refused instead of carrying the retained log out through it and putting the link where the log belongs; the line just appended stays, the log simply grows past its bound, the refusal is one warning, and the tool answers `Written: … — the log was not trimmed: …` rather than `Recorded:`. The second host of one team folder is the read-only window `home-lock` leaves, and it wrote this log too until `record()` asked `rt.readOnly()` (the next bullet): two hosts of one folder were two writers of that one name. +- **One writer per home** ([#2724](https://github.com/ThinkFlowLab/FlyBot/issues/2724), the `core/src/host/chat-index.js` guard of [#2711](https://github.com/ThinkFlowLab/FlyBot/issues/2711)): `record()` asks `rt.readOnly()` first and `trim()` asks it too, because the trim is a write like the append. In a read-only window — the second host of one team folder — nothing is appended, nothing is trimmed, no `decision` event is fired, and the tool answers `Not recorded: this window is read-only, so the decision log was not written.` followed by the host's own sentence when it gives one; the log is still read, so a Reviewer there sees what the writer left. Tests: `core/test/decisions.test.js`, `core/test/decisions-race.test.js`. +- **Opt-in** (`config.decisions`): with the flag off the tool is not registered, nothing is written and no event is fired, so a default install is unchanged. A key, token or password in the text is refused (`looksSecret`), so the log needs no secret. ### Tasks diff --git a/patches/ds-bot/files/src/host/decisions.js b/patches/ds-bot/files/src/host/decisions.js index 6b6b94bb5..f24703c68 100644 --- a/patches/ds-bot/files/src/host/decisions.js +++ b/patches/ds-bot/files/src/host/decisions.js @@ -8,6 +8,7 @@ // default install behaves exactly as before. The log is local text, one JSON line per entry; the // same entry is fired on the activity feed as `decision` so a consumer (Timeline, an audit view) // can show it without reading the file. +import { randomUUID } from 'node:crypto' import { appendFile, open, readFile, stat } from 'node:fs/promises' import { dirname, join } from 'node:path' import { cut } from './text.js' @@ -35,6 +36,13 @@ export function install(rt) { } const { home } = rt const path = join(home, 'decisions.jsonl') + // One writer per home (`home-lock`): the second host of one team folder is read-only, and it reads + // the log a writer left instead of writing one of its own. `rt.readOnly()` names that other host + // (#2724); its absence is what makes this window the writer. + const readOnly = () => rt.readOnly() !== undefined + // The host's own sentence when a record was refused for being read-only, so the answer can give + // the reason the window asks the reader to act on. + let readonlyReason = '' // One append at a time, and a failure is a warning, never a turn failure (the log is a side // record, not part of the Bot's work). let writing = Promise.resolve() @@ -49,7 +57,7 @@ export function install(rt) { // (#2103): a link left there would take the retained log and then become the log. One refusal is // said once, the same way the leaf is. let refusedTemp = false - let trimRefused = false + let trimRefused = '' const leafWritable = async () => { if (await fileKind(path) !== 'other') return true if (!refusedLeaf) { @@ -63,7 +71,9 @@ export function install(rt) { // file so a reader never sees a half-trimmed log. The Bot side stays append-only; this is the // host's own housekeeping. async function trim() { - trimRefused = false + trimRefused = '' + // The trim is a write like the append, so a read-only window leaves the log as it found it. + if (readOnly()) return linesOnDisk ?? 0 let text try { text = await readFile(path, 'utf8') } catch (error) { if (error?.code === 'ENOENT') return 0; throw error } const lines = text.split('\n').filter(Boolean) @@ -78,9 +88,12 @@ export function install(rt) { kept.reverse() const next = kept.length > 0 ? `${kept.join('\n')}\n` : '' if (next !== text) { - const tmp = `${path}.tmp` + // The temp name belongs to this write alone: one fixed `decisions.jsonl.tmp` was a name every + // writer on the home shared, so one writer's rename took the other's temp away and that write + // failed with ENOENT mid-chain (#2724). Same shape as the other atomic writers. + const tmp = `${path}.${process.pid}.${randomUUID()}.tmp` if (!tempWritable(tmp)) { - trimRefused = true + trimRefused = tmp if (!refusedTemp) { refusedTemp = true rt.warn('ds-bot: the decision log was not trimmed: %s is not a plain file of its own', tmp) @@ -96,6 +109,13 @@ export function install(rt) { function record(entry) { const line = `${JSON.stringify(entry)}\n` writing = writing.then(async () => { + // A read-only window writes nothing: the log belongs to the home's writer, and this window + // shows what that writer left (#2724). + const reason = rt.readOnly() + if (reason !== undefined) { + readonlyReason = reason ?? '' + return 'readonly' + } if (!await leafWritable()) return 'refused' // What a Bot considered and rejected is its own reasoning, so the log and its folder are // private (#2697). `appendFile`'s mode applies when the append creates the file. @@ -164,9 +184,12 @@ export function install(rt) { // A refused leaf drops the line, so the answer and the feed say the same thing: nothing was // recorded. A write that failed for another reason keeps its old shape (a warning, an answer). if (wrote === 'refused') return 'Not recorded: the decision log is not a plain file of its own.' + // The read-only window is not a failure — it is the window the host chose — so the answer says + // what the host said, and the entry is not announced on the feed it never reached (#2724). + if (wrote === 'readonly') return ['Not recorded: this window is read-only, so the decision log was not written.', readonlyReason].filter(Boolean).join(' ') // The feed payload drops the id to a safe shape and adds the live botId (a consumer keys by it). rt.fireFeed?.('decision', { botId, option, choice, ...(why ? { why } : {}), time: entry.time }) - if (wrote === 'untrimmed') return `Written: ${choice} "${option}"${why ? ` — ${why}` : ''} — the log was not trimmed: ${path}.tmp is not a plain file of its own.` + if (wrote === 'untrimmed') return `Written: ${choice} "${option}"${why ? ` — ${why}` : ''} — the log was not trimmed: ${trimRefused} is not a plain file of its own.` return `Recorded: ${choice} "${option}"${why ? ` — ${why}` : ''}.` }, })) diff --git a/patches/ds-bot/files/test/decisions-race.test.js b/patches/ds-bot/files/test/decisions-race.test.js new file mode 100644 index 000000000..3d2c7995d --- /dev/null +++ b/patches/ds-bot/files/test/decisions-race.test.js @@ -0,0 +1,137 @@ +// #2724: the decision log's atomic write named its temp file with one fixed name for every writer, +// so two writers on one home met on `/decisions.jsonl.tmp`. One writer's trim renamed the +// other's temp away, the other write then failed with ENOENT mid-chain — the trim was lost and the +// caller was still told `Recorded: …`. And `record()` never asked `rt.readOnly()`, so the second, +// read-only host of one team folder wrote the log it must only read. +// +// Two writers and a read-only one, over the real module: the store and the home lock are not part of +// what these cases judge, so the runtime facts `install()` asks for are the ones supplied here. +import assert from 'node:assert/strict' +import { mkdtempSync, readFileSync, readdirSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { test } from 'node:test' +import { install } from '../src/host/decisions.js' + +const KEPT = 2_000 +const SITUATION = 'The Bot team in /data/example is open in another dsh (Web or Desktop, pid 4242). This window shows the team but cannot change it; close the other one and reload.' + +const line = n => `${JSON.stringify({ time: 1_000 + n, bot: 'a', botName: 'Chief', option: `kept ${n}`, choice: 'used' })}\n` +const seed = () => Array.from({ length: KEPT }, (_, i) => line(i)).join('') + +function writer(home, { readOnly } = {}) { + const tools = new Map() + const warnings = [] + const feed = [] + install({ + home, + config: { decisions: true }, + ctx: { tools: { register: tool => tools.set(tool.name, tool) } }, + warn: (...args) => warnings.push(args.join(' ')), + load: async () => {}, + selfOf: id => id, + botOf: () => ({ id: 'a', name: 'Chief' }), + fireFeed: (kind, payload) => feed.push({ kind, payload }), + readOnly: () => readOnly, + }) + return { + warnings, + feed, + run: args => tools.get('record_decision').execute(args, { agent: { id: 'a' } }), + } +} + +function home(t) { + const dir = mkdtempSync(join(tmpdir(), 'ds-bot-decisions-race-')) + t.after(() => rmSync(dir, { recursive: true, force: true, maxRetries: 5 })) + return dir +} + +const optionsOnDisk = path => readFileSync(path, 'utf8').split('\n').filter(Boolean).map(text => JSON.parse(text).option) + +// Both writers trim, so both take the temp path the fixed name gave to every writer on the home. +// Five pairs, because a single pair can meet or miss the collision window depending on timing: the +// answer is that no pair of them fails, over the same log, one after the other. +test('#2724: two writers on one home both record their decision, and no write fails on a shared temp name', async (t) => { + const dir = home(t) + const log = join(dir, 'decisions.jsonl') + writeFileSync(log, seed()) + const one = writer(dir) + const two = writer(dir) + + const recorded = [] + for (let pair = 0; pair < 5; pair++) { + const [first, second] = await Promise.all([ + one.run({ option: `writer one, pair ${pair}`, choice: 'used' }), + two.run({ option: `writer two, pair ${pair}`, choice: 'rejected' }), + ]) + recorded.push([first, second]) + } + + const warnings = [...one.warnings, ...two.warnings] + assert.deepEqual(warnings.filter(text => /a decision was not written/.test(text)), [], + `no write may fail on the temp name, got: ${warnings.join(' | ')}`) + for (const [first, second] of recorded) { + assert.match(first, /^Recorded:/, `the first writer is told its decision is on disk, got: ${first}`) + assert.match(second, /^Recorded:/, `the second writer is told its decision is on disk, got: ${second}`) + } + + const kept = optionsOnDisk(log) + for (let pair = 0; pair < 5; pair++) { + assert.ok(kept.includes(`writer one, pair ${pair}`), `writer one's pair ${pair} is in the log`) + assert.ok(kept.includes(`writer two, pair ${pair}`), `writer two's pair ${pair} is in the log`) + } + assert.ok(kept.length <= KEPT, `the log stays bounded at ${KEPT} lines, got ${kept.length}`) + assert.deepEqual(readdirSync(dir).filter(name => name.endsWith('.tmp')), [], 'no temp file is left behind') +}) + +// The second host of one team folder is read-only. `record_decision` there must read the log and +// write nothing: no append, no trim, no feed event, and an answer that says so. +test('#2724: a read-only window records nothing, changes no byte and says why', async (t) => { + const dir = home(t) + const log = join(dir, 'decisions.jsonl') + const before = seed() + writeFileSync(log, before) + const only = writer(dir, { readOnly: SITUATION }) + + const answer = await only.run({ option: 'Delete the whole repo', choice: 'rejected', why: 'destructive' }) + + assert.equal(readFileSync(log, 'utf8'), before, 'the log keeps its bytes: nothing was appended or trimmed') + assert.doesNotMatch(answer, /^Recorded:/, 'the answer does not claim a record') + assert.match(answer, /read-only/, 'the answer says the window is read-only') + assert.ok(answer.includes(SITUATION), `the answer names the host's own reason, got: ${answer}`) + assert.deepEqual(only.feed, [], 'a decision that is not on disk is not announced on the feed') + assert.deepEqual(only.warnings, [], 'a read-only window has nothing to warn about') +}) + +// `rt.readOnly()`'s contract is the one the chat index reads (#2711): any value but `undefined` +// means this window is not the writer. A host that states no sentence still records nothing. +test('#2724: a read-only window with no host sentence still writes nothing', async (t) => { + const dir = home(t) + const log = join(dir, 'decisions.jsonl') + const before = seed() + writeFileSync(log, before) + const only = writer(dir, { readOnly: '' }) + + const answer = await only.run({ option: 'Ship without the tests', choice: 'rejected' }) + + assert.equal(readFileSync(log, 'utf8'), before, 'the log keeps its bytes') + assert.match(answer, /^Not recorded: this window is read-only/, `the answer refuses and says why, got: ${answer}`) + assert.match(answer, /written\.$/, 'no dangling space where the host sentence would be') + assert.deepEqual(only.feed, [], 'nothing is announced on the feed') +}) + +// The same window over a log that is over its bound: the trim is a write too, so the read-only +// window leaves the oversized log as it is instead of bounding it. +test('#2724: a read-only window does not trim an oversized log', async (t) => { + const dir = home(t) + const log = join(dir, 'decisions.jsonl') + const before = seed() + writeFileSync(log, before) + const only = writer(dir, { readOnly: SITUATION }) + + for (let i = 0; i < 3; i++) assert.match(await only.run({ option: `oversized ${i}`, choice: 'used' }), /read-only/) + + assert.equal(readFileSync(log, 'utf8'), before, 'the log is still the file the writer left') + assert.deepEqual(readdirSync(dir).filter(name => name.endsWith('.tmp')), [], 'no temp file was written') +}) diff --git a/patches/ds-bot/files/test/decisions.test.js b/patches/ds-bot/files/test/decisions.test.js index 90f9d74f6..62683f328 100644 --- a/patches/ds-bot/files/test/decisions.test.js +++ b/patches/ds-bot/files/test/decisions.test.js @@ -1,5 +1,5 @@ import assert from 'node:assert/strict' -import { existsSync, linkSync, lstatSync, mkdtempSync, readFileSync, readlinkSync, rmSync, symlinkSync, writeFileSync } from 'node:fs' +import { existsSync, linkSync, lstatSync, mkdtempSync, readFileSync, readdirSync, readlinkSync, rmSync, symlinkSync, writeFileSync } from 'node:fs' import { tmpdir } from 'node:os' import { join } from 'node:path' import { test } from 'node:test' @@ -132,9 +132,11 @@ test('a linked decision log is refused, not written through', async (t) => { }) // Housekeeping writes a temp name beside the log and renames it over the log, so the temp name is a -// place this code writes (#2103). A link left there must be refused before the write, not taken: -// otherwise the retained log is written through it and the log itself becomes a link. -test('#2103: a linked temp name does not take the trim; the log stays a plain file', async (t) => { +// place this code writes (#2103) — but it is the writing host's own name now, `...tmp` +// like the resume notes (#2724), not the fixed `/decisions.jsonl.tmp` every writer on the home +// shared. A link planted at that old name is not a name this code takes: it keeps its bytes and its +// target, the trim bounds the log, and the log itself stays a plain file. +test('#2724: the trim writes its own temp name, so a link at the old fixed name is left alone', async (t) => { const line = (n) => `${JSON.stringify({ time: 1_000 + n, bot: 'a', botName: 'Chief', option: `kept ${n}`, choice: 'used' })}\n` const full = (n) => Array.from({ length: n }, (_, i) => line(i)).join('') @@ -147,44 +149,34 @@ test('#2103: a linked temp name does not take the trim; the log stays a plain fi writeFileSync(target, before) const log = join(home, 'decisions.jsonl') writeFileSync(log, full(2_000)) - symlinkSync(target, `${log}.tmp`) + const planted = `${log}.tmp` + symlinkSync(target, planted) const warnings = [] ctx.logger.warn = (...args) => warnings.push(args.join(' ')) const first = await tool('record_decision', { option: 'Trigger the trim', choice: 'used' }) const second = await tool('record_decision', { option: 'Trigger it again', choice: 'rejected' }) - assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the temp link is not written through') - assert.equal(lstatSync(log).isSymbolicLink(), false, 'the log is still a plain file, not the link') + assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the planted link is not written through') + assert.equal(lstatSync(planted).isSymbolicLink(), true, 'the planted link is still there') + assert.equal(readlinkSync(planted), target, 'the planted link still names the same file') + assert.equal(lstatSync(log).isSymbolicLink(), false, 'the log is a plain file of its own') const lines = readFileSync(log, 'utf8').split('\n').filter(Boolean) - assert.equal(lines.length, 2_002, 'the refused trim leaves the log as it was, plus the two new lines') + assert.equal(lines.length, 2_000, 'the trim bounds the log at KEPT lines') for (const lineText of lines) assert.doesNotThrow(() => JSON.parse(lineText), 'every line stays a valid entry') assert.equal(JSON.parse(lines.at(-1)).option, 'Trigger it again') - assert.doesNotMatch(first, /^Recorded:/, 'the answer does not claim a clean record when the trim was refused') - assert.doesNotMatch(second, /^Recorded:/) - assert.equal(warnings.length, 1, 'one warning for the temp name, not one per record') - assert.match(warnings[0], /decisions\.jsonl\.tmp/) - assert.match(warnings[0], /not a plain file/) - - // The healthy path is untouched: with a normal temp name the trim still bounds the log. - const healthy = await boot({ decisions: true }) - t.after(healthy.stop) - const plain = join(healthy.home, 'decisions.jsonl') - writeFileSync(plain, full(2_000)) - const healthyWarnings = [] - healthy.ctx.logger.warn = (...args) => healthyWarnings.push(args.join(' ')) - assert.match(await healthy.tool('record_decision', { option: 'Trim normally', choice: 'used' }), /^Recorded:/) - const kept = readFileSync(plain, 'utf8').split('\n').filter(Boolean) - assert.equal(kept.length, 2_000, 'the trim keeps the newest KEPT lines') - assert.equal(JSON.parse(kept.at(-1)).option, 'Trim normally') - assert.equal(existsSync(`${plain}.tmp`), false, 'the healthy trim renames its temp name away') - assert.deepEqual(healthyWarnings, []) + assert.match(first, /^Recorded:/, 'the trim went through, so the answer is clean') + assert.match(second, /^Recorded:/) + assert.deepEqual(warnings, [], 'nothing is refused: the planted name is not one this code writes') + const leftovers = readdirSync(home).filter(name => name.endsWith('.tmp') && name !== 'decisions.jsonl.tmp') + assert.deepEqual(leftovers, [], 'the trim renames its own temp name away') }) -// The trim's temp name can be a hard link, which `lstat` reports as a plain file: the retained log -// would be written into the inode the other name holds. It is refused before the write, warned -// once, and the log keeps its lines. -test('#P-hardlink: a hard link at the trim temp name does not take the trim', async (t) => { +// The temp name is a leaf like the log itself (temp-name sweep): a hard link there is a plain file to +// `lstat` while the write would land in the inode the other name holds. The guard still refuses that, +// and a hard link at the old fixed name is no way to reach it: the outside bytes stay, and the log is +// bounded by a temp name of its own. +test('#2724: a hard link at the old fixed temp name does not take the trim', async (t) => { const line = (n) => `${JSON.stringify({ time: 1_000 + n, bot: 'a', botName: 'Chief', option: `kept ${n}`, choice: 'used' })}\n` const full = (n) => Array.from({ length: n }, (_, i) => line(i)).join('') @@ -197,20 +189,20 @@ test('#P-hardlink: a hard link at the trim temp name does not take the trim', as writeFileSync(target, before) const log = join(home, 'decisions.jsonl') writeFileSync(log, full(2_000)) - linkSync(target, `${log}.tmp`) + const planted = `${log}.tmp` + linkSync(target, planted) const warnings = [] ctx.logger.warn = (...args) => warnings.push(args.join(' ')) const first = await tool('record_decision', { option: 'Trigger the trim', choice: 'used' }) assert.equal(readFileSync(target, 'utf8'), before, 'the shared inode keeps its bytes') - assert.equal(lstatSync(target).nlink, 2, 'the outside file still carries the temp name') + assert.equal(lstatSync(target).nlink, 2, 'the outside file still carries the planted name') const lines = readFileSync(log, 'utf8').split('\n').filter(Boolean) - assert.equal(lines.length, 2_001, 'the refused trim leaves the log as it was, plus the new line') - assert.doesNotMatch(first, /^Recorded:/, 'the answer does not claim a clean record') - assert.equal(warnings.length, 1, 'one warning for the temp name') - assert.match(warnings[0], /decisions\.jsonl\.tmp/) - assert.match(warnings[0], /not a plain file/) + assert.equal(lines.length, 2_000, 'the trim bounds the log at KEPT lines') + assert.equal(JSON.parse(lines.at(-1)).option, 'Trigger the trim') + assert.match(first, /^Recorded:/, 'the trim went through, so the answer is clean') + assert.deepEqual(warnings, []) }) // #2159: a hard link at the log is a plain file to `lstat` while its bytes are also a name outside