diff --git a/backend/src/__tests__/container-lifecycle-classifier.test.ts b/backend/src/__tests__/container-lifecycle-classifier.test.ts index a4a51e32..1f2404ff 100644 --- a/backend/src/__tests__/container-lifecycle-classifier.test.ts +++ b/backend/src/__tests__/container-lifecycle-classifier.test.ts @@ -10,6 +10,7 @@ import { classifyDie, classifyGapExit, INTENTIONAL_KILL_WINDOW_MS, + MAX_NEGATIVE_SKEW_MS, } from '../services/ContainerLifecycleClassifier'; describe('classifyDie', () => { @@ -87,6 +88,28 @@ describe('classifyDie', () => { ); expect(result).toBe('crash'); }); + + it('rejects a die with a wildly future-dated timestamp (clock skew)', () => { + // Die timestamp 120s in the future while the kill happened "now": + // a real out-of-order delivery is bounded by the 500ms grace window, + // so 120s of future skew must not match an earlier intentional kill. + const result = classifyDie( + { at: now + 120_000, exitCode: 1 }, + { lastKillAt: now }, + ); + expect(result).toBe('crash'); + }); + + it('accepts a die with modest negative skew within the tolerance window', () => { + // Kill happened slightly after the die (bounded out-of-order delivery + // plus normal clock skew, under MAX_NEGATIVE_SKEW_MS). Still intentional. + const skew = MAX_NEGATIVE_SKEW_MS - 1_000; + const result = classifyDie( + { at: now, exitCode: 1 }, + { lastKillAt: now + skew }, + ); + expect(result).toBe('intentional'); + }); }); describe('classifyGapExit', () => { diff --git a/backend/src/__tests__/docker-event-service.test.ts b/backend/src/__tests__/docker-event-service.test.ts index 5cdd1de2..328cf818 100644 --- a/backend/src/__tests__/docker-event-service.test.ts +++ b/backend/src/__tests__/docker-event-service.test.ts @@ -452,6 +452,134 @@ describe('DockerEventService - reconnect', () => { }); }); +// ── Hardening: gap isolation / OOM fallback / concurrent dies ───────── + +describe('DockerEventService - hardening', () => { + it('isolates failures inside classifyGap so one bad inspect does not abort the batch', async () => { + // 1 exit out of 10 (10%) stays below the 20% mass-event threshold, so + // the gap classifier inspects the container individually. That inspect + // fails; the service must isolate the failure and still classify a + // subsequent die as a crash. + const baseline = Array.from({ length: 10 }, (_, i) => ({ + Id: `c-${i}`, + State: 'running', + })); + mockListContainers.mockResolvedValueOnce(baseline); + + service = new DockerEventService(1, 'local'); + await service.start(); + + stream.error(new Error('broken')); + stream = makeStream(); + mockGetEvents.mockImplementation(async () => stream); + + const postReconnect = baseline.map((c, i) => ({ + Id: c.Id, + State: i < 1 ? 'exited' : 'running', + })); + mockListContainers.mockResolvedValueOnce(postReconnect); + mockInspect.mockRejectedValueOnce(new Error('gone')); + + await vi.advanceTimersByTimeAsync(2_000); + await Promise.resolve(); + await Promise.resolve(); + await Promise.resolve(); + + mockDispatchAlert.mockClear(); + stream.push({ + Type: 'container', + Action: 'die', + Actor: { ID: 'post-recovery', Attributes: { exitCode: '1', name: 'app' } }, + }); + await vi.advanceTimersByTimeAsync(600); + + expect(mockDispatchAlert).toHaveBeenCalledWith( + 'error', + expect.stringContaining('Container Crash Detected'), + undefined, + ); + }); + + it('classifies exit code 137 as OOM when container inspect reports OOMKilled (no oom event)', async () => { + service = new DockerEventService(1, 'local'); + await service.start(); + + // Inspect fallback: no prior `oom` event, but the container's + // State.OOMKilled is true. + mockInspect.mockResolvedValueOnce({ + State: { OOMKilled: true, ExitCode: 137 }, + }); + + stream.push({ + Type: 'container', + Action: 'die', + Actor: { ID: 'cgroup-killed', Attributes: { exitCode: '137', name: 'hog' } }, + }); + await vi.advanceTimersByTimeAsync(600); + // Allow the awaited inspect in classifyDie to resolve. + await Promise.resolve(); + await Promise.resolve(); + await Promise.resolve(); + + const oomCall = mockDispatchAlert.mock.calls.find(c => + typeof c[1] === 'string' && c[1].includes('OOM Kill')); + const crashCall = mockDispatchAlert.mock.calls.find(c => + typeof c[1] === 'string' && c[1].includes('Crash Detected')); + expect(oomCall).toBeDefined(); + expect(crashCall).toBeUndefined(); + }); + + it('falls back to crash when exit 137 die inspect fails', async () => { + service = new DockerEventService(1, 'local'); + await service.start(); + + mockInspect.mockRejectedValueOnce(new Error('no such container')); + + stream.push({ + Type: 'container', + Action: 'die', + Actor: { ID: 'gone', Attributes: { exitCode: '137', name: 'ephemeral' } }, + }); + await vi.advanceTimersByTimeAsync(600); + await Promise.resolve(); + await Promise.resolve(); + await Promise.resolve(); + + // Inspect failed, so classification stays as the original 'crash'. + expect(mockDispatchAlert).toHaveBeenCalledWith( + 'error', + expect.stringContaining('Container Crash Detected'), + undefined, + ); + }); + + it('collapses duplicate die events for the same container within the grace window', async () => { + service = new DockerEventService(1, 'local'); + await service.start(); + + // Two dies for the same container within 500ms: the second cancels + // the first pending timer and reschedules. Exactly one crash alert + // must fire, using the later exit code. + stream.push({ + Type: 'container', + Action: 'die', + Actor: { ID: 'dup', Attributes: { exitCode: '1', name: 'dup' } }, + }); + await vi.advanceTimersByTimeAsync(100); + stream.push({ + Type: 'container', + Action: 'die', + Actor: { ID: 'dup', Attributes: { exitCode: '2', name: 'dup' } }, + }); + await vi.advanceTimersByTimeAsync(700); + + const crashCalls = mockDispatchAlert.mock.calls.filter(c => + typeof c[1] === 'string' && c[1].includes('Crash Detected')); + expect(crashCalls).toHaveLength(1); + expect(crashCalls[0][1]).toContain('Code: 2'); + }); +}); + // ── Diagnostics ──────────────────────────────────────────────────────── describe('DockerEventService - getStatus', () => { diff --git a/backend/src/services/ContainerLifecycleClassifier.ts b/backend/src/services/ContainerLifecycleClassifier.ts index 9866b437..e2ba96a0 100644 --- a/backend/src/services/ContainerLifecycleClassifier.ts +++ b/backend/src/services/ContainerLifecycleClassifier.ts @@ -14,6 +14,14 @@ export type Classification = 'intentional' | 'clean' | 'crash' | 'oom'; /** Window (ms) after a `kill` event within which a subsequent `die` is considered intentional. */ export const INTENTIONAL_KILL_WINDOW_MS = 60_000; +/** + * Maximum negative age (ms) tolerated when matching a kill to a later die. + * Absorbs small out-of-order deliveries and minor clock skew, but rejects + * wildly future-dated Docker timestamps that could otherwise flip a genuine + * crash into an "intentional" classification. + */ +export const MAX_NEGATIVE_SKEW_MS = 10_000; + export interface ContainerLifecycleState { /** Timestamp (ms) of the most recent `kill` event for this container, if any. */ lastKillAt?: number; @@ -44,11 +52,12 @@ export function classifyDie( if (state.oomPending) return 'oom'; if (typeof state.lastKillAt === 'number') { - // Use absolute age so out-of-order deliveries (kill arrives slightly - // after die) still classify as intentional. DockerEventService's 500ms - // die grace window makes this realistically bounded. - const age = Math.abs(input.at - state.lastKillAt); - if (age <= INTENTIONAL_KILL_WINDOW_MS) { + // Use signed age so a die with a wildly future-dated timestamp + // (clock skew / bad container clock) cannot match a past kill. + // Allow modest negative skew so out-of-order deliveries still + // classify as intentional within DockerEventService's grace window. + const age = input.at - state.lastKillAt; + if (age >= -MAX_NEGATIVE_SKEW_MS && age <= INTENTIONAL_KILL_WINDOW_MS) { return 'intentional'; } } diff --git a/backend/src/services/DockerEventManager.ts b/backend/src/services/DockerEventManager.ts index 9cda97ca..aaaa06de 100644 --- a/backend/src/services/DockerEventManager.ts +++ b/backend/src/services/DockerEventManager.ts @@ -46,6 +46,8 @@ export class DockerEventManager { const nodes = DatabaseService.getInstance().getNodes() .filter(n => n.type === 'local' && typeof n.id === 'number'); await Promise.all(nodes.map(n => this.spawn(n))); + + console.log(`[DockerEvents] Started; watching ${this.services.size} local node(s) for container lifecycle events`); } /** Shutdown: stop every service and unsubscribe from registry events. */ @@ -60,6 +62,8 @@ export class DockerEventManager { for (const service of this.services.values()) service.shutdown(); this.services.clear(); + + console.log('[DockerEvents] Stopped'); } /** Aggregated status for diagnostics (e.g. /api/health). */ @@ -119,7 +123,7 @@ export class DockerEventManager { await service.start(); } catch (err) { if (isDebugEnabled()) { - console.log(`[DockerEventManager] failed to start service for node ${node.name}:`, + console.log(`[DockerEvents:diag] failed to start service for node ${node.name}:`, err instanceof Error ? err.message : err); } } diff --git a/backend/src/services/DockerEventService.ts b/backend/src/services/DockerEventService.ts index 013a0cef..c2ee4865 100644 --- a/backend/src/services/DockerEventService.ts +++ b/backend/src/services/DockerEventService.ts @@ -9,6 +9,7 @@ import { ContainerLifecycleState, } from './ContainerLifecycleClassifier'; import { isDebugEnabled } from '../utils/debug'; +import { getErrorMessage } from '../utils/errors'; /** * DockerEventService @@ -218,7 +219,7 @@ export class DockerEventService { } if (isDebugEnabled()) { - console.log(`[DockerEventService:${this.nodeName}] disconnected:`, + console.log(`[DockerEvents:${this.nodeName}:diag] disconnected:`, error instanceof Error ? error.message : error); } this.scheduleReconnect(); @@ -260,7 +261,7 @@ export class DockerEventService { containers = await this.docker.listContainers({ all: true }); } catch (err) { if (isDebugEnabled()) { - console.log(`[DockerEventService:${this.nodeName}] reconcile list failed:`, + console.log(`[DockerEvents:${this.nodeName}:diag] reconcile list failed:`, err instanceof Error ? err.message : err); } return; @@ -292,7 +293,17 @@ export class DockerEventService { } else { // Inspect + classify in parallel. Below the mass-event threshold // newlyExited is small by definition, so unbounded concurrency is fine. - await Promise.all(newlyExited.map(id => this.classifyGap(id))); + // Each gap is isolated with .catch() so a single failed inspect + // (e.g. container removed between list and inspect) does not abort + // the rest of the batch. + await Promise.all(newlyExited.map(id => + this.classifyGap(id).catch(err => { + if (isDebugEnabled()) { + console.log(`[DockerEvents:${this.nodeName}:diag] gap classify failed for ${id}:`, + err instanceof Error ? err.message : err); + } + }) + )); } this.exitedBaseline = exitedNow; @@ -312,7 +323,7 @@ export class DockerEventService { await this.emitClassification(classification, null, { name, exitCode, stackName }); } catch (err) { if (isDebugEnabled()) { - console.log(`[DockerEventService:${this.nodeName}] gap inspect failed:`, + console.log(`[DockerEvents:${this.nodeName}:diag] gap inspect failed:`, err instanceof Error ? err.message : err); } } @@ -334,7 +345,7 @@ export class DockerEventService { this.handleEvent(payload); } catch (err) { if (isDebugEnabled()) { - console.log(`[DockerEventService:${this.nodeName}] event handler threw:`, + console.log(`[DockerEvents:${this.nodeName}:diag] event handler threw:`, err instanceof Error ? err.message : err); } } @@ -377,7 +388,7 @@ export class DockerEventService { if (existing) clearTimeout(existing); const timer = setTimeout(() => { this.pendingDieTimers.delete(id); - this.classifyDie(id, event); + void this.classifyDie(id, event); }, DIE_GRACE_WINDOW_MS); this.pendingDieTimers.set(id, timer); } @@ -420,14 +431,14 @@ export class DockerEventService { } } - private classifyDie(id: string, event: DockerEventPayload): void { + private async classifyDie(id: string, event: DockerEventPayload): Promise { const state = this.getOrCreateState(id, event); const exitCodeStr = event.Actor?.Attributes?.exitCode; const parsedExit = exitCodeStr !== undefined ? parseInt(exitCodeStr, 10) : undefined; const exitCode = Number.isFinite(parsedExit) ? (parsedExit as number) : undefined; const now = Date.now(); - const classification = classifyDie( + let classification = classifyDie( { at: this.eventTimeMs(event), exitCode }, { lastKillAt: state.lastKillAt, oomPending: state.oomPending }, ); @@ -438,12 +449,32 @@ export class DockerEventService { if (classification === 'intentional' || classification === 'clean') return; - // Dedup: skip if we already alerted on this container within the window. + // Dedup early: crashloops repeatedly reach this point with exit 137, + // and the OOM fallback below issues a Docker inspect. Skipping the + // inspect on deduped crashes avoids hammering the daemon. if (state.lastCrashAlertAt && now - state.lastCrashAlertAt < CRASH_DEDUP_MS) { return; } - void this.emitClassification(classification, state, { + // OOM fallback: if Docker never emitted an `oom` event but the exit + // code is 137 (SIGKILL, often the cgroup OOM killer), inspect the + // container and reuse classifyGapExit so the "what counts as OOM + // from inspect" rule lives in one place. + if (classification === 'crash' && exitCode === 137) { + try { + const inspect = await this.docker.getContainer(id).inspect(); + if (classifyGapExit(inspect) === 'oom') { + classification = 'oom'; + } + } catch (err) { + if (isDebugEnabled()) { + console.log(`[DockerEvents:${this.nodeName}:diag] OOM fallback inspect failed for ${id}:`, + getErrorMessage(err, 'unknown error')); + } + } + } + + await this.emitClassification(classification, state, { name: state.name ?? id.slice(0, 12), exitCode: exitCode ?? 0, stackName: state.stackName, @@ -492,7 +523,7 @@ export class DockerEventService { // Default-deny on settings lookup failure: don't spam users if the // DB is temporarily unavailable. if (isDebugEnabled()) { - console.log(`[DockerEventService:${this.nodeName}] settings lookup failed:`, + console.log(`[DockerEvents:${this.nodeName}:diag] settings lookup failed:`, err instanceof Error ? err.message : err); } } diff --git a/docs/features/alerts-notifications.mdx b/docs/features/alerts-notifications.mdx index 7d3b45bf..cf359d3c 100644 --- a/docs/features/alerts-notifications.mdx +++ b/docs/features/alerts-notifications.mdx @@ -230,6 +230,18 @@ Expected. Intentional stops, `docker stop` from a host terminal, and scheduled s Expected. When a large share of containers exits during a Docker daemon interruption, Sencho consolidates them into a single informational notification instead of paging per container. Individual crashes that happen after the reconnect are alerted on as normal. +### Crash alerts stopped arriving and nothing else looks wrong + +Check, in order: + +1. Open **Settings > System** and confirm **Global Crash Detection** is on. When it is off, crash, OOM, and unhealthy notifications stop on all nodes while stack metric alerts and update notifications continue as normal. +2. Look in the in-app notifications panel for a **Lost connection to Docker daemon** warning. If present, Sencho is not receiving events from the affected node and is retrying in the background; a **Reconnected to Docker daemon** info entry will appear when monitoring resumes. +3. Confirm the affected node is reachable from the host running Sencho. For remote nodes, the remote Sencho instance is responsible for its own crash detection; check its status from that instance. + +### A burst of crashes happened but I only see about twenty alerts + +Expected, and by design. Sencho caps crash notifications at around 20 per minute per node so a runaway restart loop or a stack-wide failure cannot flood your notification channels. Any crashes beyond the cap in that window are rolled up into a single **N additional containers crashed in the last minute** warning. The complete, unredacted list of events is always visible in the in-app notifications panel; only external channel delivery (Discord, Slack, webhooks) is rate-limited. + ### Delete confirmation dialog Deleting an alert rule now requires confirmation. Click the trash icon next to a rule, then confirm in the dialog that appears.