mirror of
https://github.com/Studio-Saelix/sencho.git
synced 2026-08-10 02:41:14 +00:00
fix(docker-events): harden crash detection against edge cases (#591)
* fix(docker-events): harden crash detection against edge cases - Isolate per-container failures in the reconcile path so one failed container inspect cannot abort classification for the rest of the batch after a reconnect. - Fall back to inspecting State.OOMKilled when a container exits with code 137 and no oom event preceded the die, so cgroup OOM kills that lose the oom event are still classified correctly. The dedup check runs before the fallback so crashloops do not hammer the daemon. - Guard the intentional-kill window against wildly future-dated Docker timestamps by switching to a signed age comparison with a bounded negative-skew tolerance, so clock skew cannot flip a genuine crash into an intentional stop. - Align diagnostic logging with the codebase [Service:diag] convention and add one informational lifecycle log on boot and shutdown so operators running in developer mode can confirm the watcher started. - New tests cover gap-inspect isolation, the OOM inspect fallback (both success and failure paths), duplicate die events collapsing within the grace window, and clock-skew bounds on the classifier. * docs(alerts): add troubleshooting entries for crash detection toggle and rate limits
This commit is contained in:
@@ -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', () => {
|
||||
|
||||
@@ -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', () => {
|
||||
|
||||
@@ -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';
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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<void> {
|
||||
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);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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.
|
||||
|
||||
Reference in New Issue
Block a user