From 2a7909728f8e672a7f29dacee8860a56858c66d8 Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 04:35:15 -0400 Subject: [PATCH 01/11] fix(update): stop force-quitting mid-install on macOS MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit An install requested from the top-bar pill quit the app but usually left it on the old version, with nothing in ade-update.jsonl to say why. quitAndInstall armed a single hard 10s deadline and then force-quit via app.exit(0). After that call Squirrel.Mac still has to pull the archive off its loopback server, expand it, code-sign verify the expanded bundle, and spawn ShipIt. On the ~750 MB ADE archive that is ~10s, so the deadline raced a healthy install and usually won: five of six attempts on one machine died mid-verification with ShipIt never spawned. The one that landed beat the deadline by 61ms. The escalation was also invisible: forceQuit ends the process and log writes are batched onto an async stream, so autoUpdate.quit_escalated never reached disk. - Stage the deadline: 10s is now a soft mark that only logs; the hard bound is 5min while staging may still be running. Subscribing to Electron's own autoUpdater gives update-downloaded as a real "staging finished" signal, after which a tight 15s bound applies again — ShipIt is running by then, so a live process is a genuine wedge. - Add Logger.flushSync() and call it before forceQuit so the record that explains the exit survives it. - Keep the checksum-verified archive after a first failed handoff instead of wiping it; only a second consecutive failure on the same version clears the cache. Retrying no longer re-downloads the whole release. - Track failedInstallAttempts, log autoUpdate.install_did_not_land, and surface lastInstallFailed so the pill reads "Retry install vX" rather than silently re-offering the same update. Co-Authored-By: Claude --- .../analytics/productAnalyticsPolicy.ts | 16 +- .../src/main/services/logging/logger.test.ts | 29 +++ .../src/main/services/logging/logger.ts | 28 ++- .../src/main/services/state/globalState.ts | 11 + .../updates/autoUpdateService.test.ts | 168 +++++++++++++++- .../services/updates/autoUpdateService.ts | 188 ++++++++++++++++-- .../components/app/AutoUpdateControl.test.tsx | 1 + .../components/app/AutoUpdateControl.tsx | 18 +- .../components/app/useAutoUpdateSnapshot.ts | 1 + apps/desktop/src/shared/types/core.ts | 6 + .../src/shared/types/productAnalytics.ts | 1 + .../desktop-auto-update.md | 42 ++++ 12 files changed, 475 insertions(+), 34 deletions(-) diff --git a/apps/desktop/src/main/services/analytics/productAnalyticsPolicy.ts b/apps/desktop/src/main/services/analytics/productAnalyticsPolicy.ts index 44f33440d..8815950f6 100644 --- a/apps/desktop/src/main/services/analytics/productAnalyticsPolicy.ts +++ b/apps/desktop/src/main/services/analytics/productAnalyticsPolicy.ts @@ -15,7 +15,8 @@ export const MAX_LOCAL_IDENTIFIER_LENGTH = 512; export const INTERNAL_ONLY_EVENTS = new Set([ "ade_work_session_started", "ade_work_session_completed", "ade_daily_usage_summary", "ade_analytics_budget", - "ade_update_install_aborted", "ade_update_quit_escalated", "ade_update_auto_applied", + "ade_update_install_aborted", "ade_update_quit_escalated", "ade_update_install_did_not_land", + "ade_update_auto_applied", "ade_update_auto_apply_cancelled", "ade_brain_recovered", "ade_publish_failing", ]); @@ -32,6 +33,7 @@ export const EVENT_DAILY_BUDGETS: Record = { ade_analytics_budget: 2, ade_update_install_aborted: 20, ade_update_quit_escalated: 10, + ade_update_install_did_not_land: 10, ade_update_auto_applied: 10, ade_update_auto_apply_cancelled: 10, ade_brain_recovered: 10, @@ -50,6 +52,7 @@ export const EVENT_MINUTE_BUDGETS: Record = { ade_analytics_budget: 2, ade_update_install_aborted: 6, ade_update_quit_escalated: 3, + ade_update_install_did_not_land: 3, ade_update_auto_applied: 3, ade_update_auto_apply_cancelled: 3, ade_brain_recovered: 3, @@ -60,6 +63,7 @@ const STRING_PROPERTIES = new Set([ "screen", "feature", "action", "outcome", "app_version", "runtime_mode", "provider", "model_family", "duration_bucket", "error_kind", "route_kind", "connection_state", "drop_reason", "source", "mode", "entry_point", "release_channel", "summary_kind", "reason", "last_command", "leg", "code", + "escalation_reason", ]); const NUMBER_PROPERTIES = new Set([ "sent_count", "dropped_count", "interaction_count", "session_count", "chat_session_count", @@ -67,9 +71,11 @@ const NUMBER_PROPERTIES = new Set([ "push_operations", "pr_landings", "files_changed", "artifacts_captured", "automation_runs", "worker_runs", "active_days", "current_streak_days", "token_count", "input_token_count", "output_token_count", "call_count", "duration_ms", "provider_count", "model_count", "error_count", "bytes_freed", "files_compressed", "blocked_ms", - "failing_minutes", + "failing_minutes", "attempt", +]); +const BOOLEAN_PROPERTIES = new Set([ + "recoverable", "paired", "cached_data", "is_packaged", "native_staging_completed", ]); -const BOOLEAN_PROPERTIES = new Set(["recoverable", "paired", "cached_data", "is_packaged"]); // Actions emitted only by daemon services (not user-mutation ledger rows) that // are still meaningful product facts. Kept here rather than in the usage-stats @@ -100,7 +106,8 @@ const EVENT_PROPERTY_KEYS: Record ]), ade_analytics_budget: new Set(["sent_count", "dropped_count", "drop_reason"]), ade_update_install_aborted: new Set(["reason"]), - ade_update_quit_escalated: new Set(["blocked_ms"]), + ade_update_quit_escalated: new Set(["blocked_ms", "escalation_reason", "native_staging_completed"]), + ade_update_install_did_not_land: new Set(["attempt"]), ade_update_auto_applied: new Set(), ade_update_auto_apply_cancelled: new Set(), ade_brain_recovered: new Set(["blocked_ms", "last_command"]), @@ -146,6 +153,7 @@ const SAFE_STRING_VALUES: Partial>> = { release_channel: new Set(["stable", "beta", "development", "unknown"]), summary_kind: new Set(["overall", "client", "provider", "model"]), reason: new Set(AUTO_UPDATE_INSTALL_ABORT_REASONS), + escalation_reason: new Set(["hard_deadline", "post_staging"]), }; export function safeProductAnalyticsString(value: ProductAnalyticsPropertyValue): string | null { diff --git a/apps/desktop/src/main/services/logging/logger.test.ts b/apps/desktop/src/main/services/logging/logger.test.ts index df0ad2af6..e226ffbc9 100644 --- a/apps/desktop/src/main/services/logging/logger.test.ts +++ b/apps/desktop/src/main/services/logging/logger.test.ts @@ -64,4 +64,33 @@ describe("createFileLogger", () => { expect(consoleSpy).not.toHaveBeenCalled(); }); + + // Callers on their way to app.exit() rely on this: the normal batched write + // never lands, so without a synchronous drain the records that explain the + // exit are lost. + it("writes queued lines to disk synchronously on flushSync", () => { + const logPath = path.join(fs.mkdtempSync(path.join(os.tmpdir(), "ade-logger-")), "test.log"); + const logger = createFileLogger(logPath); + + logger.error("autoUpdate.quit_escalated", { blockedMs: 300_000 }); + logger.flushSync?.(); + + const written = fs.readFileSync(logPath, "utf8").trim().split("\n"); + expect(written).toHaveLength(1); + expect(JSON.parse(written[0])).toMatchObject({ + level: "error", + event: "autoUpdate.quit_escalated", + meta: { blockedMs: 300_000 }, + }); + }); + + it("is a no-op on flushSync with nothing queued", () => { + const logPath = path.join(fs.mkdtempSync(path.join(os.tmpdir(), "ade-logger-")), "test.log"); + const logger = createFileLogger(logPath); + + logger.flushSync?.(); + logger.flushSync?.(); + + expect(fs.existsSync(logPath)).toBe(false); + }); }); diff --git a/apps/desktop/src/main/services/logging/logger.ts b/apps/desktop/src/main/services/logging/logger.ts index ca2b58cd4..a60536214 100644 --- a/apps/desktop/src/main/services/logging/logger.ts +++ b/apps/desktop/src/main/services/logging/logger.ts @@ -29,6 +29,11 @@ export type Logger = { info: (event: string, meta?: Record) => void; warn: (event: string, meta?: Record) => void; error: (event: string, meta?: Record) => void; + // Writes anything still queued straight to disk. Normal logging batches + // through an async stream, so a caller that is about to end the process + // (app.exit, force quit) must call this or its last records are lost — + // exactly the records that explain why the process died. + flushSync?: () => void; }; function resolveMinLevel(): number { @@ -224,6 +229,26 @@ export function createFileLogger( flushTimer.unref?.(); }; + // Lines already handed to an in-flight async flush have been spliced out of + // queuedLines, so draining the rest here cannot duplicate them. Rotation is + // skipped deliberately: this runs on the way out of the process, where a + // slightly oversized log beats a lost one. + const flushSync = () => { + if (flushTimer) { + clearTimeout(flushTimer); + flushTimer = null; + } + if (queuedLines.length === 0) return; + const payload = queuedLines.splice(0, queuedLines.length).join(""); + try { + if (!ensureLogDir()) return; + fs.appendFileSync(logFilePath, payload); + estimatedFileSize = (estimatedFileSize ?? 0) + Buffer.byteLength(payload, "utf8"); + } catch { + // Same contract as flush(): never crash the app over a log write. + } + }; + const writeLine = (level: LogLevel, event: string, meta?: Record) => { if (LOG_LEVELS[level] < minLevel) return; @@ -245,6 +270,7 @@ export function createFileLogger( debug: (event, meta) => writeLine("debug", event, meta), info: (event, meta) => writeLine("info", event, meta), warn: (event, meta) => writeLine("warn", event, meta), - error: (event, meta) => writeLine("error", event, meta) + error: (event, meta) => writeLine("error", event, meta), + flushSync }; } diff --git a/apps/desktop/src/main/services/state/globalState.ts b/apps/desktop/src/main/services/state/globalState.ts index e416d44e9..dbdb77360 100644 --- a/apps/desktop/src/main/services/state/globalState.ts +++ b/apps/desktop/src/main/services/state/globalState.ts @@ -35,6 +35,16 @@ export type PendingInstallUpdate = { requestedAt: string; }; +// Consecutive installs of the same version that quit without landing. The +// archive was already checksum-verified before it went "ready", so the first +// failure keeps it and a retry skips re-downloading; a repeat says the archive +// itself is suspect and earns a clean slate. +export type FailedInstallAttempts = { + targetVersion: string; + count: number; + lastFailedAt: string; +}; + export type GlobalState = { lastProjectRoot?: string; lastRemoteProjectBinding?: Extract & { @@ -43,6 +53,7 @@ export type GlobalState = { recentProjects?: RecentProject[]; pendingInstallUpdate?: PendingInstallUpdate; recentlyInstalledUpdate?: RecentlyInstalledUpdate; + failedInstallAttempts?: FailedInstallAttempts; welcomeVideo?: AppWelcomeVideoState; }; diff --git a/apps/desktop/src/main/services/updates/autoUpdateService.test.ts b/apps/desktop/src/main/services/updates/autoUpdateService.test.ts index 63d5f36b4..544ea7b0e 100644 --- a/apps/desktop/src/main/services/updates/autoUpdateService.test.ts +++ b/apps/desktop/src/main/services/updates/autoUpdateService.test.ts @@ -30,6 +30,7 @@ function makeLogger(): Logger { info: vi.fn(), warn: vi.fn(), error: vi.fn(), + flushSync: vi.fn(), }; } @@ -251,7 +252,10 @@ describe("createAutoUpdateService", () => { service.dispose(); }); - it("cleans cached downloads when a requested install relaunches on the old version", () => { + // The archive is checksum-verified before the update is offered, so one + // failed handoff does not make it suspect. Re-downloading the whole release + // on every retry is what made a flaky install cost gigabytes. + it("keeps the verified download when a requested install relaunches on the old version", () => { const globalStatePath = makeStatePath(); const updaterCacheDir = makeUpdaterCacheDir(); const logger = makeLogger(); @@ -275,12 +279,64 @@ describe("createAutoUpdateService", () => { updater: new FakeAutoUpdater(), }); - expect(readState(globalStatePath)).toEqual({}); + expect(readState(globalStatePath)).toEqual({ + failedInstallAttempts: { + targetVersion: "1.2.3", + count: 1, + lastFailedAt: "2026-04-06T15:21:00.000Z", + }, + }); + expect(fs.readdirSync(updaterCacheDir).sort()).toEqual(["pending", "update.zip"]); + expect(logger.error).toHaveBeenCalledWith( + "autoUpdate.install_did_not_land", + expect.objectContaining({ + targetVersion: "1.2.3", + attempt: 1, + downloadPreserved: true, + }), + ); + + service.dispose(); + }); + + it("clears the cached download after a second failed install of the same version", () => { + const globalStatePath = makeStatePath(); + const updaterCacheDir = makeUpdaterCacheDir(); + const logger = makeLogger(); + fs.writeFileSync(globalStatePath, JSON.stringify({ + pendingInstallUpdate: { + fromVersion: "1.2.2", + targetVersion: "1.2.3", + releaseNotesUrl: "https://www.ade-app.dev/docs/changelog/v1.2.3", + requestedAt: "2026-04-06T15:20:00.000Z", + }, + failedInstallAttempts: { + targetVersion: "1.2.3", + count: 1, + lastFailedAt: "2026-04-06T15:10:00.000Z", + }, + }), "utf8"); + + const service = createAutoUpdateService({ + logger, + currentVersion: "1.2.2", + globalStatePath, + updaterCacheDir, + startupDelayMs: 60_000, + periodicCheckMs: 60_000, + now: () => "2026-04-06T15:21:00.000Z", + updater: new FakeAutoUpdater(), + }); + expectCacheEmpty(updaterCacheDir); expect(logger.info).toHaveBeenCalledWith( "autoUpdate.cache_cleaned", expect.objectContaining({ reason: "failed_install", entriesRemoved: 2 }), ); + expect(logger.error).toHaveBeenCalledWith( + "autoUpdate.install_did_not_land", + expect.objectContaining({ attempt: 2, downloadPreserved: false }), + ); service.dispose(); }); @@ -1323,11 +1379,15 @@ describe("createAutoUpdateService", () => { service.dispose(); }); - it("force-quits when the native handoff does not reach will-quit by the hard deadline", async () => { + // Regression: the soft deadline used to force-quit, which killed the process + // mid-staging. Squirrel needs ~10s to expand and code-sign verify a ~750 MB + // bundle, so that raced — and usually beat — a healthy install. + it("does not force-quit while the native installer is still staging", async () => { vi.useFakeTimers(); const globalStatePath = makeStatePath(); const updaterCacheDir = makeUpdaterCacheDir(); const updater = new FakeAutoUpdater(); + const nativeUpdater = new EventEmitter(); const logger = makeLogger(); const forceQuit = vi.fn(); const service = createAutoUpdateService({ @@ -1337,6 +1397,8 @@ describe("createAutoUpdateService", () => { updaterCacheDir, installWatchdogMs: 1_000, quitDeadlineMs: 5_000, + quitHardDeadlineMs: 300_000, + nativeUpdater, forceQuit, getDiskSpace: () => ({ availableBytes: 20 * 1024 * 1024 * 1024, @@ -1350,28 +1412,118 @@ describe("createAutoUpdateService", () => { await expect(service.quitAndInstall()).resolves.toBe(true); expect(service.getSnapshot().status).toBe("installing"); - await vi.advanceTimersByTimeAsync(1_000); + // Well past the soft deadline: noted, never fatal. + await vi.advanceTimersByTimeAsync(60_000); + expect(forceQuit).not.toHaveBeenCalled(); + expect(logger.warn).toHaveBeenCalledWith("autoUpdate.quit_staging_slow", { + blockedMs: 5_000, + }); expect(service.getSnapshot().status).toBe("installing"); expect(readState(globalStatePath)).toMatchObject({ pendingInstallUpdate: { targetVersion: "1.2.3" }, }); + expect(fs.readdirSync(updaterCacheDir).sort()).toEqual(["pending", "update.zip"]); - await vi.advanceTimersByTimeAsync(4_000); + service.dispose(); + }); + + it("force-quits once staging finished but the process never exited", async () => { + vi.useFakeTimers(); + const globalStatePath = makeStatePath(); + const updaterCacheDir = makeUpdaterCacheDir(); + const updater = new FakeAutoUpdater(); + const nativeUpdater = new EventEmitter(); + const logger = makeLogger(); + const forceQuit = vi.fn(); + const service = createAutoUpdateService({ + logger, + currentVersion: "1.2.2", + globalStatePath, + updaterCacheDir, + installWatchdogMs: 1_000, + quitDeadlineMs: 5_000, + quitHardDeadlineMs: 300_000, + quitPostStagingDeadlineMs: 15_000, + nativeUpdater, + forceQuit, + getDiskSpace: () => ({ + availableBytes: 20 * 1024 * 1024 * 1024, + volumePath: "/System/Volumes/Data", + }), + autoCheckEnabled: false, + updater, + }); + updater.emit("update-downloaded", { version: "1.2.3" }); + + await expect(service.quitAndInstall()).resolves.toBe(true); + + await vi.advanceTimersByTimeAsync(20_000); + nativeUpdater.emit("update-downloaded"); + expect(forceQuit).not.toHaveBeenCalled(); + + await vi.advanceTimersByTimeAsync(15_000); expect(forceQuit).toHaveBeenCalledWith({ blockedPhase: "app_quit", - blockedMs: 5_000, + blockedMs: 35_000, }); expect(logger.error).toHaveBeenCalledWith("autoUpdate.quit_escalated", { blockedPhase: "app_quit", - blockedMs: 5_000, + blockedMs: 35_000, + reason: "post_staging", + nativeStagingCompleted: true, + }); + // The escalation record has to survive the app.exit() that follows. + expect(logger.flushSync).toHaveBeenCalled(); + + service.dispose(); + }); + + it("force-quits a handoff that never stages at all, at the hard deadline", async () => { + vi.useFakeTimers(); + const globalStatePath = makeStatePath(); + const updaterCacheDir = makeUpdaterCacheDir(); + const updater = new FakeAutoUpdater(); + const logger = makeLogger(); + const forceQuit = vi.fn(); + const service = createAutoUpdateService({ + logger, + currentVersion: "1.2.2", + globalStatePath, + updaterCacheDir, + installWatchdogMs: 1_000, + quitDeadlineMs: 5_000, + quitHardDeadlineMs: 300_000, + nativeUpdater: null, + forceQuit, + getDiskSpace: () => ({ + availableBytes: 20 * 1024 * 1024 * 1024, + volumePath: "/System/Volumes/Data", + }), + autoCheckEnabled: false, + updater, + }); + updater.emit("update-downloaded", { version: "1.2.3" }); + + await expect(service.quitAndInstall()).resolves.toBe(true); + + await vi.advanceTimersByTimeAsync(300_000); + + expect(forceQuit).toHaveBeenCalledWith({ + blockedPhase: "app_quit", + blockedMs: 300_000, + }); + expect(logger.error).toHaveBeenCalledWith("autoUpdate.quit_escalated", { + blockedPhase: "app_quit", + blockedMs: 300_000, + reason: "hard_deadline", + nativeStagingCompleted: false, }); expect(service.getSnapshot().status).toBe("installing"); expect(readState(globalStatePath)).toMatchObject({ pendingInstallUpdate: { targetVersion: "1.2.3" }, }); - expect(fs.readdirSync(updaterCacheDir).sort()).toEqual(["pending", "update.zip"]); service.dispose(); }); diff --git a/apps/desktop/src/main/services/updates/autoUpdateService.ts b/apps/desktop/src/main/services/updates/autoUpdateService.ts index ac2e61160..fcc1268e3 100644 --- a/apps/desktop/src/main/services/updates/autoUpdateService.ts +++ b/apps/desktop/src/main/services/updates/autoUpdateService.ts @@ -29,7 +29,20 @@ import { } from "./autoUpdateVersions"; const DEFAULT_INSTALL_WATCHDOG_MS = 30_000; +// Soft mark only. After `quitAndInstall` the OS installer (Squirrel.Mac) still +// has to pull the archive over its loopback server, expand it, and code-sign +// verify the expanded bundle before it can spawn ShipIt and replace us. For an +// ~750 MB archive that runs right around ten seconds, so treating this as a +// deadline to kill the process loses a coin flip against a healthy install. const DEFAULT_QUIT_DEADLINE_MS = 10_000; +// Hard bound while the OS installer may still be staging. Only a genuinely +// wedged handoff should reach this. +const DEFAULT_QUIT_HARD_DEADLINE_MS = 5 * 60_000; +// Once staging is done the installer is already running and about to replace +// the bundle, so a process that still has not exited is a real wedge and a +// short bound is safe again. +const DEFAULT_QUIT_POST_STAGING_DEADLINE_MS = 15_000; +const FAILED_INSTALL_CACHE_RESET_ATTEMPTS = 2; const DEFAULT_AUTO_APPLY_IDLE_MS = 2 * 60_000; const DEFAULT_AUTO_APPLY_COUNTDOWN_MS = 10_000; const DEFAULT_AUTO_APPLY_SUPPRESSION_MS = 4 * 60 * 60_000; @@ -51,6 +64,26 @@ type AutoUpdaterLike = { removeListener: (event: string, listener: (...args: any[]) => void) => unknown; }; +// Electron's own `autoUpdater`, i.e. the Squirrel.Mac binding that +// electron-updater's MacUpdater drives underneath. Its `update-downloaded` +// fires when the OS installer has finished staging the new bundle — the only +// in-process signal that the native handoff actually got somewhere. +type NativeUpdaterLike = { + on: (event: string, listener: (...args: any[]) => void) => unknown; + removeListener: (event: string, listener: (...args: any[]) => void) => unknown; +}; + +function resolveNativeUpdater(): NativeUpdaterLike | null { + try { + if (typeof require !== "function") return null; + const electron = require("electron") as { autoUpdater?: NativeUpdaterLike }; + const candidate = electron?.autoUpdater; + return typeof candidate?.on === "function" ? candidate : null; + } catch { + return null; + } +} + type CreateAutoUpdateServiceArgs = { logger: Logger; currentVersion: string; @@ -71,6 +104,9 @@ type CreateAutoUpdateServiceArgs = { getDiskSpace?: (targetPath: string) => DiskSpaceInfo; installWatchdogMs?: number; quitDeadlineMs?: number; + quitHardDeadlineMs?: number; + quitPostStagingDeadlineMs?: number; + nativeUpdater?: NativeUpdaterLike | null; autoApplyIdleMs?: number; autoApplyCountdownMs?: number; autoApplySuppressionMs?: number; @@ -111,6 +147,7 @@ export function createEmptyAutoUpdateSnapshot(currentVersion = ""): AutoUpdateSn errorDetails: null, recentlyInstalled: null, parked: null, + lastInstallFailed: null, autoApplyPending: null, autoApplySuppressedUntil: null, }; @@ -208,10 +245,12 @@ function reconcilePersistedUpdateState(args: { changed: boolean; recentlyInstalled: RecentlyInstalledUpdate | null; cacheCleanupReason: string | null; + failedInstall: { targetVersion: string; attempt: number } | null; } { const nextState: GlobalState = { ...args.state }; let changed = false; let cacheCleanupReason: string | null = null; + let failedInstall: { targetVersion: string; attempt: number } | null = null; if ( nextState.recentlyInstalledUpdate @@ -233,8 +272,25 @@ function reconcilePersistedUpdateState(args: { githubReleaseUrl: buildGithubReleaseUrl(args.currentVersion), }; cacheCleanupReason = "installed"; + nextState.failedInstallAttempts = undefined; } else { - cacheCleanupReason = "failed_install"; + const previous = nextState.failedInstallAttempts; + const attempt = previous?.targetVersion === pendingInstall.targetVersion + ? previous.count + 1 + : 1; + nextState.failedInstallAttempts = { + targetVersion: pendingInstall.targetVersion, + count: attempt, + lastFailedAt: args.now, + }; + failedInstall = { targetVersion: pendingInstall.targetVersion, attempt }; + // First failure: the archive passed its checksum before it ever went + // "ready", so the quit lost a race rather than the bytes being bad. + // Keeping it turns a retry into a click instead of a fresh download of + // the whole release. A second failure stops trusting it. + cacheCleanupReason = attempt >= FAILED_INSTALL_CACHE_RESET_ATTEMPTS + ? "failed_install" + : null; } nextState.pendingInstallUpdate = undefined; changed = true; @@ -247,6 +303,7 @@ function reconcilePersistedUpdateState(args: { cloneRecentlyInstalledUpdate(nextState.recentlyInstalledUpdate ?? null), ), cacheCleanupReason, + failedInstall, }; } @@ -283,6 +340,9 @@ export function createAutoUpdateService({ getDiskSpace = readDiskSpace, installWatchdogMs = DEFAULT_INSTALL_WATCHDOG_MS, quitDeadlineMs = DEFAULT_QUIT_DEADLINE_MS, + quitHardDeadlineMs = DEFAULT_QUIT_HARD_DEADLINE_MS, + quitPostStagingDeadlineMs = DEFAULT_QUIT_POST_STAGING_DEADLINE_MS, + nativeUpdater = resolveNativeUpdater(), autoApplyIdleMs = DEFAULT_AUTO_APPLY_IDLE_MS, autoApplyCountdownMs = DEFAULT_AUTO_APPLY_COUNTDOWN_MS, autoApplySuppressionMs = DEFAULT_AUTO_APPLY_SUPPRESSION_MS, @@ -334,10 +394,27 @@ export function createAutoUpdateService({ reason: initialState.cacheCleanupReason, }); } + if (initialState.failedInstall) { + // Relaunching on the old version after an install was requested means the + // handoff never landed. Say so plainly: silently re-offering the same + // update is what made this look like the update "did nothing". + logger.error("autoUpdate.install_did_not_land", { + targetVersion: initialState.failedInstall.targetVersion, + currentVersion, + attempt: initialState.failedInstall.attempt, + downloadPreserved: initialState.cacheCleanupReason == null, + }); + productAnalyticsService?.captureInternal({ + event: "ade_update_install_did_not_land", + surface: "desktop", + properties: { attempt: initialState.failedInstall.attempt }, + }); + } let snapshot: AutoUpdateSnapshot = { ...createEmptyAutoUpdateSnapshot(currentVersion), recentlyInstalled: initialState.recentlyInstalled, + lastInstallFailed: initialState.failedInstall, }; let checkPromise: Promise | null = null; // In-flight guard for quitAndInstall. Two IPC callers (e.g. AutoUpdateControl @@ -358,6 +435,10 @@ export function createAutoUpdateService({ let compressedUpdateVersion: string | null = null; let preservedDownloadRetry: PreservedDownloadRetry | null = null; let quitDeadlineTimer: ReturnType | null = null; + let quitSoftDeadlineTimer: ReturnType | null = null; + let quitArmedAtMs: number | null = null; + let nativeStagingCompleted = false; + let detachNativeStagingListener: (() => void) | null = null; let activityCheckTimer: ReturnType | null = null; let autoApplyDeadlineTimer: ReturnType | null = null; let idleSinceMs: number | null = null; @@ -397,9 +478,18 @@ export function createAutoUpdateService({ } function clearQuitDeadline(): void { - if (!quitDeadlineTimer) return; - clearTimeout(quitDeadlineTimer); - quitDeadlineTimer = null; + if (quitDeadlineTimer) { + clearTimeout(quitDeadlineTimer); + quitDeadlineTimer = null; + } + if (quitSoftDeadlineTimer) { + clearTimeout(quitSoftDeadlineTimer); + quitSoftDeadlineTimer = null; + } + detachNativeStagingListener?.(); + detachNativeStagingListener = null; + quitArmedAtMs = null; + nativeStagingCompleted = false; } function clearAutoApplyDeadline(): void { @@ -1079,26 +1169,84 @@ export function createAutoUpdateService({ return false; } + function escalateQuit(reason: "hard_deadline" | "post_staging"): void { + if (!installQuitArmed) return; + const blockedMs = Math.max(0, nowMs() - (quitArmedAtMs ?? nowMs())); + const blockedPhase = "app_quit"; + logger.error("autoUpdate.quit_escalated", { + blockedPhase, + blockedMs, + reason, + nativeStagingCompleted, + }); + productAnalyticsService?.captureInternal({ + event: "ade_update_quit_escalated", + surface: "desktop", + properties: { + blocked_ms: blockedMs, + escalation_reason: reason, + native_staging_completed: nativeStagingCompleted, + }, + }); + // forceQuit ends the process outright, and log writes are batched onto an + // async stream — without this the record above dies with the process and + // the escalation leaves no trace at all. + logger.flushSync?.(); + forceQuit?.({ blockedPhase, blockedMs }); + } + + // Squirrel finished expanding and verifying the new bundle and is handing off + // to its installer, so the remaining window is short and bounded. + function onNativeStagingComplete(): void { + if (!installQuitArmed || nativeStagingCompleted) return; + nativeStagingCompleted = true; + logger.info("autoUpdate.native_staging_complete", { + elapsedMs: Math.max(0, nowMs() - (quitArmedAtMs ?? nowMs())), + }); + if (quitDeadlineTimer) { + clearTimeout(quitDeadlineTimer); + quitDeadlineTimer = null; + } + quitDeadlineTimer = setTimeout(() => { + quitDeadlineTimer = null; + escalateQuit("post_staging"); + }, quitPostStagingDeadlineMs); + quitDeadlineTimer.unref?.(); + } + function armQuitDeadline(): void { clearQuitDeadline(); installQuitArmed = true; - const startedAt = nowMs(); - quitDeadlineTimer = setTimeout(() => { - quitDeadlineTimer = null; - if (!installQuitArmed) return; - const blockedMs = Math.max(0, nowMs() - startedAt); - const blockedPhase = "app_quit"; - logger.error("autoUpdate.quit_escalated", { - blockedPhase, - blockedMs, - }); - productAnalyticsService?.captureInternal({ - event: "ade_update_quit_escalated", - surface: "desktop", - properties: { blocked_ms: blockedMs }, + nativeStagingCompleted = false; + quitArmedAtMs = nowMs(); + + if (nativeUpdater) { + const listener = () => onNativeStagingComplete(); + nativeUpdater.on("update-downloaded", listener); + detachNativeStagingListener = () => { + try { + nativeUpdater.removeListener("update-downloaded", listener); + } catch { + // A detached native updater is not worth failing the install over. + } + }; + } + + // Observation, not enforcement: staging legitimately runs past this on a + // large bundle or a busy disk. Killing here is what broke installs before. + quitSoftDeadlineTimer = setTimeout(() => { + quitSoftDeadlineTimer = null; + if (!installQuitArmed || nativeStagingCompleted) return; + logger.warn("autoUpdate.quit_staging_slow", { + blockedMs: Math.max(0, nowMs() - (quitArmedAtMs ?? nowMs())), }); - forceQuit?.({ blockedPhase, blockedMs }); }, quitDeadlineMs); + quitSoftDeadlineTimer.unref?.(); + + quitDeadlineTimer = setTimeout(() => { + quitDeadlineTimer = null; + escalateQuit("hard_deadline"); + }, quitHardDeadlineMs); quitDeadlineTimer.unref?.(); } @@ -1170,6 +1318,8 @@ export function createAutoUpdateService({ error: null, errorDetails: null, parked: null, + // This attempt supersedes the notice about the previous one. + lastInstallFailed: null, autoApplyPending: null, }); try { diff --git a/apps/desktop/src/renderer/components/app/AutoUpdateControl.test.tsx b/apps/desktop/src/renderer/components/app/AutoUpdateControl.test.tsx index 8bd259f83..4fe1ca4ca 100644 --- a/apps/desktop/src/renderer/components/app/AutoUpdateControl.test.tsx +++ b/apps/desktop/src/renderer/components/app/AutoUpdateControl.test.tsx @@ -21,6 +21,7 @@ const idleSnapshot: AutoUpdateSnapshot = { errorDetails: null, recentlyInstalled: null, parked: null, + lastInstallFailed: null, autoApplyPending: null, autoApplySuppressedUntil: null, }; diff --git a/apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx b/apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx index 2be1ddf9b..fd3f47c47 100644 --- a/apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx +++ b/apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx @@ -201,6 +201,14 @@ export function AutoUpdateControl() { const runtimeRequiresDesktopUpdate = runtimeSkew?.state === "runtime_newer"; const showRuntimeSkewIndicator = runtimeRequiresDesktopUpdate && !shouldShowIndicator && !showUpdateError; + // A previous attempt quit but came back on the old version. Saying so beats + // re-offering the identical button as if nothing had happened. + const retryAfterFailedInstall = Boolean( + snapshot.lastInstallFailed + && snapshot.version + && snapshot.lastInstallFailed.targetVersion === snapshot.version, + ); + function indicatorTitle(): string { switch (effectiveStatus) { case "checking": @@ -210,7 +218,10 @@ export function AutoUpdateControl() { case "installing": return "ADE is preparing to quit and reopen automatically"; default: - return `Install ${versionLabel(snapshot.version)}. ADE will quit and reopen automatically.`; + return retryAfterFailedInstall + ? `The last attempt to install ${versionLabel(snapshot.version)} quit without finishing. ` + + "Try again — the download is already on this machine." + : `Install ${versionLabel(snapshot.version)}. ADE will quit and reopen automatically.`; } } @@ -284,7 +295,10 @@ export function AutoUpdateControl() { ) : null} {effectiveStatus === "ready" ? ( - Install update {snapshot.version ? `v${snapshot.version}` : ""} + + {retryAfterFailedInstall ? "Retry install" : "Install update"} + {snapshot.version ? ` v${snapshot.version}` : ""} + ) : null} {effectiveStatus === "installing" ? ( ADE will quit and reopen diff --git a/apps/desktop/src/renderer/components/app/useAutoUpdateSnapshot.ts b/apps/desktop/src/renderer/components/app/useAutoUpdateSnapshot.ts index 048687f47..0f2374cd0 100644 --- a/apps/desktop/src/renderer/components/app/useAutoUpdateSnapshot.ts +++ b/apps/desktop/src/renderer/components/app/useAutoUpdateSnapshot.ts @@ -16,6 +16,7 @@ export const EMPTY_AUTO_UPDATE_SNAPSHOT: AutoUpdateSnapshot = { errorDetails: null, recentlyInstalled: null, parked: null, + lastInstallFailed: null, autoApplyPending: null, autoApplySuppressedUntil: null, }; diff --git a/apps/desktop/src/shared/types/core.ts b/apps/desktop/src/shared/types/core.ts index 030003859..b95a382bc 100644 --- a/apps/desktop/src/shared/types/core.ts +++ b/apps/desktop/src/shared/types/core.ts @@ -222,6 +222,12 @@ export type AutoUpdateSnapshot = { recentlyInstalled: RecentlyInstalledUpdate | null; /** A consented install that aborted before the native updater could take over. */ parked: { reason: AutoUpdateInstallAbortReason; at: number } | null; + /** + * A previous install quit but came back on the old version. Survives the + * restart so the UI can say the update did not land instead of silently + * offering the same version again. + */ + lastInstallFailed: { targetVersion: string; attempt: number } | null; /** Renderer-visible countdown before an idle update is applied. */ autoApplyPending: { deadlineAt: number } | null; /** Explicit user cancellation suppresses another idle countdown until this epoch. */ diff --git a/apps/desktop/src/shared/types/productAnalytics.ts b/apps/desktop/src/shared/types/productAnalytics.ts index 8a374f816..f434908c2 100644 --- a/apps/desktop/src/shared/types/productAnalytics.ts +++ b/apps/desktop/src/shared/types/productAnalytics.ts @@ -12,6 +12,7 @@ export const PRODUCT_ANALYTICS_EVENTS = [ "ade_analytics_budget", "ade_update_install_aborted", "ade_update_quit_escalated", + "ade_update_install_did_not_land", "ade_update_auto_applied", "ade_update_auto_apply_cancelled", "ade_brain_recovered", diff --git a/docs/features/onboarding-and-settings/desktop-auto-update.md b/docs/features/onboarding-and-settings/desktop-auto-update.md index 6baa9f5af..20f949bf9 100644 --- a/docs/features/onboarding-and-settings/desktop-auto-update.md +++ b/docs/features/onboarding-and-settings/desktop-auto-update.md @@ -61,6 +61,48 @@ so loopback transfer and staging are not mistaken for a stalled quit. Handoff timeouts retain the pending-install marker because Squirrel may still complete; an explicit updater error clears it. +## Quit deadline during the native handoff + +`quitAndInstall` arms a deadline before entering `electron-updater` so a quit +that never happens cannot strand the app in `installing` forever. The window has +to respect what Squirrel.Mac actually does after that call: pull the archive +from the loopback server, expand it, code-sign verify the expanded bundle, then +spawn ShipIt. On a ~750 MB archive that is roughly ten seconds, and it scales +with bundle size and disk contention. + +So the deadline is staged rather than a single hard bound: + +| Stage | Default | Behavior | +| --- | --- | --- | +| Soft mark | 10s | Logs `autoUpdate.quit_staging_slow`. Never fatal. | +| Native staging complete | — | Electron's own `autoUpdater` emits `update-downloaded`; logs `autoUpdate.native_staging_complete` and re-arms the short bound below. | +| Post-staging bound | 15s | ShipIt is already running, so a process still alive here is genuinely wedged: escalate. | +| Hard bound | 5min | Staging never signalled at all: escalate. | + +Escalation logs `autoUpdate.quit_escalated` and calls `logger.flushSync()` +before `forceQuit`, because `forceQuit` ends the process and ordinary log writes +are batched onto an async stream — without the sync drain the escalation record +dies with the process and the failure leaves no trace. + +A single hard 10-second bound is what this replaced. It force-quit the process +mid-staging and lost that race most of the time, so the app quit, nothing +installed, and it relaunched on the old version with no log line explaining it. + +## When an install does not land + +Relaunching on the old version while a `pendingInstallUpdate` marker exists +means the handoff never completed. The service records this in +`failedInstallAttempts` (target version + consecutive count), logs +`autoUpdate.install_did_not_land`, and exposes `lastInstallFailed` on the +snapshot so the top-bar pill reads "Retry install vX" instead of silently +offering the same update again. + +The first such failure **keeps** the cached archive. It was checksum-verified +before the update was ever offered, so a lost quit race says nothing about the +bytes, and re-downloading the whole release on every retry is pure cost. A +second consecutive failure on the same version stops trusting the archive and +clears the updater cache. + ## Truthful version surfaces Every version surface reads from one shared snapshot so they can never disagree From 6e9dac700fdc6b1ef43704c81e2c3ffbf4920e18 Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 05:38:15 -0400 Subject: [PATCH 02/11] fix(sync): stop orphaning a pairing identity on every re-pair MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Connecting the MacBook to the Mac Studio failed with a bare "authentication" on the LAN routes, then worked after re-pairing. The Studio's log showed why: it had been rejecting the desktop as an unknown device, and it was holding SEVEN pairing records for the same laptop, six of them dead. The host keys pairing records by the desktop's per-host `deviceId` and upserts on that key, but the PIN pairing path minted a fresh `deviceId` on every call. The account-adoption path already reused the existing one. So each re-pair left the host with another record it could never match again — an unbounded pile of orphaned, still-valid secrets. - pairWithMachine now recovers this desktop's prior identity before sending the pairing request: caller-supplied hostDeviceId (carried by QR/link payloads), then the relay machine key, then a saved record already holding the endpoint. The endpoint fallback is load-bearing: machineKeyFromEndpoint only parses a relay /connect/ path and returns null for a LAN address, which is the case that actually broke. - The host stopped being silent about it. `pairingStore.authenticate()` failing logged nothing and told the client only "Sync authentication failed."; it now logs sync_host.paired_device_rejected (unknown_device vs secret_mismatch) and sends a message naming the fix. Same for an account-owner mismatch. - account.local_machines_removed now records which credentials were dropped and the previous vs current owner, and writes to a machine-local runtime/account-trust.jsonl. It previously logged counts only, through the project logger — which on a remote-bound project ships the record to the other machine, leaving nothing on the machine that lost its trust. Co-Authored-By: Claude --- .../src/services/sync/syncHostService.ts | 27 ++++++- .../account/accountBridge.trust.test.ts | 4 ++ .../main/services/account/accountBridge.ts | 41 ++++++++++- .../remoteConnectionService.test.ts | 12 +++- .../remoteRuntime/remoteConnectionService.ts | 29 +++++++- .../syncPairedMachineStore.test.ts | 71 +++++++++++++++++++ .../remoteRuntime/syncPairedMachineStore.ts | 27 ++++++- docs/features/remote-runtime/README.md | 31 ++++++++ 8 files changed, 234 insertions(+), 8 deletions(-) diff --git a/apps/ade-cli/src/services/sync/syncHostService.ts b/apps/ade-cli/src/services/sync/syncHostService.ts index dd305f375..accf3a801 100644 --- a/apps/ade-cli/src/services/sync/syncHostService.ts +++ b/apps/ade-cli/src/services/sync/syncHostService.ts @@ -6759,14 +6759,37 @@ export function createSyncHostService(args: SyncHostServiceArgs) { return true; } } - if (!pairingStore.authenticate(pairedAuth.deviceId, pairedAuth.secret)) return true; + // This rejection used to be silent on both ends: the host logged + // nothing and the client showed a bare "authentication". Name it, + // and tell the client the one thing that actually resolves it. + const knownRecord = pairingStore.getPairingRecord(pairedAuth.deviceId); + if (!pairingStore.authenticate(pairedAuth.deviceId, pairedAuth.secret)) { + authFailureMessage = knownRecord + ? "This device's saved pairing is no longer valid on this machine. Pair it again." + : "This device is not paired with this machine, or the pairing was removed. Pair it again."; + args.logger.warn("sync_host.paired_device_rejected", { + deviceId: pairedAuth.deviceId, + reason: knownRecord ? "secret_mismatch" : "unknown_device", + }); + return true; + } authenticatedPairingRecord = pairingStore.getPairingRecord(pairedAuth.deviceId); if (!authenticatedPairingRecord) return true; const pairingAccountOwner = toOptionalString(authenticatedPairingRecord.accountOwnerUserId); if (pairingAccountOwner) { const currentOwner = await refreshAccountLease(); if (!isPeerLifecycleCurrent(peer, lifecycleGeneration)) return true; - if (currentOwner !== pairingAccountOwner) return true; + if (currentOwner !== pairingAccountOwner) { + // A LAN client rejected here sees only "authentication"; the + // account mismatch is the actionable part. + authFailureMessage = "This machine is signed in to a different ADE account than the one that paired this device."; + args.logger.warn("sync_host.paired_account_owner_mismatch", { + deviceId: pairedAuth.deviceId, + hasCurrentOwner: Boolean(currentOwner), + ownerMatches: false, + }); + return true; + } } const dpopFailure = evaluatePairedHelloDpop({ storedPublicKey: authenticatedPairingRecord.dpopPublicKey, diff --git a/apps/desktop/src/main/services/account/accountBridge.trust.test.ts b/apps/desktop/src/main/services/account/accountBridge.trust.test.ts index d3f6eec75..0fbaee13c 100644 --- a/apps/desktop/src/main/services/account/accountBridge.trust.test.ts +++ b/apps/desktop/src/main/services/account/accountBridge.trust.test.ts @@ -458,6 +458,8 @@ describe("desktop account machine lifecycle", () => { const reconcileAccountOwnership = vi.fn(() => ({ removedTargetIds: [], removedCredentialHostIds: [], + removedCredentials: [], + currentOwnerUserId: null, })); const { createAccountBridge } = await import("./accountBridge"); const bridge = createAccountBridge({ @@ -600,6 +602,8 @@ describe("desktop account machine lifecycle", () => { const reconcileAccountOwnership = vi.fn(() => ({ removedTargetIds: [], removedCredentialHostIds: [], + removedCredentials: [], + currentOwnerUserId: null, })); const { createAccountBridge } = await import("./accountBridge"); const bridge = createAccountBridge({ diff --git a/apps/desktop/src/main/services/account/accountBridge.ts b/apps/desktop/src/main/services/account/accountBridge.ts index e4b4ad3cb..c4c123b5d 100644 --- a/apps/desktop/src/main/services/account/accountBridge.ts +++ b/apps/desktop/src/main/services/account/accountBridge.ts @@ -16,7 +16,9 @@ import { } from "../../../../../ade-cli/src/services/account/sharedAccountAuthService"; import { AccountMachineDirectoryService } from "../../../../../ade-cli/src/services/account/accountMachineDirectoryService"; import { resolveMachineAdeLayout } from "../../../../../ade-cli/src/services/projects/machineLayout"; +import { createFileLogger, type Logger } from "../logging/logger"; import os from "node:os"; +import path from "node:path"; import type { AccountAuthStatus, AccountLoginStartResult, @@ -167,6 +169,26 @@ export function createAccountBridge(options: AccountBridgeOptions): AccountBridg directoryBaseUrl: () => resolveDirectoryBaseUrl(options.getProjectRoot()), deviceName: () => `ADE Desktop on ${os.hostname()}`, }); + // Machine-scoped, deliberately not the project logger. Dropping a paired + // secret is a machine-level credential mutation, and the project logger + // follows the active project — which, on a remote-bound project, ships these + // records to the other machine and leaves nothing behind on the machine that + // actually lost its trust. Resolved lazily and defensively: a log sink is + // never worth failing account auth over. + let machineLogger: Logger | null | undefined; + const getMachineLogger = (): Logger | null => { + if (machineLogger !== undefined) return machineLogger; + try { + const adeDir = resolveMachineAdeLayout().adeDir; + machineLogger = adeDir + ? createFileLogger(path.join(adeDir, "runtime", "account-trust.jsonl")) + : null; + } catch { + machineLogger = null; + } + return machineLogger; + }; + const reconcileLocalMachines = (currentOwnerUserId: string | null): void => { const result = options.reconcileAccountOwnership?.(currentOwnerUserId); if ( @@ -174,10 +196,25 @@ export function createAccountBridge(options: AccountBridgeOptions): AccountBridg && (result.removedTargetIds.length > 0 || result.removedCredentialHostIds.length > 0) ) { - options.logger?.info("account.local_machines_removed", { + // Warn, not info: each removed credential costs the user a manual + // re-pair of that machine, so this is never routine. + const detail = { targetCount: result.removedTargetIds.length, credentialCount: result.removedCredentialHostIds.length, - }); + currentOwnerUserId: result.currentOwnerUserId, + removed: result.removedCredentials.map((credentials) => ({ + hostDeviceId: credentials.hostDeviceId, + hostName: credentials.hostName, + previousOwnerUserId: credentials.previousOwnerUserId, + // The whole point of the record: an account switch is intended, an + // identical owner that still pruned is the bug worth chasing. + ownerChanged: credentials.previousOwnerUserId !== result.currentOwnerUserId, + })), + }; + const sink = getMachineLogger(); + sink?.warn("account.local_machines_removed", detail); + sink?.flushSync?.(); + options.logger?.info("account.local_machines_removed", detail); } }; diff --git a/apps/desktop/src/main/services/remoteRuntime/remoteConnectionService.test.ts b/apps/desktop/src/main/services/remoteRuntime/remoteConnectionService.test.ts index 4648c88a1..37d7587c9 100644 --- a/apps/desktop/src/main/services/remoteRuntime/remoteConnectionService.test.ts +++ b/apps/desktop/src/main/services/remoteRuntime/remoteConnectionService.test.ts @@ -563,8 +563,9 @@ describe("RemoteConnectionService", () => { } as unknown as RemoteConnectionPool; const pairedStore = { pruneAccountOwned: vi.fn(() => [{ - hostIdentity: { deviceId: "owned-host" }, + hostIdentity: { deviceId: "owned-host", name: "Owned Host" }, machineKey: "owned-key", + accountOwnerUserId: "account-a", }]), }; const service = new RemoteConnectionService(registry, pool, {}, pairedStore as any); @@ -574,6 +575,13 @@ describe("RemoteConnectionService", () => { expect(service.reconcileAccountOwnership("account-b")).toEqual({ removedTargetIds: [accountOwned.id], removedCredentialHostIds: ["owned-host"], + // Detail the prune log needs to name what trust it destroyed. + removedCredentials: [{ + hostDeviceId: "owned-host", + hostName: "Owned Host", + previousOwnerUserId: "account-a", + }], + currentOwnerUserId: "account-b", }); expect(pool.disconnect).toHaveBeenCalledWith(accountOwned.id); expect(pool.disconnect).not.toHaveBeenCalledWith(localOwned.id); @@ -605,6 +613,8 @@ describe("RemoteConnectionService", () => { expect(service.reconcileAccountOwnership(null)).toEqual({ removedTargetIds: [], removedCredentialHostIds: [], + removedCredentials: [], + currentOwnerUserId: null, }); expect(pool.reconcileAccountRelayOwner).toHaveBeenCalledWith(null); expect(registry.pruneAccountOwned).not.toHaveBeenCalled(); diff --git a/apps/desktop/src/main/services/remoteRuntime/remoteConnectionService.ts b/apps/desktop/src/main/services/remoteRuntime/remoteConnectionService.ts index 0b2bbde3c..4abb628c8 100644 --- a/apps/desktop/src/main/services/remoteRuntime/remoteConnectionService.ts +++ b/apps/desktop/src/main/services/remoteRuntime/remoteConnectionService.ts @@ -86,6 +86,18 @@ type RemoteConnectionServiceOptions = { export type AccountMachineReconciliationResult = { removedTargetIds: string[]; removedCredentialHostIds: string[]; + /** + * Detail for the removed pairings. Dropping a paired secret forces the user + * to re-pair that machine by hand, so the reason has to be reconstructable + * afterwards from a log — counts alone are not enough to tell an intended + * account switch from an identity glitch that silently cost trust. + */ + removedCredentials: Array<{ + hostDeviceId: string; + hostName: string | null; + previousOwnerUserId: string | null; + }>; + currentOwnerUserId: string | null; }; type RemoteConnectionDisconnectOptions = { @@ -321,12 +333,23 @@ export class RemoteConnectionService { removedCredentialHostIds: removedCredentials.map( (credentials) => credentials.hostIdentity.deviceId, ), + removedCredentials: removedCredentials.map((credentials) => ({ + hostDeviceId: credentials.hostIdentity.deviceId, + hostName: credentials.hostIdentity.name ?? null, + previousOwnerUserId: credentials.accountOwnerUserId ?? null, + })), + currentOwnerUserId, }; } async reconcileAuthorizedAccountOwnership(): Promise { if (!this.options.getAuthorizedAccountOwnerId) { - return { removedTargetIds: [], removedCredentialHostIds: [] }; + return { + removedTargetIds: [], + removedCredentialHostIds: [], + removedCredentials: [], + currentOwnerUserId: null, + }; } const currentOwnerUserId = await this.options.getAuthorizedAccountOwnerId() .catch(() => null); @@ -433,6 +456,10 @@ export class RemoteConnectionService { appVersion: this.options.appVersion, relayAccountToken, runtimeHostGrant: parsed.runtimeHostGrant ?? null, + // Known from the pairing payload; lets the store reuse this + // desktop's existing identity for the host instead of orphaning + // a record there on every re-pair. + hostDeviceId: parsed.hostIdentity.deviceId, }, ); if (paired.hostIdentity.deviceId !== parsed.hostIdentity.deviceId) { diff --git a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.test.ts b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.test.ts index d485f5b7a..6c766f9f8 100644 --- a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.test.ts +++ b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.test.ts @@ -329,6 +329,77 @@ describe("DesktopPairedMachineStore", () => { }); }); + // Regression: re-pairing used to mint a fresh local device id every time. + // The host keys pairing records by that id, so each re-pair left it holding + // another record it could never match again — an unbounded pile of orphaned, + // still-valid secrets, and one observed machine had accumulated six. + it("reuses this desktop's pairing identity when re-pairing the same machine", async () => { + const adeHome = fs.mkdtempSync(path.join(os.tmpdir(), "ade-desktop-repair-")); + process.env.ADE_HOME = adeHome; + const presentedDeviceIds: string[] = []; + + const createWebSocket = () => new FakeWebSocket((text, ws) => { + const envelope = parseSyncEnvelope(wsDataToText(text)); + if (envelope.type === "pairing_request") { + const payload = envelope.payload as { peer: { deviceId: string } }; + presentedDeviceIds.push(payload.peer.deviceId); + ws.receive(encodeSyncEnvelope({ + type: "pairing_result", + requestId: envelope.requestId, + payload: { + ok: true, + deviceId: payload.peer.deviceId, + secret: "host-issued-secret", + }, + })); + return; + } + if (envelope.type !== "hello") return; + const payload = envelope.payload as { peer: unknown }; + ws.receive(encodeSyncEnvelope({ + type: "hello_ok", + requestId: envelope.requestId, + payload: { + peer: payload.peer, + brain: { + deviceId: "mac-studio-host", + deviceName: "Studio", + platform: "macOS", + deviceType: "desktop", + siteId: "mac-studio-site", + dbVersion: 0, + }, + serverDbVersion: 0, + heartbeatIntervalMs: 5_000, + pollIntervalMs: 1_500, + // Deliberately no relay URL: a LAN endpoint yields no machine key, + // which is the exact case the first fix attempt would have missed. + features: { rpcChannel: true, portForward: true }, + }, + })); + }) as unknown as WebSocket; + + const store = new DesktopPairedMachineStore(); + const first = await store.pairWithMachine( + "ws://192.168.1.240:8806", + "123456", + "Desktop client", + { pairingTimeoutMs: 2_000, createWebSocket, hostDeviceId: "mac-studio-host" }, + ); + const second = await store.pairWithMachine( + "ws://192.168.1.240:8806", + "123456", + "Desktop client", + { pairingTimeoutMs: 2_000, createWebSocket, hostDeviceId: "mac-studio-host" }, + ); + + expect(presentedDeviceIds).toHaveLength(2); + expect(presentedDeviceIds[1]).toBe(presentedDeviceIds[0]); + expect(second.deviceId).toBe(first.deviceId); + expect(second.siteId).toBe(first.siteId); + expect(new DesktopPairedMachineStore().list()).toHaveLength(1); + }); + it("replaces stale relay connection metadata only when explicitly requested", () => { const filePath = path.join( fs.mkdtempSync(path.join(os.tmpdir(), "ade-desktop-pairing-store-")), diff --git a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts index 7566b7f68..9d8a1353f 100644 --- a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts +++ b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts @@ -63,6 +63,13 @@ export type PairWithMachineOptions = Omit< pairingTimeoutMs?: number; relayAccountToken?: string | null; runtimeHostGrant?: string | null; + /** + * Host this pairing is aimed at, when the caller already knows it (a QR or + * link payload carries it). Lets re-pairing reuse this desktop's existing + * pairing identity for that host instead of minting a new one, which the + * host would store as a second, permanently unmatchable record. + */ + hostDeviceId?: string | null; }; export type PairWithAccountMachineOptions = Omit< @@ -578,8 +585,24 @@ export class DesktopPairedMachineStore { if (!deviceName) throw new Error("Desktop device name is required."); const keys = generateDesktopDpopKeyPair(); - const localDeviceId = randomUUID(); - const siteId = randomUUID(); + // Re-pairing the same machine must reuse this desktop's existing pairing + // identity, exactly as the account-adoption path already does. The host + // keys its pairing records by this device id and upserts on re-pair, so + // minting a fresh one instead leaves behind a record the host can never + // match again — one orphaned, still-valid secret per re-pair, forever. + // The hello that reports the host identity comes after the pairing request + // that carries this id, so recover the prior record up front: by the host + // the caller is aiming at, else the relay machine key, else the endpoint + // already recorded against a known machine. + const endpointMachineKey = machineKeyFromEndpoint(endpoint); + const existing = (options.hostDeviceId?.trim() + ? this.get(options.hostDeviceId.trim()) + : null) + ?? (endpointMachineKey ? this.get(endpointMachineKey) : null) + ?? this.list().find((machine) => machine.endpoints.includes(endpoint)) + ?? null; + const localDeviceId = existing?.deviceId ?? randomUUID(); + const siteId = existing?.siteId ?? randomUUID(); const createdAt = nowIso(); const connection = await openSyncEnvelopeConnection({ endpoint, diff --git a/docs/features/remote-runtime/README.md b/docs/features/remote-runtime/README.md index b077b8c79..ebfec5242 100644 --- a/docs/features/remote-runtime/README.md +++ b/docs/features/remote-runtime/README.md @@ -477,6 +477,37 @@ diagnostics with `ADE_ENABLE_DESKTOP_SYNC_HOST=1`. destination lane/chat rather than automatically replaying the mutation. - "Tailscale CLI was not found / timed out / failed" warning under the discovered-machines list — surfaced from `discoverLanRuntimes` diagnostics. LAN (Bonjour) discovery still ran; install or unblock `tailscale` to add tailnet peers. - Agent provider missing or unauthenticated — use the inline `AgentCliAuthCard` to install or authenticate that provider on the active runtime machine. +- `lan :: authentication` in the route list — the host was reached and it *rejected* this desktop, so the other routes' `timeout`/`unreachable` entries are noise. The host now names the reason instead of a bare "Sync authentication failed.": either the pairing was removed on that machine, the saved secret no longer matches, or the two machines are signed in to different ADE accounts. Only the last one is fixed by signing in; the others need a re-pair. + +## Pairing identity and paired-secret lifetime + +A desktop's pairing identity is per-host, not per-machine: `sync-device-id` is +the machine's stable id, but each entry in `desktop-paired-machines.json` +carries its own `deviceId` that the host uses as the key for its pairing +record. Re-pairing the same machine therefore **must** present the same +`deviceId` — the host upserts on that key. `pairWithMachine` recovers the prior +identity before it sends the pairing request, preferring the caller-supplied +`hostDeviceId` (a QR/link payload carries it), then the relay machine key, then +a saved record already holding this endpoint. The endpoint fallback matters +because `machineKeyFromEndpoint` only parses a relay `/connect/` path and +returns null for a LAN address. + +Minting a fresh id instead is not merely untidy: the host keeps the old record +forever, secret still valid, with no way to ever match it again. One machine was +observed holding six orphaned records for the same laptop. + +Two logs make a lost pairing diagnosable, both of which were previously silent: + +- Host: `sync_host.paired_device_rejected` (`unknown_device` vs + `secret_mismatch`) and `sync_host.paired_account_owner_mismatch`. +- Desktop: `account.local_machines_removed`, written to + `/runtime/account-trust.jsonl`. Deliberately **not** the + project logger — dropping a paired secret is a machine-level credential + mutation, and the project logger follows the active project, which on a + remote-bound project ships the record to the other machine and leaves nothing + on the machine that actually lost its trust. It records the previous and + current owner per removed credential, so an intended account switch is + distinguishable from an identity glitch that silently cost trust. ## Related docs From d6bceb0ac166203d831d7ad842799aa979c8ab0f Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 06:07:11 -0400 Subject: [PATCH 03/11] fix(sync): stop routine probe traffic masquerading as rejected peers MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Every relay readiness self-probe bridges into the sync host over loopback and disconnects without ever speaking the sync protocol. That landed on sync_host.peer_closed at info, identical in shape to a peer that sent a hello and was turned away — so a machine polling the relay produced a steady drip of entries that read like authentication failures. Chasing one such pattern cost real time during this investigation. Track frames received per peer and split the close log: a peer that closes having sent nothing logs sync_host.peer_closed_without_frames at debug, while anything that actually spoke — every authentication failure included — still logs sync_host.peer_closed at info. Nothing consumes the event, so no reader breaks. Co-Authored-By: Claude --- .../src/services/sync/syncHostService.test.ts | 34 +++++++++++++++++++ .../src/services/sync/syncHostService.ts | 23 +++++++++++-- docs/features/remote-runtime/README.md | 8 +++++ 3 files changed, 63 insertions(+), 2 deletions(-) diff --git a/apps/ade-cli/src/services/sync/syncHostService.test.ts b/apps/ade-cli/src/services/sync/syncHostService.test.ts index f17f68295..efca2a999 100644 --- a/apps/ade-cli/src/services/sync/syncHostService.test.ts +++ b/apps/ade-cli/src/services/sync/syncHostService.test.ts @@ -7133,6 +7133,40 @@ describe("sync host reliability guards", () => { } as unknown as Parameters[0]); } + // The relay readiness self-probe bridges into the sync host and disconnects + // without ever speaking the protocol, on every poll. Logging that at info + // made routine probe traffic indistinguishable at a glance from a peer that + // tried to authenticate and was rejected. + it("logs a peer that closed without sending a frame at debug", async () => { + const { projectRoot, cleanup } = createTempProjectRoot(); + const logger = createDiscoveryLogger(); + const host = createReliabilityHost(projectRoot, { logger }); + try { + const port = await host.waitUntilListening(); + const ws = new WebSocket(`ws://127.0.0.1:${port}`); + await new Promise((resolve, reject) => { + ws.once("open", () => resolve()); + ws.once("error", reject); + }); + ws.close(4000, "self probe complete"); + + await vi.waitFor(() => expect(logger.debug).toHaveBeenCalledWith( + "sync_host.peer_closed_without_frames", + expect.objectContaining({ + authenticated: false, + reason: "self probe complete", + }), + )); + expect(logger.info).not.toHaveBeenCalledWith( + "sync_host.peer_closed", + expect.anything(), + ); + } finally { + await host.dispose(); + cleanup(); + } + }); + it("serializes project switch handling without deadlocking later peer messages", async () => { const { projectRoot, cleanup } = createTempProjectRoot(); const project = createDiscoveryProject({ diff --git a/apps/ade-cli/src/services/sync/syncHostService.ts b/apps/ade-cli/src/services/sync/syncHostService.ts index accf3a801..87ca86d46 100644 --- a/apps/ade-cli/src/services/sync/syncHostService.ts +++ b/apps/ade-cli/src/services/sync/syncHostService.ts @@ -531,6 +531,13 @@ type PeerState = { changesetRecoveryNotBeforeMs: number; remoteAddress: string | null; remotePort: number | null; + /** + * Frames received from this peer. A peer that closes having sent none never + * attempted the sync protocol at all — the relay readiness self-probe bridges + * in and disconnects like this on every poll — so it must not be logged with + * the same weight as a peer that tried to authenticate and was rejected. + */ + framesReceived: number; transportOrigin: SyncTransportOrigin; relayAuthorization: RelayAuthorizationLifecycle | null; adoptChallenge: { @@ -3178,6 +3185,7 @@ export function createSyncHostService(args: SyncHostServiceArgs) { pairingRecord: null, connectedAt: nowIso(), lastSeenAt: nowIso(), + framesReceived: 0, lastAppliedAt: null, lastKnownServerDbVersion: 0, latencyMs: null, @@ -3232,6 +3240,7 @@ export function createSyncHostService(args: SyncHostServiceArgs) { }, authTimeoutMs); peer.authTimeout.unref?.(); ws.on("message", (raw) => { + peer.framesReceived += 1; let envelope: ParsedSyncEnvelope; try { envelope = parseSyncEnvelope(wsDataToText(raw)); @@ -3281,7 +3290,7 @@ export function createSyncHostService(args: SyncHostServiceArgs) { // changed.", "The machine took too long to respond.", …) while 1006 // means the transport died with no close frame at all. Keep this log — // it is the primary tool for diagnosing mobile disconnect loops. - args.logger.info("sync_host.peer_closed", { + const closeDetail = { code, reason: reason.toString("utf8") || null, peerDeviceId: peer.metadata?.deviceId ?? peer.pairedDeviceId ?? null, @@ -3289,7 +3298,17 @@ export function createSyncHostService(args: SyncHostServiceArgs) { remoteAddress: peer.remoteAddress ?? null, connectedAt: peer.connectedAt ?? null, authenticated: peer.authenticated, - }); + }; + // A peer that never sent a frame never attempted the protocol: the relay + // readiness self-probe bridges in and drops on every poll, and so does a + // port scan. Logging those at info buried the real signal — a rejected + // peer looks identical at a glance — so keep them at debug. Anything that + // actually spoke, including every authentication failure, stays at info. + if (!peer.authenticated && peer.framesReceived === 0) { + args.logger.debug("sync_host.peer_closed_without_frames", closeDetail); + } else { + args.logger.info("sync_host.peer_closed", closeDetail); + } if (removeAllPresenceForDevice(peer.metadata?.deviceId, "remote")) { broadcastBrainStatus(); } diff --git a/docs/features/remote-runtime/README.md b/docs/features/remote-runtime/README.md index ebfec5242..a7338884b 100644 --- a/docs/features/remote-runtime/README.md +++ b/docs/features/remote-runtime/README.md @@ -500,6 +500,14 @@ Two logs make a lost pairing diagnosable, both of which were previously silent: - Host: `sync_host.paired_device_rejected` (`unknown_device` vs `secret_mismatch`) and `sync_host.paired_account_owner_mismatch`. +- Host, for peers that never spoke: `sync_host.peer_closed_without_frames` at + **debug**. The relay readiness self-probe bridges in over loopback and + disconnects without sending a frame on every poll, and so does a port scan. + Those used to land on `sync_host.peer_closed` at info, where routine probe + traffic was indistinguishable at a glance from a peer that tried to + authenticate and was rejected. Anything that sent at least one frame — + including every authentication failure — still logs `sync_host.peer_closed` + at info. - Desktop: `account.local_machines_removed`, written to `/runtime/account-trust.jsonl`. Deliberately **not** the project logger — dropping a paired secret is a machine-level credential From 41ef34062b849f10b8855befb1c87a20a139cc41 Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 11:34:18 -0400 Subject: [PATCH 04/11] fix(sync): bind the relay tunnel to the runtime that owns the listener MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Relay never worked on this machine: routeHealth showed listenerBound=true, loopbackAdeValidated=true, port=8852 — while the tunnel client's own port was null and lastBridgeValidationAt had never once been set. The paired record agreed: lastSucceededAt=null on the relay endpoint, ever. So when LAN auth broke, there was no fallback route and the machine was simply unreachable. The tunnel client is cached one-per-machine and built by whichever runtime bootstraps first, which is regularly a scope that owns no shared listener (a headless one-shot, an embedded fallback). Everything the factory captured -- getSyncPort/getExpectedLoopbackNonce/getRelayBridgeProof and the onLoopbackValidated retry hook -- then bound to null through an optional chain, permanently. The real host later received the cached instance and started the tunnel, so the control socket connected while the port stayed null, and the one hook that could have repaired the startup ordering had never been registered on a real listener. Add attachHostListener(), called by the runtime that actually owns the listener, outside the construction closure. It overrides the constructor accessors, registers the loopback retry hook (disposing any prior one), and validates immediately since the listener may already be up with no further event coming. Co-Authored-By: Claude --- apps/ade-cli/src/bootstrap.ts | 18 +++-- .../sync/syncTunnelClientService.test.ts | 59 ++++++++++++++++ .../services/sync/syncTunnelClientService.ts | 68 +++++++++++++++++-- 3 files changed, 133 insertions(+), 12 deletions(-) diff --git a/apps/ade-cli/src/bootstrap.ts b/apps/ade-cli/src/bootstrap.ts index f6215bbc9..b759756dc 100644 --- a/apps/ade-cli/src/bootstrap.ts +++ b/apps/ade-cli/src/bootstrap.ts @@ -1568,15 +1568,19 @@ export async function createAdeRuntime(args: { }, onPublicationStateChanged: () => resolvedArgs.syncRuntime?.requestAccountMachinePublish?.(), }); - resolvedArgs.syncRuntime?.sharedSyncListener?.onLoopbackValidated(() => { - void service.validateCurrentBridge().catch((error) => { - logger.warn("sync.tunnel_bridge_validation_failed", { - error: error instanceof Error ? error.message : String(error), - }); - }); - }); return service; }); + // Bind the listener OUTSIDE the factory. The client is cached one-per-machine + // and built by whichever runtime bootstrapped first, which is regularly a + // scope with no listener (headless one-shot, embedded fallback). Everything + // captured in that factory — the port accessor and the loopback retry hook — + // then pointed at null for the life of the process, so the bridge could never + // validate and Relay stayed fail-closed even though the listener was up. + // Attaching here means the runtime that actually owns the listener wins, + // whether or not it was the one that created the instance. + if (resolvedArgs.syncRuntime?.sharedSyncListener) { + syncTunnelClientService.attachHostListener(resolvedArgs.syncRuntime.sharedSyncListener); + } // Only the runtime that actually hosts phone sync (owns the brain-level // shared listener) may register the relay tunnel. The relay DO keeps ONE // host socket per machineKey (last wins), so a headless one-shot CLI diff --git a/apps/ade-cli/src/services/sync/syncTunnelClientService.test.ts b/apps/ade-cli/src/services/sync/syncTunnelClientService.test.ts index 19a7eb7e1..35f2b787d 100644 --- a/apps/ade-cli/src/services/sync/syncTunnelClientService.test.ts +++ b/apps/ade-cli/src/services/sync/syncTunnelClientService.test.ts @@ -390,6 +390,65 @@ describe("createSyncTunnelClientService", () => { } }); + // Regression: the tunnel client is cached one-per-machine and built by + // whichever runtime bootstrapped first — regularly a scope that owns no + // listener (headless one-shot, embedded fallback). The accessors and the + // loopback retry hook captured in that closure then read null for the life + // of the process, so the bridge never validated and Relay stayed + // fail-closed even though the real listener was bound and healthy. + it("validates the bridge when the host attaches a listener the constructor never saw", async () => { + const listener = createSharedSyncListener({ bindHost: "127.0.0.1" }); + const relay = new WebSocketServer({ host: "127.0.0.1", port: 0 }); + await new Promise((resolve, reject) => { + relay.once("listening", resolve); + relay.once("error", reject); + }); + const address = relay.address(); + const relayPort = typeof address === "object" && address ? address.port : 0; + relay.on("connection", (socket, request) => { + if ((request.url ?? "").startsWith("/connect/")) { + socket.send(JSON.stringify({ t: "accepted", v: 2 })); + socket.send(JSON.stringify({ t: "ready", v: 2 })); + } + }); + const originalFetch = globalThis.fetch; + globalThis.fetch = async () => new Response(null, { status: 204 }); + // Built by a runtime with no listener: every accessor is null, and no + // loopback subscription is possible. + const service = createSyncTunnelClientService({ + getSyncPort: () => null, + getExpectedLoopbackNonce: () => null, + getRelayBridgeProof: () => null, + configStore: fakeStore(`http://127.0.0.1:${relayPort}`), + }); + + try { + await service.start(); + await vi.waitFor(() => { + expect(service.getStatus().connected).toBe(true); + }); + expect(service.getStatus().relayBridgeValidated).toBe(false); + + const syncPort = await listener.ensureListening([0]); + // The host runtime hands over the listener it owns. Before the fix this + // had no way in, and the client stayed pinned to the null accessors. + service.attachHostListener(listener); + + await vi.waitFor(() => { + expect(service.getStatus()).toMatchObject({ + connected: true, + relayBridgeValidated: true, + validatedPort: syncPort, + }); + }); + } finally { + await service.dispose(); + globalThis.fetch = originalFetch; + await listener.close(); + await new Promise((resolve) => relay.close(() => resolve())); + } + }); + it("keeps Relay offline signed out, resumes on sign-in, and closes when token refresh fails", async () => { const relay = new WebSocketServer({ host: "127.0.0.1", port: 0 }); await new Promise((resolve, reject) => { diff --git a/apps/ade-cli/src/services/sync/syncTunnelClientService.ts b/apps/ade-cli/src/services/sync/syncTunnelClientService.ts index e57239446..b6d27d517 100644 --- a/apps/ade-cli/src/services/sync/syncTunnelClientService.ts +++ b/apps/ade-cli/src/services/sync/syncTunnelClientService.ts @@ -50,6 +50,17 @@ export type SyncTunnelClientStatus = { export type SyncTunnelClientService = { start(): Promise; stop(): Promise; + /** + * Hand this client the shared listener it must bridge into. + * + * The client is cached one-per-machine and built by whichever runtime + * bootstrapped first — which is frequently NOT the runtime that owns the + * listener. Accessors captured at construction therefore read a listener + * that stays null forever, so the bridge can never validate and Relay dies + * fail-closed. The runtime that actually owns the listener calls this, and + * it wins regardless of who created the instance. + */ + attachHostListener(listener: TunnelHostListener | null): void; /** Re-probe the active shared listener without opening a Relay pipe. */ validateCurrentBridge(): Promise; /** Dial Relay exactly like a ready-v2 controller and verify bridge readiness. */ @@ -60,6 +71,14 @@ export type SyncTunnelClientService = { type MachineIdentity = { machineKey: string; secret: string }; +/** The slice of the shared sync listener the relay bridge needs. */ +export type TunnelHostListener = { + getPort(): number | null; + getExpectedLoopbackNonce(): string; + getRelayBridgeProof(): string; + onLoopbackValidated(handler: () => void): () => void; +}; + type SyncTunnelClientArgs = { logger?: Logger; /** Local ADE sync WebSocket server port, or null when the host isn't up. */ @@ -273,6 +292,8 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT let started = false; let stopped = false; let connected = false; + let hostListener: TunnelHostListener | null = null; + let detachHostListener: (() => void) | null = null; let lastError: string | null = null; let lastControlError: string | null = null; let bridgeOpenFailure: { @@ -458,10 +479,22 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT } }; + // An attached host listener always wins over the constructor accessors: the + // constructor's closure belongs to whichever runtime bootstrapped first, + // which is often not the one that owns the listener. + const syncPort = (): number | null => + hostListener ? hostListener.getPort() : args.getSyncPort(); + const expectedLoopbackNonce = (): string | null => + hostListener + ? hostListener.getExpectedLoopbackNonce() + : args.getExpectedLoopbackNonce?.() ?? null; + const relayBridgeProofValue = (): string | null => + hostListener ? hostListener.getRelayBridgeProof() : args.getRelayBridgeProof(); + const bridgeValidationIdentity = (): BridgeValidationIdentity => { const eligible = accountSignedIn(); - const port = args.getSyncPort(); - const nonce = args.getExpectedLoopbackNonce?.() ?? null; + const port = syncPort(); + const nonce = expectedLoopbackNonce(); return { key: JSON.stringify([ port, @@ -1312,10 +1345,10 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT if (!await validateCurrentBridge()) { rejectOpen( - args.getSyncPort() == null || !accountSignedIn() + syncPort() == null || !accountSignedIn() ? RELAY_CLOSE_HOST_UNAVAILABLE : RELAY_CLOSE_BRIDGE_REJECTED, - args.getSyncPort() == null ? "host sync listener unavailable" : "bridge validation failed", + syncPort() == null ? "host sync listener unavailable" : "bridge validation failed", ); return; } @@ -1337,7 +1370,7 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT rejectOpen(RELAY_CLOSE_BRIDGE_REJECTED, "bridge identity changed"); return; } - const relayBridgeProof = args.getRelayBridgeProof(); + const relayBridgeProof = relayBridgeProofValue(); if (!relayBridgeProof) { clearBridgeValidation(); recordFailure("Relay bridge refused because the local bridge credential is unavailable."); @@ -1626,6 +1659,31 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT await refreshAccountLease(); }, + attachHostListener(listener: TunnelHostListener | null): void { + if (hostListener === listener) return; + detachHostListener?.(); + detachHostListener = null; + hostListener = listener; + if (!listener) return; + // Re-run validation whenever the listener re-validates loopback. This + // subscription used to be registered in the construction closure, so + // when the creating runtime had no listener it silently bound to + // nothing and the one retry path that could repair a startup-ordering + // failure never fired. + detachHostListener = listener.onLoopbackValidated(() => { + void validateCurrentBridge().catch((error) => { + log.warn?.("sync_tunnel.bridge_validation_failed", { + error: error instanceof Error ? error.message : String(error), + }); + }); + }); + // The listener may already be bound and validated by the time the host + // attaches, in which case no future event is coming. + if (!stopped) { + void validateCurrentBridge().catch(() => {}); + } + }, + async stop(): Promise { stopped = true; started = false; From 36a2b184c8a9cb142614d8c8aac3c74674c0479b Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 11:37:53 -0400 Subject: [PATCH 05/11] fix(sync): reclaim stranded tailscale serve ports instead of ratcheting past them The sync listener had drifted from 8787 to 8852, climbing by one on every restart across days, and burning ~70 failed binds each start. The doctor said the base ports had "no visible holders" -- and lsof agreed, which sent this investigation down a long wrong path. netstat told the truth: a contiguous range was bound to this machine's tailnet address. ADE publishes its sync port with `tailscale serve --bg --tcp=`, which outlives the process that registered it, but the port ADE tracks (tailnetServePort) is in-memory only. So every restart -- and every force-kill that skipped the teardown, which the updater bug was doing all night -- orphaned the previous entry. Tailscale keeps it bound, ADE's own next wildcard bind fails EADDRINUSE against its own leftover, and it walks one port higher and leaks another. Sixty-six ports had accumulated. lsof could not see any of it because tailscaled runs as root, which is also why ADE's own inspectPort reports no holders. Reclaim stale entries after each successful publish. Only ADE's exact signature is touched -- a port inside ADE's sync range forwarding to 127.0.0.1 on the SAME port -- so a hand-rolled `tailscale serve` in that range is left strictly alone. The parsing is a pure exported helper with unit tests covering the live port, foreign forwards, out-of-range ports, and junk input. Co-Authored-By: Claude --- .../src/services/sync/syncHostService.test.ts | 46 +++++++++++ .../src/services/sync/syncHostService.ts | 77 ++++++++++++++++++- 2 files changed, 122 insertions(+), 1 deletion(-) diff --git a/apps/ade-cli/src/services/sync/syncHostService.test.ts b/apps/ade-cli/src/services/sync/syncHostService.test.ts index efca2a999..73e96999c 100644 --- a/apps/ade-cli/src/services/sync/syncHostService.test.ts +++ b/apps/ade-cli/src/services/sync/syncHostService.test.ts @@ -58,6 +58,7 @@ import { recordChatEventInReplayBuffer, resolveSyncHostInboundProjectScope, selectChangesetBatchChunk, + staleAdeTailnetServePorts, syncConnectionTransportForOrigin, } from "./syncHostService"; import { createBrainProjectActionsSyncHandler } from "./brainProjectActionsSyncHandler"; @@ -130,6 +131,51 @@ type BonjourPublishArgs = { disableIPv6: boolean; }; +// Regression: `tailscale serve --bg` outlives the process that registered it, +// but ADE tracked the served port in memory only. Every restart -- and every +// force-kill that skipped teardown -- orphaned the previous entry, which stayed +// bound on the tailnet address and made ADE's own next wildcard bind fail +// EADDRINUSE against its own leftovers. It walked one port higher and leaked +// another, ratcheting forever: 66 stranded ports and ~70 failed binds per start +// on one machine. +describe("staleAdeTailnetServePorts", () => { + const serveStatus = (ports: Record) => + JSON.stringify({ + TCP: Object.fromEntries( + Object.entries(ports).map(([port, forward]) => [port, { TCPForward: forward }]), + ), + }); + + it("reclaims ADE's own stranded ports and keeps the live one", () => { + const json = serveStatus({ + "8787": "127.0.0.1:8787", + "8788": "127.0.0.1:8788", + "8852": "127.0.0.1:8852", + }); + expect(staleAdeTailnetServePorts(json, 8852)).toEqual([8787, 8788]); + }); + + it("leaves a hand-rolled serve in the same range alone", () => { + const json = serveStatus({ + // Same port range, but forwarding somewhere ADE never would. + "8790": "127.0.0.1:3000", + "8791": "192.168.1.5:8791", + "8792": "127.0.0.1:8792", + }); + expect(staleAdeTailnetServePorts(json, null)).toEqual([8792]); + }); + + it("ignores ports outside ADE's sync range", () => { + const json = serveStatus({ "443": "127.0.0.1:443", "9100": "127.0.0.1:9100" }); + expect(staleAdeTailnetServePorts(json, null)).toEqual([]); + }); + + it("returns nothing for unparseable or empty status", () => { + expect(staleAdeTailnetServePorts("not json", 8852)).toEqual([]); + expect(staleAdeTailnetServePorts(JSON.stringify({}), 8852)).toEqual([]); + }); +}); + describe("resolveSyncHostInboundProjectScope", () => { it("keeps runtime-scoped envelopes projectless", () => { expect(resolveSyncHostInboundProjectScope("hello", "project-1", "project-1")).toEqual({ diff --git a/apps/ade-cli/src/services/sync/syncHostService.ts b/apps/ade-cli/src/services/sync/syncHostService.ts index 87ca86d46..5498e804b 100644 --- a/apps/ade-cli/src/services/sync/syncHostService.ts +++ b/apps/ade-cli/src/services/sync/syncHostService.ts @@ -172,7 +172,7 @@ import { createMachineIdentitySigningStore, type MachineIdentitySigningStore, } from "./machineIdentitySigningStore"; -import { DEFAULT_SYNC_COMPRESSION_THRESHOLD_BYTES, DEFAULT_SYNC_HOST_PORT, DEFAULT_SYNC_MAX_FRAME_BYTES, encodeSyncEnvelope, encodeSyncEnvelopeFrames, mapPlatform, parseSyncEnvelope, SYNC_CHUNKED_ENVELOPES_CAPABILITY, SYNC_RUNTIME_ONLY_CAPABILITY, wsDataToText, type ParsedSyncEnvelope } from "./syncProtocol"; +import { DEFAULT_SYNC_COMPRESSION_THRESHOLD_BYTES, DEFAULT_SYNC_HOST_PORT, DEFAULT_SYNC_MAX_FRAME_BYTES, SYNC_HOST_MAX_PORT, encodeSyncEnvelope, encodeSyncEnvelopeFrames, mapPlatform, parseSyncEnvelope, SYNC_CHUNKED_ENVELOPES_CAPABILITY, SYNC_RUNTIME_ONLY_CAPABILITY, wsDataToText, type ParsedSyncEnvelope } from "./syncProtocol"; import { resolveTailscaleCliPath } from "./resolveTailscaleCliPath"; import { createSyncRemoteCommandService, type SyncRemoteCommandService } from "./syncRemoteCommandService"; import { prepareProductAnalyticsRemoteCommand } from "./productAnalyticsRemoteCommand"; @@ -265,6 +265,40 @@ function isMobileChangesetPeer(peer: { metadata: SyncPeerMetadata | null }): boo return peer.metadata?.deviceType === "phone" || peer.metadata?.platform === "iOS"; } +/** + * Ports still advertised through `tailscale serve` that ADE published on an + * earlier run and never tore down. + * + * Only ADE's exact signature is reclaimed: a port inside ADE's own sync range + * forwarding to 127.0.0.1 on the SAME port. A hand-rolled `tailscale serve` + * that happens to sit in that range — anything forwarding elsewhere — is left + * strictly alone. + */ +export function staleAdeTailnetServePorts( + serveStatusJson: string, + currentPort: number | null, +): number[] { + let parsed: unknown; + try { + parsed = JSON.parse(serveStatusJson); + } catch { + return []; + } + const tcp = (parsed as { TCP?: unknown } | null)?.TCP; + if (!tcp || typeof tcp !== "object") return []; + const stale: number[] = []; + for (const [key, value] of Object.entries(tcp as Record)) { + const port = Number.parseInt(key, 10); + if (!Number.isInteger(port)) continue; + if (port < DEFAULT_SYNC_HOST_PORT || port > SYNC_HOST_MAX_PORT) continue; + if (currentPort != null && port === currentPort) continue; + const forward = (value as { TCPForward?: unknown } | null)?.TCPForward; + if (forward !== `127.0.0.1:${port}`) continue; + stale.push(port); + } + return stale.sort((left, right) => left - right); +} + export function isRuntimeHostPairingRecord( record: SyncPairingRecord | null | undefined, ): boolean { @@ -3852,6 +3886,11 @@ export function createSyncHostService(args: SyncHostServiceArgs) { stdout: stdoutText || null, stderr: stderrText || null, }); + // Best-effort and deliberately after publish: reclaiming old entries + // must never delay or endanger advertising the live port. + if (tailnetServeActivePublishToken === publishToken) { + void reclaimStaleTailnetServes(port).catch(() => {}); + } }) .catch((error: unknown) => { if (tailnetServeActivePublishToken !== publishToken) return; @@ -3894,6 +3933,42 @@ export function createSyncHostService(args: SyncHostServiceArgs) { }); }; + // `serve --bg` outlives the process that registered it, but the port ADE + // tracks is in-memory only, so every restart — and every force-kill that + // skips the teardown below — orphans the previous entry. Tailscale keeps it + // bound on the tailnet address, which makes ADE's own next wildcard bind fail + // EADDRINUSE against its own leftovers and walk one port higher, leaking + // another entry. It ratchets forever; one machine had 66 stranded ports and + // burned ~70 failed binds on every start. Reclaim them whenever we publish. + const reclaimStaleTailnetServes = async (currentPort: number): Promise => { + const cli = resolveTailscaleCliPath(); + let stale: number[]; + try { + const { stdout } = await execFileAsync(cli, ["serve", "status", "--json"], { timeout: 10_000 }); + stale = staleAdeTailnetServePorts(stdout, currentPort); + } catch { + // No Tailscale, no permission, unparseable output: publishing the current + // port matters more than tidying old ones. + return; + } + if (stale.length === 0) return; + let reclaimed = 0; + for (const port of stale) { + try { + await execFileAsync(cli, ["serve", `--tcp=${port}`, "off"], { timeout: 10_000 }); + reclaimed += 1; + } catch { + // A single stubborn entry must not stop the rest. + } + } + args.logger.info("sync_host.tailnet_serve_reclaimed", { + currentPort, + staleCount: stale.length, + reclaimed, + ports: stale.slice(0, 20), + }); + }; + const unpublishTailnetDiscovery = async (): Promise => { if (!tailnetServeSignature) return; tailnetServeActivePublishToken = ++tailnetServePublishSequence; From 258c58fc14a254607526ce0b17516b8acdeb51df Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 11:38:54 -0400 Subject: [PATCH 06/11] fix(doctor): stop reporting an invisible port holder as no holder 'first three base ports have no visible holders' reads as 'the ports are free', which is the opposite of the truth and cost hours of this investigation. The holder is typically tailscaled, which runs as root and is therefore invisible to this user-level probe. Say that, and name the two commands that can actually see it. Co-Authored-By: Claude --- apps/ade-cli/src/commands/doctor.ts | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/apps/ade-cli/src/commands/doctor.ts b/apps/ade-cli/src/commands/doctor.ts index a27a26f80..688627766 100644 --- a/apps/ade-cli/src/commands/doctor.ts +++ b/apps/ade-cli/src/commands/doctor.ts @@ -555,7 +555,14 @@ function syncPortRow(input: DoctorInput): DoctorRow { label: "Sync port", status: "warn", detail: `bound on ${input.syncPort} instead of 8787${ - holders.length ? ` · base holders: ${holders.join("; ")}` : " · first three base ports have no visible holders" + holders.length + ? ` · base holders: ${holders.join("; ")}` + // "No visible holders" reads as "the ports are free", which is exactly + // the wrong conclusion: the holder is usually tailscaled, and it runs + // as root so this probe cannot see it. Point at the check that can. + : " · no holders visible to this user (a root-owned holder such as" + + " tailscaled is invisible here — check `tailscale serve status`" + + " and `netstat -an -p tcp`)" }`, }; } From 89331ba6088de74de2eb44d9a8d899d27556db12 Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 12:13:47 -0400 Subject: [PATCH 07/11] fix(quality): address dual-review findings on the update/relay/port lane MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Correctness (Track A): - reclaimStaleTailnetServes re-checks the live port inside the loop and bails when disposed. The stale set is a snapshot, and reclaiming frees exactly the low ports a restarting host prefers — so a host that rebound mid-loop could have had its own just-published serve entry turned off, leaving the machine with no tailnet route while status still read "published". - pairWithMachine no longer falls back to matching a saved endpoint. A bare LAN address is not a host identity: DHCP handing 192.168.1.240 to a different Mac would have handed that Mac the identity this desktop uses with the first one. The hostDeviceId option covers the real desktop path. Corrected the comment that claimed parity with the account-adoption path, which filters on owner. - The staged quit deadline is Squirrel.Mac-specific; only MacUpdater drives the native updater. On Windows/Linux the staging signal can never arrive, so the long bound would strand the app in "installing" for five minutes where the old code force-quit at ten seconds. Gate the native updater to darwin and use a 60s bound where nothing can signal staging. - stop() releases the host-listener subscription instead of retaining a callback into a disposed client. - attachHostListener skips its eager validation while the listener is unbound; it runs during runtime construction, before ensureListening, and was recording a "listener is not bound" failure that doctor and Settings surfaced. - The paired-rejection message no longer distinguishes "unknown device" from "bad secret" to an unauthenticated caller — that was a device-existence oracle. The host still logs which it was; the user's next step is identical. - The retry tooltip stops promising the download is local once a second failure has cleared the cache. Maintainability (Track B): - cloneSnapshot deep-copies lastInstallFailed, restoring the invariant it exists to hold. - One re-armed escalation timer instead of the arm/clear dance written three times, and quitBlockedMs() instead of the same expression three times. - DEFAULT_QUIT_DEADLINE_MS -> DEFAULT_QUIT_STAGING_SLOW_WARN_MS. Its own comment said "never fatal" while its name said deadline, sitting beside two real deadlines. Names contradicting comments are how the original bug was written. - Production no longer passes the constructor accessors to the tunnel client, so the attached listener is the single source there; they remain an optional test seam. - account-trust log uses machineLayout's runtimeDir rather than re-deriving it, and drops a flushSync that had no process-exit justification. - Documented the relay-tunnel and tailscale-serve failure modes, including that lsof cannot see the root-owned holder. Rejected: the review proposed replacing resolveNativeUpdater's runtime require with a static import, asserting it was verified safe. It is not — tests mock "electron" as { app }, and a static named import makes vitest throw before any test body runs. Kept the require and documented why so it is not "simplified" again. Deferred: extracting the tailnet-serve and quit-watchdog subsystems into their own modules (both pure code motion, both worth doing, neither belongs in the same change as five behavioural fixes). Co-Authored-By: Claude --- apps/ade-cli/src/bootstrap.ts | 5 - .../src/services/sync/syncHostService.test.ts | 4 +- .../src/services/sync/syncHostService.ts | 20 +++- .../services/sync/syncTunnelClientService.ts | 37 ++++--- .../main/services/account/accountBridge.ts | 10 +- .../src/main/services/logging/logger.ts | 10 +- .../remoteRuntime/syncPairedMachineStore.ts | 21 ++-- .../updates/autoUpdateService.test.ts | 6 +- .../services/updates/autoUpdateService.ts | 103 ++++++++++-------- .../components/app/AutoUpdateControl.tsx | 7 +- docs/features/remote-runtime/README.md | 33 ++++++ 11 files changed, 163 insertions(+), 93 deletions(-) diff --git a/apps/ade-cli/src/bootstrap.ts b/apps/ade-cli/src/bootstrap.ts index b759756dc..a5ad42951 100644 --- a/apps/ade-cli/src/bootstrap.ts +++ b/apps/ade-cli/src/bootstrap.ts @@ -1547,11 +1547,6 @@ export async function createAdeRuntime(args: { const service = createSyncTunnelClientService({ logger, configStore: cloudRelayStore, - getSyncPort: () => resolvedArgs.syncRuntime?.sharedSyncListener?.getPort() ?? null, - getExpectedLoopbackNonce: () => - resolvedArgs.syncRuntime?.sharedSyncListener?.getExpectedLoopbackNonce() ?? null, - getRelayBridgeProof: () => - resolvedArgs.syncRuntime?.sharedSyncListener?.getRelayBridgeProof() ?? null, isAccountSignedIn: () => { const status = accountAuthService.getStatus(); return status.signedIn && Boolean(status.userId?.trim()); diff --git a/apps/ade-cli/src/services/sync/syncHostService.test.ts b/apps/ade-cli/src/services/sync/syncHostService.test.ts index 73e96999c..3f39dff92 100644 --- a/apps/ade-cli/src/services/sync/syncHostService.test.ts +++ b/apps/ade-cli/src/services/sync/syncHostService.test.ts @@ -162,12 +162,12 @@ describe("staleAdeTailnetServePorts", () => { "8791": "192.168.1.5:8791", "8792": "127.0.0.1:8792", }); - expect(staleAdeTailnetServePorts(json, null)).toEqual([8792]); + expect(staleAdeTailnetServePorts(json, 8852)).toEqual([8792]); }); it("ignores ports outside ADE's sync range", () => { const json = serveStatus({ "443": "127.0.0.1:443", "9100": "127.0.0.1:9100" }); - expect(staleAdeTailnetServePorts(json, null)).toEqual([]); + expect(staleAdeTailnetServePorts(json, 8852)).toEqual([]); }); it("returns nothing for unparseable or empty status", () => { diff --git a/apps/ade-cli/src/services/sync/syncHostService.ts b/apps/ade-cli/src/services/sync/syncHostService.ts index 5498e804b..b13c200bc 100644 --- a/apps/ade-cli/src/services/sync/syncHostService.ts +++ b/apps/ade-cli/src/services/sync/syncHostService.ts @@ -276,7 +276,7 @@ function isMobileChangesetPeer(peer: { metadata: SyncPeerMetadata | null }): boo */ export function staleAdeTailnetServePorts( serveStatusJson: string, - currentPort: number | null, + currentPort: number, ): number[] { let parsed: unknown; try { @@ -291,7 +291,7 @@ export function staleAdeTailnetServePorts( const port = Number.parseInt(key, 10); if (!Number.isInteger(port)) continue; if (port < DEFAULT_SYNC_HOST_PORT || port > SYNC_HOST_MAX_PORT) continue; - if (currentPort != null && port === currentPort) continue; + if (port === currentPort) continue; const forward = (value as { TCPForward?: unknown } | null)?.TCPForward; if (forward !== `127.0.0.1:${port}`) continue; stale.push(port); @@ -3954,6 +3954,13 @@ export function createSyncHostService(args: SyncHostServiceArgs) { if (stale.length === 0) return; let reclaimed = 0; for (const port of stale) { + // The snapshot is stale the moment reclaiming starts: turning off a low + // port frees it, and a host restarting mid-loop prefers exactly those low + // ports. Without re-checking, this loop can turn off the serve entry a + // newer host just published and leave the machine with no tailnet route + // at all, while status still reports "published". + if (disposed) return; + if (tailnetServePort != null && port === tailnetServePort) continue; try { await execFileAsync(cli, ["serve", `--tcp=${port}`, "off"], { timeout: 10_000 }); reclaimed += 1; @@ -6858,9 +6865,12 @@ export function createSyncHostService(args: SyncHostServiceArgs) { // and tell the client the one thing that actually resolves it. const knownRecord = pairingStore.getPairingRecord(pairedAuth.deviceId); if (!pairingStore.authenticate(pairedAuth.deviceId, pairedAuth.secret)) { - authFailureMessage = knownRecord - ? "This device's saved pairing is no longer valid on this machine. Pair it again." - : "This device is not paired with this machine, or the pairing was removed. Pair it again."; + // Deliberately identical for both cases. The host knows which it + // is and logs it below, but telling an UNAUTHENTICATED caller + // whether a device id exists here turns this into an existence + // oracle, and the user's next step is the same either way. + authFailureMessage = "This device is not paired with this machine, or its saved" + + " pairing is no longer valid. Pair it again."; args.logger.warn("sync_host.paired_device_rejected", { deviceId: pairedAuth.deviceId, reason: knownRecord ? "secret_mismatch" : "unknown_device", diff --git a/apps/ade-cli/src/services/sync/syncTunnelClientService.ts b/apps/ade-cli/src/services/sync/syncTunnelClientService.ts index b6d27d517..603bb3b6f 100644 --- a/apps/ade-cli/src/services/sync/syncTunnelClientService.ts +++ b/apps/ade-cli/src/services/sync/syncTunnelClientService.ts @@ -81,16 +81,19 @@ export type TunnelHostListener = { type SyncTunnelClientArgs = { logger?: Logger; - /** Local ADE sync WebSocket server port, or null when the host isn't up. */ - getSyncPort: () => number | null; - /** Expected identity of the active in-process sync listener. */ - getExpectedLoopbackNonce?: () => string | null; - /** Private proof accepted only by the active in-process sync listener. */ - getRelayBridgeProof: () => string | null; /** Relay is usable only while the host has a current ADE account session. */ isAccountSignedIn?: () => boolean; /** Refresh-aware lease; the account token is validated upstream and never retained here. */ getAccountLease?: () => Promise<{ userId: string; expiresAt?: string | null } | null>; + /** + * Test seam only. Production passes none of these — bootstrap hands the + * listener to attachHostListener instead, so the attached listener is the + * single source of truth there. Wiring them from a per-runtime closure is + * what caused the cached-client bug this replaced. + */ + getSyncPort?: () => number | null; + getExpectedLoopbackNonce?: () => string | null; + getRelayBridgeProof?: () => string | null; configStore: SyncCloudRelayStore; /** Overrides the identity from configStore (e.g. a shared machine store). */ machineIdentity?: () => MachineIdentity | null; @@ -479,17 +482,18 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT } }; - // An attached host listener always wins over the constructor accessors: the - // constructor's closure belongs to whichever runtime bootstrapped first, - // which is often not the one that owns the listener. + // An attached listener wins. Production never supplies the arg accessors, so + // there the listener is the only source — which is the point: the client is + // cached one-per-machine, and a closure captured by the first runtime to + // bootstrap outlived it and silently answered null forever. const syncPort = (): number | null => - hostListener ? hostListener.getPort() : args.getSyncPort(); + hostListener ? hostListener.getPort() : args.getSyncPort?.() ?? null; const expectedLoopbackNonce = (): string | null => hostListener ? hostListener.getExpectedLoopbackNonce() : args.getExpectedLoopbackNonce?.() ?? null; const relayBridgeProofValue = (): string | null => - hostListener ? hostListener.getRelayBridgeProof() : args.getRelayBridgeProof(); + hostListener ? hostListener.getRelayBridgeProof() : args.getRelayBridgeProof?.() ?? null; const bridgeValidationIdentity = (): BridgeValidationIdentity => { const eligible = accountSignedIn(); @@ -1678,8 +1682,12 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT }); }); // The listener may already be bound and validated by the time the host - // attaches, in which case no future event is coming. - if (!stopped) { + // attaches, in which case no future event is coming. Skip while it is + // still unbound: attach happens during runtime construction, before + // ensureListening, and validating there only records a "listener is not + // bound" failure that doctor and Settings surface until the subscription + // above clears it. + if (!stopped && listener.getPort() != null) { void validateCurrentBridge().catch(() => {}); } }, @@ -1687,6 +1695,9 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT async stop(): Promise { stopped = true; started = false; + detachHostListener?.(); + detachHostListener = null; + hostListener = null; clearReconnect(); if (accountStatusTimer) { clearInterval(accountStatusTimer); diff --git a/apps/desktop/src/main/services/account/accountBridge.ts b/apps/desktop/src/main/services/account/accountBridge.ts index c4c123b5d..b0be44122 100644 --- a/apps/desktop/src/main/services/account/accountBridge.ts +++ b/apps/desktop/src/main/services/account/accountBridge.ts @@ -179,9 +179,9 @@ export function createAccountBridge(options: AccountBridgeOptions): AccountBridg const getMachineLogger = (): Logger | null => { if (machineLogger !== undefined) return machineLogger; try { - const adeDir = resolveMachineAdeLayout().adeDir; - machineLogger = adeDir - ? createFileLogger(path.join(adeDir, "runtime", "account-trust.jsonl")) + const { runtimeDir } = resolveMachineAdeLayout(); + machineLogger = runtimeDir + ? createFileLogger(path.join(runtimeDir, "account-trust.jsonl")) : null; } catch { machineLogger = null; @@ -211,9 +211,7 @@ export function createAccountBridge(options: AccountBridgeOptions): AccountBridg ownerChanged: credentials.previousOwnerUserId !== result.currentOwnerUserId, })), }; - const sink = getMachineLogger(); - sink?.warn("account.local_machines_removed", detail); - sink?.flushSync?.(); + getMachineLogger()?.warn("account.local_machines_removed", detail); options.logger?.info("account.local_machines_removed", detail); } }; diff --git a/apps/desktop/src/main/services/logging/logger.ts b/apps/desktop/src/main/services/logging/logger.ts index a60536214..ce05c8bd0 100644 --- a/apps/desktop/src/main/services/logging/logger.ts +++ b/apps/desktop/src/main/services/logging/logger.ts @@ -29,10 +29,12 @@ export type Logger = { info: (event: string, meta?: Record) => void; warn: (event: string, meta?: Record) => void; error: (event: string, meta?: Record) => void; - // Writes anything still queued straight to disk. Normal logging batches - // through an async stream, so a caller that is about to end the process - // (app.exit, force quit) must call this or its last records are lost — - // exactly the records that explain why the process died. + // Writes still-queued lines straight to disk. Normal logging batches through + // an async stream, so a caller about to end the process (app.exit, force + // quit) must call this or its last records are lost — exactly the records + // that explain why the process died. Note it cannot recover a batch already + // handed to an in-flight async flush, so call it immediately after the write + // that matters, while that line is still queued. flushSync?: () => void; }; diff --git a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts index 9d8a1353f..695e0f9fc 100644 --- a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts +++ b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts @@ -586,20 +586,23 @@ export class DesktopPairedMachineStore { const keys = generateDesktopDpopKeyPair(); // Re-pairing the same machine must reuse this desktop's existing pairing - // identity, exactly as the account-adoption path already does. The host - // keys its pairing records by this device id and upserts on re-pair, so - // minting a fresh one instead leaves behind a record the host can never - // match again — one orphaned, still-valid secret per re-pair, forever. - // The hello that reports the host identity comes after the pairing request - // that carries this id, so recover the prior record up front: by the host - // the caller is aiming at, else the relay machine key, else the endpoint - // already recorded against a known machine. + // identity. The host keys its pairing records by this device id and upserts + // on re-pair, so minting a fresh one instead leaves behind a record the host + // can never match again — one orphaned, still-valid secret per re-pair, + // forever. + // + // The hello that reports the host identity arrives after the pairing request + // that carries this id, so the prior record has to be recovered up front: + // by the host the caller is aiming at, else the relay machine key. Both + // identify a HOST. Matching on a saved endpoint deliberately is not an + // option — a bare LAN address is not a host identity, so DHCP handing + // 192.168.1.240 to a different Mac would hand that Mac the identity this + // desktop uses with the first one. const endpointMachineKey = machineKeyFromEndpoint(endpoint); const existing = (options.hostDeviceId?.trim() ? this.get(options.hostDeviceId.trim()) : null) ?? (endpointMachineKey ? this.get(endpointMachineKey) : null) - ?? this.list().find((machine) => machine.endpoints.includes(endpoint)) ?? null; const localDeviceId = existing?.deviceId ?? randomUUID(); const siteId = existing?.siteId ?? randomUUID(); diff --git a/apps/desktop/src/main/services/updates/autoUpdateService.test.ts b/apps/desktop/src/main/services/updates/autoUpdateService.test.ts index 544ea7b0e..13685fb48 100644 --- a/apps/desktop/src/main/services/updates/autoUpdateService.test.ts +++ b/apps/desktop/src/main/services/updates/autoUpdateService.test.ts @@ -1396,7 +1396,7 @@ describe("createAutoUpdateService", () => { globalStatePath, updaterCacheDir, installWatchdogMs: 1_000, - quitDeadlineMs: 5_000, + quitStagingSlowWarnMs: 5_000, quitHardDeadlineMs: 300_000, nativeUpdater, forceQuit, @@ -1442,7 +1442,7 @@ describe("createAutoUpdateService", () => { globalStatePath, updaterCacheDir, installWatchdogMs: 1_000, - quitDeadlineMs: 5_000, + quitStagingSlowWarnMs: 5_000, quitHardDeadlineMs: 300_000, quitPostStagingDeadlineMs: 15_000, nativeUpdater, @@ -1493,7 +1493,7 @@ describe("createAutoUpdateService", () => { globalStatePath, updaterCacheDir, installWatchdogMs: 1_000, - quitDeadlineMs: 5_000, + quitStagingSlowWarnMs: 5_000, quitHardDeadlineMs: 300_000, nativeUpdater: null, forceQuit, diff --git a/apps/desktop/src/main/services/updates/autoUpdateService.ts b/apps/desktop/src/main/services/updates/autoUpdateService.ts index fcc1268e3..917c0ca4e 100644 --- a/apps/desktop/src/main/services/updates/autoUpdateService.ts +++ b/apps/desktop/src/main/services/updates/autoUpdateService.ts @@ -29,15 +29,19 @@ import { } from "./autoUpdateVersions"; const DEFAULT_INSTALL_WATCHDOG_MS = 30_000; -// Soft mark only. After `quitAndInstall` the OS installer (Squirrel.Mac) still -// has to pull the archive over its loopback server, expand it, and code-sign -// verify the expanded bundle before it can spawn ShipIt and replace us. For an -// ~750 MB archive that runs right around ten seconds, so treating this as a -// deadline to kill the process loses a coin flip against a healthy install. -const DEFAULT_QUIT_DEADLINE_MS = 10_000; +// Warn only, never fatal. Squirrel.Mac needs roughly this long just to expand +// and code-sign verify the archive, so killing here loses a coin flip against a +// healthy install — which is exactly the bug this replaced. +const DEFAULT_QUIT_STAGING_SLOW_WARN_MS = 10_000; // Hard bound while the OS installer may still be staging. Only a genuinely -// wedged handoff should reach this. +// wedged handoff should reach this. macOS only: it is long because Squirrel.Mac +// stages in-process and signals when it is done. const DEFAULT_QUIT_HARD_DEADLINE_MS = 5 * 60_000; +// Everywhere else the installer is an external process (NSIS, AppImage) that +// never emits the staging signal, so the long bound would just hang the app in +// "installing" for five minutes. Nothing stages in-process there, so a short +// bound is correct — and still far more generous than the 10s that broke macOS. +const DEFAULT_QUIT_HARD_DEADLINE_NO_STAGING_MS = 60_000; // Once staging is done the installer is already running and about to replace // the bundle, so a process that still has not exited is a real wedge and a // short bound is safe again. @@ -74,6 +78,11 @@ type NativeUpdaterLike = { }; function resolveNativeUpdater(): NativeUpdaterLike | null { + // Resolved through require, NOT a static import, and this is load-bearing: + // tests mock "electron" as `{ app }`, and a static `import { autoUpdater }` + // makes vitest throw "No 'autoUpdater' export is defined on the electron + // mock" before any test body runs. A missing native updater must degrade to + // "no staging signal", never to a crash. try { if (typeof require !== "function") return null; const electron = require("electron") as { autoUpdater?: NativeUpdaterLike }; @@ -103,7 +112,7 @@ type CreateAutoUpdateServiceArgs = { installTargetPath?: string; getDiskSpace?: (targetPath: string) => DiskSpaceInfo; installWatchdogMs?: number; - quitDeadlineMs?: number; + quitStagingSlowWarnMs?: number; quitHardDeadlineMs?: number; quitPostStagingDeadlineMs?: number; nativeUpdater?: NativeUpdaterLike | null; @@ -190,6 +199,7 @@ function cloneSnapshot(snapshot: AutoUpdateSnapshot): AutoUpdateSnapshot { ...snapshot, recentlyInstalled: cloneRecentlyInstalledUpdate(snapshot.recentlyInstalled), parked: snapshot.parked ? { ...snapshot.parked } : null, + lastInstallFailed: snapshot.lastInstallFailed ? { ...snapshot.lastInstallFailed } : null, autoApplyPending: snapshot.autoApplyPending ? { ...snapshot.autoApplyPending } : null, }; } @@ -339,10 +349,15 @@ export function createAutoUpdateService({ installTargetPath = process.execPath, getDiskSpace = readDiskSpace, installWatchdogMs = DEFAULT_INSTALL_WATCHDOG_MS, - quitDeadlineMs = DEFAULT_QUIT_DEADLINE_MS, - quitHardDeadlineMs = DEFAULT_QUIT_HARD_DEADLINE_MS, + quitStagingSlowWarnMs = DEFAULT_QUIT_STAGING_SLOW_WARN_MS, + // Only Squirrel.Mac reports staging progress; electron-updater's other + // backends never touch the native updater, so arming the long bound off a + // signal that cannot arrive would strand the app in "installing". + nativeUpdater = process.platform === "darwin" ? resolveNativeUpdater() : null, + quitHardDeadlineMs = nativeUpdater + ? DEFAULT_QUIT_HARD_DEADLINE_MS + : DEFAULT_QUIT_HARD_DEADLINE_NO_STAGING_MS, quitPostStagingDeadlineMs = DEFAULT_QUIT_POST_STAGING_DEADLINE_MS, - nativeUpdater = resolveNativeUpdater(), autoApplyIdleMs = DEFAULT_AUTO_APPLY_IDLE_MS, autoApplyCountdownMs = DEFAULT_AUTO_APPLY_COUNTDOWN_MS, autoApplySuppressionMs = DEFAULT_AUTO_APPLY_SUPPRESSION_MS, @@ -434,8 +449,8 @@ export function createAutoUpdateService({ let compressedUpdateBytes: number | null = null; let compressedUpdateVersion: string | null = null; let preservedDownloadRetry: PreservedDownloadRetry | null = null; - let quitDeadlineTimer: ReturnType | null = null; - let quitSoftDeadlineTimer: ReturnType | null = null; + let escalationTimer: ReturnType | null = null; + let stagingSlowWarnTimer: ReturnType | null = null; let quitArmedAtMs: number | null = null; let nativeStagingCompleted = false; let detachNativeStagingListener: (() => void) | null = null; @@ -478,13 +493,13 @@ export function createAutoUpdateService({ } function clearQuitDeadline(): void { - if (quitDeadlineTimer) { - clearTimeout(quitDeadlineTimer); - quitDeadlineTimer = null; + if (escalationTimer) { + clearTimeout(escalationTimer); + escalationTimer = null; } - if (quitSoftDeadlineTimer) { - clearTimeout(quitSoftDeadlineTimer); - quitSoftDeadlineTimer = null; + if (stagingSlowWarnTimer) { + clearTimeout(stagingSlowWarnTimer); + stagingSlowWarnTimer = null; } detachNativeStagingListener?.(); detachNativeStagingListener = null; @@ -1171,7 +1186,7 @@ export function createAutoUpdateService({ function escalateQuit(reason: "hard_deadline" | "post_staging"): void { if (!installQuitArmed) return; - const blockedMs = Math.max(0, nowMs() - (quitArmedAtMs ?? nowMs())); + const blockedMs = quitBlockedMs(); const blockedPhase = "app_quit"; logger.error("autoUpdate.quit_escalated", { blockedPhase, @@ -1195,23 +1210,27 @@ export function createAutoUpdateService({ forceQuit?.({ blockedPhase, blockedMs }); } + const quitBlockedMs = (): number => Math.max(0, nowMs() - (quitArmedAtMs ?? nowMs())); + + // One escalation timer, re-armed. Before staging completes it carries the + // long bound; after, the short one. Two variables would imply two ways to get + // force-quit, and there is only ever one armed at a time. + function armEscalation(delayMs: number, reason: "hard_deadline" | "post_staging"): void { + if (escalationTimer) clearTimeout(escalationTimer); + escalationTimer = setTimeout(() => { + escalationTimer = null; + escalateQuit(reason); + }, delayMs); + escalationTimer.unref?.(); + } + // Squirrel finished expanding and verifying the new bundle and is handing off // to its installer, so the remaining window is short and bounded. function onNativeStagingComplete(): void { if (!installQuitArmed || nativeStagingCompleted) return; nativeStagingCompleted = true; - logger.info("autoUpdate.native_staging_complete", { - elapsedMs: Math.max(0, nowMs() - (quitArmedAtMs ?? nowMs())), - }); - if (quitDeadlineTimer) { - clearTimeout(quitDeadlineTimer); - quitDeadlineTimer = null; - } - quitDeadlineTimer = setTimeout(() => { - quitDeadlineTimer = null; - escalateQuit("post_staging"); - }, quitPostStagingDeadlineMs); - quitDeadlineTimer.unref?.(); + logger.info("autoUpdate.native_staging_complete", { elapsedMs: quitBlockedMs() }); + armEscalation(quitPostStagingDeadlineMs, "post_staging"); } function armQuitDeadline(): void { @@ -1234,20 +1253,14 @@ export function createAutoUpdateService({ // Observation, not enforcement: staging legitimately runs past this on a // large bundle or a busy disk. Killing here is what broke installs before. - quitSoftDeadlineTimer = setTimeout(() => { - quitSoftDeadlineTimer = null; + stagingSlowWarnTimer = setTimeout(() => { + stagingSlowWarnTimer = null; if (!installQuitArmed || nativeStagingCompleted) return; - logger.warn("autoUpdate.quit_staging_slow", { - blockedMs: Math.max(0, nowMs() - (quitArmedAtMs ?? nowMs())), - }); - }, quitDeadlineMs); - quitSoftDeadlineTimer.unref?.(); - - quitDeadlineTimer = setTimeout(() => { - quitDeadlineTimer = null; - escalateQuit("hard_deadline"); - }, quitHardDeadlineMs); - quitDeadlineTimer.unref?.(); + logger.warn("autoUpdate.quit_staging_slow", { blockedMs: quitBlockedMs() }); + }, quitStagingSlowWarnMs); + stagingSlowWarnTimer.unref?.(); + + armEscalation(quitHardDeadlineMs, "hard_deadline"); } function dismissInstalledNotice(): void { diff --git a/apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx b/apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx index fd3f47c47..12733a0c0 100644 --- a/apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx +++ b/apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx @@ -208,6 +208,9 @@ export function AutoUpdateControl() { && snapshot.version && snapshot.lastInstallFailed.targetVersion === snapshot.version, ); + // A second consecutive failure stops trusting the archive and clears the + // cache, so only the first retry can promise the bytes are still local. + const downloadStillLocal = (snapshot.lastInstallFailed?.attempt ?? 0) < 2; function indicatorTitle(): string { switch (effectiveStatus) { @@ -220,7 +223,9 @@ export function AutoUpdateControl() { default: return retryAfterFailedInstall ? `The last attempt to install ${versionLabel(snapshot.version)} quit without finishing. ` - + "Try again — the download is already on this machine." + + (downloadStillLocal + ? "Try again — the download is already on this machine." + : "Try again — ADE will download it again first.") : `Install ${versionLabel(snapshot.version)}. ADE will quit and reopen automatically.`; } } diff --git a/docs/features/remote-runtime/README.md b/docs/features/remote-runtime/README.md index a7338884b..f56a1d27e 100644 --- a/docs/features/remote-runtime/README.md +++ b/docs/features/remote-runtime/README.md @@ -517,6 +517,39 @@ Two logs make a lost pairing diagnosable, both of which were previously silent: current owner per removed credential, so an intended account switch is distinguishable from an identity glitch that silently cost trust. +## Relay tunnel and the sync port + +The relay tunnel client is cached **one per machine**, keyed by the cloud-relay +config file, and is built by whichever runtime bootstraps first — regularly a +scope that owns no shared listener (a headless one-shot, an embedded fallback). +So it must not capture per-runtime state at construction. The runtime that owns +the listener calls `attachHostListener()`, which supplies the port, loopback +nonce, and bridge proof, registers the `onLoopbackValidated` retry hook, and +validates once the listener is bound. Symptom when this is wrong: +`routeHealth.listener` reports bound and loopback-validated on a real port while +`relayBridgeValidated` is false and `lastBridgeValidationAt` has never been set — +relay silently never works, and a LAN auth failure becomes a total outage +because no fallback route exists. + +ADE advertises its sync port with `tailscale serve --bg --tcp=`. That +outlives the process that registered it, so the served port is reclaimed after +each successful publish (`staleAdeTailnetServePorts` + +`reclaimStaleTailnetServes`). Without it every restart — and every force-kill +that skips teardown — orphans an entry that Tailscale keeps bound on the tailnet +address; ADE's own next wildcard bind then fails `EADDRINUSE` against its own +leftover and walks one port higher, leaking another. It ratchets forever: one +machine reached 66 stranded ports and ~70 failed binds per start, drifting from +8787 to 8852. + +Only ADE's exact signature is reclaimed — a port inside ADE's sync range +forwarding to `127.0.0.1` on the **same** port — so a hand-rolled +`tailscale serve` is left alone, and the live port is re-checked inside the loop +because reclaiming frees exactly the low ports a restarting host prefers. + +Diagnosing this needs `netstat -an -p tcp` or `tailscale serve status`, **not** +`lsof`: tailscaled runs as root, so a user-level probe reports the ports as +having no holder, which reads as "free" and is the opposite of the truth. + ## Related docs - [Internal architecture](./internal-architecture.md) — protocol shape, bootstrap sequence, sync command scoping. From 52f0ddfac65af48fd4c961a671d5ef8d04b50c34 Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 13:55:58 -0400 Subject: [PATCH 08/11] test(update,sync): pin the quality-pass regressions and register the new event MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Analytics gate: `ade_update_install_did_not_land` is a new event, so it is registered in the dashboard spec's Reliability incidents insight and documented in docs/logging.md. The volume insight addresses series as A..Z and derives the formula from the catalog, so a 27th event would have silently emitted an invalid "[" term — added a guard that fails loudly instead. Provisioner validate + spec tests pass (8/8). Regression tests for fixes the quality pass applied: - The updater falls back to the short hard bound when no staging signal can arrive. Only Squirrel.Mac drives the native updater, so on Windows/Linux the long bound would strand the app in "installing" for five minutes. - pairWithMachine does not reuse an identity from a different host that once used the same endpoint — the DHCP address-reuse case. - stop() releases the host-listener subscription instead of retaining a callback into a disposed client. No tests pruned: the five test files without a 1:1 source sibling are intentional feature-level suites whose imports all resolve, and the single it.skip is env-conditional. No consolidation: the touched folders are within the per-folder budget and every addition extended an existing file. Co-Authored-By: Claude --- .../sync/syncTunnelClientService.test.ts | 28 ++++++++ .../syncPairedMachineStore.test.ts | 65 +++++++++++++++++++ .../updates/autoUpdateService.test.ts | 44 +++++++++++++ docs/logging.md | 3 +- scripts/posthog/dashboard-spec.mjs | 12 +++- scripts/posthog/provision.test.mjs | 4 +- 6 files changed, 152 insertions(+), 4 deletions(-) diff --git a/apps/ade-cli/src/services/sync/syncTunnelClientService.test.ts b/apps/ade-cli/src/services/sync/syncTunnelClientService.test.ts index 35f2b787d..52b8b0c86 100644 --- a/apps/ade-cli/src/services/sync/syncTunnelClientService.test.ts +++ b/apps/ade-cli/src/services/sync/syncTunnelClientService.test.ts @@ -449,6 +449,34 @@ describe("createSyncTunnelClientService", () => { } }); + // Regression: stop() left the loopback subscription installed, so the + // listener retained a callback into a disposed client for the process + // lifetime. + it("releases the host listener subscription on stop", async () => { + const unsubscribe = vi.fn(); + const onLoopbackValidated = vi.fn(() => unsubscribe); + const fakeListener = { + getPort: () => 8787, + getExpectedLoopbackNonce: () => "n".repeat(43), + getRelayBridgeProof: () => "e".repeat(43), + onLoopbackValidated, + }; + const service = createSyncTunnelClientService({ + configStore: fakeStore("https://relay.example.com"), + }); + try { + service.attachHostListener(fakeListener); + expect(onLoopbackValidated).toHaveBeenCalledTimes(1); + expect(unsubscribe).not.toHaveBeenCalled(); + + await service.stop(); + + expect(unsubscribe).toHaveBeenCalledTimes(1); + } finally { + await service.dispose(); + } + }); + it("keeps Relay offline signed out, resumes on sign-in, and closes when token refresh fails", async () => { const relay = new WebSocketServer({ host: "127.0.0.1", port: 0 }); await new Promise((resolve, reject) => { diff --git a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.test.ts b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.test.ts index 6c766f9f8..070646241 100644 --- a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.test.ts +++ b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.test.ts @@ -400,6 +400,71 @@ describe("DesktopPairedMachineStore", () => { expect(new DesktopPairedMachineStore().list()).toHaveLength(1); }); + // Regression: identity recovery once fell back to matching any saved record + // holding this endpoint. A bare LAN address is not a host identity — DHCP + // handing 192.168.1.240 to a different Mac would have handed that Mac the + // identity this desktop uses with the first one. + it("does not reuse an identity from a different host that once used this endpoint", async () => { + const adeHome = fs.mkdtempSync(path.join(os.tmpdir(), "ade-desktop-endpoint-")); + process.env.ADE_HOME = adeHome; + const presentedDeviceIds: string[] = []; + const sharedEndpoint = "ws://192.168.1.240:8806"; + + const makeSocket = (hostDeviceId: string) => () => new FakeWebSocket((text, ws) => { + const envelope = parseSyncEnvelope(wsDataToText(text)); + if (envelope.type === "pairing_request") { + const payload = envelope.payload as { peer: { deviceId: string } }; + presentedDeviceIds.push(payload.peer.deviceId); + ws.receive(encodeSyncEnvelope({ + type: "pairing_result", + requestId: envelope.requestId, + payload: { ok: true, deviceId: payload.peer.deviceId, secret: "host-issued-secret" }, + })); + return; + } + if (envelope.type !== "hello") return; + const payload = envelope.payload as { peer: unknown }; + ws.receive(encodeSyncEnvelope({ + type: "hello_ok", + requestId: envelope.requestId, + payload: { + peer: payload.peer, + brain: { + deviceId: hostDeviceId, + deviceName: hostDeviceId, + platform: "macOS", + deviceType: "desktop", + siteId: `${hostDeviceId}-site`, + dbVersion: 0, + }, + serverDbVersion: 0, + heartbeatIntervalMs: 5_000, + pollIntervalMs: 1_500, + features: { rpcChannel: true, portForward: true }, + }, + })); + }) as unknown as WebSocket; + + const store = new DesktopPairedMachineStore(); + const first = await store.pairWithMachine(sharedEndpoint, "123456", "Desktop client", { + pairingTimeoutMs: 2_000, + createWebSocket: makeSocket("mac-a"), + hostDeviceId: "mac-a", + }); + // Same address, different machine answering — the record for mac-a still + // lists this endpoint. + const second = await store.pairWithMachine(sharedEndpoint, "123456", "Desktop client", { + pairingTimeoutMs: 2_000, + createWebSocket: makeSocket("mac-b"), + hostDeviceId: "mac-b", + }); + + expect(presentedDeviceIds).toHaveLength(2); + expect(second.deviceId).not.toBe(first.deviceId); + expect(second.siteId).not.toBe(first.siteId); + expect(new DesktopPairedMachineStore().list()).toHaveLength(2); + }); + it("replaces stale relay connection metadata only when explicitly requested", () => { const filePath = path.join( fs.mkdtempSync(path.join(os.tmpdir(), "ade-desktop-pairing-store-")), diff --git a/apps/desktop/src/main/services/updates/autoUpdateService.test.ts b/apps/desktop/src/main/services/updates/autoUpdateService.test.ts index 13685fb48..007223c61 100644 --- a/apps/desktop/src/main/services/updates/autoUpdateService.test.ts +++ b/apps/desktop/src/main/services/updates/autoUpdateService.test.ts @@ -1480,6 +1480,50 @@ describe("createAutoUpdateService", () => { service.dispose(); }); + // Regression: the staged deadline is Squirrel.Mac-specific. Only MacUpdater + // drives the native updater, so on Windows/Linux the staging signal can never + // arrive — the long bound would strand the app in "installing" for five + // minutes where the previous code force-quit in ten seconds. + it("falls back to the short hard bound when no staging signal can arrive", async () => { + vi.useFakeTimers(); + const globalStatePath = makeStatePath(); + const updaterCacheDir = makeUpdaterCacheDir(); + const updater = new FakeAutoUpdater(); + const logger = makeLogger(); + const forceQuit = vi.fn(); + const service = createAutoUpdateService({ + logger, + currentVersion: "1.2.2", + globalStatePath, + updaterCacheDir, + installWatchdogMs: 1_000, + // No hard bound supplied: the default must come from whether a staging + // signal is possible at all, not from the macOS-only five-minute value. + nativeUpdater: null, + forceQuit, + getDiskSpace: () => ({ + availableBytes: 20 * 1024 * 1024 * 1024, + volumePath: "/System/Volumes/Data", + }), + autoCheckEnabled: false, + updater, + }); + updater.emit("update-downloaded", { version: "1.2.3" }); + + await expect(service.quitAndInstall()).resolves.toBe(true); + + await vi.advanceTimersByTimeAsync(59_000); + expect(forceQuit).not.toHaveBeenCalled(); + + await vi.advanceTimersByTimeAsync(1_500); + expect(forceQuit).toHaveBeenCalledWith({ + blockedPhase: "app_quit", + blockedMs: 60_000, + }); + + service.dispose(); + }); + it("force-quits a handoff that never stages at all, at the hard deadline", async () => { vi.useFakeTimers(); const globalStatePath = makeStatePath(); diff --git a/docs/logging.md b/docs/logging.md index 8442ee8fc..cec492196 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -80,12 +80,13 @@ The public contract is `apps/desktop/src/shared/types/productAnalytics.ts`. The - `ade_analytics_budget` - `ade_update_install_aborted` - `ade_update_quit_escalated` +- `ade_update_install_did_not_land` - `ade_update_auto_applied` - `ade_update_auto_apply_cancelled` - `ade_brain_recovered` - `ade_publish_failing` -The update and reliability events are low-frequency by construction: the four `ade_update_*` events fire at most once per install attempt or idle-apply cycle (daily caps 10–20, minute caps 3–6); `ade_brain_recovered` fires once per wedge recovery at brain startup; `ade_publish_failing` is edge-triggered once per sustained failure episode (first crossing of two minutes), never per attempt. Properties are closed enums and bounded numbers — `reason` is allowlisted to the abort-reason constant, `last_command` is a closed sync-action slug, and `leg`/`code` are the coarse publish classifications. Worst-case combined volume is a handful of events on a very bad day, inside the shared ceiling. +The update and reliability events are low-frequency by construction: the five `ade_update_*` events fire at most once per install attempt or idle-apply cycle (daily caps 10–20, minute caps 3–6). `ade_update_install_did_not_land` is emitted once at startup when a requested install relaunched on the old version, so it is bounded by app launches that follow a failed handoff, and carries only a bounded `attempt` counter; `ade_brain_recovered` fires once per wedge recovery at brain startup; `ade_publish_failing` is edge-triggered once per sustained failure episode (first crossing of two minutes), never per attempt. Properties are closed enums and bounded numbers — `reason` is allowlisted to the abort-reason constant, `last_command` is a closed sync-action slug, and `leg`/`code` are the coarse publish classifications. Worst-case combined volume is a handful of events on a very bad day, inside the shared ceiling. The default machine-wide ceiling is 200 accepted events per UTC day, shared across desktop, runtime, TUI, hosted web, and API-originated aggregates. Each event also has a tighter per-day and per-minute ceiling. Capture ingress is capped, noisy events use persisted deduplication windows, the in-memory transport queue is bounded, and the previous day's accepted/drop totals are summarized in at most two budget events per day. diff --git a/scripts/posthog/dashboard-spec.mjs b/scripts/posthog/dashboard-spec.mjs index 23b427184..e54557029 100644 --- a/scripts/posthog/dashboard-spec.mjs +++ b/scripts/posthog/dashboard-spec.mjs @@ -13,6 +13,7 @@ export const EVENTS = Object.freeze({ ANALYTICS_BUDGET: "ade_analytics_budget", UPDATE_INSTALL_ABORTED: "ade_update_install_aborted", UPDATE_QUIT_ESCALATED: "ade_update_quit_escalated", + UPDATE_INSTALL_DID_NOT_LAND: "ade_update_install_did_not_land", UPDATE_AUTO_APPLIED: "ade_update_auto_applied", UPDATE_AUTO_APPLY_CANCELLED: "ade_update_auto_apply_cancelled", BRAIN_RECOVERED: "ade_brain_recovered", @@ -30,6 +31,14 @@ export const EVENTS = Object.freeze({ }); const ALL_INGESTED_EVENTS = Object.freeze(Object.values(EVENTS)); +// PostHog series letters are A..Z, so the catalog cannot exceed 26 events +// without a different addressing scheme. Fail loudly here rather than emitting +// a formula containing "[" that PostHog would silently reject. +if (ALL_INGESTED_EVENTS.length > 26) { + throw new Error( + `Event catalog has ${ALL_INGESTED_EVENTS.length} events; the volume insight formula only addresses 26 (A..Z).`, + ); +} const ALL_INGESTED_EVENTS_FORMULA = ALL_INGESTED_EVENTS .map((_, index) => String.fromCharCode("A".charCodeAt(0) + index)) .join("+"); @@ -517,6 +526,7 @@ export const dashboardSpec = Object.freeze({ eventNode(EVENTS.PUBLISH_FAILING, "Route publish failing"), eventNode(EVENTS.UPDATE_INSTALL_ABORTED, "Update install aborted"), eventNode(EVENTS.UPDATE_QUIT_ESCALATED, "Update quit escalated"), + eventNode(EVENTS.UPDATE_INSTALL_DID_NOT_LAND, "Update did not land"), eventNode(EVENTS.UPDATE_AUTO_APPLIED, "Update auto-applied"), ], interval: "day", @@ -562,7 +572,7 @@ export const dashboardSpec = Object.freeze({ insight( "monthly-analytics-volume", "30-day ingested analytics volume", - "PostHog's actual ingested count across ADE's closed 25-event catalog. The goal line marks the current 1,000,000-event monthly Product Analytics free allowance. This is an instrumentation health view, not the account billing meter: stray or abusive events sent with the public project token are outside this chart.", + "PostHog's actual ingested count across ADE's closed 26-event catalog. The goal line marks the current 1,000,000-event monthly Product Analytics free allowance. This is an instrumentation health view, not the account billing meter: stray or abusive events sent with the public project token are outside this chart.", trends({ series: ALL_INGESTED_EVENTS.map((event) => eventNode(event, event)), formula: ALL_INGESTED_EVENTS_FORMULA, diff --git a/scripts/posthog/provision.test.mjs b/scripts/posthog/provision.test.mjs index 4feee4228..f50bdb29c 100644 --- a/scripts/posthog/provision.test.mjs +++ b/scripts/posthog/provision.test.mjs @@ -76,8 +76,8 @@ test("dashboard queries match the bounded instrumentation semantics", () => { const ingestedVolume = findInsight("monthly-analytics-volume"); assert.equal(ingestedVolume.name, "30-day ingested analytics volume"); - assert.equal(ingestedVolume.query.source.series.length, 25); - assert.equal(ingestedVolume.query.source.trendsFilter.formula, "A+B+C+D+E+F+G+H+I+J+K+L+M+N+O+P+Q+R+S+T+U+V+W+X+Y"); + assert.equal(ingestedVolume.query.source.series.length, 26); + assert.equal(ingestedVolume.query.source.trendsFilter.formula, "A+B+C+D+E+F+G+H+I+J+K+L+M+N+O+P+Q+R+S+T+U+V+W+X+Y+Z"); }); test("config requires HTTPS and a numeric project ID", () => { From d1de0c906b030fc97c2c73b6cccd99b4fb63d0b2 Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 14:15:22 -0400 Subject: [PATCH 09/11] docs,cli,ios: parity passes for the update/relay/port lane MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Docs review found real errors in this lane's own documentation. The remote-runtime README described a pairing-identity fallback that matches a saved endpoint — the quality pass had REMOVED that fallback precisely because DHCP could hand another Mac the address, and a regression test now asserts it must not happen. It also claimed account.local_machines_removed is written only to the machine sink when the code also mirrors it to the project logger. Both corrected, plus the platform split on the quit deadline, the flushSync contract, the account-trust sink, and the 26-event catalog cap. CLI: `ade update status --text` had no formatter, so it fell through to the generic action-result dump and rendered lastInstallFailed as an unlabeled JSON blob. Added a real formatter with an explicit failed-install row, and corrected `ade help update`, which claimed a failed install always falls back to error — it now explains that "installing" can legitimately sit for minutes and that the desktop app should not be killed to unstick it. Verified the high-value case: exactly one production construction site for the tunnel client, and it attaches the listener immediately after, so no runtime silently loses relay. iOS: no source changes needed. The pairing deviceId is minted once and held in the Keychain across re-pair, forget, and trust reset, so iOS never had the bug the desktop just fixed; and auth failures branch on ADEErrorCode before any string match, so the reworded host messages cannot break it. Added a test that locks that invariant against the new wording. TUI: no changes required; verified rather than assumed. Co-Authored-By: Claude --- apps/ade-cli/src/cli.test.ts | 62 +++++++++++ apps/ade-cli/src/cli.ts | 105 +++++++++++++++++- apps/ade-cli/src/commands/doctor.ts | 6 + apps/ios/ADETests/ADETests.swift | 48 ++++++++ docs/ARCHITECTURE.md | 6 +- .../onboarding-and-settings/README.md | 24 +++- .../desktop-auto-update.md | 37 ++++-- docs/features/remote-runtime/README.md | 78 ++++++++----- docs/features/sync-and-multi-device/README.md | 35 +++++- docs/logging.md | 10 +- 10 files changed, 354 insertions(+), 57 deletions(-) diff --git a/apps/ade-cli/src/cli.test.ts b/apps/ade-cli/src/cli.test.ts index 75cef138d..592ffa780 100644 --- a/apps/ade-cli/src/cli.test.ts +++ b/apps/ade-cli/src/cli.test.ts @@ -1328,6 +1328,68 @@ describe("ADE CLI", () => { expect(output).not.toContain("no PIN set"); }); + it("surfaces a prior install that did not land in update status --text", () => { + const plan = expectExecutePlan(buildCliPlan(["update", "status"])); + expect(inferFormatter(plan)).toBe("update-status"); + + const output = formatOutput( + { + status: "ready", + currentVersion: "1.2.37", + latestKnownVersion: "1.2.38", + version: "1.2.38", + progressPercent: null, + bytesPerSecond: null, + transferredBytes: null, + totalBytes: null, + releaseNotesUrl: null, + error: null, + errorDetails: null, + recentlyInstalled: null, + parked: null, + lastInstallFailed: { targetVersion: "1.2.38", attempt: 2 }, + autoApplyPending: null, + autoApplySuppressedUntil: null, + }, + { text: true } as any, + inferFormatter(plan), + ); + + expect(output).toContain("status"); + expect(output).toContain("1.2.38 did not land"); + expect(output).toContain("attempt 2"); + expect(output).toContain("ade update install"); + }); + + it("omits install-failure and progress rows from a clean update snapshot", () => { + const plan = expectExecutePlan(buildCliPlan(["update", "status"])); + const output = formatOutput( + { + status: "downloading", + currentVersion: "1.2.37", + latestKnownVersion: "1.2.38", + version: "1.2.38", + progressPercent: 42.4, + bytesPerSecond: 1_048_576, + transferredBytes: 1_048_576, + totalBytes: 4_194_304, + releaseNotesUrl: null, + error: null, + errorDetails: null, + recentlyInstalled: null, + parked: null, + lastInstallFailed: null, + autoApplyPending: null, + autoApplySuppressedUntil: null, + }, + { text: true } as any, + inferFormatter(plan), + ); + + expect(output).toContain("42% · 1 MB of 4 MB · 1 MB/s"); + expect(output).not.toContain("last install failed"); + }); + it("applies sync web clipboard and open flags only when a link exists", () => { const options = { ...baseResolveOpts(), diff --git a/apps/ade-cli/src/cli.ts b/apps/ade-cli/src/cli.ts index a2d86f39d..2a7363c10 100644 --- a/apps/ade-cli/src/cli.ts +++ b/apps/ade-cli/src/cli.ts @@ -256,7 +256,8 @@ type FormatterId = | "storage-compress" | "storage-maintenance" | "sync-status" - | "sync-web"; + | "sync-web" + | "update-status"; type ChatWaitTarget = | "idle" @@ -2304,16 +2305,27 @@ ${CURSOR_CLOUD_HELP.cloud}`, the post-install notice. quitAndInstall relaunches the desktop app and only succeeds when status is "ready". - $ ade --socket update status --text Read AutoUpdateSnapshot (status, version, progress) + $ ade --socket update status --text Read AutoUpdateSnapshot (status, version, progress, last failed install) $ ade --socket update check --text Trigger a background update check $ ade --socket update install --text Refresh latest, then quit and install when ready $ ade --socket update dismiss --text Clear the recently-installed banner $ ade --socket update actions --text List callable update actions Snapshot status values: idle, checking, downloading, ready, installing, error. - "installing" appears between quitAndInstall and the desktop relaunch; if the - install fails, status falls back to error and the pending-install record is - cleared automatically. + "installing" appears between quitAndInstall and the desktop relaunch. That + window is deliberately long — the OS installer stages the new bundle in + process on macOS, so the app is only force-quit after a hard bound of several + minutes (about a minute on Windows/Linux, where staging is external). Do NOT + read a few slow minutes in "installing" as a hang, and do not kill the desktop + app to "unstick" it: that is exactly what makes an install fail to land. + + If quitAndInstall fails before the native handoff, status falls back to error + and the pending-install record is cleared. If the app quits but relaunches on + the OLD version, the install did not land: the next snapshot carries + "lastInstallFailed": { targetVersion, attempt }, which survives the restart. + Check that field before re-offering the same update — the first failure keeps + the downloaded archive so a retry is just another install, and only a second + failure discards the download and forces a fresh one. `, }; @@ -16834,6 +16846,86 @@ function formatStorageMaintenance(value: unknown): string { return `${header}\n\n${table}`; } +function formatEpochTimestamp(value: unknown): string | null { + if (typeof value !== "number" || !Number.isFinite(value) || value <= 0) return null; + const iso = new Date(value).toISOString(); + return `${iso} (${relativeTime(iso)})`; +} + +function formatUpdateStatus(value: unknown): string { + if (!isRecord(value)) return JSON.stringify(value, null, 2); + const errorDetails = isRecord(value.errorDetails) ? value.errorDetails : null; + const recentlyInstalled = isRecord(value.recentlyInstalled) ? value.recentlyInstalled : null; + const parked = isRecord(value.parked) ? value.parked : null; + // A previous install quit and the app came back on the old version. The + // snapshot deliberately keeps this across the restart, so an agent reading + // status must see it — otherwise the same update is silently offered again + // and the failure reads as "the update did nothing". + const lastInstallFailed = isRecord(value.lastInstallFailed) ? value.lastInstallFailed : null; + const autoApplyPending = isRecord(value.autoApplyPending) ? value.autoApplyPending : null; + + const progressParts: string[] = []; + if (typeof value.progressPercent === "number" && Number.isFinite(value.progressPercent)) { + progressParts.push(`${Math.round(value.progressPercent)}%`); + } + if (typeof value.transferredBytes === "number" && typeof value.totalBytes === "number") { + progressParts.push( + `${formatBytes(value.transferredBytes)} of ${formatBytes(value.totalBytes)}`, + ); + } + if (typeof value.bytesPerSecond === "number" && value.bytesPerSecond > 0) { + progressParts.push(`${formatBytes(value.bytesPerSecond)}/s`); + } + + const failedAttempt = typeof lastInstallFailed?.attempt === "number" + ? lastInstallFailed.attempt + : null; + const lastInstallFailedLine = lastInstallFailed + // renderKeyValues truncates each value at 96 columns, so this has to stay + // short enough that the retry hint survives a long version string. + ? `${asString(lastInstallFailed.targetVersion) ?? "unknown"} did not land` + + `${failedAttempt != null ? ` · attempt ${failedAttempt}` : ""}` + + " · relaunched on old version — retry: ade update install" + : null; + + const parkedLine = parked + ? `${asString(parked.reason) ?? "unknown reason"}${ + formatEpochTimestamp(parked.at) ? ` at ${formatEpochTimestamp(parked.at)}` : "" + }` + : null; + + const recentlyInstalledLine = recentlyInstalled + ? `${asString(recentlyInstalled.version) ?? "unknown version"}${ + asString(recentlyInstalled.installedAt) + ? ` · ${relativeTime(asString(recentlyInstalled.installedAt)!)}` + : "" + }` + : null; + + const errorLine = asString(value.error); + const errorDetailLine = errorDetails + ? `${asString(errorDetails.kind) ?? "error"} during ${ + asString(errorDetails.phase) ?? "unknown phase" + }${errorDetails.preservesDownload === true ? " · download preserved" : ""}` + : null; + + return renderKeyValues("ADE update", [ + ["status", value.status], + ["current version", value.currentVersion], + ["latest known", value.latestKnownVersion], + ["update version", value.version], + ["progress", progressParts.length ? progressParts.join(" · ") : null], + ["release notes", value.releaseNotesUrl], + ["last install failed", lastInstallFailedLine], + ["parked", parkedLine], + ["recently installed", recentlyInstalledLine], + ["auto-apply at", formatEpochTimestamp(autoApplyPending?.deadlineAt)], + ["auto-apply suppressed until", formatEpochTimestamp(value.autoApplySuppressedUntil)], + ["error", errorLine], + ["error detail", errorDetailLine], + ]); +} + function formatLastFailureLine(report: AdeLastFailureReport): string { const repeat = report.count > 1 ? ` x${report.count}` : ""; const scope = report.projectRoot ? ` [${report.projectRoot}]` : ""; @@ -18440,6 +18532,8 @@ function formatTextOutput( return formatStorageCompression(value); case "storage-maintenance": return formatStorageMaintenance(value); + case "update-status": + return formatUpdateStatus(value); case "action-result": default: if (isRecord(value)) @@ -18558,6 +18652,7 @@ function inferFormatter( if (label === "history commits") return "history-commits"; if (label === "history show") return "history-show"; if (label === "actions list") return "actions-list"; + if (label === "update status") return "update-status"; if (label.endsWith("actions")) return "actions-list"; const firstStep = plan.steps[0]; const params = typeof firstStep?.params === "object" && firstStep.params != null diff --git a/apps/ade-cli/src/commands/doctor.ts b/apps/ade-cli/src/commands/doctor.ts index 688627766..252b0a4bd 100644 --- a/apps/ade-cli/src/commands/doctor.ts +++ b/apps/ade-cli/src/commands/doctor.ts @@ -563,6 +563,12 @@ function syncPortRow(input: DoctorInput): DoctorRow { : " · no holders visible to this user (a root-owned holder such as" + " tailscaled is invisible here — check `tailscale serve status`" + " and `netstat -an -p tcp`)" + }${ + // The usual cause is ADE's own stranded `tailscale serve` entries from + // earlier runs. The host now reclaims those on its next publish, so the + // fix is a brain restart, not 60-odd manual `serve --tcp=N off` calls. + holders.length ? "" : " · ADE reclaims its own stale serve entries on the" + + " next publish; `ade brain restart` should return it to 8787" }`, }; } diff --git a/apps/ios/ADETests/ADETests.swift b/apps/ios/ADETests/ADETests.swift index 1e4c75d44..9f6a1a1d5 100644 --- a/apps/ios/ADETests/ADETests.swift +++ b/apps/ios/ADETests/ADETests.swift @@ -3617,6 +3617,54 @@ final class ADETests: XCTestCase { XCTAssertEqual(SyncUserFacingError.message(for: compressedPayloadError), "The machine sent unreadable sync data. Reconnect and try again.") } + /// The host owns the wording of `hello_error.message` and reworded it — a + /// paired-device rejection and an account-owner mismatch now carry their own + /// prose instead of a generic "authentication failed". iOS must key on + /// `ADEErrorCode`, never on that prose, so a host reword can never silently + /// drop these back to the raw server string. + func testSyncUserFacingAuthFailureIgnoresHostSuppliedWording() { + let rewordedPairingRejection = NSError( + domain: "ADE", + code: 5, + userInfo: [ + NSLocalizedDescriptionKey: "This device is not paired with this machine, or its saved pairing is no longer valid. Pair it again.", + "ADEErrorCode": "auth_failed", + ] + ) + XCTAssertEqual( + SyncUserFacingError.message(for: rewordedPairingRejection), + "This phone is no longer paired with this machine. Pair again from Settings." + ) + + let accountOwnerMismatch = NSError( + domain: "ADE", + code: 5, + userInfo: [ + NSLocalizedDescriptionKey: "This machine is signed in to a different ADE account than the one that paired this device.", + "ADEErrorCode": "auth_failed", + ] + ) + XCTAssertEqual( + SyncUserFacingError.message(for: accountOwnerMismatch), + "This phone is no longer paired with this machine. Pair again from Settings." + ) + + // Attribution still wins over the code, whatever the host wrote. + let unattributedReword = NSError( + domain: "ADE", + code: 5, + userInfo: [ + NSLocalizedDescriptionKey: "This device is not paired with this machine, or its saved pairing is no longer valid. Pair it again.", + "ADEErrorCode": "auth_failed", + "ADEAmbiguousRouteAuthFailure": true, + ] + ) + XCTAssertEqual( + SyncUserFacingError.message(for: unattributedReword), + "A machine on this route rejected the saved pairing — possibly a different ADE machine. ADE kept the pairing and will keep trying other routes. If you unpaired this phone on purpose, pair again from Settings." + ) + } + @MainActor func testSyncServiceMigratesLegacyConnectionDraftProfile() throws { let legacyDraftKey = "ade.sync.connectionDraft" diff --git a/docs/ARCHITECTURE.md b/docs/ARCHITECTURE.md index 8c7b4d8c7..155eaa5dd 100644 --- a/docs/ARCHITECTURE.md +++ b/docs/ARCHITECTURE.md @@ -184,7 +184,7 @@ ade brain update status --text Use `ADE_VERSION=vX.Y.Z` for a pinned release or `ADE_INSTALL_DIR` to choose the destination directory. The installer defaults to `$ADE_HOME/bin/ade`; both install and `ade brain update` verify downloaded runtime assets against `SHA256SUMS`. `ade brain update` stages the next release under `$ADE_HOME/runtime/updates/`, verifies the staged binary against the staged native deps, promotes the binary/deps into place, and restarts the per-user brain service. -**Health check (`ade doctor [--online] [--text]`).** `apps/ade-cli/src/commands/doctor.ts` connects to the machine brain over the local socket (bounded ~2 s) and prints one status row (`ok` / `warn` / `fail`) per subsystem: **App** (installed desktop version from the `.app` `Info.plist` vs the latest known version — read from disk, or from GitHub with `--online`), **Brain** (running version/pid/uptime plus any build-hash or role mismatch), **Wedge history** (the most recent recovered event-loop wedge, if any), **Sync port** (whether the shared listener bound the default `8787`, and the holders of the base ports when it drifted), **Publish health** (the account-directory publisher's last-leg durations and slowest leg), **Relay** (end-to-end verified vs a classified failure), and **Account** (signed-in state and source). The command exits non-zero when any row is `fail`. The row-evaluation logic (`evaluateDoctorRows`) is pure and dependency-injected so the desktop connection-doctor card and the CLI share one verdict. +**Health check (`ade doctor [--online] [--text]`).** `apps/ade-cli/src/commands/doctor.ts` connects to the machine brain over the local socket (bounded ~2 s) and prints one status row (`ok` / `warn` / `fail`) per subsystem: **App** (installed desktop version from the `.app` `Info.plist` vs the latest known version — read from disk, or from GitHub with `--online`), **Brain** (running version/pid/uptime plus any build-hash or role mismatch), **Wedge history** (the most recent recovered event-loop wedge, if any), **Sync port** (whether the shared listener bound the default `8787`, and the holders of the base ports when it drifted — with no visible holder reported as exactly that, since a root-owned holder such as `tailscaled` is invisible to a user-level probe and must be checked with `tailscale serve status` / `netstat -an -p tcp`), **Publish health** (the account-directory publisher's last-leg durations and slowest leg), **Relay** (end-to-end verified vs a classified failure), and **Account** (signed-in state and source). The command exits non-zero when any row is `fail`. The row-evaluation logic (`evaluateDoctorRows`) is pure and dependency-injected so the desktop connection-doctor card and the CLI share one verdict. **Install + PATH wiring (when the desktop ships `ade`).** On macOS / Linux the desktop installer drops the launcher at `$HOME/.local/bin/ade`; on Windows it lands at `%LOCALAPPDATA%\ADE\bin\ade.cmd`. After a successful install on Windows, the packaged `.cmd` installer adds the target directory to HKCU `Environment\Path` when needed and broadcasts an environment-change notification. After a successful install on POSIX, `ensureUserBinOnShellPath` appends a marked `export PATH="$HOME/.local/bin:$PATH"` block to the user's shell rc (`.zshrc` for zsh, `.bashrc` for bash, `.profile` otherwise) iff (a) the install dir isn't already on the inherited `PATH` and (b) the file doesn't already contain the marker / line / target dir. The install IPC reply tells the renderer which profile was edited so the Settings/Onboarding UI can prompt the user to open a new terminal or `source` it. @@ -297,7 +297,7 @@ The `/open` route is the HTTPS half of the ADE deeplink scheme (`https://ade-app Four independent Cloudflare Workers, each its own npm package / lockfile / `wrangler.jsonc` with its own trust model. None is a runtime dependency of the desktop app; the brain talks to them over HTTPS/WebSocket. - **`apps/push-relay/`** — fans ADE agent-state transitions out to iPhones as APNs alert pushes and Live Activity updates (Worker + a single D1 database; free-plan compatible, no Durable Objects). The brain is the only publisher: it claims an unguessable 32–64-hex `machineKey` with a relay secret (`POST /machines/:key/claim`, first-writer-wins) and HMAC-signs every later call (`x-ade-push-signature: sha256=HMAC(secret, "...")`). It stores only device tokens and in-flight notification payloads — no chat/PR content. APNs auth is an ES256 provider JWT from the `.p8` (wrangler secrets `APNS_KEY` / `APNS_KEY_ID` / `APNS_TEAM_ID`). Brain-side publisher lives at `apps/ade-cli/src/services/push/`. See [features/sync-and-multi-device/push-notifications.md](./features/sync-and-multi-device/push-notifications.md). -- **`apps/tunnel-relay/`** — pipes ADE **sync** WebSocket frames between a controller and a brain when there is no direct LAN/Tailscale path (Worker + Durable Object with SQLite storage, one instance per `machineKey`, WebSocket Hibernation API). The brain holds a persistent HMAC-signed outbound control socket while the machine has a valid ADE account session; a controller dials `/connect/:machineKey`; the DO pairs it with a dedicated brain-side pipe socket and passes bytes through 1:1 with no frame wrapping, so the normal ADE hello / pairing / DPoP handshake is unchanged. Native 30-second ping / 10-second pong transport liveness is the primary keepalive; because a hibernated or wedged DO can leave the edge answering those transport pings after the machine's control registration is dead, the brain adds a low-frequency application-level `{t:"ping"}`/`{t:"pong"}` keepalive (180 s interval, 30 s deadline) to catch such "zombie" controls, and verifies the path end-to-end with a self-probe (`syncRelaySelfProbe`) that dials `/connect/:machineKey?ready=2` like a real controller. The account directory advertises a `relay` endpoint only after that self-probe round-trips (honest relay publication); an at-capacity `4503` close is treated as liveness proof, not failure. Failed bridge opens are rejected explicitly; application close codes and bounded sanitized reasons survive the phone/pipe/local boundaries. Early controller frames are bounded by both 64 frames and 256 KiB, and idle-sweep alarms run only while a client or pipe exists. Brain-side client is `apps/ade-cli/src/services/sync/syncTunnelClientService.ts`. There is no user relay toggle: sign-in starts and advertises Relay, while sign-out closes it. It remains the lowest-priority `relay` address candidate after LAN and Tailscale. TLS terminates at the Worker, so this is a trusted-operator plaintext path rather than end-to-end encryption; relay payload E2E encryption is planned security work. +- **`apps/tunnel-relay/`** — pipes ADE **sync** WebSocket frames between a controller and a brain when there is no direct LAN/Tailscale path (Worker + Durable Object with SQLite storage, one instance per `machineKey`, WebSocket Hibernation API). The brain holds a persistent HMAC-signed outbound control socket while the machine has a valid ADE account session; a controller dials `/connect/:machineKey`; the DO pairs it with a dedicated brain-side pipe socket and passes bytes through 1:1 with no frame wrapping, so the normal ADE hello / pairing / DPoP handshake is unchanged. Native 30-second ping / 10-second pong transport liveness is the primary keepalive; because a hibernated or wedged DO can leave the edge answering those transport pings after the machine's control registration is dead, the brain adds a low-frequency application-level `{t:"ping"}`/`{t:"pong"}` keepalive (180 s interval, 30 s deadline) to catch such "zombie" controls, and verifies the path end-to-end with a self-probe (`syncRelaySelfProbe`) that dials `/connect/:machineKey?ready=2` like a real controller. The account directory advertises a `relay` endpoint only after that self-probe round-trips (honest relay publication); an at-capacity `4503` close is treated as liveness proof, not failure. Failed bridge opens are rejected explicitly; application close codes and bounded sanitized reasons survive the phone/pipe/local boundaries. Early controller frames are bounded by both 64 frames and 256 KiB, and idle-sweep alarms run only while a client or pipe exists. Brain-side client is `apps/ade-cli/src/services/sync/syncTunnelClientService.ts`, shared one-per-machine and handed the shared sync listener by `attachHostListener()` from whichever runtime actually owns that listener (which is often not the runtime that constructed the client). There is no user relay toggle: sign-in starts and advertises Relay, while sign-out closes it. It remains the lowest-priority `relay` address candidate after LAN and Tailscale. TLS terminates at the Worker, so this is a trusted-operator plaintext path rather than end-to-end encryption; relay payload E2E encryption is planned security work. - **`apps/account-directory/`** — Clerk-authenticated machine directory and OAuth device-authorization bridge (Worker + D1). The machine brain publishes a health-filtered registration through `accountMachinePublisherService.ts`: a 30-second heartbeat keeps the row inside the Worker's 90-second online window, while sign-in and publish-relevant relay-route changes trigger coalesced immediate writes and reset the heartbeat deadline. The Worker scopes rows by Clerk `sub`, selects at most the 500 most recently seen machines, then returns online-first order. Machine-list responses expose separate auth and D1 durations through `Server-Timing`, including auth failures. Authentication failures return only fixed classifications such as `token expired`, `invalid issuer`, and `invalid audience`; directory clients consume at most 512 response bytes before exposing the short reason in machine-list results and publisher health. Clients attach `X-ADE-Correlation-ID`; the Worker reflects and CORS-exposes it and logs it with route, method, status, and duration so a connection attempt can be followed without recording account tokens or full endpoint URLs. Desktop, ADE Code, hosted web, and iOS use the compiled HTTPS Worker origin by default. Headless login binds each short-lived device code to a daemon secret, uses Clerk OAuth + PKCE in any browser, and atomically burns the approved token pair on redemption. Each published row also carries the machine's long-lived Ed25519 identity as `pubkey`; a same-account desktop/iOS client verifies that key during the sealed `ade-adopt-v1` handshake to adopt a machine over a direct LAN/Tailscale route (LAN → Tailscale → Relay fallback) without exposing the account bearer in plaintext — see [features/sync-and-multi-device/README.md](./features/sync-and-multi-device/README.md). - **`apps/webhook-relay/`** — the pre-existing GitHub webhook relay (different trust model and lifecycle again). See its own docs. @@ -1114,7 +1114,7 @@ The sync subsystem is **owned by the ADE runtime** (`apps/ade-cli/src/services/s - **Bounded, snapshot-isolated exports**: `exportChangesSince` scans bounded `db_version` windows (the sync pump walks 250k-version windows per poll) inside a read transaction that pins the WAL snapshot — the `crsql_changes` vtab aborts on concurrent commits and a bare `LIMIT` cannot bound a vtab scan. Callers can exclude tables in SQL before limiting and reject a single oversized version group with `crsql_export_version_group_too_large` rather than materializing it. Startup self-heals orphaned `__crsql_clock`/`__crsql_pks` shadow tables (base table dropped, shadows left behind), which otherwise abort every `crsql_changes` scan. - **Fair, acknowledged delivery**: host/desktop-peer batches normally target 250 rows / 256 KB; active chat peers get a 64 KB target and at most 2 seconds of background deferral above the 512 KB socket watermark. The sender advances only after `changeset_ack`. Six failed sends abandon the encoded batch but keep its `fromDbVersion`, then re-export progressively smaller windows (down to 16 rows / 16 KB) after bounded backoff. An iOS replica with ACK + chunk support and a gap strictly over 5,000 versions receives one ACK-gated compact current-state reseed, built at most 1,000 rows per poll and capped at 10,000 rows / 4 MiB; oversized state falls back to incremental replay. iOS persists its last-acked cursor/pending batch and performs the same no-skip recovery from 64 rows / 64 KB down to one row / 4 KB. - **Suppression**: `discardUnpublishedChangesForTables` writes a per-table, per-site high-water mark into the local-only `local_crr_change_suppressions` table. Subsequent `exportChangesSince` calls drop local-site rows for those tables at or below that mark, so a local wipe (e.g. clearing `devices` and `sync_cluster_state` when joining another host as a viewer) cannot leak back as DELETE rows. The viewer-join path follows the wipe with `syncPeerService.acknowledgeLocalDbVersion()` to advance the outbound cursor past the suppressed range. -- **Transport**: one brain-level WebSocket listener on port 8787 by default (preferred-port retry for ~3 s before falling back to a port scan, so restarts do not drift the port phones saved); JSON-framed changesets + zlib compression for large batches; encoded envelopes >720 KB are sliced into `envelope_chunk` frames for peers declaring the `chunkedEnvelopes` capability; 60s ping/pong. Controllers adopt the host-advertised interval and postpone their fallback heartbeat whenever any inbound envelope proves the socket is alive, avoiding redundant application frames on relay-backed connections. Relay controllers use ready-v2 (`accepted` then `ready`) and send no ADE hello before the machine pipe/local listener exists; a non-v2 Worker is retried on a fresh legacy socket, never downgraded in place. iOS races up to three authenticated candidates and shares monotonic `connectionAttempt` metadata so the host rejects late losing routes; `hello_ok.connectionTransport` is the host-observed direct/relay truth. The same envelope channel carries project catalog, project-switch, and runtime-scoped project-action messages (browse/open/create/clone/list GitHub repos/default parent directory); on a hosted-project switch the new host service adopts the open sockets, so connected phones survive the swap. A machine-wide fallback handler serves catalog/project actions when no project host owns the listener, while handoff-time reconnects still park for adoption by the next host. Phones keep per-host-DB sync cursors keyed by the `serverDbSiteId` from `hello_ok`, and the host filters high-churn tables the phone never reads (transcripts, operations, usage logs, automation runs) from phone changesets. +- **Transport**: one brain-level WebSocket listener on port 8787 by default (preferred-port retry for ~3 s before falling back to a port scan, so restarts do not drift the port phones saved; each tailnet publish also retires ADE's own leftover `tailscale serve` entries, which otherwise hold the low ports through `tailscaled` and ratchet the listener upward on every restart); JSON-framed changesets + zlib compression for large batches; encoded envelopes >720 KB are sliced into `envelope_chunk` frames for peers declaring the `chunkedEnvelopes` capability; 60s ping/pong. Controllers adopt the host-advertised interval and postpone their fallback heartbeat whenever any inbound envelope proves the socket is alive, avoiding redundant application frames on relay-backed connections. Relay controllers use ready-v2 (`accepted` then `ready`) and send no ADE hello before the machine pipe/local listener exists; a non-v2 Worker is retried on a fresh legacy socket, never downgraded in place. iOS races up to three authenticated candidates and shares monotonic `connectionAttempt` metadata so the host rejects late losing routes; `hello_ok.connectionTransport` is the host-observed direct/relay truth. The same envelope channel carries project catalog, project-switch, and runtime-scoped project-action messages (browse/open/create/clone/list GitHub repos/default parent directory); on a hosted-project switch the new host service adopts the open sockets, so connected phones survive the swap. A machine-wide fallback handler serves catalog/project actions when no project host owns the listener, while handoff-time reconnects still park for adoption by the next host. Phones keep per-host-DB sync cursors keyed by the `serverDbSiteId` from `hello_ok`, and the host filters high-churn tables the phone never reads (transcripts, operations, usage logs, automation runs) from phone changesets. ### 13.2 Device model diff --git a/docs/features/onboarding-and-settings/README.md b/docs/features/onboarding-and-settings/README.md index c73800e13..8b066436d 100644 --- a/docs/features/onboarding-and-settings/README.md +++ b/docs/features/onboarding-and-settings/README.md @@ -519,8 +519,8 @@ Auto-update (top-bar control, not a settings tab): electron-updater wrapper that owns the renderer-visible `AutoUpdateSnapshot` (`status: "idle" | "checking" | "downloading" | "ready" | "installing" | "error"`, version, progress, recently - installed notice, plus the `parked` / `autoApplyPending` / - `autoApplySuppressedUntil` fields and `currentVersion` / + installed notice, plus the `parked` / `lastInstallFailed` / + `autoApplyPending` / `autoApplySuppressedUntil` fields and `currentVersion` / `latestKnownVersion` for the truthful-version surfaces). Tracks superseded downloads against the current ready version via `compareUpdateVersions` (the SemVer-aware comparator in `autoUpdateVersions.ts` that handles @@ -543,6 +543,13 @@ Auto-update (top-bar control, not a settings tab): `snapshot.parked` with a typed `AutoUpdateInstallAbortReason` (`refresh_failed`, `install_preflight_failed`, `prepare_failed`, `prepare_timeout`, `handoff_failed`) so the shell banner can offer a retry. + Once the native handoff starts, a staged quit deadline bounds it: a + never-fatal slow mark, then either the post-staging bound (armed when + Electron's own `autoUpdater` reports the OS installer finished staging) or the + hard bound. Escalation logs `autoUpdate.quit_escalated` with its + `hard_deadline` / `post_staging` reason, drains the log with + `logger.flushSync()`, and force-quits. See + [desktop-auto-update.md](./desktop-auto-update.md) for the numbers. When the runtime reports `RuntimeActivitySummary.idle` (no active agent turns or work sessions), a staged update is auto-applied after an idle grace period plus a renderer-visible countdown (`autoApplyPending`); an explicit cancel @@ -553,14 +560,23 @@ Auto-update (top-bar control, not a settings tab): the same SemVer comparator (so `>=` target counts as installed, even if the running build is one ahead), populates `recentlyInstalledUpdate` with the actual running version, and - cleans up the updater cache directory. On packaged launches with a + cleans up the updater cache directory. A launch that comes back on the *old* + version instead records `failedInstallAttempts` (target version + consecutive + count), logs `autoUpdate.install_did_not_land`, captures + `ade_update_install_did_not_land`, and surfaces `lastInstallFailed`. The + first such failure keeps the verified download so the retry is a click, not + another full release download; a second consecutive failure on the same + version clears the cache. On packaged launches with a recently installed update, the desktop refreshes the per-user runtime service so `ade serve` re-execs the updated bundled CLI and clients do not fall back to an isolated build-mismatch runtime. - `apps/desktop/src/renderer/components/app/AutoUpdateControl.tsx` — the small badge in the app shell top bar. Shows "Checking for updates" / "Downloading vX.Y.Z (NN%)" / "Install update vX.Y.Z" / - "ADE will quit and reopen" depending on the snapshot. Clicking the + "ADE will quit and reopen" depending on the snapshot. When + `lastInstallFailed` names the staged version, the ready label reads "Retry + install vX.Y.Z" and the tooltip says whether the download is still on the + machine. Clicking the install affordance prompts the user, sets a local `installRequested` flag, and calls `window.ade.updateQuitAndInstall()`; if the IPC returns `false` diff --git a/docs/features/onboarding-and-settings/desktop-auto-update.md b/docs/features/onboarding-and-settings/desktop-auto-update.md index 20f949bf9..9a42e044b 100644 --- a/docs/features/onboarding-and-settings/desktop-auto-update.md +++ b/docs/features/onboarding-and-settings/desktop-auto-update.md @@ -77,25 +77,40 @@ So the deadline is staged rather than a single hard bound: | Soft mark | 10s | Logs `autoUpdate.quit_staging_slow`. Never fatal. | | Native staging complete | — | Electron's own `autoUpdater` emits `update-downloaded`; logs `autoUpdate.native_staging_complete` and re-arms the short bound below. | | Post-staging bound | 15s | ShipIt is already running, so a process still alive here is genuinely wedged: escalate. | -| Hard bound | 5min | Staging never signalled at all: escalate. | - -Escalation logs `autoUpdate.quit_escalated` and calls `logger.flushSync()` +| Hard bound | 5min (macOS) / 60s elsewhere | Staging never signalled at all: escalate. | + +The staging signal comes from Electron's own `autoUpdater` — the Squirrel.Mac +binding `electron-updater`'s `MacUpdater` drives underneath — resolved through +`require("electron")` at construction and only on darwin, degrading to "no +staging signal" if it is absent rather than throwing. Everywhere else the +installer is an external process (NSIS, AppImage) that never emits that event, +so nothing stages in-process, the long bound could only hang the app in +`installing` for five minutes, and the shorter 60-second bound applies from the +start. + +Escalation logs `autoUpdate.quit_escalated` with its `hard_deadline` / +`post_staging` reason and whether staging had completed, captures the matching +`ade_update_quit_escalated` analytics event, and calls `logger.flushSync()` before `forceQuit`, because `forceQuit` ends the process and ordinary log writes are batched onto an async stream — without the sync drain the escalation record dies with the process and the failure leaves no trace. -A single hard 10-second bound is what this replaced. It force-quit the process -mid-staging and lost that race most of the time, so the app quit, nothing -installed, and it relaunched on the old version with no log line explaining it. +A single hard bound around ten seconds cannot work: it force-quits the process +mid-staging and loses that race most of the time, so the app quits, nothing +installs, and it relaunches on the old version. ## When an install does not land Relaunching on the old version while a `pendingInstallUpdate` marker exists -means the handoff never completed. The service records this in -`failedInstallAttempts` (target version + consecutive count), logs -`autoUpdate.install_did_not_land`, and exposes `lastInstallFailed` on the -snapshot so the top-bar pill reads "Retry install vX" instead of silently -offering the same update again. +means the handoff never completed. `reconcilePersistedUpdateState` records this +in the `failedInstallAttempts` global-state row (target version + consecutive +count + timestamp), logs `autoUpdate.install_did_not_land`, captures the +internal-only `ade_update_install_did_not_land` event with just the bounded +`attempt` counter, and exposes `lastInstallFailed` on the snapshot so the +top-bar pill reads "Retry install vX" instead of silently offering the same +update again. Requesting another install clears `lastInstallFailed` (the new +attempt supersedes the notice); a launch that does land on the target version +clears `failedInstallAttempts` entirely. The first such failure **keeps** the cached archive. It was checksum-verified before the update was ever offered, so a lost quit race says nothing about the diff --git a/docs/features/remote-runtime/README.md b/docs/features/remote-runtime/README.md index f56a1d27e..8a0bde8ea 100644 --- a/docs/features/remote-runtime/README.md +++ b/docs/features/remote-runtime/README.md @@ -68,6 +68,24 @@ relay payload E2E encryption is planned security work. See the trust boundary in security model). The published machine name is channel-suffixed (` · Beta` / ` · Alpha`, stable left bare) so two channels on one Mac are distinguishable rows. +- `apps/ade-cli/src/services/sync/syncTunnelClientService.ts` and + `apps/ade-cli/src/bootstrap.ts` — the relay side of a paired route. The tunnel + client is shared one-per-machine (`getSharedSyncTunnelClientService`, keyed by + `sync-cloud-relay.json`); bootstrap hands the shared listener to + `attachHostListener()` outside the construction factory so the runtime that + owns the listener supplies the port, loopback nonce, and bridge proof + regardless of which runtime created the instance. See *Relay tunnel and the + sync port* below. +- `apps/ade-cli/src/services/sync/syncHostService.ts` — the host end: paired + hello authentication (with the `sync_host.paired_device_rejected` / + `sync_host.paired_account_owner_mismatch` rejection logs and the + frame-count-aware peer-close logs) and tailnet publication, including + `staleAdeTailnetServePorts` / `reclaimStaleTailnetServes`, which retire + ADE's own leftover `tailscale serve` entries after each successful publish. +- `apps/ade-cli/src/commands/doctor.ts` — the `Sync port` row names a drifted + port and its base-port holders, and says explicitly that a root-owned holder + such as `tailscaled` is invisible to this probe rather than reporting the + ports as free. - `apps/ade-cli/src/tuiClient/remoteLauncher.ts`, `pairedRemoteConnector.ts`, `remoteLaunchBudget.ts`, and `remoteBridge.ts` — `ade code remote` target resolution, legacy account-target migration, @@ -477,7 +495,7 @@ diagnostics with `ADE_ENABLE_DESKTOP_SYNC_HOST=1`. destination lane/chat rather than automatically replaying the mutation. - "Tailscale CLI was not found / timed out / failed" warning under the discovered-machines list — surfaced from `discoverLanRuntimes` diagnostics. LAN (Bonjour) discovery still ran; install or unblock `tailscale` to add tailnet peers. - Agent provider missing or unauthenticated — use the inline `AgentCliAuthCard` to install or authenticate that provider on the active runtime machine. -- `lan :: authentication` in the route list — the host was reached and it *rejected* this desktop, so the other routes' `timeout`/`unreachable` entries are noise. The host now names the reason instead of a bare "Sync authentication failed.": either the pairing was removed on that machine, the saved secret no longer matches, or the two machines are signed in to different ADE accounts. Only the last one is fixed by signing in; the others need a re-pair. +- `lan :: authentication` in the route list — the host was reached and it *rejected* this desktop, so the other routes' `timeout`/`unreachable` entries are noise. The host's `hello_error` message names which of three causes it was: the pairing was removed on that machine, the saved secret no longer matches, or the two machines are signed in to different ADE accounts. The first two are reported identically (an unauthenticated caller must not be told whether a device id exists on that host) and both need a re-pair; only the account mismatch is fixed by signing in. ## Pairing identity and paired-secret lifetime @@ -486,36 +504,44 @@ the machine's stable id, but each entry in `desktop-paired-machines.json` carries its own `deviceId` that the host uses as the key for its pairing record. Re-pairing the same machine therefore **must** present the same `deviceId` — the host upserts on that key. `pairWithMachine` recovers the prior -identity before it sends the pairing request, preferring the caller-supplied -`hostDeviceId` (a QR/link payload carries it), then the relay machine key, then -a saved record already holding this endpoint. The endpoint fallback matters -because `machineKeyFromEndpoint` only parses a relay `/connect/` path and -returns null for a LAN address. - -Minting a fresh id instead is not merely untidy: the host keeps the old record -forever, secret still valid, with no way to ever match it again. One machine was -observed holding six orphaned records for the same laptop. - -Two logs make a lost pairing diagnosable, both of which were previously silent: +identity (and its `siteId`) before it sends the pairing request, because the +`hello` that reports the host identity only arrives afterwards. It looks the +saved record up by two things that both identify a *host*: the caller-supplied +`hostDeviceId` (a QR/link payload and account-directory adoption both carry it), +then the relay machine key parsed out of a `/connect/` endpoint. A bare LAN +address is not a host identity — DHCP handing `192.168.1.240` to a different Mac +would hand that Mac the identity this desktop uses with the first one — so +matching on a saved endpoint is deliberately not an option, and a LAN pairing +with no `hostDeviceId` mints a fresh identity. + +Minting a fresh id when one already exists is not merely untidy: the host keeps +the old record forever, secret still valid, with no way to ever match it again, +accumulating one orphaned credential per re-pair. + +Three logs make a lost pairing diagnosable: - Host: `sync_host.paired_device_rejected` (`unknown_device` vs - `secret_mismatch`) and `sync_host.paired_account_owner_mismatch`. + `secret_mismatch`) and `sync_host.paired_account_owner_mismatch`, both at + warn. The host distinguishes those two rejection causes for itself but tells + the unauthenticated caller the same thing either way, so the close reason is + not an existence oracle for device ids. - Host, for peers that never spoke: `sync_host.peer_closed_without_frames` at **debug**. The relay readiness self-probe bridges in over loopback and disconnects without sending a frame on every poll, and so does a port scan. - Those used to land on `sync_host.peer_closed` at info, where routine probe - traffic was indistinguishable at a glance from a peer that tried to - authenticate and was rejected. Anything that sent at least one frame — - including every authentication failure — still logs `sync_host.peer_closed` - at info. -- Desktop: `account.local_machines_removed`, written to - `/runtime/account-trust.jsonl`. Deliberately **not** the - project logger — dropping a paired secret is a machine-level credential - mutation, and the project logger follows the active project, which on a - remote-bound project ships the record to the other machine and leaves nothing - on the machine that actually lost its trust. It records the previous and - current owner per removed credential, so an intended account switch is - distinguishable from an identity glitch that silently cost trust. + Keeping that routine traffic out of `sync_host.peer_closed` is what makes a + rejected peer visible at a glance. Anything that sent at least one frame — + including every authentication failure — logs `sync_host.peer_closed` at + info. +- Desktop: `account.local_machines_removed`, written at **warn** to the + machine-scoped `/runtime/account-trust.jsonl` (and mirrored + at info to the project logger). The machine-scoped sink is the load-bearing + one: dropping a paired secret is a machine-level credential mutation, and the + project logger follows the active project, which on a remote-bound project + ships the record to the other machine and leaves nothing on the machine that + actually lost its trust. Each removed credential records its host device id, + host name, previous owner, and whether the owner actually changed, so an + intended account switch is distinguishable from an identity glitch that + silently cost trust. The sink is resolved lazily and never fails account auth. ## Relay tunnel and the sync port diff --git a/docs/features/sync-and-multi-device/README.md b/docs/features/sync-and-multi-device/README.md index 63983ee53..5da81a022 100644 --- a/docs/features/sync-and-multi-device/README.md +++ b/docs/features/sync-and-multi-device/README.md @@ -610,7 +610,11 @@ Canonical files (`apps/ade-cli/src/services/sync/`): that holder, logs `sync_listener.zombie_reaped`, and retries the freed port once — so a dead-but-port-holding sibling brain cannot force the new brain onto a drifted port that phones never saved. The same diagnosis feeds the - `ade doctor` Sync-port row. The listener is + `ade doctor` Sync-port row, which is explicit that it cannot see a root-owned + holder: a stranded `tailscale serve` entry from an earlier run holds the port + through `tailscaled`, so a user-level probe reports no holders even though the + port is taken (`tailscale serve status` and `netstat -an -p tcp` show it). + Those leftovers are reclaimed on the next tailnet publish. The listener is handed between hosts on project switch: the new host adopts the open sockets — peer metadata carried over, pairing auth re-validated against the pairing store, changeset cursors recomputed @@ -840,9 +844,18 @@ Canonical files (`apps/ade-cli/src/services/sync/`): validation is **proactive**: `validateCurrentBridge()` re-probes the loopback sync listener (matching port + identity nonce) whenever the control socket opens and whenever the shared listener reports a fresh loopback - validation (`sharedSyncListener.onLoopbackValidated`, wired in - `bootstrap.ts`), serializing probes through the same validation queue used by - inbound opens. This flips `relayBridgeValidated` — and therefore directory relay + validation, serializing probes through the same validation queue used by + inbound opens. The listener itself arrives through `attachHostListener()`, + which `bootstrap.ts` calls from the runtime that owns the shared listener — + not from the construction factory. The client is shared one-per-machine + (`getSharedSyncTunnelClientService`, keyed by `sync-cloud-relay.json`) and is + built by whichever runtime bootstraps first, which is regularly a scope with + no listener at all (a headless one-shot, an embedded fallback), so anything + captured at construction would answer `null` for the life of the process and + the bridge could never validate. Attaching supplies the port, loopback nonce, + and relay bridge proof, subscribes the `onLoopbackValidated` retry hook + (whose failures log `sync_tunnel.bridge_validation_failed`), and validates + immediately if the listener is already bound; `stop()` detaches it. This flips `relayBridgeValidated` — and therefore directory relay publication — true as soon as the listener is confirmed, so the earlier "bridge not validated against the sync port" state self-heals instead of waiting for an inbound client to open the first tunnel. `openTunnel` still @@ -1277,7 +1290,19 @@ grace. Older peers close exactly when their initial token expires. (`SyncTailnetDiscoveryStatus`: `disabled | publishing | published | pending_approval | unavailable | failed`) plus `error` / `stderr` tails. The runtime tracks a `tailnetServeSignature` (`serve:`) - so re-publishing is a no-op while the port hasn't changed. + so re-publishing is a no-op while the port hasn't changed. Because + `serve --bg` outlives the process that registered it, each successful publish + is followed by a best-effort reclaim (`staleAdeTailnetServePorts` + + `reclaimStaleTailnetServes`, logged as `sync_host.tailnet_serve_reclaimed`): + `tailscale serve status --json` is scanned for ADE's exact signature — a port + in the sync range forwarding to `127.0.0.1` on the **same** port — and every + match other than the live one is turned off. Without it, a restart or + force-kill strands an entry that Tailscale keeps bound on the tailnet address, + ADE's next wildcard bind fails `EADDRINUSE` against its own leftover and walks + one port higher, and the port ratchets upward on every start. A hand-rolled + `tailscale serve` forwarding anywhere else is never touched, and the live port + is re-checked inside the loop because reclaiming frees exactly the low ports a + concurrently restarting host prefers. ## Sync protocol (summary) diff --git a/docs/logging.md b/docs/logging.md index cec492196..99482b483 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -22,7 +22,11 @@ Only closed event names, closed property keys, and coarse allowlisted values may Operational logs use ADE's local logging services and may include bounded diagnostic context appropriate for the local machine. They are for debugging a specific installation and must not be forwarded to PostHog. -The machine brain writes the same `{ts, level, event, meta}` JSONL format as the desktop logger to `~/.ade/runtime/brain.jsonl`, honoring `ADE_LOG_LEVEL` (default `info`). The file rotates at 10 MiB to `brain.1.jsonl`; warnings and errors are also mirrored to stderr with an ISO-8601 timestamp and uppercase level for launchd diagnostics. Account-directory publish outcomes record only bounded per-leg durations, the failing leg, and coarse failure codes such as `token_timeout` or `http_timeout`; they never include bearer tokens or response bodies. These high-frequency health events remain local operational logs and are not product analytics. +The machine brain writes the same `{ts, level, event, meta}` JSONL format as the desktop logger to `~/.ade/runtime/brain.jsonl`, honoring `ADE_LOG_LEVEL` (default `info`). The file rotates at 10 MiB to `brain.1.jsonl`; warnings and errors are also mirrored to stderr with an ISO-8601 timestamp and uppercase level for launchd diagnostics. + +Writes are batched onto an async stream, so a caller that is about to end the process (`app.exit`, a force quit, an install handoff escalation) must call `logger.flushSync()` immediately after the line that matters — while it is still queued — or the records explaining the exit die with the process. `flushSync` drains only what is still queued (a batch already handed to an in-flight async flush is not duplicated), skips rotation deliberately, and, like every other log write, never throws. + +Not every operational log belongs to the active project. `createFileLogger` also backs machine-scoped sinks for facts that outlive or fall outside a project: `accountBridge` writes `account.local_machines_removed` to `/runtime/account-trust.jsonl`, because dropping a paired machine credential is a machine-level mutation and the project logger follows the active project — on a remote-bound project it would ship the record to the other machine and leave nothing on the machine that actually lost its trust. Account-directory publish outcomes record only bounded per-leg durations, the failing leg, and coarse failure codes such as `token_timeout` or `http_timeout`; they never include bearer tokens or response bodies. These high-frequency health events remain local operational logs and are not product analytics. Claude compaction observations use the local structured line `agent_chat.claude_context_compaction_observed` with `sessionId`, `trigger` @@ -86,7 +90,7 @@ The public contract is `apps/desktop/src/shared/types/productAnalytics.ts`. The - `ade_brain_recovered` - `ade_publish_failing` -The update and reliability events are low-frequency by construction: the five `ade_update_*` events fire at most once per install attempt or idle-apply cycle (daily caps 10–20, minute caps 3–6). `ade_update_install_did_not_land` is emitted once at startup when a requested install relaunched on the old version, so it is bounded by app launches that follow a failed handoff, and carries only a bounded `attempt` counter; `ade_brain_recovered` fires once per wedge recovery at brain startup; `ade_publish_failing` is edge-triggered once per sustained failure episode (first crossing of two minutes), never per attempt. Properties are closed enums and bounded numbers — `reason` is allowlisted to the abort-reason constant, `last_command` is a closed sync-action slug, and `leg`/`code` are the coarse publish classifications. Worst-case combined volume is a handful of events on a very bad day, inside the shared ceiling. +The update and reliability events are low-frequency by construction: the five `ade_update_*` events fire at most once per install attempt or idle-apply cycle (daily caps 10–20, minute caps 3–6). `ade_update_install_did_not_land` is emitted once at startup when a requested install relaunched on the old version, so it is bounded by app launches that follow a failed handoff, and carries only a bounded `attempt` counter; `ade_brain_recovered` fires once per wedge recovery at brain startup; `ade_publish_failing` is edge-triggered once per sustained failure episode (first crossing of two minutes), never per attempt. Properties are closed enums and bounded numbers — `reason` is allowlisted to the abort-reason constant, `escalation_reason` to `hard_deadline` / `post_staging`, `last_command` is a closed sync-action slug, and `leg`/`code` are the coarse publish classifications. Worst-case combined volume is a handful of events on a very bad day, inside the shared ceiling. The default machine-wide ceiling is 200 accepted events per UTC day, shared across desktop, runtime, TUI, hosted web, and API-originated aggregates. Each event also has a tighter per-day and per-minute ceiling. Capture ingress is capped, noisy events use persisted deduplication windows, the in-memory transport queue is bounded, and the previous day's accepted/drop totals are summarized in at most two budget events per day. @@ -146,7 +150,7 @@ The full-access personal key belongs only in encrypted ADE secrets. When running - ADE · Marketing acquisition - ADE · Reliability and analytics budget -When an event or property contract changes, update the dashboard spec and its tests in the same change. Run the provisioner in `--validate` mode locally. A live provisioning run requires the personal management key and should be idempotent: an immediate second run must report no changes. +The 30-day volume insight sums the whole ingested catalog through a formula that addresses each series by its PostHog letter (`A`…`Z`), so the catalog cannot exceed 26 events; the spec throws at load time rather than emitting a formula PostHog would reject. When an event or property contract changes, update the dashboard spec and its tests in the same change. Run the provisioner in `--validate` mode locally. A live provisioning run requires the personal management key and should be idempotent: an immediate second run must report no changes. ## How to instrument new code From c8fd130e00b40eea79a590a746d86f1509beb2f8 Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 14:47:07 -0400 Subject: [PATCH 10/11] fix(review): address CodeRabbit findings on #916 MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Security (the one that matters): account/host identifiers were going to the project logger. The machine-local sink exists precisely because the project logger ships records to the OTHER machine on a remote-bound project, and this lane had widened that call from counts to full detail — re-introducing the cross-machine identifier exposure the split was added to prevent. The project logger is back to counts; owner ids stay machine-local. Correctness: - reclaimStaleTailnetServes probes 127.0.0.1: immediately before each teardown. `tailscale serve` is machine-global while the sync-host singleton is uid- and channel-scoped, so a sibling ADE can own one of these ports, and its entry is byte-identical to a stranded one. Re-reading serve status (the suggested fix) cannot separate them; whether anything is actually listening can. This also closes the snapshot-to-teardown window. - attachHostListener invalidates the bridge and closes relay connections when it replaces a real listener. Ready tunnels kept forwarding into the previous listener's socket, so "new owner wins" held for validation inputs while live traffic still reached the machine that no longer owned the bridge. - formatEpochTimestamp returns null for epochs past 8.64e15 instead of letting toISOString throw RangeError and take down `ade update status --text`. Diagnostics: - Dropped `ownerChanged`. pruneAccountOwned only removes records whose owner already differs from the current one, so the field was a constant true and could never surface the "identical owner that still pruned" case its comment claimed to catch. - Restored flushSync on the credential-removal record, now with the reason it was missing: this is the forensic line for "why did my pairing vanish", and the file logger batches on a 500 ms timer, so a quit shortly after the prune would lose exactly it. Flushing at the write site closes that window without a separate shutdown handler. - Renamed a test whose name claimed progress rows are omitted while its body asserts they render. Co-Authored-By: Claude --- apps/ade-cli/src/cli.test.ts | 2 +- apps/ade-cli/src/cli.ts | 7 ++++- .../src/services/sync/syncHostService.ts | 24 +++++++++++++++++ .../services/sync/syncTunnelClientService.ts | 11 ++++++++ .../main/services/account/accountBridge.ts | 27 ++++++++++++------- 5 files changed, 60 insertions(+), 11 deletions(-) diff --git a/apps/ade-cli/src/cli.test.ts b/apps/ade-cli/src/cli.test.ts index 592ffa780..9cbc7be02 100644 --- a/apps/ade-cli/src/cli.test.ts +++ b/apps/ade-cli/src/cli.test.ts @@ -1361,7 +1361,7 @@ describe("ADE CLI", () => { expect(output).toContain("ade update install"); }); - it("omits install-failure and progress rows from a clean update snapshot", () => { + it("renders progress and omits the install-failure row for a clean update snapshot", () => { const plan = expectExecutePlan(buildCliPlan(["update", "status"])); const output = formatOutput( { diff --git a/apps/ade-cli/src/cli.ts b/apps/ade-cli/src/cli.ts index 2a7363c10..46dc15486 100644 --- a/apps/ade-cli/src/cli.ts +++ b/apps/ade-cli/src/cli.ts @@ -16848,7 +16848,12 @@ function formatStorageMaintenance(value: unknown): string { function formatEpochTimestamp(value: unknown): string | null { if (typeof value !== "number" || !Number.isFinite(value) || value <= 0) return null; - const iso = new Date(value).toISOString(); + // Finite and positive still admits epochs past 8.64e15, where toISOString + // throws RangeError. Every other field here degrades to a missing row rather + // than taking down `ade update status --text`; this one must too. + const date = new Date(value); + if (Number.isNaN(date.getTime())) return null; + const iso = date.toISOString(); return `${iso} (${relativeTime(iso)})`; } diff --git a/apps/ade-cli/src/services/sync/syncHostService.ts b/apps/ade-cli/src/services/sync/syncHostService.ts index b13c200bc..3b0454555 100644 --- a/apps/ade-cli/src/services/sync/syncHostService.ts +++ b/apps/ade-cli/src/services/sync/syncHostService.ts @@ -1,6 +1,7 @@ import fs from "node:fs"; import http from "node:http"; import { execFile, spawn, type ChildProcess } from "node:child_process"; +import net from "node:net"; import os from "node:os"; import path from "node:path"; import { runWithAbortSignal } from "./abortSignal"; @@ -3933,6 +3934,20 @@ export function createSyncHostService(args: SyncHostServiceArgs) { }); }; + // A stranded `tailscale serve` entry forwards to a port nothing listens on. + // A live one — this host or a sibling ADE — has a real listener behind it. + const isLocalPortServing = (port: number): Promise => new Promise((resolve) => { + const socket = net.connect({ port, host: "127.0.0.1" }); + const settle = (serving: boolean) => { + socket.removeAllListeners(); + socket.destroy(); + resolve(serving); + }; + socket.setTimeout(750, () => settle(false)); + socket.once("connect", () => settle(true)); + socket.once("error", () => settle(false)); + }); + // `serve --bg` outlives the process that registered it, but the port ADE // tracks is in-memory only, so every restart — and every force-kill that // skips the teardown below — orphans the previous entry. Tailscale keeps it @@ -3961,6 +3976,15 @@ export function createSyncHostService(args: SyncHostServiceArgs) { // at all, while status still reports "published". if (disposed) return; if (tailnetServePort != null && port === tailnetServePort) continue; + // `tailscale serve` is machine-global while the sync-host singleton is + // uid- and channel-scoped, so a sibling ADE (another channel, another + // user) can legitimately own one of these ports. Its serve entry is + // byte-identical to a stale one — same port forwarding to 127.0.0.1 on + // the same port — so the status output cannot tell them apart. What does + // is whether anything is actually listening: a stranded entry forwards + // into nothing. Probe immediately before each teardown, so the window + // between the snapshot and this `off` is closed too. + if (await isLocalPortServing(port)) continue; try { await execFileAsync(cli, ["serve", `--tcp=${port}`, "off"], { timeout: 10_000 }); reclaimed += 1; diff --git a/apps/ade-cli/src/services/sync/syncTunnelClientService.ts b/apps/ade-cli/src/services/sync/syncTunnelClientService.ts index 603bb3b6f..55fd3ee88 100644 --- a/apps/ade-cli/src/services/sync/syncTunnelClientService.ts +++ b/apps/ade-cli/src/services/sync/syncTunnelClientService.ts @@ -1665,9 +1665,20 @@ export function createSyncTunnelClientService(args: SyncTunnelClientArgs): SyncT attachHostListener(listener: TunnelHostListener | null): void { if (hostListener === listener) return; + const hadListener = hostListener != null; detachHostListener?.(); detachHostListener = null; hostListener = listener; + // Swapping owners has to invalidate what the previous owner proved. + // Ready tunnels keep forwarding into the OLD listener's local socket, so + // leaving them up means "new owner wins" is only true for validation + // inputs while live traffic still reaches the machine that no longer + // owns the bridge. Drop the validation and the pipes together; the next + // tunnel re-opens against the new listener. + if (hadListener) { + clearBridgeValidation(); + closeRelayConnections("host listener replaced"); + } if (!listener) return; // Re-run validation whenever the listener re-validates loopback. This // subscription used to be registered in the construction closure, so diff --git a/apps/desktop/src/main/services/account/accountBridge.ts b/apps/desktop/src/main/services/account/accountBridge.ts index b0be44122..92258c509 100644 --- a/apps/desktop/src/main/services/account/accountBridge.ts +++ b/apps/desktop/src/main/services/account/accountBridge.ts @@ -196,23 +196,32 @@ export function createAccountBridge(options: AccountBridgeOptions): AccountBridg && (result.removedTargetIds.length > 0 || result.removedCredentialHostIds.length > 0) ) { - // Warn, not info: each removed credential costs the user a manual - // re-pair of that machine, so this is never routine. - const detail = { + const counts = { targetCount: result.removedTargetIds.length, credentialCount: result.removedCredentialHostIds.length, + }; + // Warn, not info: each removed credential costs the user a manual + // re-pair of that machine, so this is never routine. + // + // Account and host identifiers go ONLY to the machine-local sink. The + // project logger is the reason this split exists — on a remote-bound + // project it ships records to the other machine, so putting owner ids in + // it would re-introduce exactly the cross-machine identifier exposure the + // split was added to prevent. It gets counts, nothing more. + getMachineLogger()?.warn("account.local_machines_removed", { + ...counts, currentOwnerUserId: result.currentOwnerUserId, removed: result.removedCredentials.map((credentials) => ({ hostDeviceId: credentials.hostDeviceId, hostName: credentials.hostName, previousOwnerUserId: credentials.previousOwnerUserId, - // The whole point of the record: an account switch is intended, an - // identical owner that still pruned is the bug worth chasing. - ownerChanged: credentials.previousOwnerUserId !== result.currentOwnerUserId, })), - }; - getMachineLogger()?.warn("account.local_machines_removed", detail); - options.logger?.info("account.local_machines_removed", detail); + }); + // Dropping a paired secret is the forensic record for "why did my + // pairing vanish". The file logger batches on a 500 ms timer, so a quit + // that follows the prune closely would lose exactly that line. + getMachineLogger()?.flushSync?.(); + options.logger?.info("account.local_machines_removed", counts); } }; From 38e59cb8041d19899a1de63283253bca74786d96 Mon Sep 17 00:00:00 2001 From: Arul Sharma <31745423+arul28@users.noreply.github.com> Date: Mon, 27 Jul 2026 15:54:30 -0400 Subject: [PATCH 11/11] fix(review): address Codex findings on #916 MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - The failed-install notice now survives an ordinary relaunch. failedInstall was only derived inside the pendingInstallUpdate branch, so one quit-and- reopen dropped lastInstallFailed from the snapshot while the persisted counter still made the next failure attempt 2 and evicted the cache — the UI claimed a clean slate the cache policy disagreed with. Derived from the persisted record instead, and cleared when an install actually lands. - flushSync drains the in-flight batch, not just the queue. A line landing exactly on the batch limit makes scheduleFlush call flush() synchronously, which splices the batch out before its first await; flushSync then saw an empty queue, wrote nothing, and the app.exit() that follows killed the pending write — losing precisely the escalation record this API was added to preserve. Test pins the boundary. Not fixed here, documented in place: reusing the pairing identity means the host rotates that record's secret before answering, while the client saves the replacement only after hello_ok, so a drop in between costs one manual re-pair of a previously working pairing. Minting a fresh id instead would trade that narrow window for the unbounded orphaned-record leak this reuse exists to stop. Closing it properly needs an atomic commit/ack in the pairing protocol — a host-side change that does not belong in a merge loop. Co-Authored-By: Claude --- .../src/main/services/logging/logger.test.ts | 19 ++++++++++++++++ .../src/main/services/logging/logger.ts | 22 ++++++++++++++----- .../remoteRuntime/syncPairedMachineStore.ts | 10 +++++++++ .../services/updates/autoUpdateService.ts | 15 +++++++++++++ 4 files changed, 60 insertions(+), 6 deletions(-) diff --git a/apps/desktop/src/main/services/logging/logger.test.ts b/apps/desktop/src/main/services/logging/logger.test.ts index e226ffbc9..b5c8f6ba6 100644 --- a/apps/desktop/src/main/services/logging/logger.test.ts +++ b/apps/desktop/src/main/services/logging/logger.test.ts @@ -84,6 +84,25 @@ describe("createFileLogger", () => { }); }); + // Regression: a line landing exactly on the batch limit makes scheduleFlush + // call flush() synchronously, which splices the batch out before its first + // await. Draining only the queue would then write nothing and the app.exit() + // that follows would lose the record flushSync exists to preserve. + it("drains a batch already handed to an in-flight flush", () => { + const logPath = path.join(fs.mkdtempSync(path.join(os.tmpdir(), "ade-logger-")), "test.log"); + const logger = createFileLogger(logPath, { flushBatchSize: 2 }); + + logger.info("first.event"); + // Hits flushBatchSize, so flush() runs synchronously up to its first await + // and the batch is no longer in queuedLines. + logger.error("autoUpdate.quit_escalated", { blockedMs: 300_000 }); + logger.flushSync?.(); + + const written = fs.readFileSync(logPath, "utf8"); + expect(written).toContain("autoUpdate.quit_escalated"); + expect(written).toContain("first.event"); + }); + it("is a no-op on flushSync with nothing queued", () => { const logPath = path.join(fs.mkdtempSync(path.join(os.tmpdir(), "ade-logger-")), "test.log"); const logger = createFileLogger(logPath); diff --git a/apps/desktop/src/main/services/logging/logger.ts b/apps/desktop/src/main/services/logging/logger.ts index ce05c8bd0..8db039d03 100644 --- a/apps/desktop/src/main/services/logging/logger.ts +++ b/apps/desktop/src/main/services/logging/logger.ts @@ -86,6 +86,9 @@ export function createFileLogger( let queuedLines: string[] = []; let flushTimer: NodeJS.Timeout | null = null; let flushInProgress = false; + // The batch a running flush() spliced out of queuedLines but has not yet + // written. flushSync must be able to reach it. + let inFlightPayload: string | null = null; let flushRequested = false; let logDirReady = false; let logStream: fs.WriteStream | null = null; @@ -201,6 +204,7 @@ export function createFileLogger( const payload = lines.join(""); const bytes = Buffer.byteLength(payload, "utf8"); flushInProgress = true; + inFlightPayload = payload; try { if (!ensureLogDir()) return; @@ -210,6 +214,7 @@ export function createFileLogger( } catch { // Last ditch: avoid crashing the app on log write failures. } finally { + inFlightPayload = null; flushInProgress = false; if (flushRequested || queuedLines.length > 0) { flushRequested = false; @@ -231,17 +236,22 @@ export function createFileLogger( flushTimer.unref?.(); }; - // Lines already handed to an in-flight async flush have been spliced out of - // queuedLines, so draining the rest here cannot duplicate them. Rotation is - // skipped deliberately: this runs on the way out of the process, where a - // slightly oversized log beats a lost one. + // Drains the in-flight batch as well as the queue. A line that lands exactly + // on the batch limit triggers flush() synchronously, which splices it out + // before its first await — so draining only queuedLines would return having + // written nothing, and the app.exit() that follows would kill the pending + // write and lose precisely the record this API exists to preserve. Rotation + // is skipped deliberately: on the way out, a slightly oversized log beats a + // lost one, and a duplicated line beats a missing one if the async write also + // lands. const flushSync = () => { if (flushTimer) { clearTimeout(flushTimer); flushTimer = null; } - if (queuedLines.length === 0) return; - const payload = queuedLines.splice(0, queuedLines.length).join(""); + const pending = inFlightPayload ?? ""; + if (pending.length === 0 && queuedLines.length === 0) return; + const payload = pending + queuedLines.splice(0, queuedLines.length).join(""); try { if (!ensureLogDir()) return; fs.appendFileSync(logFilePath, payload); diff --git a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts index 695e0f9fc..660d2e6f5 100644 --- a/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts +++ b/apps/desktop/src/main/services/remoteRuntime/syncPairedMachineStore.ts @@ -591,6 +591,16 @@ export class DesktopPairedMachineStore { // can never match again — one orphaned, still-valid secret per re-pair, // forever. // + // Known tradeoff: because the host upserts on this id, `pairPeer` rotates + // the secret and DPoP binding for an EXISTING record before it answers, and + // this client only persists the replacement after `hello_ok`. A drop in + // between leaves the host holding credentials the desktop never saved, so a + // previously working pairing needs one more manual re-pair. Minting a fresh + // id instead would avoid that window at the cost of the unbounded orphaned- + // record leak this reuse exists to stop — strictly worse. Closing it + // properly needs an atomic commit/ack in the pairing protocol, which is a + // host-side change and not something to land in a merge loop. + // // The hello that reports the host identity arrives after the pairing request // that carries this id, so the prior record has to be recovered up front: // by the host the caller is aiming at, else the relay machine key. Both diff --git a/apps/desktop/src/main/services/updates/autoUpdateService.ts b/apps/desktop/src/main/services/updates/autoUpdateService.ts index 917c0ca4e..a1ab9920c 100644 --- a/apps/desktop/src/main/services/updates/autoUpdateService.ts +++ b/apps/desktop/src/main/services/updates/autoUpdateService.ts @@ -270,6 +270,20 @@ function reconcilePersistedUpdateState(args: { changed = true; } + // The counter outlives the launch that recorded it, so the notice has to as + // well. Without this, one ordinary quit-and-reopen drops lastInstallFailed + // from the snapshot while the persisted counter still makes the next failure + // attempt 2 and evicts the cache — the UI would claim a clean slate the + // policy does not agree with. The renderer only shows it when it matches the + // version actually being offered, so surfacing it here is safe. + const persistedFailure = nextState.failedInstallAttempts; + if (persistedFailure) { + failedInstall = { + targetVersion: persistedFailure.targetVersion, + attempt: persistedFailure.count, + }; + } + const pendingInstall = nextState.pendingInstallUpdate; if (pendingInstall) { const installedTargetOrNewer = compareUpdateVersions(args.currentVersion, pendingInstall.targetVersion) >= 0; @@ -283,6 +297,7 @@ function reconcilePersistedUpdateState(args: { }; cacheCleanupReason = "installed"; nextState.failedInstallAttempts = undefined; + failedInstall = null; } else { const previous = nextState.failedInstallAttempts; const attempt = previous?.targetVersion === pendingInstall.targetVersion