Open Bug 1642045 Opened 2 years ago Updated 1 day ago

Intermittent raptor-browsertime Critical: Failed waiting on page <random_url> to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette

Categories

(Testing :: Raptor, defect, P5)

defect

Tracking

(firefox95 affected)

REOPENED
Tracking Status
firefox95 --- affected

People

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

References

Details

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

Attachments

(1 file)

Filed by: ccoroiu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=304320138&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Gt5ZCSRBQ5-7Ms9EXts1hQ/runs/0/artifacts/public/logs/live_backing.log


[task 2020-05-29T21:40:43.393Z] 21:40:34 INFO - raptor-browsertime Info: Testing url https://www.amazon.com/s/ref=nb_sb_noss_2/139-6317191-5622045?url=search-alias%3Daps&field-keywords=mobile+phone iteration 6
[task 2020-05-29T21:40:43.393Z] 21:40:34 INFO - raptor-browsertime Info: Start firefox window recorder.
[task 2020-05-29T21:40:43.393Z] 21:40:34 INFO - raptor-browsertime Info: Fri, 29 May 2020 21:40:34 GMT adb:command Send '0019host:transport:ZY32259TSG'
[task 2020-05-29T21:40:43.393Z] 21:40:34 INFO - raptor-browsertime Info: Fri, 29 May 2020 21:40:34 GMT adb:command Send '003Dshell:rm -rf -- "/sdcard/browsertime-firefox-windowrecording"'
[task 2020-05-29T21:40:43.393Z] 21:40:34 INFO - raptor-browsertime Info: Fri, 29 May 2020 21:40:34 GMT adb:command Send '0019host:transport:ZY32259TSG'
[task 2020-05-29T21:40:43.393Z] 21:40:34 INFO - raptor-browsertime Info: Fri, 29 May 2020 21:40:34 GMT adb:command Send '0037shell:mkdir /sdcard/browsertime-firefox-windowrecording'
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - Exception in thread ProcessReader:
[task 2020-05-29T21:40:43.393Z] 21:40:43 ERROR - Traceback (most recent call last):
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - self.run()
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - File "/usr/lib/python2.7/threading.py", line 754, in run
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - self.__target(*self.__args, **self.__kwargs)
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - File "/builds/task_1590788038/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1116, in _read
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - callback(line.rstrip())
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - File "/builds/task_1590788038/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1026, in call
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - e(*args, **kwargs)
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - File "/builds/task_1590788038/workspace/build/tests/raptor/raptor/browsertime/base.py", line 348, in _line_handler
[task 2020-05-29T21:40:43.393Z] 21:40:43 INFO - raise Exception("Browsertime failed to run")
[task 2020-05-29T21:41:15.309Z] 21:40:43 INFO - Exception: Browsertime failed to run
[task 2020-05-29T21:41:15.309Z] 21:40:48 CRITICAL - raptor-browsertime Critical: Failed waiting on page to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - raptor-browsertime-android Info: removing reverse socket connections
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - adb command_output: adb -s ZY32259TSG wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 845
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - raptor-perftest Info: Removing temporary directory: /tmp/tmpSO4Y86
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - raptor-perftest Info: Removing temporary directory: /tmp/tmpVOSxcr
[task 2020-05-29T21:41:15.309Z] 21:40:48 ERROR - Traceback (most recent call last):
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - File "/builds/task_1590788038/workspace/build/tests/raptor/raptor/raptor.py", line 202, in <module>
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - main()
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - File "/builds/task_1590788038/workspace/build/tests/raptor/raptor/raptor.py", line 149, in main
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - File "/builds/task_1590788038/workspace/build/tests/raptor/raptor/browsertime/android.py", line 143, in run_tests
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - File "/builds/task_1590788038/workspace/build/tests/raptor/raptor/perftest.py", line 386, in run_tests
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - File "/builds/task_1590788038/workspace/build/tests/raptor/raptor/browsertime/base.py", line 364, in run_test
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - raise Exception(self.browsertime_failure)
[task 2020-05-29T21:41:15.309Z] 21:40:48 INFO - Exception: Failed waiting on page to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2020-05-29T21:41:15.309Z] 21:40:48 ERROR - Return code: 1

Remove the "exception followed by" since the exception is always thrown because of the way we are killing browsertime on failures.

Summary: Intermittent Exception: Browsertime failed to run followed by raptor-browsertime Critical: Failed waiting on page to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette → Intermittent raptor-browsertime Critical: Failed waiting on page to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Summary: Intermittent raptor-browsertime Critical: Failed waiting on page to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette → Intermittent raptor-browsertime Critical: Failed waiting on page <random_url> to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette

Looks like this was a transient failure. I'll watch it over the course of the week.

Status: REOPENED → RESOLVED
Closed: 1 year ago7 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Flags: needinfo?(bpostelnicu)

The job has been removed from Beta, does this also happens on central?

Flags: needinfo?(bpostelnicu) → needinfo?(malexandru)
Duplicate of this bug: 1727609

The youtube watch (youtube-w) tasks for fenix started to fail frequently, place investigate or redirect the request.

Flags: needinfo?(aionescu)

This might be due to the video recorded (video unavailable) and some policy consent dialog. Might need re-recording.

Whiteboard: [perftest:triage]
Whiteboard: [perftest:triage]

This may be caused by crashes in firefox that browsertime fails to report. There is an existing JIRA ticket for providing crash detection in browsertime, increased priority from medium to high

Flags: needinfo?(aionescu)
Flags: needinfo?(aionescu)

Can I have that JIRA ticket link?

Flags: needinfo?(aionescu) → needinfo?(ksereduck)

Sorry for the spam. It was perma failing but the issue got resolved by a backout.

Summary: Intermittent raptor-browsertime Critical: Failed waiting on page <random_url> to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette → Perma [tier 2] raptor-browsertime Critical: Failed waiting on page <random_url> to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
Regressed by: 1731982
Summary: Perma [tier 2] raptor-browsertime Critical: Failed waiting on page <random_url> to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette → Intermittent raptor-browsertime Critical: Failed waiting on page <random_url> to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
No longer regressed by: 1731982

There are 43 total failures in the last 7 days on

  • windows10-64-shippable-qr opt
  • linux1804-64-shippable-qr opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=355085749&repo=autoland&lineNumber=1304

[task 2021-10-17T15:10:02.783Z] 15:10:02     INFO -  raptor-browsertime Info: Starting a browsertime pageload
[task 2021-10-17T15:10:02.783Z] 15:10:02     INFO -  raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2021-10-17T15:10:03.782Z] 15:10:03     INFO -  raptor-browsertime Info: Navigating to about:blank, count: 0
[task 2021-10-17T15:10:03.783Z] 15:10:03     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 3
[task 2021-10-17T15:10:09.814Z] 15:10:09     INFO -  raptor-browsertime Info: Navigating to primary url:https://www.cnn.com/2021/03/22/weather/climate-change-warm-waters-lake-michigan/index.html
[task 2021-10-17T15:10:09.814Z] 15:10:09     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2021-10-17T15:10:10.815Z] 15:10:10     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2021-10-17T15:10:10.815Z] 15:10:10     INFO -  raptor-browsertime Info: Testing url https://www.cnn.com/2021/03/22/weather/climate-change-warm-waters-lake-michigan/index.html iteration 3
[task 2021-10-17T15:10:17.006Z] 15:10:17    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2021-10-17T15:10:17.023Z] 15:10:17     INFO -  raptor-browsertime Info:     at Object.throwDecodedError (C:\Users\task_1634469524\fetches\browsertime\node_modules\selenium-webdriver\lib\error.js:517:15)
[task 2021-10-17T15:10:17.024Z] 15:10:17     INFO -  raptor-browsertime Info:     at parseHttpResponse (C:\Users\task_1634469524\fetches\browsertime\node_modules\selenium-webdriver\lib\http.js:643:13)
[task 2021-10-17T15:10:17.024Z] 15:10:17     INFO -  raptor-browsertime Info:     at Executor.execute (C:\Users\task_1634469524\fetches\browsertime\node_modules\selenium-webdriver\lib\http.js:569:28)
[task 2021-10-17T15:10:17.024Z] 15:10:17     INFO -  raptor-browsertime Info:     at processTicksAndRejections (internal/process/task_queues.js:97:5)
[task 2021-10-17T15:10:17.025Z] 15:10:17     INFO -  raptor-browsertime Info:     at async Driver.execute (C:\Users\task_1634469524\fetches\browsertime\node_modules\selenium-webdriver\lib\webdriver.js:732:17)
[task 2021-10-17T15:10:17.025Z] 15:10:17     INFO -  raptor-browsertime Info: URL failed to load, trying 5 more time(s): Failed waiting on page https://www.cnn.com/2021/03/22/weather/climate-change-warm-waters-lake-michigan/index.html  to finished loading, timed out after 300000 ms
[task 2021-10-17T15:10:17.026Z] 15:10:17 CRITICAL -  raptor-browsertime Critical: Failed waiting on page https://www.cnn.com/2021/03/22/weather/climate-change-warm-waters-lake-michigan/index.html to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2021-10-17T15:10:17.026Z] 15:10:17     INFO -  raptor-mitmproxy Info: MitmproxyDesktop stop!!
[task 2021-10-17T15:10:17.027Z] 15:10:17     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2021-10-17T15:10:17.027Z] 15:10:17     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 1120
[task 2021-10-17T15:10:17.027Z] 15:10:17     INFO -  raptor-mitmproxy Info: Sending CTRL_BREAK_EVENT to mitmproxy
[task 2021-10-17T15:10:19.024Z] 15:10:19     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2021-10-17T15:10:19.025Z] 15:10:19     INFO -  raptor-mitmproxy Info: Turning off the browser proxy
[task 2021-10-17T15:10:19.025Z] 15:10:19     INFO -  raptor-mitmproxy Info: writing: C:\Users\task_1634469524\build\application\firefox\distribution\policies.json
[task 2021-10-17T15:10:19.026Z] 15:10:19     INFO -  raptor-perftest Info: Removing temporary directory: C:\Users\task_1634469524\AppData\Local\Temp\tmpizjlrteh
[task 2021-10-17T15:10:19.064Z] 15:10:19    ERROR -  Traceback (most recent call last):
[task 2021-10-17T15:10:19.065Z] 15:10:19     INFO -    File "C:\Users\task_1634469524\build\tests\raptor\raptor\raptor.py", line 213, in <module>
[task 2021-10-17T15:10:19.065Z] 15:10:19     INFO -      main()
[task 2021-10-17T15:10:19.065Z] 15:10:19     INFO -    File "C:\Users\task_1634469524\build\tests\raptor\raptor\raptor.py", line 159, in main
[task 2021-10-17T15:10:19.066Z] 15:10:19     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2021-10-17T15:10:19.066Z] 15:10:19     INFO -    File "C:\Users\task_1634469524\build\tests\raptor\raptor\perftest.py", line 457, in run_tests
[task 2021-10-17T15:10:19.066Z] 15:10:19     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2021-10-17T15:10:19.067Z] 15:10:19     INFO -    File "C:\Users\task_1634469524\build\tests\raptor\raptor\browsertime\base.py", line 567, in run_test
[task 2021-10-17T15:10:19.067Z] 15:10:19     INFO -      raise Exception(self.browsertime_failure)
[task 2021-10-17T15:10:19.068Z] 15:10:19     INFO -  Exception: Failed waiting on page https://www.cnn.com/2021/03/22/weather/climate-change-warm-waters-lake-michigan/index.html to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2021-10-17T15:10:19.123Z] 15:10:19    ERROR - Return code: 1
[task 2021-10-17T15:10:19.123Z] 15:10:19  WARNING - setting return code to 1
[task 2021-10-17T15:10:19.123Z] 15:10:19     INFO - Copying Raptor results to upload dir:
[task 2021-10-17T15:10:19.123Z] 15:10:19     INFO - C:\Users\task_1634469524\build\blobber_upload_dir\perfherder-data.json
[task 2021-10-17T15:10:19.123Z] 15:10:19     INFO - Copying raptor results from C:\Users\task_1634469524\build\raptor.json to C:\Users\task_1634469524\build\blobber_upload_dir\perfherder-data.json
[task 2021-10-17T15:10:19.124Z] 15:10:19 CRITICAL - Error copying results C:\Users\task_1634469524\build\raptor.json to upload dir C:\Users\task_1634469524\build\blobber_upload_dir\perfherder-data.json
[task 2021-10-17T15:10:19.124Z] 15:10:19     INFO - [Errno 2] No such file or directory: 'C:\\Users\\task_1634469524\\build\\raptor.json'
[task 2021-10-17T15:10:19.124Z] 15:10:19     INFO - Running post-action listener: _package_coverage_data
[task 2021-10-17T15:10:19.124Z] 15:10:19     INFO - Running post-action listener: _resource_record_post_action
[task 2021-10-17T15:10:19.124Z] 15:10:19     INFO - Running post-action listener: process_java_coverage_data
[task 2021-10-17T15:10:19.125Z] 15:10:19     INFO - Running post-action listener: stop_device

Greg, can you please take a look?

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

Yup, thanks for the ni?.

:kimberlythegeek, could you re-record the cnn pages and see if that helps with these failures?

Flags: needinfo?(gmierz2) → needinfo?(ksereduck)

(In reply to Greg Mierzwinski [:sparky] from comment #56)

:kimberlythegeek, could you re-record the cnn pages and see if that helps with these failures?

will do--although we may need to disable autoplay for these tests as well. I was getting vismet failures at first, presumably because 1) the cookie prompt was not displaying, so 2) the video was automatically playing. This seemed to affect the detection of whether the page was fully loaded or not.

I got around this by increasing wait time while recording

Flags: needinfo?(ksereduck)

Ah good point! Can you try disabling the auto-play for only the cnn page and see if that helps instead of re-recording?

Flags: needinfo?(ksereduck)

:sparky on it!

Flags: needinfo?(ksereduck)
Assignee: nobody → ksereduck
Attachment #9246477 - Attachment description: WIP: Bug 1642045: Re-record cnn to resolve timeout errors → Bug 1642045: Re-record cnn to resolve timeout errors
Pushed by ksereduck@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/329de07e7a96
Re-record cnn to resolve timeout errors r=perftest-reviewers,AlexandruIonescu
Status: REOPENED → RESOLVED
Closed: 7 months ago2 months ago
Resolution: --- → FIXED
Target Milestone: --- → 95 Branch

That patch won't resolve all of the errors we get with this line.

Status: RESOLVED → REOPENED
Keywords: leave-open
Resolution: FIXED → ---
Target Milestone: 95 Branch → ---

== Change summary for alert #31998 (as of Thu, 21 Oct 2021 06:47:36 GMT) ==

Improvements:

Ratio Test Platform Options Absolute values (old vs new)
40% cnn LastVisualChange macosx1014-64-shippable-qr cold webrender 12,440.00 -> 7,476.67

For up to date results, see: https://treeherder.mozilla.org/perfherder/alerts?id=31998

Update:
There have been 40 failures within the last 7 days:
• 1 failures on Android 7.0 MotoG5 Shippable WebRender opt
• 3 failures on Linux 18.04 x64 WebRender Shippable opt
• 4 failures on OS X 10.14 WebRender Shippable opt
• 5 failures on OS X 10.15 WebRender Shippable opt
• 27 failures on Windows 10 x64 WebRender Shippable opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=356520554&repo=mozilla-central&lineNumber=1277

[task 2021-10-30T22:58:51.717Z] 22:58:51     INFO -  raptor-browsertime Info: Starting a browsertime pageload
[task 2021-10-30T22:58:51.718Z] 22:58:51     INFO -  raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2021-10-30T22:58:52.717Z] 22:58:52     INFO -  raptor-browsertime Info: Navigating to about:blank, count: 0
[task 2021-10-30T22:58:52.718Z] 22:58:52     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 1
[task 2021-10-30T22:59:00.764Z] 22:59:00     INFO -  raptor-browsertime Info: Navigating to primary url:https://docs.google.com/document/d/1US-07msg12slQtI_xchzYxcKlTs6Fp7WqIc6W5GK5M8/edit?usp=sharing
[task 2021-10-30T22:59:00.764Z] 22:59:00     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2021-10-30T22:59:01.763Z] 22:59:01     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2021-10-30T22:59:01.764Z] 22:59:01     INFO -  raptor-browsertime Info: Testing url https://docs.google.com/document/d/1US-07msg12slQtI_xchzYxcKlTs6Fp7WqIc6W5GK5M8/edit?usp=sharing iteration 1
[task 2021-10-30T22:59:15.172Z] 22:59:15     INFO -  raptor-browsertime Info: Navigating to secondary url:https://docs.google.com/document/d/1vUnn0ePU-ynArE1OdxyEHXR2G0sl74ja_st_4OOzlgE/preview
[task 2021-10-30T22:59:15.173Z] 22:59:15     INFO -  raptor-browsertime Info: Navigating to url https://docs.google.com/document/d/1vUnn0ePU-ynArE1OdxyEHXR2G0sl74ja_st_4OOzlgE/preview iteration 1
[task 2021-10-30T22:59:29.227Z] 22:59:29     INFO -  raptor-browsertime Info: Navigating to primary url:https://docs.google.com/document/d/1US-07msg12slQtI_xchzYxcKlTs6Fp7WqIc6W5GK5M8/edit?usp=sharing
[task 2021-10-30T22:59:29.227Z] 22:59:29     INFO -  raptor-browsertime Info: Cycle 1, waiting for 1000 ms
[task 2021-10-30T22:59:30.227Z] 22:59:30     INFO -  raptor-browsertime Info: Cycle 1, starting the measure
[task 2021-10-30T22:59:30.227Z] 22:59:30     INFO -  raptor-browsertime Info: Testing url https://docs.google.com/document/d/1US-07msg12slQtI_xchzYxcKlTs6Fp7WqIc6W5GK5M8/edit?usp=sharing iteration 1
[task 2021-10-30T22:59:36.447Z] 22:59:36    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2021-10-30T22:59:36.473Z] 22:59:36     INFO -  raptor-browsertime Info:     at Object.throwDecodedError (C:\Users\task_1635598598\fetches\browsertime\node_modules\selenium-webdriver\lib\error.js:517:15)
[task 2021-10-30T22:59:36.474Z] 22:59:36     INFO -  raptor-browsertime Info:     at parseHttpResponse (C:\Users\task_1635598598\fetches\browsertime\node_modules\selenium-webdriver\lib\http.js:643:13)
[task 2021-10-30T22:59:36.475Z] 22:59:36     INFO -  raptor-browsertime Info:     at Executor.execute (C:\Users\task_1635598598\fetches\browsertime\node_modules\selenium-webdriver\lib\http.js:569:28)
[task 2021-10-30T22:59:36.475Z] 22:59:36     INFO -  raptor-browsertime Info:     at processTicksAndRejections (internal/process/task_queues.js:97:5)
[task 2021-10-30T22:59:36.475Z] 22:59:36     INFO -  raptor-browsertime Info:     at async Driver.execute (C:\Users\task_1635598598\fetches\browsertime\node_modules\selenium-webdriver\lib\webdriver.js:732:17)
[task 2021-10-30T22:59:36.476Z] 22:59:36     INFO -  raptor-browsertime Info: URL failed to load, trying 5 more time(s): Failed waiting on page https://docs.google.com/document/d/1US-07msg12slQtI_xchzYxcKlTs6Fp7WqIc6W5GK5M8/edit?usp=sharing  to finished loading, timed out after 300000 ms
[task 2021-10-30T22:59:36.477Z] 22:59:36 CRITICAL -  raptor-browsertime Critical: Failed waiting on page https://docs.google.com/document/d/1US-07msg12slQtI_xchzYxcKlTs6Fp7WqIc6W5GK5M8/edit?usp=sharing to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2021-10-30T22:59:36.477Z] 22:59:36     INFO -  raptor-mitmproxy Info: MitmproxyDesktop stop!!
[task 2021-10-30T22:59:36.477Z] 22:59:36     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2021-10-30T22:59:36.478Z] 22:59:36     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 2036
[task 2021-10-30T22:59:36.478Z] 22:59:36     INFO -  raptor-mitmproxy Info: Sending CTRL_BREAK_EVENT to mitmproxy
[task 2021-10-30T22:59:38.474Z] 22:59:38     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2021-10-30T22:59:38.475Z] 22:59:38     INFO -  raptor-mitmproxy Info: Turning off the browser proxy
[task 2021-10-30T22:59:38.475Z] 22:59:38     INFO -  raptor-mitmproxy Info: writing: C:\Users\task_1635598598\build\application\firefox\distribution\policies.json
[task 2021-10-30T22:59:38.476Z] 22:59:38     INFO -  raptor-perftest Info: Removing temporary directory: C:\Users\task_1635598598\AppData\Local\Temp\tmpzu8ps7xc
[task 2021-10-30T22:59:38.516Z] 22:59:38    ERROR -  Traceback (most recent call last):
[task 2021-10-30T22:59:38.517Z] 22:59:38     INFO -    File "C:\Users\task_1635598598\build\tests\raptor\raptor\raptor.py", line 213, in <module>
[task 2021-10-30T22:59:38.517Z] 22:59:38     INFO -      main()
[task 2021-10-30T22:59:38.517Z] 22:59:38     INFO -    File "C:\Users\task_1635598598\build\tests\raptor\raptor\raptor.py", line 159, in main
[task 2021-10-30T22:59:38.518Z] 22:59:38     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2021-10-30T22:59:38.518Z] 22:59:38     INFO -    File "C:\Users\task_1635598598\build\tests\raptor\raptor\perftest.py", line 457, in run_tests
[task 2021-10-30T22:59:38.518Z] 22:59:38     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2021-10-30T22:59:38.519Z] 22:59:38     INFO -    File "C:\Users\task_1635598598\build\tests\raptor\raptor\browsertime\base.py", line 567, in run_test
[task 2021-10-30T22:59:38.519Z] 22:59:38     INFO -      raise Exception(self.browsertime_failure)

Hi Kimberly, are you working on this? Any updates?

Flags: needinfo?(ksereduck)
Depends on: 1738679

There have been a high number of intermittent failures for cnn page load test since re-recording in mitm6. I ran multiple (~20) test runs using the mitm6 recording:

  • without secondary url, autoplay disabled
  • without secondary url, autoplay enabled
  • with secondary url, autoplay disabled (current configuration)
  • with secondary url, autoplay enabled

there continues to be a high number of failures with each of these methods. These failures arose after re-recording in mitm6, and this site has already been re-recorded multiple times.

I suspect that either this is an issue with mitm6 or with changes to cnn live site since the last recording. Since we are currently working on upgrading to mitmproxy 7 and will need to record again soon anyways, I propose restoring cnn to mitm5 until the upgrade is complete.

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