Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
12 changes: 8 additions & 4 deletions docs/reports.mdx
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ build/reports/plugwright/<env>.log per-environment output, matrix runs o
```json
{
"environment": "staging",
"summary": { "total": 47, "passed": 33, "failed": 0, "skipped": 14, "durationMs": 152340 },
"summary": { "total": 47, "passed": 33, "failed": 0, "skipped": 14, "skippedInstances": 0, "durationMs": 152340 },
"tests": [
{
"file": "…/dist/commands.spec.js",
Expand Down Expand Up @@ -61,15 +61,19 @@ A test (or block) run with [`concurrency`](/writing-tests) still gets one entry,
"plugin": null,
"botUsername": null,
"instances": [
{ "index": 1, "botUsername": "pw_a1", "passed": true, "durationMs": 640, "error": null },
{ "index": 2, "botUsername": "pw_b2", "passed": false, "durationMs": 812, "error": "Expected message matching \"Claimed\" not received" },
{ "index": 3, "botUsername": "pw_c3", "passed": true, "durationMs": 701, "error": null }
{ "index": 1, "botUsername": "pw_a1", "passed": true, "durationMs": 640, "error": null, "skipped": false, "skipReason": null },
{ "index": 2, "botUsername": "pw_b2", "passed": false, "durationMs": 812, "error": "Expected message matching \"Claimed\" not received", "skipped": false, "skipReason": null },
{ "index": 3, "botUsername": "pw_c3", "passed": true, "durationMs": 0, "error": null, "skipped": true, "skipReason": "serial block \"claims\" stopped at \"only one player can claim the chest\"" }
]
}
```

`instances` is `null` for an ordinary, non-concurrent test — `botUsername` on the row itself is where its bot lives instead. The JUnit report doesn't carry this breakdown; it only ever sees the one aggregated pass/fail/duration, so read the JSON report when a concurrent test fails.

Read `skipped` before `passed`. Instances of a `describe.serial` block diverge: one whose earlier test failed stops there, and every position after it is recorded with `passed: true` and `durationMs: 0` without having run. Counting those as passes is how a block that broke on three of ten bots comes out looking like seven-out-of-ten coverage.

The row's own `status` is `skip` only when *every* instance skipped, so `summary.skipped` misses instance-level skips entirely. `summary.skippedInstances` counts them across the whole run; the console summary prints the same number next to `Skipped`.

## JUnit XML

```xml
Expand Down
17 changes: 16 additions & 1 deletion runner-package/lib/matchers.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,10 @@ import { ServerWrapper } from './server.js';
import { GuiItemLocator } from './wrappers.js';
import { sleep } from './utils.js';

/** How many of the most recent lines a failed `toHaveReceivedMessage` quotes back. Enough to
* show the server's actual answer without pasting a login wall's worth of chat into a report. */
const MESSAGE_TAIL_LINES = 10;

export class RunnerMatchers<T = unknown> extends Matchers<T> {
constructor(actual: T, isNot: boolean = false) {
super(actual, isNot);
Expand Down Expand Up @@ -109,10 +113,21 @@ export class RunnerMatchers<T = unknown> extends Matchers<T> {
const effectiveSince = since ?? (this.actual instanceof PlayerWrapper ? undefined : this.actual.startIndex);
const view = (): string[] => buffer.slice(effectiveSince);

// What arrived instead is the whole diagnosis: "the server said nothing" and "the server
// answered something else" fail identically otherwise, and on a live server under
// `concurrency: N` that is the difference between a throttled command and a real bug.
const received = (): string => {
const seen = view();
if (seen.length === 0) return '; nothing was received';
const tail = seen.slice(-MESSAGE_TAIL_LINES);
const elided = seen.length > tail.length ? `last ${tail.length} of ${seen.length}` : `${seen.length}`;
return `; ${elided} received: ${tail.map(line => JSON.stringify(line)).join(', ')}`;
};

await this.pollAssertion(
() => view().some(isMatch),
() => `Expected NOT to receive message matching "${expectedMessage}", but received: "${view().find(isMatch)}"`,
() => `Expected message matching "${expectedMessage}" not received`,
() => `Expected message matching "${expectedMessage}" not received${received()}`,
{ timeout, pollingRate }
);
}
Expand Down
68 changes: 56 additions & 12 deletions runner-package/lib/reporter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -15,8 +15,17 @@ function statusOf(result: TestResult): 'PASS' | 'FAIL' | 'SKIP' {
return result.passed ? 'PASS' : 'FAIL';
}

/** min/avg/max duration across a `concurrency > 1` result's instances. */
function instanceStats(instances: NonNullable<TestResult['instances']>): { min: number; avg: number; max: number } {
type Instances = NonNullable<TestResult['instances']>;

/** The instances that actually ran the test. A skipped instance carries `durationMs: 0` and no
* outcome of its own, so counting it as a pass overstates how many bots got through and its
* zero drags every duration statistic down. */
function ranInstances(instances: Instances): Instances {
return instances.filter(i => !i.skipped);
}

/** min/avg/max duration across a `concurrency > 1` result's instances that ran. */
function instanceStats(instances: Instances): { min: number; avg: number; max: number } {
const durations = instances.map(i => i.durationMs);
return {
min: Math.min(...durations),
Expand All @@ -39,7 +48,15 @@ export function printTestSummary(testResults: TestResult[]): number {
console.log(` Total: ${pc.bold(String(testResults.length))}`);
console.log(` Passed: ${pc.green(pc.bold(String(passed.length)))}`);
console.log(` Failed: ${failed.length > 0 ? pc.red(pc.bold(String(failed.length))) : pc.dim(String(failed.length))}`);
console.log(` Skipped: ${skipped.length > 0 ? pc.yellow(pc.bold(String(skipped.length))) : pc.dim(String(skipped.length))}`);
// A test row only counts as skipped when every one of its concurrent instances skipped it,
// so under `concurrency: N` a block that stops early on some bots leaves "Skipped: 0" while
// dozens of instances never ran. Count those too rather than let them disappear.
const skippedInstances = testResults.reduce(
(sum, r) => sum + (r.instances?.filter(i => i.skipped).length ?? 0),
0,
);
const instanceNote = skippedInstances > 0 ? pc.dim(` (${skippedInstances} concurrent instances)`) : '';
console.log(` Skipped: ${skipped.length > 0 ? pc.yellow(pc.bold(String(skipped.length))) : pc.dim(String(skipped.length))}${instanceNote}`);
console.log(` Duration: ${pc.dim(formatDuration(totalDuration))}`);

const statusCol = 'Status';
Expand All @@ -66,10 +83,15 @@ export function printTestSummary(testResults: TestResult[]): number {
: pc.red(pc.bold(statusPadded));
const duration = formatDuration(result.durationMs);
// A concurrent test/block's row is one aggregate over N instances — say how many
// passed right in the table, not just in the failed-tests detail below.
const instanceTag = result.instances
? pc.dim(` [${result.instances.filter(i => i.passed).length}/${result.instances.length}]`)
: '';
// passed right in the table, not just in the failed-tests detail below. The ratio is
// over the instances that ran, with the skipped ones counted separately: reading
// "[8/10]" when two of those ten never reached this test is worse than reading nothing.
const instanceTag = result.instances ? (() => {
const ran = ranInstances(result.instances!);
const skippedCount = result.instances!.length - ran.length;
const skipNote = skippedCount > 0 ? `, ${skippedCount} skipped` : '';
return pc.dim(` [${ran.filter(i => i.passed).length}/${ran.length}${skipNote}]`);
})() : '';
console.log(` ${coloredStatus} ${result.testName.padEnd(testWidth)} ${pc.dim(duration.padStart(durationWidth))}${instanceTag}`);
}

Expand Down Expand Up @@ -99,14 +121,28 @@ export function printTestSummary(testResults: TestResult[]): number {
}

if (result.instances) {
const { min, avg, max } = instanceStats(result.instances);
console.log(` ${pc.dim(`${result.instances.length} instances: min ${formatDuration(min)} / avg ${formatDuration(avg)} / max ${formatDuration(max)}`)}`);
const ran = ranInstances(result.instances);
const skippedCount = result.instances.length - ran.length;
const skipNote = skippedCount > 0 ? `, ${skippedCount} skipped` : '';
if (ran.length > 0) {
const { min, avg, max } = instanceStats(ran);
console.log(` ${pc.dim(`${ran.length} instances ran${skipNote}: min ${formatDuration(min)} / avg ${formatDuration(avg)} / max ${formatDuration(max)}`)}`);
} else {
console.log(` ${pc.dim(`0 instances ran${skipNote}`)}`);
}
for (const instance of result.instances) {
const tag = `[${instance.index}/${result.instances.length}]`;
const label = instance.botUsername ?? '?';
const status = instance.passed ? pc.green('OK') : pc.red('FAIL');
const detail = instance.error ? pc.red(` ${instance.error.message}`) : '';
console.log(` ${pc.dim(`- ${tag} ${label}:`)} ${status} ${pc.dim(`(${formatDuration(instance.durationMs)})`)}${detail}`);
const status = instance.skipped
? pc.yellow('SKIP')
: instance.passed ? pc.green('OK') : pc.red('FAIL');
const detail = instance.skipped
? pc.dim(instance.skipReason ? ` ${instance.skipReason}` : '')
: instance.error ? pc.red(` ${instance.error.message}`) : '';
// A skip has no duration of its own, so printing "(0ms)" next to it reads
// as an instant pass — the exact confusion this branch exists to remove.
const timing = instance.skipped ? '' : ` ${pc.dim(`(${formatDuration(instance.durationMs)})`)}`;
console.log(` ${pc.dim(`- ${tag} ${label}:`)} ${status}${timing}${detail}`);
}
}

Expand Down Expand Up @@ -143,6 +179,12 @@ export function writeJsonReport(path: string, environmentName: string, testResul
passed: passed.length,
failed: failed.length,
skipped: skipped.length,
// Instance-level skips, which `skipped` above cannot show: a test row is only
// skipped when all of its concurrent instances were.
skippedInstances: testResults.reduce(
(sum, r) => sum + (r.instances?.filter(i => i.skipped).length ?? 0),
0,
),
durationMs,
},
tests: testResults.map(r => ({
Expand All @@ -163,6 +205,8 @@ export function writeJsonReport(path: string, environmentName: string, testResul
passed: i.passed,
durationMs: i.durationMs,
error: i.error ? i.error.message : null,
skipped: !!i.skipped,
skipReason: i.skipReason ?? null,
}))
: null,
})),
Expand Down
4 changes: 3 additions & 1 deletion runner-package/lib/test-runner.ts
Original file line number Diff line number Diff line change
Expand Up @@ -335,7 +335,7 @@ export async function runSerialBlock(params: RunSerialBlockParams): Promise<Test
console.log(pc.dim(` Test: ${testCase.name} - SKIPPED (${stopReason})`) + formatInstanceTag(instance));
results.push({
file, testName: testCase.name, passed: true, durationMs: 0, skipped: true,
skipReason: stopReason, plugin: pluginName,
skipReason: stopReason, plugin: pluginName, botUsername: player.username,
});
continue;
}
Expand Down Expand Up @@ -444,6 +444,8 @@ function aggregateInstances(results: TestResult[]): TestResult {
passed: r.passed,
durationMs: r.durationMs,
error: r.error,
skipped: r.skipped,
skipReason: r.skipReason,
})),
};
}
6 changes: 6 additions & 0 deletions runner-package/lib/types.ts
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,12 @@ export interface TestInstanceResult {
passed: boolean;
durationMs: number;
error?: Error;
/** Set when this instance never ran the test: its serial block stopped at an earlier one,
* so nothing here was exercised. Check it before `passed` — a skip carries `passed: true`
* and `durationMs: 0`, which on its own is indistinguishable from an instant pass. */
skipped?: boolean;
/** Why this instance skipped, copied from the block's stop reason. */
skipReason?: string;
}

export interface TestResult {
Expand Down
Loading