From 3ec9085444b2784a0a2646c90c9feb4808c14344 Mon Sep 17 00:00:00 2001 From: Sucukdeluxe Date: Sat, 22 Aug 2026 08:58:36 +0200 Subject: [PATCH] fix(notifications): harden final delivery lifecycle Enforce one shared shutdown deadline while persisting late digests during blocked sends. Start stall cooldowns from serialized delivery acknowledgements, atomically rewrite cleaned legacy outboxes, retain run summaries for 24 hours, and prevent duplicate history or synthetic post-process start times. --- .../final-fix-report.md | 130 ++++++++++++++++ src/main/app-controller.ts | 49 ++++-- src/main/download-health-monitor.ts | 57 +++++-- src/main/download-manager.ts | 11 +- src/main/notification-events.ts | 2 +- src/main/notification-outbox.ts | 146 +++++++++++++----- tests/download-health-monitor.test.ts | 90 ++++++++++- tests/main-shutdown-lifecycle.test.ts | 135 +++++++++++++++- tests/notification-outbox.test.ts | 128 +++++++++++++++ tests/notify-hooks.test.ts | 62 ++++++++ 10 files changed, 733 insertions(+), 77 deletions(-) create mode 100644 .superpowers/sdd/2026-08-22-notification-center-v2/final-fix-report.md diff --git a/.superpowers/sdd/2026-08-22-notification-center-v2/final-fix-report.md b/.superpowers/sdd/2026-08-22-notification-center-v2/final-fix-report.md new file mode 100644 index 0000000..5643a65 --- /dev/null +++ b/.superpowers/sdd/2026-08-22-notification-center-v2/final-fix-report.md @@ -0,0 +1,130 @@ +# Notification Center v2 Final Fix Report + +## Status + +PASS. + +Alle Findings der finalen Whole-Branch-Prüfung wurden in einer testgetriebenen Fixwelle behoben. Es wurden keine Subagents eingesetzt, keine fremden Änderungen zurückgesetzt und keine alten ungetrackten Release-, Audit-, Stage- oder Build-Verzeichnisse verändert. + +## Behobene Findings + +### Globales Shutdown-Deadlinebudget + +- `AppController.shutdown()` verwendet ein gemeinsames Deadlinebudget von 3000 ms. +- Health-Timer, Runtime-Timer und weitere Produzenten werden zuerst gestoppt. +- Eine bereits laufende Health-Auswertung, die finale Health-Auswertung, der Digest-Flush und der Outbox-Drain teilen sich dasselbe Restbudget. +- `DownloadManager.prepareForShutdown()` läuft vor Digest-Flush und Drain. +- Ein blockierter Discord-Versand blockiert neue Outbox-Persistenz nicht mehr. +- Ein Paket-Digest, der erst während des Shutdown-Fensters final wird, wird sofort in die persistente Outbox geschrieben. + +### Delivery-Ack und Stall-Cooldown + +- `NotificationOutbox` meldet ausschließlich erfolgreiche tatsächliche Zustellungen mit Event und realem Zustellzeitpunkt zurück. +- `DownloadHealthMonitor` startet den Stall-Cooldown erst mit diesem Zustellzeitpunkt. +- Ein während eines Discord-Ausfalls gepufferter Stall bleibt über seine stabile Event-ID dedupliziert. +- Health-Samples und Delivery-Acks werden serialisiert, sodass keine veraltete Sample-Persistenz einen gerade gesetzten Cooldown überschreibt. +- Wiederholte Acks derselben stabilen Stall-ID sind idempotent. +- Ein fehlgeschlagener Health-Ack führt weder zur erneuten Discord-Zustellung noch zur Blockade nachfolgender Outbox-Ereignisse. +- Persistierte Ack-IDs werden strikt auf das interne Stall-ID-Format begrenzt. + +### Atomare Legacy-Outbox-Bereinigung + +- Eine vorhandene Outbox-Datei wird beim Laden sofort in den bereinigten kanonischen Zustand zurückgeschrieben. +- Abgelaufene und ungültige Ereignisse verschwinden auch dann atomar auf Disk, wenn danach keine Queue-Einträge verbleiben. +- Private Legacy-Felder und private Fehler-Sentinels verbleiben nicht bis zum nächsten Enqueue oder Drain in der Datei. + +### Ereignis-TTL + +- `run_completed` besitzt unabhängig von seiner Erfolgs- oder Fehlerpriorität immer eine TTL von 24 Stunden. +- Paket-Erfolgsmeldungen behalten ihre sechs Stunden TTL. + +### History-Dedup + +- Das autoritative finale `PackageResult` markiert das Paket unmittelbar als fachlich im Verlauf erfasst. +- Eine anschließende manuelle Paketlöschung erzeugt keinen zweiten `deleted`-Verlaufseintrag. +- Ein echter Reset entfernt die Markierung weiterhin für eine neue Ergebnisgeneration. + +### Postprocess-Startzeit + +- `postProcessStartedAt` wird nicht mehr aus `postProcessQueuedAt` erfunden. +- Wenn ein Paket nie einen Postprocess-Slot erhalten hat, bleiben Startzeit und Postprocess-Dauer bei 0. + +## TDD-Nachweis + +Erster RED-Lauf: + +```text +Test Files 4 failed (4) +Tests 9 failed | 76 passed (85) +``` + +Die neun erwarteten Fehler belegten das bisherige Verhalten für Deadline, späte Digest-Persistenz, blockierenden Send/Enqueue-Lock, fehlenden Delivery-Ack, zu frühen Cooldown, Legacy-Datei, Erfolg-Run-TTL, History-Doppelentry und erfundenen Postprocess-Start. + +Zusätzliche gezielte RED-Läufe belegten: + +- ein nach begonnenem Shutdown-Flush finalisierter Digest blieb zunächst nur im Speicher; +- ein Ack-Fehler blockierte nachfolgende Outbox-Ereignisse; +- eine frei gesetzte Ack-ID gelangte in die Health-Datei; +- ein paralleler Recovery-Sample konnte einen Delivery-Cooldown überschreiben. + +Alle jeweiligen GREEN-Läufe bestanden nach der minimalen Produktionskorrektur. + +## Finaler fokussierter Gate + +```text +.\node_modules\.bin\vitest.cmd run tests\notification-outbox.test.ts tests\download-health-monitor.test.ts tests\notify-hooks.test.ts tests\download-manager.test.ts tests\session-restart-loss.test.ts tests\main-shutdown-lifecycle.test.ts +Test Files 6 passed (6) +Tests 344 passed (344) +Duration 163.36s +Exit 0 +``` + +Enthalten: + +- Notification Outbox: 22 Tests +- Download Health Monitor: 34 Tests +- Notification Hooks: 27 Tests +- Download Manager: 240 Tests +- Session Restart/Loss: 16 Tests +- Main Shutdown Lifecycle: 5 Tests + +TypeScript: + +```text +.\node_modules\.bin\tsc.cmd --noEmit +Exit 0 +``` + +Diffprüfung: + +```text +git diff --check +Exit 0 +``` + +Vitest meldete ausschließlich die bereits vorhandene Vite-CJS-Node-API-Deprecation-Warnung. Es gab keine Testfehler, unbehandelten Ablehnungen oder Timer-Leak-Meldungen. + +## Geänderter Scope + +Produktionsdateien: + +- `src/main/app-controller.ts` +- `src/main/notification-outbox.ts` +- `src/main/download-health-monitor.ts` +- `src/main/notification-events.ts` +- `src/main/download-manager.ts` + +Tests: + +- `tests/notification-outbox.test.ts` +- `tests/download-health-monitor.test.ts` +- `tests/notify-hooks.test.ts` +- `tests/main-shutdown-lifecycle.test.ts` + +Bericht: + +- `.superpowers/sdd/2026-08-22-notification-center-v2/final-fix-report.md` + +## Restbedenken + +Keine offenen bekannten Korrektheitsfehler innerhalb des beauftragten Scopes. Der Discord-Transport kann eine Zustellung bei einem Prozessabbruch exakt zwischen externer HTTP-Annahme und lokaler atomarer Entfernung grundsätzlich nicht transaktional mit Discord koordinieren; stabile IDs und die persistente FIFO-Outbox begrenzen dieses unvermeidbare externe Exactly-once-Fenster. diff --git a/src/main/app-controller.ts b/src/main/app-controller.ts index 52946bb..a8283cd 100644 --- a/src/main/app-controller.ts +++ b/src/main/app-controller.ts @@ -173,7 +173,14 @@ export class AppController { color: event.payload.color ?? (event.priority === "error" ? 0xe74c3c : 0x2ecc71), fields: event.payload.fields, timestamp: event.createdAt - }) + }), + onDelivered: (event, deliveredAt) => { + return this.downloadHealthMonitor?.acknowledgeDelivery( + event, + deliveredAt, + this.settings.notifyStallCooldownMinutes * 60_000 + ); + } }); this.downloadHealthMonitor = new DownloadHealthMonitor(this.storagePaths.notificationHealthFile); void this.notificationOutbox.drain().catch((error) => { @@ -1338,17 +1345,12 @@ export class AppController { } public async shutdown(): Promise { + const deadlineAt = Date.now() + 3000; if (this.downloadHealthTimer) { clearInterval(this.downloadHealthTimer); this.downloadHealthTimer = null; } this.manager.suspendDownloadHealthMonitoring?.(); - if (this.downloadHealthEvaluation) { - await this.downloadHealthEvaluation; - } - if (this.downloadHealthMonitor) { - await this.evaluateDownloadHealth(); - } if (this.runtimeStatsTimer) { clearInterval(this.runtimeStatsTimer); this.runtimeStatsTimer = null; @@ -1356,14 +1358,20 @@ export class AppController { stopDebugServer(); abortActiveUpdateDownload(); cancelPendingAsyncSaves(); - const notificationFlush = this.manager.flushNotificationsForShutdown?.(); - if (notificationFlush) { - await notificationFlush; + this.manager.prepareForShutdown(); + if (this.downloadHealthEvaluation) { + await this.waitForShutdownTask(this.downloadHealthEvaluation, deadlineAt); } - await this.notificationOutbox.drainForShutdown(3000).catch((error) => { + if (this.downloadHealthMonitor && Date.now() < deadlineAt) { + await this.waitForShutdownTask(this.evaluateDownloadHealth(), deadlineAt); + } + const notificationFlush = this.manager.flushNotificationsForShutdown?.(); + if (notificationFlush && Date.now() < deadlineAt) { + await this.waitForShutdownTask(notificationFlush, deadlineAt); + } + await this.notificationOutbox.drainForShutdown(Math.max(0, deadlineAt - Date.now())).catch((error) => { logger.warn(`Notification-Outbox konnte beim Beenden nicht geleert werden: ${String(error)}`); }); - this.manager.prepareForShutdown(); this.megaWebFallback.dispose(); for (const fallback of this.realDebridWebFallbacks.values()) { fallback.dispose(); @@ -1381,7 +1389,22 @@ export class AppController { if (this.settings.historyRetentionMode === "session") { clearHistory(this.storagePaths); } - logger.info("App beendet"); + logger.info("App beendet"); + } + + private async waitForShutdownTask(task: Promise, deadlineAt: number): Promise { + const remainingMs = Math.max(0, deadlineAt - Date.now()); + if (remainingMs <= 0) { + return; + } + let timer: NodeJS.Timeout | null = null; + const timeout = new Promise((resolve) => { + timer = setTimeout(resolve, remainingMs); + }); + await Promise.race([task.then(() => undefined, () => undefined), timeout]); + if (timer) { + clearTimeout(timer); + } } private getDesktopDirectory(): string | null { diff --git a/src/main/download-health-monitor.ts b/src/main/download-health-monitor.ts index 6eb4bcd..47b0148 100644 --- a/src/main/download-health-monitor.ts +++ b/src/main/download-health-monitor.ts @@ -53,6 +53,7 @@ export interface DownloadHealthState { alertedAt: number; lastAlertAt: number; cooldownUntil: number; + lastDeliveredStallEventId: string | null; recoverySamples: number; lastSampleAt: number | null; downloadProgressSequence: number; @@ -87,6 +88,7 @@ const HEALTH_STATUSES = new Set([ ]); const INCIDENT_TYPES = new Set(["scheduler", "no_data"]); const FINGERPRINT_PATTERN = /^[a-f0-9]{64}$/; +const STALL_EVENT_ID_PATTERN = /^health:stall:[a-f0-9]{16}:\d+$/; const MIN_SUSPICIOUS_SAMPLES = 3; const SCHEDULER_STALE_AFTER_MS = 30_000; const ERROR_EVENT_TTL_MS = 24 * 60 * 60 * 1000; @@ -101,6 +103,10 @@ function validFingerprint(value: unknown): string | null { return typeof value === "string" && FINGERPRINT_PATTERN.test(value) ? value : null; } +function validStallEventId(value: unknown): string | null { + return typeof value === "string" && STALL_EVENT_ID_PATTERN.test(value) ? value : null; +} + function durationText(durationMs: number): string { const totalSeconds = Math.max(0, Math.floor(durationMs / 1000)); if (totalSeconds < 60) { @@ -195,6 +201,7 @@ export function createDownloadHealthState(overrides: Partial= stallAfterMs && state.suspiciousSamples >= MIN_SUSPICIOUS_SAMPLES; if (confirmed && options.notifyOnStall && now >= state.cooldownUntil) { state.status = "alerted"; state.alertedAt = now; - state.lastAlertAt = now; - state.cooldownUntil = now + cooldownMs; state.recoverySamples = 0; events.push(incidentEvent(state, snapshot, now)); } @@ -406,6 +412,7 @@ function persistedState(state: DownloadHealthState): Omit = Promise.resolve(); + public constructor(private readonly filePath: string, initialState?: DownloadHealthState) { this.state = initialState ? createDownloadHealthState(initialState) : loadDownloadHealthState(filePath); } @@ -480,18 +490,43 @@ export class DownloadHealthMonitor { return createDownloadHealthState(this.state); } - public async sample( + public acknowledgeDelivery(event: NotificationEvent, deliveredAt: number, cooldownMs: number): Promise { + return this.runExclusive(async () => { + const eventId = validStallEventId(event.id); + if (event.type !== "download_stalled" || !eventId || this.state.lastDeliveredStallEventId === eventId) { + return; + } + const acknowledgedAt = finiteInteger(deliveredAt); + this.state = createDownloadHealthState({ + ...this.state, + lastAlertAt: acknowledgedAt, + cooldownUntil: acknowledgedAt + finiteInteger(cooldownMs), + lastDeliveredStallEventId: eventId + }); + saveDownloadHealthState(this.filePath, this.state); + }); + } + + public sample( snapshot: DownloadHealthSnapshot, now: number, options: DownloadHealthOptions, enqueue: (event: NotificationEvent) => Promise ): Promise { - const evaluation = evaluateDownloadHealth(this.state, snapshot, now, options); - for (const event of evaluation.events) { - await enqueue(event); - } - saveDownloadHealthState(this.filePath, evaluation.state); - this.state = evaluation.state; - return evaluation; + return this.runExclusive(async () => { + const evaluation = evaluateDownloadHealth(this.state, snapshot, now, options); + for (const event of evaluation.events) { + await enqueue(event); + } + saveDownloadHealthState(this.filePath, evaluation.state); + this.state = evaluation.state; + return evaluation; + }); + } + + private runExclusive(operation: () => Promise): Promise { + const result = this.operationChain.then(operation, operation); + this.operationChain = result.then(() => undefined, () => undefined); + return result; } } diff --git a/src/main/download-manager.ts b/src/main/download-manager.ts index 5798a11..01eb1f0 100644 --- a/src/main/download-manager.ts +++ b/src/main/download-manager.ts @@ -1963,6 +1963,8 @@ export class DownloadManager extends EventEmitter { private successDigestTimer: NodeJS.Timeout | null = null; private notificationEnqueueChain: Promise = Promise.resolve(); + + private notificationsShuttingDown = false; private itemCount = 0; @@ -8807,6 +8809,7 @@ export class DownloadManager extends EventEmitter { } public async flushNotificationsForShutdown(): Promise { + this.notificationsShuttingDown = true; this.flushPackageSuccessDigest(); await this.notificationEnqueueChain; } @@ -12151,6 +12154,10 @@ export class DownloadManager extends EventEmitter { private queueSuccessfulPackageResult(envelope: PackageResultEnvelope): void { const key = this.packageResultKey(envelope.result.packageId, envelope.generation); this.successDigestResults.set(key, envelope); + if (this.notificationsShuttingDown) { + this.flushPackageSuccessDigest(); + return; + } if (this.successDigestTimer) { return; } @@ -12219,9 +12226,6 @@ export class DownloadManager extends EventEmitter { if (!(pkg.downloadEndedAt || 0)) { pkg.downloadEndedAt = completedAt; } - if (!(pkg.postProcessStartedAt || 0) && (pkg.postProcessQueuedAt || 0) > 0) { - pkg.postProcessStartedAt = pkg.postProcessQueuedAt; - } pkg.postProcessCompletedAt = completedAt; pkg.terminalAt = completedAt; const result = finalizePackageResult({ @@ -12236,6 +12240,7 @@ export class DownloadManager extends EventEmitter { pkg.status = result.status === "partial" ? "failed" : result.status; pkg.updatedAt = completedAt; if (this.onHistoryEntryCallback) { + this.historyRecordedPackages.add(packageId); this.onHistoryEntryCallback(buildHistoryEntry(result, { generation, outputDir: pkg.outputDir, diff --git a/src/main/notification-events.ts b/src/main/notification-events.ts index 44b448d..ed8c505 100644 --- a/src/main/notification-events.ts +++ b/src/main/notification-events.ts @@ -166,7 +166,7 @@ function event( type, priority, createdAt, - expiresAt: createdAt + (priority === "success" ? SUCCESS_TTL_MS : IMPORTANT_TTL_MS), + expiresAt: createdAt + (type === "run_completed" || priority === "error" ? IMPORTANT_TTL_MS : SUCCESS_TTL_MS), attempts: 0, nextAttemptAt: createdAt, payload: { title, description, color, fields } diff --git a/src/main/notification-outbox.ts b/src/main/notification-outbox.ts index ee1594d..1af326f 100644 --- a/src/main/notification-outbox.ts +++ b/src/main/notification-outbox.ts @@ -44,6 +44,7 @@ export interface NotificationOutboxStatus { export interface NotificationOutboxOptions { filePath: string; send: (event: NotificationEvent) => Promise; + onDelivered?: (event: NotificationEvent, deliveredAt: number) => void | Promise; now?: () => number; autoDrain?: boolean; } @@ -166,14 +167,17 @@ export class NotificationOutbox { private operationChain: Promise = Promise.resolve(); private readonly filePath: string; private readonly sendEvent: (event: NotificationEvent) => Promise; + private readonly onDelivered: ((event: NotificationEvent, deliveredAt: number) => void | Promise) | null; private readonly clock: () => number; private readonly autoDrain: boolean; private retryTimer: NodeJS.Timeout | null = null; private shutdownRequested = false; + private drainOperation: Promise | null = null; public constructor(options: NotificationOutboxOptions) { this.filePath = options.filePath; this.sendEvent = options.send; + this.onDelivered = options.onDelivered || null; this.clock = options.now || Date.now; this.autoDrain = Boolean(options.autoDrain); this.load(); @@ -196,45 +200,16 @@ export class NotificationOutbox { } public drain(now?: number): Promise { - return this.runExclusive(async () => { - let currentNow = finiteInteger(now ?? this.clock()); - this.enforceLimits(currentNow); - while (this.events.length > 0) { - const current = this.events[0]; - if (current.nextAttemptAt > currentNow) { - await this.persist(currentNow); - if (this.autoDrain) { - this.scheduleDrain(Math.max(0, current.nextAttemptAt - this.clock())); - } - break; - } - let sent = false; - try { - sent = await this.sendEvent(current); - } catch { - sent = false; - } - const outcomeAt = finiteInteger(this.clock(), currentNow); - if (!sent) { - current.attempts += 1; - current.nextAttemptAt = outcomeAt + retryDelayMs(current.attempts); - this.lastFailureAt = outcomeAt; - await this.persist(outcomeAt); - if (this.autoDrain) { - this.scheduleDrain(Math.max(0, current.nextAttemptAt - this.clock())); - } - break; - } - this.events.shift(); - this.lastSuccessAt = outcomeAt; - await this.persist(outcomeAt); - currentNow = finiteInteger(this.clock(), outcomeAt); - } - if (this.events.length === 0) { - this.clearRetryTimer(); - await this.persist(finiteInteger(this.clock(), currentNow)); + if (this.drainOperation) { + return this.drainOperation; + } + const operation = this.performDrain(now).finally(() => { + if (this.drainOperation === operation) { + this.drainOperation = null; } }); + this.drainOperation = operation; + return operation; } public async drainForShutdown(timeoutMs = DEFAULT_SHUTDOWN_TIMEOUT_MS): Promise { @@ -258,12 +233,76 @@ export class NotificationOutbox { }; } - private runExclusive(operation: () => Promise): Promise { + private runExclusive(operation: () => Promise): Promise { const result = this.operationChain.then(operation, operation); - this.operationChain = result.catch(() => {}); + this.operationChain = result.then(() => undefined, () => undefined); return result; } + private async performDrain(now?: number): Promise { + let currentNow = finiteInteger(now ?? this.clock()); + while (true) { + const current = await this.runExclusive(async () => { + this.enforceLimits(currentNow); + const next = this.events[0] || null; + if (!next) { + this.clearRetryTimer(); + await this.persist(finiteInteger(this.clock(), currentNow)); + return null; + } + if (next.nextAttemptAt > currentNow) { + await this.persist(currentNow); + if (this.autoDrain) { + this.scheduleDrain(Math.max(0, next.nextAttemptAt - this.clock())); + } + return null; + } + return next; + }); + if (!current) { + return; + } + let sent = false; + try { + sent = await this.sendEvent(current); + } catch { + sent = false; + } + const outcomeAt = finiteInteger(this.clock(), currentNow); + const delivered = await this.runExclusive(async () => { + const index = this.events.findIndex((event) => event.id === current.id); + if (index < 0) { + return false; + } + if (!sent) { + const queued = this.events[index]; + queued.attempts += 1; + queued.nextAttemptAt = outcomeAt + retryDelayMs(queued.attempts); + this.lastFailureAt = outcomeAt; + await this.persist(outcomeAt); + if (this.autoDrain) { + this.scheduleDrain(Math.max(0, queued.nextAttemptAt - this.clock())); + } + return false; + } + this.events.splice(index, 1); + this.lastSuccessAt = outcomeAt; + await this.persist(outcomeAt); + return true; + }); + if (!sent) { + return; + } + if (delivered && this.onDelivered) { + try { + await this.onDelivered(current, outcomeAt); + } catch { + } + } + currentNow = finiteInteger(this.clock(), outcomeAt); + } + } + private scheduleDrain(delayMs: number): void { if (this.shutdownRequested) { return; @@ -284,10 +323,10 @@ export class NotificationOutbox { } private load(): void { + if (!fs.existsSync(this.filePath)) { + return; + } try { - if (!fs.existsSync(this.filePath)) { - return; - } const parsed = JSON.parse(fs.readFileSync(this.filePath, "utf8")) as Partial; this.events = Array.isArray(parsed.events) ? parsed.events.flatMap((event) => { @@ -303,6 +342,7 @@ export class NotificationOutbox { this.lastSuccessAt = 0; this.lastFailureAt = 0; } + this.persistSync(this.clock()); } private enforceLimits(now: number): void { @@ -332,4 +372,26 @@ export class NotificationOutbox { throw error; } } + + private persistSync(now: number): void { + this.enforceLimits(now); + fs.mkdirSync(path.dirname(this.filePath), { recursive: true }); + const tempPath = `${this.filePath}.tmp`; + const state: PersistedNotificationOutbox = { + version: 1, + events: this.events, + lastSuccessAt: this.lastSuccessAt, + lastFailureAt: this.lastFailureAt + }; + try { + fs.writeFileSync(tempPath, JSON.stringify(state), "utf8"); + fs.renameSync(tempPath, this.filePath); + } catch (error) { + try { + fs.rmSync(tempPath, { force: true }); + } catch { + } + throw error; + } + } } diff --git a/tests/download-health-monitor.test.ts b/tests/download-health-monitor.test.ts index 8dfd524..9ce6bf7 100644 --- a/tests/download-health-monitor.test.ts +++ b/tests/download-health-monitor.test.ts @@ -11,6 +11,7 @@ import { type DownloadHealthSnapshot, type DownloadHealthState } from "../src/main/download-health-monitor"; +import { NotificationOutbox } from "../src/main/notification-outbox"; const RUN_FINGERPRINT = "a".repeat(64); const QUEUE_FINGERPRINT = "b".repeat(64); @@ -250,8 +251,13 @@ describe("evaluateDownloadHealth", () => { expect(result.state.alertedAt).toBe(0); }); - it("applies a ten-minute cooldown before another incident event", () => { - const firstAlert = alertedState(); + it("applies a ten-minute cooldown after a delivered incident event", () => { + const firstAlert = createDownloadHealthState({ + ...alertedState(), + lastAlertAt: 90_000, + cooldownUntil: 690_000, + lastDeliveredStallEventId: `health:stall:${RUN_FINGERPRINT.slice(0, 16)}:0` + }); const recovered = evaluate(firstAlert, snapshot({ itemCompletionSequence: 1 }), 105_000).state; const duringCooldown = sampleTimes(recovered, [120_000, 165_000, 210_000]); const afterCooldown = evaluate(duringCooldown.state, snapshot(), 690_000); @@ -263,6 +269,83 @@ describe("evaluateDownloadHealth", () => { ]); }); + it("starts the cooldown at actual Discord delivery after a buffered outage", async () => { + const root = fs.mkdtempSync(path.join(os.tmpdir(), "rd-health-delivery-ack-")); + tempDirs.push(root); + const healthFile = path.join(root, "health.json"); + const outboxFile = path.join(root, "outbox.json"); + const suspicious = sampleTimes(createDownloadHealthState(), [0, 45_000]).state; + const monitor = new DownloadHealthMonitor(healthFile, suspicious); + let now = 90_000; + let deliveryAvailable = false; + const deliveredIds: string[] = []; + const outbox = new NotificationOutbox({ + filePath: outboxFile, + now: () => now, + send: async (queuedEvent) => { + if (deliveryAvailable) deliveredIds.push(queuedEvent.id); + return deliveryAvailable; + }, + onDelivered: (queuedEvent, deliveredAt) => { + return monitor.acknowledgeDelivery(queuedEvent, deliveredAt, 600_000); + } + }); + + const confirmed = await monitor.sample(snapshot(), now, { + stallAfterMs: 90_000, + cooldownMs: 600_000, + notifyOnStall: true, + notifyOnRecovery: true + }, (event) => outbox.enqueue(event)); + await outbox.drain(); + now = 300_000; + const repeated = await monitor.sample(snapshot(), now, { + stallAfterMs: 90_000, + cooldownMs: 600_000, + notifyOnStall: true, + notifyOnRecovery: true + }, (event) => outbox.enqueue(event)); + + expect(confirmed.events).toHaveLength(1); + expect(repeated.events).toEqual([]); + expect(outbox.getStatus().queued).toBe(1); + expect(monitor.getState().cooldownUntil).toBe(0); + + deliveryAvailable = true; + now = 420_000; + await outbox.drain(now); + + expect(deliveredIds).toEqual([confirmed.events[0].id]); + expect(monitor.getState().lastAlertAt).toBe(420_000); + expect(monitor.getState().cooldownUntil).toBe(1_020_000); + }); + + it("serializes a delivery acknowledgement behind a concurrent recovery sample", async () => { + const root = fs.mkdtempSync(path.join(os.tmpdir(), "rd-health-ack-race-")); + tempDirs.push(root); + const filePath = path.join(root, "health.json"); + const confirmed = sampleTimes(createDownloadHealthState(), [0, 45_000, 90_000]); + const monitor = new DownloadHealthMonitor(filePath, confirmed.state); + let releaseEnqueue = () => {}; + const enqueueBlocked = new Promise((resolve) => { releaseEnqueue = resolve; }); + const recovery = monitor.sample(snapshot({ itemCompletionSequence: 1 }), 105_000, { + stallAfterMs: 90_000, + cooldownMs: 600_000, + notifyOnStall: true, + notifyOnRecovery: true + }, async () => enqueueBlocked); + await Promise.resolve(); + + const acknowledgement = monitor.acknowledgeDelivery(confirmed.events[0], 300_000, 600_000); + releaseEnqueue(); + await Promise.all([recovery, acknowledgement]); + + expect(monitor.getState().status).toBe("healthy"); + expect(monitor.getState().lastAlertAt).toBe(300_000); + expect(monitor.getState().cooldownUntil).toBe(900_000); + expect(monitor.getState().lastDeliveredStallEventId).toBe(confirmed.events[0].id); + }); + it("keeps the incident event id stable when outbox persistence rejects the state transition", () => { const suspicious = sampleTimes(createDownloadHealthState(), [0, 45_000]).state; const firstAttempt = evaluate(suspicious, snapshot(), 90_000); @@ -367,7 +450,8 @@ describe("download health restart persistence", () => { ...alertedState(), privateUrl: "https://private.example.test/file", privatePath: "C:\\private\\download.bin", - privateAccount: "private@example.test" + privateAccount: "private@example.test", + lastDeliveredStallEventId: "https://private.example.test/stall" } as DownloadHealthState; saveDownloadHealthState(filePath, state); diff --git a/tests/main-shutdown-lifecycle.test.ts b/tests/main-shutdown-lifecycle.test.ts index 619b79f..c7d9abb 100644 --- a/tests/main-shutdown-lifecycle.test.ts +++ b/tests/main-shutdown-lifecycle.test.ts @@ -1,7 +1,7 @@ import fs from "node:fs"; import os from "node:os"; import path from "node:path"; -import { describe, expect, it, vi } from "vitest"; +import { afterEach, describe, expect, it, vi } from "vitest"; const electron = vi.hoisted(() => { const handlers = new Map void>(); @@ -43,6 +43,7 @@ import { saveDownloadHealthState, type DownloadHealthSnapshot } from "../src/main/download-health-monitor"; +import { NotificationOutbox, type NotificationEvent } from "../src/main/notification-outbox"; function deferred(): { promise: Promise; resolve: () => void } { let resolve = () => {}; @@ -50,6 +51,23 @@ function deferred(): { promise: Promise; resolve: () => void } { return { promise, resolve }; } +function shutdownEvent(id: string, priority: "success" | "error" = "success"): NotificationEvent { + return { + id, + type: "package_completed", + priority, + createdAt: Date.now(), + expiresAt: Date.now() + 6 * 60 * 60 * 1000, + attempts: 0, + nextAttemptAt: Date.now(), + payload: { title: "Paket-Digest", fields: [] } + }; +} + +afterEach(() => { + vi.useRealTimers(); +}); + describe("main shutdown lifecycle", () => { it("AppController waits for the bounded outbox drain before disposing runtime owners", async () => { const drain = deferred(); @@ -70,11 +88,120 @@ describe("main shutdown lifecycle", () => { const shutdown = controller.shutdown(); expect(shutdown).toBeInstanceOf(Promise); - expect(controller.notificationOutbox.drainForShutdown).toHaveBeenCalledWith(3000); - expect(manager.prepareForShutdown).not.toHaveBeenCalled(); + const drainBudget = controller.notificationOutbox.drainForShutdown.mock.calls[0][0]; + expect(drainBudget).toBeGreaterThan(0); + expect(drainBudget).toBeLessThanOrEqual(3000); + expect(manager.prepareForShutdown).toHaveBeenCalledTimes(1); drain.resolve(); await shutdown; - expect(manager.prepareForShutdown).toHaveBeenCalledTimes(1); + }); + + it("uses one three-second deadline even when a running health evaluation never settles", async () => { + vi.useFakeTimers(); + vi.setSystemTime(1000); + const runningEvaluation = deferred(); + const controller = Object.create(AppController.prototype) as any; + controller.downloadHealthTimer = setInterval(() => {}, 60_000); + controller.downloadHealthEvaluation = runningEvaluation.promise; + controller.downloadHealthMonitor = null; + controller.runtimeStatsTimer = null; + controller.notificationOutbox = { drainForShutdown: vi.fn(async () => undefined) }; + controller.manager = { + suspendDownloadHealthMonitoring: vi.fn(), + prepareForShutdown: vi.fn(), + flushNotificationsForShutdown: vi.fn(async () => undefined) + }; + controller.megaWebFallback = { dispose: vi.fn() }; + controller.realDebridWebFallbacks = new Map(); + controller.pendingRealDebridWebAccountIds = new Map(); + controller.allDebridWebFallback = { dispose: vi.fn() }; + controller.bestDebridWebFallback = { dispose: vi.fn() }; + controller.shutdownLogStorage = vi.fn(); + controller.audit = vi.fn(); + controller.settings = { historyRetentionMode: "never" }; + let completed = false; + + const shutdown = controller.shutdown().then(() => { completed = true; }); + await vi.advanceTimersByTimeAsync(2999); + expect(completed).toBe(false); + await vi.advanceTimersByTimeAsync(1); + const completedAtDeadline = completed; + runningEvaluation.resolve(); + await vi.runAllTimersAsync(); + await shutdown; + + expect(completedAtDeadline).toBe(true); + expect(controller.manager.prepareForShutdown).toHaveBeenCalledTimes(1); + }); + + it("persists a digest completed inside the shared shutdown window while an earlier send is blocked", async () => { + vi.useFakeTimers(); + vi.setSystemTime(1000); + const root = fs.mkdtempSync(path.join(os.tmpdir(), "rd-shutdown-outbox-")); + const filePath = path.join(root, "outbox.json"); + let releaseSend = (_sent: boolean) => {}; + let markSendStarted = () => {}; + const sendStarted = new Promise((resolve) => { markSendStarted = resolve; }); + const blockedSend = new Promise((resolve) => { releaseSend = resolve; }); + const lateEnqueued = deferred(); + const outbox = new NotificationOutbox({ + filePath, + now: Date.now, + send: async (event) => { + if (event.id === "already-sending") { + markSendStarted(); + return blockedSend; + } + return true; + } + }); + await outbox.enqueue(shutdownEvent("already-sending", "error")); + const activeDrain = outbox.drain(); + await sendStarted; + const controller = Object.create(AppController.prototype) as any; + controller.downloadHealthTimer = null; + controller.downloadHealthEvaluation = null; + controller.downloadHealthMonitor = null; + controller.runtimeStatsTimer = null; + controller.notificationOutbox = outbox; + controller.manager = { + suspendDownloadHealthMonitoring: vi.fn(), + prepareForShutdown: vi.fn(), + flushNotificationsForShutdown: vi.fn(() => new Promise((resolve) => { + setTimeout(() => { + void outbox.enqueue(shutdownEvent("late-digest")).then(() => { + lateEnqueued.resolve(); + resolve(); + }); + }, 500); + })) + }; + controller.megaWebFallback = { dispose: vi.fn() }; + controller.realDebridWebFallbacks = new Map(); + controller.pendingRealDebridWebAccountIds = new Map(); + controller.allDebridWebFallback = { dispose: vi.fn() }; + controller.bestDebridWebFallback = { dispose: vi.fn() }; + controller.shutdownLogStorage = vi.fn(); + controller.audit = vi.fn(); + controller.settings = { historyRetentionMode: "never" }; + let completed = false; + + const shutdown = controller.shutdown().then(() => { completed = true; }); + await vi.advanceTimersByTimeAsync(500); + await lateEnqueued.promise; + const stateDuringWindow = JSON.parse(fs.readFileSync(filePath, "utf8")) as { events: NotificationEvent[] }; + await vi.advanceTimersByTimeAsync(2500); + const completedAtDeadline = completed; + releaseSend(true); + await vi.runAllTimersAsync(); + await activeDrain; + await shutdown; + + expect(stateDuringWindow.events.map((event) => event.id)).toContain("late-digest"); + expect(completedAtDeadline).toBe(true); + expect(controller.manager.prepareForShutdown.mock.invocationCallOrder[0]) + .toBeLessThan(controller.manager.flushNotificationsForShutdown.mock.invocationCallOrder[0]); + fs.rmSync(root, { recursive: true, force: true }); }); it("prevents quit once, waits for shutdown, then allows exactly one loop-free quit", async () => { diff --git a/tests/notification-outbox.test.ts b/tests/notification-outbox.test.ts index 929150a..2001370 100644 --- a/tests/notification-outbox.test.ts +++ b/tests/notification-outbox.test.ts @@ -296,6 +296,38 @@ describe("NotificationOutbox", () => { } }); + it("persists a cleaned empty legacy file atomically during load", () => { + const filePath = createOutboxFile(); + const rename = vi.spyOn(fs, "renameSync"); + fs.writeFileSync(filePath, JSON.stringify({ + version: 1, + events: [ + event("expired-private", { + expiresAt: 999, + payload: { + title: "Paket fehlgeschlagen", + fields: [{ name: "Fehler", value: `Download · ${privateFailureDetails}`, inline: false }] + } + }), + { id: "", privateSentinel: privateFailureDetails } + ], + lastSuccessAt: 0, + lastFailureAt: 0, + privateSentinel: privateFailureDetails + }), "utf8"); + + const outbox = new NotificationOutbox({ filePath, send: async () => true, now: () => 1000 }); + + const raw = fs.readFileSync(filePath, "utf8"); + expect(outbox.getStatus().queued).toBe(0); + expect(JSON.parse(raw).events).toEqual([]); + expect(raw).not.toContain("private.example.test"); + expect(raw).not.toContain("SUPERSECRET"); + expect(rename).toHaveBeenCalledWith(`${filePath}.tmp`, filePath); + expect(fs.existsSync(`${filePath}.tmp`)).toBe(false); + rename.mockRestore(); + }); + it("drops expired events before persisting or sending", async () => { const filePath = createOutboxFile(); const send = vi.fn().mockResolvedValue(true); @@ -512,6 +544,102 @@ describe("NotificationOutbox", () => { } }); + it("persists an enqueue while an earlier delivery is blocked", async () => { + const filePath = createOutboxFile(); + let releaseSend = (_sent: boolean) => {}; + let markSendStarted = () => {}; + const sendStarted = new Promise((resolve) => { markSendStarted = resolve; }); + const sendResult = new Promise((resolve) => { releaseSend = resolve; }); + const outbox = new NotificationOutbox({ + filePath, + send: async () => { + markSendStarted(); + return sendResult; + }, + now: () => 1000 + }); + await outbox.enqueue(event("blocked")); + const draining = outbox.drain(); + await sendStarted; + + const lateEnqueue = outbox.enqueue(event("late-digest", { + type: "package_completed", + priority: "success" + })); + const persistedBeforeRelease = await Promise.race([ + lateEnqueue.then(() => true), + new Promise((resolve) => setTimeout(() => resolve(false), 25)) + ]); + const stateBeforeRelease = persisted(filePath); + releaseSend(true); + await draining; + await lateEnqueue; + + expect(persistedBeforeRelease).toBe(true); + expect(stateBeforeRelease.events.map((queuedEvent) => queuedEvent.id)).toContain("late-digest"); + }); + + it("acknowledges only successful delivery with its actual completion time", async () => { + const filePath = createOutboxFile(); + let now = 1000; + const delivered: Array<{ id: string; deliveredAt: number }> = []; + const failedOutbox = new NotificationOutbox({ + filePath, + now: () => now, + send: async () => { + now = 2000; + return false; + }, + onDelivered: (queuedEvent, deliveredAt) => { + delivered.push({ id: queuedEvent.id, deliveredAt }); + } + }); + + await failedOutbox.enqueue(event("failed")); + await failedOutbox.drain(); + expect(delivered).toEqual([]); + + const deliveredFilePath = createOutboxFile(); + now = 3000; + const deliveredOutbox = new NotificationOutbox({ + filePath: deliveredFilePath, + now: () => now, + send: async () => true, + onDelivered: (queuedEvent, deliveredAt) => { + delivered.push({ id: queuedEvent.id, deliveredAt }); + } + }); + await deliveredOutbox.enqueue(event("delivered", { nextAttemptAt: 3000 })); + await deliveredOutbox.drain(); + + expect(delivered).toEqual([{ id: "delivered", deliveredAt: 3000 }]); + }); + + it("does not redeliver or block later events when delivery acknowledgement fails", async () => { + const filePath = createOutboxFile(); + const sent: string[] = []; + const outbox = new NotificationOutbox({ + filePath, + now: () => 1000, + send: async (queuedEvent) => { + sent.push(queuedEvent.id); + return true; + }, + onDelivered: (queuedEvent) => { + if (queuedEvent.id === "first") { + throw new Error("health state unavailable"); + } + } + }); + await outbox.enqueue(event("first")); + await outbox.enqueue(event("second")); + + await expect(outbox.drain()).resolves.toBeUndefined(); + + expect(sent).toEqual(["first", "second"]); + expect(persisted(filePath).events).toEqual([]); + }); + it("returns after the default three-second shutdown budget when sending hangs", async () => { vi.useFakeTimers(); const filePath = createOutboxFile(); diff --git a/tests/notify-hooks.test.ts b/tests/notify-hooks.test.ts index 577fb66..c02872f 100644 --- a/tests/notify-hooks.test.ts +++ b/tests/notify-hooks.test.ts @@ -4,6 +4,7 @@ import path from "node:path"; import { afterEach, describe, expect, it, vi } from "vitest"; import { DownloadManager } from "../src/main/download-manager"; import { defaultSettings } from "../src/main/constants"; +import { buildRunNotificationEvent, buildRunResult } from "../src/main/notification-events"; import type { NotificationEvent } from "../src/main/notification-outbox"; import { createStoragePaths, emptySession } from "../src/main/storage"; import { shutdownItemLogs } from "../src/main/item-log"; @@ -154,6 +155,35 @@ describe("authoritative package completion", () => { expect(pkg.terminalAt).toBe(pkg.postProcessCompletedAt); }); + it("keeps postprocess start unset when a queued package never receives a slot", async () => { + const { manager, session, history } = setup(); + const pkg = addPackage(session); + const state = internal(manager); + pkg.postProcessQueuedAt = Date.now() - 5000; + state.runPackageIds.add(pkg.id); + + state.tryFinalizePackageResult(pkg.id); + await flushNotifications(); + + expect(history).toHaveLength(1); + expect(history[0].postProcessStartedAt).toBe(0); + expect(history[0].postProcessDurationSeconds).toBe(0); + }); + + it("records exactly one business history entry when a finalized package is manually deleted", async () => { + const { manager, session, history } = setup(); + const pkg = addPackage(session); + const state = internal(manager); + state.runPackageIds.add(pkg.id); + + state.tryFinalizePackageResult(pkg.id); + await flushNotifications(); + manager.cancelPackage(pkg.id); + + expect(history).toHaveLength(1); + expect(history[0]).toMatchObject({ id: `hist-${pkg.id}-1`, status: "completed" }); + }); + it("turns a deferred remux failure into one immediate failed package event", async () => { const { manager, session, events, history } = setup({ notifyPackageSuccessMode: "digest" }); const pkg = addPackage(session); @@ -304,9 +334,41 @@ describe("authoritative package completion", () => { expect(events.map((event) => event.type)).toEqual(["package_completed"]); expect(events[0].payload.title).toContain("Paket-Digest"); }); + + it("persists a success digest that finalizes after shutdown flushing has started", async () => { + const { manager, session, events } = setup({ notifyPackageSuccessMode: "digest" }); + const pkg = addPackage(session); + const state = internal(manager); + state.runPackageIds.add(pkg.id); + + await state.flushNotificationsForShutdown(); + state.tryFinalizePackageResult(pkg.id); + await flushNotifications(); + + expect(events.map((event) => event.type)).toEqual(["package_completed"]); + expect(events[0].payload.title).toContain("Paket-Digest"); + }); }); describe("authoritative run completion", () => { + it.each([ + ["successful", 0, "success"], + ["failed", 1, "error"] + ] as const)("keeps a %s run_completed event for 24 hours", (_label, failedFiles, priority) => { + const notification = buildRunNotificationEvent(buildRunResult({ + id: `run-${priority}`, + stopped: false, + startedAt: 1000, + completedAt: 2000, + packages: [], + failedFiles + })); + + expect(notification.type).toBe("run_completed"); + expect(notification.priority).toBe(priority); + expect(notification.expiresAt - notification.createdAt).toBe(24 * 60 * 60 * 1000); + }); + it("emits run_stopped without run_completed for a manual stop", async () => { const { manager, session, events } = setup(); const pkg = addPackage(session, ["completed", "queued"]);