Skip to content

Commit 6f3e9ab

Browse files
davidje13davidje13
committed
Add JSON logging to CLI, and ability to mask custom/delegated URLs in logs
1 parent 2b1ddac commit 6f3e9ab

14 files changed

Lines changed: 444 additions & 208 deletions

‎src/bin/ServerManager.mts‎

Lines changed: 80 additions & 71 deletions
Original file line numberDiff line numberDiff line change
@@ -1,37 +1,34 @@
11
import { spawn } from 'node:child_process';
22
import { createServer, type Server, type ServerOptions } from 'node:http';
3-
import type { Readable, Writable } from 'node:stream';
3+
import type { Readable } from 'node:stream';
44
import { findCause, HTTPError, WebListener, type ListenOptions } from '../index.mts';
55
import type { ConfigServer, ConfigServerOptions, ConfigBackgroundTask } from './config/types.mts';
66
import { buildRouter } from './routes/buildRouter.mts';
77
import { markImportingDone } from './routes/custom/loadCustomHandler.mts';
88
import { clearZipCache } from './zipCache.mts';
9-
import type { Logger, AddColour } from './log.mts';
9+
import type { Logger } from './log.mts';
1010
import { TransientError } from './TransientError.mts';
1111

1212
export class ServerManager {
1313
declare private _started: boolean;
1414
declare private _building: boolean;
1515
declare private _stopping: boolean;
16-
declare private readonly _log: Logger;
17-
declare private readonly _colour: AddColour;
1816
declare private readonly _servers: Map<number, ServerState>;
1917
declare private _backgroundTasks: Set<BackgroundTaskState>;
2018
declare private _autoRetry: NodeJS.Timeout | undefined;
2119

22-
constructor(log: Logger, colour: AddColour) {
20+
constructor() {
2321
this._started = false;
2422
this._building = false;
2523
this._stopping = false;
26-
this._log = log;
27-
this._colour = colour;
2824
this._servers = new Map();
2925
this._backgroundTasks = new Set();
3026
}
3127

3228
async set(
3329
servers: ConfigServer[],
3430
backgroundTasks: ConfigBackgroundTask[],
31+
log: Logger,
3532
errorHandler: (error: unknown) => void,
3633
) {
3734
if (this._building || this._stopping) {
@@ -59,7 +56,7 @@ export class ServerManager {
5956
}
6057
canRetry = true;
6158
tasks.push(async () => {
62-
this._backgroundTasks.add(await this._startBackgroundTask(taskConfig));
59+
this._backgroundTasks.add(await this._startBackgroundTask(taskConfig, log));
6360
});
6461
}
6562
for (const taskState of previousBackgroundTasks) {
@@ -71,16 +68,22 @@ export class ServerManager {
7168
const serverConfig = servers[i]!;
7269
const port = serverConfig.port;
7370
if (port <= 0 || port > 65535) {
74-
this._log(0, `servers[${i}] must have a specific port from 1 to 65535`);
71+
log(0, {
72+
type: 'warn',
73+
message: `servers[${i}] must have a specific port from 1 to 65535`,
74+
});
7575
continue;
7676
}
7777
if (ports.has(port)) {
78-
this._log(0, `skipping servers[${i}] because port ${port} has already been defined`);
78+
log(0, {
79+
type: 'warn',
80+
message: `skipping servers[${i}] because port ${port} has already been defined`,
81+
});
7982
continue;
8083
}
8184
ports.add(port);
8285
tasks.push(async () => {
83-
const state = await this._rerunServer(serverConfig, this._servers.get(port));
86+
const state = await this._rerunServer(serverConfig, this._servers.get(port), log);
8487
if (state) {
8588
this._servers.set(port, state);
8689
} else {
@@ -105,7 +108,7 @@ export class ServerManager {
105108
await task();
106109
} catch (error: unknown) {
107110
if (canRetry && !this._stopping && error instanceof TransientError) {
108-
this._log(1, `${error.message} (retrying)`);
111+
log(1, { type: 'warn', message: `${error.message} (retrying)` });
109112
doRetry = true;
110113
} else {
111114
failures.push(error);
@@ -114,7 +117,7 @@ export class ServerManager {
114117
}),
115118
);
116119
if (failures.length) {
117-
await this._shutdown();
120+
await this._shutdown(log);
118121
throw failures.length > 1 ? new AggregateError(failures) : failures[0]!;
119122
}
120123
};
@@ -124,16 +127,16 @@ export class ServerManager {
124127
markImportingDone();
125128

126129
if (this._stopping) {
127-
this._shutdown();
130+
this._shutdown(log);
128131
} else if (doRetry) {
129132
this._autoRetry = setTimeout(() => {
130133
clearZipCache();
131-
this.set(servers, backgroundTasks, errorHandler);
134+
this.set(servers, backgroundTasks, log, errorHandler);
132135
}, 1000);
133136
} else if (this._servers.size) {
134-
this._log(1, 'all servers ready');
137+
log(1, { message: 'all servers ready' });
135138
} else {
136-
this._log(1, 'no servers configured');
139+
log(1, { message: 'no servers configured' });
137140
}
138141
} catch (error: unknown) {
139142
errorHandler(error);
@@ -142,13 +145,16 @@ export class ServerManager {
142145
}
143146
}
144147

145-
private async _startBackgroundTask(config: ConfigBackgroundTask): Promise<BackgroundTaskState> {
146-
const name = this._colour('35', config.command);
148+
private async _startBackgroundTask(
149+
config: ConfigBackgroundTask,
150+
log: Logger,
151+
): Promise<BackgroundTaskState> {
152+
const logBase = { service: config.command, serviceCol: '35' };
147153

148154
const ac = new AbortController();
149155

150156
return new Promise((resolve, reject) => {
151-
this._log(2, `${name} ${this._colour('2', 'starting')}`);
157+
log(2, { ...logBase, type: 'detail', message: 'starting' });
152158
let running = true;
153159
const proc = spawn(config.command, config.arguments, {
154160
cwd: config.cwd,
@@ -160,26 +166,26 @@ export class ServerManager {
160166
signal: ac.signal,
161167
});
162168
if (config.options.displayStdout) {
163-
pipePrefixed(proc.stdout, `${name} ${this._colour('2', '[stdout]')} `, process.stderr);
169+
watchOutput(proc.stdout, (ln) => log(0, { ...logBase, thread: 'stdout', message: ln }));
164170
} else {
165171
proc.stdout.resume();
166172
}
167173
if (config.options.displayStderr) {
168-
pipePrefixed(proc.stderr, `${name} ${this._colour('2', '[stderr]')} `, process.stderr);
174+
watchOutput(proc.stderr, (ln) => log(0, { ...logBase, thread: 'stderr', message: ln }));
169175
} else {
170176
proc.stderr.resume();
171177
}
172178
proc.addListener('error', (err) => {
173-
this._log(0, `${name} startup failed: ${err.message}`);
179+
log(0, { ...logBase, type: 'error', message: `startup failed: ${err.message}` });
174180
running = false;
175181
reject(err);
176182
});
177183
proc.addListener('exit', (code, signal) => {
178-
if (code !== null) {
179-
this._log(2, `${name} closed ${this._colour('2', `(exit code ${code})`)}`);
180-
} else {
181-
this._log(2, `${name} closed ${this._colour('2', `(exit signal ${signal})`)}`);
182-
}
184+
log(2, {
185+
...logBase,
186+
message: 'closed',
187+
stats: code !== null ? { code } : { signal },
188+
});
183189
running = false;
184190
});
185191
proc.addListener('spawn', () =>
@@ -191,10 +197,12 @@ export class ServerManager {
191197
if (proc.signalCode !== null || proc.exitCode !== null) {
192198
closeResolve();
193199
} else {
194-
this._log(
195-
2,
196-
`${name} ${this._colour('2', `closing (signal ${config.options.killSignal})`)}`,
197-
);
200+
log(2, {
201+
...logBase,
202+
type: 'detail',
203+
message: 'closing',
204+
stats: { signal: config.options.killSignal },
205+
});
198206
proc.addListener('exit', closeResolve);
199207
proc.kill(config.options.killSignal);
200208
}
@@ -207,45 +215,51 @@ export class ServerManager {
207215
private async _rerunServer(
208216
{ port, host, options, mount }: ConfigServer,
209217
existing: ServerState | undefined,
218+
log: Logger,
210219
): Promise<ServerState | undefined> {
211-
const name = this._colour('34', `http://${host}:${port}`);
220+
const logBase = { service: `http://${host}:${port}`, serviceCol: '34' };
212221
const router = await buildRouter(
213222
mount,
214-
(warning) => this._log(1, `${name} ${this._colour('33', 'warning')}: ${warning}`),
223+
(warning) => log(1, { ...logBase, type: 'warn', message: warning }),
215224
options.logRequests
216-
? (info) => {
217-
const method = this._colour('1', info.method.replaceAll(/[^a-zA-Z0-9\-_]/g, '?'));
218-
const status = this._colour(
219-
STATUS_COLOURS[(info.status / 100) | 0] ?? '',
220-
String(info.status),
221-
);
222-
const duration = this._colour('2', `(${info.duration}ms)`);
223-
this._log(0, `${name} ${method} ${info.path} ${status} ${duration}`);
224-
}
225+
? (info) =>
226+
log(0, {
227+
...logBase,
228+
method: info.method,
229+
path: info.path,
230+
status: info.status,
231+
stats: { duration: info.duration },
232+
})
225233
: undefined,
226234
);
227235
const weblistener = new WebListener(router);
228236
weblistener.addEventListener('error', (evt) => {
229237
evt.preventDefault();
230238
const { error, context, request } = evt.detail;
231239
if ((findCause(error, HTTPError)?.statusCode ?? 500) >= 500) {
232-
this._log(0, `${name} ${this._colour('91', 'error')}: ${context} ${request?.url} ${error}`);
240+
log(0, {
241+
...logBase,
242+
thread: context,
243+
type: 'error',
244+
path: request?.url,
245+
message: String(error),
246+
});
233247
}
234248
});
235249

236250
let server: Server;
237251
let launch: Promise<void> | undefined;
238252
if (existing && host === existing.host && serverOptionsCompatible(options, existing.options)) {
239253
server = existing.server;
240-
this._log(2, `${name} updated`);
254+
log(2, { ...logBase, message: 'updated' });
241255
existing.detach();
242256
} else {
243257
if (existing) {
244-
this._log(2, `${name} ${this._colour('2', 'restarting (step 1: shutdown)')}`);
258+
log(2, { ...logBase, type: 'detail', message: 'restarting (step 1: shutdown)' });
245259
await existing.close();
246-
this._log(2, `${name} ${this._colour('2', 'restarting (step 2: start)')}`);
260+
log(2, { ...logBase, type: 'detail', message: 'restarting (step 2: start)' });
247261
} else {
248-
this._log(2, `${name} ${this._colour('2', 'starting')}`);
262+
log(2, { ...logBase, type: 'detail', message: 'starting' });
249263
}
250264
if (this._stopping) {
251265
return undefined;
@@ -260,7 +274,7 @@ export class ServerManager {
260274
await launch;
261275
// wait an extra tick before confirming we are ready (required on Linux)
262276
await new Promise((resolve) => setTimeout(resolve, 1));
263-
this._log(2, `${name} ready`);
277+
log(2, { ...logBase, message: 'ready' });
264278
}
265279
return {
266280
host,
@@ -272,61 +286,56 @@ export class ServerManager {
272286
const listeners = detach('shutdown', options.shutdownTimeout, true, () => {
273287
server.close(() => {
274288
// ignore any error (happens if server is already closed)
275-
this._log(2, `${name} closed`);
289+
log(2, { ...logBase, message: 'closed' });
276290
resolve();
277291
});
278292
server.closeAllConnections();
279293
});
280294
const connections = listeners.countConnections();
281295
if (connections > 0) {
282-
this._log(
283-
2,
284-
`${name} ${this._colour('2', `closing (remaining connections: ${connections})`)}`,
285-
);
296+
log(2, {
297+
...logBase,
298+
type: 'detail',
299+
message: 'closing',
300+
stats: { connections },
301+
});
286302
}
287303
}),
288304
};
289305
}
290306

291-
private async _shutdown() {
307+
private async _shutdown(log: Logger) {
292308
if (this._servers.size) {
293-
this._log(2, this._colour('2', 'shutting down'));
309+
log(2, { type: 'detail', message: 'shutting down' });
294310
await Promise.all(
295311
[...this._servers.values(), ...this._backgroundTasks].map((state) => state.close()),
296312
);
297313
}
298314
if (this._started) {
299-
this._log(2, 'shutdown complete');
315+
log(2, { message: 'shutdown complete' });
300316
}
301317
}
302318

303-
shutdown() {
319+
shutdown(log: Logger) {
304320
if (this._stopping) {
305321
return;
306322
}
307323
clearTimeout(this._autoRetry);
308324
this._autoRetry = undefined;
309325
this._stopping = true;
310326
if (!this._building) {
311-
this._shutdown();
327+
this._shutdown(log);
312328
}
313329
}
314330
}
315331

316-
const STATUS_COLOURS = ['', '37', '32', '36', '31', '41;97'];
317-
318-
function pipePrefixed(readable: Readable, prefix: string, target: Writable) {
332+
function watchOutput(readable: Readable, lineHandler: (ln: string) => void) {
319333
let line = '';
320334
const writeln = (ln: string) =>
321-
target.write(
322-
prefix +
323-
ln
324-
.replaceAll(/\x1b\[[\d;]*[A-K]/g, '')
325-
.replaceAll(
326-
/[\x00-\x1f]/g,
327-
(c) => `\\x${c.charCodeAt(0).toString(16).padStart(2, '0')}`,
328-
) +
329-
'\n',
335+
lineHandler(
336+
ln
337+
.replaceAll(/\x1b\[[\d;]*[A-K]/g, '')
338+
.replaceAll(/[\x00-\x1f]/g, (c) => `\\x${c.charCodeAt(0).toString(16).padStart(2, '0')}`),
330339
);
331340
readable.addListener('data', (chunk) => {
332341
line += chunk;

0 commit comments

Comments
 (0)