Skip to content

Commit 0e004a7

Browse files
authored
fix(api): defer docker startup tasks until ready (#1952)
## Summary - move Docker startup work out of the Nest bootstrap critical path and schedule it only after the API is listening - replace the `@Timeout` decorators with a dedicated startup task helper that logs failures without blocking readiness - trim the temporary bootstrap progress logs while keeping the ready-signal and deferred Docker startup behavior intact - add focused coverage for delayed execution, rejection logging, and missing-provider behavior ## Testing - `pnpm --dir api test src/unraid-api/graph/resolvers/docker/docker-startup-tasks.spec.ts` - `pnpm --dir api type-check` <!-- This is an auto-generated comment: release notes by coderabbit.ai --> ## Summary by CodeRabbit * **Chores** * Increased application startup timeout budget (15s → 30s) to improve initialization robustness. * Added safeguards to prevent duplicate "process ready" signals and centralized readiness signaling. * **New Features** * Added a background startup task scheduler and listener to run template scanning and container digest refresh after the app is ready; failures are logged. * **Tests** * Added tests for startup task scheduling, execution timing, and failure logging. <!-- end of auto-generated comment: release notes by coderabbit.ai -->
1 parent 726ae51 commit 0e004a7

File tree

8 files changed

+254
-17
lines changed

8 files changed

+254
-17
lines changed

api/src/index.ts

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -30,8 +30,7 @@ import { StateManager } from '@app/store/watch/state-watch.js';
3030

3131
let server: NestFastifyApplication<RawServerDefault> | null = null;
3232

33-
// PM2 listen_timeout is 15 seconds (ecosystem.config.json)
34-
// We use 13 seconds as our total budget to ensure our timeout triggers before PM2 kills us
33+
// PM2 listen_timeout is 30 seconds (ecosystem.config.json)
3534
const TOTAL_STARTUP_BUDGET_MS = 30_000;
3635
// Reserve time for the NestJS bootstrap (the most critical and time-consuming operation)
3736
const BOOTSTRAP_RESERVED_MS = 20_000;
Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
export const APP_READY_EVENT = 'app.ready';
2+
3+
export interface AppReadyEvent {
4+
reason: 'nestjs-server-listening';
5+
}

api/src/unraid-api/graph/resolvers/docker/container-status.job.ts

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
import { Injectable, Logger, OnApplicationBootstrap } from '@nestjs/common';
2-
import { SchedulerRegistry, Timeout } from '@nestjs/schedule';
2+
import { SchedulerRegistry } from '@nestjs/schedule';
33

44
import { CronJob } from 'cron';
55

@@ -41,7 +41,6 @@ export class ContainerStatusJob {
4141
/**
4242
* Refresh container digests 5 seconds after application start.
4343
*/
44-
@Timeout(5_000)
4544
async refreshContainerDigestsAfterStartup() {
4645
if (!this.dockerConfigService.enabled()) return;
4746
await this.dockerManifestService.refreshDigests();
Lines changed: 123 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,123 @@
1+
import { Test } from '@nestjs/testing';
2+
3+
import { describe, expect, it, vi } from 'vitest';
4+
5+
import type { AppReadyEvent } from '@app/unraid-api/app/app-lifecycle.events.js';
6+
import { ContainerStatusJob } from '@app/unraid-api/graph/resolvers/docker/container-status.job.js';
7+
import {
8+
DockerStartupTasksListener,
9+
scheduleDockerStartupTasks,
10+
} from '@app/unraid-api/graph/resolvers/docker/docker-startup-tasks.js';
11+
import { DockerTemplateScannerService } from '@app/unraid-api/graph/resolvers/docker/docker-template-scanner.service.js';
12+
13+
describe('scheduleDockerStartupTasks', () => {
14+
it('schedules docker startup work after the provided delay', async () => {
15+
vi.useFakeTimers();
16+
17+
const bootstrapScan = vi.fn().mockResolvedValue(undefined);
18+
const refreshContainerDigestsAfterStartup = vi.fn().mockResolvedValue(undefined);
19+
const logger = {
20+
info: vi.fn(),
21+
warn: vi.fn(),
22+
};
23+
24+
scheduleDockerStartupTasks(
25+
{
26+
dockerTemplateScannerService: { bootstrapScan },
27+
containerStatusJob: { refreshContainerDigestsAfterStartup },
28+
},
29+
logger,
30+
250
31+
);
32+
33+
expect(bootstrapScan).not.toHaveBeenCalled();
34+
expect(refreshContainerDigestsAfterStartup).not.toHaveBeenCalled();
35+
36+
await vi.advanceTimersByTimeAsync(250);
37+
38+
expect(bootstrapScan).toHaveBeenCalledTimes(1);
39+
expect(refreshContainerDigestsAfterStartup).toHaveBeenCalledTimes(1);
40+
41+
vi.useRealTimers();
42+
});
43+
44+
it('warns when a background docker startup task rejects', async () => {
45+
vi.useFakeTimers();
46+
47+
const backgroundError = new Error('docker unavailable');
48+
const logger = {
49+
info: vi.fn(),
50+
warn: vi.fn(),
51+
};
52+
53+
scheduleDockerStartupTasks(
54+
{
55+
dockerTemplateScannerService: {
56+
bootstrapScan: vi.fn().mockRejectedValue(backgroundError),
57+
},
58+
containerStatusJob: {
59+
refreshContainerDigestsAfterStartup: vi.fn().mockResolvedValue(undefined),
60+
},
61+
},
62+
logger,
63+
250
64+
);
65+
66+
await vi.advanceTimersByTimeAsync(250);
67+
await vi.runAllTicks();
68+
69+
expect(logger.warn).toHaveBeenCalledWith(
70+
backgroundError,
71+
'Docker template bootstrap scan failed'
72+
);
73+
74+
vi.useRealTimers();
75+
});
76+
77+
it('does nothing when docker providers are unavailable', () => {
78+
const logger = {
79+
info: vi.fn(),
80+
warn: vi.fn(),
81+
};
82+
83+
expect(() => scheduleDockerStartupTasks({}, logger)).not.toThrow();
84+
expect(logger.info).not.toHaveBeenCalled();
85+
expect(logger.warn).not.toHaveBeenCalled();
86+
});
87+
});
88+
89+
describe('DockerStartupTasksListener', () => {
90+
it('schedules docker startup work when the app ready event is emitted', async () => {
91+
vi.useFakeTimers();
92+
93+
const bootstrapScan = vi.fn().mockResolvedValue(undefined);
94+
const refreshContainerDigestsAfterStartup = vi.fn().mockResolvedValue(undefined);
95+
const module = await Test.createTestingModule({
96+
providers: [
97+
DockerStartupTasksListener,
98+
{
99+
provide: DockerTemplateScannerService,
100+
useValue: { bootstrapScan },
101+
},
102+
{
103+
provide: ContainerStatusJob,
104+
useValue: { refreshContainerDigestsAfterStartup },
105+
},
106+
],
107+
}).compile();
108+
const listener = module.get(DockerStartupTasksListener);
109+
const event: AppReadyEvent = {
110+
reason: 'nestjs-server-listening',
111+
};
112+
113+
listener.handleAppReady(event);
114+
115+
await vi.advanceTimersByTimeAsync(5_000);
116+
117+
expect(bootstrapScan).toHaveBeenCalledTimes(1);
118+
expect(refreshContainerDigestsAfterStartup).toHaveBeenCalledTimes(1);
119+
120+
await module.close();
121+
vi.useRealTimers();
122+
});
123+
});
Lines changed: 67 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,67 @@
1+
import { Injectable } from '@nestjs/common';
2+
import { OnEvent } from '@nestjs/event-emitter';
3+
4+
import type { AppReadyEvent } from '@app/unraid-api/app/app-lifecycle.events.js';
5+
import { apiLogger } from '@app/core/log.js';
6+
import { APP_READY_EVENT } from '@app/unraid-api/app/app-lifecycle.events.js';
7+
import { ContainerStatusJob } from '@app/unraid-api/graph/resolvers/docker/container-status.job.js';
8+
import { DockerTemplateScannerService } from '@app/unraid-api/graph/resolvers/docker/docker-template-scanner.service.js';
9+
10+
const DEFAULT_DOCKER_STARTUP_DELAY_MS = 5_000;
11+
12+
interface DockerStartupTasksDependencies {
13+
containerStatusJob?: Pick<ContainerStatusJob, 'refreshContainerDigestsAfterStartup'> | null;
14+
dockerTemplateScannerService?: Pick<DockerTemplateScannerService, 'bootstrapScan'> | null;
15+
}
16+
17+
interface DockerStartupLogger {
18+
info: (message: string, ...args: unknown[]) => void;
19+
warn: (error: unknown, message: string, ...args: unknown[]) => void;
20+
}
21+
22+
export const scheduleDockerStartupTasks = (
23+
{ dockerTemplateScannerService, containerStatusJob }: DockerStartupTasksDependencies,
24+
logger: DockerStartupLogger,
25+
delayMs = DEFAULT_DOCKER_STARTUP_DELAY_MS
26+
): void => {
27+
if (!dockerTemplateScannerService && !containerStatusJob) {
28+
return;
29+
}
30+
31+
logger.info('Scheduling Docker startup tasks to run in %dms', delayMs);
32+
33+
if (dockerTemplateScannerService) {
34+
setTimeout(() => {
35+
void dockerTemplateScannerService.bootstrapScan().catch((error: unknown) => {
36+
logger.warn(error, 'Docker template bootstrap scan failed');
37+
});
38+
}, delayMs);
39+
}
40+
41+
if (containerStatusJob) {
42+
setTimeout(() => {
43+
void containerStatusJob.refreshContainerDigestsAfterStartup().catch((error: unknown) => {
44+
logger.warn(error, 'Docker container digest refresh after startup failed');
45+
});
46+
}, delayMs);
47+
}
48+
};
49+
50+
@Injectable()
51+
export class DockerStartupTasksListener {
52+
constructor(
53+
private readonly dockerTemplateScannerService: DockerTemplateScannerService,
54+
private readonly containerStatusJob: ContainerStatusJob
55+
) {}
56+
57+
@OnEvent(APP_READY_EVENT)
58+
handleAppReady(_event: AppReadyEvent): void {
59+
scheduleDockerStartupTasks(
60+
{
61+
dockerTemplateScannerService: this.dockerTemplateScannerService,
62+
containerStatusJob: this.containerStatusJob,
63+
},
64+
apiLogger
65+
);
66+
}
67+
}

api/src/unraid-api/graph/resolvers/docker/docker-template-scanner.service.ts

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,4 @@
11
import { Injectable, Logger } from '@nestjs/common';
2-
import { Timeout } from '@nestjs/schedule';
32
import { readdir, readFile } from 'fs/promises';
43
import { join } from 'path';
54

@@ -33,7 +32,6 @@ export class DockerTemplateScannerService {
3332
private readonly dockerService: DockerService
3433
) {}
3534

36-
@Timeout(5_000)
3735
async bootstrapScan(attempt = 1, maxAttempts = 5): Promise<void> {
3836
if (!ENABLE_NEXT_DOCKER_RELEASE) {
3937
return;

api/src/unraid-api/graph/resolvers/docker/docker.module.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ import { DockerManifestService } from '@app/unraid-api/graph/resolvers/docker/do
1010
import { DockerNetworkService } from '@app/unraid-api/graph/resolvers/docker/docker-network.service.js';
1111
import { DockerPhpService } from '@app/unraid-api/graph/resolvers/docker/docker-php.service.js';
1212
import { DockerPortService } from '@app/unraid-api/graph/resolvers/docker/docker-port.service.js';
13+
import { DockerStartupTasksListener } from '@app/unraid-api/graph/resolvers/docker/docker-startup-tasks.js';
1314
import { DockerStatsService } from '@app/unraid-api/graph/resolvers/docker/docker-stats.service.js';
1415
import { DockerTailscaleService } from '@app/unraid-api/graph/resolvers/docker/docker-tailscale.service.js';
1516
import { DockerTemplateIconService } from '@app/unraid-api/graph/resolvers/docker/docker-template-icon.service.js';
@@ -35,6 +36,7 @@ import { ServicesModule } from '@app/unraid-api/graph/services/services.module.j
3536
DockerConfigService,
3637
DockerTemplateScannerService,
3738
DockerTemplateIconService,
39+
DockerStartupTasksListener,
3840
DockerStatsService,
3941
DockerTailscaleService,
4042
DockerLogService,

api/src/unraid-api/main.ts

Lines changed: 55 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -2,20 +2,66 @@ import type { NestFastifyApplication } from '@nestjs/platform-fastify';
22
import { ValidationPipe } from '@nestjs/common';
33
import { ConfigService } from '@nestjs/config';
44
import { NestFactory } from '@nestjs/core';
5+
import { EventEmitter2 } from '@nestjs/event-emitter';
56
import { FastifyAdapter } from '@nestjs/platform-fastify/index.js';
67

78
import fastifyCookie from '@fastify/cookie';
89
import fastifyHelmet from '@fastify/helmet';
910
import { LoggerErrorInterceptor, Logger as PinoLogger } from 'nestjs-pino';
1011

12+
import type { AppReadyEvent } from '@app/unraid-api/app/app-lifecycle.events.js';
1113
import { apiLogger } from '@app/core/log.js';
1214
import { LOG_LEVEL, PORT } from '@app/environment.js';
13-
import { AppModule } from '@app/unraid-api/app/app.module.js';
14-
import { GraphQLExceptionsFilter } from '@app/unraid-api/exceptions/graphql-exceptions.filter.js';
15-
import { HttpExceptionFilter } from '@app/unraid-api/exceptions/http-exceptions.filter.js';
15+
import { APP_READY_EVENT } from '@app/unraid-api/app/app-lifecycle.events.js';
16+
17+
const READY_SIGNAL_SENT_SYMBOL = Symbol.for('unraid-api.processReadySignalSent');
18+
19+
type ReadySignalAwareGlobal = typeof globalThis & {
20+
[READY_SIGNAL_SENT_SYMBOL]?: boolean;
21+
};
22+
23+
const readySignalState = globalThis as ReadySignalAwareGlobal;
24+
25+
const signalProcessReady = (reason: string): boolean => {
26+
if (readySignalState[READY_SIGNAL_SENT_SYMBOL] === true) {
27+
return false;
28+
}
29+
30+
if (!process.send) {
31+
apiLogger.warn(
32+
new Error('process.send is unavailable'),
33+
'Unable to send PM2 ready signal while %s',
34+
reason
35+
);
36+
return false;
37+
}
38+
39+
try {
40+
const readySignalSent = process.send('ready');
41+
42+
if (!readySignalSent) {
43+
apiLogger.warn(
44+
'process.send returned false while sending PM2 ready signal while %s',
45+
reason
46+
);
47+
return false;
48+
}
49+
50+
readySignalState[READY_SIGNAL_SENT_SYMBOL] = true;
51+
apiLogger.info('Sent PM2 ready signal while %s', reason);
52+
return true;
53+
} catch (error: unknown) {
54+
apiLogger.error(error, 'Failed to send PM2 ready signal while %s', reason);
55+
return false;
56+
}
57+
};
1658

1759
export async function bootstrapNestServer(): Promise<NestFastifyApplication> {
18-
apiLogger.debug('Creating Nest Server');
60+
const [{ AppModule }, { GraphQLExceptionsFilter }, { HttpExceptionFilter }] = await Promise.all([
61+
import('@app/unraid-api/app/app.module.js'),
62+
import('@app/unraid-api/exceptions/graphql-exceptions.filter.js'),
63+
import('@app/unraid-api/exceptions/http-exceptions.filter.js'),
64+
]);
1965

2066
const app = await NestFactory.create<NestFastifyApplication>(AppModule, new FastifyAdapter(), {
2167
bufferLogs: false,
@@ -144,14 +190,12 @@ export async function bootstrapNestServer(): Promise<NestFastifyApplication> {
144190
// This 'ready' signal tells pm2 that the api has started.
145191
// PM2 documents this as Graceful Start or Clean Restart.
146192
// See https://pm2.keymetrics.io/docs/usage/signals-clean-restart/
147-
if (process.send) {
148-
process.send('ready');
149-
} else {
150-
apiLogger.warn(
151-
'Warning: process.send is unavailable. This will affect IPC communication with PM2.'
152-
);
153-
}
193+
signalProcessReady('NestJS server is now listening');
154194
apiLogger.info('Nest Server is now listening');
195+
const appReadyEvent: AppReadyEvent = {
196+
reason: 'nestjs-server-listening',
197+
};
198+
app.get(EventEmitter2).emit(APP_READY_EVENT, appReadyEvent);
155199

156200
return app;
157201
}

0 commit comments

Comments
 (0)