From 21ee9286dfca3b953920e18788263b66b8393ec0 Mon Sep 17 00:00:00 2001 From: jubnl Date: Tue, 28 Apr 2026 05:01:03 +0200 Subject: [PATCH] fix: auto-backup retention deletes itself and manual backups on Docker MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two bugs in cleanupOldBackups: 1. Filter was .endsWith('.zip') — swept manual backup-*.zip files too. Now restricted to auto-backup-* prefix. 2. Age was derived from stat.birthtimeMs, which is 0 on overlayfs (Docker default), making every backup appear epoch-old and get deleted immediately. Age is now parsed from the filename timestamp and falls back to mtimeMs (reliable on overlayfs). Also converts inline require('./services/auditLog') calls to a static import throughout scheduler.ts, and adds 8 unit tests covering the fixed retention logic including the overlayfs regression case. --- server/src/scheduler.ts | 80 +++++++++++-------------- server/tests/unit/scheduler.test.ts | 90 ++++++++++++++++++++++++++++- 2 files changed, 122 insertions(+), 48 deletions(-) diff --git a/server/src/scheduler.ts b/server/src/scheduler.ts index 13177b7f..12d81539 100644 --- a/server/src/scheduler.ts +++ b/server/src/scheduler.ts @@ -2,6 +2,7 @@ import cron, { type ScheduledTask } from 'node-cron'; import archiver from 'archiver'; import path from 'node:path'; import fs from 'node:fs'; +import { logInfo, logError } from './services/auditLog'; const dataDir = path.join(__dirname, '../data'); const backupsDir = path.join(dataDir, 'backups'); @@ -79,11 +80,9 @@ async function runBackup(): Promise { if (fs.existsSync(uploadsDir)) archive.directory(uploadsDir, 'uploads'); archive.finalize(); }); - const { logInfo: li } = require('./services/auditLog'); - li(`Auto-Backup created: ${filename}`); + logInfo(`Auto-Backup created: ${filename}`); } catch (err: unknown) { - const { logError: le } = require('./services/auditLog'); - le(`Auto-Backup: ${err instanceof Error ? err.message : err}`); + logError(`Auto-Backup: ${err instanceof Error ? err.message : err}`); if (fs.existsSync(outputPath)) fs.unlinkSync(outputPath); return; } @@ -94,23 +93,28 @@ async function runBackup(): Promise { } } -function cleanupOldBackups(keepDays: number): void { +function autoBackupTimestampMs(filename: string): number | null { + // auto-backup-2026-04-27T00-00-00.zip → 2026-04-27T00:00:00 + const stamp = filename.slice('auto-backup-'.length, -'.zip'.length); + const iso = stamp.replace(/T(\d{2})-(\d{2})-(\d{2})$/, 'T$1:$2:$3'); + const ms = Date.parse(iso); + return Number.isNaN(ms) ? null : ms; +} + +export function cleanupOldBackups(keepDays: number, now: number = Date.now()): void { try { - const MS_PER_DAY = 24 * 60 * 60 * 1000; - const cutoff = Date.now() - keepDays * MS_PER_DAY; - const files = fs.readdirSync(backupsDir).filter(f => f.endsWith('.zip')); + const cutoff = now - keepDays * 24 * 60 * 60 * 1000; + const files = fs.readdirSync(backupsDir).filter(f => f.startsWith('auto-backup-') && f.endsWith('.zip')); for (const file of files) { const filePath = path.join(backupsDir, file); - const stat = fs.statSync(filePath); - if (stat.birthtimeMs < cutoff) { + const ageMs = autoBackupTimestampMs(file) ?? fs.statSync(filePath).mtimeMs; + if (ageMs < cutoff) { fs.unlinkSync(filePath); - const { logInfo: li } = require('./services/auditLog'); - li(`Auto-Backup old backup deleted: ${file}`); + logInfo(`Auto-Backup old backup deleted: ${file}`); } } } catch (err: unknown) { - const { logError: le } = require('./services/auditLog'); - le(`Auto-Backup cleanup: ${err instanceof Error ? err.message : err}`); + logError(`Auto-Backup cleanup: ${err instanceof Error ? err.message : err}`); } } @@ -122,16 +126,14 @@ function start(): void { const settings = loadSettings(); if (!settings.enabled) { - const { logInfo: li } = require('./services/auditLog'); - li('Auto-Backup disabled'); + logInfo('Auto-Backup disabled'); return; } const expression = buildCronExpression(settings); const tz = process.env.TZ || 'UTC'; currentTask = cron.schedule(expression, runBackup, { timezone: tz }); - const { logInfo: li2 } = require('./services/auditLog'); - li2(`Auto-Backup scheduled: ${settings.interval} (${expression}), tz: ${tz}, retention: ${settings.keep_days === 0 ? 'forever' : settings.keep_days + ' days'}`); + logInfo(`Auto-Backup scheduled: ${settings.interval} (${expression}), tz: ${tz}, retention: ${settings.keep_days === 0 ? 'forever' : settings.keep_days + ' days'}`); } // Demo mode: hourly reset of demo user data @@ -146,12 +148,10 @@ function startDemoReset(): void { const { resetDemoUser } = require('./demo/demo-reset'); resetDemoUser(); } catch (err: unknown) { - const { logError: le } = require('./services/auditLog'); - le(`Demo reset: ${err instanceof Error ? err.message : err}`); + logError(`Demo reset: ${err instanceof Error ? err.message : err}`); } }); - const { logInfo: li3 } = require('./services/auditLog'); - li3('Demo hourly reset scheduled'); + logInfo('Demo hourly reset scheduled'); } // Trip reminders: daily check at 9 AM local time for trips starting tomorrow @@ -167,14 +167,12 @@ function startTripReminders(): void { const channelsRaw = getSetting('notification_channels') || getSetting('notification_channel') || 'none'; const activeChannels = channelsRaw === 'none' ? [] : channelsRaw.split(',').map((c: string) => c.trim()); if (!reminderEnabled) { - const { logInfo: li } = require('./services/auditLog'); - li('Trip reminders: disabled in settings'); + logInfo('Trip reminders: disabled in settings'); return; } const tripCount = (db.prepare('SELECT COUNT(*) as c FROM trips WHERE reminder_days > 0 AND start_date IS NOT NULL').get() as { c: number }).c; - const { logInfo: liSetup } = require('./services/auditLog'); - liSetup(`Trip reminders: enabled via [${activeChannels.join(',')}]${tripCount > 0 ? `, ${tripCount} trip(s) with active reminders` : ''}`); + logInfo(`Trip reminders: enabled via [${activeChannels.join(',')}]${tripCount > 0 ? `, ${tripCount} trip(s) with active reminders` : ''}`); } catch { return; } @@ -196,13 +194,11 @@ function startTripReminders(): void { await send({ event: 'trip_reminder', actorId: null, scope: 'trip', targetId: trip.id, params: { trip: trip.title, tripId: String(trip.id) } }).catch(() => {}); } - const { logInfo: li } = require('./services/auditLog'); if (trips.length > 0) { - li(`Trip reminders sent for ${trips.length} trip(s): ${trips.map(t => `"${t.title}" (${t.reminder_days}d)`).join(', ')}`); + logInfo(`Trip reminders sent for ${trips.length} trip(s): ${trips.map(t => `"${t.title}" (${t.reminder_days}d)`).join(', ')}`); } } catch (err: unknown) { - const { logError: le } = require('./services/auditLog'); - le(`Trip reminder check failed: ${err instanceof Error ? err.message : err}`); + logError(`Trip reminder check failed: ${err instanceof Error ? err.message : err}`); } }, { timezone: tz }); } @@ -222,12 +218,10 @@ function startTodoReminders(): void { const getSetting = (key: string) => (db.prepare('SELECT value FROM app_settings WHERE key = ?').get(key) as { value: string } | undefined)?.value; const enabled = getSetting('notify_todo_due') !== 'false'; if (!enabled) { - const { logInfo: li } = require('./services/auditLog'); - li('Todo due reminders: disabled in settings'); + logInfo('Todo due reminders: disabled in settings'); return; } - const { logInfo: liSetup } = require('./services/auditLog'); - liSetup(`Todo due reminders: enabled (lead ${TODO_REMINDER_LEAD_DAYS}d)`); + logInfo(`Todo due reminders: enabled (lead ${TODO_REMINDER_LEAD_DAYS}d)`); const tz = process.env.TZ || 'UTC'; todoReminderTask = cron.schedule('0 9 * * *', async () => { @@ -271,13 +265,11 @@ function startTodoReminders(): void { db.prepare('UPDATE todo_items SET reminded_at = CURRENT_TIMESTAMP WHERE id = ?').run(todo.id); } - const { logInfo: li } = require('./services/auditLog'); if (todos.length > 0) { - li(`Todo reminders sent for ${todos.length} item(s)`); + logInfo(`Todo reminders sent for ${todos.length} item(s)`); } } catch (err: unknown) { - const { logError: le } = require('./services/auditLog'); - le(`Todo reminder check failed: ${err instanceof Error ? err.message : err}`); + logError(`Todo reminder check failed: ${err instanceof Error ? err.message : err}`); } }, { timezone: tz }); } @@ -294,8 +286,7 @@ function startVersionCheck(): void { const { checkAndNotifyVersion } = require('./services/adminService'); await checkAndNotifyVersion(); } catch (err: unknown) { - const { logError: le } = require('./services/auditLog'); - le(`Version check: ${err instanceof Error ? err.message : err}`); + logError(`Version check: ${err instanceof Error ? err.message : err}`); } }, { timezone: tz }); } @@ -313,12 +304,10 @@ function startIdempotencyCleanup(): void { const cutoff = Math.floor(Date.now() / 1000) - 86400; const result = db.prepare('DELETE FROM idempotency_keys WHERE created_at < ?').run(cutoff); if (result.changes > 0) { - const { logInfo: li } = require('./services/auditLog'); - li(`Idempotency cleanup: removed ${result.changes} expired key(s)`); + logInfo(`Idempotency cleanup: removed ${result.changes} expired key(s)`); } } catch (err: unknown) { - const { logError: le } = require('./services/auditLog'); - le(`Idempotency cleanup: ${err instanceof Error ? err.message : err}`); + logError(`Idempotency cleanup: ${err instanceof Error ? err.message : err}`); } }, { timezone: tz }); } @@ -340,8 +329,7 @@ function startTrekPhotoCacheCleanup(): void { const { sweepExpired } = require('./services/memories/trekPhotoCache'); sweepExpired(); } catch (err: unknown) { - const { logError: le } = require('./services/auditLog'); - le(`Trek photo cache cleanup: ${err instanceof Error ? err.message : err}`); + logError(`Trek photo cache cleanup: ${err instanceof Error ? err.message : err}`); } }); } diff --git a/server/tests/unit/scheduler.test.ts b/server/tests/unit/scheduler.test.ts index 94447d33..69a4a2fa 100644 --- a/server/tests/unit/scheduler.test.ts +++ b/server/tests/unit/scheduler.test.ts @@ -1,4 +1,4 @@ -import { describe, it, expect, vi } from 'vitest'; +import { describe, it, expect, vi, beforeEach } from 'vitest'; // Prevent node-cron from scheduling anything at import time vi.mock('node-cron', () => ({ @@ -17,6 +17,7 @@ vi.mock('node:fs', () => ({ writeFileSync: vi.fn(), readdirSync: vi.fn(() => []), statSync: vi.fn(() => ({ mtime: new Date(), size: 0 })), + unlinkSync: vi.fn(), createWriteStream: vi.fn(() => ({ on: vi.fn(), pipe: vi.fn() })), }, existsSync: vi.fn(() => false), @@ -25,14 +26,20 @@ vi.mock('node:fs', () => ({ writeFileSync: vi.fn(), readdirSync: vi.fn(() => []), statSync: vi.fn(() => ({ mtime: new Date(), size: 0 })), + unlinkSync: vi.fn(), createWriteStream: vi.fn(() => ({ on: vi.fn(), pipe: vi.fn() })), })); vi.mock('../../../src/db/database', () => ({ db: { prepare: () => ({ all: vi.fn(() => []), get: vi.fn(), run: vi.fn() }) }, })); vi.mock('../../../src/config', () => ({ JWT_SECRET: 'test-secret', ENCRYPTION_KEY: '0'.repeat(64) })); +vi.mock('../../src/services/auditLog', () => ({ + logInfo: vi.fn(), + logError: vi.fn(), +})); -import { buildCronExpression } from '../../src/scheduler'; +import fs from 'node:fs'; +import { buildCronExpression, cleanupOldBackups } from '../../src/scheduler'; interface BackupSettings { enabled: boolean; @@ -130,3 +137,82 @@ describe('buildCronExpression', () => { }); }); }); + +describe('cleanupOldBackups', () => { + const DAY = 24 * 60 * 60 * 1000; + const NOW = new Date('2026-04-27T02:00:00Z').getTime(); + + function isoFilename(daysAgo: number, prefix: 'auto-backup' | 'backup' = 'auto-backup'): string { + const d = new Date(NOW - daysAgo * DAY); + const stamp = d.toISOString().replace(/[:.]/g, '-').slice(0, 19); + return `${prefix}-${stamp}.zip`; + } + + beforeEach(() => { + vi.mocked(fs.readdirSync).mockReset(); + vi.mocked(fs.statSync).mockReset(); + vi.mocked(fs.unlinkSync as ReturnType).mockReset(); + (vi.mocked(fs.statSync) as ReturnType).mockReturnValue({ mtime: new Date(), mtimeMs: NOW, birthtimeMs: NOW, size: 0 }); + }); + + it('never deletes manual backup-*.zip files regardless of age', () => { + const manual = isoFilename(365 * 5, 'backup'); + const auto = isoFilename(0); + vi.mocked(fs.readdirSync).mockReturnValue([manual, auto] as unknown as string[]); + cleanupOldBackups(7, NOW); + const deleted = (vi.mocked(fs.unlinkSync as ReturnType)).mock.calls.map((c: unknown[]) => c[0] as string); + expect(deleted.some((p: string) => p.includes(manual))).toBe(false); + }); + + it('keeps auto-backups newer than retention', () => { + const recent = isoFilename(3); + vi.mocked(fs.readdirSync).mockReturnValue([recent] as unknown as string[]); + cleanupOldBackups(7, NOW); + expect(vi.mocked(fs.unlinkSync as ReturnType)).not.toHaveBeenCalled(); + }); + + it('deletes auto-backups older than retention', () => { + const old = isoFilename(30); + vi.mocked(fs.readdirSync).mockReturnValue([old] as unknown as string[]); + cleanupOldBackups(7, NOW); + expect(vi.mocked(fs.unlinkSync as ReturnType)).toHaveBeenCalledOnce(); + const [calledPath] = (vi.mocked(fs.unlinkSync as ReturnType)).mock.calls[0] as string[]; + expect(calledPath).toContain(old); + }); + + it('overlayfs regression: birthtimeMs=0 does not delete a same-day backup', () => { + const fresh = isoFilename(0); + vi.mocked(fs.readdirSync).mockReturnValue([fresh] as unknown as string[]); + (vi.mocked(fs.statSync) as ReturnType).mockReturnValue({ birthtimeMs: 0, mtimeMs: NOW, mtime: new Date(NOW), size: 100 }); + cleanupOldBackups(7, NOW); + expect(vi.mocked(fs.unlinkSync as ReturnType)).not.toHaveBeenCalled(); + }); + + it('malformed filename falls back to mtimeMs: keeps recent file', () => { + vi.mocked(fs.readdirSync).mockReturnValue(['auto-backup-garbage.zip'] as unknown as string[]); + (vi.mocked(fs.statSync) as ReturnType).mockReturnValue({ birthtimeMs: 0, mtimeMs: NOW - 1 * DAY, mtime: new Date(NOW - 1 * DAY), size: 0 }); + cleanupOldBackups(7, NOW); + expect(vi.mocked(fs.unlinkSync as ReturnType)).not.toHaveBeenCalled(); + }); + + it('malformed filename falls back to mtimeMs: deletes stale file', () => { + vi.mocked(fs.readdirSync).mockReturnValue(['auto-backup-garbage.zip'] as unknown as string[]); + (vi.mocked(fs.statSync) as ReturnType).mockReturnValue({ birthtimeMs: 0, mtimeMs: NOW - 30 * DAY, mtime: new Date(NOW - 30 * DAY), size: 0 }); + cleanupOldBackups(7, NOW); + expect(vi.mocked(fs.unlinkSync as ReturnType)).toHaveBeenCalledOnce(); + }); + + it('ignores non-zip files and does not crash', () => { + const old = isoFilename(30); + vi.mocked(fs.readdirSync).mockReturnValue([old, 'notes.txt'] as unknown as string[]); + cleanupOldBackups(7, NOW); + const calls = (vi.mocked(fs.unlinkSync as ReturnType)).mock.calls as string[][]; + expect(calls.every(([p]: string[]) => !p.includes('notes.txt'))).toBe(true); + expect(calls.length).toBe(1); + }); + + it('swallows readdirSync errors without throwing', () => { + vi.mocked(fs.readdirSync).mockImplementation(() => { throw new Error('ENOENT'); }); + expect(() => cleanupOldBackups(7, NOW)).not.toThrow(); + }); +});