From 68cdb56192630bd41bc3b31d57dad1feb08e57ea Mon Sep 17 00:00:00 2001 From: Monikon Date: Sat, 12 Sep 2026 16:19:58 +0300 Subject: [PATCH 1/5] fix(runner): carry skip state into concurrent instance results A serial block instance that stopped early reported its remaining tests as `passed: true, durationMs: 0`, and `aggregateInstances` copied that into the aggregate's `instances` array verbatim. A skip was then indistinguishable from an instant pass for every consumer of that array. Skipped instances also lost their bot's name, which the reporter renders as "?". Adds `skipped`/`skipReason` to `TestInstanceResult` and sets `botUsername` on skip rows. Rendering is unchanged here; see the follow-up. --- runner-package/lib/test-runner.ts | 4 +++- runner-package/lib/types.ts | 6 ++++++ 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/runner-package/lib/test-runner.ts b/runner-package/lib/test-runner.ts index 050d750..3691e9b 100644 --- a/runner-package/lib/test-runner.ts +++ b/runner-package/lib/test-runner.ts @@ -335,7 +335,7 @@ export async function runSerialBlock(params: RunSerialBlockParams): Promise Date: Sat, 12 Sep 2026 16:20:44 +0300 Subject: [PATCH 2/5] fix(reporter): show skipped concurrent instances as skips, not passes The per-test instance ratio counted skipped instances as passes, so a block that stopped early on two of ten bots still printed "[8/10]" with two of those eight never having run the test. The detail list printed the same instances as "OK (0ms)" under a "?" label, and their zeros pulled the min/avg duration down. The ratio is now over the instances that ran, with the skip count alongside it; skipped instances render as SKIP with their stop reason and no duration. The JSON report carries `skipped`/`skipReason` per instance. --- runner-package/lib/reporter.ts | 52 +++++++++++++++++++++++++++------- 1 file changed, 41 insertions(+), 11 deletions(-) diff --git a/runner-package/lib/reporter.ts b/runner-package/lib/reporter.ts index dfa8a8c..80d4db5 100644 --- a/runner-package/lib/reporter.ts +++ b/runner-package/lib/reporter.ts @@ -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): { min: number; avg: number; max: number } { +type Instances = NonNullable; + +/** 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), @@ -66,10 +75,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}`); } @@ -99,14 +113,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}`); } } @@ -163,6 +191,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, })), From 106ca1a64c9a1b68b3b76d809d22d58c6c9eb7ea Mon Sep 17 00:00:00 2001 From: Monikon Date: Sat, 12 Sep 2026 16:21:15 +0300 Subject: [PATCH 3/5] fix(reporter): count instance-level skips in the run summary A test row only counts as skipped when every one of its concurrent instances skipped it, so a run where several bots stopped their block early still printed "Skipped: 0" with nothing anywhere saying otherwise. The console summary now notes how many concurrent instances were skipped next to the test count, and the JSON report carries the same number as `summary.skippedInstances`. --- runner-package/lib/reporter.ts | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-) diff --git a/runner-package/lib/reporter.ts b/runner-package/lib/reporter.ts index 80d4db5..918f197 100644 --- a/runner-package/lib/reporter.ts +++ b/runner-package/lib/reporter.ts @@ -48,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'; @@ -171,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 => ({ From ee7c033e75fed160064327992513138bf3076591 Mon Sep 17 00:00:00 2001 From: Monikon Date: Sat, 12 Sep 2026 16:22:17 +0300 Subject: [PATCH 4/5] feat(matchers): quote what arrived when toHaveReceivedMessage times out "Expected message matching X not received" reads the same whether the server answered something else or said nothing at all, which is the whole question when a test fails on some concurrent instances and passes on others. The failure now appends the last 10 lines of the buffer it searched, or says outright that nothing was received. --- runner-package/lib/matchers.ts | 17 ++++++++++++++++- 1 file changed, 16 insertions(+), 1 deletion(-) diff --git a/runner-package/lib/matchers.ts b/runner-package/lib/matchers.ts index 0dac074..b8db911 100644 --- a/runner-package/lib/matchers.ts +++ b/runner-package/lib/matchers.ts @@ -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 extends Matchers { constructor(actual: T, isNot: boolean = false) { super(actual, isNot); @@ -109,10 +113,21 @@ export class RunnerMatchers extends Matchers { 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 } ); } From 996cc191a66c25d4537ae8faf86b41ab7209084e Mon Sep 17 00:00:00 2001 From: Monikon Date: Sat, 12 Sep 2026 16:22:54 +0300 Subject: [PATCH 5/5] docs(reports): document instance skips in the JSON report Covers the new `skipped`/`skipReason` fields on each concurrent instance, `summary.skippedInstances`, and why a skipped instance's `passed: true` must not be read as a pass. --- docs/reports.mdx | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/docs/reports.mdx b/docs/reports.mdx index 54d7b4c..dbb2c34 100644 --- a/docs/reports.mdx +++ b/docs/reports.mdx @@ -16,7 +16,7 @@ build/reports/plugwright/.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", @@ -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