From 442e2feb14d9ca9a77dca467e9129b71723e82bb Mon Sep 17 00:00:00 2001 From: Day Dreamer <87640074+HugoXK@users.noreply.github.com> Date: Wed, 4 Nov 2026 19:12:54 +0800 Subject: [PATCH] host: the report names what the last append attempt met `leafRefusedNow` was cleared only when an append landed, so the failure branch left it as the first refusal had set it: a host whose linked leaf became a plain `0444` file met `EACCES` on the next append while the report still said `not written (not a plain file of its own)` -- a claim about a file the leaf no longer is. The flag now starts each attempt false and `refuseLeaf()` sets it again, so the line describes the last attempt: a `0444` leaf reads `not written (EACCES)`, a leaf that lands reads `recording`, and a leaf that is a link reads the guard's sentence. `refusedLeaf` and its one stderr line per host are untouched (#2089), and `clear()` keeps its three answers (#2364). --- .../2383-diag-log-write-failure.fixed.md | 1 + core/src/host/diagnostics.js | 28 ++- core/test/diagnostics.test.js | 161 +++++++++++++++++ docs/subsystems/core-host.md | 2 +- patches/ds-bot/0001-core-fixes.patch | 47 ++++- patches/ds-bot/0007-version-and-tooling.patch | 163 +++++++++++++++++- 6 files changed, 393 insertions(+), 9 deletions(-) create mode 100644 changelog.d/2383-diag-log-write-failure.fixed.md diff --git a/changelog.d/2383-diag-log-write-failure.fixed.md b/changelog.d/2383-diag-log-write-failure.fixed.md new file mode 100644 index 00000000..1ad1c01c --- /dev/null +++ b/changelog.d/2383-diag-log-write-failure.fixed.md @@ -0,0 +1 @@ +The diagnostics report behind Settings → Feedback's **Report on GitHub** now says whether FlyBot's own error log is being written: `diagnostics log: recording` while appends land, `not written (EACCES)` (or the code the disk gave) after an append it refused, and `not written (not a plain file of its own)` when `logs/diagnostics.jsonl` is a link or another file's second name. A support bundle therefore no longer lists recent errors whose file is missing or short without saying why; a host with the log turned off adds no line ([#2383](https://github.com/ThinkFlowLab/FlyBot/issues/2383)). diff --git a/core/src/host/diagnostics.js b/core/src/host/diagnostics.js index d70211cc..aa0ee006 100644 --- a/core/src/host/diagnostics.js +++ b/core/src/host/diagnostics.js @@ -84,7 +84,10 @@ export function reportMarkdown({ facts, client = {}, entries = [], clientEntries // The journal is only mentioned while the host runs one: an off journal is not a fact about // this host, and a stopped one is exactly what a report about a bug it was meant to catch misses. const journal = facts.stateJournal === undefined ? [] : ['', `state journal: ${facts.stateJournal}`] - const out = [...lines, ...journal, ''] + // The log's own line, in the journal's shape (#2134): a host whose log is off says nothing, and + // every other bundle gets the one fact the recent errors cannot show — whether they were written. + const log = facts.diagnosticsLog === undefined ? [] : ['', `diagnostics log: ${facts.diagnosticsLog}`] + const out = [...lines, ...journal, ...log, ''] out.push(recent.length === 0 ? 'No host errors recorded.' : `Recent host errors (${recent.length} of ${entries.length}, oldest first):`) if (recent.length > 0) out.push('```', ...recent.map(entryLine), '```') const stacks = recent.filter(entry => entry.stack).slice(-3) @@ -123,7 +126,10 @@ export function install(rt) { const toFile = config.diagnosticsFile !== false let fresh = [] let writing = Promise.resolve() + // `fileFailed` keeps stderr to one line per host; `fileFailure` is the reason the report shows, + // and a later append that lands clears it again so the line describes this host's log now. let fileFailed = false + let fileFailure const clean = text => cleanText(text, { redact: rt.redactSecrets }) @@ -143,8 +149,14 @@ export function install(rt) { // The log is one leaf file under the home, so a link there is not a place to write (#2089). The // check sits inside the chain, before the append and before the size rename, so a linked leaf is // left alone entirely; one line on stderr per host says so, without the home folder in it. + // `refusedLeaf` is that latch and never clears. The report answers a different question — what the + // last append attempt met — so `leafRefusedNow` is cleared when an attempt starts and a refusal + // sets it again; an append that fails for another reason leaves it clear, and `fileFailure` says + // which reason that was. let refusedLeaf = false + let leafRefusedNow = false const refuseLeaf = () => { + leafRefusedNow = true if (refusedLeaf) return refusedLeaf = true console.error('[ds-bot] diagnostics log is not a plain file of its own; nothing was written there') @@ -153,15 +165,18 @@ export function install(rt) { const append = (entry) => { if (!toFile) return writing = writing.then(async () => { + leafRefusedNow = false if (await fileKind(logPath) === 'other') { refuseLeaf(); return } await mkdir(dirname(logPath), { recursive: true }) const size = await stat(logPath).then(info => info.size, () => 0) if (size > LOG_MAX_BYTES) await rename(logPath, `${logPath}.1`) await appendFile(logPath, `${JSON.stringify(entry)}\n`, 'utf8') + fileFailure = undefined }).catch((error) => { + fileFailure = error?.code ?? clean(error?.message ?? String(error)) if (fileFailed) return fileFailed = true - console.error('[ds-bot] diagnostics log not written:', error?.code ?? clean(error?.message ?? String(error))) + console.error('[ds-bot] diagnostics log not written:', fileFailure) }) } @@ -246,6 +261,15 @@ export function install(rt) { : journal.recording ? (readOnly ? 'paused (this window is read-only)' : journal.opened === false ? 'not started (opens with the first save)' : 'recording') : `stopped (${clean(journal.because)})`, + // Where those errors are kept is the other half of that sentence, in the same shape: a host + // with the log off says nothing (#2134), a host whose appends land says so, and a refused + // leaf or a failed append names its own reason — the words stderr already used, never the + // folder, and never a claim about a file behind a link this host did not write (#2089). Both + // reasons are read as they stand now, not as the stderr latches left them (#2383). + diagnosticsLog: !toFile ? undefined + : leafRefusedNow ? 'not written (not a plain file of its own)' + : fileFailure ? `not written (${fileFailure})` + : 'recording', } } diff --git a/core/test/diagnostics.test.js b/core/test/diagnostics.test.js index 795c62cc..6cc4c658 100644 --- a/core/test/diagnostics.test.js +++ b/core/test/diagnostics.test.js @@ -350,6 +350,167 @@ test('a state journal that has not opened says it starts with the first save (#2 assert.equal(held.facts.stateJournal, 'paused (this window is read-only)') }) +// #2383: the report is what a user hands over, and it never said that this host's own log file +// could not be written. The reason was already computed for stderr (`fileFailed`, `refusedLeaf`) +// and never reached `facts()`/`reportMarkdown()`, so a support bundle showed the recent errors +// without the one sentence that explains why their file is missing or short. The line follows the +// journal's shape (#2134): a host with the log off adds none, a host with it on says whether it is +// recording or why it is not, and it never carries the home folder. +test('the report says the diagnostics log could not be written (#2383)', async (t) => { + if (process.getuid?.() === 0) { + t.skip('root writes a leaf without its write bit') + return + } + const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) + t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) + mkdirSync(join(home, 'logs'), { recursive: true }) + const logPath = join(home, 'logs', 'diagnostics.jsonl') + writeFileSync(logPath, 'OLD LINE\n') + chmodSync(logPath, 0o444) + + const stderr = [] + const quiet = t.mock.method(console, 'error', (...args) => stderr.push(args.join(' '))) + const rt = host(home) + rt.warn('ds-bot: a line the log refuses') + await rt.dispose() + const report = await rt.diagnostics.report({}) + quiet.mock.restore() + + assert.equal(report.facts.diagnosticsLog, 'not written (EACCES)', 'the report carries the reason, not only stderr') + assert.match(report.markdown, /^diagnostics log: not written \(EACCES\)$/m) + assert.equal(stderr.filter(line => /not written/.test(line)).length, 1, 'stderr keeps its one line') + assert.equal(report.markdown.includes(home), false, 'the line never carries the home folder') + assert.equal(readFileSync(logPath, 'utf8'), 'OLD LINE\n', 'the leaf keeps its bytes') +}) + +// The other reason the log is not written is the leaf guard (#2089): a link at the path is not +// this host's to write. The report names the refusal in the same words stderr uses, and the file +// behind the link keeps its bytes (the refusal itself is unchanged). +test('the report says the diagnostics log is not a plain file of its own (#2383)', async (t) => { + const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) + t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) + const elsewhere = mkdtempSync(join(tmpdir(), 'ds-bot-diag-target-')) + t.after(() => rmSync(elsewhere, { recursive: true, force: true, maxRetries: 5 })) + mkdirSync(join(home, 'logs'), { recursive: true }) + const target = join(elsewhere, 'diagnostics.jsonl') + const before = 'PRE-EXISTING LINE\n' + writeFileSync(target, before) + symlinkSync(target, join(home, 'logs', 'diagnostics.jsonl')) + + const rt = host(home) + rt.warn('ds-bot: first entry') + await rt.dispose() + const report = await rt.diagnostics.report({}) + + assert.equal(report.facts.diagnosticsLog, 'not written (not a plain file of its own)') + assert.match(report.markdown, /^diagnostics log: not written \(not a plain file of its own\)$/m) + assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the link keeps its bytes') + assert.equal(report.markdown.includes(home), false, 'the line never carries the home folder') +}) + +// The refusal on stderr is a latch for the host's lifetime (#2089): one line per host, however many +// entries the guard drops. The report line answers a different question — what the leaf is now — so +// the two must not share one flag. A host whose link was replaced by a file of its own writes the +// next entry into that leaf, and the report has to say `recording`; the stderr latch keeps its one +// line and is not refreshed by the landing entry. +test('the report says recording again once the leaf is readable again (#2383)', async (t) => { + const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) + t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) + const elsewhere = mkdtempSync(join(tmpdir(), 'ds-bot-diag-target-')) + t.after(() => rmSync(elsewhere, { recursive: true, force: true, maxRetries: 5 })) + mkdirSync(join(home, 'logs'), { recursive: true }) + const target = join(elsewhere, 'diagnostics.jsonl') + const before = 'PRE-EXISTING LINE\n' + writeFileSync(target, before) + const logPath = join(home, 'logs', 'diagnostics.jsonl') + symlinkSync(target, logPath) + + const stderr = [] + const quiet = t.mock.method(console, 'error', (...args) => stderr.push(args.join(' '))) + const rt = host(home) + rt.warn('ds-bot: a line the link refuses') + // The refusal is written inside the background chain, so wait for it rather than for a pause: the + // link has to be gone only after the entry was actually refused, not only after it was queued. + const refused = () => stderr.some(line => /is not a plain file of its own/.test(line)) + for (let waited = 0; !refused() && waited < 5000; waited += 20) await new Promise(resolve => setTimeout(resolve, 20)) + assert.equal(refused(), true, 'the guard refused the entry while the leaf was a link') + rmSync(logPath) + rt.warn('ds-bot: a line that lands') + await rt.dispose() + const report = await rt.diagnostics.report({}) + quiet.mock.restore() + + assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the link keeps its bytes') + const written = readFileSync(logPath, 'utf8').trim().split('\n') + assert.equal(written.length, 1, 'the entry landed in the leaf of its own') + assert.match(written[0], /a line that lands/) + assert.equal(report.facts.diagnosticsLog, 'recording', 'the report describes the leaf as it is now') + assert.match(report.markdown, /^diagnostics log: recording$/m) + const refusals = stderr.filter(line => /is not a plain file of its own/.test(line)) + assert.equal(refusals.length, 1, 'the stderr latch keeps its one line per host') +}) + +// The two reasons are read as the leaf stands when the report is built, and the leaf can change +// between attempts (#2383): a host whose link was refused and whose leaf is then a plain 0444 file +// meets EACCES on the next append, so the report has to name EACCES rather than the earlier refusal. +// The stderr latches keep their own lines: one guard line and one failure line for the host. +test('the report names the reason the last append met (#2383)', async (t) => { + if (process.getuid?.() === 0) { + t.skip('root writes a leaf without its write bit') + return + } + const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) + t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) + const elsewhere = mkdtempSync(join(tmpdir(), 'ds-bot-diag-target-')) + t.after(() => rmSync(elsewhere, { recursive: true, force: true, maxRetries: 5 })) + mkdirSync(join(home, 'logs'), { recursive: true }) + const target = join(elsewhere, 'diagnostics.jsonl') + const before = 'PRE-EXISTING LINE\n' + writeFileSync(target, before) + const logPath = join(home, 'logs', 'diagnostics.jsonl') + symlinkSync(target, logPath) + + const stderr = [] + const quiet = t.mock.method(console, 'error', (...args) => stderr.push(args.join(' '))) + const rt = host(home) + rt.warn('ds-bot: a line the link refuses') + const refused = () => stderr.some(line => /is not a plain file of its own/.test(line)) + for (let waited = 0; !refused() && waited < 5000; waited += 20) await new Promise(resolve => setTimeout(resolve, 20)) + assert.equal(refused(), true, 'the guard refused the entry while the leaf was a link') + rmSync(logPath) + writeFileSync(logPath, 'OLD LINE\n') + chmodSync(logPath, 0o444) + rt.warn('ds-bot: a line the plain leaf refuses') + await rt.dispose() + const report = await rt.diagnostics.report({}) + quiet.mock.restore() + + assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the link keeps its bytes') + assert.equal(readFileSync(logPath, 'utf8'), 'OLD LINE\n', 'the leaf keeps its bytes') + assert.equal(report.facts.diagnosticsLog, 'not written (EACCES)', 'the reason is the one the last attempt met') + assert.match(report.markdown, /^diagnostics log: not written \(EACCES\)$/m) + assert.equal(stderr.filter(line => /is not a plain file of its own/.test(line)).length, 1, 'the stderr latch keeps its one guard line') + assert.equal(stderr.filter(line => /not written: EACCES/.test(line)).length, 1, 'the failure keeps its one line') +}) + +// The two ordinary states, in the shape #2134 gave the journal: off adds no line at all, on says +// the log is recording — the answer a bundle needs to tell "no errors were logged" from "the log +// could not take them". +test('the report says nothing about the log while it is off, and recording while it is on (#2383)', async (t) => { + const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) + t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) + const off = await host(home, { config: { diagnosticsFile: false } }).diagnostics.report({}) + assert.equal(off.facts.diagnosticsLog, undefined, 'a host without the log says nothing about it') + assert.doesNotMatch(off.markdown, /diagnostics log:/) + + const rt = host(home) + rt.warn('ds-bot: a line that lands') + await rt.dispose() + const live = await rt.diagnostics.report({}) + assert.equal(live.facts.diagnosticsLog, 'recording') + assert.match(live.markdown, /^diagnostics log: recording$/m) +}) + // The Read-only row answered one constant for every window that may not write, but the store // answers three ways (#2153): `stuck` (the team file cannot be read) is not a live lock at all, // and a report that calls a newer or unreadable team file "another dsh holds the team" sends the diff --git a/docs/subsystems/core-host.md b/docs/subsystems/core-host.md index 00a04200..25a6654e 100644 --- a/docs/subsystems/core-host.md +++ b/docs/subsystems/core-host.md @@ -406,7 +406,7 @@ Work a member hands a Bot with `message_bot` from its group Session runs in a hi - Host diagnostics never depend on `ctx.logger`: DSH may export no logger, and a test or plugin-local host may carry one without `warn`. `rt.warn` still writes stderr and the diagnostics log in that case (`src/host/diagnostics.js`). Plugins reach the same log through `flybot.warn` (#68); see [plugin-runtime](plugin-runtime.md). - The `Read-only` row of a report repeats this host's own answer rather than one constant: `rt.readOnly()` is `undefined` while the window writes, a sentence about a live `state.lock` when another dsh holds the team, and a sentence about the team file when it is `stuck` (a newer version, a file that will not parse, an unreadable path). The report shows that sentence — `clean(cut(answer, 200))`, so saved keys, the home folder and `|` are handled like any other report text — the same one the sidebar shows, so a newer team file reads `update FlyBot` and an unreadable one reads `could not be read`, never `another dsh holds the team`; a writable window still adds no row ([#2167](https://github.com/ThinkFlowLab/FlyBot/issues/2167)). -- The log itself is one leaf file under the home, and a write asks it before it appends ([#2089](https://github.com/ThinkFlowLab/FlyBot/issues/2089)): when `logs/diagnostics.jsonl` is a link, a hard link or anything other than a plain file of its own — the line is dropped with one line on stderr that carries no home folder, the entries stay readable in memory, and `clear` leaves a file behind such a link untouched rather than truncating it. Past 1 MB the leaf moves aside to `diagnostics.jsonl.1`, and `clear` removes that name as well — in the same write chain, behind the same leaf guard — so a cleared log leaves no rotated lines behind. The truncate runs first and the removal only after it: a leaf that cannot be emptied keeps the rotated copy where it is, because those lines are then the only copy left of them. The removal keeps a `try` of its own: a copy the host cannot remove (a directory under that name, a folder without its write bit) keeps its bytes, is named on one stderr line that carries no folder, and never turns a Clear that emptied the leaf into one that leaves every line on disk. The truncate keeps a `try` of its own for the same reason ([#2364](https://github.com/ThinkFlowLab/FlyBot/issues/2364)): the leaf guard asks the file's kind, not its mode, so a plain `0444` leaf passes it and the write fails with `EACCES` — that failure is named on one stderr line, `[ds-bot] diagnostics log not truncated: `, which carries no folder, the same way `append` names its own; the answer it leaves behind is `leaf: 'kept'`. `clear` answers with what it did — `{ leaf: 'truncated' | 'kept' | 'absent', rotated: 'removed' | 'kept' | 'none' }` — and `diagnostics-clear` passes that result through instead of a constant, so the Feedback page's sentence matches it: the unchanged one, one that names the leftover `logs/diagnostics.jsonl.1`, or one that does not claim a cleared log ([#2360](https://github.com/ThinkFlowLab/FlyBot/issues/2360)). `rotated` says what this call did to that name: `removed` when it deleted one, `kept` when one was there and still is — the removal failed, or the truncate failed first and nothing was removed — and `none` when there was none; a leaf the guard refuses never reaches the probe, so it answers `none`. What the window reads moves only with an emptied leaf: `entries()` answers the old lines through `cleared` plus the live ones in `fresh`, and `logText()` behind the Download reads the same, so a Clear that leaves the leaf full changes neither of them — the page can no longer show "not cleared" next to "0 recent errors" while every byte is still on disk. Only a leaf that really was truncated clears both — plus a host that keeps no log file at all (`diagnosticsFile: false`), which has no file and no list to keep; an `ENOENT` write leaves both alone like every other refusal ([#2364](https://github.com/ThinkFlowLab/FlyBot/issues/2364)). That is the answer, one stderr line and nothing else that moves: the truncate, the `fileKind` guard, the removal rule and the `try` keep the behaviour they had, and a leaf that is not there yet still gets the empty file the write always landed there. `absent` therefore means nothing was on disk to clear — this host keeps no log file (`diagnosticsFile: false`), or the folder is not there so the write found nothing to truncate — not a leaf the call refused. +- The log itself is one leaf file under the home, and a write asks it before it appends ([#2089](https://github.com/ThinkFlowLab/FlyBot/issues/2089)): when `logs/diagnostics.jsonl` is a link, a hard link or anything other than a plain file of its own — the line is dropped with one line on stderr that carries no home folder, the entries stay readable in memory, and `clear` leaves a file behind such a link untouched rather than truncating it. Past 1 MB the leaf moves aside to `diagnostics.jsonl.1`, and `clear` removes that name as well — in the same write chain, behind the same leaf guard — so a cleared log leaves no rotated lines behind. The truncate runs first and the removal only after it: a leaf that cannot be emptied keeps the rotated copy where it is, because those lines are then the only copy left of them. The removal keeps a `try` of its own: a copy the host cannot remove (a directory under that name, a folder without its write bit) keeps its bytes, is named on one stderr line that carries no folder, and never turns a Clear that emptied the leaf into one that leaves every line on disk. The truncate keeps a `try` of its own for the same reason ([#2364](https://github.com/ThinkFlowLab/FlyBot/issues/2364)): the leaf guard asks the file's kind, not its mode, so a plain `0444` leaf passes it and the write fails with `EACCES` — that failure is named on one stderr line, `[ds-bot] diagnostics log not truncated: `, which carries no folder, the same way `append` names its own; the answer it leaves behind is `leaf: 'kept'`. `clear` answers with what it did — `{ leaf: 'truncated' | 'kept' | 'absent', rotated: 'removed' | 'kept' | 'none' }` — and `diagnostics-clear` passes that result through instead of a constant, so the Feedback page's sentence matches it: the unchanged one, one that names the leftover `logs/diagnostics.jsonl.1`, or one that does not claim a cleared log ([#2360](https://github.com/ThinkFlowLab/FlyBot/issues/2360)). `rotated` says what this call did to that name: `removed` when it deleted one, `kept` when one was there and still is — the removal failed, or the truncate failed first and nothing was removed — and `none` when there was none; a leaf the guard refuses never reaches the probe, so it answers `none`. What the window reads moves only with an emptied leaf: `entries()` answers the old lines through `cleared` plus the live ones in `fresh`, and `logText()` behind the Download reads the same, so a Clear that leaves the leaf full changes neither of them — the page can no longer show "not cleared" next to "0 recent errors" while every byte is still on disk. Only a leaf that really was truncated clears both — plus a host that keeps no log file at all (`diagnosticsFile: false`), which has no file and no list to keep; an `ENOENT` write leaves both alone like every other refusal ([#2364](https://github.com/ThinkFlowLab/FlyBot/issues/2364)). That is the answer, one stderr line and nothing else that moves: the truncate, the `fileKind` guard, the removal rule and the `try` keep the behaviour they had, and a leaf that is not there yet still gets the empty file the write always landed there. `absent` therefore means nothing was on disk to clear — this host keeps no log file (`diagnosticsFile: false`), or the folder is not there so the write found nothing to truncate — not a leaf the call refused. The report says whether that same file is being written, in the shape the journal line already has: `diagnostics log: recording` while the appends land, `not written ()` after an append the host could not make, and `not written (not a plain file of its own)` when the leaf guard refused the write, so a bundle that lists recent errors also says when the file holding them is missing or short and why. The value follows the last append attempt, not the first refusal: a host that puts a plain file of its own back writes the next entry into it and says `recording` again, and a leaf that has become a plain `0444` file says `not written (EACCES)` on the next attempt, while the guard's own stderr line stays one per host ([#2089](https://github.com/ThinkFlowLab/FlyBot/issues/2089)); a host with the log off (`diagnosticsFile: false`) adds no line at all, the rule the journal line keeps ([#2383](https://github.com/ThinkFlowLab/FlyBot/issues/2383)). ### Untrusted fences in every shared room diff --git a/patches/ds-bot/0001-core-fixes.patch b/patches/ds-bot/0001-core-fixes.patch index 441cee1b..d738ff9c 100644 --- a/patches/ds-bot/0001-core-fixes.patch +++ b/patches/ds-bot/0001-core-fixes.patch @@ -4996,7 +4996,7 @@ diff --git a/src/host/diagnostics.js b/src/host/diagnostics.js row('DSH', facts.dshVersion), row('Surface', client.surface), row('OS', facts.os), -@@ -78,11 +78,14 @@ export function reportMarkdown({ facts, client = {}, entries = [], clientEntries +@@ -78,11 +78,17 @@ export function reportMarkdown({ facts, client = {}, entries = [], clientEntries row('Read-only', facts.readOnly), ].filter(Boolean) const recent = entries.slice(-REPORT_ENTRIES) @@ -5004,7 +5004,10 @@ diff --git a/src/host/diagnostics.js b/src/host/diagnostics.js + // The journal is only mentioned while the host runs one: an off journal is not a fact about + // this host, and a stopped one is exactly what a report about a bug it was meant to catch misses. + const journal = facts.stateJournal === undefined ? [] : ['', `state journal: ${facts.stateJournal}`] -+ const out = [...lines, ...journal, ''] ++ // The log's own line, in the journal's shape (#2134): a host whose log is off says nothing, and ++ // every other bundle gets the one fact the recent errors cannot show — whether they were written. ++ const log = facts.diagnosticsLog === undefined ? [] : ['', `diagnostics log: ${facts.diagnosticsLog}`] ++ const out = [...lines, ...journal, ...log, ''] out.push(recent.length === 0 ? 'No host errors recorded.' : `Recent host errors (${recent.length} of ${entries.length}, oldest first):`) if (recent.length > 0) out.push('```', ...recent.map(entryLine), '```') const stacks = recent.filter(entry => entry.stack).slice(-3) @@ -5025,15 +5028,32 @@ diff --git a/src/host/diagnostics.js b/src/host/diagnostics.js return undefined } -@@ -134,9 +134,20 @@ export function install(rt) { +@@ -117,7 +117,10 @@ export function install(rt) { + const toFile = config.diagnosticsFile !== false + let fresh = [] + let writing = Promise.resolve() ++ // `fileFailed` keeps stderr to one line per host; `fileFailure` is the reason the report shows, ++ // and a later append that lands clears it again so the line describes this host's log now. + let fileFailed = false ++ let fileFailure + + const clean = text => cleanText(text, { redact: rt.redactSecrets }) + +@@ -134,20 +134,53 @@ export function install(rt) { : Promise.resolve([]) let cleared = 0 + // The log is one leaf file under the home, so a link there is not a place to write (#2089). The + // check sits inside the chain, before the append and before the size rename, so a linked leaf is + // left alone entirely; one line on stderr per host says so, without the home folder in it. ++ // `refusedLeaf` is that latch and never clears. The report answers a different question — what the ++ // last append attempt met — so `leafRefusedNow` is cleared when an attempt starts and a refusal ++ // sets it again; an append that fails for another reason leaves it clear, and `fileFailure` says ++ // which reason that was. + let refusedLeaf = false ++ let leafRefusedNow = false + const refuseLeaf = () => { ++ leafRefusedNow = true + if (refusedLeaf) return + refusedLeaf = true + console.error('[ds-bot] diagnostics log is not a plain file of its own; nothing was written there') @@ -5042,11 +5062,19 @@ diff --git a/src/host/diagnostics.js b/src/host/diagnostics.js const append = (entry) => { if (!toFile) return writing = writing.then(async () => { ++ leafRefusedNow = false + if (await fileKind(logPath) === 'other') { refuseLeaf(); return } await mkdir(dirname(logPath), { recursive: true }) const size = await stat(logPath).then(info => info.size, () => 0) if (size > LOG_MAX_BYTES) await rename(logPath, `${logPath}.1`) -@@ -148,6 +148,19 @@ export function install(rt) { + await appendFile(logPath, `${JSON.stringify(entry)}\n`, 'utf8') ++ fileFailure = undefined + }).catch((error) => { ++ fileFailure = error?.code ?? clean(error?.message ?? String(error)) + if (fileFailed) return + fileFailed = true +- console.error('[ds-bot] diagnostics log not written:', error?.code ?? clean(error?.message ?? String(error))) ++ console.error('[ds-bot] diagnostics log not written:', fileFailure) }) } @@ -5086,7 +5114,7 @@ diff --git a/src/host/diagnostics.js b/src/host/diagnostics.js return { botVersion: ownVersion(), dshVersion: dshVersion(), -@@ -199,12 +199,24 @@ export function install(rt) { +@@ -199,12 +199,33 @@ export function install(rt) { node: process.version, team: `${count(bots.length, 'Bot', 'Bots')}, ${rt.state.mainBotIds.length} Main, ${count(groups, 'group chat', 'group chats')}`, models: models.length > 0 ? models.join(', ') : undefined, @@ -5104,6 +5132,15 @@ diff --git a/src/host/diagnostics.js b/src/host/diagnostics.js + : journal.recording ? (readOnly ? 'paused (this window is read-only)' + : journal.opened === false ? 'not started (opens with the first save)' : 'recording') + : `stopped (${clean(journal.because)})`, ++ // Where those errors are kept is the other half of that sentence, in the same shape: a host ++ // with the log off says nothing (#2134), a host whose appends land says so, and a refused ++ // leaf or a failed append names its own reason — the words stderr already used, never the ++ // folder, and never a claim about a file behind a link this host did not write (#2089). Both ++ // reasons are read as they stand now, not as the stderr latches left them (#2383). ++ diagnosticsLog: !toFile ? undefined ++ : leafRefusedNow ? 'not written (not a plain file of its own)' ++ : fileFailure ? `not written (${fileFailure})` ++ : 'recording', } } diff --git a/patches/ds-bot/0007-version-and-tooling.patch b/patches/ds-bot/0007-version-and-tooling.patch index 5789f221..7a99adc9 100644 --- a/patches/ds-bot/0007-version-and-tooling.patch +++ b/patches/ds-bot/0007-version-and-tooling.patch @@ -1005,7 +1005,7 @@ diff --git a/test/diagnostics.test.js b/test/diagnostics.test.js test('diagnostics append fallback redacts an error message', async (t) => { const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) -@@ -133,6 +133,145 @@ test('diagnostics append fallback redacts an error message', async (t) => { +@@ -133,6 +133,306 @@ test('diagnostics append fallback redacts an error message', async (t) => { assert.match(stderr.join('\n'), /api_key=\[hidden\]/) }) @@ -1084,6 +1084,167 @@ diff --git a/test/diagnostics.test.js b/test/diagnostics.test.js + assert.equal(held.facts.stateJournal, 'paused (this window is read-only)') +}) + ++// #2383: the report is what a user hands over, and it never said that this host's own log file ++// could not be written. The reason was already computed for stderr (`fileFailed`, `refusedLeaf`) ++// and never reached `facts()`/`reportMarkdown()`, so a support bundle showed the recent errors ++// without the one sentence that explains why their file is missing or short. The line follows the ++// journal's shape (#2134): a host with the log off adds none, a host with it on says whether it is ++// recording or why it is not, and it never carries the home folder. ++test('the report says the diagnostics log could not be written (#2383)', async (t) => { ++ if (process.getuid?.() === 0) { ++ t.skip('root writes a leaf without its write bit') ++ return ++ } ++ const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) ++ t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) ++ mkdirSync(join(home, 'logs'), { recursive: true }) ++ const logPath = join(home, 'logs', 'diagnostics.jsonl') ++ writeFileSync(logPath, 'OLD LINE\n') ++ chmodSync(logPath, 0o444) ++ ++ const stderr = [] ++ const quiet = t.mock.method(console, 'error', (...args) => stderr.push(args.join(' '))) ++ const rt = host(home) ++ rt.warn('ds-bot: a line the log refuses') ++ await rt.dispose() ++ const report = await rt.diagnostics.report({}) ++ quiet.mock.restore() ++ ++ assert.equal(report.facts.diagnosticsLog, 'not written (EACCES)', 'the report carries the reason, not only stderr') ++ assert.match(report.markdown, /^diagnostics log: not written \(EACCES\)$/m) ++ assert.equal(stderr.filter(line => /not written/.test(line)).length, 1, 'stderr keeps its one line') ++ assert.equal(report.markdown.includes(home), false, 'the line never carries the home folder') ++ assert.equal(readFileSync(logPath, 'utf8'), 'OLD LINE\n', 'the leaf keeps its bytes') ++}) ++ ++// The other reason the log is not written is the leaf guard (#2089): a link at the path is not ++// this host's to write. The report names the refusal in the same words stderr uses, and the file ++// behind the link keeps its bytes (the refusal itself is unchanged). ++test('the report says the diagnostics log is not a plain file of its own (#2383)', async (t) => { ++ const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) ++ t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) ++ const elsewhere = mkdtempSync(join(tmpdir(), 'ds-bot-diag-target-')) ++ t.after(() => rmSync(elsewhere, { recursive: true, force: true, maxRetries: 5 })) ++ mkdirSync(join(home, 'logs'), { recursive: true }) ++ const target = join(elsewhere, 'diagnostics.jsonl') ++ const before = 'PRE-EXISTING LINE\n' ++ writeFileSync(target, before) ++ symlinkSync(target, join(home, 'logs', 'diagnostics.jsonl')) ++ ++ const rt = host(home) ++ rt.warn('ds-bot: first entry') ++ await rt.dispose() ++ const report = await rt.diagnostics.report({}) ++ ++ assert.equal(report.facts.diagnosticsLog, 'not written (not a plain file of its own)') ++ assert.match(report.markdown, /^diagnostics log: not written \(not a plain file of its own\)$/m) ++ assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the link keeps its bytes') ++ assert.equal(report.markdown.includes(home), false, 'the line never carries the home folder') ++}) ++ ++// The refusal on stderr is a latch for the host's lifetime (#2089): one line per host, however many ++// entries the guard drops. The report line answers a different question — what the leaf is now — so ++// the two must not share one flag. A host whose link was replaced by a file of its own writes the ++// next entry into that leaf, and the report has to say `recording`; the stderr latch keeps its one ++// line and is not refreshed by the landing entry. ++test('the report says recording again once the leaf is readable again (#2383)', async (t) => { ++ const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) ++ t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) ++ const elsewhere = mkdtempSync(join(tmpdir(), 'ds-bot-diag-target-')) ++ t.after(() => rmSync(elsewhere, { recursive: true, force: true, maxRetries: 5 })) ++ mkdirSync(join(home, 'logs'), { recursive: true }) ++ const target = join(elsewhere, 'diagnostics.jsonl') ++ const before = 'PRE-EXISTING LINE\n' ++ writeFileSync(target, before) ++ const logPath = join(home, 'logs', 'diagnostics.jsonl') ++ symlinkSync(target, logPath) ++ ++ const stderr = [] ++ const quiet = t.mock.method(console, 'error', (...args) => stderr.push(args.join(' '))) ++ const rt = host(home) ++ rt.warn('ds-bot: a line the link refuses') ++ // The refusal is written inside the background chain, so wait for it rather than for a pause: the ++ // link has to be gone only after the entry was actually refused, not only after it was queued. ++ const refused = () => stderr.some(line => /is not a plain file of its own/.test(line)) ++ for (let waited = 0; !refused() && waited < 5000; waited += 20) await new Promise(resolve => setTimeout(resolve, 20)) ++ assert.equal(refused(), true, 'the guard refused the entry while the leaf was a link') ++ rmSync(logPath) ++ rt.warn('ds-bot: a line that lands') ++ await rt.dispose() ++ const report = await rt.diagnostics.report({}) ++ quiet.mock.restore() ++ ++ assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the link keeps its bytes') ++ const written = readFileSync(logPath, 'utf8').trim().split('\n') ++ assert.equal(written.length, 1, 'the entry landed in the leaf of its own') ++ assert.match(written[0], /a line that lands/) ++ assert.equal(report.facts.diagnosticsLog, 'recording', 'the report describes the leaf as it is now') ++ assert.match(report.markdown, /^diagnostics log: recording$/m) ++ const refusals = stderr.filter(line => /is not a plain file of its own/.test(line)) ++ assert.equal(refusals.length, 1, 'the stderr latch keeps its one line per host') ++}) ++ ++// The two reasons are read as the leaf stands when the report is built, and the leaf can change ++// between attempts (#2383): a host whose link was refused and whose leaf is then a plain 0444 file ++// meets EACCES on the next append, so the report has to name EACCES rather than the earlier refusal. ++// The stderr latches keep their own lines: one guard line and one failure line for the host. ++test('the report names the reason the last append met (#2383)', async (t) => { ++ if (process.getuid?.() === 0) { ++ t.skip('root writes a leaf without its write bit') ++ return ++ } ++ const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) ++ t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) ++ const elsewhere = mkdtempSync(join(tmpdir(), 'ds-bot-diag-target-')) ++ t.after(() => rmSync(elsewhere, { recursive: true, force: true, maxRetries: 5 })) ++ mkdirSync(join(home, 'logs'), { recursive: true }) ++ const target = join(elsewhere, 'diagnostics.jsonl') ++ const before = 'PRE-EXISTING LINE\n' ++ writeFileSync(target, before) ++ const logPath = join(home, 'logs', 'diagnostics.jsonl') ++ symlinkSync(target, logPath) ++ ++ const stderr = [] ++ const quiet = t.mock.method(console, 'error', (...args) => stderr.push(args.join(' '))) ++ const rt = host(home) ++ rt.warn('ds-bot: a line the link refuses') ++ const refused = () => stderr.some(line => /is not a plain file of its own/.test(line)) ++ for (let waited = 0; !refused() && waited < 5000; waited += 20) await new Promise(resolve => setTimeout(resolve, 20)) ++ assert.equal(refused(), true, 'the guard refused the entry while the leaf was a link') ++ rmSync(logPath) ++ writeFileSync(logPath, 'OLD LINE\n') ++ chmodSync(logPath, 0o444) ++ rt.warn('ds-bot: a line the plain leaf refuses') ++ await rt.dispose() ++ const report = await rt.diagnostics.report({}) ++ quiet.mock.restore() ++ ++ assert.equal(readFileSync(target, 'utf8'), before, 'the file behind the link keeps its bytes') ++ assert.equal(readFileSync(logPath, 'utf8'), 'OLD LINE\n', 'the leaf keeps its bytes') ++ assert.equal(report.facts.diagnosticsLog, 'not written (EACCES)', 'the reason is the one the last attempt met') ++ assert.match(report.markdown, /^diagnostics log: not written \(EACCES\)$/m) ++ assert.equal(stderr.filter(line => /is not a plain file of its own/.test(line)).length, 1, 'the stderr latch keeps its one guard line') ++ assert.equal(stderr.filter(line => /not written: EACCES/.test(line)).length, 1, 'the failure keeps its one line') ++}) ++ ++// The two ordinary states, in the shape #2134 gave the journal: off adds no line at all, on says ++// the log is recording — the answer a bundle needs to tell "no errors were logged" from "the log ++// could not take them". ++test('the report says nothing about the log while it is off, and recording while it is on (#2383)', async (t) => { ++ const home = mkdtempSync(join(tmpdir(), 'ds-bot-diag-')) ++ t.after(() => rmSync(home, { recursive: true, force: true, maxRetries: 5 })) ++ const off = await host(home, { config: { diagnosticsFile: false } }).diagnostics.report({}) ++ assert.equal(off.facts.diagnosticsLog, undefined, 'a host without the log says nothing about it') ++ assert.doesNotMatch(off.markdown, /diagnostics log:/) ++ ++ const rt = host(home) ++ rt.warn('ds-bot: a line that lands') ++ await rt.dispose() ++ const live = await rt.diagnostics.report({}) ++ assert.equal(live.facts.diagnosticsLog, 'recording') ++ assert.match(live.markdown, /^diagnostics log: recording$/m) ++}) ++ +// The Read-only row answered one constant for every window that may not write, but the store +// answers three ways (#2153): `stuck` (the team file cannot be read) is not a live lock at all, +// and a report that calls a newer or unreadable team file "another dsh holds the team" sends the