1925308 - Intermittent TSAN testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py | TestQuitRestart.test_restart_safe_mode - socket.timeout: Process unexpectedly quit without restarting (exit code: 0)

Status: RESOLVED FIXED

(Testing :: Marionette Client and Harness, defect, P3)

Description

[Joel Maher ( :jmaher ) (UTC -8)]

as per try:

TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py TestQuitRestart.test_restart_safe_mode
[task 2024-10-09T19:13:53.657Z] 19:13:53     INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py TestQuitRestart.test_restart_safe_mode | socket.timeout: Process unexpectedly quit without restarting (exit code: 0)
[task 2024-10-09T19:13:53.658Z] 19:13:53     INFO - Traceback (most recent call last):
[task 2024-10-09T19:13:53.658Z] 19:13:53     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_harness/marionette_test/testcases.py", line 198, in run
[task 2024-10-09T19:13:53.658Z] 19:13:53     INFO -     testMethod()
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py", line 201, in test_restart_safe_mode
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -     self.marionette.restart(safe_mode=True)
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -     return func(*args, **kwargs)
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/marionette.py", line 1290, in restart
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -     reraise(
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/six.py", line 718, in reraise
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -     raise value.with_traceback(tb)
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/marionette.py", line 1271, in restart
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -     self.raise_for_port(timeout=timeout_restart, check_process_status=False)
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/marionette_driver/marionette.py", line 744, in raise_for_port
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO -     raise socket.timeout(
[task 2024-10-09T19:13:53.659Z] 19:13:53     INFO - TEST-INFO took 493435ms

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This is a specific failure when trying to restart Firefox into safemode for a TSAN build. Maybe it takes way longer for that restart so that we finally fail. We agreed to disable the test for now to get bug 1916662 landed.

Comment 2

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Trying to run this test locally I actually get a KeyError for tsan:

KeyError: 'tsan'

  File "/Users/henrik/code/gecko/testing/marionette/mach_commands.py", line 113, in marionette_test
    return run_marionette(tests, topsrcdir=command_context.topsrcdir, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/henrik/code/gecko/testing/marionette/mach_commands.py", line 58, in run_marionette
    failed = MarionetteHarness(MarionetteTestRunner, args=vars(args)).run()
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/henrik/code/gecko/testing/marionette/harness/marionette_harness/runtests.py", line 79, in run
    runner.run_tests(tests)
  File "/Users/henrik/code/gecko/testing/marionette/harness/marionette_harness/runner/base.py", line 1016, in run_tests
    self.run_test_sets()
  File "/Users/henrik/code/gecko/testing/marionette/harness/marionette_harness/runner/base.py", line 1242, in run_test_sets
    self.run_test_set(self.tests)
  File "/Users/henrik/code/gecko/testing/marionette/harness/marionette_harness/runner/base.py", line 1212, in run_test_set
    self.run_test(test["filepath"], test["expected"])
  File "/Users/henrik/code/gecko/testing/marionette/harness/marionette_harness/runner/base.py", line 1156, in run_test
    handler.add_tests_to_suite(
  File "/Users/henrik/code/gecko/testing/marionette/harness/marionette_harness/marionette_test/testcases.py", line 380, in add_tests_to_suite
    test_mod = load_source(mod_name, filepath)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/henrik/code/gecko/testing/mozbase/mozfile/mozfile/mozfile.py", line 649, in load_source
    loader.exec_module(module)
  File "<frozen importlib._bootstrap_external>", line 940, in exec_module
  File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  File "/Users/henrik/code/gecko/testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py", line 87, in <module>
    class TestQuitRestart(MarionetteTestCase):
  File "/Users/henrik/code/gecko/testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py", line 201, in TestQuitRestart
    mozinfo.info["tsan"] == True,
    ~~~~~~~~~~~~^^^^^^^^

This happens because the tsan flag is not set for non-TSAN builds. I assume that in CI we always set it and then default to false.

I'll push a fix for that given that currently I'm not able to successfully run this test file.

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Bug 1925308 - [marionette] Fix KeyError when trying to get the `tsan` flag.

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Because the initial log files are no longer accessible I've pushed another try build to see more details:
https://treeherder.mozilla.org/jobs?repo=try&tier=1%2C2%2C3&revision=8faa879942e058653f3b230c4557a25f9678161c

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/bcd55a055406
[marionette] Fix KeyError when trying to get the `tsan` flag. r=webdriver-reviewers,Sasha

Comment 6

[Norisz Fay [:noriszfay]]

https://hg.mozilla.org/mozilla-central/rev/bcd55a055406

Comment 7

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #4)

Because the initial log files are no longer accessible I've pushed another try build to see more details:
https://treeherder.mozilla.org/jobs?repo=try&tier=1%2C2%2C3&revision=8faa879942e058653f3b230c4557a25f9678161c

Surprisingly after the test testing/marionette/harness/marionette_harness/tests/unit/test_marionette.py TestMarionette.test_disable_enable_new_connections we loose any logging for Marionette unit tests. This seems to happen only for TSAN builds on Linux but no other build type and platform.

[task 2024-11-22T16:45:53.153Z] 16:45:53     INFO -  1732293953152	Marionette	DEBUG	421 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2024-11-22T16:45:53.155Z] 16:45:53     INFO -  1732293953154	Marionette	TRACE	[544] MarionetteCommands actor destroyed for window id 161061273643
[task 2024-11-22T16:45:53.160Z] 16:45:53     INFO -  1732293953160	Marionette	DEBUG	421 <- [1,8,null,{"value":null}]
[task 2024-11-22T16:45:53.163Z] 16:45:53     INFO -  1732293953162	Marionette	DEBUG	Closed connection 421
[task 2024-11-22T16:45:54.247Z] 16:45:54     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmp0mdb5_pi.mozrunner
[task 2024-11-22T16:46:06.789Z] 16:46:06     INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_marionette.py TestMarionette.test_disable_enable_new_connections | took 13685ms
[task 2024-11-22T16:46:06.789Z] 16:46:06     INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_marionette.py TestMarionette.test_marionette_active_port_file
[task 2024-11-22T16:46:12.134Z] 16:46:12     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmp0mdb5_pi.mozrunner
[task 2024-11-22T16:46:23.959Z] 16:46:23     INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_marionette.py TestMarionette.test_marionette_active_port_file | took 17170ms
[task 2024-11-22T16:46:23.960Z] 16:46:23     INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_marionette.py TestMarionette.test_raise_for_port_non_existing_process
[task 2024-11-22T16:46:28.314Z] 16:46:28     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmp0mdb5_pi.mozrunner
[task 2024-11-22T16:46:40.217Z] 16:46:40     INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_marionette.py TestMarionette.test_raise_for_port_non_existing_process | took 16257ms
[..]
[task 2024-11-22T17:25:38.709Z] 17:25:38     INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_window_type_chrome.py TestWindowTypeChrome.test_get_window_type
[task 2024-11-22T17:25:39.970Z] 17:25:39     INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_window_type_chrome.py TestWindowTypeChrome.test_get_window_type | took 1260ms
[task 2024-11-22T17:25:39.971Z] 17:25:39     INFO - 

This actually blocks as to identify the underlying issue. Before filing a new bug to get this fixed I'll try to find some time this week to take a look at on a Linux machine.

Comment 8

[Intermittent Failures Robot]

Summary

1 failures in 3682 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• linux1804-64-tsan-qr: 1
  • opt: 1

Table

	no_variant
linux1804-64-tsan-qr/opt	1

For more details, see:

https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1925308&startday=2025-01-06&endday=2025-01-12&tree=all

Comment 9

[Intermittent Failures Robot]

1 failures were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Table

	no_variant
windows11-x86_64/opt	1

For more details, see:

https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1925308&startday=2025-06-23&endday=2025-06-29&tree=all

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This is only the test TestQuitRestart.test_restart_safe_mode which is affected here. Also I landed the patch but doesn't actually work on this bug.

Nevertheless I pushed a try build to check if it is still failing or not:
https://treeherder.mozilla.org/jobs?repo=try&revision=ef2f28bdbf055715cb85a1e4b2ca24482de44d77

Comment 11

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #7)

Surprisingly after the test testing/marionette/harness/marionette_harness/tests/unit/test_marionette.py TestMarionette.test_disable_enable_new_connections we loose any logging for Marionette unit tests. This seems to happen only for TSAN builds on Linux but no other build type and platform.

If we have to do further investigation we might need bug 1989904 fixed first to better understand what's going on.

Comment 12

[Henrik Skupin [:whimboo][⌚️UTC+2]]

I can see a hang related to the ThreadSanitizer: CHECK failed: sanitizer_deadlock_detector1.cpp:166 log entry. This might actually have an affect here. I'll retrigger some more jobs to see if it is always failing to have a better reproducible test case.

Comment 13

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This test is actually failing because of bug 1991871.

Comment 14

[Intermittent Failures Robot]

1 failures were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 1

Table

	no_variant
windows11-x86_64/asan	1

For more details, see:

https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1925308&startday=2025-10-13&endday=2025-10-19&tree=all

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Bug 1925308 - [marionette] Unskip test_restart_safe_mode for TSAN builds.

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/9fbd4b2eeb80
https://hg.mozilla.org/integration/autoland/rev/77cb0f20e63c
[marionette] Unskip test_restart_safe_mode for TSAN builds. r=webdriver-reviewers,Sasha

Comment 17

[Norisz Fay [:noriszfay]]

https://hg.mozilla.org/mozilla-central/rev/77cb0f20e63c