diff --git a/LehrerApp.Desktop/AppBootstrapper.cs b/LehrerApp.Desktop/AppBootstrapper.cs index 9ef4713..13aa735 100644 --- a/LehrerApp.Desktop/AppBootstrapper.cs +++ b/LehrerApp.Desktop/AppBootstrapper.cs @@ -200,7 +200,7 @@ public static class AppBootstrapper { services.AddSingleton(sp => new EventApplier( sp.GetRequiredService(), sp.GetRequiredService(), - BuildHttp(serverUrl, syncSettings))); + BuildHttp(serverUrl, syncSettings), sp.GetRequiredService())); services.AddSingleton(sp => new SyncEventPublisher( sp.GetRequiredService(), deviceId, sp.GetRequiredService())); services.AddSingleton(sp => new AttachmentSyncer( @@ -219,7 +219,8 @@ public static class AppBootstrapper DeviceId = deviceId, DeviceType = DeviceType.Desktop, AutoSyncIntervalMinutes = 5, - })); + }, + sp.GetRequiredService())); services.AddSingleton(sp => new SnapshotService( BuildHttp(serverUrl, syncSettings), diff --git a/LehrerApp.Sync.Tests/SyncEngineTests.cs b/LehrerApp.Sync.Tests/SyncEngineTests.cs new file mode 100644 index 0000000..09d6c24 --- /dev/null +++ b/LehrerApp.Sync.Tests/SyncEngineTests.cs @@ -0,0 +1,88 @@ +using System.Net; +using System.Net.Http.Json; +using LehrerApp.Core.Models; +using LehrerApp.Data; +using LehrerApp.Sync.Crypto; +using LehrerApp.Sync.Models; +using Xunit; + +namespace LehrerApp.Sync.Tests; + +public sealed class SyncEngineTests +{ + private static LiteDbContext NewInMemoryContext() => new(new MemoryStream()); + private static readonly byte[] Key = SyncCrypto.GenerateKey(); + + /// Regression: EventApplier.ApplyAsync fing früher nur LiteException ab. Jede andere Ausnahme + /// (z.B. eine ungültige/korrupte Payload eines einzelnen Ereignisses) fiel unbehandelt aus + /// SyncEngine.PullAsync heraus, BEVOR _queue.SetLastServerSeq() erreicht wurde — der nächste + /// Sync-Versuch lud denselben Batch erneut und scheiterte am selben Ereignis erneut: ein + /// dauerhaft blockierter Sync, bei dem selbst bereits im selben Batch erfolgreich angewendete + /// Ereignisse (wie hier "goodStudent") nie durchkamen. + [Fact] + public async Task SyncNowAsync_KorruptesEreignisImPullBatch_BlockiertNachfolgendeEreignisseNicht() + { + using var temp = new TempEventQueue(); + using var db = NewInMemoryContext(); + var applier = new EventApplier(db, Key); + var resolver = new ConflictResolver(temp.Queue); + var attachments = new AttachmentSyncer(db, new HttpClient(), Key); + + var goodStudent = new Student { FirstName = "Anna", LastName = "Beispiel" }; + var badEvent = new SyncEvent + { + DeviceId = "other-device", DeviceType = DeviceType.Desktop, + EntityType = nameof(Student), EntityId = Guid.NewGuid().ToString(), + Operation = "Save", Payload = "offensichtlich-keine-gueltige-verschluesselte-payload", + SequenceNr = 1, + }; + var goodEvent = new SyncEvent + { + DeviceId = "other-device", DeviceType = DeviceType.Desktop, + EntityType = nameof(Student), EntityId = goodStudent.Id.ToString(), + Operation = "Save", Payload = SyncCrypto.EncryptObject(goodStudent, Key), + SequenceNr = 2, + }; + + var handler = new FakeHttpMessageHandler(req => + { + if (req.RequestUri!.AbsolutePath == "/api/sync/pull") + return new HttpResponseMessage(HttpStatusCode.OK) + { + Content = JsonContent.Create(new PullResponse + { Events = [badEvent, goodEvent], ServerSequenceNr = 2 }), + }; + return new HttpResponseMessage(HttpStatusCode.OK); + }); + var http = new HttpClient(handler) { BaseAddress = new Uri("https://example.invalid") }; + var engine = new SyncEngine(temp.Queue, resolver, applier, attachments, http, + new SyncConfig { DeviceId = "this-device" }); + + var result = await engine.SyncNowAsync(); + + Assert.True(result.Success); + Assert.NotNull(db.Students.FindById(goodStudent.Id)); + // Nicht bei 0 stecken geblieben - der Batch gilt als vollständig verarbeitet, auch wenn ein + // einzelnes Ereignis darin übersprungen werden musste. + Assert.Equal(2, temp.Queue.GetLastServerSeq()); + } + + private sealed class TempEventQueue : IDisposable + { + private readonly string _directory = Path.Combine( + Path.GetTempPath(), $"lehrerapp-sync-tests-engine-{Guid.NewGuid():N}"); + public EventQueue Queue { get; } + + public TempEventQueue() + { + Directory.CreateDirectory(_directory); + Queue = new EventQueue(Path.Combine(_directory, "queue.db")); + } + + public void Dispose() + { + Queue.Dispose(); + if (Directory.Exists(_directory)) Directory.Delete(_directory, recursive: true); + } + } +} diff --git a/LehrerApp.Sync/EventApplier.cs b/LehrerApp.Sync/EventApplier.cs index facc140..e0d5585 100644 --- a/LehrerApp.Sync/EventApplier.cs +++ b/LehrerApp.Sync/EventApplier.cs @@ -1,6 +1,7 @@ using System.Text; using JsonSerializer = System.Text.Json.JsonSerializer; using LehrerApp.Core.Models; +using LehrerApp.Core.Services; using LehrerApp.Data; using LehrerApp.Sync.Crypto; using LehrerApp.Sync.Models; @@ -23,13 +24,18 @@ namespace LehrerApp.Sync; /// Pfad bewusst NICHT geprüft (v1-Einschränkung, siehe TODO.md 10.3) — nur harte LiteDB-Unique- /// Constraints greifen noch und führen zum Überspringen des einzelnen Ereignisses. /// -public class EventApplier(LiteDbContext db, byte[] syncKey, HttpClient? http = null) +public class EventApplier(LiteDbContext db, byte[] syncKey, HttpClient? http = null, AppLogger? logger = null) { private static readonly Dictionary Handlers = BuildHandlers(); public async Task ApplyAsync(SyncEvent evt) { - if (!Handlers.TryGetValue(evt.EntityType, out var handler)) return; + if (!Handlers.TryGetValue(evt.EntityType, out var handler)) + { + logger?.Warn($"Sync: kein Handler für Entitätstyp '{evt.EntityType}' (EntityId={evt.EntityId}, " + + $"Operation={evt.Operation}) - Ereignis übersprungen."); + return; + } try { var json = evt.Payload.Length == 0 ? "" : Decrypt(evt.Payload); @@ -37,10 +43,25 @@ public class EventApplier(LiteDbContext db, byte[] syncKey, HttpClient? http = n if (evt.EntityType == nameof(Documentation) && evt.Operation != "Delete" && http is not null) await DownloadMissingAttachmentsAsync(json); } - catch (LiteException) + catch (LiteException ex) { // Harte Constraint-Verletzung (z.B. Unique-Index) - dieses eine Ereignis // überspringen, statt den gesamten Sync-Lauf abzubrechen. + logger?.Error($"Sync: Ereignis übersprungen (LiteDB-Constraint) - {evt.EntityType} " + + $"{evt.Operation} EntityId={evt.EntityId}", ex); + } + catch (Exception ex) + { + // Jede andere Ausnahme (z.B. Entschlüsselung/Deserialisierung fehlgeschlagen) darf + // NICHT aus ApplyAsync herausfallen: SyncEngine.PullAsync ruft dies in einer Schleife + // über einen ganzen Ereignis-Batch auf, ohne eigenes try/catch - eine unbehandelte + // Ausnahme hier würde den kompletten Pull-Lauf abbrechen, BEVOR SetLastServerSeq + // aufgerufen wird. Der Pull würde beim nächsten Versuch denselben Batch erneut laden + // und an genau demselben Ereignis wieder scheitern - ein dauerhaft blockierter Sync, + // bei dem selbst bereits erfolgreich angewendete Ereignisse im selben Batch nie als + // erledigt markiert werden. + logger?.Error($"Sync: Ereignis konnte nicht angewendet werden - {evt.EntityType} " + + $"{evt.Operation} EntityId={evt.EntityId}", ex); } } diff --git a/LehrerApp.Sync/SyncEngine.cs b/LehrerApp.Sync/SyncEngine.cs index 6dc969e..5af3219 100644 --- a/LehrerApp.Sync/SyncEngine.cs +++ b/LehrerApp.Sync/SyncEngine.cs @@ -1,4 +1,5 @@ using System.Net.Http.Json; +using LehrerApp.Core.Services; using LehrerApp.Sync.Models; namespace LehrerApp.Sync; @@ -15,13 +16,14 @@ public class SyncEngine : IDisposable private readonly AttachmentSyncer _attachments; private readonly HttpClient _http; private readonly SyncConfig _config; + private readonly AppLogger? _logger; private readonly Timer _timer; public SyncStatus Status { get; private set; } = new(); public event Action? StatusChanged; public SyncEngine(EventQueue queue, ConflictResolver resolver, EventApplier applier, - AttachmentSyncer attachments, HttpClient http, SyncConfig config) + AttachmentSyncer attachments, HttpClient http, SyncConfig config, AppLogger? logger = null) { _queue = queue; _resolver = resolver; @@ -29,6 +31,7 @@ public class SyncEngine : IDisposable _attachments = attachments; _http = http; _config = config; + _logger = logger; _timer = new Timer( async _ => await SyncNowAsync(true), null, TimeSpan.FromMinutes(config.AutoSyncIntervalMinutes), @@ -50,8 +53,21 @@ public class SyncEngine : IDisposable SetState(SyncState.Idle); return new() { Success = true, EventsPushed = pushed, EventsPulled = pulled, Conflicts = conflicts }; } - catch (HttpRequestException) { SetState(SyncState.Offline); return new() { Reason = "Server nicht erreichbar" }; } - catch (Exception ex) { SetState(SyncState.Error, ex.Message); return new() { Reason = ex.Message }; } + catch (HttpRequestException ex) + { + // Sammelt sowohl echte Netzwerkfehler als auch nicht-erfolgreiche HTTP-Antworten + // (EnsureSuccessStatusCode() in Push/PullAsync) unter demselben "Offline"-Status - + // ohne Log wäre ein z.B. 401/500 vom Server nicht von "kein Internet" unterscheidbar. + _logger?.Error("Sync fehlgeschlagen (HTTP)", ex); + SetState(SyncState.Offline); + return new() { Reason = "Server nicht erreichbar" }; + } + catch (Exception ex) + { + _logger?.Error("Sync fehlgeschlagen", ex); + SetState(SyncState.Error, ex.Message); + return new() { Reason = ex.Message }; + } } private async Task<(int Pushed, int Conflicts)> PushAsync() diff --git a/TODO.md b/TODO.md index 33bda7e..8b6e90e 100644 --- a/TODO.md +++ b/TODO.md @@ -1514,6 +1514,36 @@ die Docker-Verifikation unter 10.2.4 (kein Docker im Entwicklungsstand verfügba Namens-Eindeutigkeit bei Aspekten u.ä.) werden auf diesem Pfad nicht geprüft — nur harte LiteDB-Unique-Constraints greifen noch und führen zum Überspringen des einzelnen Ereignisses. Für Einzel-/Wenig-Geräte-Nutzung akzeptiert, siehe 10.3.4. + + **Nachtrag (Bugfix — blockierter Sync bei jedem Fehler, unsichtbar und ungeloggt):** + Nutzer-Bug-Report — nach erfolgreicher Gerätekopplung kam eine neu angelegte `Lesson` auf dem + zweiten Gerät trotz mehrfacher manueller Synchronisation nicht an. Ursache im Code gefunden + (nicht live reproduziert, da keine zwei physischen Testgeräte zur Verfügung stehen): + `EventApplier.ApplyAsync` fing bisher nur `LiteException` ab — jede andere Ausnahme (z.B. + eine fehlerhafte Entschlüsselung/Deserialisierung eines einzelnen Ereignisses) fiel + unbehandelt aus der `foreach`-Schleife in `SyncEngine.PullAsync` heraus, **bevor** + `_queue.SetLastServerSeq()` erreicht wurde. Der nächste Sync-Versuch lud dadurch denselben + Ereignis-Batch erneut und scheiterte am selben Ereignis erneut — ein dauerhaft blockierter + Pull, bei dem selbst bereits im selben Batch erfolgreich angewendete Ereignisse nie als + erledigt markiert wurden. Verschärft durch fehlende Sichtbarkeit: weder `SyncEngine` noch + `EventApplier` protokollierten Ausnahmen — ein Fehlschlag zeigte sich höchstens als knapper + "Fehler: …"-Text in der kleinen Sync-Statusleiste, ohne Log-Eintrag (derselbe blinde Fleck wie + beim Pairing-Bugfix in 10.3.1). + + **Umsetzung:** `EventApplier.ApplyAsync` fängt jetzt jede Ausnahme pro Ereignis ab (protokolliert + über neu injizierten `AppLogger`, übersprüngen statt den ganzen Batch abzubrechen) — ein + einzelnes fehlerhaftes Ereignis kann den Sync nicht mehr dauerhaft blockieren. `SyncEngine` + loggt seinerseits jeden Sync-Fehlschlag (HTTP wie generisch) vollständig statt nur die + knappe `ex.Message` im Status anzuzeigen. Neuer Regressionstest + (`SyncEngineTests.SyncNowAsync_KorruptesEreignisImPullBatch_BlockiertNachfolgendeEreignisseNicht`) + belegt mit einem absichtlich korrupten Ereignis vor einem gültigen im selben Pull-Batch, dass + Zweiteres trotzdem ankommt und `GetLastServerSeq()` fortschreitet statt stecken zu bleiben. + **Wichtig:** betrifft nur `LehrerApp.Sync`/`LehrerApp.Desktop` — der Server (`LehrerApp.Api`) + ist unverändert, ein Redeploy der API ist für diesen Fix nicht nötig, wohl aber ein + Neu-Build/Neustart der Desktop-Clients. Ob dies tatsächlich die vom Nutzer beobachtete Ursache + war, ist damit noch nicht bestätigt — nach dem Update sollte ein erneuter Testlauf entweder + funktionieren oder jetzt einen konkreten, geloggten Fehler liefern statt eines stillen + Fehlschlags. - [x] **10.1.8** Datei-Anhänge (Dokumentation) über den laufenden Sync mitschicken. **Umsetzung:** Eigener, unverschlüsselt im JSON-Ereigniskanal nicht mitgeführter Binärkanal