Closed Bug 1635749 Opened 5 months ago Closed 3 months ago

Intermittent raptor-browsertime Critical: Couldn't execute async script named toggle composition recorder error:WebDriverError: Failed to decode response from marionette

Categories

(Testing :: Raptor, defect, P5)

Version 3
defect

Tracking

(firefox79 fixed)

RESOLVED FIXED
mozilla79
Tracking Status
firefox79 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: sparky)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Attachments

(1 file)

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


This occurred when several other browsertime tasks failed with bug 1518984.

[task 2020-05-06T01:34:35.728Z] 01:18:04 INFO - raptor-browsertime Info: Testing url https://www.amazon.com iteration 2
[task 2020-05-06T01:34:35.728Z] 01:18:04 INFO - raptor-browsertime Info: Start firefox window recorder.
[task 2020-05-06T01:34:35.728Z] 01:18:04 INFO - raptor-browsertime Info: Wed, 06 May 2020 01:18:04 GMT adb:command Send '0019host:transport:ZY32259TSG'
[task 2020-05-06T01:34:35.728Z] 01:18:04 INFO - raptor-browsertime Info: Wed, 06 May 2020 01:18:04 GMT adb:command Send '003Dshell:rm -rf -- "/sdcard/browsertime-firefox-windowrecording"'
[task 2020-05-06T01:34:35.728Z] 01:18:04 INFO - raptor-browsertime Info: Wed, 06 May 2020 01:18:04 GMT adb:command Send '0019host:transport:ZY32259TSG'
[task 2020-05-06T01:34:35.728Z] 01:18:04 INFO - raptor-browsertime Info: Wed, 06 May 2020 01:18:04 GMT adb:command Send '0037shell:mkdir /sdcard/browsertime-firefox-windowrecording'
[task 2020-05-06T01:34:35.728Z] 01:18:13 INFO - raptor-browsertime Info: Stop firefox window recorder.
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - Exception in thread ProcessReader:
[task 2020-05-06T01:34:35.728Z] 01:18:56 ERROR - Traceback (most recent call last):
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - self.run()
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - File "/usr/lib/python2.7/threading.py", line 754, in run
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - self.__target(*self.__args, **self.__kwargs)
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - File "/builds/task_1588722818/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1116, in _read
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - callback(line.rstrip())
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - File "/builds/task_1588722818/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1026, in call
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - e(*args, **kwargs)
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - File "/builds/task_1588722818/workspace/build/tests/raptor/raptor/browsertime/base.py", line 348, in _line_handler
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - raise Exception("Browsertime failed to run")
[task 2020-05-06T01:34:35.728Z] 01:18:56 INFO - Exception: Browsertime failed to run
[task 2020-05-06T01:34:35.728Z] 01:34:35 CRITICAL - raptor-browsertime Critical: Couldn't execute async script named toggle composition recorder error:WebDriverError: Failed to decode response from marionette
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - raptor-browsertime-android Info: removing reverse socket connections
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - adb command_output: adb -s ZY32259TSG wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 1089
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - raptor-perftest Info: Removing temporary directory: /tmp/tmp4kGavJ
[task 2020-05-06T01:35:02.988Z] 01:34:35 ERROR - Traceback (most recent call last):
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - File "/builds/task_1588722818/workspace/build/tests/raptor/raptor/raptor.py", line 201, in <module>
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - main()
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - File "/builds/task_1588722818/workspace/build/tests/raptor/raptor/raptor.py", line 148, in main
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - File "/builds/task_1588722818/workspace/build/tests/raptor/raptor/browsertime/android.py", line 143, in run_tests
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - File "/builds/task_1588722818/workspace/build/tests/raptor/raptor/perftest.py", line 373, in run_tests
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - File "/builds/task_1588722818/workspace/build/tests/raptor/raptor/browsertime/base.py", line 364, in run_test
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - raise Exception(self.browsertime_failure)
[task 2020-05-06T01:35:02.988Z] 01:34:35 INFO - Exception: Couldn't execute async script named toggle composition recorder error:WebDriverError: Failed to decode response from marionette
[task 2020-05-06T01:35:02.988Z] 01:34:35 ERROR - Return code: 1

See Also: → 1635752

These errors are going to become more frequent since we now kill browsertime as soon as it hits an error (rather than hitting it in the visual metrics task).

:barret, could you take a look at this issue? I think that if you enable the marionette trace log, it should provide more information.

Flags: needinfo?(brennie)

We talked about this in person and :sparky is going to investigate using the android screen recorder. This failure may be due to out-of-memory errors on the g5.

Flags: needinfo?(brennie)

There are 26 failures in the past 7 days. This occurs on android-hw-g5-7-0-arm7-api-16-shippable opt.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=306950362&repo=mozilla-central&lineNumber=1664

:sparky, any updates on this bug?

Whiteboard: [stockwell needswork:owner]
Flags: needinfo?(gmierz2)
Assignee: nobody → gmierz2
Status: NEW → ASSIGNED
Pushed by gmierz2@outlook.com:
https://hg.mozilla.org/integration/autoland/rev/8aff011594bf
Disable firefox window recorder temporarily. r=perftest-reviewers,Bebe
Flags: needinfo?(gmierz2)
Status: ASSIGNED → RESOLVED
Closed: 3 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla79

This also affects Fenix. Shall this bug get reopened?

Flags: needinfo?(gmierz2)

Created bug 1652357 because it failed once more today (on the same push).

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