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 <noreply@anthropic.com>
This commit is contained in:
2026-08-19 09:37:34 +02:00
co-authored by Claude Opus 5
parent 89ae7b73a1
commit 477a850a91
2 changed files with 102 additions and 49 deletions
+80 -49
View File
@@ -215,17 +215,11 @@ function shouldEncryptChanges(_resourceType: string): boolean {
/** /**
* Erstellt einen neuen Audit-Log-Eintrag mit Hash-Kette * 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<void> { export async function createAuditLog(data: CreateAuditLogData): Promise<void> {
try { 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 // Sensitivität bestimmen falls nicht angegeben
const sensitivity = data.sensitivity || determineSensitivity(data.resourceType); const sensitivity = data.sensitivity || determineSensitivity(data.resourceType);
@@ -248,47 +242,84 @@ export async function createAuditLog(data: CreateAuditLogData): Promise<void> {
} }
} }
// Hash generieren // Kette atomar fortschreiben: Vorgaenger-Hash lesen UND neuen Eintrag
const hash = generateHash({ // schreiben muessen eine Einheit sein. Vorher lagen beide Schritte offen
userEmail: data.userEmail, // nebeneinander zwei parallele Requests lasen denselben letzten Hash und
action: data.action, // haengten sich beide daran, was die Kette zerriss (echte Bruchstellen im
resourceType: data.resourceType, // Bestand, u. a. 05.05./07.05.2026).
resourceId: data.resourceId, //
endpoint: data.endpoint, // Serialisiert wird ueber einen benannten MySQL-Lock (GET_LOCK), NICHT ueber
createdAt, // `SELECT … FOR UPDATE` am Kettenende: letzteres nimmt Gap-/Next-Key-Locks
previousHash, // 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<Array<Record<string, number | null>>>`
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<Array<{ hash: string }>>`
SELECT hash FROM AuditLog ORDER BY id DESC LIMIT 1
`;
const previousHash = lastRows[0]?.hash || null;
const createdAt = new Date();
// Eintrag erstellen const hash = generateHash({
await prisma.auditLog.create({ userEmail: data.userEmail,
data: { action: data.action,
userId: data.userId, resourceType: data.resourceType,
userEmail: data.userEmail, resourceId: data.resourceId,
userRole: data.userRole, endpoint: data.endpoint,
customerId: data.customerId, createdAt,
isCustomerPortal: data.isCustomerPortal || false, previousHash,
action: data.action, });
sensitivity,
resourceType: data.resourceType, await tx.auditLog.create({
resourceId: data.resourceId, data: {
resourceLabel: data.resourceLabel, userId: data.userId,
endpoint: data.endpoint, userEmail: data.userEmail,
httpMethod: data.httpMethod, userRole: data.userRole,
ipAddress: data.ipAddress, customerId: data.customerId,
userAgent: data.userAgent, isCustomerPortal: data.isCustomerPortal || false,
changesBefore, action: data.action,
changesAfter, sensitivity,
changesEncrypted, resourceType: data.resourceType,
dataSubjectId: data.dataSubjectId, resourceId: data.resourceId,
legalBasis: data.legalBasis, resourceLabel: data.resourceLabel,
success: data.success ?? true, endpoint: data.endpoint,
errorMessage: data.errorMessage, httpMethod: data.httpMethod,
durationMs: data.durationMs, ipAddress: data.ipAddress,
createdAt, userAgent: data.userAgent,
hash, changesBefore,
previousHash, 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) { } catch (error) {
// Audit-Logging darf niemals die Hauptoperation blockieren // Audit-Logging darf niemals die Hauptoperation blockieren
console.error('[AuditService] Fehler beim Erstellen des Audit-Logs:', error); console.error('[AuditService] Fehler beim Erstellen des Audit-Logs:', error);
+22
View File
@@ -97,6 +97,28 @@ isolierte Instanz (keine Multi-Tenancy im Code), Provisioning + Abrechnung
## ✅ Erledigt ## ✅ 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) - [x] **🛡️ Audit-Integritaet: Dauer-Fehlalarm ueber 67 % des Logs behoben** (2026-08-18)
- Beim Nachpruefen aufgefallen: `verifyIntegrity` meldete **3107 von 4630** - Beim Nachpruefen aufgefallen: `verifyIntegrity` meldete **3107 von 4630**
Zeilen als „manipuliert“. Davon waren **3100 Fehlalarme** eingegrenzt auf Zeilen als „manipuliert“. Davon waren **3100 Fehlalarme** eingegrenzt auf