Backup-Operations-Log + EBUSY-Fix beim Restore

Backup-Seite zeigt zwei neue Log-Panels: links Backup-Erstellung,
rechts Backup-Wiederherstellung. Jeder Eintrag mit ✓/✗-Status,
Summary, Timestamp + User. Klick öffnet Modal mit vollständigem
Verlauf – alle console.log/error/warn/info-Zeilen werden während
der Operation in einen Puffer mitgefangen und im fullLog-Feld
persistiert. Auto-Refresh alle 5s.

Persistenz: neue Tabelle BackupLog mit Migration
20260519100000_backup_log (CREATE TABLE IF NOT EXISTS für Re-Deploys
auf DBs mit Vorab-db-push). fullLog auf 1 MB gecappt.

Endpoints (settings:update):
- GET /api/settings/backup-logs?operation=CREATE|RESTORE&limit=50
- GET /api/settings/backup-logs/:id

EBUSY-Fix: Der neue Log-Verlauf hat sofort einen alten Bug
sichtbar gemacht. backup.service.restoreBackup rief
deleteDirectory(UPLOADS_DIR) auf, dessen finales rmdirSync auf
/app/uploads ein EBUSY warf – das Verzeichnis ist im Container ein
Bind-Mount und lässt sich nicht aushängen. Fix: neuer Helper
emptyDirectory() löscht nur die Inhalte, das Verzeichnis bleibt
stehen.

Live-verifiziert: 4867 Datensätze + 1 Datei in 13.2s
wiederhergestellt; Log-Modal zeigt den vollständigen Verlauf.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
2026-05-19 11:53:04 +02:00
parent 95541e8ac4
commit 37df8c0c4a
8 changed files with 506 additions and 15 deletions
@@ -0,0 +1,23 @@
-- BackupLog: persistierte Historie aller Backup-/Restore-Vorgänge mit
-- Status + Volltext-Log. UI zeigt in zwei Listen (je CREATE und RESTORE).
--
-- IF NOT EXISTS damit Re-Deploys auf bestehende DBs nicht crashen, falls
-- jemand vorher manuell `prisma db push` gefahren hat.
CREATE TABLE IF NOT EXISTS `BackupLog` (
`id` INTEGER NOT NULL AUTO_INCREMENT,
`operation` ENUM('CREATE', 'RESTORE') NOT NULL,
`backupName` VARCHAR(191) NULL,
`success` BOOLEAN NOT NULL,
`durationMs` INTEGER NOT NULL DEFAULT 0,
`summary` TEXT NOT NULL,
`fullLog` LONGTEXT NOT NULL,
`userId` INTEGER NULL,
`userEmail` VARCHAR(191) NULL,
`ipAddress` VARCHAR(191) NULL,
`createdAt` DATETIME(3) NOT NULL DEFAULT CURRENT_TIMESTAMP(3),
INDEX `BackupLog_operation_createdAt_idx`(`operation`, `createdAt`),
INDEX `BackupLog_createdAt_idx`(`createdAt`),
PRIMARY KEY (`id`)
) DEFAULT CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci;
+27
View File
@@ -1146,6 +1146,33 @@ enum SecuritySeverity {
CRITICAL // Threshold überschritten (>10 failed login/h, >5 403/min)
}
enum BackupOperation {
CREATE
RESTORE
}
// Persistiertes Log für Backup-Vorgänge.
// `summary` ist die einzeilige Anzeige in der Liste (z.B. "4859 Datensätze
// wiederhergestellt"), `fullLog` der detaillierte Output inkl. Stack-Trace
// für das Modal. Wird beim Build/Restore in `backup.controller.ts`
// geschrieben.
model BackupLog {
id Int @id @default(autoincrement())
operation BackupOperation
backupName String?
success Boolean
durationMs Int @default(0)
summary String @db.Text
fullLog String @db.LongText
userId Int?
userEmail String?
ipAddress String?
createdAt DateTime @default(now())
@@index([operation, createdAt])
@@index([createdAt])
}
model SecurityEvent {
id Int @id @default(autoincrement())
type SecurityEventType
+195 -9
View File
@@ -1,5 +1,6 @@
import { Request, Response } from 'express';
import * as backupService from '../services/backup.service.js';
import prisma from '../lib/prisma.js';
/**
* Validiert Backup-Namen: nur Zeichen die auch der Backup-Generator erstellen darf
@@ -11,6 +12,83 @@ function isValidBackupName(name: string): boolean {
}
import { logChange } from '../services/audit.service.js';
// Fängt console.log/info/warn/error für die Laufzeit einer Operation in
// einen Puffer mit ab (zusätzlich landet alles weiterhin in stdout/stderr).
// Wird in createBackup/restoreBackup verwendet, um den vollständigen
// Verlauf in `BackupLog.fullLog` zu persistieren. Da die Backup-Operationen
// in der Praxis nicht parallel laufen (Single-User-Admin-UI), reicht die
// process-globale Patch-Variante.
function startLogCapture(): { lines: string[]; restore: () => void } {
const lines: string[] = [];
const orig = {
log: console.log,
info: console.info,
warn: console.warn,
error: console.error,
};
function fmt(args: unknown[]): string {
return args
.map((a) => {
if (a instanceof Error) return a.stack || a.message;
if (typeof a === 'object') {
try {
return JSON.stringify(a);
} catch {
return String(a);
}
}
return String(a);
})
.join(' ');
}
console.log = (...args: unknown[]) => { lines.push(fmt(args)); orig.log(...args); };
console.info = (...args: unknown[]) => { lines.push(fmt(args)); orig.info(...args); };
console.warn = (...args: unknown[]) => { lines.push(`[WARN] ${fmt(args)}`); orig.warn(...args); };
console.error = (...args: unknown[]) => { lines.push(`[ERROR] ${fmt(args)}`); orig.error(...args); };
return {
lines,
restore: () => {
console.log = orig.log;
console.info = orig.info;
console.warn = orig.warn;
console.error = orig.error;
},
};
}
async function recordBackupLog(opts: {
req: Request;
operation: 'CREATE' | 'RESTORE';
backupName: string | null;
success: boolean;
durationMs: number;
summary: string;
fullLog: string;
}) {
try {
const user = (opts.req as any).user;
await prisma.backupLog.create({
data: {
operation: opts.operation,
backupName: opts.backupName,
success: opts.success,
durationMs: opts.durationMs,
summary: opts.summary.slice(0, 2000),
// LongText: bis ~4 GB, aber wir cappen bei 1 MB damit nichts entgleist
fullLog: opts.fullLog.slice(0, 1_000_000),
userId: user?.userId ?? null,
userEmail: user?.email ?? null,
ipAddress:
(opts.req as any).socket?.remoteAddress ||
(opts.req.headers?.['x-forwarded-for'] as string) ||
null,
},
});
} catch (err) {
console.error('[BackupLog] Konnte Log nicht persistieren:', err);
}
}
/**
* Liste aller Backups abrufen
* GET /api/settings/backups
@@ -29,19 +107,44 @@ export async function listBackups(req: Request, res: Response) {
* POST /api/settings/backup
*/
export async function createBackup(req: Request, res: Response) {
const start = Date.now();
const capture = startLogCapture();
try {
const result = await backupService.createBackup();
const durationMs = Date.now() - start;
if (result.success) {
capture.restore();
const summary = `Backup ${result.backupName} erstellt (${(durationMs / 1000).toFixed(1)}s)`;
await recordBackupLog({
req, operation: 'CREATE', backupName: result.backupName ?? null,
success: true, durationMs, summary,
fullLog: capture.lines.join('\n') || summary,
});
await logChange({
req, action: 'CREATE', resourceType: 'Backup',
label: `Backup ${result.backupName} erstellt`,
});
res.json({ data: { backupName: result.backupName }, message: 'Backup erfolgreich erstellt' });
} else {
capture.restore();
await recordBackupLog({
req, operation: 'CREATE', backupName: null,
success: false, durationMs,
summary: `Backup fehlgeschlagen: ${result.error || 'unbekannt'}`,
fullLog: capture.lines.join('\n') + '\n[Fehler] ' + (result.error || ''),
});
res.status(500).json({ error: 'Backup fehlgeschlagen', details: result.error });
}
} catch (error: any) {
const durationMs = Date.now() - start;
capture.restore();
await recordBackupLog({
req, operation: 'CREATE', backupName: null,
success: false, durationMs,
summary: `Fehler: ${error?.message || 'unbekannt'}`,
fullLog: capture.lines.join('\n') + '\n[Exception] ' + (error?.stack || error?.message || error),
});
res.status(500).json({ error: 'Fehler beim Erstellen des Backups', details: error.message });
}
}
@@ -74,16 +177,26 @@ function makeRestoreErrorReadable(raw: unknown): string {
}
export async function restoreBackup(req: Request, res: Response) {
const start = Date.now();
const { name } = req.params;
if (!name || !isValidBackupName(name)) {
return res.status(400).json({ error: 'Ungültiger Backup-Name' });
}
const capture = startLogCapture();
try {
const { name } = req.params;
if (!name || !isValidBackupName(name)) {
return res.status(400).json({ error: 'Ungültiger Backup-Name' });
}
const result = await backupService.restoreBackup(name);
const durationMs = Date.now() - start;
if (result.success) {
capture.restore();
const summary = `${result.restoredRecords} Datensätze, ${result.restoredFiles || 0} Dateien (${(durationMs / 1000).toFixed(1)}s)`;
await recordBackupLog({
req, operation: 'RESTORE', backupName: name,
success: true, durationMs, summary,
fullLog: capture.lines.join('\n') || summary,
});
await logChange({
req, action: 'UPDATE', resourceType: 'Backup',
label: `Backup ${name} wiederhergestellt`,
@@ -97,18 +210,33 @@ export async function restoreBackup(req: Request, res: Response) {
});
} else {
console.error(`[restore] Backup ${name} fehlgeschlagen:`, result.error);
capture.restore();
await recordBackupLog({
req, operation: 'RESTORE', backupName: name,
success: false, durationMs,
summary: `Fehlgeschlagen: ${makeRestoreErrorReadable(result.error)}`,
fullLog: capture.lines.join('\n') + '\n[Fehler] ' + (result.error || ''),
});
res.status(500).json({
error: 'Wiederherstellung fehlgeschlagen',
details: makeRestoreErrorReadable(result.error),
hint: 'Vollständiger Stack-Trace im Server-Log: docker logs opencrm-app | tail -200',
hint: 'Vollständiger Verlauf in den Backup-Logs unterhalb der Backup-Liste.',
});
}
} catch (error: any) {
console.error(`[restore] Exception bei Backup ${req.params.name}:`, error?.stack || error);
const durationMs = Date.now() - start;
console.error(`[restore] Exception bei Backup ${name}:`, error?.stack || error);
capture.restore();
await recordBackupLog({
req, operation: 'RESTORE', backupName: name,
success: false, durationMs,
summary: `Exception: ${makeRestoreErrorReadable(error)}`,
fullLog: capture.lines.join('\n') + '\n[Exception] ' + (error?.stack || error?.message || error),
});
res.status(500).json({
error: 'Fehler bei der Wiederherstellung',
details: makeRestoreErrorReadable(error),
hint: 'Vollständiger Stack-Trace im Server-Log: docker logs opencrm-app | tail -200',
hint: 'Vollständiger Verlauf in den Backup-Logs unterhalb der Backup-Liste.',
});
}
}
@@ -243,3 +371,61 @@ export async function factoryReset(req: Request, res: Response) {
console.error('factoryReset error:', error);
}
}
/**
* Liste der Backup-Logs (CREATE oder RESTORE)
* GET /api/settings/backup-logs?operation=CREATE|RESTORE&limit=50
* Liefert die Übersichtsdaten OHNE den großen fullLog.
*/
export async function listBackupLogs(req: Request, res: Response) {
try {
const op = String(req.query.operation || '').toUpperCase();
const limit = Math.min(Math.max(parseInt(String(req.query.limit || '50'), 10) || 50, 1), 200);
const where: any = {};
if (op === 'CREATE' || op === 'RESTORE') {
where.operation = op;
}
const logs = await prisma.backupLog.findMany({
where,
orderBy: { createdAt: 'desc' },
take: limit,
select: {
id: true,
operation: true,
backupName: true,
success: true,
durationMs: true,
summary: true,
userEmail: true,
ipAddress: true,
createdAt: true,
},
});
res.json({ data: logs });
} catch (error: any) {
res.status(500).json({ error: 'Fehler beim Laden der Logs', details: error.message });
}
}
/**
* Detail eines Backup-Logs inkl. fullLog
* GET /api/settings/backup-logs/:id
*/
export async function getBackupLogDetail(req: Request, res: Response) {
try {
const id = parseInt(req.params.id, 10);
if (!Number.isFinite(id) || id < 1) {
return res.status(400).json({ error: 'Ungültige ID' });
}
const log = await prisma.backupLog.findUnique({ where: { id } });
if (!log) {
return res.status(404).json({ error: 'Log-Eintrag nicht gefunden' });
}
res.json({ data: log });
} catch (error: any) {
res.status(500).json({ error: 'Fehler beim Laden des Log-Details', details: error.message });
}
}
+14
View File
@@ -101,6 +101,20 @@ router.post(
backupController.factoryReset
);
// Backup-Operations-Log: Liste (ohne fullLog) + Detail
router.get(
'/backup-logs',
authenticate,
requirePermission('settings:update'),
backupController.listBackupLogs
);
router.get(
'/backup-logs/:id',
authenticate,
requirePermission('settings:update'),
backupController.getBackupLogDetail
);
// Rate-Limit-Verwaltung (Admin)
router.get(
'/rate-limits/active',
+22 -4
View File
@@ -138,6 +138,24 @@ function deleteDirectory(dirPath: string): void {
fs.rmdirSync(dirPath);
}
// Wie deleteDirectory, ABER das Ziel-Verzeichnis selbst bleibt stehen
// nur die Inhalte verschwinden. Notwendig für Docker-Bind-Mounts wie
// `/app/uploads`: dort wirft `rmdir` ein EBUSY, weil das Volume vom Host
// gemountet ist und sich nicht aushängen lässt.
function emptyDirectory(dirPath: string): void {
if (!fs.existsSync(dirPath)) return;
const items = fs.readdirSync(dirPath);
for (const item of items) {
const itemPath = path.join(dirPath, item);
const stats = fs.lstatSync(itemPath);
if (stats.isDirectory()) {
deleteDirectory(itemPath);
} else {
fs.unlinkSync(itemPath);
}
}
}
/**
* Liste aller verfügbaren Backups
*/
@@ -926,10 +944,10 @@ export async function restoreBackup(backupName: string): Promise<RestoreResult>
let restoredFiles = 0;
const uploadsBackupDir = path.join(backupDir, 'uploads');
if (fs.existsSync(uploadsBackupDir)) {
// Bestehenden Uploads-Ordner leeren (optional: könnte auch nur überschreiben)
if (fs.existsSync(UPLOADS_DIR)) {
deleteDirectory(UPLOADS_DIR);
}
// Inhalte leeren, das Verzeichnis selbst NICHT löschen
// UPLOADS_DIR ist im Container ein Bind-Mount auf den Host und
// `rmdir` darauf liefert EBUSY (siehe emptyDirectory()).
emptyDirectory(UPLOADS_DIR);
restoredFiles = copyDirectory(uploadsBackupDir, UPLOADS_DIR);
}