feat: Erfolgs-Protokollierung für die gesamte Sync-Kette

SyncEventPublisher/SyncEngine/EventApplier protokollierten bisher
ausschließlich Fehlschläge - ein sauberes Log bewies nur "nichts ist
abgestürzt", nicht ob eine Änderung tatsächlich hoch-/heruntergeladen
wurde. Jetzt wird auch der Erfolgspfad geloggt: Einreihen in die Outbox
(mit SequenceNr), Push/Pull mit Anzahl und Entitätstypen sowie der vom
Server bestätigten ServerSequenceNr, und jedes tatsächlich angewendete
Ereignis. Damit lässt sich anhand der Log-Dateien beider Geräte
nachvollziehen, an welcher Stelle der Kette eine Änderung verloren geht.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
2026-08-18 22:20:33 +02:00
co-authored by Claude Sonnet 5
parent dea7da8cca
commit 270c4d40cd
5 changed files with 44 additions and 6 deletions
+2 -1
View File
@@ -202,7 +202,8 @@ public static class AppBootstrapper
sp.GetRequiredService<LiteDbContext>(), sp.GetRequiredService<byte[]>(), sp.GetRequiredService<LiteDbContext>(), sp.GetRequiredService<byte[]>(),
BuildHttp(serverUrl, syncSettings), sp.GetRequiredService<AppLogger>())); BuildHttp(serverUrl, syncSettings), sp.GetRequiredService<AppLogger>()));
services.AddSingleton(sp => new SyncEventPublisher( services.AddSingleton(sp => new SyncEventPublisher(
sp.GetRequiredService<EventQueue>(), deviceId, sp.GetRequiredService<byte[]>())); sp.GetRequiredService<EventQueue>(), deviceId, sp.GetRequiredService<byte[]>(),
sp.GetRequiredService<AppLogger>()));
services.AddSingleton(sp => new AttachmentSyncer( services.AddSingleton(sp => new AttachmentSyncer(
sp.GetRequiredService<LiteDbContext>(), BuildHttp(serverUrl, syncSettings), sp.GetRequiredService<LiteDbContext>(), BuildHttp(serverUrl, syncSettings),
sp.GetRequiredService<byte[]>())); sp.GetRequiredService<byte[]>()));
+1
View File
@@ -42,6 +42,7 @@ public class EventApplier(LiteDbContext db, byte[] syncKey, HttpClient? http = n
handler(db, evt.Operation, evt.EntityId, json); handler(db, evt.Operation, evt.EntityId, json);
if (evt.EntityType == nameof(Documentation) && evt.Operation != "Delete" && http is not null) if (evt.EntityType == nameof(Documentation) && evt.Operation != "Delete" && http is not null)
await DownloadMissingAttachmentsAsync(json); await DownloadMissingAttachmentsAsync(json);
logger?.Info($"Sync: Ereignis angewendet - {evt.EntityType} {evt.Operation} EntityId={evt.EntityId}");
} }
catch (LiteException ex) catch (LiteException ex)
{ {
+20 -3
View File
@@ -44,13 +44,17 @@ public class SyncEngine : IDisposable
if (Status.State == SyncState.Syncing) if (Status.State == SyncState.Syncing)
return new() { Skipped = true, Reason = "Sync bereits aktiv" }; return new() { Skipped = true, Reason = "Sync bereits aktiv" };
SetState(SyncState.Syncing); SetState(SyncState.Syncing);
_logger?.Info($"Sync: Start ({(isAutomatic ? "automatisch" : "manuell")}), Gerät={_config.DeviceId}, " +
$"{_queue.PendingCount()} lokal ausstehend");
try try
{ {
var (pushed, _) = await PushAsync(); var (pushed, pushConflicts) = await PushAsync();
await _attachments.UploadPendingAsync(_queue); await _attachments.UploadPendingAsync(_queue);
var (pulled, conflicts) = await PullAsync(); var (pulled, conflicts) = await PullAsync();
_queue.SetLastSyncAt(DateTime.UtcNow); _queue.SetLastSyncAt(DateTime.UtcNow);
SetState(SyncState.Idle); SetState(SyncState.Idle);
_logger?.Info($"Sync: Fertig - {pushed} gepusht ({pushConflicts} Push-Konflikte), " +
$"{pulled} gepullt ({conflicts} Pull-Konflikte)");
return new() { Success = true, EventsPushed = pushed, EventsPulled = pulled, Conflicts = conflicts }; return new() { Success = true, EventsPushed = pushed, EventsPulled = pulled, Conflicts = conflicts };
} }
catch (HttpRequestException ex) catch (HttpRequestException ex)
@@ -74,14 +78,18 @@ public class SyncEngine : IDisposable
{ {
var pending = _queue.GetPending(); var pending = _queue.GetPending();
if (pending.Count == 0) return (0, 0); if (pending.Count == 0) return (0, 0);
_logger?.Info($"Sync: Push - {pending.Count} Ereignis(se) ausstehend: " +
string.Join(", ", pending.Select(e => $"{e.EntityType}/{e.Operation}")));
var resp = await _http.PostAsJsonAsync("/api/sync/push", pending); var resp = await _http.PostAsJsonAsync("/api/sync/push", pending);
resp.EnsureSuccessStatusCode(); resp.EnsureSuccessStatusCode();
var result = await resp.Content.ReadFromJsonAsync<PushResponse>(); var result = await resp.Content.ReadFromJsonAsync<PushResponse>();
if (result is null) return (0, 0); if (result is null) { _logger?.Warn("Sync: Push - leere Server-Antwort."); return (0, 0); }
_queue.Acknowledge(pending _queue.Acknowledge(pending
.Where(e => !result.ConflictingEventIds.Contains(e.EventId)) .Where(e => !result.ConflictingEventIds.Contains(e.EventId))
.Select(e => e.EventId)); .Select(e => e.EventId));
_queue.SetLastServerSeq(result.ServerSequenceNr); _queue.SetLastServerSeq(result.ServerSequenceNr);
_logger?.Info($"Sync: Push - vom Server bestätigt bis ServerSequenceNr={result.ServerSequenceNr}, " +
$"{result.ConflictingEventIds.Count} vom Server abgelehnt (Konflikt).");
return (pending.Count - result.ConflictingEventIds.Count, return (pending.Count - result.ConflictingEventIds.Count,
result.ConflictingEventIds.Count); result.ConflictingEventIds.Count);
} }
@@ -89,9 +97,16 @@ public class SyncEngine : IDisposable
private async Task<(int Pulled, int Conflicts)> PullAsync() private async Task<(int Pulled, int Conflicts)> PullAsync()
{ {
var since = _queue.GetLastServerSeq(); var since = _queue.GetLastServerSeq();
_logger?.Info($"Sync: Pull - frage Server nach Ereignissen seit ServerSequenceNr={since}.");
var resp = await _http.GetFromJsonAsync<PullResponse>( var resp = await _http.GetFromJsonAsync<PullResponse>(
$"/api/sync/pull?since={since}&deviceId={_config.DeviceId}"); $"/api/sync/pull?since={since}&deviceId={_config.DeviceId}");
if (resp is null || resp.Events.Count == 0) return (0, 0); if (resp is null || resp.Events.Count == 0)
{
_logger?.Info("Sync: Pull - keine neuen Ereignisse vom Server.");
return (0, 0);
}
_logger?.Info($"Sync: Pull - {resp.Events.Count} Ereignis(se) vom Server erhalten: " +
string.Join(", ", resp.Events.Select(e => $"{e.EntityType}/{e.Operation}")));
var conflicts = 0; var conflicts = 0;
foreach (var evt in resp.Events) foreach (var evt in resp.Events)
{ {
@@ -99,6 +114,8 @@ public class SyncEngine : IDisposable
if (c is null) { await _applier.ApplyAsync(evt); continue; } if (c is null) { await _applier.ApplyAsync(evt); continue; }
_queue.AddConflict(c); _queue.AddConflict(c);
conflicts++; conflicts++;
_logger?.Info($"Sync: Pull - Konflikt bei {evt.EntityType}/{evt.EntityId}, " +
$"Auflösung={c.Resolution}");
if (c.Resolution == "RemoteWon") await _applier.ApplyAsync(evt); if (c.Resolution == "RemoteWon") await _applier.ApplyAsync(evt);
} }
_queue.SetLastServerSeq(resp.ServerSequenceNr); _queue.SetLastServerSeq(resp.ServerSequenceNr);
+8 -2
View File
@@ -1,4 +1,5 @@
using LehrerApp.Core.Models; using LehrerApp.Core.Models;
using LehrerApp.Core.Services;
using LehrerApp.Data; using LehrerApp.Data;
using LehrerApp.Sync.Crypto; using LehrerApp.Sync.Crypto;
using LehrerApp.Sync.Models; using LehrerApp.Sync.Models;
@@ -10,12 +11,17 @@ namespace LehrerApp.Sync;
/// AppBootstrapper an <see cref="LiteDbContext.OnChange"/> gehängt, wenn Sync konfiguriert ist — /// AppBootstrapper an <see cref="LiteDbContext.OnChange"/> gehängt, wenn Sync konfiguriert ist —
/// dort entsteht aus den ~27 Repository-Aufrufen genau ein verschlüsseltes Ereignis pro Aufruf. /// dort entsteht aus den ~27 Repository-Aufrufen genau ein verschlüsseltes Ereignis pro Aufruf.
/// </summary> /// </summary>
public class SyncEventPublisher(EventQueue queue, string deviceId, byte[] syncKey) public class SyncEventPublisher(EventQueue queue, string deviceId, byte[] syncKey, AppLogger? logger = null)
{ {
public void Publish(string entityType, string entityId, string operation, object? payload) public void Publish(string entityType, string entityId, string operation, object? payload)
{ {
var encrypted = payload is null ? "" : SyncCrypto.EncryptObject(payload, syncKey); var encrypted = payload is null ? "" : SyncCrypto.EncryptObject(payload, syncKey);
queue.Enqueue(deviceId, DeviceType.Desktop, entityType, entityId, operation, encrypted); var evt = queue.Enqueue(deviceId, DeviceType.Desktop, entityType, entityId, operation, encrypted);
// Erfolgs-Protokollierung (nicht nur Fehler, siehe SyncEngine/EventApplier) — sonst lässt
// sich ohne zwei parallele Testgeräte nie nachvollziehen, ob eine lokale Änderung
// überhaupt in die Outbox gelangt ist, bevor Push/Pull überhaupt ins Spiel kommen.
logger?.Info($"Sync: Ereignis eingereiht (SequenceNr={evt.SequenceNr}) - {entityType} {operation} " +
$"EntityId={entityId}");
// Anhänge reisen nicht im JSON-Ereignis mit (würde den Kanal für Fotos/Scans aufblähen), // Anhänge reisen nicht im JSON-Ereignis mit (würde den Kanal für Fotos/Scans aufblähen),
// sondern als eigener Binärtransfer über AttachmentSyncer — hier nur zur Warteliste hinzufügen. // sondern als eigener Binärtransfer über AttachmentSyncer — hier nur zur Warteliste hinzufügen.
+13
View File
@@ -1544,6 +1544,19 @@ die Docker-Verifikation unter 10.2.4 (kein Docker im Entwicklungsstand verfügba
war, ist damit noch nicht bestätigt — nach dem Update sollte ein erneuter Testlauf entweder 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 funktionieren oder jetzt einen konkreten, geloggten Fehler liefern statt eines stillen
Fehlschlags. Fehlschlags.
**Nachtrag (Erfolgs-Protokollierung nachgerüstet):** Der Fix oben half nicht — beide Geräte
meldeten einen sauberen Sync ohne Fehler, die neu angelegte Lesson kam trotzdem nicht an.
Grund: bis dahin protokollierten `SyncEventPublisher`/`SyncEngine`/`EventApplier`
ausschließlich Fehlschläge — ein sauberes Log bewies also nur "nichts ist abgestürzt", nicht
"die Änderung wurde tatsächlich hoch-/heruntergeladen". Jetzt protokollieren alle drei auch
den Erfolgspfad: `SyncEventPublisher.Publish` beim Einreihen in die Outbox (mit
`SequenceNr`), `SyncEngine.PushAsync`/`PullAsync` mit Anzahl und Entitätstypen der
gesendeten/empfangenen Ereignisse sowie der vom Server bestätigten `ServerSequenceNr`, und
`EventApplier.ApplyAsync` bei jedem tatsächlich angewendeten Ereignis. Damit lässt sich beim
nächsten Testlauf anhand der Log-Dateien beider Geräte lückenlos nachvollziehen, an welcher
Stelle der Kette (Einreihen → Push → Server → Pull → Anwenden) eine Änderung tatsächlich
verloren geht — bisher war das reine Spekulation ohne Live-Testgeräte.
- [x] **10.1.8** Datei-Anhänge (Dokumentation) über den laufenden Sync mitschicken. - [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 **Umsetzung:** Eigener, unverschlüsselt im JSON-Ereigniskanal nicht mitgeführter Binärkanal