web icon indicating copy to clipboard operation
web copied to clipboard

[@web/test-runner] `requestAnimationFrame` sometimes not firing callback

Open trusktr opened this issue 2 years ago • 6 comments

Yesterday I ported Lume tests from Karma(+Jasmine) to @web/test-runner (with jest-browser-globals for Jest's version of expect(), and this made porting very easy because it is very similar to Jasmine's expect()), and it is AWESOME!

Everything about @web/test-runner is soooooooooo goooooooooood in every way (worth an entire article), not to mention I'm running all tests as vanilla ES Modules. 🎉

In Karma I had to battle so many issues to get things wired up, gave up on source maps and never had proper stack traces, while with web-test-runner I simply deleted lots of dependencies and configuration, and everything just worked after adding import maps and tweaking test code just a tiny bit. The test debugging experience is phenomenal, and browser launching is beautifully abstracted so it really feels as simple as running a simple JSDom test runner except its a real browser.


One thing I noticed though, is that one of my tests that relies on requestAnimationFrame started failing sometimes. Once in a while, the callback will never fire. (In Karma, it was not tampered with, so it always worked, however I do want to migrate to mocked timers for determinism.)

I see that rAF is mocked (EDIT: not mocked, but wrapped) here by web-test-runner:

https://github.com/modernweb-dev/web/blob/f8c22bc6cf0c35bdd345f6ea3907337ae1496736/packages/test-runner-chrome/src/ChromeLauncherPage.ts#L68-L85

Is there a way to disable this for now, so I can avoid failing tests?

EDIT: I see, rAF requires browser tabs to be visible for callbacks to fire. Is the tab switching logic perhaps not working? Does it need to be awaited?

What if, instead of multiple tabs, it uses multiple windows? Then they can all be visible and all of them can fire rAF without this wrapper?

trusktr avatar Oct 29 '23 04:10 trusktr

I am able to work around the issue for now by adding this to web-test-runner.config.js:

concurrency: 1

which works, but not as quickly.

trusktr avatar Oct 29 '23 05:10 trusktr

Hmmm, I'm investigating that piece of code, and sometimes I can't reproduce the problem at all (f.e. 100 runs work fine). But then sometimes, it fails right away. So I'm not sure that concurrency: 1 actually fixed anything because it behaved the same as when I couldn't reproduce the issue (in theory, if there is only one tab, it will always be the one that's focused).

F.e. last night I could not reproduce at all. Today, I get onto my laptop, and it happened first try (test timeout because callback never called never calls done()).

trusktr avatar Oct 29 '23 19:10 trusktr

We recently discovered some tests breaking too, im on mobile but some more info on this here: https://mastodon.social/@43081j/111255035153197046

I did have a chat with @justinfagnani recently who said he found some chrome flag, could you share some info on that justin?

thepassle avatar Oct 29 '23 19:10 thepassle

A workaround to this is probably to install fake timers with sinon. I haven't tried it yet.

Using fake timers has allowed writing deterministic tests that don't fail due timing differences across OSes, hardware, and environments. With fake timers in place, we always get the same time stamps across test re-runs, the same ordering of code across tests runs, etc.

trusktr avatar Oct 29 '23 20:10 trusktr

I'm trying to debug, and to me it seems that puppeteer promises for exposed functions are not resolving inside the browser context.

I changed ChromeLauncherPage.ts to the following to try to make it easier to understand,
// ...elided...
import { Mutex } from 'async-mutex';

const mutex = new Mutex();

declare global {
  interface Window {
    __bringTabToFront: () => Promise<void>;
    __acquireMutexLock: (id: string) => Promise<void>;
    __releaseMutexLock: (id: string) => Promise<void>;
  }
}

export class ChromeLauncherPage {
// ...elided...
  private patchAdded = false;
  private mutexReleasers: Record<number, () => void> = {};

// ...elided...

  async runSession(url: string, coverage: boolean) {
// ...elided...

    // Patching the browser page to workaround an issue in the new headless mode of Chrome where some functions
    // with callbacks (requestAnimationFrame and requestIdleCallback) are not executing their callbacks.
    // https://github.com/puppeteer/puppeteer/issues/10350
    if (!this.patchAdded) {
      await this.puppeteerPage.exposeFunction('__bringTabToFront', async () => {
        await this.puppeteerPage.bringToFront()
      });
      await this.puppeteerPage.exposeFunction('__acquireMutexLock', async (id: string) => {
        const release = await mutex.acquire()
        this.mutexReleasers[id] = release
      });
      await this.puppeteerPage.exposeFunction('__releaseMutexLock', (id: string) => {
        this.mutexReleasers[id]?.();
      });
      await this.puppeteerPage.evaluateOnNewDocument(() => {
        const fakeIds = new Set<string>()
        const win = window as any

        // eslint-disable-next-line @typescript-eslint/ban-types
        function patchFunction(name: string, fn: Function, cancelName: string, cancelFn: Function) {
          win[name] = async (callback, ...args: unknown[]) => {
            const fakeId = Math.random().toString().substring(2) + Math.random().toString().substring(2);
            fakeIds.add(fakeId)

            window.__acquireMutexLock(fakeId).then(() => {
              // Make sure that the tab running the test code is brought back to the front.
              window.__bringTabToFront().then(() => {
                fn.call(window, () => {
                  // if not canceled
                  if (fakeIds.has(fakeId)) callback()

                  window.__releaseMutexLock(fakeId);
                }, ...args);
              })
            });

            return fakeId
          };

          win[cancelName] = async (fakeId: string) => {
            fakeIds.delete(fakeId)
          }
        }

        patchFunction('requestAnimationFrame', window.requestAnimationFrame, 'cancelAnimationFrame', window.cancelAnimationFrame);
        patchFunction('requestIdleCallback', window.requestIdleCallback, 'cancelIdleCallback', window.cancelIdleCallback);
      });
      this.patchAdded = true;
    }

    await this.puppeteerPage.setViewport({ height: 600, width: 800 });
    await this.puppeteerPage.goto(url);
  }

// ...elided...

and I can verify that the code inside of, for example, __acquireMutexLock runs in the Node.js context, however the browser-side code hangs forever because the promise appears to never resolve:

            window.__acquireMutexLock(fakeId).then(() => {
              // This never runs!
            })

Because that promise never fires the then block, we never run the rAF or rIC in my version of the code, and tests always fail 100% of the time.

If that would work the way that Puppeteer documentation shows (which is the same in the docs for puppeteer 20.9.0, the version test-runner uses), then maybe what I'm trying might work.

UPDATE

I simplified it to the following,
import { Page, JSCoverageEntry } from 'puppeteer-core';
import { TestRunnerCoreConfig } from '@web/test-runner-core';
import { v8ToIstanbul } from '@web/test-runner-coverage-v8';
import { SessionResult } from '@web/test-runner-core';
import { Mutex } from 'async-mutex';

const mutex = new Mutex();

declare global {
  interface Window {
    __bringTabToFront: (id: string) => Promise<void>;
    __releaseMutexLock: (id: string) => Promise<void>;
  }
}

export class ChromeLauncherPage {
  private config: TestRunnerCoreConfig;
  private testFiles: string[];
  private product: string;
  public puppeteerPage: Page;
  private nativeInstrumentationEnabledOnPage = false;
  private patchAdded = false;
  private mutexReleasers: Record<number, () => void> = {};

  constructor(
    config: TestRunnerCoreConfig,
    testFiles: string[],
    product: string,
    puppeteerPage: Page,
  ) {
    this.config = config;
    this.testFiles = testFiles;
    this.product = product;
    this.puppeteerPage = puppeteerPage;
  }

  async runSession(url: string, coverage: boolean) {
    if (
      coverage &&
      this.config.coverageConfig?.nativeInstrumentation !== false &&
      this.product === 'chromium'
    ) {
      if (this.nativeInstrumentationEnabledOnPage) {
        await this.puppeteerPage.coverage.stopJSCoverage();
      }
      this.nativeInstrumentationEnabledOnPage = true;
      await this.puppeteerPage.coverage.startJSCoverage({
        includeRawScriptCoverage: true,
      });
    }

    // Patching the browser page to workaround an issue in the new headless mode of Chrome where some functions
    // with callbacks (requestAnimationFrame and requestIdleCallback) are not executing their callbacks.
    // https://github.com/puppeteer/puppeteer/issues/10350
    if (!this.patchAdded) {
      await this.puppeteerPage.exposeFunction('__bringTabToFront', async (id: string) => {
        const release = await mutex.acquire()
        this.mutexReleasers[id] = release
        await this.puppeteerPage.bringToFront()
      });
      await this.puppeteerPage.exposeFunction('__releaseMutexLock', (id: string) => {
        this.mutexReleasers[id]?.();
      });
      await this.puppeteerPage.evaluateOnNewDocument(() => {
        const fakeIds = new Set<string>()
        const win = window as any

        // eslint-disable-next-line @typescript-eslint/ban-types
        function patchFunction(name: string, fn: Function, cancelName: string, cancelFn: Function) {
          win[name] = async (callback, ...args: unknown[]) => {
            const fakeId = Math.random().toString().substring(2) + Math.random().toString().substring(2);
            fakeIds.add(fakeId)

            // Make sure that the tab running the test code is brought back to the front.
            window.__bringTabToFront(fakeId).then(() => {
              fn.call(window, () => {
                // if not canceled
                if (fakeIds.has(fakeId)) callback()

                window.__releaseMutexLock(fakeId);
              }, ...args);
            });

            return fakeId
          };

          win[cancelName] = async (fakeId: string) => {
            fakeIds.delete(fakeId)
          }
        }

        patchFunction('requestAnimationFrame', window.requestAnimationFrame, 'cancelAnimationFrame', window.cancelAnimationFrame);
        patchFunction('requestIdleCallback', window.requestIdleCallback, 'cancelIdleCallback', window.cancelIdleCallback);
      });
      this.patchAdded = true;
    }

    await this.puppeteerPage.setViewport({ height: 600, width: 800 });
    await this.puppeteerPage.goto(url);
  }

  async stopSession(): Promise<SessionResult> {
    const testCoverage = await this.collectTestCoverage(this.config, this.testFiles);

    // navigate to an empty page to kill any running code on the page, stopping timers and
    // breaking a potential endless reload loop
    await this.puppeteerPage.goto('about:blank');

    return { testCoverage };
  }

  private async collectTestCoverage(config: TestRunnerCoreConfig, testFiles: string[]) {
    const userAgentPromise = this.puppeteerPage
      .browser()
      .userAgent()
      .catch(() => undefined);

    try {
      const coverageFromBrowser = await this.puppeteerPage.evaluate(
        () => (window as any).__coverage__,
      );

      if (coverageFromBrowser) {
        // coverage was generated by JS, return that
        return coverageFromBrowser;
      }
    } catch (error) {
      // evaluate throws when the test navigates in the browser
    }

    if (config.coverageConfig?.nativeInstrumentation === false) {
      throw new Error(
        'Coverage is enabled with nativeInstrumentation disabled. ' +
          'Expected coverage provided in the browser as a global __coverage__ variable.' +
          'Use a plugin like babel-plugin-istanbul to generate the coverage, or enable native instrumentation.',
      );
    }

    if (!this.nativeInstrumentationEnabledOnPage) {
      return undefined;
    }

    const [userAgent, coverageResult] = await Promise.all([
      userAgentPromise,
      this.puppeteerPage.coverage?.stopJSCoverage(),
    ]);
    const v8Coverage = coverageResult
      ?.map(entry => entry.rawScriptCoverage)
      .filter((cov): cov is Required<JSCoverageEntry>['rawScriptCoverage'] => cov !== undefined);
    this.nativeInstrumentationEnabledOnPage = false;

    return v8ToIstanbul(config, testFiles, v8Coverage, userAgent);
  }
}

which is now closer to the original, still a little easier to understand, but the window.__bringTabToFront(fakeId) promise is never resolving on the client.

Did I do overlook something? Or have you all had this issue too with promises not resolving?

trusktr avatar Oct 29 '23 22:10 trusktr

I went looking for the flag in our configs and didn't find it yet. I seem to recall either a flag, or that Chrome fixed an issue. @rictic do you remember anything here?

We can reach out to Chrome too.

justinfagnani avatar Oct 29 '23 22:10 justinfagnani