From 38ce135b302a2985bb635d43ab7dbeb480546d01 Mon Sep 17 00:00:00 2001 From: ChakraFusion <112588066+ChakraFusion@users.noreply.github.com> Date: Thu, 15 Oct 2026 12:21:46 +0200 Subject: [PATCH 1/2] sync: a report stamps the devices synced as of when it compared them RefreshLineage, run when a peer reports it finished pulling or that the two are in sync, stamped "last synced" once it had read both sides and written the lineage. A location with no merge base yet counts only edits made after that stamp (plus the 2 s clock-skew allowance) as new, so an edit made while the refresh ran - seconds on a slow disk - could count as made before the devices were compared. The stamp is now the time the comparison began, before either side was read. A stamp that ends up earlier than another written meanwhile only makes more edits count as new, which is the safe direction. Hardening, not the cause of the CI failure of TestMultiRootScenario_ALateReportDoesNotHideADivergence: that was the test editing inside the skew allowance, fixed in the next commit. TestRefreshLineage_StampsWhenTheComparisonBegan: fails 3/3 without this (stamp ~100 ms after the peer's side was read), passes with it. Co-Authored-By: Claude Opus 5.5 --- internal/p2p/syncengine/engine.go | 18 ++++++++-- internal/p2p/syncengine/engine_test.go | 6 ++++ internal/p2p/syncengine/stamp_test.go | 50 ++++++++++++++++++++++++++ 3 files changed, 72 insertions(+), 2 deletions(-) create mode 100644 internal/p2p/syncengine/stamp_test.go diff --git a/internal/p2p/syncengine/engine.go b/internal/p2p/syncengine/engine.go index f60d67fe..821b81f9 100644 --- a/internal/p2p/syncengine/engine.go +++ b/internal/p2p/syncengine/engine.go @@ -393,7 +393,16 @@ func syncedNow() string { return time.Now().UTC().Format("2006-01-02T15:04:05.00 // up to date with this save?" needs. The two are written together so they // cannot disagree about when. func (e *Engine) recordSynced(gameID, peerID string) { - ts := syncedNow() + e.recordSyncedAt(gameID, peerID, syncedNow()) +} + +// recordSyncedAt is recordSynced for a comparison that began at ts. The stamp +// says the two devices were the same as of that time, and a location with no +// merge base yet counts only the edits made after it as new. Stamped with the +// time the comparison ended instead, it reached past edits made while it ran +// — on a slow disk that is seconds — and an edit made on both devices then +// read as neither having changed: one quietly replaced the other. +func (e *Engine) recordSyncedAt(gameID, peerID, ts string) { _ = e.Store.UpdatePeerLastSynced(peerID, ts) _ = e.Store.UpdateGamePeerLastSynced(gameID, peerID, ts) } @@ -1182,6 +1191,11 @@ func (e *Engine) ConfirmInSync(ctx context.Context, gameID string, peer Peer, cl // the lineage (making future local deletions of them propagate instead of // the file being pulled back). func (e *Engine) RefreshLineage(ctx context.Context, gameID string, peer Peer) { + // Taken before either side is read: whatever the comparison below finds, + // it found as of no earlier than this, and an edit made while it runs — + // after the peer's manifest was fetched, or after ours was read — must + // still count as made after the time it stamps (recordSyncedAt). + checkedAt := syncedNow() game, err := e.Store.GetGame(gameID) if err != nil { return @@ -1219,7 +1233,7 @@ func (e *Engine) RefreshLineage(ctx context.Context, gameID string, peer Peer) { if local.ManifestHash() == remoteData.Manifest.ManifestHash() { _ = e.Store.SetAgreedHash(gameID, peer.ID, local.ManifestHash()) if rootsAgree { - e.recordSynced(gameID, peer.ID) + e.recordSyncedAt(gameID, peer.ID, checkedAt) e.notifySyncConfirmed(gameID) } } diff --git a/internal/p2p/syncengine/engine_test.go b/internal/p2p/syncengine/engine_test.go index 1ed654ff..aa501a7f 100644 --- a/internal/p2p/syncengine/engine_test.go +++ b/internal/p2p/syncengine/engine_test.go @@ -47,6 +47,9 @@ type fakeTransport struct { // "sync-complete" once a pull's files are all written, before the sync // that pulled them has finished. onSyncEvent func(eventType string) + // onFetchManifest runs as the peer's manifest is served, before it is + // read: a test's way to stand in a comparison that is part-way through. + onFetchManifest func() } func (f *fakeTransport) FetchManifest(ctx context.Context, peer Peer, gameID string, q ManifestQuery) (ManifestResponse, error) { @@ -63,6 +66,9 @@ func (f *fakeTransport) FetchManifest(ctx context.Context, peer Peer, gameID str if f.manifestErr != nil { return ManifestResponse{}, f.manifestErr } + if f.onFetchManifest != nil { + f.onFetchManifest() + } m, err := delta.BuildManifest(f.remoteDir) if err != nil { return ManifestResponse{}, err diff --git a/internal/p2p/syncengine/stamp_test.go b/internal/p2p/syncengine/stamp_test.go new file mode 100644 index 00000000..2300c4d4 --- /dev/null +++ b/internal/p2p/syncengine/stamp_test.go @@ -0,0 +1,50 @@ +package syncengine + +import ( + "context" + "testing" + "time" +) + +// The time a peer's report confirms the two devices the same is the time the +// comparison began, not the time it finished. +// +// A location with no merge base yet counts only the edits made after that +// time as new. RefreshLineage stamped it once it had read both sides and +// written the lineage — seconds later on a slow disk — so an edit made on both +// devices while it ran read as neither having changed, and one replaced the +// other with no conflict raised. CI: TestMultiRootScenario_ALateReportDoesNotHideADivergence +// on Windows, "A=\"B-version\" B=\"B-version\"". +func TestRefreshLineage_StampsWhenTheComparisonBegan(t *testing.T) { + env := setupEngine(t) + write(t, env.localDir, "save.dat", "same") + write(t, env.remoteDir, "save.dat", "same") + + var fetchedAt time.Time + env.transport.onFetchManifest = func() { + fetchedAt = time.Now() + // The rest of the comparison taking a while, as it does on a busy + // machine: an edit made now is after the peer's side was read. + time.Sleep(100 * time.Millisecond) + } + env.engine.RefreshLineage(context.Background(), "game1", env.peer) + + p, err := env.store.GetPeer(env.peer.ID) + if err != nil { + t.Fatal(err) + } + if !p.LastSynced.Valid { + t.Fatal("identical sides were not stamped as synced") + } + stamped, err := time.Parse("2006-01-02T15:04:05.000Z", p.LastSynced.String) + if err != nil { + t.Fatal(err) + } + if fetchedAt.IsZero() { + t.Fatal("the peer's manifest was never fetched") + } + if stamped.After(fetchedAt) { + t.Errorf("stamped synced at %s, %v after the peer's side was read: an edit made in between would not count as new", + stamped.Format(time.RFC3339Nano), stamped.Sub(fetchedAt)) + } +} From ea6e0c003799256cd0229b0f053d2a1028ee1ff8 Mon Sep 17 00:00:00 2001 From: Claude Date: Wed, 14 Oct 2026 23:36:44 +0000 Subject: [PATCH 2/2] e2e: the late-report test edits after the skew allowance, not inside it TestMultiRootScenario_ALateReportDoesNotHideADivergence clears the location's merge base and has both devices edit it. With no base, edits are judged against when the two were last confirmed the same, and only one made more than DetectConflict's 2 s clock-skew allowance after it counts as new. The refresh started by the setup's own reports can stamp that time after SettleSync returns, and the edits then came within it: neither side read as changed, B's version replaced A's, and the test reported "no conflict was raised: A=\"B-version\" B=\"B-version\"" - on Windows CI about one shard run in ten. Instrumented runs show the stamp 1.7-1.9 s before the edits each time; a stamp 1.5 s before them reproduces the failure every time, and 3 s does not. The test now waits until that time has stopped moving and is more than the allowance in the past. It still fails as it should when a report stamps the two as synced while the location differs (the bug it was written for). Co-Authored-By: Claude Opus 5.5 --- e2e/multiroot_scenarios_test.go | 34 +++++++++++++++++++++++++++++++++ 1 file changed, 34 insertions(+) diff --git a/e2e/multiroot_scenarios_test.go b/e2e/multiroot_scenarios_test.go index e6659650..16615064 100644 --- a/e2e/multiroot_scenarios_test.go +++ b/e2e/multiroot_scenarios_test.go @@ -480,6 +480,14 @@ func TestMultiRootScenario_ALateReportDoesNotHideADivergence(t *testing.T) { if err := a.Daemon.Store.SetAgreedHashForRoot(gameID, b.NodeID(), "config", ""); err != nil { t.Fatal(err) } + // With no base, the edits are judged against when the two were + // last confirmed the same, and only one made more than the 2 s + // clock-skew allowance after it counts as new (DetectConflict). A + // refresh the setup's own reports started can stamp that time + // after SettleSync returns; edits made in the next two seconds + // then read as neither side having changed, and the test failed on + // its own timing (Windows CI: stamped 1.8 s before the edits). + waitPastLastSynced(t, a, b.NodeID()) writeIn(t, aConfig, "settings.ini", "A-version") writeIn(t, bConfig, "settings.ini", "B-version") @@ -514,6 +522,32 @@ func TestMultiRootScenario_ALateReportDoesNotHideADivergence(t *testing.T) { } } +// waitPastLastSynced waits until a's "last synced" time for the peer has +// stopped moving and lies further back than the clock-skew allowance a +// location without a merge base is judged with (syncengine's +// clockSkewToleranceMs, 2 s), so an edit made after it counts as new. +func waitPastLastSynced(t *testing.T, a *testutil.TestDaemon, peerID string) { + t.Helper() + const past = 3 * time.Second // the 2 s allowance, and a margin + stamp := func() string { + p, err := a.Daemon.Store.GetPeer(peerID) + if err != nil || !p.LastSynced.Valid { + return "" + } + return p.LastSynced.String + } + deadline := time.Now().Add(45 * time.Second) + for time.Now().Before(deadline) { + s := stamp() + at, err := time.Parse("2006-01-02T15:04:05.000Z", s) + if s == "" || (err == nil && time.Since(at) > past) { + return + } + time.Sleep(100 * time.Millisecond) + } + t.Fatalf("the last-synced time kept moving: %s", stamp()) +} + // The location's own TestStaleBase_OneSidedEditDoesNotConflict. A report that // never arrives leaves the base behind both devices, with the push it was // about still on record — B holds exactly what A sent. An edit on A alone must