diff --git a/src/monitoring/__tests__/eventLoopLagMonitor.test.ts b/src/monitoring/__tests__/eventLoopLagMonitor.test.ts new file mode 100644 index 00000000..e0d47afc --- /dev/null +++ b/src/monitoring/__tests__/eventLoopLagMonitor.test.ts @@ -0,0 +1,177 @@ +import { EventLoopLagMonitor, SamplingProfile, DEFAULT_PROFILE, LagStats } from '../src/monitoring/eventLoopLagMonitor'; + +describe('EventLoopLagMonitor', () => { + describe('initial state', () => { + it('should have zero samples when created', () => { + const monitor = new EventLoopLagMonitor(); + expect(monitor.sampleCount).toBe(0); + expect(monitor.isDegraded).toBe(false); + + const stats = monitor.getStats(); + expect(stats.count).toBe(0); + }); + }); + + describe('start and record', () => { + it('should record samples when started', () => { + const monitor = new EventLoopLagMonitor({ sampleIntervalS: 0.01 }); + monitor.start(); + + for (let i = 0; i < 5; i++) { + const sample = monitor.record(); + expect(sample).not.toBeNull(); + expect(sample!.lagMs).toBeGreaterThanOrEqual(0); + } + expect(monitor.sampleCount).toBe(5); + }); + + it('should return null when stopped', () => { + const monitor = new EventLoopLagMonitor(); + monitor.start(); + monitor.stop(); + expect(monitor.record()).toBeNull(); + }); + }); + + describe('lag detection', () => { + it('should detect lag via intendedAt parameter', () => { + const monitor = new EventLoopLagMonitor({ sampleIntervalS: 0.1 }); + monitor.start(); + + // On-time sample + const now = Date.now(); + const s1 = monitor.record(now); + expect(s1!.lagMs).toBeLessThan(50); + + // Delayed sample (intended 300ms ago) + const s2 = monitor.record(now - 300); + expect(s2!.lagMs).toBeGreaterThan(100); + }); + }); + + describe('stats aggregation', () => { + it('should compute correct percentiles', () => { + const monitor = new EventLoopLagMonitor({ sampleIntervalS: 0.01, windowSize: 10 }); + monitor.start(); + + const base = Date.now(); + // Mix of normal and laggy samples + monitor.record(base); + monitor.record(base - 50); // 50ms lag + monitor.record(base - 200); // 200ms lag + monitor.record(base); + monitor.record(base - 10); + + const stats = monitor.getStats(); + expect(stats.count).toBe(5); + expect(stats.maxMs).toBeGreaterThanOrEqual(200); + expect(stats.minMs).toBeLessThanOrEqual(10); + expect(stats.avgMs).toBeGreaterThan(0); + }); + }); + + describe('degradation alerts', () => { + it('should fire warning callback after consecutive degraded samples', () => { + const alerts: Array<{ level: string; stats: LagStats }> = []; + + const monitor = new EventLoopLagMonitor( + { + sampleIntervalS: 0.01, + alertThresholdMs: 20, + maxConsecutiveDegraded: 2, + }, + { + onWarning: (stats) => alerts.push({ level: 'warning', stats }), + onCritical: (stats) => alerts.push({ level: 'critical', stats }), + onSaturation: (stats) => alerts.push({ level: 'saturation', stats }), + } + ); + monitor.start(); + + // Normal sample + monitor.record(); + + // Two laggy samples + const base = Date.now(); + monitor.record(base - 100); + expect(monitor.isDegraded).toBe(false); + + monitor.record(base - 100); + expect(monitor.isDegraded).toBe(true); + expect(alerts.length).toBeGreaterThanOrEqual(1); + expect(alerts[0].level).toBe('warning'); + }); + + it('should fire critical callback for high lag', () => { + const alerts: string[] = []; + const monitor = new EventLoopLagMonitor( + { + alertThresholdMs: 10, + criticalThresholdMs: 50, + maxConsecutiveDegraded: 2, + }, + { + onCritical: () => alerts.push('critical'), + } + ); + monitor.start(); + monitor.record(); // normal + const base = Date.now(); + monitor.record(base - 100); // 100ms lag + monitor.record(base - 100); // 100ms lag + expect(alerts).toContain('critical'); + }); + + it('should fire saturation callback for extreme lag', () => { + const alerts: string[] = []; + const monitor = new EventLoopLagMonitor( + { + alertThresholdMs: 10, + criticalThresholdMs: 50, + saturationThresholdMs: 100, + maxConsecutiveDegraded: 2, + }, + { + onSaturation: () => alerts.push('saturation'), + } + ); + monitor.start(); + monitor.record(); + const base = Date.now(); + monitor.record(base - 200); // 200ms lag > saturation + monitor.record(base - 200); + expect(alerts).toContain('saturation'); + }); + }); + + describe('reset', () => { + it('should clear samples and degradation state', () => { + const monitor = new EventLoopLagMonitor({ maxConsecutiveDegraded: 1, alertThresholdMs: 5 }); + monitor.start(); + const base = Date.now(); + monitor.record(base - 50); + monitor.record(base - 50); + expect(monitor.sampleCount).toBeGreaterThan(0); + expect(monitor.isDegraded).toBe(true); + + monitor.reset(); + expect(monitor.sampleCount).toBe(0); + expect(monitor.isDegraded).toBe(false); + }); + }); + + describe('SampleProfile defaults', () => { + it('should have reasonable defaults', () => { + expect(DEFAULT_PROFILE.windowSize).toBe(100); + expect(DEFAULT_PROFILE.alertThresholdMs).toBe(100); + expect(DEFAULT_PROFILE.criticalThresholdMs).toBe(500); + expect(DEFAULT_PROFILE.saturationThresholdMs).toBe(1000); + }); + + it('should allow partial overrides', () => { + const monitor = new EventLoopLagMonitor({ alertThresholdMs: 50 }); + monitor.start(); + expect(monitor).toBeDefined(); + }); + }); +}); diff --git a/src/monitoring/eventLoopLagMonitor.ts b/src/monitoring/eventLoopLagMonitor.ts new file mode 100644 index 00000000..6eb410ac --- /dev/null +++ b/src/monitoring/eventLoopLagMonitor.ts @@ -0,0 +1,238 @@ +/** + * Event-loop lag monitor with sampling profile and capacity saturation alerts. + * + * Measures scheduling delay (time between intended and actual execution) + * and raises alerts when lag exceeds configured thresholds. + */ +import { logger } from '../logging'; + +/** A single lag measurement. */ +export interface LagSample { + timestamp: number; + intendedAt: number; + actualAt: number; + lagMs: number; +} + +/** Configuration for lag sampling behaviour. */ +export interface SamplingProfile { + /** Max samples to retain. */ + windowSize: number; + /** How often to sample (seconds). */ + sampleIntervalS: number; + /** Lag threshold for warning alert (ms). */ + alertThresholdMs: number; + /** Lag threshold for critical alert (ms). */ + criticalThresholdMs: number; + /** Lag threshold for saturation alarm (ms). */ + saturationThresholdMs: number; + /** Consecutive high-lag samples before alert fires. */ + maxConsecutiveDegraded: number; +} + +export const DEFAULT_PROFILE: SamplingProfile = { + windowSize: 100, + sampleIntervalS: 1.0, + alertThresholdMs: 100, + criticalThresholdMs: 500, + saturationThresholdMs: 1000, + maxConsecutiveDegraded: 5, +}; + +/** Aggregated statistics from lag samples. */ +export interface LagStats { + count: number; + minMs: number; + maxMs: number; + avgMs: number; + p50Ms: number; + p95Ms: number; + p99Ms: number; + degradedCount: number; + criticalCount: number; + saturationCount: number; +} + +export type AlertCallback = (stats: LagStats) => void; + +/** + * Monitors event-loop lag with configurable sampling and alerting. + * + * @example + * ```typescript + * const monitor = new EventLoopLagMonitor(); + * monitor.start(); + * + * // In your event loop: + * monitor.record(); + * + * // Check stats periodically: + * const stats = monitor.getStats(); + * if (stats.p95Ms > 100) { + * logger.warn('Event loop lag: p95=%.1fms', stats.p95Ms); + * } + * ``` + */ +export class EventLoopLagMonitor { + private readonly profile: SamplingProfile; + private samples: LagSample[] = []; + private lastSampleAt: number = 0; + private consecutiveDegraded: number = 0; + private running: boolean = false; + private readonly onWarning?: AlertCallback; + private readonly onCritical?: AlertCallback; + private readonly onSaturation?: AlertCallback; + + constructor( + profile: Partial = {}, + callbacks?: { + onWarning?: AlertCallback; + onCritical?: AlertCallback; + onSaturation?: AlertCallback; + } + ) { + this.profile = { ...DEFAULT_PROFILE, ...profile }; + this.onWarning = callbacks?.onWarning; + this.onCritical = callbacks?.onCritical; + this.onSaturation = callbacks?.onSaturation; + } + + /** Begin monitoring (clears any previous samples). */ + start(): void { + this.samples = []; + this.consecutiveDegraded = 0; + this.lastSampleAt = Date.now(); + this.running = true; + } + + /** Stop monitoring. */ + stop(): void { + this.running = false; + } + + /** + * Record a lag measurement. + * Call this from your event loop iteration. + */ + record(intendedAt?: number): LagSample | null { + if (!this.running) return null; + + const now = Date.now(); + const intended = intendedAt ?? this.lastSampleAt + this.profile.sampleIntervalS * 1000; + const effectiveIntended = Math.min(intended, now); + + const lag = now - effectiveIntended; + const sample: LagSample = { + timestamp: now, + intendedAt: effectiveIntended, + actualAt: now, + lagMs: Math.max(0, lag), + }; + + this.samples.push(sample); + if (this.samples.length > this.profile.windowSize) { + this.samples.shift(); + } + this.lastSampleAt = now; + + this.evaluateAlerts(sample); + return sample; + } + + private evaluateAlerts(sample: LagSample): void { + if (sample.lagMs > this.profile.alertThresholdMs) { + this.consecutiveDegraded++; + } else { + this.consecutiveDegraded = 0; + return; + } + + if (this.consecutiveDegraded < this.profile.maxConsecutiveDegraded) return; + + const stats = this.computeStats(); + + if (sample.lagMs > this.profile.saturationThresholdMs && this.onSaturation) { + this.onSaturation(stats); + } else if (sample.lagMs > this.profile.criticalThresholdMs && this.onCritical) { + this.onCritical(stats); + } else if (this.onWarning) { + this.onWarning(stats); + } + } + + /** Return aggregated statistics from collected samples. */ + getStats(): LagStats { + return this.computeStats(); + } + + private computeStats(): LagStats { + if (this.samples.length === 0) { + return { + count: 0, minMs: 0, maxMs: 0, avgMs: 0, + p50Ms: 0, p95Ms: 0, p99Ms: 0, + degradedCount: 0, criticalCount: 0, saturationCount: 0, + }; + } + + const lags = this.samples.map(s => s.lagMs).sort((a, b) => a - b); + const n = lags.length; + + const percentile = (pct: number): number => { + const idx = Math.min(Math.floor(n * pct / 100), n - 1); + return lags[idx]; + }; + + const { alertThresholdMs, criticalThresholdMs, saturationThresholdMs } = this.profile; + + return { + count: n, + minMs: lags[0], + maxMs: lags[n - 1], + avgMs: lags.reduce((s, v) => s + v, 0) / n, + p50Ms: percentile(50), + p95Ms: percentile(95), + p99Ms: percentile(99), + degradedCount: lags.filter(v => v > alertThresholdMs).length, + criticalCount: lags.filter(v => v > criticalThresholdMs).length, + saturationCount: lags.filter(v => v > saturationThresholdMs).length, + }; + } + + get sampleCount(): number { + return this.samples.length; + } + + get isDegraded(): boolean { + return this.consecutiveDegraded >= this.profile.maxConsecutiveDegraded; + } + + /** Clear all samples and reset degradation counter. */ + reset(): void { + this.samples = []; + this.consecutiveDegraded = 0; + } +} + +/** Default warning callback: logs at WARN level. */ +export function defaultWarningCallback(stats: LagStats): void { + logger.warn( + 'Event-loop lag WARNING: p95=%.1fms, max=%.1fms, degraded=%d/%d samples', + stats.p95Ms, stats.maxMs, stats.degradedCount, stats.count + ); +} + +/** Default critical callback: logs at ERROR level. */ +export function defaultCriticalCallback(stats: LagStats): void { + logger.error( + 'Event-loop lag CRITICAL: p95=%.1fms, p99=%.1fms, max=%.1fms', + stats.p95Ms, stats.p99Ms, stats.maxMs + ); +} + +/** Default saturation callback: logs at CRITICAL level with alarm phrasing. */ +export function defaultSaturationCallback(stats: LagStats): void { + logger.critical( + 'Event-loop SATURATION ALARM: avg=%.1fms, p99=%.1fms, saturation_count=%d', + stats.avgMs, stats.p99Ms, stats.saturationCount + ); +}