1772270 - Intermittent [Tier 2] raptor-browsertime Error: Browsertime failed to run| raptor-browsertime Critical: Failed waiting on page https://imgur.com/gallery/m5tYJL6 to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from

Status: RESOLVED DUPLICATE of bug 1642045

(Testing :: Raptor, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ccozmuta [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=379979972&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MeZm8vJLSMmOzgucC26Qdw/runs/0/artifacts/public/logs/live_backing.log

---

[task 2022-06-02T05:05:35.887Z] 05:05:35     INFO -  raptor-browsertime Info: Navigating to primary url:https://imgur.com/gallery/m5tYJL6
[task 2022-06-02T05:05:35.888Z] 05:05:35     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2022-06-02T05:05:36.889Z] 05:05:36     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2022-06-02T05:05:36.890Z] 05:05:36     INFO -  raptor-browsertime Info: Testing url https://imgur.com/gallery/m5tYJL6 iteration 3
[task 2022-06-02T05:05:36.891Z] 05:05:36     INFO -  raptor-browsertime Info: Start firefox window recorder.
[task 2022-06-02T05:07:22.542Z] 05:07:22    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2022-06-02T05:07:22.563Z] 05:07:22     INFO -  raptor-browsertime Info:     at Object.throwDecodedError (/home/cltbld/tasks/task_165414263700320/fetches/browsertime/node_modules/selenium-webdriver/lib/error.js:522:15)
[task 2022-06-02T05:07:22.564Z] 05:07:22     INFO -  raptor-browsertime Info:     at parseHttpResponse (/home/cltbld/tasks/task_165414263700320/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:549:13)
[task 2022-06-02T05:07:22.564Z] 05:07:22     INFO -  raptor-browsertime Info:     at Executor.execute (/home/cltbld/tasks/task_165414263700320/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:475:28)
[task 2022-06-02T05:07:22.565Z] 05:07:22     INFO -  raptor-browsertime Info:     at processTicksAndRejections (node:internal/process/task_queues:96:5)
[task 2022-06-02T05:07:22.565Z] 05:07:22     INFO -  raptor-browsertime Info:     at async Driver.execute (/home/cltbld/tasks/task_165414263700320/fetches/browsertime/node_modules/selenium-webdriver/lib/webdriver.js:735:17)
[task 2022-06-02T05:07:22.566Z] 05:07:22     INFO -  raptor-browsertime Info: URL failed to load, trying 5 more time(s): Failed waiting on page https://imgur.com/gallery/m5tYJL6  to finished loading, timed out after 300000 ms
[task 2022-06-02T05:07:22.567Z] 05:07:22 CRITICAL -  raptor-browsertime Critical: Failed waiting on page https://imgur.com/gallery/m5tYJL6 to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2022-06-02T05:07:22.567Z] 05:07:22     INFO -  raptor-mitmproxy Info: MitmproxyDesktop stop!!
[task 2022-06-02T05:07:22.567Z] 05:07:22     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2022-06-02T05:07:22.568Z] 05:07:22     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 3321
[task 2022-06-02T05:07:22.725Z] 05:07:22     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2022-06-02T05:07:22.726Z] 05:07:22     INFO -  raptor-mitmproxy Info: Turning off the browser proxy
[task 2022-06-02T05:07:22.726Z] 05:07:22     INFO -  raptor-mitmproxy Info: writing: /home/cltbld/tasks/task_165414263700320/build/application/firefox/distribution/policies.json
[task 2022-06-02T05:07:22.726Z] 05:07:22     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmpqyvcrn97
[task 2022-06-02T05:07:22.754Z] 05:07:22    ERROR -  Traceback (most recent call last):
[task 2022-06-02T05:07:22.755Z] 05:07:22     INFO -    File "/home/cltbld/tasks/task_165414263700320/build/tests/raptor/raptor/raptor.py", line 215, in <module>
[task 2022-06-02T05:07:22.755Z] 05:07:22     INFO -      main()
[task 2022-06-02T05:07:22.756Z] 05:07:22     INFO -    File "/home/cltbld/tasks/task_165414263700320/build/tests/raptor/raptor/raptor.py", line 161, in main
[task 2022-06-02T05:07:22.756Z] 05:07:22     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2022-06-02T05:07:22.756Z] 05:07:22     INFO -    File "/home/cltbld/tasks/task_165414263700320/build/tests/raptor/raptor/perftest.py", line 462, in run_tests
[task 2022-06-02T05:07:22.757Z] 05:07:22     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2022-06-02T05:07:22.757Z] 05:07:22     INFO -    File "/home/cltbld/tasks/task_165414263700320/build/tests/raptor/raptor/browsertime/base.py", line 601, in run_test
[task 2022-06-02T05:07:22.757Z] 05:07:22     INFO -      raise Exception(self.browsertime_failure)
[task 2022-06-02T05:07:22.758Z] 05:07:22     INFO -  Exception: Failed waiting on page https://imgur.com/gallery/m5tYJL6 to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2022-06-02T05:07:22.819Z] 05:07:22    ERROR - Return code: 1
[task 2022-06-02T05:07:22.819Z] 05:07:22  WARNING - setting return code to 1
[task 2022-06-02T05:07:22.819Z] 05:07:22     INFO - Copying Raptor results to upload dir:
[task 2022-06-02T05:07:22.819Z] 05:07:22     INFO - /home/cltbld/tasks/task_165414263700320/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-02T05:07:22.819Z] 05:07:22     INFO - Copying raptor results from /home/cltbld/tasks/task_165414263700320/build/raptor.json to /home/cltbld/tasks/task_165414263700320/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-02T05:07:22.819Z] 05:07:22 CRITICAL - Error copying results /home/cltbld/tasks/task_165414263700320/build/raptor.json to upload dir /home/cltbld/tasks/task_165414263700320/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-02T05:07:22.819Z] 05:07:22     INFO - [Errno 2] No such file or directory: '/home/cltbld/tasks/task_165414263700320/build/raptor.json'
[task 2022-06-02T05:07:22.820Z] 05:07:22     INFO - Running post-action listener: _package_coverage_data
[task 2022-06-02T05:07:22.820Z] 05:07:22     INFO - Running post-action listener: _resource_record_post_action
[task 2022-06-02T05:07:22.820Z] 05:07:22     INFO - Running post-action listener: process_java_coverage_data
[task 2022-06-02T05:07:22.820Z] 05:07:22     INFO - Running post-action listener: stop_device
[task 2022-06-02T05:07:22.820Z] 05:07:22     INFO - [mozharness: 2022-06-02 05:07:22.820881Z] Finished run-tests step (success)
[task 2022-06-02T05:07:22.820Z] 05:07:22     INFO - Running post-run listener: _resource_record_post_run
[task 2022-06-02T05:07:22.893Z] 05:07:22     INFO - Total resource usage - Wall time: 346s; CPU: 16%; Read bytes: 150166282240; Write bytes: 6441226240; Read time: 2173140; Write time: 2502392
[task 2022-06-02T05:07:22.893Z] 05:07:22     INFO - TinderboxPrint: CPU usage<br/>15.9%
[task 2022-06-02T05:07:22.893Z] 05:07:22     INFO - TinderboxPrint: I/O read bytes / time<br/>150,166,282,240 / 2,173,140
[task 2022-06-02T05:07:22.893Z] 05:07:22     INFO - TinderboxPrint: I/O write bytes / time<br/>6,441,226,240 / 2,502,392
[task 2022-06-02T05:07:22.894Z] 05:07:22     INFO - TinderboxPrint: CPU idle<br/>1,963.1 (71.2%)
[task 2022-06-02T05:07:22.894Z] 05:07:22     INFO - TinderboxPrint: CPU iowait<br/>352.4 (12.8%)
[task 2022-06-02T05:07:22.894Z] 05:07:22     INFO - TinderboxPrint: CPU system<br/>140.2 (5.1%)
[task 2022-06-02T05:07:22.894Z] 05:07:22     INFO - TinderboxPrint: CPU user<br/>271.9 (9.9%)
[task 2022-06-02T05:07:22.894Z] 05:07:22     INFO - TinderboxPrint: Swap in / out<br/>4,943,872 / 1,166,069,760
[task 2022-06-02T05:07:22.894Z] 05:07:22     INFO - install-chromium-distribution - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2022-06-02T05:07:22.894Z] 05:07:22     INFO - install - Wall time: 10s; CPU: 13%; Read bytes: 0; Write bytes: 407945216; Read time: 0; Write time: 3508
[task 2022-06-02T05:07:22.897Z] 05:07:22     INFO - run-tests - Wall time: 336s; CPU: 16%; Read bytes: 150164504576; Write bytes: 6031077376; Read time: 2173132; Write time: 2498844
[task 2022-06-02T05:07:22.954Z] 05:07:22  WARNING - returning nonzero exit status 1
[taskcluster 2022-06-02T05:07:22.982Z]    Exit Code: 1
[taskcluster 2022-06-02T05:07:22.982Z]    User Time: 4m50.076583s
[taskcluster 2022-06-02T05:07:22.982Z]  Kernel Time: 46.650834s
[taskcluster 2022-06-02T05:07:22.982Z]    Wall Time: 6m42.692772959s
[taskcluster 2022-06-02T05:07:22.982Z]       Result: FAILED
[taskcluster 2022-06-02T05:07:22.983Z] === Task Finished ===
[taskcluster 2022-06-02T05:07:22.983Z] Task Duration: 6m42.696480213s