Closed Bug 1635752 Opened 4 years ago Closed 3 years ago

Intermittent raptor-browsertime Critical: BrowserError: Could not start the browser with 3 tries

Categories

(Testing :: Raptor, defect, P5)

Product:
Testing
Component:
Raptor
Version:
Version 3
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: archaeopteryx [at] coole-files.de
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=300966739&repo=fenix
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/NiVlNeAmRLa1Z5aCFSwpwQ/runs/0/artifacts/public/logs/live_backing.log

This failure has been observed when several browsertime runs failed, e.g. also with bug 1635749 and bug 1518984

[task 2020-05-06T01:59:23.618Z] 01:39:07 INFO - raptor-browsertime Info: Wed, 06 May 2020 01:39:07 GMT adb:sync RECV /sdcard/browsertime-firefox-windowrecording/windowrecording-1588729134953.14/frame-6-3831.png
[task 2020-05-06T01:59:23.618Z] 01:39:08 INFO - raptor-browsertime Info: Browsertime pageload ended.
[task 2020-05-06T01:59:23.618Z] 01:39:08 INFO - raptor-browsertime Info: https://www.instagram.com BackEndTime: 47 DomInteractiveTime: 474 DomContentLoadedTime: 482 FirstPaint: 226 PageLoadTime: 1628
[task 2020-05-06T01:59:23.618Z] 01:39:14 INFO - raptor-browsertime Info: Browser failed to start, trying 2 more time(s): ECONNREFUSED connect ECONNREFUSED 127.0.0.1:45358
[task 2020-05-06T01:59:23.618Z] 01:39:15 INFO - raptor-browsertime Info: Browser failed to start, trying 1 more time(s): No Android devices are online
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - raptor-browsertime Info: Browser failed to start, trying 0 more time(s): No Android devices are online
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - Exception in thread ProcessReader:
[task 2020-05-06T01:59:23.618Z] 01:39:16 ERROR - Traceback (most recent call last):
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - self.run()
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - File "/usr/lib/python2.7/threading.py", line 754, in run
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - self.__target(*self.__args, **self.__kwargs)
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - File "/builds/task_1588728610/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1116, in _read
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - callback(line.rstrip())
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - File "/builds/task_1588728610/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1026, in call
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - e(*args, **kwargs)
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - File "/builds/task_1588728610/workspace/build/tests/raptor/raptor/browsertime/base.py", line 348, in _line_handler
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - raise Exception("Browsertime failed to run")
[task 2020-05-06T01:59:23.618Z] 01:39:16 INFO - Exception: Browsertime failed to run
[task 2020-05-06T01:59:23.618Z] 01:39:20 CRITICAL - raptor-browsertime Critical: BrowserError: Could not start the browser with 3 tries
[task 2020-05-06T01:59:23.618Z] 01:39:20 INFO - raptor-browsertime-android Info: removing reverse socket connections
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - raptor-perftest Info: Removing temporary directory: /tmp/tmpgj3Ata
[task 2020-05-06T01:59:23.618Z] 01:44:20 ERROR - Traceback (most recent call last):
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - File "/builds/task_1588728610/workspace/build/tests/raptor/raptor/raptor.py", line 201, in <module>
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - main()
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - File "/builds/task_1588728610/workspace/build/tests/raptor/raptor/raptor.py", line 148, in main
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - File "/builds/task_1588728610/workspace/build/tests/raptor/raptor/browsertime/android.py", line 143, in run_tests
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - File "/builds/task_1588728610/workspace/build/tests/raptor/raptor/perftest.py", line 381, in run_tests
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - self.run_test_teardown(test)
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - File "/builds/task_1588728610/workspace/build/tests/raptor/raptor/browsertime/android.py", line 147, in run_test_teardown
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - self.device.remove_socket_connections("reverse")
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - File "/builds/task_1588728610/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb.py", line 1377, in remove_socket_connections
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - self.command_output(cmd, timeout=timeout)
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - File "/builds/task_1588728610/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb.py", line 1271, in command_output
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - timeout=timeout)
[task 2020-05-06T01:59:23.618Z] 01:44:20 INFO - File "/builds/task_1588728610/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb.py", line 321, in command_output
[task 2020-05-06T01:59:23.618Z] 01:44:20 CRITICAL - raise ADBTimeoutError("%s" % adb_process)
[task 2020-05-06T01:59:23.618Z] 01:44:20 CRITICAL - mozdevice.adb.ADBTimeoutError: args: adb wait-for-device reverse --remove-all, exitcode: None, stdout:
[task 2020-05-06T01:59:23.618Z] 01:44:20 ERROR - Return code: 1

The error message in the bug name is a generic error, the next line contains the actual error that we saw. That said, this is a device issue and related to the ADBTimeoutError so I'm marking this bug as a duplicate of bug 1500266.

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → DUPLICATE
Summary: Intermittent Exception: Browsertime failed to run → Intermittent Critical: BrowserError: Could not start the browser with 3 tries
Summary: Intermittent Critical: BrowserError: Could not start the browser with 3 tries → Intermittent raptor-browsertime Critical: BrowserError: Could not start the browser with 3 tries

Reopening since there seems to be failures with this signature that are unrelated to ADB.

Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 4 years ago → 4 years ago
Resolution: --- → INCOMPLETE

recent failure: https://treeherder.mozilla.org/logviewer?job_id=321061848&repo=autoland&lineNumber=1913

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Greg, could you please have a look over these failures?

They don't look tree related, first failed on autoland https://tinyurl.com/y2t2bahh then only on central: https://tinyurl.com/y44awn96
added jobs on autoland to see if they would still fail but all came out green: https://tinyurl.com/y2y8zcd2

Wanted to see if it's worker related but it doesn't seem to be, eg of some workers:

As you can see they have a high failure rate on central with 124 failures so far, all on android-hw-p2-8-0-android-aarch64-shippable browsertime jobs: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2020-11-08&endday=2020-11-15&tree=trunk&bug=1635752
Failure log: https://treeherder.mozilla.org/logviewer?job_id=321793786&repo=mozilla-central
Logcat: https://firefoxci.taskcluster-artifacts.net/eO2V7lYETeuZ9gB6kZguAw/0/public/test_info/logcat-HT7AR1A03631.log

[taskcluster 2020-11-14T13:20:35.965Z] [taskcluster-proxy] Successfully refreshed taskcluster-proxy credentials: task-client/eO2V7lYETeuZ9gB6kZguAw/0/on/bitbar/pixel2-46/until/1605361235.943
[taskcluster 2020-11-14T13:37:36.021Z] [taskcluster-proxy] Successfully refreshed taskcluster-proxy credentials: task-client/eO2V7lYETeuZ9gB6kZguAw/0/on/bitbar/pixel2-46/until/1605362255.989
[task 2020-11-14T13:46:04.982Z] 13:05:51     INFO -  raptor-browsertime Info: Running tests using Firefox - 15 iteration(s)
[task 2020-11-14T13:46:04.982Z] 13:06:51     INFO -  raptor-browsertime Info: Browser failed to start, trying 2 more time(s): Failed to start browser in 60 seconds.
[task 2020-11-14T13:46:04.982Z] 13:07:51     INFO -  raptor-browsertime Info: Browser failed to start, trying 1 more time(s): Failed to start browser in 60 seconds.
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -  raptor-browsertime Info: Browser failed to start, trying 0 more time(s): Failed to start browser in 60 seconds.
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -  Exception in thread ProcessReader:
[task 2020-11-14T13:46:04.982Z] 13:08:51    ERROR -  Traceback (most recent call last):
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -    File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -      self.run()
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -    File "/usr/lib/python2.7/threading.py", line 754, in run
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -      self.__target(*self.__args, **self.__kwargs)
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -    File "/builds/task_160535901583540/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1265, in _read
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -      callback(line.rstrip())
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -    File "/builds/task_160535901583540/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1171, in __call__
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -      e(*args, **kwargs)
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -    File "/builds/task_160535901583540/workspace/build/tests/raptor/raptor/browsertime/base.py", line 412, in _line_handler
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -      raise Exception("Browsertime failed to run")
[task 2020-11-14T13:46:04.982Z] 13:08:51     INFO -  Exception: Browsertime failed to run
[task 2020-11-14T13:46:04.982Z] 13:45:52 CRITICAL -  raptor-browsertime Critical: BrowserError: Could not start the browser with 3 tries
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -  raptor-browsertime-android Info: removing reverse socket connections
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -  adb command_output: adb -s HT7AR1A03631 wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 1025
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmpF2LHv2
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmpbtETg1
[task 2020-11-14T13:46:04.982Z] 13:45:52    ERROR -  Traceback (most recent call last):
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -    File "/builds/task_160535901583540/workspace/build/tests/raptor/raptor/raptor.py", line 205, in <module>
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -      main()
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -    File "/builds/task_160535901583540/workspace/build/tests/raptor/raptor/raptor.py", line 151, in main
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -    File "/builds/task_160535901583540/workspace/build/tests/raptor/raptor/browsertime/android.py", line 195, in run_tests
[task 2020-11-14T13:46:04.982Z] 13:45:52     INFO -      return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2020-11-14T13:46:04.983Z] 13:45:52     INFO -    File "/builds/task_160535901583540/workspace/build/tests/raptor/raptor/perftest.py", line 390, in run_tests
[task 2020-11-14T13:46:04.983Z] 13:45:52     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2020-11-14T13:46:04.983Z] 13:45:52     INFO -    File "/builds/task_160535901583540/workspace/build/tests/raptor/raptor/browsertime/base.py", line 451, in run_test
[task 2020-11-14T13:46:04.983Z] 13:45:52     INFO -      raise Exception(self.browsertime_failure)
[task 2020-11-14T13:46:04.983Z] 13:45:52     INFO -  Exception: BrowserError: Could not start the browser with 3 tries
[task 2020-11-14T13:46:04.983Z] 13:45:52    ERROR - Return code: 1

Thanks for looking into this.

Flags: needinfo?(gmierz2)
Whiteboard: [stockwell needswork:owner]

The perma-failure that was going on here has resolved itself.

Flags: needinfo?(gmierz2)
See Also: → 1678112
Whiteboard: [stockwell disable-recommended] → [stockwell unknown]
Whiteboard: [stockwell disable-recommended] → [stockwell unknown]
Whiteboard: [stockwell disable-recommended]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 4 years ago → 3 years ago
Resolution: --- → INCOMPLETE
See Also: → 1832290
You need to log in before you can comment on or make changes to this bug.