feat(stacks): in-process per-(nodeId, action) metrics + admin endpoint (#1196)

Sencho exports no telemetry by design (privacy-first posture). That left
operators with no answer for "why is this remote node slow today?"
except scrolling logs. The audit log records mutations but has no
latency information.

Adds StackOpMetricsService - a tiny singleton holding per-(nodeId, action)
counters and a 1000-sample ring buffer of latencies for p50/p95.
Exposed through GET /api/stack-metrics (admin-only) so operators can
pull the snapshot when debugging without touching disk or scrolling
journalctl. No external export; the data never leaves the process.

Wiring: deploy, down, restart, stop, start, update routes each capture
t0 at entry, set ok=true after the success path, and record() in a
finally block so failures count too. The record() call is cheap (one
Map lookup, one push, occasional shift on the bounded ring buffer)
and bounded in memory regardless of throughput.

Resolves M-4 from the stack-management audit.

API:
  GET /api/stack-metrics  (admin-only)
  Response: { entries: [{ nodeId, action, count, successCount,
              errorCount, avgMs, p50Ms, p95Ms }, ...] }
  Ordering: nodeId ascending, then action ascending.

Note on route mounting: /api/stack-metrics rather than the audit doc's
suggested /api/meta/stack-metrics because metaRouter is intentionally
mounted before authGate (public /api/health and /api/meta endpoints);
adding an admin-only route to that group would either bypass auth or
need a special inline gate that fights the existing structure. A
dedicated /api/stack-metrics router after authGate is cleaner.

Tests:
  - 9 unit tests in stack-op-metrics-service.test.ts: singleton,
    keyed-by-nodeId-action, p50/p95 math, ring-buffer cap at 1000,
    NaN/negative/Infinity rejection, ordering, reset.
  - 3 integration tests in stack-metrics-route.test.ts: 401 without
    auth, empty on fresh process, shape after recording.
This commit is contained in:
Anso
2026-05-24 16:07:54 -04:00
committed by GitHub
parent 60247d9c2e
commit 7ec6fe05bb
6 changed files with 313 additions and 2 deletions
@@ -0,0 +1,62 @@
/**
* Integration tests for GET /api/stack-metrics. Admin-only endpoint
* surfacing the in-process snapshot from StackOpMetricsService.
*/
import { describe, it, expect, beforeAll, afterAll, beforeEach, vi } from 'vitest';
import request from 'supertest';
import { setupTestDb, cleanupTestDb, loginAsTestAdmin } from './helpers/setupTestDb';
let tmpDir: string;
let app: import('express').Express;
let authCookie: string;
beforeAll(async () => {
tmpDir = await setupTestDb();
({ app } = await import('../index'));
authCookie = await loginAsTestAdmin(app);
});
afterAll(() => {
vi.restoreAllMocks();
cleanupTestDb(tmpDir);
});
beforeEach(async () => {
const { StackOpMetricsService } = await import('../services/StackOpMetricsService');
StackOpMetricsService.resetForTests();
});
describe('GET /api/stack-metrics', () => {
it('returns 401 without an auth cookie', async () => {
const res = await request(app).get('/api/stack-metrics');
expect(res.status).toBe(401);
});
it('returns an empty array on a fresh process', async () => {
const res = await request(app).get('/api/stack-metrics').set('Cookie', authCookie);
expect(res.status).toBe(200);
expect(res.body).toEqual({ entries: [] });
});
it('returns recorded entries with the expected shape', async () => {
const { StackOpMetricsService } = await import('../services/StackOpMetricsService');
const svc = StackOpMetricsService.getInstance();
svc.record(1, 'deploy', 100, true);
svc.record(1, 'deploy', 200, false);
svc.record(2, 'restart', 50, true);
const res = await request(app).get('/api/stack-metrics').set('Cookie', authCookie);
expect(res.status).toBe(200);
expect(res.body.entries).toHaveLength(2);
expect(res.body.entries[0]).toMatchObject({
nodeId: 1,
action: 'deploy',
count: 2,
successCount: 1,
errorCount: 1,
avgMs: 150,
});
expect(typeof res.body.entries[0].p50Ms).toBe('number');
expect(typeof res.body.entries[0].p95Ms).toBe('number');
});
});
@@ -0,0 +1,98 @@
/**
* Unit tests for StackOpMetricsService — the in-process per-(nodeId, action)
* counter + p50/p95 latency facility surfaced by GET /api/stack-metrics.
*/
import { describe, it, expect, beforeEach } from 'vitest';
import { StackOpMetricsService } from '../services/StackOpMetricsService';
beforeEach(() => {
StackOpMetricsService.resetForTests();
});
describe('StackOpMetricsService', () => {
it('returns a singleton', () => {
expect(StackOpMetricsService.getInstance()).toBe(StackOpMetricsService.getInstance());
});
it('starts empty', () => {
expect(StackOpMetricsService.getInstance().size()).toBe(0);
expect(StackOpMetricsService.getInstance().snapshot()).toEqual([]);
});
it('records counts split between success and error', () => {
const svc = StackOpMetricsService.getInstance();
svc.record(1, 'deploy', 100, true);
svc.record(1, 'deploy', 200, false);
svc.record(1, 'deploy', 300, true);
const entries = svc.snapshot();
expect(entries).toHaveLength(1);
expect(entries[0]).toMatchObject({
nodeId: 1,
action: 'deploy',
count: 3,
successCount: 2,
errorCount: 1,
avgMs: 200,
});
});
it('keys independently by (nodeId, action)', () => {
const svc = StackOpMetricsService.getInstance();
svc.record(1, 'deploy', 10, true);
svc.record(1, 'restart', 20, true);
svc.record(2, 'deploy', 30, true);
expect(svc.size()).toBe(3);
const entries = svc.snapshot();
expect(entries.map(e => `${e.nodeId}:${e.action}`)).toEqual([
'1:deploy', '1:restart', '2:deploy',
]);
});
it('computes p50 and p95 from recent samples', () => {
const svc = StackOpMetricsService.getInstance();
for (let i = 1; i <= 100; i++) {
svc.record(1, 'deploy', i, true);
}
const [entry] = svc.snapshot();
expect(entry.p50Ms).toBe(50);
expect(entry.p95Ms).toBe(95);
});
it('caps the sample ring buffer at 1000 to bound memory', () => {
const svc = StackOpMetricsService.getInstance();
for (let i = 1; i <= 1500; i++) {
svc.record(1, 'deploy', i, true);
}
const [entry] = svc.snapshot();
expect(entry.count).toBe(1500);
// p95 uses only the last 1000 samples (501..1500), so p95 = 501 + floor((1000-1) * 0.95) = 501 + 949 = 1450
expect(entry.p95Ms).toBe(1450);
});
it('ignores non-finite or negative durations', () => {
const svc = StackOpMetricsService.getInstance();
svc.record(1, 'deploy', NaN, true);
svc.record(1, 'deploy', -5, true);
svc.record(1, 'deploy', Infinity, true);
expect(svc.size()).toBe(0);
});
it('snapshot ordering: nodeId asc, then action asc', () => {
const svc = StackOpMetricsService.getInstance();
svc.record(3, 'start', 1, true);
svc.record(1, 'update', 1, true);
svc.record(2, 'deploy', 1, true);
svc.record(1, 'deploy', 1, true);
const keys = svc.snapshot().map(e => `${e.nodeId}:${e.action}`);
expect(keys).toEqual(['1:deploy', '1:update', '2:deploy', '3:start']);
});
it('resetForTests clears all state', () => {
const before = StackOpMetricsService.getInstance();
before.record(1, 'deploy', 100, true);
StackOpMetricsService.resetForTests();
expect(StackOpMetricsService.getInstance()).not.toBe(before);
expect(StackOpMetricsService.getInstance().size()).toBe(0);
});
});
+2
View File
@@ -49,6 +49,7 @@ import { containersRouter, portsRouter } from './routes/containers';
import { nodesRouter } from './routes/nodes';
import { stacksRouter } from './routes/stacks';
import { stackActivityRouter } from './routes/stackActivity';
import { stackMetricsRouter } from './routes/stackMetrics';
import { secretsRouter } from './routes/secrets';
// Suppress [DEP0060] DeprecationWarning emitted by http-proxy@1.18.1 which calls
@@ -141,6 +142,7 @@ app.use('/api/dashboard', dashboardRouter);
app.use('/api/nodes', nodesRouter);
app.use('/api/stacks', stackActivityRouter);
app.use('/api/stacks', stacksRouter);
app.use('/api/stack-metrics', stackMetricsRouter);
const { server, wss, pilotTunnelWss } = createServer(app);
attachUpgrade(server, { wss, pilotTunnelWss });
+19
View File
@@ -0,0 +1,19 @@
import { Router, type Request, type Response } from 'express';
import { requireAdmin } from '../middleware/tierGates';
import { StackOpMetricsService } from '../services/StackOpMetricsService';
export const stackMetricsRouter = Router();
/**
* Admin-only snapshot of in-process stack lifecycle metrics. No external
* export: this endpoint exists so an operator debugging "why is this remote
* node slow today?" can pull per-(nodeId, action) counts and latencies
* without scrolling logs.
*
* Mounted at /api/stack-metrics after the global authGate, so it inherits
* the standard session/Bearer auth surface like every other authed route.
*/
stackMetricsRouter.get('/', (req: Request, res: Response): void => {
if (!requireAdmin(req, res)) return;
res.json({ entries: StackOpMetricsService.getInstance().snapshot() });
});
+17 -2
View File
@@ -15,6 +15,7 @@ import { requirePermission, checkPermission } from '../middleware/permissions';
import { requirePaid, requireAdmin, effectiveTier } from '../middleware/tierGates';
import { NotificationService, type NotificationCategory } from '../services/NotificationService';
import { StackOpLockService, type StackOpAction } from '../services/StackOpLockService';
import { StackOpMetricsService, type StackOpAction as StackMetricAction } from '../services/StackOpMetricsService';
import { isValidGitSourcePath, isValidStackName, isValidServiceName, isPathWithinBase, isValidRelativeStackPath } from '../utils/validation';
import { getErrorMessage } from '../utils/errors';
import { isDebugEnabled } from '../utils/debug';
@@ -930,17 +931,19 @@ stacksRouter.post('/:stackName/deploy', async (req: Request, res: Response) => {
if (!(await requireStackExists(req.nodeId, stackName, res))) return;
// Lock held below. All early-returns must stay inside the try so finally fires.
if (!tryAcquireStackOpLock(req, res, stackName, 'deploy')) return;
const t0 = Date.now();
let ok = false;
try {
if (!(await runPolicyGate(req, res, stackName, req.nodeId))) return;
const skipScan = req.body?.skip_scan === true;
const debug = isDebugEnabled();
const atomic = effectiveTier(req) === 'paid';
if (debug) console.debug('[Stacks:debug] Deploy starting', { stackName, atomic, nodeId: req.nodeId });
const t0 = Date.now();
await ComposeService.getInstance(req.nodeId).deployStack(stackName, getTerminalWs(), atomic);
invalidateNodeCaches(req.nodeId);
dlog(`[Stacks] Deploy completed: ${sanitizeForLog(stackName)}`);
if (debug) console.debug(`[Stacks:debug] Deploy finished in ${Date.now() - t0}ms`);
ok = true;
res.json({ message: 'Deployed successfully' });
notifyActionSuccess('deploy_success', `${stackName} deployed`, stackName, req.user?.username ?? 'system');
if (!skipScan) {
@@ -968,6 +971,7 @@ stacksRouter.post('/:stackName/deploy', async (req: Request, res: Response) => {
}
} finally {
releaseStackOpLock(req, stackName);
StackOpMetricsService.getInstance().record(req.nodeId, 'deploy', Date.now() - t0, ok);
}
});
@@ -977,11 +981,14 @@ stacksRouter.post('/:stackName/down', async (req: Request, res: Response) => {
if (!(await requireStackExists(req.nodeId, stackName, res))) return;
// Lock held below. All early-returns must stay inside the try so finally fires.
if (!tryAcquireStackOpLock(req, res, stackName, 'down')) return;
const t0 = Date.now();
let ok = false;
try {
if (isDebugEnabled()) console.debug(`[Stacks:debug] Down starting`, { stackName: sanitizeForLog(stackName), nodeId: req.nodeId });
await ComposeService.getInstance(req.nodeId).runCommand(stackName, 'down', getTerminalWs());
invalidateNodeCaches(req.nodeId);
dlog(`[Stacks] Down completed: ${sanitizeForLog(stackName)}`);
ok = true;
res.json({ status: 'Command started' });
} catch (error: unknown) {
console.error('[Stacks] Down failed: %s', sanitizeForLog(stackName), error);
@@ -995,6 +1002,7 @@ stacksRouter.post('/:stackName/down', async (req: Request, res: Response) => {
}
} finally {
releaseStackOpLock(req, stackName);
StackOpMetricsService.getInstance().record(req.nodeId, 'down', Date.now() - t0, ok);
}
});
@@ -1066,6 +1074,8 @@ async function bulkContainerOp(
if (!requirePermission(req, res, 'stack:deploy', 'stack', stackName)) return;
// Lock held below. All early-returns must stay inside the try so finally fires.
if (!tryAcquireStackOpLock(req, res, stackName, action)) return;
const t0 = Date.now();
let ok = false;
try {
const titleCase = action.charAt(0).toUpperCase() + action.slice(1);
if (isDebugEnabled()) console.debug(`[Stacks:debug] ${titleCase} starting`, { stackName: sanitizeForLog(stackName), nodeId: req.nodeId });
@@ -1090,6 +1100,7 @@ async function bulkContainerOp(
invalidateNodeCaches(req.nodeId);
dlog(`[Stacks] ${titleCase} completed: ${sanitizeForLog(stackName)} (${outcome.count} containers)`);
ok = true;
res.json({ success: true, message: `${titleCase} completed via Engine API.` });
const { category, pastTense } = CONTAINER_ACTION_META[action];
notifyActionSuccess(category, `${stackName} ${pastTense}`, stackName, req.user?.username ?? 'system');
@@ -1100,6 +1111,7 @@ async function bulkContainerOp(
}
} finally {
releaseStackOpLock(req, stackName);
StackOpMetricsService.getInstance().record(req.nodeId, action as StackMetricAction, Date.now() - t0, ok);
}
}
@@ -1179,13 +1191,14 @@ stacksRouter.post('/:stackName/update', async (req: Request, res: Response) => {
if (!(await requireStackExists(req.nodeId, stackName, res))) return;
// Lock held below. All early-returns must stay inside the try so finally fires.
if (!tryAcquireStackOpLock(req, res, stackName, 'update')) return;
const t0 = Date.now();
let ok = false;
try {
if (!(await runPolicyGate(req, res, stackName, req.nodeId))) return;
const skipScan = req.body?.skip_scan === true;
const debug = isDebugEnabled();
const atomic = effectiveTier(req) === 'paid';
if (debug) console.debug('[Stacks:debug] Update starting', { stackName, atomic, nodeId: req.nodeId });
const t0 = Date.now();
await ComposeService.getInstance(req.nodeId).updateStack(stackName, getTerminalWs(), atomic);
DatabaseService.getInstance().clearStackUpdateStatus(req.nodeId, stackName);
invalidateNodeCaches(req.nodeId);
@@ -1199,6 +1212,7 @@ stacksRouter.post('/:stackName/update', async (req: Request, res: Response) => {
});
dlog(`[Stacks] Update completed: ${sanitizeForLog(stackName)}`);
if (debug) console.debug(`[Stacks:debug] Update finished in ${Date.now() - t0}ms`);
ok = true;
res.json({ status: 'Update completed' });
notifyActionSuccess('image_update_applied', `${stackName} updated`, stackName, req.user?.username ?? 'system');
if (!skipScan) {
@@ -1225,6 +1239,7 @@ stacksRouter.post('/:stackName/update', async (req: Request, res: Response) => {
}
} finally {
releaseStackOpLock(req, stackName);
StackOpMetricsService.getInstance().record(req.nodeId, 'update', Date.now() - t0, ok);
}
});
@@ -0,0 +1,115 @@
/**
* In-memory counters + latency samples for stack lifecycle operations.
* Internal-only - never exported to any external system. Surfaced to
* admins via GET /api/stack-metrics so operators have a way to debug
* "why is this remote node slow today?" without scrolling logs.
*
* State is process-local on purpose. A Sencho restart clears all metrics;
* the alternative (persisting to SQLite) would add write amplification
* to every lifecycle op for very little operator value.
*/
export type StackOpAction = 'deploy' | 'down' | 'restart' | 'stop' | 'start' | 'update';
interface StackOpStats {
count: number;
successCount: number;
errorCount: number;
totalMs: number;
/**
* Ring buffer of recent latencies (newest at the end). Capped at
* MAX_SAMPLES to bound memory regardless of throughput. p50/p95 are
* computed from this window on demand.
*/
recentSamples: number[];
}
export interface StackOpSnapshotEntry {
nodeId: number;
action: StackOpAction;
count: number;
successCount: number;
errorCount: number;
avgMs: number;
p50Ms: number;
p95Ms: number;
}
const MAX_SAMPLES = 1000;
function percentile(sorted: readonly number[], p: number): number {
if (sorted.length === 0) return 0;
const idx = Math.min(sorted.length - 1, Math.floor((sorted.length - 1) * p));
return sorted[idx];
}
export class StackOpMetricsService {
private static instance: StackOpMetricsService;
private readonly stats = new Map<string, StackOpStats>();
public static getInstance(): StackOpMetricsService {
if (!StackOpMetricsService.instance) {
StackOpMetricsService.instance = new StackOpMetricsService();
}
return StackOpMetricsService.instance;
}
public static resetForTests(): void {
this.instance = new StackOpMetricsService();
}
private key(nodeId: number, action: StackOpAction): string {
return `${nodeId}:${action}`;
}
/**
* Record one completed op. Call from the route layer after the lifecycle
* call resolves or rejects; `ok=false` for the rejection path.
*/
public record(nodeId: number, action: StackOpAction, durationMs: number, ok: boolean): void {
if (!Number.isFinite(durationMs) || durationMs < 0) return;
const k = this.key(nodeId, action);
let s = this.stats.get(k);
if (!s) {
s = { count: 0, successCount: 0, errorCount: 0, totalMs: 0, recentSamples: [] };
this.stats.set(k, s);
}
s.count += 1;
if (ok) s.successCount += 1;
else s.errorCount += 1;
s.totalMs += durationMs;
s.recentSamples.push(durationMs);
if (s.recentSamples.length > MAX_SAMPLES) {
// Drop oldest. Array.shift is O(n) but n is bounded to MAX_SAMPLES
// and this path is once-per-stack-op (low cadence).
s.recentSamples.shift();
}
}
public snapshot(): StackOpSnapshotEntry[] {
const out: StackOpSnapshotEntry[] = [];
for (const [key, s] of this.stats.entries()) {
const [nodeIdStr, action] = key.split(':');
const nodeId = Number(nodeIdStr);
if (!Number.isFinite(nodeId)) continue;
const sorted = [...s.recentSamples].sort((a, b) => a - b);
out.push({
nodeId,
action: action as StackOpAction,
count: s.count,
successCount: s.successCount,
errorCount: s.errorCount,
avgMs: s.count === 0 ? 0 : Math.round(s.totalMs / s.count),
p50Ms: percentile(sorted, 0.5),
p95Ms: percentile(sorted, 0.95),
});
}
// Stable ordering: nodeId asc, then action asc.
out.sort((a, b) => a.nodeId - b.nodeId || a.action.localeCompare(b.action));
return out;
}
public size(): number {
return this.stats.size;
}
}