diff --git a/src/DodoSSH.Client.App/ViewModels/VaultViewModel.cs b/src/DodoSSH.Client.App/ViewModels/VaultViewModel.cs index 45abb07..07c1a10 100644 --- a/src/DodoSSH.Client.App/ViewModels/VaultViewModel.cs +++ b/src/DodoSSH.Client.App/ViewModels/VaultViewModel.cs @@ -1276,7 +1276,12 @@ internal sealed partial class VaultViewModel( var report = await SyncOnceAsync(server.Sync, cancellationToken).ConfigureAwait(true); - if (report is not null && (report.Pulled > 0 || report.Pushed > 0 || report.NeedsAttention)) + // A pass that had to start over says so even when it pulled nothing, which is the one place + // this loop breaks its own rule about staying quiet. A machine that silently re-read the whole + // vault has had something happen to it, and the alternative is that nobody ever finds out. + if (report is not null + && (report.Pulled > 0 || report.Pushed > 0 || report.NeedsAttention + || report.ResyncedFromStart)) { Status = Describe(report); } @@ -2493,11 +2498,19 @@ internal sealed partial class VaultViewModel( /// private static string Describe(SyncReport report) { + // Said first, and in both branches, because it is the explanation for the numbers after it. A pass + // reporting "214 in" on a vault nobody has touched all week reads as something having gone wrong; + // this is what actually happened, and it needs nothing from the reader. + var replayed = report.ResyncedFromStart + ? "The server no longer recognised this machine's position, so the vault was read again from " + + "the beginning. " + : string.Empty; + if (!report.NeedsAttention) { - return report.Pulled == 0 && report.Pushed == 0 + return replayed + (report.Pulled == 0 && report.Pushed == 0 ? "Already up to date." - : $"Synchronised: {report.Pulled} in, {report.Pushed} out."; + : $"Synchronised: {report.Pulled} in, {report.Pushed} out."); } var notes = new List(); @@ -2529,7 +2542,7 @@ internal sealed partial class VaultViewModel( notes.Add("this vault was rekeyed and your access needs re-issuing"); } - return "Synchronised, but: " + string.Join("; ", notes) + "."; + return replayed + "Synchronised, but: " + string.Join("; ", notes) + "."; } private async Task RunAsync(string busyMessage, Func work) diff --git a/src/DodoSSH.Client.Sync/SyncEngine.cs b/src/DodoSSH.Client.Sync/SyncEngine.cs index 6160169..b29c1aa 100644 --- a/src/DodoSSH.Client.Sync/SyncEngine.cs +++ b/src/DodoSSH.Client.Sync/SyncEngine.cs @@ -129,12 +129,30 @@ public sealed class SyncEngine { var state = await syncState.ReadAsync(vaultId, cancellationToken).ConfigureAwait(false); + // At most one restart per pull. A server that rejects the cursor it has just issued is not + // telling this client anything it can act on, and replaying the whole log against it would turn + // one broken deployment into an unbounded amount of work. + var alreadyStartedOver = false; + for (var page = 0; page < options.MaxPullPages; page++) { - var response = await api.SyncPullAsync( - vaultId, - new SyncPullRequest(state.Cursor, options.PullPageSize, ItemKinds.SyncedTypes), - cancellationToken).ConfigureAwait(false); + SyncPullResponse response; + + try + { + response = await api.SyncPullAsync( + vaultId, + new SyncPullRequest(state.Cursor, options.PullPageSize, ItemKinds.SyncedTypes), + cancellationToken).ConfigureAwait(false); + } + catch (DodoSshApiException exception) + when (!alreadyStartedOver && WasTheCursorRefused(exception, state.Cursor)) + { + alreadyStartedOver = true; + state = await StartOverAsync(state, report, cancellationToken).ConfigureAwait(false); + + continue; + } foreach (var change in response.Changes) { @@ -161,6 +179,69 @@ public sealed class SyncEngine } } + /// + /// Whether the server refused the cursor this client sent, rather than failing for some other reason. + /// + /// + /// Read from the problem code and not from the prose, which is free to change, and never claimed for a + /// request that carried no cursor: "from the beginning" is the one position a client is allowed to ask + /// for, so a rejection of that is a server this code cannot reason about and has to surface. + /// It is also what keeps the retry from looping — the restarted request sends no cursor. + /// + private static bool WasTheCursorRefused(DodoSshApiException exception, string? cursor) => + !string.IsNullOrEmpty(cursor) + && string.Equals(exception.Code, ProblemCodes.InvalidCursor, StringComparison.Ordinal); + + /// + /// Forgets this vault's position and reads the log again from the beginning. + /// + /// + /// + /// A cursor the server will not accept is not a transient failure. Every later pass reads the same + /// stored cursor and is refused the same way, so a vault that met one stayed there for good — pulling + /// nothing, and pushing nothing either, because the pass threw before it reached the outbox. The user + /// saw a 400 saying to resync from the beginning and had no way to do it. This is that way. + /// + /// + /// The causes are all on the far side: a rotated cursor signing key, a vault served from a restored + /// database whose sequences no longer reach that far, a cache copied between machines. None of them is + /// something the person at the keyboard did, and none of them is something they could act on if asked. + /// + /// + /// The mirror is deliberately kept. Replaying from the beginning rewrites every row the server + /// still has — applying a change is a blind overwrite — so the re-pull repairs the mirror as it goes. + /// Clearing it first would claim more than the evidence supports: the position was refused, not the + /// contents, and a machine that loses its connection halfway through the replay would be left with + /// less than it started with. SyncStateStore.ResetAsync is the heavier remedy, for when the + /// cache itself is the thing in doubt. + /// + /// + /// That leaves one gap, and it is worth naming rather than leaving to be discovered: once the server + /// starts collecting tombstones — DodoOptions.TombstoneRetentionDays, not implemented yet — a + /// replay no longer carries a deletion older than the retention window. A machine that missed such a + /// delete and then had its cursor refused would keep the row. Nothing here can tell that from a row + /// the server still has, so the answer when it matters will be to clear the mirror as well, not to + /// guess. + /// + /// + /// Written down before the replay begins, so a process that dies mid-replay starts the next one from + /// the beginning as well, rather than meeting the same refusal again. + /// + /// + private async Task StartOverAsync( + StoredSyncState state, + SyncReportBuilder report, + CancellationToken cancellationToken) + { + var restarted = state with { Cursor = null }; + + await syncState.SaveAsync(restarted, cancellationToken).ConfigureAwait(false); + + report.ResyncedFromStart = true; + + return restarted; + } + private StoredSyncState Record( Guid vaultId, StoredSyncState state, diff --git a/src/DodoSSH.Client.Sync/SyncReport.cs b/src/DodoSSH.Client.Sync/SyncReport.cs index 8380b08..8c5bf9b 100644 --- a/src/DodoSSH.Client.Sync/SyncReport.cs +++ b/src/DodoSSH.Client.Sync/SyncReport.cs @@ -75,6 +75,15 @@ public sealed record SyncOptions /// True when the push loop hit with work still outstanding. Not /// a failure: the next pass continues from here. /// +/// +/// True when the server refused this machine's stored position and the whole log was read again from the +/// beginning. +/// +/// Deliberately absent from . Nothing is outstanding and nothing was lost — +/// the pass recovered on its own — but it explains a sync that pulled the entire vault on a day nobody +/// changed anything, which is otherwise the sort of thing that looks like a fault. +/// +/// public sealed record SyncReport( Guid VaultId, int Pulled, @@ -87,7 +96,8 @@ public sealed record SyncReport( uint ServerKeyGeneration, bool RekeyRequired, long ServerTimeSkewMs, - bool RoundsExhausted) + bool RoundsExhausted, + bool ResyncedFromStart) { /// Whether anything happened that a user should be told about. public bool NeedsAttention => @@ -119,6 +129,8 @@ internal sealed class SyncReportBuilder(Guid vaultId) internal bool RoundsExhausted { get; set; } + internal bool ResyncedFromStart { get; set; } + internal SyncReport Build() => new( vaultId, @@ -132,7 +144,8 @@ internal sealed class SyncReportBuilder(Guid vaultId) ServerKeyGeneration, RekeyRequired, ServerTimeSkewMs, - RoundsExhausted); + RoundsExhausted, + ResyncedFromStart); } /// The record written to the conflict log when a merge had to override something. diff --git a/tests/DodoSSH.Client.Sync.Tests/FakeVaultServer.cs b/tests/DodoSSH.Client.Sync.Tests/FakeVaultServer.cs index a950a61..d11897d 100644 --- a/tests/DodoSSH.Client.Sync.Tests/FakeVaultServer.cs +++ b/tests/DodoSSH.Client.Sync.Tests/FakeVaultServer.cs @@ -1,4 +1,5 @@ using System.Globalization; +using System.Net; using DodoSSH.Client.Api; using DodoSSH.Contracts; @@ -61,6 +62,26 @@ internal sealed class FakeVaultServer : ISyncApi /// Forces the next push to answer . internal bool DenyWrites { get; set; } + /// + /// Refuses every cursor a client sends, as a server does whose signing key has been rotated. + /// + /// + /// A cursor this fake issued itself is refused just as readily, which is the whole point: the position + /// is not wrong, the deployment's ability to verify it is gone. A pull carrying no cursor is still + /// served, because "from the beginning" is what the real server tells a client to fall back to and is + /// the only position it cannot reject. + /// + internal bool RefuseCursors { get; set; } + + /// + /// Refuses a pull that carries no cursor as well, which no real server does. + /// + /// + /// Here so a test can prove the client gives up on such a server rather than replaying the log against + /// it. Starting over is the only position a client may ask for, so being refused it has no next step. + /// + internal bool RefuseEvenTheBeginning { get; set; } + /// Pushes received, so a test can prove a retry did or did not happen. internal int PushCount { get; private set; } @@ -463,8 +484,19 @@ internal sealed class FakeVaultServer : ISyncApi private static string EncodeCursor(long sequence) => "fake-v1:" + sequence.ToString(CultureInfo.InvariantCulture); - private static long DecodeCursor(string? cursor) + private long DecodeCursor(string? cursor) { + if (RefuseCursors && (RefuseEvenTheBeginning || !string.IsNullOrEmpty(cursor))) + { + // What the real endpoint answers: 400, the invalid-cursor code, and the sentence telling the + // client to start over. See DodoSSH.Api.Features.Sync.SyncEndpoints. + throw new DodoSshApiException( + HttpStatusCode.BadRequest, + ProblemCodes.InvalidCursor, + "The server returned 400: The sync cursor is not valid for this vault. " + + "Resync from the beginning."); + } + if (string.IsNullOrEmpty(cursor)) { return 0; diff --git a/tests/DodoSSH.Client.Sync.Tests/SyncEngineTests.cs b/tests/DodoSSH.Client.Sync.Tests/SyncEngineTests.cs index d61d64e..52bba4a 100644 --- a/tests/DodoSSH.Client.Sync.Tests/SyncEngineTests.cs +++ b/tests/DodoSSH.Client.Sync.Tests/SyncEngineTests.cs @@ -1,3 +1,5 @@ +using DodoSSH.Client.Api; +using DodoSSH.Contracts; using static DodoSSH.Client.Sync.Tests.SyncHarness; namespace DodoSSH.Client.Sync.Tests; @@ -118,6 +120,70 @@ public sealed class SyncEngineTests after.Cursor.ShouldBe(before.Cursor); } + [Fact] + public async Task ARefusedCursor_ReadsTheVaultAgainFromTheBeginning() + { + // The server's cursor signing key was rotated, or the vault is being served from a restored + // database. The stored position is refused for good, so a pass that only reported the 400 would + // leave this machine frozen at it — asking once a minute, for ever, and being told the same thing. + using var harness = await CreateAsync(); + + await harness.First.SyncAsync(); + + var entityId = await harness.Second.CreateAsync(Host("prod-db")); + await harness.Second.SyncAsync(); + + harness.Server.RefuseCursors = true; + + var report = await harness.First.SyncAsync(); + + report.ResyncedFromStart.ShouldBeTrue(); + report.Pulled.ShouldBe(1); + + // And the point of all of it: the change that was on the far side of the refused position is here. + (await harness.First.FindAsync(entityId)).Secret.Label.ShouldBe("prod-db"); + } + + [Fact] + public async Task ARefusedCursor_DoesNotStrandWhatIsWaitingToBePushed() + { + // The half that made this worth recovering from rather than merely reporting. The pull runs first, + // so a pass that gave up on the refusal never reached the outbox at all: every edit made on this + // machine stayed queued behind a position the server was never going to accept again. + using var harness = await CreateAsync(); + + await harness.First.SyncAsync(); + + var entityId = await harness.First.CreateAsync(Host("prod-db")); + + harness.Server.RefuseCursors = true; + + var report = await harness.First.SyncAsync(); + + report.ResyncedFromStart.ShouldBeTrue(); + report.Pushed.ShouldBe(1); + harness.Server.Find(entityId).ShouldNotBeNull(); + } + + [Fact] + public async Task ARefusalOfTheBeginningItself_IsReportedRatherThanRetried() + { + // "From the beginning" is the one position a client is allowed to ask for, so a server that + // refuses it is one this code cannot reason about. Saying so beats replaying the log against it + // until a page bound runs out. + using var harness = await CreateAsync(); + + await harness.First.SyncAsync(); + + harness.Server.RefuseCursors = true; + harness.Server.RefuseEvenTheBeginning = true; + + var failure = await Should.ThrowAsync( + async () => await harness.First.SyncAsync()); + + failure.Code.ShouldBe(ProblemCodes.InvalidCursor); + } + [Fact] public async Task ClockSkew_IsRecordedAndNotActedOn() {