From 477a850a91fd476703442908dd1a8bd452a9c441 Mon Sep 17 00:00:00 2001 From: duffyduck Date: Wed, 19 Aug 2026 09:37:34 +0200 Subject: [PATCH] Audit-Kette: Race beim Fortschreiben behoben (parallele Requests) createAuditLog las den Vorgaenger-Hash und schrieb den neuen Eintrag als zwei getrennte Schritte. Zwei parallele Requests lasen denselben letzten Hash und haengten sich beide daran - die Kette zerriss (Bruchstellen im Bestand vom 05.05. und 07.05.2026). Fix: Lesen + Schreiben in einer Transaktion, serialisiert ueber einen benannten MySQL-Lock (GET_LOCK). Der Lock liegt in der DB und wirkt daher auch ueber mehrere App-Instanzen hinweg. Release im finally, weil benannte Locks nicht transaktional sind - sonst wandert die Sperre mit der Verbindung zurueck in den Pool und blockiert alle weiteren Schreiber. Verworfener erster Ansatz: SELECT ... FOR UPDATE auf das Kettenende nimmt Gap-/ Next-Key-Locks, die mit den gleichzeitigen INSERTs kollidieren - gemessen gingen 38 von 40 parallelen Eintraegen durch Deadlocks verloren, still verschluckt vom catch. Ein fehlender Audit-Eintrag ist unsichtbar und damit gefaehrlicher als ein sichtbarer Kettenbruch. Verifiziert: 100 parallele Schreiber -> 100/100 geschrieben, 0 neue Brueche (444 ms); Folge-Schreiber in 6 ms, IS_FREE_LOCK frei (kein Lock-Leak). Ungueltige Zeilen bleiben bei den 7 historischen. tsc gruen. Co-Authored-By: Claude Opus 5 --- backend/src/services/audit.service.ts | 129 ++++++++++++++++---------- docs/todo.md | 22 +++++ 2 files changed, 102 insertions(+), 49 deletions(-) diff --git a/backend/src/services/audit.service.ts b/backend/src/services/audit.service.ts index b893f083..f116099c 100644 --- a/backend/src/services/audit.service.ts +++ b/backend/src/services/audit.service.ts @@ -215,17 +215,11 @@ function shouldEncryptChanges(_resourceType: string): boolean { /** * Erstellt einen neuen Audit-Log-Eintrag mit Hash-Kette */ +// Name des DB-weiten Locks, ueber den die Hash-Kette serialisiert wird. +const AUDIT_CHAIN_LOCK = 'opencrm_audit_chain'; + export async function createAuditLog(data: CreateAuditLogData): Promise { try { - // Letzten Hash abrufen für die Kette - const lastLog = await prisma.auditLog.findFirst({ - orderBy: { id: 'desc' }, - select: { hash: true }, - }); - - const previousHash = lastLog?.hash || null; - const createdAt = new Date(); - // Sensitivität bestimmen falls nicht angegeben const sensitivity = data.sensitivity || determineSensitivity(data.resourceType); @@ -248,47 +242,84 @@ export async function createAuditLog(data: CreateAuditLogData): Promise { } } - // Hash generieren - const hash = generateHash({ - userEmail: data.userEmail, - action: data.action, - resourceType: data.resourceType, - resourceId: data.resourceId, - endpoint: data.endpoint, - createdAt, - previousHash, - }); + // Kette atomar fortschreiben: Vorgaenger-Hash lesen UND neuen Eintrag + // schreiben muessen eine Einheit sein. Vorher lagen beide Schritte offen + // nebeneinander – zwei parallele Requests lasen denselben letzten Hash und + // haengten sich beide daran, was die Kette zerriss (echte Bruchstellen im + // Bestand, u. a. 05.05./07.05.2026). + // + // Serialisiert wird ueber einen benannten MySQL-Lock (GET_LOCK), NICHT ueber + // `SELECT … FOR UPDATE` am Kettenende: letzteres nimmt Gap-/Next-Key-Locks + // am Index-Ende, die mit den gleichzeitigen INSERTs kollidieren – gemessen + // gingen dabei 38 von 40 parallelen Eintraegen durch Deadlocks verloren. + // Ein FEHLENDER Audit-Eintrag ist unsichtbar und damit schlimmer als ein + // sichtbarer Kettenbruch. Der benannte Lock kennt keine Gap-Locks und + // serialisiert sauber; er liegt in der DB und wirkt daher auch ueber + // mehrere App-Instanzen hinweg. + // Alles Rechenintensive (Serialisieren/Verschluesseln) passiert bewusst + // VOR der Transaktion, damit die Sperre so kurz wie moeglich gehalten wird. + await prisma.$transaction(async (tx) => { + // Interaktive Transaktion => alle Queries auf DERSELBEN Verbindung, + // Voraussetzung dafuer, dass GET_LOCK/RELEASE_LOCK zusammengehoeren. + const got = await tx.$queryRaw>>` + SELECT GET_LOCK(${AUDIT_CHAIN_LOCK}, 10) AS ok + `; + const locked = Number(Object.values(got[0] ?? {})[0] ?? 0) === 1; + try { + const lastRows = await tx.$queryRaw>` + SELECT hash FROM AuditLog ORDER BY id DESC LIMIT 1 + `; + const previousHash = lastRows[0]?.hash || null; + const createdAt = new Date(); - // Eintrag erstellen - await prisma.auditLog.create({ - data: { - userId: data.userId, - userEmail: data.userEmail, - userRole: data.userRole, - customerId: data.customerId, - isCustomerPortal: data.isCustomerPortal || false, - action: data.action, - sensitivity, - resourceType: data.resourceType, - resourceId: data.resourceId, - resourceLabel: data.resourceLabel, - endpoint: data.endpoint, - httpMethod: data.httpMethod, - ipAddress: data.ipAddress, - userAgent: data.userAgent, - changesBefore, - changesAfter, - changesEncrypted, - dataSubjectId: data.dataSubjectId, - legalBasis: data.legalBasis, - success: data.success ?? true, - errorMessage: data.errorMessage, - durationMs: data.durationMs, - createdAt, - hash, - previousHash, - }, - }); + const hash = generateHash({ + userEmail: data.userEmail, + action: data.action, + resourceType: data.resourceType, + resourceId: data.resourceId, + endpoint: data.endpoint, + createdAt, + previousHash, + }); + + await tx.auditLog.create({ + data: { + userId: data.userId, + userEmail: data.userEmail, + userRole: data.userRole, + customerId: data.customerId, + isCustomerPortal: data.isCustomerPortal || false, + action: data.action, + sensitivity, + resourceType: data.resourceType, + resourceId: data.resourceId, + resourceLabel: data.resourceLabel, + endpoint: data.endpoint, + httpMethod: data.httpMethod, + ipAddress: data.ipAddress, + userAgent: data.userAgent, + changesBefore, + changesAfter, + changesEncrypted, + dataSubjectId: data.dataSubjectId, + legalBasis: data.legalBasis, + success: data.success ?? true, + errorMessage: data.errorMessage, + durationMs: data.durationMs, + createdAt, + hash, + previousHash, + }, + }); + } finally { + // Benannte Locks sind NICHT transaktional – ohne explizites Release + // wandert die Sperre mit der Verbindung zurueck in den Pool und + // blockiert alle weiteren Schreiber. + if (locked) { + await tx.$queryRaw`SELECT RELEASE_LOCK(${AUDIT_CHAIN_LOCK}) AS released`; + } + } + }, { timeout: 20000, maxWait: 15000 }); } catch (error) { // Audit-Logging darf niemals die Hauptoperation blockieren console.error('[AuditService] Fehler beim Erstellen des Audit-Logs:', error); diff --git a/docs/todo.md b/docs/todo.md index d0d6c35c..02309a9e 100644 --- a/docs/todo.md +++ b/docs/todo.md @@ -97,6 +97,28 @@ isolierte Instanz (keine Multi-Tenancy im Code), Provisioning + Abrechnung ## ✅ Erledigt +- [x] **🔗 Audit-Kette: Race beim Fortschreiben behoben (parallele Requests)** (2026-08-18) + - `createAuditLog` las den Vorgaenger-Hash und schrieb den neuen Eintrag als + zwei getrennte Schritte. Zwei parallele Requests lasen denselben letzten + Hash und haengten sich beide daran → Kette zerrissen (echte Bruchstellen im + Bestand: 05.05./07.05.2026). + - Fix: Lesen + Schreiben in einer Transaktion, serialisiert ueber einen + benannten MySQL-Lock (`GET_LOCK('opencrm_audit_chain')`). Liegt in der DB, + wirkt daher auch ueber mehrere App-Instanzen hinweg. Release im `finally`, + da benannte Locks nicht transaktional sind (sonst wandert die Sperre mit der + Verbindung zurueck in den Pool und blockiert alle Schreiber). + - **Verworfener erster Ansatz – wichtig:** `SELECT … FOR UPDATE` auf das + Kettenende nimmt Gap-/Next-Key-Locks, die mit den gleichzeitigen INSERTs + kollidieren. Gemessen: **38 von 40** parallelen Eintraegen gingen durch + Deadlocks verloren (vom `catch` still verschluckt). Ein FEHLENDER + Audit-Eintrag ist unsichtbar und damit gefaehrlicher als ein sichtbarer + Kettenbruch – deshalb der Umbau auf den benannten Lock. + - Verifiziert: 100 parallele Schreiber → **100/100 geschrieben, 0 neue + Brueche** (444 ms); Folge-Schreiber danach in 6 ms, `IS_FREE_LOCK` = frei + (kein Lock-Leak). Gesamtzahl ungueltiger Zeilen bleibt bei den 7 + historischen. Rechenintensives (Serialisieren/Verschluesseln) liegt bewusst + VOR der Transaktion, damit die Sperre kurz bleibt. `tsc` gruen. + - [x] **🛡️ Audit-Integritaet: Dauer-Fehlalarm ueber 67 % des Logs behoben** (2026-08-18) - Beim Nachpruefen aufgefallen: `verifyIntegrity` meldete **3107 von 4630** Zeilen als „manipuliert“. Davon waren **3100 Fehlalarme** – eingegrenzt auf