Skip to content

refactor: improve e2e test reporting #10304

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 9 commits into from
Oct 17, 2023
Merged

refactor: improve e2e test reporting #10304

Show file tree
Hide file tree
Changes from 6 commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
54c4b2d
refactor: better e2e test reporting
aslilac Oct 16, 2023
1096c2f
🧹
aslilac Oct 16, 2023
e7d17dc
Merge branch 'main' into better-playwright-reporter
aslilac Oct 16, 2023
011dc55
report specific test failure names
aslilac Oct 16, 2023
335593a
🧹
aslilac Oct 16, 2023
91475e4
🧹
aslilac Oct 16, 2023
395a019
let's see what this looks like
aslilac Oct 17, 2023
406b6ed
Merge branch 'main' into better-playwright-reporter
aslilac Oct 17, 2023
1c6ff27
ignore some lines
aslilac Oct 17, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions site/.eslintrc.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -91,6 +91,9 @@ rules:
- allowSingleExtends: true
"brace-style": "off"
"curly": ["error", "all"]
"eslint-comments/disable-enable-pair":
- error
- allowWholeFile: true
"eslint-comments/require-description": "error"
eqeqeq: error
import/default: "off"
Expand Down
1 change: 1 addition & 0 deletions site/e2e/playwright.config.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ const localURL = (port: number, path: string): string => {
};

export default defineConfig({
preserveOutput: "failures-only",
projects: [
{
name: "setup",
Expand Down
160 changes: 110 additions & 50 deletions site/e2e/reporter.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,85 +1,145 @@
import fs from "fs";
/* eslint-disable no-console -- Logging is sort of the whole point here */
import * as fs from "fs/promises";
import type {
FullConfig,
Suite,
TestCase,
TestResult,
FullResult,
Reporter,
TestError,
} from "@playwright/test/reporter";
import axios from "axios";
import type { Writable } from "stream";

class CoderReporter implements Reporter {
config: FullConfig | null = null;
testOutput = new Map<string, Array<[Writable, string]>>();
passedCount = 0;
failedTests: TestCase[] = [];
timedOutTests: TestCase[] = [];

onBegin(config: FullConfig, suite: Suite) {
// eslint-disable-next-line no-console -- Helpful for debugging
console.log(`Starting the run with ${suite.allTests().length} tests`);
this.config = config;
console.log(`==> Running ${suite.allTests().length} tests`);
}

onTestBegin(test: TestCase) {
// eslint-disable-next-line no-console -- Helpful for debugging
console.log(`Starting test ${test.title}`);
this.testOutput.set(test.id, []);
console.log(`==> Starting test ${test.title}`);
}

onStdOut(chunk: string, test: TestCase, _: TestResult): void {
// eslint-disable-next-line no-console -- Helpful for debugging
console.log(
`[stdout] [${test ? test.title : "unknown"}]: ${chunk.replace(
/\n$/g,
"",
)}`,
);
onStdOut(chunk: string, test?: TestCase, _?: TestResult): void {
if (!test) {
const preserve = this.config?.preserveOutput === "always";
if (preserve) {
console.log(`[stdout] ${chunk.replace(/\n$/g, "")}`);
}
return;
}
this.testOutput.get(test.id)!.push([process.stdout, chunk]);
}

onStdErr(chunk: string, test: TestCase, _: TestResult): void {
// eslint-disable-next-line no-console -- Helpful for debugging
console.log(
`[stderr] [${test ? test.title : "unknown"}]: ${chunk.replace(
/\n$/g,
"",
)}`,
);
onStdErr(chunk: string, test?: TestCase, _?: TestResult): void {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We might be losing here output from coderd, which can be really useful during backend debugging. In the legacy version, it is logged like this:

[stderr] [unknown]: [WebServer] 2023-10-17 06:54:03.412 [info]  provisionerd.runner: apply successful  job_id=89020454-1bd8-4eed-a0c9-eb12fa532a92  template_name=68ac3052  template_version=hardcore_moser9  workspace_build_id=465c8cad-3fcb-42fb-b9bb-56007b4a1db3  workspace_id=74006ba8-82a8-4693-b971-f3da61ad02e0  workspace_name=d93260bd  workspace_owner=admin  workspace_transition=start  resource_count=1  resources="[name:\"example\" type:\"echo\"]"  state_len=0

It looks like the new reporter simply skips these log records.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

that was sort of intentional. it adds a lot of noise when trying to debug a frontend failure, and since it's not tied to a specific test case it's hard to buffer and display later in a way that makes sense.

I also added some logic for preserveOutput, but I just read the docs and it turns out it does something entirely different from what I expected, and can't even be set from the command line like I hoped 😵‍💫

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the idea was supposed to be that backend peeps could set --preserveOutput=always when they ran the tests... I'd really like to find a compromise here to keep the output clean when possible. it's just always such a pain to find the actual error in all of the mountains of logs.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

example run, which now has 41 occurrences of the word "error" but succeeded https://github.com/coder/coder/actions/runs/6549912328/job/17787879014?pr=10304

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A good compromise would be only filtering out audit_log entries, which do not bring a lot of value. 👍

I would leave coderd output as it is helpful with debugging the request flow or provisioner behavior, especially while dealing with flaky issues.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if we can also ignore lines like echo: recv done on Session session_id= error=EOF then I'll be happy. :)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agree 👍

if (!test) {
const preserve = this.config?.preserveOutput === "always";
if (preserve) {
console.error(`[stderr] ${chunk.replace(/\n$/g, "")}`);
}
return;
}
this.testOutput.get(test.id)!.push([process.stderr, chunk]);
}

async onTestEnd(test: TestCase, result: TestResult) {
// eslint-disable-next-line no-console -- Helpful for debugging
console.log(`Finished test ${test.title}: ${result.status}`);
console.log(`==> Finished test ${test.title}: ${result.status}`);

if (result.status === "passed") {
this.passedCount++;
}

if (result.status === "failed") {
this.failedTests.push(test);
}

if (result.status !== "passed") {
// eslint-disable-next-line no-console -- Helpful for debugging
console.log("errors", result.errors, "attachments", result.attachments);
if (result.status === "timedOut") {
this.timedOutTests.push(test);
}
await exportDebugPprof(test.title);

const outputFile = `test-results/debug-pprof-goroutine-${test.title}.txt`;
await exportDebugPprof(outputFile);

const preserve = this.config?.preserveOutput;
const logOutput =
preserve === "always" ||
(result.status !== "passed" && preserve !== "never");
if (logOutput) {
console.log(`Data from pprof has been saved to ${outputFile}`);
console.log("==> Output");
const output = this.testOutput.get(test.id)!;
for (const [target, chunk] of output) {
target.write(`${chunk.replace(/\n$/g, "")}\n`);
}

if (result.errors.length > 0) {
console.log("==> Errors");
for (const error of result.errors) {
reportError(error);
}
}

if (result.attachments.length > 0) {
console.log("==> Attachments");
for (const attachment of result.attachments) {
console.log(attachment);
}
}
}
this.testOutput.delete(test.id);
}

onEnd(result: FullResult) {
// eslint-disable-next-line no-console -- Helpful for debugging
console.log(`Finished the run: ${result.status}`);
console.log(`==> Tests ${result.status}`);
console.log(`${this.passedCount} passed`);
if (this.failedTests.length > 0) {
console.log(`${this.failedTests.length} failed`);
for (const test of this.failedTests) {
console.log(` ${test.location.file} › ${test.title}`);
}
}
if (this.timedOutTests.length > 0) {
console.log(`${this.timedOutTests.length} timed out`);
for (const test of this.timedOutTests) {
console.log(` ${test.location.file} › ${test.title}`);
}
}
}
}

const exportDebugPprof = async (testName: string) => {
const url = "http://127.0.0.1:6060/debug/pprof/goroutine?debug=1";
const outputFile = `test-results/debug-pprof-goroutine-${testName}.txt`;
const exportDebugPprof = async (outputFile: string) => {
const response = await axios.get(
"http://127.0.0.1:6060/debug/pprof/goroutine?debug=1",
);
if (response.status !== 200) {
throw new Error(`Error: Received status code ${response.status}`);
}

await axios
.get(url)
.then((response) => {
if (response.status !== 200) {
throw new Error(`Error: Received status code ${response.status}`);
}
await fs.writeFile(outputFile, response.data);
};

fs.writeFile(outputFile, response.data, (err) => {
if (err) {
throw new Error(`Error writing to ${outputFile}: ${err.message}`);
} else {
// eslint-disable-next-line no-console -- Helpful for debugging
console.log(`Data from ${url} has been saved to ${outputFile}`);
}
});
})
.catch((error) => {
throw new Error(`Error: ${error.message}`);
});
const reportError = (error: TestError) => {
if (error.location) {
console.log(`${error.location.file}:${error.location.line}:`);
}
if (error.snippet) {
console.log(error.snippet);
}

if (error.message) {
console.log(error.message);
} else {
console.log(error);
}
};

// eslint-disable-next-line no-unused-vars -- Playwright config uses it
Expand Down