From ca346916c1683279f18526358e953aa87bc1879c Mon Sep 17 00:00:00 2001 From: Anso Date: Sun, 31 May 2026 16:00:00 -0400 Subject: [PATCH] fix(auto-update): paid-gate execute route and harden image-check watchdog (#1257) * fix(auto-update): paid-gate execute route and harden image-check watchdog Auto-update execution is a paid capability, but POST /api/auto-update/execute was reachable by any admin regardless of license. Add the paid guard so it matches the rest of the surface (scheduled-task management and fleet refresh). The scheduler dispatch to remote nodes still works because the controlling instance forwards its tier with the request. Restrict GET /api/image-updates/fleet to admins. The single-node status endpoint that drives the sidebar update dot stays open to all roles. Replace the image-check watchdog timer that released the run lock after five minutes. On a healthy but slow scan it let a manual refresh start a second concurrent check, duplicating notifications and racing the status writes. The scan now owns its lock for its full duration, and every Docker socket and filesystem read is bounded so a wedged daemon or mount cannot stall a scan forever. * test(auto-update): assert the debug skip-log branch in the image-check guard The concurrency-guard test covered the warn branch for a trigger arriving past the long-run threshold but never exercised the developer-mode debug skip log. Add a case that enables developer mode and asserts the debug line fires for a mid-scan trigger under the threshold. --- .../__tests__/image-update-service.test.ts | 147 +++++++++++++++--- .../__tests__/image-updates-routes.test.ts | 74 ++++++++- backend/src/routes/imageUpdates.ts | 4 +- backend/src/services/ImageUpdateService.ts | 61 ++++++-- 4 files changed, 248 insertions(+), 38 deletions(-) diff --git a/backend/src/__tests__/image-update-service.test.ts b/backend/src/__tests__/image-update-service.test.ts index 5dfd24d7..fb4a2711 100644 --- a/backend/src/__tests__/image-update-service.test.ts +++ b/backend/src/__tests__/image-update-service.test.ts @@ -143,6 +143,25 @@ describe('ImageUpdateService - image ref parsing (via checkImage)', () => { expect(result.error).toContain('Failed to inspect local image'); }); + it('bounds a hung local inspect instead of hanging the scan', async () => { + // A wedged Docker socket must not stall the check forever: withTimeout + // rejects the inspect, the existing catch turns it into an error result. + const docker = { + getDocker: () => ({ + getImage: () => ({ inspect: vi.fn().mockImplementation(() => new Promise(() => { /* never resolves */ })) }), + }), + } as any; + const orig = (ImageUpdateService as any).SOCKET_TIMEOUT_MS; + (ImageUpdateService as any).SOCKET_TIMEOUT_MS = 20; + try { + const result = await service.checkImage(docker, 'nginx:latest'); + expect(result.hasUpdate).toBe(false); + expect(result.error).toContain('Failed to inspect local image'); + } finally { + (ImageUpdateService as any).SOCKET_TIMEOUT_MS = orig; + } + }); + it('returns { hasUpdate: false } when no RepoDigests match', async () => { // Empty RepoDigests means locally built image const docker = makeMockDocker([]); @@ -516,21 +535,20 @@ services: }); }); -// ── check() timeout ───────────────────────────────────────────────────── +// ── check() concurrency guard ─────────────────────────────────────────── -describe('ImageUpdateService - check() timeout', () => { +describe('ImageUpdateService - check() concurrency guard', () => { beforeEach(() => { vi.clearAllMocks(); (ImageUpdateService as any).instance = undefined; }); - it('releases isRunning lock after CHECK_TIMEOUT_MS', async () => { - // Override the module-level DatabaseService mock to return a node + async function stubDbWithLocalNode(developerMode: '0' | '1' = '0') { const dbModule = await import('../services/DatabaseService'); - const origGetInstance = dbModule.DatabaseService.getInstance; + const orig = dbModule.DatabaseService.getInstance; dbModule.DatabaseService.getInstance = (() => ({ - getGlobalSettings: () => ({ developer_mode: '0' }), + getGlobalSettings: () => ({ developer_mode: developerMode }), getNodes: () => [{ type: 'local', id: 1, name: 'local', mode: 'proxy', compose_dir: '/tmp/compose', is_default: true, status: 'online', created_at: 1 }], upsertStackUpdateStatus: mockUpsertStackUpdateStatus, getStackUpdateStatus: mockGetStackUpdateStatus, @@ -539,33 +557,120 @@ describe('ImageUpdateService - check() timeout', () => { setSystemState: mockSetSystemState, addNotificationHistory: mockAddNotificationHistory, })) as unknown as typeof dbModule.DatabaseService.getInstance; + return () => { dbModule.DatabaseService.getInstance = orig; }; + } + it('does not start a second check body while one is in flight', async () => { + const restoreDb = await stubDbWithLocalNode(); const service = ImageUpdateService.getInstance(); - // Make checkNode hang indefinitely so the timeout fires - (service as any).checkNode = vi.fn().mockImplementation(() => + // checkNode never resolves: simulate a scan that overruns / a wedged socket. + const checkNodeMock = vi.fn().mockImplementation(() => new Promise(() => { /* never resolves */ }) ); + (service as any).checkNode = checkNodeMock; - // Override timeout to 100ms for fast test - const orig = (ImageUpdateService as any).CHECK_TIMEOUT_MS; - (ImageUpdateService as any).CHECK_TIMEOUT_MS = 100; + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + const skipWarn = /running for \d+ minute/; - // Don't await; this will hang intentionally - const checkPromise = (service as any).check(); - - // Let microtasks flush so check() enters its body + const first = (service as any).check(); await new Promise(r => setTimeout(r, 10)); expect(service.isChecking()).toBe(true); + expect(checkNodeMock).toHaveBeenCalledTimes(1); - // Wait for timeout to fire - await new Promise(r => setTimeout(r, 200)); + // A concurrent trigger (e.g. a manual refresh) under the long-run threshold + // must be a silent no-op: no second body, no warning. + await (service as any).check(); + expect(checkNodeMock).toHaveBeenCalledTimes(1); + expect(service.isChecking()).toBe(true); + expect(warnSpy.mock.calls.some(c => skipWarn.test(String(c[0])))).toBe(false); - expect(service.isChecking()).toBe(false); + // Past the long-run threshold the trigger warns (operator signal) but still + // must not spawn a concurrent body. + const orig = (ImageUpdateService as any).CHECK_TIMEOUT_MS; + (ImageUpdateService as any).CHECK_TIMEOUT_MS = 1; + await new Promise(r => setTimeout(r, 5)); + await (service as any).check(); + expect(checkNodeMock).toHaveBeenCalledTimes(1); + expect(service.isChecking()).toBe(true); + expect(warnSpy.mock.calls.some(c => skipWarn.test(String(c[0])))).toBe(true); - // Cleanup (ImageUpdateService as any).CHECK_TIMEOUT_MS = orig; - dbModule.DatabaseService.getInstance = origGetInstance; - checkPromise.catch(() => {}); + warnSpy.mockRestore(); + restoreDb(); + first.catch(() => {}); + }); + + it('treats a manual refresh during an in-flight check as a no-op', async () => { + const restoreDb = await stubDbWithLocalNode(); + const service = ImageUpdateService.getInstance(); + const checkNodeMock = vi.fn().mockImplementation(() => + new Promise(() => { /* never resolves */ }) + ); + (service as any).checkNode = checkNodeMock; + + const first = (service as any).check(); + await new Promise(r => setTimeout(r, 10)); + expect(checkNodeMock).toHaveBeenCalledTimes(1); + + // This is the exact regression the guard replaces: a manual refresh firing + // while a scan is in flight. It reports it fired (the cooldown is clear) but + // the in-check guard prevents a second concurrent scan body. + const triggered = service.triggerManualRefresh(); + await new Promise(r => setTimeout(r, 10)); + expect(triggered).toBe(true); + expect(checkNodeMock).toHaveBeenCalledTimes(1); + expect(service.isChecking()).toBe(true); + + restoreDb(); + first.catch(() => {}); + }); + + it('logs a debug skip line for a mid-scan trigger when developer mode is on', async () => { + const restoreDb = await stubDbWithLocalNode('1'); + // isDebugEnabled short-circuits to false under NODE_ENV=test unless DATA_DIR + // is set; set it so the developer_mode flag is actually consulted. + const prevDataDir = process.env.DATA_DIR; + process.env.DATA_DIR = prevDataDir ?? '/tmp/image-update-debug-test'; + const logSpy = vi.spyOn(console, 'log').mockImplementation(() => {}); + try { + const service = ImageUpdateService.getInstance(); + const checkNodeMock = vi.fn().mockImplementation(() => + new Promise(() => { /* never resolves */ }) + ); + (service as any).checkNode = checkNodeMock; + + const first = (service as any).check(); + await new Promise(r => setTimeout(r, 10)); + + // Under the long-run threshold with developer mode on, the skipped trigger + // takes the debug branch rather than the WARN branch. + await (service as any).check(); + expect(checkNodeMock).toHaveBeenCalledTimes(1); + expect(logSpy.mock.calls.some(c => /Check already in progress; skipping/.test(String(c[0])))).toBe(true); + + first.catch(() => {}); + } finally { + logSpy.mockRestore(); + if (prevDataDir === undefined) delete process.env.DATA_DIR; else process.env.DATA_DIR = prevDataDir; + restoreDb(); + } + }); + + it('releases the lock when a check finishes and allows the next run', async () => { + const restoreDb = await stubDbWithLocalNode(); + const service = ImageUpdateService.getInstance(); + const checkNodeMock = vi.fn().mockResolvedValue(undefined); + (service as any).checkNode = checkNodeMock; + + await (service as any).check(); + expect(service.isChecking()).toBe(false); + expect(checkNodeMock).toHaveBeenCalledTimes(1); + + // A fresh trigger after completion runs a new body. + await (service as any).check(); + expect(checkNodeMock).toHaveBeenCalledTimes(2); + + restoreDb(); }); }); diff --git a/backend/src/__tests__/image-updates-routes.test.ts b/backend/src/__tests__/image-updates-routes.test.ts index 83d85d1b..d251299b 100644 --- a/backend/src/__tests__/image-updates-routes.test.ts +++ b/backend/src/__tests__/image-updates-routes.test.ts @@ -6,7 +6,9 @@ import { describe, it, expect, beforeAll, afterAll, vi } from 'vitest'; import request from 'supertest'; import bcrypt from 'bcrypt'; -import { setupTestDb, cleanupTestDb, loginAsTestAdmin } from './helpers/setupTestDb'; +import jwt from 'jsonwebtoken'; +import { setupTestDb, cleanupTestDb, loginAsTestAdmin, TEST_JWT_SECRET } from './helpers/setupTestDb'; +import { PROXY_TIER_HEADER, PROXY_VARIANT_HEADER } from '../services/license-headers'; let tmpDir: string; let app: import('express').Express; @@ -87,6 +89,13 @@ describe('GET /api/image-updates/fleet', () => { expect(res.status).toBe(401); }); + it('rejects non-admin users with 403', async () => { + // The cross-node aggregation is part of the admin-only readiness surface; + // the single-node GET / endpoint stays open for the sidebar update dot. + const res = await request(app).get('/api/image-updates/fleet').set('Cookie', viewerCookie); + expect(res.status).toBe(403); + }); + it('returns the fleet-wide aggregation map', async () => { const res = await request(app).get('/api/image-updates/fleet').set('Cookie', adminCookie); expect(res.status).toBe(200); @@ -156,6 +165,69 @@ describe('POST /api/auto-update/execute', () => { expect(res.status).toBe(403); }); + it('rejects a Community-tier admin with 403 PAID_REQUIRED', async () => { + // Auto-update execution is a paid capability; an admin on a Community + // license must not be able to drive it directly through the API. + const { LicenseService } = await import('../services/LicenseService'); + const tierSpy = vi.spyOn(LicenseService.getInstance(), 'getTier').mockReturnValue('community'); + try { + const res = await request(app) + .post('/api/auto-update/execute') + .set('Cookie', adminCookie) + .send({ target: '*' }); + expect(res.status).toBe(403); + expect(res.body.code).toBe('PAID_REQUIRED'); + } finally { + tierSpy.mockRestore(); + vi.spyOn(LicenseService.getInstance(), 'getTier').mockReturnValue('paid'); + } + }); + + it('honors a paid proxy tier header from a node_proxy caller on a Community runtime', async () => { + // The scheduler dispatches to a remote's /execute with a node_proxy Bearer + // token and the controlling instance's tier header. A Community-licensed + // remote runtime must still run the update because the trusted header, not + // the local license, decides entitlement. + const { LicenseService } = await import('../services/LicenseService'); + const tierSpy = vi.spyOn(LicenseService.getInstance(), 'getTier').mockReturnValue('community'); + const proxyToken = jwt.sign({ scope: 'node_proxy' }, TEST_JWT_SECRET, { expiresIn: '5m' }); + try { + const res = await request(app) + .post('/api/auto-update/execute') + .set('Authorization', `Bearer ${proxyToken}`) + .set(PROXY_TIER_HEADER, 'paid') + .set(PROXY_VARIANT_HEADER, 'admiral') + .send({ target: '*' }); + // Gate passes: no stacks on the fresh instance, so the handler returns + // the "no stacks found" summary rather than a 403. + expect(res.status).toBe(200); + expect(typeof res.body.result).toBe('string'); + } finally { + tierSpy.mockRestore(); + vi.spyOn(LicenseService.getInstance(), 'getTier').mockReturnValue('paid'); + } + }); + + it('rejects a node_proxy caller whose tier header is community with 403', async () => { + // The trusted header, not the local license, decides entitlement: a paid + // local runtime must still 403 when the controlling instance is Community. + const { LicenseService } = await import('../services/LicenseService'); + const tierSpy = vi.spyOn(LicenseService.getInstance(), 'getTier').mockReturnValue('paid'); + const proxyToken = jwt.sign({ scope: 'node_proxy' }, TEST_JWT_SECRET, { expiresIn: '5m' }); + try { + const res = await request(app) + .post('/api/auto-update/execute') + .set('Authorization', `Bearer ${proxyToken}`) + .set(PROXY_TIER_HEADER, 'community') + .send({ target: '*' }); + expect(res.status).toBe(403); + expect(res.body.code).toBe('PAID_REQUIRED'); + } finally { + tierSpy.mockRestore(); + vi.spyOn(LicenseService.getInstance(), 'getTier').mockReturnValue('paid'); + } + }); + it('rejects missing target with 400', async () => { const res = await request(app) .post('/api/auto-update/execute') diff --git a/backend/src/routes/imageUpdates.ts b/backend/src/routes/imageUpdates.ts index 5a9e2d35..703d6b48 100644 --- a/backend/src/routes/imageUpdates.ts +++ b/backend/src/routes/imageUpdates.ts @@ -52,7 +52,8 @@ imageUpdatesRouter.get('/status', authMiddleware, (_req: Request, res: Response) res.json({ checking: ImageUpdateService.getInstance().isChecking() }); }); -imageUpdatesRouter.get('/fleet', authMiddleware, async (_req: Request, res: Response): Promise => { +imageUpdatesRouter.get('/fleet', authMiddleware, async (req: Request, res: Response): Promise => { + if (!requireAdmin(req, res)) return; try { const result = await CacheService.getInstance().getOrFetch>>( FLEET_UPDATE_CACHE_KEY, @@ -197,6 +198,7 @@ export const autoUpdateRouter = Router(); autoUpdateRouter.post('/execute', authMiddleware, async (req: Request, res: Response): Promise => { if (!requireAdmin(req, res)) return; + if (!requirePaid(req, res)) return; try { const { target } = req.body as { target?: string }; console.log(`[AutoUpdate] Execute requested: target="${sanitizeForLog(target || '')}"`); diff --git a/backend/src/services/ImageUpdateService.ts b/backend/src/services/ImageUpdateService.ts index e2666f3b..ab7ffbe6 100644 --- a/backend/src/services/ImageUpdateService.ts +++ b/backend/src/services/ImageUpdateService.ts @@ -94,13 +94,15 @@ export class ImageUpdateService { private intervalId: NodeJS.Timeout | null = null; private startupTimeoutId: NodeJS.Timeout | null = null; private isRunning = false; + private checkStartedAt = 0; private lastManualRefreshAt = 0; private static readonly INTERVAL_MS = 6 * 60 * 60 * 1000; // 6 hours private static readonly STARTUP_DELAY_MS = 2 * 60 * 1000; // 2 min after boot private static readonly MANUAL_COOLDOWN_MS = 2 * 60 * 1000; // 2 min between manual triggers private static readonly INTER_IMAGE_DELAY_MS = 300; // be polite to registries - private static readonly CHECK_TIMEOUT_MS = 5 * 60 * 1000; // 5 min overall cap per scan + private static readonly CHECK_TIMEOUT_MS = 5 * 60 * 1000; // threshold for the "running long" skip warning + private static readonly SOCKET_TIMEOUT_MS = 30 * 1000; // per-call cap on Docker socket / filesystem reads public static get manualCooldownMinutes(): number { return ImageUpdateService.MANUAL_COOLDOWN_MS / (60 * 1000); @@ -154,16 +156,28 @@ export class ImageUpdateService { // ─── Core check ────────────────────────────────────────────────────────── private async check() { - if (this.isRunning) return; + // The finally block is the sole owner of isRunning, so a scan that + // overruns can never have its lock released out from under it. A + // previous fixed timer cleared the lock after CHECK_TIMEOUT_MS, which + // let a manual refresh start a second concurrent check on a healthy but + // slow scan, duplicating notifications and racing the status writes. + // Registry calls are bounded (10s) and the Docker/filesystem reads are + // wrapped in withTimeout, so the scan body always settles and the + // finally releases the lock; the only thing the guard below protects + // against is a concurrent trigger arriving mid-scan. + if (this.isRunning) { + const elapsedMs = Date.now() - this.checkStartedAt; + if (elapsedMs >= ImageUpdateService.CHECK_TIMEOUT_MS) { + console.warn(`[ImageUpdateService] A check has been running for ${Math.round(elapsedMs / 60_000)} minute(s); skipping this trigger. The Docker socket may be unresponsive.`); + } else if (isDebugEnabled()) { + console.log('[ImageUpdateService:debug] Check already in progress; skipping this trigger.'); + } + return; + } this.isRunning = true; + this.checkStartedAt = Date.now(); console.log('[ImageUpdateService] Starting image update check...'); - const checkTimeout = setTimeout(() => { - console.warn('[ImageUpdateService] Check timed out after ' + - `${ImageUpdateService.CHECK_TIMEOUT_MS / 60_000} minutes; releasing lock`); - this.isRunning = false; - }, ImageUpdateService.CHECK_TIMEOUT_MS); - try { const db = DatabaseService.getInstance(); // Only check local nodes - remote nodes run their own instance @@ -179,7 +193,6 @@ export class ImageUpdateService { } catch (e) { console.error('[ImageUpdateService] Check failed:', e); } finally { - clearTimeout(checkTimeout); this.isRunning = false; } } @@ -190,7 +203,7 @@ export class ImageUpdateService { const composeDir = path.resolve(NodeRegistry.getInstance().getComposeDir(nodeId)); // Phase 1: Filesystem discovery (all stacks with compose files) - const stacks = await fs.getStacks(); + const stacks = await withTimeout(fs.getStacks(), ImageUpdateService.SOCKET_TIMEOUT_MS, 'getStacks'); const stackImages = new Map>(); for (const name of stacks) stackImages.set(name, new Set()); @@ -201,14 +214,14 @@ export class ImageUpdateService { // Phase 2: Parse compose files for image refs for (const stackName of stacks) { try { - const content = await fs.getStackContent(stackName); + const content = await withTimeout(fs.getStackContent(stackName), ImageUpdateService.SOCKET_TIMEOUT_MS, 'getStackContent'); // Load .env for variable resolution (best-effort) let envVars: Record = {}; try { - const hasEnv = await fs.envExists(stackName); + const hasEnv = await withTimeout(fs.envExists(stackName), ImageUpdateService.SOCKET_TIMEOUT_MS, 'envExists'); if (hasEnv) { - const envContent = await fs.getEnvContent(stackName); + const envContent = await withTimeout(fs.getEnvContent(stackName), ImageUpdateService.SOCKET_TIMEOUT_MS, 'getEnvContent'); envVars = loadDotEnv(envContent); } } catch { @@ -235,7 +248,7 @@ export class ImageUpdateService { // Phase 3: Container augmentation (captures actual deployed image tags) try { - const containers = await docker.getAllContainers(); + const containers = await withTimeout(docker.getAllContainers(), ImageUpdateService.SOCKET_TIMEOUT_MS, 'getAllContainers'); for (const c of containers) { const workingDir: string | undefined = c.Labels?.['com.docker.compose.project.working_dir']; if (!workingDir) continue; @@ -367,7 +380,7 @@ export class ImageUpdateService { // Get local digest from RepoDigests let localDigest: string | null = null; try { - const inspect = await docker.getDocker().getImage(imageRef).inspect(); + const inspect = await withTimeout(docker.getDocker().getImage(imageRef).inspect(), ImageUpdateService.SOCKET_TIMEOUT_MS, 'inspect'); const repoDigests: string[] = inspect.RepoDigests ?? []; for (const rd of repoDigests) { @@ -402,3 +415,21 @@ export class ImageUpdateService { function sleep(ms: number): Promise { return new Promise(resolve => setTimeout(resolve, ms)); } + +/** + * Reject after `ms` if `p` has not settled. Docker socket and filesystem reads + * have no built-in timeout, so without this a wedged daemon would hang a scan + * forever and hold the run lock until the process restarts. The rejecting await + * lets the scan body unwind so the `finally` releases the lock and the next + * interval can retry. Handlers are attached to `p` so a late settle does not + * surface as an unhandled rejection. + */ +function withTimeout(p: Promise, ms: number, label: string): Promise { + return new Promise((resolve, reject) => { + const timer = setTimeout(() => reject(new Error(`${label} timed out after ${ms}ms`)), ms); + p.then( + (value) => { clearTimeout(timer); resolve(value); }, + (err) => { clearTimeout(timer); reject(err); }, + ); + }); +}