TEST-UNEXPECTED-FAIL testing/raptor/test/test_raptor.py::test_start_browser[firefox]

RESOLVED FIXED in Firefox 68

Status

defect
P1
normal
RESOLVED FIXED
3 months ago
2 months ago

People

(Reporter: whimboo, Assigned: whimboo)

Tracking

Version 3
mozilla68
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox68 fixed)

Details

Attachments

(4 attachments)

This test fails only locally (at least on MacOS) because in automation it isn't run due to missing browser binaries. The failure is printed by pytest is:

0:17.92 testing/raptor/test/test_raptor.py::test_start_browser[firefox] Exception in thread Thread-3:
0:17.92 Traceback (most recent call last):
0:17.92 File "/usr/local/Cellar/python@2/2.7.16/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 801, in __bootstrap_inner
0:17.92 self.run()
0:17.92 File "/usr/local/Cellar/python@2/2.7.16/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 754, in run
0:17.92 self.__target(*self.__args, **self.__kwargs)
0:17.92 File "/Users/henrik/code/gecko/testing/raptor/raptor/raptor.py", line 407, in run_test
0:17.92 self.run_test_setup(test)
0:17.92 File "/Users/henrik/code/gecko/testing/raptor/raptor/raptor.py", line 135, in run_test_setup
0:17.92 browser_cycle=test['browser_cycle'])
0:17.92 KeyError: 'browser_cycle'
0:17.92
0:17.92 TEST-UNEXPECTED-FAIL
0:17.92 testing/raptor/test/test_raptor.py::test_start_browser[chrome] xfail
0:17.92
0:17.92 =================================== FAILURES ===================================
0:17.92 _________________________ test_start_browser[firefox] __________________________
0:17.92
0:17.92 get_binary = <function inner at 0x10bb6d938>, app = 'firefox'
0:17.92
0:17.92 @pytest.mark.parametrize('app', [
0:17.92 'firefox',
0:17.92 pytest.mark.xfail('chrome'),
0:17.92 ])
0:17.92 def test_start_browser(get_binary, app):
0:17.92 binary = get_binary(app)
0:17.93 assert binary
0:17.93
0:17.93 raptor = RaptorDesktopFirefox(app, binary)
0:17.93 raptor.create_browser_profile()
0:17.93 raptor.create_browser_handler()
0:17.93 raptor.start_control_server()
0:17.93
0:17.93 test = {}
0:17.93 test['name'] = 'raptor-{}-tp6'.format(app)
0:17.93
0:17.93 thread = threading.Thread(target=raptor.run_test, args=(test,))
0:17.93 thread.start()
0:17.93
0:17.93 timeout = time.time() + 5 # seconds
0:17.93 while time.time() < timeout:
0:17.93 try:
0:17.93 is_running = raptor.runner.is_running()
0:17.93 assert is_running
0:17.93 break
0:17.93 except RunnerNotStartedError:
0:17.93 time.sleep(0.1)
0:17.93 else:
0:17.93 > assert False # browser didn't start
0:17.93 E assert False
0:17.93
0:17.93 ../../test/test_raptor.py:106: AssertionError
0:17.93 ------------------------------ Captured log call -------------------------------
0:17.93 init.py 369 INFO checking for vcs source checkout...
0:17.93 init.py 369 INFO hg
0:17.93 init.py 369 INFO Adding configure options from /Users/henrik/.mozbuild/mozconfigs/debug
0:17.93 init.py 369 INFO --enable-artifact-builds
0:17.93 init.py 369 INFO --enable-debug
0:17.93 init.py 369 INFO BUILD_SYSTEM_TELEMETRY=1
0:17.93 init.py 369 INFO checking for host system type...
0:17.93 init.py 369 INFO x86_64-apple-darwin18.2.0
0:17.93 init.py 369 INFO checking for target system type...
0:17.93 init.py 369 INFO x86_64-apple-darwin18.2.0
0:17.93 ================ 1 failed, 5 passed, 1 xfailed in 6.10 seconds =================
0:17.93 Setting retcode to 1 from /Users/henrik/code/gecko/testing/raptor/test/test_raptor.py
0:17.93 Return code from mach python-test: 1

The KeyError here happens because the test doesn't set the browser_cycle property on the dictionary. The fix would be to use get() with a default value of 1.

Once that is done the next failure occurs which interestingly doesn't mark the test as failed:

0:13.32 testing/raptor/test/test_raptor.py::test_start_browser[firefox] Exception in thread Thread-3:
0:13.32 Traceback (most recent call last):
0:13.32 File "/usr/local/Cellar/python@2/2.7.16/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 801, in __bootstrap_inner
0:13.32 self.run()
0:13.32 File "/usr/local/Cellar/python@2/2.7.16/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 754, in run
0:13.32 self.__target(*self.__args, **self.__kwargs)
0:13.32 File "/Users/henrik/code/gecko/testing/raptor/raptor/raptor.py", line 421, in run_test
0:13.32 self.wait_for_test_finish(test, timeout)
0:13.32 File "/Users/henrik/code/gecko/testing/raptor/raptor/raptor.py", line 326, in wait_for_test_finish
0:13.32 timeout = int(timeout / 1000) * int(test['page_cycles'])
0:13.32 TypeError: unsupported operand type(s) for /: 'NoneType' and 'int'
0:13.32
0:13.32 PASSED

This happens because the failing code is part of a spawned thread, and the exception isn't correctly handed over to the main thread inside the test.

Fixing that will now correctly report the failure and marking the test as failed.

The next problem here is that the test doesn't specify a timeout value, so that the division won't work. If I add a timeout like say 10s, it will pass but stalls for a while because wait_for_test_finished() adds some arbitrary extra time to it:

https://searchfox.org/mozilla-central/source/testing/raptor/raptor/raptor.py#325-332

Making the post_startup_delay property configurable mostly fixes it, and makes the test work.

Note that I won't fix the timeout=None issue here, given that is way more complex and should be handled on a follow-up bug.

Blocks: 1506928

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

Note that I won't fix the timeout=None issue here, given that is way more complex and should be handled on a follow-up bug.

I filed bug 1541385.

Comment 7

3 months ago
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4b426a086562
[raptor] Fall back to 1 browser_cycle / page_cycle if test doesn't specify a value. r=rwood
https://hg.mozilla.org/integration/autoland/rev/bf54318fe559
[raptor] Check for failures in spawned thread for test_start_browser. r=rwood
https://hg.mozilla.org/integration/autoland/rev/a77666feb358
[raptor] Make post_startup_delay configurable. r=rwood
https://hg.mozilla.org/integration/autoland/rev/3f56360e90ad
[raptor] Use proper timeout values for test_start_browser. r=rwood

Comment 9

2 months ago

I just pulled from inbound and now when running from the command line locally I get

17:11:55 ERROR - Traceback (most recent call last):
17:11:55 INFO - File "testing/raptor/raptor/raptor.py", line 933, in <module>
17:11:55 INFO - main()
17:11:55 INFO - File "testing/raptor/raptor/raptor.py", line 891, in main
17:11:55 INFO - activity=args.activity)
17:11:55 INFO - File "testing/raptor/raptor/raptor.py", line 572, in init
17:11:55 INFO - power_test, is_release_build, debug_mode, post_startup_delay)
17:11:55 INFO - File "testing/raptor/raptor/raptor.py", line 109, in init
17:11:55 INFO - % self.post_startup_delay)
17:11:55 ERROR - TypeError: %d format: a number is required, not NoneType

perhaps post_startup_delay shouldn't be defaulted to a None type or the format string should be changed or self.post_startup_delay = min(self.post_startup_delay, 3000) should deal with a None.

Flags: needinfo?(hskupin)

Comment 10

2 months ago

Ignore comment 9. It was the result of a bad pull and merge.

Updated

2 months ago
Flags: needinfo?(hskupin)
You need to log in before you can comment on or make changes to this bug.