Test failures failing to show at the bottom since the change to use BufferedLogging #2936

paladox · 2025-04-25T13:52:45Z

Hi, we're trying to upgrade from the following:

    "@web/test-runner": "^0.14.0",
    "@web/test-runner-playwright": "^0.9.0",
    "@web/test-runner-visual-regression": "^0.7.1",

to

    "@web/test-runner": "^0.20.1",
    "@web/test-runner-playwright": "^0.11.0",
    "@web/test-runner-visual-regression": "^0.10.0",

and our config is:

import path from 'path';
import { esbuildPlugin } from '@web/dev-server-esbuild';
import { defaultReporter, summaryReporter } from '@web/test-runner';
import { visualRegressionPlugin } from '@web/test-runner-visual-regression/plugin';

function testRunnerHtmlFactory() {
  return (testFramework) => `
    <!DOCTYPE html>
    <html>
      <head>
        <link rel="stylesheet" href="polygerrit-ui/app/styles/main.css">
        <link rel="stylesheet" href="polygerrit-ui/app/styles/fonts.css">
        <link rel="stylesheet" href="polygerrit-ui/app/styles/material-icons.css">
      </head>
      <body>
        <script type="module" src="${testFramework}"></script>
      </body>
    </html>
  `;
}

const runUnderBazel = !!process.env['RUNFILES_DIR'];

function getModulesDir() {
  return runUnderBazel
    ? [
        path.join(process.cwd(), 'external/plugins_npm/node_modules'),
        path.join(process.cwd(), 'external/ui_npm/node_modules'),
        path.join(process.cwd(), 'external/ui_dev_npm/node_modules'),
      ]
    : [
        path.join(process.cwd(), 'plugins/node_modules'),
        path.join(process.cwd(), 'app/node_modules'),
        path.join(process.cwd(), 'node_modules'),
      ];
}

function getArgValue(flag) {
  const withEquals = process.argv.find((arg) => arg.startsWith(`${flag}=`));
  if (withEquals) return withEquals.split('=')[1];

  const index = process.argv.indexOf(flag);
  if (index !== -1 && process.argv[index + 1] && !process.argv[index + 1].startsWith('--')) {
    return process.argv[index + 1];
  }

  return undefined;
}

const pathPrefix = runUnderBazel ? 'polygerrit-ui/' : '';
const testFiles = getArgValue('--test-files') ?? `${pathPrefix}app/**/*_test.{ts,js}`;
const rootDir = getArgValue('--root-dir') ?? `${path.resolve(process.cwd())}/`;
const tsConfig = getArgValue('--ts-config') ?? `${pathPrefix}app/tsconfig.json`;

/** @type {import('@web/test-runner').TestRunnerConfig} */
const config = {
  // TODO: https://g-issues.gerritcodereview.com/issues/365565157 - undo the
  // change once the underlying issue is fixed.
  concurrency: 1,

  files: [
    testFiles,
    `!${pathPrefix}**/node_modules/**/*`,
    ...(process.argv.includes('--run-screenshots')
      ? []
      : [`!${pathPrefix}app/**/*_screenshot_test.{ts,js}`]),
  ],

  port: 9876,

  nodeResolve: {
    modulePaths: getModulesDir(),
  },

  testFramework: {
    config: {
      ui: 'tdd',
      timeout: 5000,
    },
  },

  plugins: [
    esbuildPlugin({
      ts: true,
      target: 'es2020',
      tsconfig: tsConfig,
    }),
    visualRegressionPlugin({
      diffOptions: { threshold: 0.8 },
      update: process.argv.includes('--update-screenshots'),
    }),
  ],

  // serve from gerrit root directory so that we can serve fonts from
  // /lib/fonts/, see middleware.
  rootDir,

  reporters: [defaultReporter(), summaryReporter()],

  middleware: [
    // Fonts are in /lib/fonts/, but css tries to load from
    // /polygerrit-ui/app/fonts/. In production this works because our build
    // copies them over, see /polygerrit-ui/BUILD
    async (context, next) => {
      if (context.url.startsWith('/polygerrit-ui/app/fonts/')) {
        context.url = context.url.replace('/polygerrit-ui/app/', '/lib/');
      }
      await next();
    },
  ],

  testRunnerHtml: testRunnerHtmlFactory(),
};

export default config;

My problem is the test failures are not shown at the bottom. It took me a while to find where the test failure was

�[2K�[1A�[2K�[Gpolygerrit-ui/app/elements/gr-app_test.ts:

 🚧 Browser logs:
      Lit is in dev mode. Not recommended for production! See https://lit.dev/msg/dev-mode for more information.
      initResin
      initResin
      Multiple versions of Lit loaded. Loading multiple versions is not recommended. See https://lit.dev/msg/multiple-versions for more information.

 ❌ gr-app callback tests > requestUpdate in reactive-element is called after dispatching 'location-change' event in gr-router
      AssertionError: expected false to be true
      + expected - actual
      
      -false
      +true
      
      at n4.<anonymous> (polygerrit-ui/app/elements/gr-app_test.ts:40:11)

In the older versions it was shown at the bottom, made easier to discover. How do I get this behaviour back?

The text was updated successfully, but these errors were encountered:

paladox · 2025-04-25T20:46:50Z

Seems

web/packages/test-runner-core/src/cli/TestRunnerCli.ts

Line 282 in 29f73c5

if (this.runner.testRun === testRun) {

isn't getting triggered?

I created a custom formatter to call it after summeryReporter is called which worked around it. Seems this is caused by b2c8573. Which changed from TestRunnerLogger to using the BufferLogger

E.g.

let cachedLogger;
export function customSummaryReporter() {
  return {
    reportTestFileResults({ logger }) {
      cachedLogger = logger;
    },
    onTestRunFinished({ sessions }) {
      cachedLogger.logBufferedMessages();
    },
  };
};

I also tested to see what testRun returns in reportTestFileResults and got a 0. And this.runner.testRun returns 0.

paladox · 2025-04-26T12:23:22Z

Hmm, even crossing out

web/packages/test-runner-core/src/cli/TestRunnerCli.ts

Line 282 in 29f73c5

if (this.runner.testRun === testRun) {

doesn't fix it. But the workaround does. Strange?

paladox · 2025-04-26T18:25:29Z

Oh I think I know why. It's because we do the logging in

web/packages/test-runner/src/reporter/summaryReporter.ts

Line 103 in 29f73c5

onTestRunFinished({ sessions }) {

. But we call

web/packages/test-runner-core/src/cli/TestRunnerCli.ts

Line 282 in 29f73c5

if (this.runner.testRun === testRun) {

after reportTestFileResults but before onTestRunFinished. So we'd need to add cachedLogger.logBufferedMessages(); in onTestRunFinished for summery.

I guess it was missing cachedLogger.logBufferedMessages(); after all. Adding that fixed it.

MichaelWest22 · 2025-05-07T12:37:30Z

Yeah I found the same issue just before you and created a PR #2932 to try and fix it. I Don't think the buffered logger is actually needed for this missing error reporting logging (it is just a single action to do the error logging) which is why in my PR i just reverted to the non buffered logger to fix the issue. I was also worried that others could have worked around the missing error reporting and so putting error reporting back in now could now alter these users reporting so I added an option to turn on the error reporting but left it disabled to match the current broken behavior. Maybe this could default to on though. I also found an issue where when they broke the error reporting they added log reporting and when you combine this reporter with the defaultReporter like you have in your config it then prints all logs twice which is a bit annoying. So I also added a config flag to allow turning off the log logging if required.

MichaelWest22 · 2025-05-08T04:33:01Z

Also I think there may be an issue with the fix you have proposed as it is still reusing the buffered logger from the earlier test stage. This buffered logger has already been flushed out with .logBufferMessages() and then it adds the error logging on the end of the logger and you then flush it again but this also re-outputs the original log lines as the buffer logger is only designed to be flushed once at the end. This is why i found I had to create a new logger to resolve the issue for me anyway.

paladox · 2025-05-08T08:00:54Z

I think we can go along with your change.

paladox changed the title ~~How to get test failures to show at the bottom again~~ Tests failing to show at the bottom since the change to use BufferedLogging Apr 25, 2025

paladox changed the title ~~Tests failing to show at the bottom since the change to use BufferedLogging~~ Test failures failing to show at the bottom since the change to use BufferedLogging Apr 25, 2025

paladox mentioned this issue Apr 26, 2025

summaryReporter: Add missing cachedLogger.logBufferedMessages() call in onTestRunFinished #2937

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Test failures failing to show at the bottom since the change to use BufferedLogging #2936

Test failures failing to show at the bottom since the change to use BufferedLogging #2936

paladox commented Apr 25, 2025

paladox commented Apr 25, 2025 •

edited

Loading

paladox commented Apr 26, 2025

paladox commented Apr 26, 2025

MichaelWest22 commented May 7, 2025

MichaelWest22 commented May 8, 2025

paladox commented May 8, 2025

Test failures failing to show at the bottom since the change to use BufferedLogging #2936

Test failures failing to show at the bottom since the change to use BufferedLogging #2936

Comments

paladox commented Apr 25, 2025

paladox commented Apr 25, 2025 • edited Loading

paladox commented Apr 26, 2025

paladox commented Apr 26, 2025

MichaelWest22 commented May 7, 2025

MichaelWest22 commented May 8, 2025

paladox commented May 8, 2025

paladox commented Apr 25, 2025 •

edited

Loading