C3: E2E logging refactor (#4164)

* C3: Dont show animated spinners in non-interactive terminals

* C3: Write e2e output to log files instead of stdout

* C3: Upload e2e logs as artifacts

* Don't cleanup projects when importing helper

* Adding a .gitkeep to .e2e-logs

* Make per-pm folders

* Upload artifacts when e2e step fails

* Remove hack for testing failure

* Add shell to last step in e2e action

* Suppress console logs in case of error

.github/actions/run-c3-e2e/action.yml

@@ -33,10 +33,23 @@ runs:
         git config --global user.name 'Wrangler automated PR updater'
 
     - name: E2E Tests
+      id: run-e2e
       shell: bash
+      continue-on-error: true
       run: pnpm run --filter create-cloudflare test:e2e:${{ inputs.package-manager }}
       env:
         CLOUDFLARE_API_TOKEN: ${{ inputs.apiToken }}
         CLOUDFLARE_ACCOUNT_ID: ${{ inputs.accountId }}
         E2E_QUARANTINE: ${{ inputs.quarantine }}
         FRAMEWORK_CLI_TO_TEST: ${{ inputs.framework }}
+
+    - name: Upload Logs
+      uses: actions/upload-artifact@v3
+      with:
+        name: e2e-logs
+        path: packages/create-cloudflare/.e2e-logs
+
+    - name: Fail if errors detected
+      shell: bash
+      if: ${{ steps.run-e2e.outcome == 'failure' }}
+      run: exit 1

packages/create-cloudflare/.gitignore

@@ -1,6 +1,7 @@
 node_modules
 /dist
 create-cloudflare-*.tgz
+/.e2e-logs/*
 
 .DS_Store
 

packages/create-cloudflare/e2e-tests/cli.test.ts

@@ -1,11 +1,19 @@
 import { existsSync, rmSync, mkdtempSync, realpathSync } from "fs";
 import { tmpdir } from "os";
 import { join } from "path";
-import { beforeEach, afterEach, describe, test, expect } from "vitest";
+import {
+	beforeEach,
+	afterEach,
+	describe,
+	test,
+	expect,
+	beforeAll,
+} from "vitest";
 import { version } from "../package.json";
 import * as shellquote from "../src/helpers/shell-quote";
 import { frameworkToTest } from "./frameworkToTest";
-import { isQuarantineMode, keys, runC3 } from "./helpers";
+import { isQuarantineMode, keys, recreateLogFolder, runC3 } from "./helpers";
+import type { Suite } from "vitest";
 
 // Note: skipIf(frameworkToTest) makes it so that all the basic C3 functionality
 //       tests are skipped in case we are testing a specific framework
@@ -15,6 +23,10 @@ describe.skipIf(frameworkToTest || isQuarantineMode())(
 		const tmpDirPath = realpathSync(mkdtempSync(join(tmpdir(), "c3-tests")));
 		const projectPath = join(tmpDirPath, "basic-tests");
 
+		beforeAll((ctx) => {
+			recreateLogFolder(ctx as Suite);
+		});
+
 		beforeEach(() => {
 			rmSync(projectPath, { recursive: true, force: true });
 		});
@@ -25,27 +37,28 @@ describe.skipIf(frameworkToTest || isQuarantineMode())(
 			}
 		});
 
-		test("--version", async () => {
-			const { output } = await runC3({ argv: ["--version"] });
+		test("--version", async (ctx) => {
+			const { output } = await runC3({ ctx, argv: ["--version"] });
 			expect(output).toEqual(version);
 		});
 
-		test("--version with positionals", async () => {
+		test("--version with positionals", async (ctx) => {
 			const argv = shellquote.parse("foo bar baz --version");
-			const { output } = await runC3({ argv });
+			const { output } = await runC3({ ctx, argv });
 			expect(output).toEqual(version);
 		});
 
-		test("--version with flags", async () => {
+		test("--version with flags", async (ctx) => {
 			const argv = shellquote.parse(
 				"foo --type webFramework --no-deploy --version"
 			);
-			const { output } = await runC3({ argv });
+			const { output } = await runC3({ ctx, argv });
 			expect(output).toEqual(version);
 		});
 
-		test("Using arrow keys + enter", async () => {
+		test("Using arrow keys + enter", async (ctx) => {
 			const { output } = await runC3({
+				ctx,
 				argv: [projectPath],
 				promptHandlers: [
 					{
@@ -74,9 +87,10 @@ describe.skipIf(frameworkToTest || isQuarantineMode())(
 			expect(output).toContain(`no deploy`);
 		});
 
-		test("Typing custom responses", async () => {
+		test("Typing custom responses", async (ctx) => {
 			const { output } = await runC3({
 				argv: [],
+				ctx,
 				promptHandlers: [
 					{
 						matcher:
@@ -109,8 +123,9 @@ describe.skipIf(frameworkToTest || isQuarantineMode())(
 			expect(output).toContain(`no deploy`);
 		});
 
-		test("Mixed args and interactive", async () => {
+		test("Mixed args and interactive", async (ctx) => {
 			const { output } = await runC3({
+				ctx,
 				argv: [projectPath, "--ts", "--no-deploy"],
 				promptHandlers: [
 					{

packages/create-cloudflare/e2e-tests/helpers.ts

@@ -1,15 +1,22 @@
-import { existsSync, mkdtempSync, realpathSync, rmSync } from "fs";
+import {
+	createWriteStream,
+	existsSync,
+	mkdirSync,
+	mkdtempSync,
+	realpathSync,
+	rmSync,
+} from "fs";
 import crypto from "node:crypto";
 import { tmpdir } from "os";
-import { join } from "path";
+import { basename, join } from "path";
 import { spawn } from "cross-spawn";
+import { stripAnsi } from "helpers/cli";
 import { sleep } from "helpers/common";
-import { spinnerFrames } from "helpers/interactive";
 import { detectPackageManager } from "helpers/packages";
 import { fetch } from "undici";
 import { expect } from "vitest";
 import { version } from "../package.json";
-import type { SpinnerStyle } from "helpers/interactive";
+import type { Suite, TestContext } from "vitest";
 
 export const C3_E2E_PREFIX = "c3-e2e-";
 
@@ -36,12 +43,13 @@ export type RunnerConfig = {
 	argv?: string[];
 	outputPrefix?: string;
 	quarantine?: boolean;
+	ctx: TestContext;
 };
 
 export const runC3 = async ({
 	argv = [],
 	promptHandlers = [],
-	outputPrefix = "",
+	ctx,
 }: RunnerConfig) => {
 	const cmd = "node";
 	const args = ["./dist/cli.js", ...argv];
@@ -51,28 +59,34 @@ export const runC3 = async ({
 
 	const { name: pm } = detectPackageManager();
 
-	console.log(
-		`\x1b[44m${outputPrefix} Running C3 with command: \`${cmd} ${args.join(
-			" "
-		)}\` (using ${pm})\x1b[0m`
-	);
-
 	const stdout: string[] = [];
 	const stderr: string[] = [];
 
 	promptHandlers = promptHandlers && [...promptHandlers];
 
+	// The .ansi extension allows for editor extensions that format ansi terminal codes
+	const logFilename = `${normalizeTestName(ctx)}.ansi`;
+	const logStream = createWriteStream(
+		join(getLogPath(ctx.meta.suite), logFilename)
+	);
+
+	logStream.write(
+		`Running C3 with command: \`${cmd} ${args.join(" ")}\` (using ${pm})\n\n`
+	);
+
 	await new Promise((resolve, rejects) => {
 		proc.stdout.on("data", (data) => {
 			const lines: string[] = data.toString().split("\n");
 			const currentDialog = promptHandlers[0];
 
 			lines.forEach(async (line) => {
-				if (filterLine(line)) {
-					console.log(`${outputPrefix} ${line}`);
-				}
 				stdout.push(line);
 
+				const stripped = stripAnsi(line).trim();
+				if (stripped.length > 0) {
+					logStream.write(`${stripped}\n`);
+				}
+
 				if (currentDialog && currentDialog.matcher.test(line)) {
 					// Add a small sleep to avoid input race
 					await sleep(1000);
@@ -94,33 +108,67 @@ export const runC3 = async ({
 		});
 
 		proc.stderr.on("data", (data) => {
+			logStream.write(data);
 			stderr.push(data);
 		});
 
 		proc.on("close", (code) => {
+			logStream.close();
+
 			if (code === 0) {
 				resolve(null);
 			} else {
-				console.log(stderr.join("\n").trim());
 				rejects(code);
 			}
 		});
 
 		proc.on("error", (exitCode) => {
 			rejects({
 				exitCode,
-				output: condenseOutput(stdout).join("\n").trim(),
+				output: stdout.join("\n").trim(),
 				errors: stderr.join("\n").trim(),
 			});
 		});
 	});
 
 	return {
-		output: condenseOutput(stdout).join("\n").trim(),
+		output: stdout.join("\n").trim(),
 		errors: stderr.join("\n").trim(),
 	};
 };
 
+export const recreateLogFolder = (suite: Suite) => {
+	// Clean the old folder if exists (useful for dev)
+	rmSync(getLogPath(suite), {
+		recursive: true,
+		force: true,
+	});
+
+	mkdirSync(getLogPath(suite), { recursive: true });
+};
+
+const getLogPath = (suite: Suite) => {
+	const { file } = suite;
+
+	const suiteFilename = file
+		? basename(file.name).replace(".test.ts", "")
+		: "unknown";
+
+	return join("./.e2e-logs/", process.env.TEST_PM as string, suiteFilename);
+};
+
+const normalizeTestName = (ctx: TestContext) => {
+	const baseName = ctx.meta.name
+		.toLowerCase()
+		.replace(/\s+/g, "_") // replace any whitespace with `_`
+		.replace(/\W/g, ""); // strip special characters
+
+	// Ensure that each retry gets its own log file
+	const retryCount = ctx.meta.result?.retryCount ?? 0;
+	const suffix = retryCount > 0 ? `_${retryCount}` : "";
+	return baseName + suffix;
+};
+
 export const testProjectDir = (suite: string) => {
 	const tmpDirPath = realpathSync(
 		mkdtempSync(join(tmpdir(), `c3-tests-${suite}`))
@@ -187,25 +235,6 @@ export const testDeploymentCommitMessage = async (
 	expect(projectLatestCommitMessage).toContain(`framework = ${framework}`);
 };
 
-// Removes lines from the output of c3 that aren't particularly useful for debugging tests
-export const condenseOutput = (lines: string[]) => {
-	return lines.filter(filterLine);
-};
-
-const filterLine = (line: string) => {
-	// Remove all lines with spinners
-	for (const spinnerType of Object.keys(spinnerFrames)) {
-		for (const frame of spinnerFrames[spinnerType as SpinnerStyle]) {
-			if (line.includes(frame)) return false;
-		}
-	}
-
-	// Remove empty lines
-	if (line.replace(/\s/g, "").length == 0) return false;
-
-	return true;
-};
-
 export const isQuarantineMode = () => {
 	return process.env.E2E_QUARANTINE === "true";
 };