From 452ad2077cfa0a700e370ef84746616ba62de612 Mon Sep 17 00:00:00 2001 From: Daniel Ehrhardt Date: Sun, 25 Oct 2026 08:56:47 +0100 Subject: [PATCH] Fix main's snapshot tests and stop repeating the same device group warnings - remote-snapshot.test.ts: drop the imports two merges added twice, and expect the free-slug behaviour for a project or workspace both computers made - A remote run's memory merge goes ahead on the runner's existing setup when the setup copy fails - A setup copy that fails like last time and a replica change that keeps failing on retry are logged at info after the first warning --- packages/core/src/remote/replica.ts | 10 +++++++++- packages/core/src/remote/runners.ts | 12 +++++++----- packages/core/test/remote-snapshot.test.ts | 22 +++++++++++----------- packages/core/test/replica.test.ts | 19 +++++++++++++++++-- 4 files changed, 44 insertions(+), 19 deletions(-) diff --git a/packages/core/src/remote/replica.ts b/packages/core/src/remote/replica.ts index 4010b89c..e9bc70d9 100644 --- a/packages/core/src/remote/replica.ts +++ b/packages/core/src/remote/replica.ts @@ -459,6 +459,8 @@ function emptyResult(): ApplyResult { return { applied: 0, kept: 0, deferred: 0, failed: 0, entities: new Set(), agents: new Set(), removedAgents: [], keys: {} }; } +const stuckWarned = new Set(); + /** * Write what `peer` changed. `peerWinsTies`: the peer is the primary. Each row is checked against its last change here * first; a row that points at one that isn't here yet waits (replica_deferred) and is tried with the next pull. @@ -491,7 +493,13 @@ export function applyChanges(peer: string, changes: ReplicaChange[], opts: Apply } catch { /* the database is in trouble: the next pull brings it again */ } - log.warn(`could not take a change of ${c.t} yet`, { peer, key: c.k, error: one instanceof Error ? one.message : String(one) }); + const error = one instanceof Error ? one.message : String(one); + // Tried again with every pull: the same failure is worth one warning. + const seen = `${peer}${KEY_SEP}${c.t}${KEY_SEP}${c.k}${KEY_SEP}${error}`; + if (stuckWarned.size >= 1000) stuckWarned.clear(); + const level = stuckWarned.has(seen) ? "info" : "warn"; + stuckWarned.add(seen); + log[level](`could not take a change of ${c.t} yet`, { peer, key: c.k, error }); } } Object.assign(result, partial); diff --git a/packages/core/src/remote/runners.ts b/packages/core/src/remote/runners.ts index 1bc649cb..fa5e32e7 100644 --- a/packages/core/src/remote/runners.ts +++ b/packages/core/src/remote/runners.ts @@ -642,7 +642,7 @@ export function startRunners(): void { for (const r of all("SELECT * FROM runners")) startLink(r); setMirrorHooks({ runFinished: (runnerId, run) => { - void syncRunner(runnerId, { agentId: run.agentId }).catch((err) => log.warn(`could not merge memory after run ${run.id}`, err instanceof Error ? err.message : err)); + void syncRunner(runnerId, { agentId: run.agentId, work: true }).catch((err) => logFailure(`could not merge memory after run ${run.id}`, err)); }, resync: (runnerId, runId) => links.get(runnerId)?.sendClientEvent({ type: "run.resync", runId }), released: (runnerId, conversationId) => pendingReleases(runnerId).includes(conversationId), @@ -741,7 +741,7 @@ export function linkGone(err: unknown): boolean { function logFailure(text: string, err: unknown): void { const detail = err instanceof Error ? err.message : err; - if (linkGone(err)) log.info(text, detail); + if (linkGone(err) || (err as { repeated?: boolean } | null)?.repeated) log.info(text, detail); else log.warn(text, detail); } @@ -784,12 +784,14 @@ export function syncRunner(id: string, opts: { agentId?: string; profileId?: str /* the next connect tells */ } } catch (err) { - update("runners", id, { sync_error: `Couldn't copy your setup: ${message(err)}`, updated_at: now() }); - const failure = Object.assign(new HttpError(502, `Couldn't copy your setup to ${r.name}: ${message(err)}`, "runner_sync_failed"), { cause: err }); + const syncError = `Couldn't copy your setup: ${message(err)}`; + update("runners", id, { sync_error: syncError, updated_at: now() }); + // The same failure as last time: it was warned about then, every edit and run tries again. + const failure = Object.assign(new HttpError(502, `Couldn't copy your setup to ${r.name}: ${message(err)}`, "runner_sync_failed"), { cause: err, repeated: r.sync_error === syncError }); // Work goes ahead on the setup the runner has (the runner card shows why) — not when it never got one or lacks the key. if (!opts.work || needsKey || !r.synced_at || linkGone(err)) throw failure; warnings.push(failure.message); - logFailure(failure.message, err); + logFailure(`could not copy the setup to runner ${id}`, failure); } finally { syncing.delete(id); emit(id); diff --git a/packages/core/test/remote-snapshot.test.ts b/packages/core/test/remote-snapshot.test.ts index f3915ecf..0cee33b2 100644 --- a/packages/core/test/remote-snapshot.test.ts +++ b/packages/core/test/remote-snapshot.test.ts @@ -12,10 +12,8 @@ import { setLogLevel } from "../src/log"; import type { MemorySnapshot } from "../src/memory/files"; import { clearGroup, setGroup } from "../src/remote/group"; import { mergeMemory, readMemoryState, writeMemoryState } from "../src/remote/memorySync"; -import { ensureReplica, resetReplicaCache } from "../src/remote/replica"; -import { appliedDigest, applySnapshot, buildSnapshot, snapshotDigest, type ConfigSnapshot } from "../src/remote/snapshot"; -import { clearGroup, setGroup } from "../src/remote/group"; import { ensureReplica, madeHere, pendingKeys, resetReplicaCache } from "../src/remote/replica"; +import { appliedDigest, applySnapshot, buildSnapshot, snapshotDigest, type ConfigSnapshot } from "../src/remote/snapshot"; import * as runner from "../src/runner/runner"; import { getSettings, resetSettingsCache, updateSettings } from "../src/services/settings"; import { HttpError } from "../src/util"; @@ -726,7 +724,7 @@ describe("applying a snapshot on a runner", () => { expect(vault.isUnlocked()).toBe(true); }); - test("a secondary keeps a project it made with the same name as one of the primary's, and the rest of the copy lands", async () => { + test("a project a secondary made with the same name as one of the primary's moves to a free slug, and the rest of the copy lands", async () => { const secondary = mkdtempSync(join(tmpdir(), "godmode-snapshot-secondary-")); try { use(controller); @@ -749,10 +747,11 @@ describe("applying a snapshot on a runner", () => { use(secondary); const result = await applySnapshot(copy); - expect(result.warnings).toEqual(['"Earshot" (projects) wasn\'t copied: this computer has its own one with the same name.']); - expect(exists("projects", "prj_here")).toBe(true); - expect(exists("projects", "prj_there")).toBe(false); - expect(row("agents", "agt_helper")).toMatchObject({ project_id: "prj_here", instructions: "Work on Earshot." }); + expect(result.warnings).toEqual([]); + expect(row("projects", "prj_here").slug).toBe("earshot-2"); + expect(row("projects", "prj_there").slug).toBe("earshot"); + expect(pendingKeys("rnr_primary", "projects").has("prj_here")).toBe(true); + expect(row("agents", "agt_helper")).toMatchObject({ project_id: "prj_there", instructions: "Work on Earshot." }); expect(appliedDigest()).toBe(copy.digest); } finally { clearGroup(); @@ -779,10 +778,11 @@ describe("applying a snapshot on a runner", () => { use(secondary); const result = await applySnapshot(copy); - expect(result.warnings.join("\n")).toContain('"Studio" (workspaces) wasn\'t copied'); + expect(result.warnings).toEqual([]); + expect(row("workspaces", "ws_here").slug).toBe("studio-2"); + expect(row("workspaces", "ws_there").slug).toBe("studio"); expect(row("projects", "prj_here")).toMatchObject({ workspace_id: "ws_here", slug: "earshot" }); - expect(exists("workspaces", "ws_there")).toBe(false); - expect(exists("projects", "prj_there")).toBe(false); + expect(row("projects", "prj_there")).toMatchObject({ workspace_id: "ws_there", slug: "earshot" }); expect(exists("agents", "agt_helper")).toBe(true); expect(appliedDigest()).toBe(copy.digest); } finally { diff --git a/packages/core/test/replica.test.ts b/packages/core/test/replica.test.ts index 9f787441..0c9ed46f 100644 --- a/packages/core/test/replica.test.ts +++ b/packages/core/test/replica.test.ts @@ -5,12 +5,12 @@ */ import { afterAll, beforeAll, beforeEach, describe, expect, test } from "bun:test"; import type { Database } from "bun:sqlite"; -import { mkdtempSync, rmSync } from "node:fs"; +import { existsSync, mkdirSync, mkdtempSync, readFileSync, rmSync } from "node:fs"; import { tmpdir } from "node:os"; import { join } from "node:path"; import { loadConfig } from "../src/config"; import { all, closeDb, get, openDb, run, setDb } from "../src/db"; -import { setLogLevel } from "../src/log"; +import { setFileLogLevel, setLogDir, setLogLevel } from "../src/log"; import { getSettings, resetSettingsCache, updateSettings } from "../src/services/settings"; import { applyChanges, changesFor, ensureReplica, pendingFor, pendingKeys, replicaSeq, replicaTables, resetReplicaCache, retryDeferred, type ReplicaChange } from "../src/remote/replica"; @@ -272,6 +272,21 @@ describe("between two computers", () => { expect(all("SELECT * FROM replica_deferred")).toHaveLength(0); }); + test("a change that keeps failing is warned about once, its retries only at info", () => { + use(b); + const logs = join(dir, "logs"); + mkdirSync(logs, { recursive: true }); + setLogDir(logs); + setFileLogLevel("info"); + const broken: ReplicaChange = { t: "goals", k: "gol_broken", at: T(40), row: { id: "gol_broken", title: null, created_at: T(40), updated_at: T(40) } }; + expect(applyChanges("rnr_a", [broken], { peerWinsTies: false }).failed).toBe(1); + expect(retryDeferred("rnr_a", { peerWinsTies: false }).failed).toBe(1); + expect(retryDeferred("rnr_a", { peerWinsTies: false }).failed).toBe(1); + const file = join(logs, "godmode.jsonl"); + const lines = existsSync(file) ? readFileSync(file, "utf8").trim().split("\n").map((l) => JSON.parse(l) as { level: string; msg: string }) : []; + expect(lines.filter((l) => l.msg === "could not take a change of goals yet").map((l) => l.level)).toEqual(["warn", "info", "info"]); + }); + test("an agent whose folder name isn't safe never lands", () => { use(b); const evil: ReplicaChange = { t: "agents", k: "agt_evil", at: T(20), row: { id: "agt_evil", name: "Evil", slug: "../../outside", created_at: T(0), updated_at: T(0) } };