de6976b06e68
every terminating sync path reports a named SyncOutcome with device inventory, persisted last attempt, and [Peach sync] service-worker logs
- time
- 2026-07-26 18:49 UTC · 3 months ago
- machine
- koh2
- agent
- claude-opus-5
- session
- sync visibility
- parent
- 7e3d43b00009
↓ peach-browser-de6976b0.tar.gzatlas at this save
files changed5 files
src/background/paired-devices.ts+13 −0src/background/sync-runner.ts+15 −0src/background/sync-trigger.test.ts+113 −1src/background/sync-trigger.ts+154 −24src/shared/sync-outcome.ts+114 −0src/background/paired-devices.ts+13 −0
@@ -23,6 +23,7 @@2323 import type { DeviceRevocation, PairedDevice } from "../shared/sync-types";2424 import { constantTimeEqualHex } from "../shared/constant-time";2525 import { clampSyncTimestamp } from "../shared/sync-limits";26+import type { SyncOutcome } from "../shared/sync-outcome";2627 2728 const REGISTRY_KEY = "peach_paired_devices_v3";2829 const REVOCATIONS_KEY = "peach_device_revocations_v1";@@ -292,7 +293,17 @@292293 await chrome.storage.local.set({ [LAST_SYNC_AT_KEY]: when });293294 }294295 296+/**297+ * The last sync ATTEMPT, not just the last success. A 3-second flash in the298+ * popup is useless for debugging a real phone, so every terminating path299+ * writes this and Settings reads it back after the fact — including across an300+ * MV3 service-worker restart.301+ */295302 export interface SyncResult {303+ outcome: SyncOutcome;304+ detail?: string;305+ /** When the attempt finished, success or not. */306+ at: number;296307 entriesReceived: number;297308 entriesSent: number;298309 }@@ -304,6 +315,8 @@304315 if (305316 value &&306317 typeof value === "object" &&318+ typeof (value as Record<string, unknown>).outcome === "string" &&319+ typeof (value as Record<string, unknown>).at === "number" &&307320 typeof (value as Record<string, unknown>).entriesReceived === "number" &&308321 typeof (value as Record<string, unknown>).entriesSent === "number"309322 ) {src/background/sync-runner.ts+15 −0
@@ -122,6 +122,13 @@122122 123123 try {124124 const outcome = await runSyncInitiator(session, adapter);125+ if (outcome.status !== "completed") {126+ console.info(127+ `[Peach sync] protocol ended ${outcome.status} with ${device.deviceName ?? device.deviceId}${128+ outcome.error ? `: ${outcome.error}` : ""129+ }`,130+ );131+ }125132 if (outcome.status === "completed") {126133 return {127134 ok: true,@@ -161,6 +168,14 @@161168 );162169 } catch (error) {163170 lastError = error;171+ // Each clock-skew window fails separately and only the last one survives172+ // into the thrown message; on a real device the earlier ones are often173+ // the informative ones.174+ console.info(175+ `[Peach sync] relay dial failed — relay=${relayUrl} rendezvous=${rendezvousId}: ${176+ error instanceof Error ? error.message : String(error)177+ }`,178+ );164179 }165180 }166181 const detail = lastError instanceof Error ? lastError.message : "unreachable";src/background/sync-trigger.test.ts+113 −1
@@ -201,7 +201,119 @@201201 // Read the raw storage value to confirm persistence.202202 const raw = await (globalThis as unknown as { chrome: { storage: { local: { get(k: string): Promise<Record<string, unknown>> } } } })203203 .chrome.storage.local.get("peach_last_sync_result");204- expect(raw.peach_last_sync_result).toEqual({ entriesReceived: 3, entriesSent: 1 });204+ expect(raw.peach_last_sync_result).toMatchObject({205+ outcome: "completed_changes",206+ entriesReceived: 3,207+ entriesSent: 1,208+ });209+ expect(typeof (raw.peach_last_sync_result as { at: unknown }).at).toBe("number");210+ });211+212+ // Every terminating path must be distinguishable. Before this, "nobody to213+ // sync with", "runner not wired" and "synced, nothing to do" were all a bare214+ // `return` — the user and the logs saw the same nothing in all three cases.215+ describe("reported outcomes", () => {216+ it("reports no_paired_devices when the registry is empty", async () => {217+ setSyncRunner(async () => ({ ok: true, entriesReceived: 0, entriesSent: 0 }));218+ await triggerSyncIfReachable({ reason: "manual" });219+ const s = getSyncState();220+ expect(s.outcome).toBe("no_paired_devices");221+ expect(s.status).toBe("idle");222+ expect(typeof s.finishedAt).toBe("number");223+ });224+225+ it("reports no_eligible_host naming the deviceType and trustSource found", async () => {226+ // This is the diagnostic that matters on real hardware: a device that227+ // paired fine but whose type/trust puts it outside the host filter.228+ await upsertPairedDevice({ ...EXT, deviceName: "Other Chrome" });229+ await upsertPairedDevice({230+ ...ANDROID,231+ deviceId: "untrusted-android",232+ deviceName: "Pixel",233+ trustSource: undefined,234+ });235+ setSyncRunner(async () => ({ ok: true, entriesReceived: 0, entriesSent: 0 }));236+ await triggerSyncIfReachable({ reason: "manual" });237+ const s = getSyncState();238+ expect(s.outcome).toBe("no_eligible_host");239+ expect(s.status).toBe("error");240+ expect(s.detail).toContain("Other Chrome [type=extension, trust=unset]");241+ expect(s.detail).toContain("Pixel [type=android, trust=unset]");242+ });243+244+ it("reports runner_unavailable when the runner slot is never wired", async () => {245+ await upsertPairedDevice(ANDROID);246+ setSyncRunner(null);247+ await triggerSyncIfReachable({ reason: "manual" });248+ const s = getSyncState();249+ expect(s.outcome).toBe("runner_unavailable");250+ expect(s.status).toBe("error");251+ });252+253+ it("distinguishes completed_no_changes from a failure", async () => {254+ await upsertPairedDevice(ANDROID);255+ setSyncRunner(async () => ({ ok: true, entriesReceived: 0, entriesSent: 0 }));256+ await triggerSyncIfReachable({ reason: "manual" });257+ const s = getSyncState();258+ expect(s.outcome).toBe("completed_no_changes");259+ expect(s.status).toBe("idle");260+ expect(s.error).toBeUndefined();261+ });262+263+ it("surfaces a runner throw as its own message rather than swallowing it", async () => {264+ await upsertPairedDevice(ANDROID);265+ setSyncRunner(async () => {266+ throw new Error("relay_sync_failed:WebSocket connect timed out");267+ });268+ await triggerSyncIfReachable({ reason: "manual" });269+ const s = getSyncState();270+ expect(s.outcome).toBe("relay_unreachable");271+ expect(s.detail).toBe("relay_sync_failed:WebSocket connect timed out");272+ expect(s.error).toBe("relay_sync_failed:WebSocket connect timed out");273+ });274+275+ it.each([276+ ["sync_disabled", "sync_disabled"],277+ ["private_relay_unset", "private_relay_unset"],278+ ["vault_id_mismatch", "vault_id_mismatch"],279+ ["sync_timeout", "sync_timeout"],280+ ["VAULT_LOCKED", "vault_locked"],281+ ["relay_sync_failed:sync_handshake_timeout", "handshake_failed"],282+ ["something nobody predicted", "run_failed"],283+ ])("classifies runner error %s as %s", async (error, outcome) => {284+ await upsertPairedDevice(ANDROID);285+ setSyncRunner(async () => ({ ok: false, error }));286+ await triggerSyncIfReachable({ reason: "manual", force: true });287+ expect(getSyncState().outcome).toBe(outcome);288+ });289+290+ it("keeps the in-flight run's state when a concurrent trigger is dropped", async () => {291+ await upsertPairedDevice(ANDROID);292+ setSyncRunner(async () => {293+ await new Promise<void>((r) => setTimeout(r, 30));294+ return { ok: true as const, entriesReceived: 0, entriesSent: 0 };295+ });296+ const first = triggerSyncIfReachable({ reason: "manual" });297+ while (getSyncState().status !== "syncing") await Promise.resolve();298+ await triggerSyncIfReachable({ reason: "vault_change" });299+ // The dropped trigger must not stamp a terminal outcome over a live run.300+ expect(getSyncState().status).toBe("syncing");301+ await first;302+ expect(getSyncState().outcome).toBe("completed_no_changes");303+ });304+305+ it("restores the last outcome across a SW restart so a failure stays inspectable", async () => {306+ await upsertPairedDevice(ANDROID);307+ setSyncRunner(async () => ({ ok: false, error: "vault_id_mismatch" }));308+ await triggerSyncIfReachable({ reason: "manual" });309+ _resetSyncTriggerForTest();310+ expect(getSyncState().outcome).toBeUndefined();311+ await hydratePersistedSyncState();312+ const s = getSyncState();313+ expect(s.outcome).toBe("vault_id_mismatch");314+ expect(s.detail).toBe("vault_id_mismatch");315+ expect(typeof s.finishedAt).toBe("number");316+ });205317 });206318 207319 it("hydratePersistedSyncState restores lastSyncAt across SW restart simulation", async () => {src/background/sync-trigger.ts+154 −24
@@ -12,12 +12,14 @@1212 1313 import {1414 getLastSyncAt,15+ getLastSyncResult,1516 listPairedDevices,1617 markLastSyncedAt,1718 setLastSyncAt,1819 setLastSyncResult,1920 } from "./paired-devices";2021 import type { PairedDevice } from "../shared/sync-types";22+import { isSyncFailure, type SyncOutcome } from "../shared/sync-outcome";2123 2224 export type SyncTriggerReason = "vault_change" | "foreground" | "manual";2325 @@ -26,10 +28,15 @@2628 export interface SyncState {2729 status: SyncRunStatus;2830 reason?: SyncTriggerReason;31+ /** Last SUCCESSFUL sync. `finishedAt` is the last attempt of any kind. */2932 lastSyncAt?: number;3033 entriesReceived?: number;3134 entriesSent?: number;3235 error?: string;36+ outcome?: SyncOutcome;37+ /** Raw internal code, or the device inventory behind `no_eligible_host`. */38+ detail?: string;39+ finishedAt?: number;3340 }3441 3542 export type SyncRunResult =@@ -81,11 +88,28 @@8188 */8289 export async function hydratePersistedSyncState(): Promise<void> {8390 const state = getSyncTriggerState();84- if (state.lastState.lastSyncAt !== undefined) return;85- const persisted = await getLastSyncAt();86- if (typeof persisted === "number") {87- state.lastState = { ...state.lastState, lastSyncAt: persisted };91+ if (state.lastState.lastSyncAt === undefined) {92+ const persisted = await getLastSyncAt();93+ if (typeof persisted === "number") {94+ state.lastState = { ...state.lastState, lastSyncAt: persisted };95+ }8896 }97+ // The outcome of the last attempt survives too, otherwise a failure that98+ // happened before the SW died is unreportable — which is the case a real99+ // device most needs explained.100+ if (state.lastState.outcome === undefined) {101+ const last = await getLastSyncResult();102+ if (last) {103+ state.lastState = {104+ ...state.lastState,105+ outcome: last.outcome,106+ detail: last.detail,107+ finishedAt: last.at,108+ entriesReceived: last.entriesReceived,109+ entriesSent: last.entriesSent,110+ };111+ }112+ }89113 }90114 91115 export async function triggerSyncIfReachable(opts: {@@ -96,7 +120,11 @@96120 // Claim the guard synchronously before any await, otherwise two97121 // concurrent triggers could both pass the gate before either reached98122 // the registry lookup.99- if (state.syncInFlight && !opts.force) return;123+ if (state.syncInFlight && !opts.force) {124+ // Deliberately does NOT overwrite lastState — the in-flight run owns it.125+ log(`trigger (${opts.reason}) ignored, a sync is already in flight`);126+ return;127+ }100128 state.syncInFlight = true;101129 102130 try {@@ -114,10 +142,31 @@114142 (d.deviceType === "android" || d.deviceType === "ios") &&115143 (d.trustSource === "direct" || d.trustSource === "vouched"),116144 );117- if (hosts.length === 0) return;118- if (!state.runner) return;145+ if (devices.length === 0) {146+ finish({ outcome: "no_paired_devices" });147+ return;148+ }149+ if (hosts.length === 0) {150+ // The device inventory is the diagnostic: it says exactly which151+ // deviceType/trustSource combination the eligibility filter rejected.152+ finish({ outcome: "no_eligible_host", detail: inventory(devices) });153+ return;154+ }155+ if (!state.runner) {156+ finish({ outcome: "runner_unavailable" });157+ return;158+ }119159 120- setState({ status: "syncing", reason: opts.reason, error: undefined });160+ setState({161+ status: "syncing",162+ reason: opts.reason,163+ error: undefined,164+ outcome: undefined,165+ detail: undefined,166+ });167+ log(168+ `starting (${opts.reason}) against ${hosts.length} host(s): ${inventory(hosts)}`,169+ );121170 await runSyncRounds(hosts);122171 } finally {123172 state.syncInFlight = false;@@ -126,7 +175,10 @@126175 127176 async function runSyncRounds(hosts: PairedDevice[]): Promise<void> {128177 const state = getSyncTriggerState();129- if (!state.runner) return;178+ if (!state.runner) {179+ finish({ outcome: "runner_unavailable" });180+ return;181+ }130182 131183 let entriesReceived = 0;132184 let entriesSent = 0;@@ -137,6 +189,7 @@137189 try {138190 const result = await state.runner(host);139191 if (!result.ok) {192+ log(`host ${describeHost(host)} refused: ${result.error}`);140193 if (firstError === undefined) firstError = result.error;141194 continue;142195 }@@ -145,32 +198,109 @@145198 await markLastSyncedAt(host.deviceId, Date.now());146199 anySucceeded = true;147200 } catch (err) {148- if (firstError === undefined) {149- firstError = (err as Error)?.message ?? String(err);150- }201+ const message = (err as Error)?.message ?? String(err);202+ log(`host ${describeHost(host)} threw: ${message}`);203+ if (firstError === undefined) firstError = message;151204 }152205 }153206 154207 if (anySucceeded) {155208 const now = Date.now();156- setState({157- status: "idle",158- lastSyncAt: now,209+ finish({210+ outcome: entriesReceived + entriesSent > 0 ? "completed_changes" : "completed_no_changes",211+ // A partial success still names the host that failed — otherwise "synced"212+ // hides the peer that never got the change.213+ detail: firstError,159214 entriesReceived,160215 entriesSent,161- error: undefined,162216 });163- // Persist so the popup's "last synced" indicator and entry counts164- // survive a SW restart. Best-effort — storage failures must not165- // surface as sync failures.217+ // Persist so the popup's "last synced" indicator survives a SW restart.218+ // Best-effort — storage failures must not surface as sync failures.166219 void setLastSyncAt(now).catch(() => undefined);167- void setLastSyncResult({ entriesReceived, entriesSent }).catch(() => undefined);168220 } else {169- setState({170- status: "error",171- error: firstError ?? "no_host_reachable",172- });221+ const error = firstError ?? "no_host_reachable";222+ finish({ outcome: classifySyncError(error), detail: error });173223 }224+}225+226+/**227+ * Runner errors are opaque strings by contract (`SyncRunResult.error` and any228+ * throw). Mapping them here is the only place the popup's plain-English copy229+ * can key off something stable.230+ */231+function classifySyncError(error: string): SyncOutcome {232+ if (error.includes("VAULT_LOCKED")) return "vault_locked";233+ if (error.includes("sync_disabled")) return "sync_disabled";234+ if (error.includes("private_relay_unset")) return "private_relay_unset";235+ if (error.includes("vault_id_mismatch")) return "vault_id_mismatch";236+ if (error.includes("sync_timeout")) return "sync_timeout";237+ if (error.startsWith("relay_sync_failed")) {238+ return /handshake|PAIR_IDENTITY|identity does not match/i.test(error)239+ ? "handshake_failed"240+ : "relay_unreachable";241+ }242+ return "run_failed";243+}244+245+interface SyncFinish {246+ outcome: SyncOutcome;247+ detail?: string;248+ entriesReceived?: number;249+ entriesSent?: number;250+}251+252+/**253+ * The single exit for every terminating path. Nothing may `return` out of a254+ * sync run without going through here — that silence is the bug this whole255+ * module was reworked to remove.256+ */257+function finish(result: SyncFinish): void {258+ const now = Date.now();259+ const failed = isSyncFailure(result.outcome);260+ const entriesReceived = result.entriesReceived ?? 0;261+ const entriesSent = result.entriesSent ?? 0;262+ setState({263+ status: failed ? "error" : "idle",264+ outcome: result.outcome,265+ detail: result.detail,266+ error: failed ? result.detail ?? result.outcome : undefined,267+ finishedAt: now,268+ entriesReceived,269+ entriesSent,270+ ...(result.outcome === "completed_changes" || result.outcome === "completed_no_changes"271+ ? { lastSyncAt: now }272+ : {}),273+ });274+ log(275+ `${result.outcome}${result.detail ? ` — ${result.detail}` : ""}` +276+ (entriesReceived + entriesSent > 0277+ ? ` (sent ${entriesSent}, received ${entriesReceived})`278+ : ""),279+ );280+ void setLastSyncResult({281+ outcome: result.outcome,282+ detail: result.detail,283+ at: now,284+ entriesReceived,285+ entriesSent,286+ }).catch(() => undefined);287+}288+289+/** What the eligibility filter actually saw. Names, not just counts. */290+function inventory(devices: PairedDevice[]): string {291+ return devices.map(describeHost).join("; ");292+}293+294+function describeHost(d: PairedDevice): string {295+ return `${d.deviceName ?? d.deviceId} [type=${d.deviceType ?? "unset"}, trust=${d.trustSource ?? "unset"}]`;296+}297+298+/**299+ * MV3 kills the service worker constantly, so devtools on the SW is the only300+ * post-hoc record of a sync attempt. Prefixed so it can be filtered.301+ */302+function log(message: string): void {303+ console.info(`[Peach sync] ${message}`);174304 }175305 176306 function setState(patch: Partial<SyncState>): void {src/shared/sync-outcome.ts+114 −0
@@ -0,0 +1,114 @@1+// Why a sync run ended, in a form both the service worker and the popup can2+// name. Before this existed, "no eligible host", "runner not wired" and3+// "synced fine, nothing to do" were all a bare `return` — indistinguishable4+// to the user and to us. A failed sync and a successful no-op must never5+// look the same again.6+7+export type SyncOutcome =8+ | "completed_changes"9+ | "completed_no_changes"10+ | "no_paired_devices"11+ | "no_eligible_host"12+ | "runner_unavailable"13+ | "sync_disabled"14+ | "private_relay_unset"15+ | "vault_locked"16+ | "relay_unreachable"17+ | "handshake_failed"18+ | "vault_id_mismatch"19+ | "sync_timeout"20+ | "run_failed";21+22+/** Outcomes where sync did not do what the user asked, so the UI shows red. */23+const FAILURES: ReadonlySet<SyncOutcome> = new Set<SyncOutcome>([24+ "no_eligible_host",25+ "runner_unavailable",26+ "private_relay_unset",27+ "vault_locked",28+ "relay_unreachable",29+ "handshake_failed",30+ "vault_id_mismatch",31+ "sync_timeout",32+ "run_failed",33+]);34+35+export function isSyncFailure(outcome: SyncOutcome): boolean {36+ return FAILURES.has(outcome);37+}38+39+export interface SyncOutcomeSummary {40+ status?: "idle" | "syncing" | "error";41+ outcome?: SyncOutcome;42+ entriesSent?: number;43+ entriesReceived?: number;44+ detail?: string;45+}46+47+/**48+ * The one indicator light. `busy` pulses green, `ok` is solid green, `error`49+ * is red, `idle` is unlit. Nothing that is actually broken may resolve to50+ * `ok` — a paired-but-unsyncable device is red, not green.51+ */52+export type SyncIndicator = "busy" | "ok" | "error" | "idle";53+54+export function syncIndicator(s: SyncOutcomeSummary, pairedCount: number): SyncIndicator {55+ if (s.status === "syncing") return "busy";56+ if (s.outcome && isSyncFailure(s.outcome)) return "error";57+ if (s.outcome === "completed_changes" || s.outcome === "completed_no_changes") {58+ return "ok";59+ }60+ // Paired with a healthy history but no attempt since this SW woke: still a61+ // successful pair, which is what the light is claiming.62+ if (pairedCount > 0 && s.outcome === undefined) return "ok";63+ return "idle";64+}65+66+const INDICATOR_LABEL: Record<SyncIndicator, string> = {67+ busy: "Syncing",68+ ok: "Sync healthy",69+ error: "Sync problem",70+ idle: "Not syncing",71+};72+73+/** Colour alone is never the signal — this is the same claim in words. */74+export function syncIndicatorLabel(75+ indicator: SyncIndicator,76+ s: SyncOutcomeSummary,77+): string {78+ return `${INDICATOR_LABEL[indicator]} — ${describeSyncOutcome(s)}`;79+}80+81+const COPY: Record<SyncOutcome, string> = {82+ completed_changes: "Synced",83+ completed_no_changes: "Up to date — nothing to send or receive",84+ no_paired_devices: "No devices paired yet",85+ no_eligible_host: "Paired, but no device here can accept a sync",86+ runner_unavailable: "Sync isn't running in the background — reload Peach",87+ sync_disabled: "Sync is switched off",88+ private_relay_unset: "Private relay chosen but no address set",89+ vault_locked: "Vault was locked — unlock and sync again",90+ relay_unreachable: "Couldn't reach the relay",91+ handshake_failed: "Reached the relay, but the device didn't answer",92+ vault_id_mismatch: "That device holds a different vault",93+ sync_timeout: "The device stopped responding mid-sync",94+ run_failed: "Sync failed",95+};96+97+/**98+ * One plain-English line for a sync outcome. `detail` — the raw internal code99+ * or the device inventory behind `no_eligible_host` — is appended rather than100+ * hidden: it is the whole diagnostic on a real device, where devtools is not101+ * an option.102+ */103+export function describeSyncOutcome(s: SyncOutcomeSummary): string {104+ if (!s.outcome) return "Not synced yet";105+ const base = COPY[s.outcome] ?? "Sync failed";106+ if (s.outcome === "completed_changes") {107+ const moved = [108+ (s.entriesSent ?? 0) > 0 ? `${s.entriesSent} sent` : null,109+ (s.entriesReceived ?? 0) > 0 ? `${s.entriesReceived} received` : null,110+ ].filter(Boolean);111+ return moved.length > 0 ? `${base} — ${moved.join(", ")}` : base;112+ }113+ return s.detail ? `${base} (${s.detail})` : base;114+}