Skip to content

Commit 3060789

Browse files
dstaleydstaley
committed
ci: add some logging
1 parent 2696e04 commit 3060789

7 files changed

Lines changed: 178 additions & 13 deletions

File tree

‎integration/models/application.ts‎

Lines changed: 50 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,16 @@
11
import * as path from 'node:path';
22

3-
import { awaitableTreekill, createLogger, fs, getPort, run, waitForIdleProcess, waitForServer } from '../scripts';
3+
import {
4+
awaitableTreekill,
5+
createCiDiagnosticLogger,
6+
createLogger,
7+
fs,
8+
getPort,
9+
run,
10+
startDetachedProcessLogMirror,
11+
waitForIdleProcess,
12+
waitForServer,
13+
} from '../scripts';
414
import type { ApplicationConfig } from './applicationConfig.js';
515
import type { EnvironmentConfig } from './environment.js';
616

@@ -21,6 +31,9 @@ export const application = (
2131
const stderrFilePath = path.resolve(appDirPath, `e2e.${now}.err.log`);
2232
let buildOutput = '';
2333
let serveOutput = '';
34+
const createPhaseLogger = (phase: string) => {
35+
return createCiDiagnosticLogger(`${appDirName} :: ${phase}`, logger.child({ prefix: phase }).info);
36+
};
2437

2538
const self = {
2639
name,
@@ -42,14 +55,18 @@ export const application = (
4255
setup: async (opts?: { strategy?: 'ci' | 'i' | 'copy'; force?: boolean }) => {
4356
const { force } = opts || {};
4457
const nodeModulesExist = await fs.pathExists(path.resolve(appDirPath, 'node_modules'));
58+
const log = createPhaseLogger('setup');
4559
if (force || !nodeModulesExist) {
46-
const log = logger.child({ prefix: 'setup' }).info;
60+
log(`Running "${scripts.setup}" in ${appDirPath}`);
4761
await run(scripts.setup, { cwd: appDirPath, log });
4862
state.completedSetup = true;
63+
log(`Completed "${scripts.setup}"`);
64+
return;
4965
}
66+
log(`Skipping "${scripts.setup}" because node_modules already exists in ${appDirPath}`);
5067
},
5168
dev: async (opts: { port?: number; manualStart?: boolean; detached?: boolean; serverUrl?: string } = {}) => {
52-
const log = logger.child({ prefix: 'dev' }).info;
69+
const log = createPhaseLogger('dev');
5370
const port = opts.port || (await getPort());
5471
const getServerUrl = () => {
5572
if (opts.serverUrl) {
@@ -68,21 +85,45 @@ export const application = (
6885
return { port, serverUrl: runtimeServerUrl };
6986
}
7087

88+
log(`Running "${scripts.dev}" in ${appDirPath}`);
89+
if (opts.detached) {
90+
log(`Detached process logs will be written to ${stdoutFilePath} and ${stderrFilePath}`);
91+
}
7192
const proc = run(scripts.dev, {
7293
cwd: appDirPath,
7394
env: { PORT: port.toString() },
7495
detached: opts.detached,
7596
stdout: opts.detached ? fs.openSync(stdoutFilePath, 'a') : undefined,
7697
stderr: opts.detached ? fs.openSync(stderrFilePath, 'a') : undefined,
77-
log: opts.detached ? undefined : log,
98+
log,
99+
});
100+
void proc.on('error', error => {
101+
log(`Process error: ${error.message}`);
102+
});
103+
void proc.on('exit', (code, signal) => {
104+
log(`Process exited with code ${String(code)}${signal ? ` and signal ${signal}` : ''}`);
78105
});
106+
const detachedLogMirror = opts.detached
107+
? startDetachedProcessLogMirror({
108+
stdoutFilePath,
109+
stderrFilePath,
110+
log,
111+
})
112+
: undefined;
79113

80114
const shouldExit = () => !!proc.exitCode && proc.exitCode !== 0;
81-
await waitForServer(runtimeServerUrl, { log, maxAttempts: Infinity, shouldExit });
82-
log(`Server started at ${runtimeServerUrl}, pid: ${proc.pid}`);
83-
cleanupFns.push(() => awaitableTreekill(proc.pid, 'SIGKILL'));
84-
state.serverUrl = runtimeServerUrl;
85-
return { port, serverUrl: runtimeServerUrl, pid: proc.pid };
115+
try {
116+
await waitForServer(runtimeServerUrl, { log, maxAttempts: Infinity, shouldExit });
117+
log(`Server started at ${runtimeServerUrl}, pid: ${proc.pid}`);
118+
cleanupFns.push(() => awaitableTreekill(proc.pid, 'SIGKILL'));
119+
state.serverUrl = runtimeServerUrl;
120+
return { port, serverUrl: runtimeServerUrl, pid: proc.pid };
121+
} catch (error) {
122+
log(`Server failed to start at ${runtimeServerUrl}`);
123+
throw error;
124+
} finally {
125+
await detachedLogMirror?.stop();
126+
}
86127
},
87128
build: async () => {
88129
const log = logger.child({ prefix: 'build' }).info;

‎integration/models/longRunningApplication.ts‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -59,6 +59,7 @@ export const longRunningApplication = (params: LongRunningApplicationParams) =>
5959
// will be called by global.setup.ts and by the test runner
6060
// the first time this is called, the app starts and the state is persisted in the state file
6161
init: async () => {
62+
console.log(`Starting long running app "${id}"`);
6263
try {
6364
const publishableKey = params.env.publicVariables.get('CLERK_PUBLISHABLE_KEY');
6465
const secretKey = params.env.privateVariables.get('CLERK_SECRET_KEY');
@@ -102,6 +103,7 @@ export const longRunningApplication = (params: LongRunningApplicationParams) =>
102103
try {
103104
const { port, serverUrl, pid } = await app.dev({ detached: true });
104105
stateFile.addLongRunningApp({ port, serverUrl, pid, id, appDir: app.appDir, env: params.env.toJson() });
106+
console.log(`Long running app "${id}" started at ${serverUrl} (pid: ${pid})`);
105107
} catch (error) {
106108
console.error('Error during app dev:', error);
107109
throw error;

‎integration/scripts/ciDiagnostics.ts‎

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,12 @@
1+
/* eslint-disable turbo/no-undeclared-env-vars */
2+
3+
export const shouldLogCiDiagnostics = () => Boolean(process.env.CI);
4+
5+
export const createCiDiagnosticLogger = (prefix: string, debugLog?: (msg: string) => void) => {
6+
return (msg: string) => {
7+
debugLog?.(msg);
8+
if (shouldLogCiDiagnostics()) {
9+
console.log(`[${prefix}] ${msg}`);
10+
}
11+
};
12+
};

‎integration/scripts/clerkJsServer.ts‎

Lines changed: 26 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,7 @@ import path from 'node:path';
55

66
import { constants } from '../constants';
77
import { stateFile } from '../models/stateFile';
8-
import { awaitableTreekill, fs, waitForServer } from '.';
8+
import { awaitableTreekill, createCiDiagnosticLogger, fs, startDetachedProcessLogMirror, waitForServer } from '.';
99
import { run } from './run';
1010

1111
export const startClerkJsHttpServer = async () => {
@@ -37,23 +37,45 @@ const copyClerkJsToTempDir = async () => {
3737
};
3838

3939
const serveFromTempDir = async () => {
40-
console.log('Serving clerkJs from temp dir');
40+
const log = createCiDiagnosticLogger('clerkJsHttpServer');
41+
log('Serving clerkJs from temp dir');
4142
const port = 18211;
4243
const serverUrl = `http://localhost:${port}`;
4344
const now = Date.now();
4445
const stdoutFilePath = path.resolve(constants.TMP_DIR, `clerkJsHttpServer.${now}.log`);
4546
const stderrFilePath = path.resolve(constants.TMP_DIR, `clerkJsHttpServer.${now}.err.log`);
4647
const clerkJsTempDir = getClerkJsTempDir();
48+
log(`Running "node_modules/.bin/http-server ${clerkJsTempDir} -d --gzip --cors -a localhost" in ${process.cwd()}`);
49+
log(`Detached process logs will be written to ${stdoutFilePath} and ${stderrFilePath}`);
4750
const proc = run(`node_modules/.bin/http-server ${clerkJsTempDir} -d --gzip --cors -a localhost`, {
4851
cwd: process.cwd(),
4952
env: { PORT: port.toString() },
5053
detached: true,
5154
stdout: fs.openSync(stdoutFilePath, 'a'),
5255
stderr: fs.openSync(stderrFilePath, 'a'),
56+
log,
57+
});
58+
void proc.on('error', error => {
59+
log(`Process error: ${error.message}`);
60+
});
61+
void proc.on('exit', (code, signal) => {
62+
log(`Process exited with code ${String(code)}${signal ? ` and signal ${signal}` : ''}`);
63+
});
64+
const detachedLogMirror = startDetachedProcessLogMirror({
65+
stdoutFilePath,
66+
stderrFilePath,
67+
log,
5368
});
5469
stateFile.setClerkJsHttpServerPid(proc.pid);
55-
await waitForServer(serverUrl, { log: console.log, maxAttempts: Infinity });
56-
console.log('clerk.browser.js is being served from', serverUrl);
70+
try {
71+
await waitForServer(serverUrl, { log, maxAttempts: Infinity });
72+
log(`clerk.browser.js is being served from ${serverUrl}`);
73+
} catch (error) {
74+
log(`clerk.browser.js failed to start from ${serverUrl}`);
75+
throw error;
76+
} finally {
77+
await detachedLogMirror.stop();
78+
}
5779
};
5880

5981
// The location where the clerk.browser.js is served from

‎integration/scripts/detachedProcessLogMirror.ts‎

Lines changed: 84 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,84 @@
1+
import { readFile } from 'node:fs/promises';
2+
3+
type DetachedProcessLogMirrorOptions = {
4+
stdoutFilePath?: string;
5+
stderrFilePath?: string;
6+
log: (msg: string) => void;
7+
intervalInMs?: number;
8+
};
9+
10+
type FileReadState = {
11+
contentsLength: number;
12+
hasLoggedReadError: boolean;
13+
};
14+
15+
const readNewLogOutput = async (filePath: string, label: string, log: (msg: string) => void, state: FileReadState) => {
16+
try {
17+
const contents = await readFile(filePath, 'utf8');
18+
if (contents.length < state.contentsLength) {
19+
state.contentsLength = 0;
20+
}
21+
if (contents.length === state.contentsLength) {
22+
return;
23+
}
24+
25+
const nextChunk = contents.slice(state.contentsLength);
26+
state.contentsLength = contents.length;
27+
state.hasLoggedReadError = false;
28+
29+
nextChunk
30+
.split(/\r?\n/)
31+
.map(line => line.trimEnd())
32+
.filter(Boolean)
33+
.forEach(line => log(`${label} ${line}`));
34+
} catch (error) {
35+
const readError = error as NodeJS.ErrnoException;
36+
if (readError.code === 'ENOENT') {
37+
return;
38+
}
39+
if (!state.hasLoggedReadError) {
40+
log(`${label} Failed to read ${filePath}: ${readError.message}`);
41+
state.hasLoggedReadError = true;
42+
}
43+
}
44+
};
45+
46+
export const startDetachedProcessLogMirror = (opts: DetachedProcessLogMirrorOptions) => {
47+
const { stdoutFilePath, stderrFilePath, log, intervalInMs = 1000 } = opts;
48+
const stdoutState: FileReadState = { contentsLength: 0, hasLoggedReadError: false };
49+
const stderrState: FileReadState = { contentsLength: 0, hasLoggedReadError: false };
50+
let isReading = false;
51+
let isStopped = false;
52+
53+
const flush = async () => {
54+
await Promise.all([
55+
stdoutFilePath ? readNewLogOutput(stdoutFilePath, '[stdout]', log, stdoutState) : Promise.resolve(),
56+
stderrFilePath ? readNewLogOutput(stderrFilePath, '[stderr]', log, stderrState) : Promise.resolve(),
57+
]);
58+
};
59+
60+
const timer = setInterval(() => {
61+
if (isStopped || isReading) {
62+
return;
63+
}
64+
isReading = true;
65+
void flush().finally(() => {
66+
isReading = false;
67+
});
68+
}, intervalInMs);
69+
70+
timer.unref?.();
71+
72+
return {
73+
stop: async () => {
74+
isStopped = true;
75+
clearInterval(timer);
76+
77+
while (isReading) {
78+
await new Promise(resolve => setTimeout(resolve, 25));
79+
}
80+
81+
await flush();
82+
},
83+
};
84+
};

‎integration/scripts/index.ts‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,10 +6,12 @@ export const getPort = _getPort;
66
export const chalk = _chalk;
77
export const fs = _fs;
88
export { createLogger } from './logger';
9+
export { createCiDiagnosticLogger, shouldLogCiDiagnostics } from './ciDiagnostics';
910

1011
export { waitForIdleProcess } from './waitForIdleProcess';
1112
export { range } from './range';
1213
export { chunkLogger, run } from './run';
14+
export { startDetachedProcessLogMirror } from './detachedProcessLogMirror';
1315

1416
export * from './setup';
1517
export * from './waitForServer';

‎integration/tests/global.setup.ts‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,8 +12,10 @@ setup('start long running apps', async () => {
1212
await startClerkJsHttpServer();
1313

1414
const { appIds } = parseEnvOptions();
15+
console.log(`Preparing long running apps for E2E_APP_ID=${appIds.join(',') || '<none>'}`);
1516
if (appIds.length) {
1617
const apps = appConfigs.longRunningApps.getByPattern(appIds);
18+
console.log(`Matched long running apps: ${apps.map(app => app.id).join(', ')}`);
1719
// state cannot be shared using playwright,
1820
// so we save the state in a file using a strategy similar to `storageState`
1921
await Promise.all(apps.map(app => app.init()));

0 commit comments

Comments
 (0)