search

web-platform-tests / wpt

Test suites for Web platform specs — including WHATWG, W3C, and others
https://web-platform-tests.org/
Other
5.01k stars 3.11k forks source link

`./wpt run firefox path/to/someTest` doesn't run tests when Firefox is installed via Snap #44321

Open mbrodesser-Igalia opened 9 months ago

mbrodesser-Igalia commented 9 months ago

Works with "chrome" instead of "firefox".

In both cases:

./wpt run firefox trusted-types/block-string-assignment-to-Element-setAttribute.html
Running 1 tests in web-platform-tests

is logged.

Happened on Ubuntu 22.04.

gsnedders commented 9 months ago

What happens if you pass --log-mach - --log-mach-level debug to get more output?

This runs to completion for me:

gsnedders@gsnedders-marsha web-platform-tests % ./wpt run --log-mach - --log-mach-level debug firefox trusted-types/block-string-assignment-to-Element-setAttribute.html
/Volumes/gsnedders/projects/wpt/web-platform-tests/_venv3/lib/python3.9/site-packages/urllib3/__init__.py:34: NotOpenSSLWarning: urllib3 v2.0 only supports OpenSSL 1.1.1+, currently the 'ssl' module is compiled with 'LibreSSL 3.3.6'. See: https://github.com/urllib3/urllib3/issues/3020
  warnings.warn(
 0:00.00 INFO Set tests_root to /Volumes/gsnedders/projects/wpt/web-platform-tests
 0:00.00 INFO Set metadata_root to /Volumes/gsnedders/projects/wpt/web-platform-tests
 0:00.00 INFO Set manifest_update to True
 0:00.00 INFO Set manifest_download to True
 0:00.02 INFO Can't find certutil, certificates will not be checked.
Consider installing certutil via your OS package manager or directly.
 0:00.02 INFO Using webdriver binary /opt/homebrew/bin/geckodriver
 0:05.00 INFO Using cached test prefs from /Volumes/gsnedders/projects/wpt/web-platform-tests/_venv3/profiles/nightly/124.0
 0:05.00 INFO Running in headless mode, pass --no-headless to disable
 0:05.32 mozversion INFO application_buildid: 20240125094742
 0:05.32 mozversion INFO application_changeset: 6497cc2893d106073139365b5ebb6738adc3bbc9
 0:05.32 mozversion INFO application_display_name: Firefox Nightly
 0:05.32 mozversion INFO application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
 0:05.32 mozversion INFO application_name: Firefox
 0:05.32 mozversion INFO application_remotingname: firefox-nightly
 0:05.32 mozversion INFO application_repository: https://hg.mozilla.org/mozilla-central
 0:05.32 mozversion INFO application_vendor: Mozilla
 0:05.32 mozversion INFO application_version: 124.0a1
 0:05.32 mozversion INFO platform_buildid: 20240125094742
 0:05.32 mozversion INFO platform_changeset: 6497cc2893d106073139365b5ebb6738adc3bbc9
 0:05.32 mozversion INFO platform_repository: https://hg.mozilla.org/mozilla-central
 0:05.32 mozversion INFO platform_version: 124.0a1
 0:05.33 vcs DEBUG git rev-parse --show-toplevel
 0:05.63 vcs DEBUG git rev-parse --show-cdup
 0:05.64 vcs DEBUG git rev-parse HEAD
 0:14.48 wptserve INFO Starting http server on http://127.0.0.1:8003
 0:14.48 wptserve INFO Starting http server on http://127.0.0.1:8002
 0:14.48 wptserve INFO Starting http server on http://127.0.0.1:8000
 0:14.48 wptserve INFO Starting http server on http://127.0.0.1:8001
 0:14.48 wptserve INFO Starting https server on https://127.0.0.1:8444
 0:14.48 wptserve INFO Starting https server on https://127.0.0.1:8446
 0:14.48 wptserve INFO Starting https server on https://127.0.0.1:8445
 0:14.48 wptserve INFO Starting https server on https://127.0.0.1:8443
 0:14.48 wptserve INFO Starting http2 server on https://127.0.0.1:9000
 0:14.48 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:14.48 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:14.48 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:14.48 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:14.48 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:14.48 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:14.54 wptserve INFO Starting WebTransport over HTTP/3 server on 127.0.0.1:11000
 0:15.57 SUITE_START: web-platform-test - running 1 tests
 0:15.57 INFO Using 1 child processes
 0:15.57 DEBUG Dispatch start_init
 0:15.57 DEBUG Got new test group subsuite: test_type:testharness
 0:15.57 DEBUG new state: initializing
 0:15.57 DEBUG Dispatch init
 0:15.60 INFO --certutil-binary not supplied; Firefox will not check certificates
 0:15.60 DEBUG Init called, starting browser and runner
 0:15.60 DEBUG Starting browser with settings {'check_leaks': False, 'lsan_disabled': False, 'lsan_allowed': set(), 'lsan_max_stack_depth': None, 'mozleak_allowed': False, 'mozleak_thresholds': False, 'special_powers': None}
 0:15.61 DEBUG Starting Firefox
 0:15.61 INFO Application command: /Applications/Firefox Nightly.app/Contents/MacOS/firefox --marionette about:blank -foreground -profile /var/folders/qk/hmjj9_lx2cg3_4v3vx3y7y_w0000gn/T/tmp4u_qmdc7
 0:15.62 DEBUG OutputHandler.after_process_start
 0:15.62 DEBUG Firefox Started
 0:15.62 DEBUG OutputHandler.start
 0:15.62 INFO Starting runner
 0:15.62 DEBUG Test runner started
 0:15.67 pid:8703 Full command: /Applications/Firefox Nightly.app/Contents/MacOS/firefox --marionette about:blank
pid:8703 *** You are running in headless mode.
 0:15.86 pid:8703 1707479722861 Marionette  INFO    Marionette enabled
 0:16.12 pid:8703 1707479723119 Marionette  INFO    Listening on port 50200
/Volumes/gsnedders/projects/wpt/web-platform-tests/_venv3/lib/python3.9/site-packages/urllib3/__init__.py:34: NotOpenSSLWarning: urllib3 v2.0 only supports OpenSSL 1.1.1+, currently the 'ssl' module is compiled with 'LibreSSL 3.3.6'. See: https://github.com/urllib3/urllib3/issues/3020
  warnings.warn(
 0:16.59 DEBUG Got command: 'log'
 0:16.59 DEBUG Executor setup
 0:16.59 DEBUG Got command: 'log'
 0:16.59 DEBUG Connecting to Marionette on port 50200
 0:16.59 DEBUG Got command: 'log'
 0:16.59 DEBUG Waiting for Marionette connection
 0:16.60 DEBUG Got command: 'log'
 0:16.59 DEBUG Starting Marionette session
 0:16.70 pid:8703 1707479723696 RemoteAgent WARN    TLS certificate errors will be ignored for this session
 0:16.77 pid:8703 [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
 0:17.25 DEBUG Got command: 'log'
 0:17.25 DEBUG Marionette session started
 0:17.25 DEBUG Got command: 'log'
 0:17.25 DEBUG Loading http://web-platform.test:8000/testharness_runner.html
 0:17.40 DEBUG Got command: 'init_succeeded'
 0:17.40 DEBUG new state: running
 0:17.40 DEBUG Dispatch run_test
 0:17.40 TEST_START: /trusted-types/block-string-assignment-to-Element-setAttribute.html
 0:17.40 DEBUG Got command: 'log'
 0:17.40 DEBUG Executor setup done
 0:17.43 pid:8703 JavaScript error: http://web-platform.test:8000/trusted-types/block-string-assignment-to-Element-setAttribute.html, line 12: ReferenceError: trustedTypes is not defined
 0:17.44 DEBUG Got command: 'log'
 0:17.44 DEBUG Got async callback: complete
 0:17.44 DEBUG Got command: 'log'
 0:17.44 DEBUG ReferenceError: trustedTypes is not defined
 0:17.44 DEBUG Got command: 'test_ended'
 0:17.44 TEST_END: ERROR, expected OK - ReferenceError: trustedTypes is not defined
@http://web-platform.test:8000/trusted-types/block-string-assignment-to-Element-setAttribute.html:12:22

 0:17.44 INFO No more tests
 0:17.44 DEBUG new state: stop
 0:17.44 DEBUG TestRunnerManager main loop terminating, starting cleanup
 0:17.44 INFO No more tests
 0:17.44 DEBUG Stopping Firefox 8703
 0:17.44 DEBUG Shutting down attempt 1/3
 0:17.44 pid:8703 1707479724440 Marionette  INFO    Stopped listening on port 50200
 0:17.69 pid:8703 console.error: ({})
 0:18.96 INFO Browser exited with return code 0
 0:18.96 DEBUG OutputHandler.after_process_stop
 0:18.96 DEBUG stopped
 0:18.96 DEBUG ensure_runner_stopped
 0:18.96 DEBUG stopped
 0:18.96 DEBUG Runner process exited with code 0
 0:18.96 DEBUG TestRunnerManager cleanup
 0:17.68 INFO Closing logging queue
 0:17.68 INFO queue closed
 0:18.96 DEBUG TestRunnerManager teardown
 0:18.96 DEBUG OutputHandler.after_process_stop
 0:18.98 DEBUG TestRunnerManager main loop terminated
 0:18.98 DEBUG Stop flag set in ManagerGroup
 0:18.98 SUITE_END

web-platform-test
~~~~~~~~~~~~~~~~~
Ran 1 checks (1 tests)
Expected results: 0
Unexpected results: 1
  test: 1 (1 error)

Unexpected Results
------------------
ERROR /trusted-types/block-string-assignment-to-Element-setAttribute.html - ReferenceError: trustedTypes is not defined
@http://web-platform.test:8000/trusted-types/block-string-assignment-to-Element-setAttribute.html:12:22
 0:18.98 INFO Got 1 unexpected results, with 0 unexpected passes
 0:18.99 wptserve INFO Stopped WebTransport over HTTP/3 server on 127.0.0.1:11000
 0:19.43 wptserve INFO Stopped http server on 127.0.0.1:8000
 0:19.44 wptserve INFO Stopped http server on 127.0.0.1:8001
 0:19.44 wptserve INFO Stopped http server on 127.0.0.1:8002
 0:19.44 wptserve INFO Stopped http server on 127.0.0.1:8003
 0:19.44 wptserve INFO Stopped http server on 127.0.0.1:8445
 0:19.44 wptserve INFO Stopped http server on 127.0.0.1:9000
 0:19.44 wptserve INFO Stopped http server on 127.0.0.1:8444
 0:19.44 wptserve INFO Stopped http server on 127.0.0.1:8446
 0:19.44 wptserve INFO Stopped http server on 127.0.0.1:8443
 0:19.47 wptserve INFO Close on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:19.47 wptserve INFO Close on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:19.51 INFO Closing logging queue
 0:19.51 INFO queue closed
gsnedders@gsnedders-marsha web-platform-tests %
mbrodesser-Igalia commented 9 months ago

@gsnedders 

$ ./wpt run --log-mach - --log-mach-level debug firefox trusted-types/block-string-assignment-to-Element-setAttribute.html
 0:00.00 INFO Set tests_root to /home/mirko/work/code/wpt
 0:00.00 INFO Set metadata_root to /home/mirko/work/code/wpt
 0:00.00 INFO Set manifest_update to True
 0:00.00 INFO Set manifest_download to True
 0:00.01 INFO Can't find certutil, certificates will not be checked.
Consider installing certutil via your OS package manager or directly.
 0:00.02 INFO Using webdriver binary /snap/bin/geckodriver
 0:00.20 WARNING Supplied channel doesn't match binary, using supplied channel
 0:00.20 INFO Downloading test prefs from https://hg.mozilla.org/mozilla-central/archive/tip.zip/testing/profiles/
 0:04.58 INFO Test prefs downloaded to /home/mirko/work/code/wpt/_venv3/profiles/nightly/122.0
 0:04.58 INFO Running in headless mode, pass --no-headless to disable
 0:04.87 vcs DEBUG git rev-parse --show-toplevel
 0:04.87 vcs DEBUG git rev-parse --show-cdup
 0:04.87 vcs DEBUG git rev-parse HEAD
 0:09.66 wptserve INFO Starting http server on http://127.0.0.1:8003
 0:09.66 wptserve INFO Starting http server on http://127.0.0.1:8000
 0:09.66 wptserve INFO Starting http server on http://127.0.0.1:8001
 0:09.66 wptserve INFO Starting https server on https://127.0.0.1:8443
 0:09.66 wptserve INFO Starting https server on https://127.0.0.1:8444
 0:09.67 wptserve INFO Starting http server on http://127.0.0.1:8002
 0:09.70 wptserve INFO Starting http2 server on https://127.0.0.1:9000
 0:09.70 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:09.70 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:09.70 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:09.70 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:09.70 wptserve INFO Starting WebTransport over HTTP/3 server on 127.0.0.1:11000
 0:09.70 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:09.70 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:09.70 wptserve INFO Starting https server on https://127.0.0.1:8446
 0:09.71 wptserve INFO Starting https server on https://127.0.0.1:8445
 0:10.69 SUITE_START: web-platform-test - running 1 tests
 0:10.69 INFO Using 1 child processes
 0:10.69 DEBUG Dispatch start_init
 0:10.69 DEBUG Got new test group subsuite: test_type:testharness
 0:10.69 DEBUG new state: initializing
 0:10.69 DEBUG Dispatch init
 0:10.70 INFO --certutil-binary not supplied; Firefox will not check certificates
 0:10.70 DEBUG Init called, starting browser and runner
 0:10.70 DEBUG Starting browser with settings {'check_leaks': False, 'lsan_disabled': False, 'lsan_allowed': set(), 'lsan_max_stack_depth': None, 'mozleak_allowed': False, 'mozleak_thresholds': False, 'special_powers': None}
 0:10.70 DEBUG Starting Firefox
 0:10.70 INFO Application command: /usr/bin/firefox --marionette about:blank -profile /tmp/tmpiky3eec5
 0:10.71 DEBUG OutputHandler.after_process_start
 0:10.71 DEBUG Firefox Started
 0:10.71 DEBUG OutputHandler.start
 0:10.71 INFO Starting runner
 0:10.71 DEBUG Test runner started
 0:10.82 pid:40460 Full command: /usr/bin/firefox --marionette about:blank
pid:40460 *** You are running in headless mode.
 0:10.82 pid:40460 Gtk-Message: 11:11:13.683: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
 0:10.93 DEBUG Got command: 'log'
 0:10.93 DEBUG Executor setup
 0:10.93 DEBUG Got command: 'log'
 0:10.93 DEBUG Connecting to Marionette on port 45479
 0:10.93 DEBUG Got command: 'log'
 0:10.93 DEBUG Waiting for Marionette connection
 0:11.13 pid:40460 [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
 1:20.70 DEBUG init_failed called from timer
 1:20.70 DEBUG Got command: 'init_failed'
 1:20.71 DEBUG Stopping Firefox 40460
 1:20.71 DEBUG Shutting down attempt 1/2
 1:20.74 INFO Browser exited with return code -15
 1:20.74 DEBUG OutputHandler.after_process_stop
 1:20.74 DEBUG stopped
 1:20.74 DEBUG ensure_runner_stopped
 1:20.74 DEBUG stopped
 1:30.75 WARNING Forcibly terminating runner process
 1:30.75 DEBUG After terminating runner process
 1:30.75 DEBUG Recreating command queue
 1:30.75 DEBUG Recreating remote queue
 1:30.75 DEBUG TestRunnerManager cleanup
 1:30.75 DEBUG new state: initializing
 1:30.75 DEBUG Dispatch init
 1:30.75 DEBUG Init called, starting browser and runner
 1:30.75 DEBUG Starting browser with settings {'check_leaks': False, 'lsan_disabled': False, 'lsan_allowed': set(), 'lsan_max_stack_depth': None, 'mozleak_allowed': False, 'mozleak_thresholds': False, 'special_powers': None}
 1:30.76 DEBUG Starting Firefox
 1:30.76 INFO Application command: /usr/bin/firefox --marionette about:blank -profile /tmp/tmpn0t9u94o
 1:30.77 DEBUG OutputHandler.after_process_start
 1:30.77 DEBUG Firefox Started
 1:30.77 DEBUG OutputHandler.start
 1:30.77 INFO Starting runner
 1:30.77 DEBUG Test runner started
 1:30.90 pid:40683 Full command: /usr/bin/firefox --marionette about:blank
pid:40683 *** You are running in headless mode.
 1:30.90 pid:40683 Gtk-Message: 11:12:33.757: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
 1:30.98 DEBUG Got command: 'log'
 1:30.98 DEBUG Executor setup
 1:30.98 DEBUG Got command: 'log'
 1:30.98 DEBUG Connecting to Marionette on port 44381
 1:30.98 DEBUG Got command: 'log'
 1:30.98 DEBUG Waiting for Marionette connection
 1:31.18 pid:40683 [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
mbrodesser-Igalia commented 9 months ago

@gsnedders is using macOS, btw.

gsnedders commented 9 months ago

So it's simply not managing to start Firefox… which is almost certainly going to be a Firefox bug, and not a WPT bug. cc @jgraham @whimboo

If you run it with --no-headless, does it still fail? Heck, does /usr/bin/firefox about:blank work at all?

whimboo commented 9 months ago

@mbrodesser-Igalia which version of Firefox are you running? Is that one that got installed via Snap?

The logs show that Browser exited with return code -15 which means that after the around 70s geckodriver kills Firefox because no connection could be made. Would you mind running it again with the --webdriver-arg="-vv" argument included? Maybe this gives an idea what's broken when opening Firefox. Maybe try without headless as well.

mbrodesser-Igalia commented 9 months ago

So it's simply not managing to start Firefox… which is almost certainly going to be a Firefox bug, and not a WPT bug. cc @jgraham @whimboo

If you run it with --no-headless, does it still fail? Heck, does /usr/bin/firefox about:blank work at all?

It still fails with --no-headless, with a "Profile Missing" error: "Your Firefox profile cannot be loaded. It may be missing or inaccessible."

/usr/bin/firefox about:blank works.

mbrodesser-Igalia commented 9 months ago

@mbrodesser-Igalia which version of Firefox are you running? Is that one that got installed via Snap?

@whimboo to generate the logs for the previous comments, the default channel was used, which is supposed to be Nightly. Version: 123.0a1 (2024-01-17) (64-bit). That, AFAIR, was not installed via Snap.

However, with the release channel, the test still fails:

$ ./wpt run --channel=stable --webdriver-arg="-vv" --log-mach - --log-mach-level debug firefox trusted-types/block-string-assignment-to-Element-setAttribute.html
 0:00.00 INFO Set tests_root to /home/mirko/work/code/wpt
 0:00.00 INFO Set metadata_root to /home/mirko/work/code/wpt
 0:00.00 INFO Set manifest_update to True
 0:00.00 INFO Set manifest_download to True
 0:00.01 INFO Can't find certutil, certificates will not be checked.
Consider installing certutil via your OS package manager or directly.
 0:00.01 INFO Using webdriver binary /snap/bin/geckodriver
 0:00.19 INFO Using cached test prefs from /home/mirko/work/code/wpt/_venv3/profiles/stable/122.0
 0:00.19 INFO Running in headless mode, pass --no-headless to disable
 0:00.43 vcs DEBUG git rev-parse --show-toplevel
 0:00.43 vcs DEBUG git rev-parse --show-cdup
 0:00.43 vcs DEBUG git rev-parse HEAD
 0:02.90 wptserve INFO Starting http server on http://127.0.0.1:8000
 0:02.90 wptserve INFO Starting http server on http://127.0.0.1:8003
 0:02.90 wptserve INFO Starting http server on http://127.0.0.1:8002
 0:02.90 wptserve INFO Starting http server on http://127.0.0.1:8001
 0:02.90 wptserve INFO Starting https server on https://127.0.0.1:8443
 0:02.91 wptserve INFO Starting https server on https://127.0.0.1:8444
 0:02.95 wptserve INFO Starting http2 server on https://127.0.0.1:9000
 0:02.95 wptserve INFO Starting https server on https://127.0.0.1:8445
 0:02.96 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:02.96 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:02.96 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:02.96 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:02.96 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:02.96 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:02.97 wptserve INFO Starting https server on https://127.0.0.1:8446
 0:03.29 SUITE_START: web-platform-test - running 1 tests
 0:03.30 INFO Using 1 child processes
 0:03.30 DEBUG Dispatch start_init
 0:03.30 DEBUG Got new test group subsuite: test_type:testharness
 0:03.30 DEBUG new state: initializing
 0:03.30 DEBUG Dispatch init
 0:03.31 INFO --certutil-binary not supplied; Firefox will not check certificates
 0:03.31 DEBUG Init called, starting browser and runner
 0:03.31 DEBUG Starting browser with settings {'check_leaks': False, 'lsan_disabled': False, 'lsan_allowed': set(), 'lsan_max_stack_depth': None, 'mozleak_allowed': False, 'mozleak_thresholds': False, 'special_powers': None}
 0:03.31 DEBUG Starting Firefox
 0:03.31 INFO Application command: /usr/bin/firefox --marionette about:blank -profile /tmp/tmpb7gijjtp
 0:03.32 DEBUG OutputHandler.after_process_start
 0:03.32 DEBUG Firefox Started
 0:03.32 DEBUG OutputHandler.start
 0:03.32 INFO Starting runner
 0:03.32 DEBUG Test runner started
 0:03.45 pid:17365 Full command: /usr/bin/firefox --marionette about:blank
pid:17365 *** You are running in headless mode.
 0:03.45 pid:17365 Gtk-Message: 10:32:16.644: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
 0:03.53 DEBUG Got command: 'log'
 0:03.53 DEBUG Executor setup
 0:03.53 DEBUG Got command: 'log'
 0:03.53 DEBUG Connecting to Marionette on port 33261
 0:03.53 DEBUG Got command: 'log'
 0:03.53 DEBUG Waiting for Marionette connection
 0:03.67 pid:17365 [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt

That one uses Firefox 122.0 (64-bit).

The logs show that Browser exited with return code -15 which means that after the around 70s geckodriver kills Firefox because no connection could be made. Would you mind running it again with the --webdriver-arg="-vv" argument included? Maybe this gives an idea what's broken when opening Firefox. Maybe try without headless as well.

mbrodesser-Igalia commented 9 months ago

No-headless with release fails too:

$ ./wpt run --no-headless --channel=stable --webdriver-arg="-vv" --log-mach - --log-mach-level debug firefox trusted-types/block-string-assignment-to-Element-setAttribute.html
 0:00.00 INFO Set tests_root to /home/mirko/work/code/wpt
 0:00.00 INFO Set metadata_root to /home/mirko/work/code/wpt
 0:00.00 INFO Set manifest_update to True
 0:00.00 INFO Set manifest_download to True
 0:00.01 INFO Can't find certutil, certificates will not be checked.
Consider installing certutil via your OS package manager or directly.
 0:00.01 INFO Using webdriver binary /snap/bin/geckodriver
 0:00.19 INFO Using cached test prefs from /home/mirko/work/code/wpt/_venv3/profiles/stable/122.0
 0:00.44 vcs DEBUG git rev-parse --show-toplevel
 0:00.44 vcs DEBUG git rev-parse --show-cdup
 0:00.44 vcs DEBUG git rev-parse HEAD
 0:01.94 wptserve INFO Starting http server on http://127.0.0.1:8000
 0:01.94 wptserve INFO Starting http server on http://127.0.0.1:8002
 0:01.94 wptserve INFO Starting http server on http://127.0.0.1:8001
 0:01.94 wptserve INFO Starting http server on http://127.0.0.1:8003
 0:01.94 wptserve INFO Starting https server on https://127.0.0.1:8443
 0:01.95 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:01.95 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:01.95 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:01.98 wptserve INFO Starting http2 server on https://127.0.0.1:9000
 0:01.99 wptserve INFO Starting https server on https://127.0.0.1:8446
 0:01.99 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:01.99 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:01.99 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:02.00 wptserve INFO Starting https server on https://127.0.0.1:8445
 0:02.00 wptserve INFO Starting https server on https://127.0.0.1:8444
 0:02.33 SUITE_START: web-platform-test - running 1 tests
 0:02.33 INFO Using 1 child processes
 0:02.34 DEBUG Dispatch start_init
 0:02.34 DEBUG Got new test group subsuite: test_type:testharness
 0:02.34 DEBUG new state: initializing
 0:02.34 DEBUG Dispatch init
 0:02.35 INFO --certutil-binary not supplied; Firefox will not check certificates
 0:02.35 DEBUG Init called, starting browser and runner
 0:02.35 DEBUG Starting browser with settings {'check_leaks': False, 'lsan_disabled': False, 'lsan_allowed': set(), 'lsan_max_stack_depth': None, 'mozleak_allowed': False, 'mozleak_thresholds': False, 'special_powers': None}
 0:02.35 DEBUG Starting Firefox
 0:02.35 INFO Application command: /usr/bin/firefox --marionette about:blank -profile /tmp/tmpkrcbpmjo
 0:02.35 DEBUG OutputHandler.after_process_start
 0:02.35 DEBUG Firefox Started
 0:02.35 DEBUG OutputHandler.start
 0:02.35 INFO Starting runner
 0:02.35 DEBUG Test runner started
 0:02.47 pid:18542 Full command: /usr/bin/firefox --marionette about:blank
pid:18542 Gtk-Message: 10:36:30.013: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
 0:02.51 pid:18542 [18542, Main Thread] WARNING: GTK+ module /snap/firefox/3728/gnome-platform/usr/lib/gtk-2.0/modules/libcanberra-gtk-module.so cannot be loaded.
 0:02.51 pid:18542 GTK+ 2.x symbols detected. Using GTK+ 2.x and GTK+ 3 in the same process is not supported.: 'glib warning', file /build/firefox/parts/firefox/build/toolkit/xre/nsSigHandlers.cpp:187
 0:02.51 pid:18542 (firefox:18542): Gtk-WARNING **: 10:36:30.050: GTK+ module /snap/firefox/3728/gnome-platform/usr/lib/gtk-2.0/modules/libcanberra-gtk-module.so cannot be loaded.
 0:02.51 pid:18542 GTK+ 2.x symbols detected. Using GTK+ 2.x and GTK+ 3 in the same process is not supported.
 0:02.51 pid:18542 Gtk-Message: 10:36:30.050: Failed to load module "canberra-gtk-module"
 0:02.51 pid:18542 [18542, Main Thread] WARNING: GTK+ module /snap/firefox/3728/gnome-platform/usr/lib/gtk-2.0/modules/libcanberra-gtk-module.so cannot be loaded.
 0:02.51 pid:18542 GTK+ 2.x symbols detected. Using GTK+ 2.x and GTK+ 3 in the same process is not supported.: 'glib warning', file /build/firefox/parts/firefox/build/toolkit/xre/nsSigHandlers.cpp:187
 0:02.51 pid:18542 (firefox:18542): Gtk-WARNING **: 10:36:30.051: GTK+ module /snap/firefox/3728/gnome-platform/usr/lib/gtk-2.0/modules/libcanberra-gtk-module.so cannot be loaded.
 0:02.51 pid:18542 GTK+ 2.x symbols detected. Using GTK+ 2.x and GTK+ 3 in the same process is not supported.
 0:02.51 pid:18542 Gtk-Message: 10:36:30.051: Failed to load module "canberra-gtk-module"
 0:02.57 DEBUG Got command: 'log'
 0:02.57 DEBUG Executor setup
 0:02.57 DEBUG Got command: 'log'
 0:02.57 DEBUG Connecting to Marionette on port 56329
 0:02.57 DEBUG Got command: 'log'
 0:02.57 DEBUG Waiting for Marionette connection
 0:02.70 pid:18542 ATTENTION: default value of option mesa_glthread overridden by environment.
 0:02.71 pid:18542 ATTENTION: default value of option mesa_glthread overridden by environment.
whimboo commented 9 months ago

Ok, so the last log is actually helpful. As I can see you indeed use the snap version of geckodriver and Firefox.

The failure here seems to be with loading the libcanberra-gtk-module.so module because GTK+ 2.x symbols detected. Using GTK+ 2.x and GTK+ 3 in the same process is not supported. Whereby the comments on this bug tell that it is harmless. Mind checking comment 2 on this bug if that still shows the same problem?

whimboo commented 9 months ago

Oh wait... actually I just saw: /usr/bin/firefox --marionette about:blank -profile /tmp/tmpkrcbpmjo. This won't work because Firefox cannot reach this profile folder because it's outside of the locations the Firefox Snap package can access.

Can you please try with a Firefox and geckodriver build as downloaded from mozilla.org? If my theory is right we need Snap support in wptrunner.

mbrodesser-Igalia commented 9 months ago

@mbrodesser-Igalia which version of Firefox are you running? Is that one that got installed via Snap?

@whimboo to generate the logs for the previous comments, the default channel was used, which is supposed to be Nightly. Version: 123.0a1 (2024-01-17) (64-bit). That, AFAIR, was not installed via Snap.

@whimboo be reminded that e.g. https://github.com/web-platform-tests/wpt/issues/44321#issuecomment-1938384631 was generated with the default channel (Nightly). However, the corresponding logs show

 0:10.70 INFO Application command: /usr/bin/firefox --marionette about:blank -profile /tmp/tmpiky3eec5

which isn't Nightly. That might be a separate issue from the potential one with Snap.

mbrodesser-Igalia commented 9 months ago

Oh wait... actually I just saw: /usr/bin/firefox --marionette about:blank -profile /tmp/tmpkrcbpmjo. This won't work because Firefox cannot reach this profile folder because it's outside of the locations the Firefox Snap package can access.

Can you please try with a Firefox and geckodriver build as downloaded from mozilla.org? If my theory is right we need Snap support in wptrunner.

@whimboo: log generated with Firefox downloaded from mozilla.org:

$ ./wpt run --no-headless --webdriver-arg="-vv" --log-mach - --log-mach-level debug firefox html/dom/elements/name-content-attribute-and-property.html 
 0:00.00 INFO Set tests_root to /home/mirko/work/code/wpt
 0:00.00 INFO Set metadata_root to /home/mirko/work/code/wpt
 0:00.00 INFO Set manifest_update to True
 0:00.00 INFO Set manifest_download to True
 0:00.01 INFO Can't find certutil, certificates will not be checked.
Consider installing certutil via your OS package manager or directly.
 0:00.01 INFO Using webdriver binary /snap/bin/geckodriver
 0:00.03 WARNING Supplied channel doesn't match binary, using supplied channel
 0:00.03 INFO Using cached test prefs from /home/mirko/work/code/wpt/_venv3/profiles/nightly/122.0.1
 0:00.11 mozversion INFO application_buildid: 20240205133611
 0:00.11 mozversion INFO application_changeset: 5eb7272884b4ce02cffab7900e41551608885492
 0:00.11 mozversion INFO application_display_name: Firefox
 0:00.11 mozversion INFO application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
 0:00.11 mozversion INFO application_name: Firefox
 0:00.11 mozversion INFO application_remotingname: firefox
 0:00.11 mozversion INFO application_repository: https://hg.mozilla.org/releases/mozilla-release
 0:00.11 mozversion INFO application_vendor: Mozilla
 0:00.11 mozversion INFO application_version: 122.0.1
 0:00.11 mozversion INFO platform_buildid: 20240205133611
 0:00.11 mozversion INFO platform_changeset: 5eb7272884b4ce02cffab7900e41551608885492
 0:00.11 mozversion INFO platform_repository: https://hg.mozilla.org/releases/mozilla-release
 0:00.11 mozversion INFO platform_version: 122.0.1
 0:00.11 vcs DEBUG git rev-parse --show-toplevel
 0:00.11 vcs DEBUG git rev-parse --show-cdup
 0:00.11 vcs DEBUG git rev-parse HEAD
 0:01.69 wptserve INFO Starting http server on http://127.0.0.1:8002
 0:01.69 wptserve INFO Starting http server on http://127.0.0.1:8000
 0:01.69 wptserve INFO Starting http server on http://127.0.0.1:8001
 0:01.69 wptserve INFO Starting http server on http://127.0.0.1:8003
 0:01.69 wptserve INFO Starting https server on https://127.0.0.1:8443
 0:01.69 wptserve INFO Starting https server on https://127.0.0.1:8444
 0:01.74 wptserve INFO Starting http2 server on https://127.0.0.1:9000
 0:01.74 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:01.74 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:01.74 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
 0:01.75 wptserve INFO Create socket on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:01.75 wptserve INFO Bind on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:01.75 wptserve INFO Starting https server on https://127.0.0.1:8446
 0:01.75 wptserve INFO Listen on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
 0:01.76 wptserve INFO Starting https server on https://127.0.0.1:8445
 0:01.78 wptserve INFO Starting WebTransport over HTTP/3 server on 127.0.0.1:11000
 0:02.64 SUITE_START: web-platform-test - running 1 tests
 0:02.64 INFO Using 1 child processes
 0:02.64 DEBUG Dispatch start_init
 0:02.64 DEBUG Got new test group subsuite: test_type:testharness
 0:02.64 DEBUG new state: initializing
 0:02.64 DEBUG Dispatch init
 0:02.65 INFO --certutil-binary not supplied; Firefox will not check certificates
 0:02.65 DEBUG Init called, starting browser and runner
 0:02.65 DEBUG Starting browser with settings {'check_leaks': False, 'lsan_disabled': False, 'lsan_allowed': set(), 'lsan_max_stack_depth': None, 'mozleak_allowed': False, 'mozleak_thresholds': False, 'special_powers': None}
 0:02.65 DEBUG Starting Firefox
 0:02.65 INFO Application command: /home/mirko/Downloads/firefox/firefox --marionette about:blank -profile /tmp/tmpyndqn3m6
 0:02.65 DEBUG OutputHandler.after_process_start
 0:02.65 DEBUG Firefox Started
 0:02.65 DEBUG OutputHandler.start
 0:02.65 INFO Starting runner
 0:02.66 DEBUG Test runner started
 0:02.87 DEBUG Got command: 'log'
 0:02.87 DEBUG Executor setup
 0:02.87 DEBUG Got command: 'log'
 0:02.87 DEBUG Connecting to Marionette on port 41887
 0:02.87 DEBUG Got command: 'log'
 0:02.87 DEBUG Waiting for Marionette connection
 0:03.00 pid:15581 Full command: /home/mirko/Downloads/firefox/firefox --marionette about:blank
pid:15581 ATTENTION: default value of option mesa_glthread overridden by environment.
 0:03.01 pid:15581 1707905379757    Marionette  INFO    Marionette enabled
 0:03.04 pid:15581 ATTENTION: default value of option mesa_glthread overridden by environment.
 0:03.09 pid:15581 1707905379840    Marionette  INFO    Listening on port 41887
 0:03.19 DEBUG Got command: 'log'
 0:03.19 DEBUG Starting Marionette session
 0:03.27 pid:15581 1707905380020    RemoteAgent WARN    TLS certificate errors will be ignored for this session
 0:03.46 pid:15581 console.error: ({})
 0:03.65 DEBUG Got command: 'log'
 0:03.65 DEBUG Marionette session started
 0:03.66 DEBUG Got command: 'log'
 0:03.65 DEBUG Loading http://web-platform.test:8000/testharness_runner.html
 0:03.80 DEBUG Got command: 'init_succeeded'
 0:03.80 DEBUG new state: running
 0:03.80 DEBUG Dispatch run_test
 0:03.80 TEST_START: /html/dom/elements/name-content-attribute-and-property.html
[...]

That is, it indeed worked with the non-Snap version.

whimboo commented 9 months ago

@whimboo be reminded that e.g. #44321 (comment) was generated with the default channel (Nightly). However, the corresponding logs show

Right. We diverged a bit from the original issue. So most likely the problem is somewhere in this Firefox class and the binary under /usr/bin/firefox is inappropriately detected as Nighly:

https://github.com/web-platform-tests/wpt/blob/34dd07ed48f51d6f607a8e7c411d893003482210/tools/wpt/browser.py#L197

If you would have the time and could test I would appreciate. I don't have a Linux system setup using the Snap Firefox package, and @jgraham is away at the moment.

mbrodesser-Igalia commented 9 months ago

@whimboo be reminded that e.g. #44321 (comment) was generated with the default channel (Nightly). However, the corresponding logs show

Right. We diverged a bit from the original issue. So most likely the problem is somewhere in this Firefox class and the binary under /usr/bin/firefox is inappropriately detected as Nighly:

https://github.com/web-platform-tests/wpt/blob/34dd07ed48f51d6f607a8e7c411d893003482210/tools/wpt/browser.py#L197

If you would have the time and could test I would appreciate. I don't have a Linux system setup using the Snap Firefox package, and @jgraham is away at the moment.

@whimboo: are you using Ubuntu with Snap support? If so, one can install Firefox from mozilla.org and the Snap package, switching via the $PATH variable.

whimboo commented 9 months ago

No, I'm on MacOS and as such cannot easily test this scenario.

mbrodesser-Igalia commented 9 months ago

@whimboo let's deal with the Snap- and Nightly- issues separately: https://github.com/web-platform-tests/wpt/issues/44585.

mbrodesser-Igalia commented 9 months ago

No, I'm on MacOS and as such cannot easily test this scenario.

Sorry, there are more urgent issues I currently need to work on. Consider installing a VM with Ubuntu.

whimboo commented 9 months ago

No worries it might have to wait then until @jgraham is back. I'm not really working on wptrunner but trying to help with investigations. Thanks for filing!