playwright icon indicating copy to clipboard operation
playwright copied to clipboard

[REGRESSION]: 1.28 does not work with electron-serve anymore.

Open mxschmitt opened this issue 2 years ago • 2 comments

Repro: https://github.com/andirsun/electron-test

Originally filed here: https://github.com/microsoft/playwright/issues/18928#issuecomment-1346691438

(base) ➜  electron-test git:(main) ✗ DEBUG=pw:api,pw:browser npx playwright test
Debugger attached.
Debugger attached.

Running 1 test using 1 worker

     1 tests/desktop.spec.test.js:14:1 › renders the first page
  pw:api => selectors.setTestIdAttribute started +0ms
  pw:api => electron.launch started +1ms
  pw:api <= selectors.setTestIdAttribute succeeded +2ms
  pw:browser <launching> /Users/maxschmitt/Developer/tmp/electron-test/node_modules/electron/dist/Electron.app/Contents/MacOS/Electron /Users/maxschmitt/Developer/tmp/electron-test/node_modules/playwright-core/lib/server/electron/loader.js --inspect=0 --remote-debugging-port=0 /Users/maxschmitt/Developer/tmp/electron-test . +0ms
  pw:browser <launched> pid=9227 +10ms
  pw:browser [pid=9227][err] Debugger listening on ws://127.0.0.1:52875/04bbd2b9-877f-4e9e-97c9-cf294853140f +113ms
  pw:browser [pid=9227][err] For help, see: https://nodejs.org/en/docs/inspector +0ms
  pw:browser <ws connecting> ws://127.0.0.1:52875/04bbd2b9-877f-4e9e-97c9-cf294853140f +0ms
  pw:browser [pid=9227][err] Debugger attached. +6ms
  pw:browser <ws connected> ws://127.0.0.1:52875/04bbd2b9-877f-4e9e-97c9-cf294853140f +1ms
  pw:browser [pid=9227][err]  +39ms
  pw:browser [pid=9227][err] DevTools listening on ws://127.0.0.1:52877/devtools/browser/f691d994-fa64-4141-96fa-e400b0b2e5e9 +0ms
  pw:browser <ws connecting> ws://127.0.0.1:52877/devtools/browser/f691d994-fa64-4141-96fa-e400b0b2e5e9 +1ms
  pw:browser <ws connected> ws://127.0.0.1:52877/devtools/browser/f691d994-fa64-4141-96fa-e400b0b2e5e9 +60ms
  pw:api <= electron.launch succeeded +241ms
  pw:api => electronApplication.firstWindow started +1ms
  pw:browser [pid=9227][err] (node:9227) UnhandledPromiseRejectionWarning: Error: protocol.registerSchemesAsPrivileged should be called before app is ready +1ms
  pw:browser [pid=9227][err]     at t.exports (/Users/maxschmitt/Developer/tmp/electron-test/app/background.js:1:32119) +0ms
  pw:browser [pid=9227][err]     at /Users/maxschmitt/Developer/tmp/electron-test/app/background.js:1:34026 +0ms
  pw:browser [pid=9227][err]     at /Users/maxschmitt/Developer/tmp/electron-test/app/background.js:1:35220 +0ms
  pw:browser [pid=9227][err]     at Object.<anonymous> (/Users/maxschmitt/Developer/tmp/electron-test/app/background.js:1:35241) +0ms
  pw:browser [pid=9227][err]     at Module._compile (node:internal/modules/cjs/loader:1116:14) +0ms
  pw:browser [pid=9227][err]     at Object.Module._extensions..js (node:internal/modules/cjs/loader:1169:10) +0ms
  pw:browser [pid=9227][err]     at Module.load (node:internal/modules/cjs/loader:988:32) +0ms
  pw:browser [pid=9227][err]     at Module._load (node:internal/modules/cjs/loader:829:12) +0ms
  pw:browser [pid=9227][err]     at Function.c._load (node:electron/js2c/asar_bundle:5:13343) +0ms
  pw:browser [pid=9227][err]     at Module.require (node:internal/modules/cjs/loader:1012:19) +0ms
  pw:browser [pid=9227][err] (Use `Electron --trace-warnings ...` to show where the warning was created) +0ms  pw:browser [pid=9227][err] (node:9227) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) +0ms
  pw:browser [pid=9227][err] objc[9228]: Class WebSwapCGLLayer is implemented in both /System/Library/Frameworks/WebKit.framework/Versions/A/Frameworks/WebCore.framework/Versions/A/Frameworks/libANGLE-shared.dylib (0x24a98b2e0) and /Users/maxschmitt/Developer/tmp/electron-test/node_modules/electron/dist/Electron.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Libraries/libGLESv2.dylib (0x1308193c8). One of the two will be used. Which one is undefined. +157ms

mxschmitt avatar Dec 12 '22 16:12 mxschmitt

For the other folks who run into it, it would be amazing if you could provide us the logs which you get via setting the DEBUG=pw:api,pw:browser env var.

as requested ...

first the logs with playwright v1.27.1 (test is working):

node@88b9a9e0ba97:/opt/magic_mirror$ DEBUG=pw:api,pw:browser npx jest tests/electron/env_spec.js
  pw:api => electron.launch started +0ms
  pw:browser <launching> /opt/magic_mirror/node_modules/electron/dist/electron js/electron.js --inspect=0 --remote-debugging-port=0 +0ms
  pw:browser <launched> pid=1258 +5ms
  pw:browser [pid=1258][err] Debugger listening on ws://127.0.0.1:33121/3bbc641b-f7d0-4dc8-94ea-b5ff666abbff +62ms
  pw:browser [pid=1258][err] For help, see: https://nodejs.org/en/docs/inspector +0ms
  pw:browser <ws connecting> ws://127.0.0.1:33121/3bbc641b-f7d0-4dc8-94ea-b5ff666abbff +1ms
  pw:browser <ws connected> ws://127.0.0.1:33121/3bbc641b-f7d0-4dc8-94ea-b5ff666abbff +11ms
  pw:browser [pid=1258][err] Debugger attached. +1ms
  pw:browser [pid=1258][err] [1258:1212/175409.659108:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /run/dbus/system_bus_socket: No such file or directory +348ms
  pw:browser [pid=1258][err] [1258:1212/175409.659212:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /run/dbus/system_bus_socket: No such file or directory +0ms
  pw:browser [pid=1258][err] [1258:1212/175409.713723:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory +54ms
  pw:browser [pid=1258][err] [1258:1212/175409.714155:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory +1ms
  pw:browser [pid=1258][err]  +7ms
  pw:browser [pid=1258][err] DevTools listening on ws://127.0.0.1:35381/devtools/browser/659cd29a-9e2d-4327-8a8c-699e41de5c70 +0ms
  pw:browser <ws connecting> ws://127.0.0.1:35381/devtools/browser/659cd29a-9e2d-4327-8a8c-699e41de5c70 +0ms
  pw:browser [pid=1258][err] [1297:1212/175409.737511:ERROR:gpu_memory_buffer_support_x11.cc(44)] dri3 extension not supported. +16ms
  pw:browser [pid=1258][err] [1258:1212/175409.742339:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory +5ms
  pw:browser <ws connected> ws://127.0.0.1:35381/devtools/browser/659cd29a-9e2d-4327-8a8c-699e41de5c70 +11ms
  pw:api   "commit" event fired +557ms
  pw:api   "commit" event fired +48ms
  pw:api   navigated to "http://localhost:8080/" +0ms
  pw:api <= electron.launch succeeded +7ms
  pw:api => page.title started +3ms
  pw:api   "domcontentloaded" event fired +108ms
  pw:api <= page.title succeeded +2ms
  pw:api => locator.waitFor started +9ms
  pw:api waiting for selector "#module_0_helloworld" to be visible +5ms
  pw:api   "load" event fired +12ms
  pw:api   selector resolved to visible <div id="module_0_helloworld" class="module helloworl…>…</div> +19ms
  pw:api <= locator.waitFor succeeded +5ms
  pw:api => locator.textContent started +2ms
  pw:api waiting for selector "#module_0_helloworld" +1ms
  pw:api   selector resolved to <div id="module_0_helloworld" class="module helloworl…>…</div> +7ms
  pw:api <= locator.textContent succeeded +4ms
  pw:api => electronApplication.close started +3ms
  pw:browser <ws disconnecting> ws://127.0.0.1:33121/3bbc641b-f7d0-4dc8-94ea-b5ff666abbff +268ms
  pw:browser [pid=1258][err] Debugger ending on ws://127.0.0.1:33121/3bbc641b-f7d0-4dc8-94ea-b5ff666abbff +3ms
  pw:browser [pid=1258][err] For help, see: https://nodejs.org/en/docs/inspector +0ms
  pw:browser <ws disconnected> ws://127.0.0.1:33121/3bbc641b-f7d0-4dc8-94ea-b5ff666abbff code=1005 reason= +4ms
  pw:browser <ws disconnected> ws://127.0.0.1:35381/devtools/browser/659cd29a-9e2d-4327-8a8c-699e41de5c70 code=1006 reason= +65ms
  pw:api <= electronApplication.close succeeded +79ms
 PASS   electron  tests/electron/env_spec.js
  Electron app environment
    ✓ should open browserwindow (880 ms)

Test Suites: 1 passed, 1 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        1.383 s
Ran all test suites matching /tests\/electron\/env_spec.js/i.
  pw:browser [pid=1258] <process did exit: exitCode=0, signal=null> +41ms
  pw:browser [pid=1258] starting temporary directories cleanup +0ms
  pw:browser [pid=1258] finished temporary directories cleanup +3ms

now the logs with playwright v1.28.1 of the same test (which fails now):

node@88b9a9e0ba97:/opt/magic_mirror$ DEBUG=pw:api,pw:browser npx jest tests/electron/env_spec.js
  pw:api => electron.launch started +0ms
  pw:browser <launching> /opt/magic_mirror/node_modules/electron/dist/electron /opt/magic_mirror/node_modules/playwright-core/lib/server/electron/loader.js --inspect=0 --remote-debugging-port=0 /opt/magic_mirror js/electron.js +0ms
  pw:browser <launched> pid=957 +6ms
  pw:browser [pid=957][err] Debugger listening on ws://127.0.0.1:45417/c443cd7f-4b48-446e-b53c-9bdfa376a9a8 +63ms
  pw:browser [pid=957][err] For help, see: https://nodejs.org/en/docs/inspector +0ms
  pw:browser <ws connecting> ws://127.0.0.1:45417/c443cd7f-4b48-446e-b53c-9bdfa376a9a8 +1ms
  pw:browser <ws connected> ws://127.0.0.1:45417/c443cd7f-4b48-446e-b53c-9bdfa376a9a8 +7ms
  pw:browser [pid=957][err] Debugger attached. +1ms
  pw:browser [pid=957][err] [957:1212/174810.803241:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /run/dbus/system_bus_socket: No such file or directory +116ms
  pw:browser [pid=957][err] [957:1212/174810.803360:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /run/dbus/system_bus_socket: No such file or directory +1ms
  pw:browser [pid=957][err] [957:1212/174810.843835:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory +40ms
  pw:browser [pid=957][err] [957:1212/174810.844443:ERROR:bus.cc(399)] Failed to connect to the bus: Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory +1ms
  pw:browser [pid=957][err]  +1ms
  pw:browser [pid=957][err] DevTools listening on ws://127.0.0.1:45309/devtools/browser/14f80039-41a0-4499-8596-23207a352994 +0ms
  pw:browser <ws connecting> ws://127.0.0.1:45309/devtools/browser/14f80039-41a0-4499-8596-23207a352994 +0ms
  pw:browser <ws connected> ws://127.0.0.1:45309/devtools/browser/14f80039-41a0-4499-8596-23207a352994 +6ms
  pw:api <= electron.launch succeeded +263ms
  pw:api => electronApplication.firstWindow started +1ms
  pw:browser [pid=957][err] [981:1212/174810.945130:ERROR:gl_surface_egl.cc(324)] No suitable EGL configs found. +93ms
  pw:browser [pid=957][err] [981:1212/174810.945307:ERROR:gl_context_egl.cc(142)] eglGetConfigAttrib failed with error EGL_BAD_CONFIG +0ms
  pw:browser [pid=957][err] [981:1212/174810.946291:ERROR:gl_surface_egl.cc(324)] No suitable EGL configs found. +1ms
  pw:browser [pid=957][err] [981:1212/174810.946416:ERROR:gl_surface_egl.cc(1111)] eglCreatePbufferSurface failed with error EGL_BAD_CONFIG +1ms
  pw:browser [pid=957][err] [981:1212/174810.946524:ERROR:gpu_info_collector.cc(80)] gl::GLContext::CreateOffscreenGLSurface failed +2ms
  pw:browser [pid=957][err] [981:1212/174810.946592:ERROR:gpu_info_collector.cc(348)] Could not create surface for info collection. +0ms
  pw:browser [pid=957][err] [981:1212/174810.946634:ERROR:gpu_init.cc(87)] CollectGraphicsInfo failed. +0ms
  pw:browser [pid=957][err] [981:1212/174810.951524:ERROR:viz_main_impl.cc(186)] Exiting GPU process due to errors during initialization +3ms
  pw:browser [pid=957][err] (node:957) UnhandledPromiseRejectionWarning: Error: app.disableHardwareAcceleration() can only be called before app is ready +29ms
  pw:browser [pid=957][err]     at Object.<anonymous> (/opt/magic_mirror/js/electron.js:14:6) +1ms
  pw:browser [pid=957][err]     at Module._compile (node:internal/modules/cjs/loader:1141:14) +0ms
  pw:browser [pid=957][err]     at Module._extensions..js (node:internal/modules/cjs/loader:1196:10) +0ms
  pw:browser [pid=957][err]     at Module.load (node:internal/modules/cjs/loader:1011:32) +0ms
  pw:browser [pid=957][err]     at Module._load (node:internal/modules/cjs/loader:846:12) +0ms
  pw:browser [pid=957][err]     at f._load (node:electron/js2c/asar_bundle:2:13328) +0ms
  pw:browser [pid=957][err]     at Module.require (node:internal/modules/cjs/loader:1035:19) +0ms
  pw:browser [pid=957][err]     at require (node:internal/modules/cjs/helpers:102:18) +0ms
  pw:browser [pid=957][err]     at globalThis.__playwright_run (/opt/magic_mirror/node_modules/playwright-core/lib/server/electron/loader.js:52:3) +0ms
  pw:browser [pid=957][err] (Use `electron --trace-warnings ...` to show where the warning was created) +0ms
  pw:browser [pid=957][err] (node:957) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) +0ms
  pw:browser [pid=957][err] [1003:1212/174811.074435:ERROR:gl_surface_egl.cc(324)] No suitable EGL configs found. +92ms
  pw:browser [pid=957][err] [1003:1212/174811.074676:ERROR:gl_context_egl.cc(142)] eglGetConfigAttrib failed with error EGL_BAD_CONFIG +1ms
  pw:browser [pid=957][err] [1003:1212/174811.075396:ERROR:gl_surface_egl.cc(324)] No suitable EGL configs found. +0ms
  pw:browser [pid=957][err] [1003:1212/174811.075680:ERROR:gl_surface_egl.cc(1111)] eglCreatePbufferSurface failed with error EGL_BAD_CONFIG +1ms
  pw:browser [pid=957][err] [1003:1212/174811.075843:ERROR:gpu_info_collector.cc(80)] gl::GLContext::CreateOffscreenGLSurface failed +0ms
  pw:browser [pid=957][err] [1003:1212/174811.076733:ERROR:gpu_info_collector.cc(348)] Could not create surface for info collection. +1ms
  pw:browser [pid=957][err] [1003:1212/174811.076906:ERROR:gpu_init.cc(87)] CollectGraphicsInfo failed. +0ms
  pw:browser [pid=957][err] [1003:1212/174811.079342:ERROR:viz_main_impl.cc(186)] Exiting GPU process due to errors during initialization +3ms
  pw:browser [pid=957][err] [1023:1212/174811.108163:ERROR:gpu_memory_buffer_support_x11.cc(44)] dri3 extension not supported. +28ms
  pw:api <= electronApplication.firstWindow failed +30s
  pw:api => electronApplication.close started +3ms
  pw:browser [pid=957][err] Waiting for the debugger to disconnect... +30s
  pw:browser <ws disconnecting> ws://127.0.0.1:45417/c443cd7f-4b48-446e-b53c-9bdfa376a9a8 +1ms
  pw:browser <ws disconnected> ws://127.0.0.1:45417/c443cd7f-4b48-446e-b53c-9bdfa376a9a8 code=1005 reason= +9ms
  pw:browser <ws disconnected> ws://127.0.0.1:45309/devtools/browser/14f80039-41a0-4499-8596-23207a352994 code=1006 reason= +4ms
  pw:browser [pid=957] <process did exit: exitCode=0, signal=null> +2ms
  pw:browser [pid=957] starting temporary directories cleanup +0ms
  pw:api <= electronApplication.close succeeded +21ms
 FAIL   electron  tests/electron/env_spec.js (30.782 s)
  Electron app environment
    ✕ should open browserwindow (30300 ms)

  ● Electron app environment › should open browserwindow

    electronApplication.firstWindow: Timeout 30000ms exceeded while waiting for event "window"

      13 |      global.electronApp = await electron.launch({ args: electronParams });
      14 |
    > 15 |      await global.electronApp.firstWindow();
         |                               ^
      16 |      while (global.electronApp.windows().length < electronParams.length) await events.on(global.electronApp, "window");
      17 |
      18 |      for (const win of global.electronApp.windows()) {

      at Object.firstWindow [as startApplication] (tests/electron/helpers/global-setup.js:15:27)
      at Object.<anonymous> (tests/electron/env_spec.js:5:3)

Test Suites: 1 failed, 1 total
Tests:       1 failed, 1 total
Snapshots:   0 total
Time:        30.824 s
Ran all test suites matching /tests\/electron\/env_spec.js/i.
  pw:browser [pid=957] finished temporary directories cleanup +41ms

khassel avatar Dec 12 '22 17:12 khassel

Here’s a complete, self-contained test case that depends only on electron and playwright-core. Works with [email protected], fails with 1.28.0 and 1.28.1.

https://gist.github.com/andersk/96a04d05e1bd55c2754c514dd547d1e3

test.js

const { BrowserWindow, app, protocol } = require("electron");

protocol.registerSchemesAsPrivileged([]);
app.whenReady().then(() => {
  const win = new BrowserWindow();
  win.loadURL("data:text/plain,Hello, world!");
});
app.on("window-all-closed", () => {
  app.quit();
});

index.js

const { _electron } = require("playwright-core");

(async () => {
  const app = await _electron.launch({ args: ["."] });
  const win = await app.firstWindow();
  console.log("text =", await win.innerText(":root"));
  app.close();
})();

The problem occurs when calling protocol.registerSchemesAsPrivileged, which is only allowed to be called before the ready event fires on app. The same problem can be reproduced with other functions with this requirement, such as app.disableHardwareAcceleration.

This requirement was broken by

  • #18972

which does await app.whenReady() before the user code has a chance to run any pre-ready initialization code. It tries to mock app.isReady and app.whenReady so the user code doesn’t notice, but the Electron API is not fooled.

andersk avatar Dec 15 '22 08:12 andersk

Slight correction: based on git bisect, this was actually broken earlier by

  • #18804

andersk avatar Dec 15 '22 23:12 andersk