diff --git a/apps/desktop/electron/backend-ready.test.ts b/apps/desktop/electron/backend-ready.test.ts index 7255f6e8a5..9919570971 100644 --- a/apps/desktop/electron/backend-ready.test.ts +++ b/apps/desktop/electron/backend-ready.test.ts @@ -320,90 +320,22 @@ test('bufferedOutput without a sentinel still times out (no false positive)', as await assert.rejects(wait, /Timed out waiting/) }) -// --------------------------------------------------------------------------- -// merged-tail seed (#103792): the spawn-time tail holds stdout AND stderr in -// ONE buffer, so it is not line-accurate. uvicorn logs to stderr in raw -// chunks, and a chunk that ends without a newline is concatenated straight -// onto the stdout sentinel that follows it. A `^`-anchored scan then recovers -// nothing from a backend that announced perfectly, the wait hits its 90s -// deadline, and a healthy listening backend is killed — while desktop.log -// (which reads both streams) plainly shows the READY line. -// --------------------------------------------------------------------------- - -test('resolves when a partial stderr line is spliced onto the sentinel in the merged tail (#103792)', async () => { +test('the merged-tail seed recovers a sentinel spliced onto a partial stderr line (#103792)', async () => { const child = makeFakeChild() - // No trailing newline on the stderr chunk, exactly as uvicorn emits it. - const mergedTail = 'INFO Started server process [4711]HERMES_BACKEND_READY port=65238\n' - + // uvicorn's stderr chunk has no trailing newline, so the tail is not line-accurate. const port = await waitForDashboardPortAnnouncement(child, { - bufferedOutput: () => mergedTail, + bufferedOutput: () => 'INFO Started server process [4711]HERMES_BACKEND_READY port=65238', timeoutMs: 500 }) assert.equal(port, 65238) }) -test('splice recovery also covers the legacy HERMES_DASHBOARD_READY sentinel', async () => { +test('the merged-tail seed does not match prose that merely names the sentinel', async () => { const child = makeFakeChild() - const port = await waitForDashboardPortAnnouncement(child, { - bufferedOutput: () => 'INFO Application startup complete.HERMES_DASHBOARD_READY port=65239\n', - timeoutMs: 500 - }) - - assert.equal(port, 65239) -}) - -test('a spliced sentinel with no trailing newline is still recovered from the tail', async () => { - const child = makeFakeChild() - - // The tail is a snapshot: the sentinel's own newline may not have been - // flushed into it yet. Line-splitting would drop it; the tail scan must not. - const port = await waitForDashboardPortAnnouncement(child, { - bufferedOutput: () => 'waiting for application startupHERMES_BACKEND_READY port=65240', - timeoutMs: 500 - }) - - assert.equal(port, 65240) -}) - -test('the merged-tail scan does not match prose that merely names the sentinel', async () => { - const child = makeFakeChild() - - // `port=` is what makes the token unambiguous. Without it, a log - // line discussing the sentinel must never be mistaken for an announcement. - const wait = waitForDashboardPort( - child, - 50, - () => '', - () => 'still waiting for HERMES_BACKEND_READY from the backend\n' - ) - - await assert.rejects(wait, /Timed out waiting/) -}) - -test('the merged-tail scan does not match a longer token ending in the sentinel', async () => { - const child = makeFakeChild() - - const wait = waitForDashboardPort( - child, - 50, - () => '', - () => 'X_HERMES_BACKEND_READY port=1234\n' - ) - - await assert.rejects(wait, /Timed out waiting/) -}) - -test('the LIVE per-line scanner stays line-anchored (splice tolerance is tail-only)', async () => { - const child = makeFakeChild() - - const wait = waitForDashboardPort(child, 60) - // Live stdout chunks ARE line-accurate for this stream, so a sentinel that - // is a suffix of some other line is not an announcement. Loosening this - // would let unrelated child output settle the boot on a bogus port. - child.stdout.emit('data', 'downloading HERMES_BACKEND_READY port=1234\n') + const wait = waitForDashboardPort(child, 50, () => '', () => 'still waiting for HERMES_BACKEND_READY from the backend\n') await assert.rejects(wait, /Timed out waiting/) }) diff --git a/apps/desktop/electron/backend-ready.ts b/apps/desktop/electron/backend-ready.ts index 844fbe1d60..7fd8287d61 100644 --- a/apps/desktop/electron/backend-ready.ts +++ b/apps/desktop/electron/backend-ready.ts @@ -5,19 +5,11 @@ import fs from 'node:fs' // works against both the headless backend and old/dashboard runtimes. const _READY_RE = /^HERMES_(?:BACKEND|DASHBOARD)_READY port=(\d+)/m -// Same sentinel, matched inside the spawn-time output tail rather than inside -// a single line. The tail merges stdout AND stderr into one buffer, so it is -// NOT line-accurate: uvicorn's stderr startup logging is appended in raw -// chunks, and a chunk that ends without a newline is concatenated directly -// onto the stdout sentinel that follows it, producing -// `INFO Started server process [4711]HERMES_BACKEND_READY port=65238`. -// A `^`-anchored match then fails on a backend that announced perfectly: the -// seed below silently recovers nothing, the wait hits its 90s deadline, and a -// healthy, listening backend is killed while desktop.log plainly shows the -// READY line (#103792). Guard on a token boundary instead of a line start. -// `port=` keeps the token unambiguous, so prose that merely mentions -// the sentinel cannot match. -const _READY_IN_MERGED_TAIL_RE = /(?:^|[^0-9A-Z_])HERMES_(?:BACKEND|DASHBOARD)_READY port=(\d+)/ +// Same sentinel inside a MERGED stdout+stderr buffer (the spawn-time output tail, a remote +// `>> log 2>&1` file): uvicorn's stderr chunks end without a newline, so the sentinel can be +// spliced onto them (`...process [4711]HERMES_BACKEND_READY port=65238`) and `^` never lines up +// (#103792). Match on a token boundary instead; `port=` keeps prose mentions out. +export const READY_IN_MERGED_OUTPUT_RE = /(? { assert.equal(READY_RE.exec('HERMES_BACKEND_READY port=4321')?.[1], '4321') assert.equal(READY_RE.exec('HERMES_DASHBOARD_READY port=8765')?.[1], '8765') + // The remote log is `>> log 2>&1`, so a stderr chunk without a newline can be spliced onto the sentinel. + assert.equal(READY_RE.exec('INFO Started server process [4711]HERMES_BACKEND_READY port=65238')?.[1], '65238') }) test('spawnRemoteDashboard rejects when no pid is returned', async () => { diff --git a/apps/desktop/electron/remote-lifecycle.ts b/apps/desktop/electron/remote-lifecycle.ts index 40108383cd..1dd5082748 100644 --- a/apps/desktop/electron/remote-lifecycle.ts +++ b/apps/desktop/electron/remote-lifecycle.ts @@ -27,6 +27,7 @@ import crypto from 'node:crypto' +import { READY_IN_MERGED_OUTPUT_RE } from './backend-ready' import { parseRemoteProfileListing } from './connection-registry' import { assertBootstrapNotSuperseded } from './ssh-connection' @@ -35,7 +36,7 @@ const LOCKFILE_SCHEMA_VERSION = 2 // an old running dashboard unsafe to reattach to (token handling, readiness/spawn // args, served-token reconciliation). A mismatch forces a clean respawn. const PROTOCOL_VERSION = 1 -const READY_RE = /^HERMES_(?:BACKEND|DASHBOARD)_READY port=(\d+)/m +const READY_RE = READY_IN_MERGED_OUTPUT_RE // the remote log is `>> log 2>&1`: merged, not line-accurate const REMOTE_LOCK_DIR = '~/.hermes/desktop-ssh' const SUPPORTED_REMOTE_OS = new Set(['Linux', 'Darwin']) const DEFAULT_READY_TIMEOUT_MS = 45_000