From 72b6cdd0a3afe72ec332c71a2f45000aee957adc Mon Sep 17 00:00:00 2001 From: Anso Date: Wed, 6 May 2026 11:21:37 -0400 Subject: [PATCH] fix: suppress ERROR logging for missing .env files in image update scan (#936) * fix: suppress ERROR logging for missing .env files in image update scan The ImageUpdateService logged a full ERROR stack trace for every stack without a .env file, which is a normal and expected configuration. Also added a 5-minute check timeout, developer_mode diagnostic logging, and proper startup timeout cleanup. * fix: add missing Node fields in test mock to satisfy tsc strict checking * fix: remove unused variables to satisfy ESLint no-unused-vars --- .../__tests__/image-update-service.test.ts | 265 +++++++++++++++++- backend/src/services/FileSystemService.ts | 6 +- backend/src/services/ImageUpdateService.ts | 38 ++- 3 files changed, 302 insertions(+), 7 deletions(-) diff --git a/backend/src/__tests__/image-update-service.test.ts b/backend/src/__tests__/image-update-service.test.ts index 641312d8..1105421a 100644 --- a/backend/src/__tests__/image-update-service.test.ts +++ b/backend/src/__tests__/image-update-service.test.ts @@ -11,7 +11,7 @@ const { mockGetStackUpdateStatus, mockUpsertStackUpdateStatus, mockClearStackUpdateStatus, mockGetSystemState, mockSetSystemState, mockAddNotificationHistory, mockDispatchAlert, - mockGetStacks, mockGetStackContent, mockGetEnvContent, + mockGetStacks, mockGetStackContent, mockGetEnvContent, mockEnvExists, mockGetAllContainers, } = vi.hoisted(() => ({ mockGetAuthForRegistry: vi.fn().mockResolvedValue(null), @@ -25,6 +25,7 @@ const { mockGetStacks: vi.fn().mockResolvedValue([]), mockGetStackContent: vi.fn().mockResolvedValue(''), mockGetEnvContent: vi.fn().mockRejectedValue(new Error('no env')), + mockEnvExists: vi.fn().mockResolvedValue(false), mockGetAllContainers: vi.fn().mockResolvedValue([]), })); @@ -65,6 +66,7 @@ vi.mock('../services/FileSystemService', () => ({ getStacks: mockGetStacks, getStackContent: mockGetStackContent, getEnvContent: mockGetEnvContent, + envExists: mockEnvExists, }), }, })); @@ -444,3 +446,264 @@ services: })); }); }); + +// ── .env file handling ────────────────────────────────────────────────── + +describe('ImageUpdateService - .env file handling in checkNode', () => { + const COMPOSE = ` +services: + app: + image: nginx:latest +`; + + const fakeDb = () => ({ + getStackUpdateStatus: mockGetStackUpdateStatus, + upsertStackUpdateStatus: mockUpsertStackUpdateStatus, + clearStackUpdateStatus: mockClearStackUpdateStatus, + getSystemState: mockGetSystemState, + setSystemState: mockSetSystemState, + addNotificationHistory: mockAddNotificationHistory, + }); + + function stubCheckImage(service: ImageUpdateService, hasUpdate: boolean) { + (service as any).checkImage = vi.fn().mockResolvedValue({ hasUpdate }); + } + + beforeEach(() => { + vi.clearAllMocks(); + (ImageUpdateService as any).instance = undefined; + mockGetSystemState.mockReturnValue('1'); + mockGetStacks.mockResolvedValue(['stackA']); + mockGetStackContent.mockResolvedValue(COMPOSE); + mockGetAllContainers.mockResolvedValue([]); + mockGetEnvContent.mockRejectedValue(new Error('no env')); + mockEnvExists.mockResolvedValue(false); + }); + + it('skips getEnvContent when envExists returns false', async () => { + mockEnvExists.mockResolvedValue(false); + const service = ImageUpdateService.getInstance(); + stubCheckImage(service, false); + + await (service as any).checkNode(1, 'local', fakeDb()); + + expect(mockEnvExists).toHaveBeenCalledWith('stackA'); + expect(mockGetEnvContent).not.toHaveBeenCalled(); + }); + + it('reads .env when envExists returns true', async () => { + mockEnvExists.mockResolvedValue(true); + mockGetEnvContent.mockResolvedValue('IMAGE_TAG=1.0'); + const service = ImageUpdateService.getInstance(); + stubCheckImage(service, false); + + await (service as any).checkNode(1, 'local', fakeDb()); + + expect(mockEnvExists).toHaveBeenCalledWith('stackA'); + expect(mockGetEnvContent).toHaveBeenCalledWith('stackA'); + }); + + it('continues gracefully when .env exists but is unreadable', async () => { + mockEnvExists.mockResolvedValue(true); + mockGetEnvContent.mockRejectedValue(new Error('EACCES: permission denied')); + const service = ImageUpdateService.getInstance(); + stubCheckImage(service, false); + + await (service as any).checkNode(1, 'local', fakeDb()); + + // Should not throw; should still complete and write status + expect(mockUpsertStackUpdateStatus).toHaveBeenCalled(); + }); +}); + +// ── check() timeout ───────────────────────────────────────────────────── + +describe('ImageUpdateService - check() timeout', () => { + + 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 + const dbModule = await import('../services/DatabaseService'); + const origGetInstance = dbModule.DatabaseService.getInstance; + dbModule.DatabaseService.getInstance = (() => ({ + getGlobalSettings: () => ({ developer_mode: '0' }), + 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, + clearStackUpdateStatus: mockClearStackUpdateStatus, + getSystemState: mockGetSystemState, + setSystemState: mockSetSystemState, + addNotificationHistory: mockAddNotificationHistory, + })) as unknown as typeof dbModule.DatabaseService.getInstance; + + const service = ImageUpdateService.getInstance(); + // Make checkNode hang indefinitely so the timeout fires + (service as any).checkNode = vi.fn().mockImplementation(() => + new Promise(() => { /* never resolves */ }) + ); + + // Override timeout to 100ms for fast test + const orig = (ImageUpdateService as any).CHECK_TIMEOUT_MS; + (ImageUpdateService as any).CHECK_TIMEOUT_MS = 100; + + // Don't await; this will hang intentionally + const checkPromise = (service as any).check(); + + // Let microtasks flush so check() enters its body + await new Promise(r => setTimeout(r, 10)); + expect(service.isChecking()).toBe(true); + + // Wait for timeout to fire + await new Promise(r => setTimeout(r, 200)); + + expect(service.isChecking()).toBe(false); + + // Cleanup + (ImageUpdateService as any).CHECK_TIMEOUT_MS = orig; + dbModule.DatabaseService.getInstance = origGetInstance; + checkPromise.catch(() => {}); + }); +}); + +// ── stop() cancels startup timeout ────────────────────────────────────── + +describe('ImageUpdateService - stop() cancels startup timeout', () => { + beforeEach(() => { + vi.clearAllMocks(); + (ImageUpdateService as any).instance = undefined; + }); + + it('prevents check from firing after stop() is called during startup delay', async () => { + const service = ImageUpdateService.getInstance(); + const checkSpy = vi.spyOn(service as any, 'check'); + + service.start(); + service.stop(); + + // Wait past the startup delay to see if check fires + await new Promise(r => setTimeout(r, 100)); + + expect(checkSpy).not.toHaveBeenCalled(); + }); +}); + +// ── Stale stack pruning ───────────────────────────────────────────────── + +describe('ImageUpdateService - stale stack pruning', () => { + const COMPOSE = ` +services: + app: + image: nginx:latest +`; + + const fakeDb = () => ({ + getStackUpdateStatus: mockGetStackUpdateStatus, + upsertStackUpdateStatus: mockUpsertStackUpdateStatus, + clearStackUpdateStatus: mockClearStackUpdateStatus, + getSystemState: mockGetSystemState, + setSystemState: mockSetSystemState, + addNotificationHistory: mockAddNotificationHistory, + }); + + function stubCheckImage(service: ImageUpdateService, hasUpdate: boolean) { + (service as any).checkImage = vi.fn().mockResolvedValue({ hasUpdate }); + } + + beforeEach(() => { + vi.clearAllMocks(); + (ImageUpdateService as any).instance = undefined; + mockGetSystemState.mockReturnValue('1'); + mockGetStacks.mockResolvedValue(['stackA']); + mockGetStackContent.mockResolvedValue(COMPOSE); + mockGetAllContainers.mockResolvedValue([]); + mockEnvExists.mockResolvedValue(false); + }); + + it('prunes stale stacks no longer on disk', async () => { + // previousState has stackB which no longer exists on disk + mockGetStackUpdateStatus.mockReturnValue({ stackA: false, stackB: true }); + const service = ImageUpdateService.getInstance(); + stubCheckImage(service, false); + + await (service as any).checkNode(1, 'local', fakeDb()); + + expect(mockClearStackUpdateStatus).toHaveBeenCalledWith(1, 'stackB'); + }); + + it('does not prune stacks still on disk', async () => { + mockGetStackUpdateStatus.mockReturnValue({ stackA: false }); + const service = ImageUpdateService.getInstance(); + stubCheckImage(service, false); + + await (service as any).checkNode(1, 'local', fakeDb()); + + expect(mockClearStackUpdateStatus).not.toHaveBeenCalled(); + }); +}); + +// ── Container augmentation filtering ──────────────────────────────────── + +describe('ImageUpdateService - container augmentation filtering', () => { + const COMPOSE = ` +services: + app: + image: nginx:latest +`; + + const fakeDb = () => ({ + getStackUpdateStatus: mockGetStackUpdateStatus, + upsertStackUpdateStatus: mockUpsertStackUpdateStatus, + clearStackUpdateStatus: mockClearStackUpdateStatus, + getSystemState: mockGetSystemState, + setSystemState: mockSetSystemState, + addNotificationHistory: mockAddNotificationHistory, + }); + + beforeEach(() => { + vi.clearAllMocks(); + (ImageUpdateService as any).instance = undefined; + mockGetSystemState.mockReturnValue('1'); + mockGetStacks.mockResolvedValue(['stackA']); + mockGetStackContent.mockResolvedValue(COMPOSE); + mockEnvExists.mockResolvedValue(false); + }); + + it('includes containers whose working_dir matches compose dir', async () => { + mockGetAllContainers.mockResolvedValue([ + { + Labels: { 'com.docker.compose.project.working_dir': '/tmp/compose/stackA' }, + Image: 'nginx:1.25', + }, + ]); + const service = ImageUpdateService.getInstance(); + const checkImageSpy = vi.fn().mockResolvedValue({ hasUpdate: false }); + (service as any).checkImage = checkImageSpy; + + await (service as any).checkNode(1, 'local', fakeDb()); + + // Should check both the compose image and the container image + const checkedImages = checkImageSpy.mock.calls.map((c: any[]) => c[1]); + expect(checkedImages).toContain('nginx:1.25'); + }); + + it('excludes containers outside compose dir', async () => { + mockGetAllContainers.mockResolvedValue([ + { + Labels: { 'com.docker.compose.project.working_dir': '/other/place/app' }, + Image: 'someapp:v2', + }, + ]); + const service = ImageUpdateService.getInstance(); + const checkImageSpy = vi.fn().mockResolvedValue({ hasUpdate: false }); + (service as any).checkImage = checkImageSpy; + + await (service as any).checkNode(1, 'local', fakeDb()); + + const checkedImages = checkImageSpy.mock.calls.map((c: any[]) => c[1]); + expect(checkedImages).not.toContain('someapp:v2'); + }); +}); diff --git a/backend/src/services/FileSystemService.ts b/backend/src/services/FileSystemService.ts index 699cf1a1..6d0b5eba 100644 --- a/backend/src/services/FileSystemService.ts +++ b/backend/src/services/FileSystemService.ts @@ -185,8 +185,10 @@ export class FileSystemService { try { return await fsPromises.readFile(envPath, 'utf-8'); } catch (error) { - console.error('Error reading env file:', error); - throw new Error(`Failed to read env file for stack: ${stackName}`); + if ((error as NodeJS.ErrnoException).code !== 'ENOENT') { + console.error('Error reading env file:', error); + } + throw error; } } diff --git a/backend/src/services/ImageUpdateService.ts b/backend/src/services/ImageUpdateService.ts index 8b6cc03a..1e6a56c9 100644 --- a/backend/src/services/ImageUpdateService.ts +++ b/backend/src/services/ImageUpdateService.ts @@ -91,6 +91,7 @@ export function extractImagesFromCompose( export class ImageUpdateService { private static instance: ImageUpdateService; private intervalId: NodeJS.Timeout | null = null; + private startupTimeoutId: NodeJS.Timeout | null = null; private isRunning = false; private lastManualRefreshAt = 0; @@ -98,6 +99,7 @@ export class ImageUpdateService { 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 public static get manualCooldownMinutes(): number { return ImageUpdateService.MANUAL_COOLDOWN_MS / (60 * 1000); @@ -114,11 +116,15 @@ export class ImageUpdateService { public start() { if (this.intervalId) return; - setTimeout(() => this.check(), ImageUpdateService.STARTUP_DELAY_MS); + this.startupTimeoutId = setTimeout(() => this.check(), ImageUpdateService.STARTUP_DELAY_MS); this.intervalId = setInterval(() => this.check(), ImageUpdateService.INTERVAL_MS); } public stop() { + if (this.startupTimeoutId) { + clearTimeout(this.startupTimeoutId); + this.startupTimeoutId = null; + } if (this.intervalId) { clearInterval(this.intervalId); this.intervalId = null; @@ -151,6 +157,12 @@ export class ImageUpdateService { this.isRunning = true; 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 @@ -166,6 +178,7 @@ export class ImageUpdateService { } catch (e) { console.error('[ImageUpdateService] Check failed:', e); } finally { + clearTimeout(checkTimeout); this.isRunning = false; } } @@ -180,6 +193,10 @@ export class ImageUpdateService { const stackImages = new Map>(); for (const name of stacks) stackImages.set(name, new Set()); + if (isDebugEnabled()) { + console.log(`[ImageUpdateService:debug] Node ${nodeId}: Phase 1 complete - ${stacks.length} stack(s) found`); + } + // Phase 2: Parse compose files for image refs for (const stackName of stacks) { try { @@ -188,10 +205,13 @@ export class ImageUpdateService { // Load .env for variable resolution (best-effort) let envVars: Record = {}; try { - const envContent = await fs.getEnvContent(stackName); - envVars = loadDotEnv(envContent); + const hasEnv = await fs.envExists(stackName); + if (hasEnv) { + const envContent = await fs.getEnvContent(stackName); + envVars = loadDotEnv(envContent); + } } catch { - // No .env file or unreadable; continue with process.env only + // .env file exists but unreadable; continue with process.env only } // Docker Compose precedence: host env overrides .env const merged: Record = { ...envVars }; @@ -207,6 +227,11 @@ export class ImageUpdateService { } } + if (isDebugEnabled()) { + const composeImageCount = [...stackImages.values()].reduce((sum, s) => sum + s.size, 0); + console.log(`[ImageUpdateService:debug] Node ${nodeId}: Phase 2 complete - ${composeImageCount} image(s) extracted from compose files`); + } + // Phase 3: Container augmentation (captures actual deployed image tags) try { const containers = await docker.getAllContainers(); @@ -230,6 +255,11 @@ export class ImageUpdateService { console.warn('[ImageUpdateService] Container augmentation failed:', e); } + if (isDebugEnabled()) { + const totalBeforeDedup = [...stackImages.values()].reduce((sum, s) => sum + s.size, 0); + console.log(`[ImageUpdateService:debug] Node ${nodeId}: Phase 3 complete - ${totalBeforeDedup} image(s) across all stacks (pre-dedup)`); + } + // Phase 4: Deduplicate and check all unique images const allImages = new Set(); for (const imgs of stackImages.values()) for (const img of imgs) allImages.add(img);