Closed Bug 1720276 Opened 4 years ago Closed 4 years ago

Permanent beta Linux clang ytp raptor-browsertime Critical: Failed waiting on page https://yttest.prod.mozaws.net/2020/main.html?test_type=playbackperf-sfr-h264-test&raptor=true&exclude=1,2&muted=true&command=run to finished loading,

Categories

(Testing :: General, defect, P5)

Product:
Testing
Component:
General
Type:
defect

Tracking

(firefox-esr78 unaffected, firefox90 unaffected, firefox91 fixed, firefox92 fixed)

Status:
RESOLVED FIXED
Milestone:
91 Branch
Tracking Flags:
Tracking Status
firefox-esr78 --- unaffected
firefox90 --- unaffected
firefox91 --- fixed
firefox92 --- fixed

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

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

Youtube playback tasks fail to run on mozilla-beta

[task 2021-07-13T03:03:27.612Z] 03:03:27     INFO -  raptor-browsertime Info: Starting a browsertime benchamrk
[task 2021-07-13T03:03:27.613Z] 03:03:27     INFO -  raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2021-07-13T03:03:28.615Z] 03:03:28     INFO -  raptor-browsertime Info: Navigating to about:blank
[task 2021-07-13T03:03:28.615Z] 03:03:28     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 1
[task 2021-07-13T03:03:33.660Z] 03:03:33     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2021-07-13T03:03:34.662Z] 03:03:34     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2021-07-13T03:03:34.663Z] 03:03:34     INFO -  raptor-browsertime Info: Testing url https://yttest.prod.mozaws.net/2020/main.html?test_type=playbackperf-sfr-h264-test&raptor=true&exclude=1,2&muted=true&command=run iteration 1
[task 2021-07-13T03:03:39.695Z] 03:03:39    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2021-07-13T03:03:39.717Z] 03:03:39     INFO -  raptor-browsertime Info: b'    at Object.throwDecodedError (/home/cltbld/tasks/task_162614532800716/fetches/browsertime/node_modules/selenium-webdriver/lib/error.js:517:15)'
[task 2021-07-13T03:03:39.717Z] 03:03:39     INFO -  raptor-browsertime Info: b'    at parseHttpResponse (/home/cltbld/tasks/task_162614532800716/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:655:13)'
[task 2021-07-13T03:03:39.717Z] 03:03:39     INFO -  raptor-browsertime Info: b'    at Executor.execute (/home/cltbld/tasks/task_162614532800716/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:581:28)'
[task 2021-07-13T03:03:39.718Z] 03:03:39     INFO -  raptor-browsertime Info: b'    at processTicksAndRejections (internal/process/task_queues.js:97:5)'
[task 2021-07-13T03:03:39.718Z] 03:03:39     INFO -  raptor-browsertime Info: b'    at async Driver.execute (/home/cltbld/tasks/task_162614532800716/fetches/browsertime/node_modules/selenium-webdriver/lib/webdriver.js:724:17)'
[task 2021-07-13T03:03:39.719Z] 03:03:39     INFO -  raptor-browsertime Info: URL failed to load, trying 5 more time(s): Failed waiting on page https://yttest.prod.mozaws.net/2020/main.html?test_type=playbackperf-sfr-h264-test&raptor=true&exclude=1,2&muted=true&command=run  to finished loading, timed out after 300000 ms
[task 2021-07-13T03:03:39.719Z] 03:03:39 CRITICAL -  raptor-browsertime Critical: Failed waiting on page https://yttest.prod.mozaws.net/2020/main.html?test_type=playbackperf-sfr-h264-test&raptor=true&exclude=1,2&muted=true&command=run to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2021-07-13T03:03:39.719Z] 03:03:39     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmpqg19rd2x
[task 2021-07-13T03:03:39.725Z] 03:03:39    ERROR -  Traceback (most recent call last):
[task 2021-07-13T03:03:39.725Z] 03:03:39     INFO -    File "/home/cltbld/tasks/task_162614532800716/build/tests/raptor/raptor/raptor.py", line 213, in <module>
[task 2021-07-13T03:03:39.725Z] 03:03:39     INFO -      main()
[task 2021-07-13T03:03:39.726Z] 03:03:39     INFO -    File "/home/cltbld/tasks/task_162614532800716/build/tests/raptor/raptor/raptor.py", line 159, in main
[task 2021-07-13T03:03:39.726Z] 03:03:39     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2021-07-13T03:03:39.726Z] 03:03:39     INFO -    File "/home/cltbld/tasks/task_162614532800716/build/tests/raptor/raptor/perftest.py", line 456, in run_tests
[task 2021-07-13T03:03:39.726Z] 03:03:39     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2021-07-13T03:03:39.727Z] 03:03:39     INFO -    File "/home/cltbld/tasks/task_162614532800716/build/tests/raptor/raptor/browsertime/base.py", line 502, in run_test
[task 2021-07-13T03:03:39.727Z] 03:03:39     INFO -      raise Exception(self.browsertime_failure)
[task 2021-07-13T03:03:39.727Z] 03:03:39     INFO -  Exception: Failed waiting on page https://yttest.prod.mozaws.net/2020/main.html?test_type=playbackperf-sfr-h264-test&raptor=true&exclude=1,2&muted=true&command=run to finished loading, timed out after 300000 ms WebDriverError: Failed to decode response from marionette
[task 2021-07-13T03:03:39.788Z] 03:03:39    ERROR - Return code: 1

There are also these cnn failures.

[task 2021-07-13T04:28:42.774Z] 04:28:42     INFO -  raptor-browsertime Info: Starting a browsertime pageload
[task 2021-07-13T04:28:42.775Z] 04:28:42     INFO -  raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2021-07-13T04:28:43.777Z] 04:28:43     INFO -  raptor-browsertime Info: Navigating to about:blank
[task 2021-07-13T04:28:43.777Z] 04:28:43     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 1
[task 2021-07-13T04:28:48.836Z] 04:28:48     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2021-07-13T04:28:49.838Z] 04:28:49     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2021-07-13T04:28:49.839Z] 04:28:49     INFO -  raptor-browsertime Info: Testing url https://www.cnn.com/2021/03/22/weather/climate-change-warm-waters-lake-michigan/index.html iteration 1
[task 2021-07-13T04:28:49.842Z] 04:28:49     INFO -  raptor-browsertime Info: Start firefox window recorder.
[task 2021-07-13T04:28:55.347Z] 04:28:55    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2021-07-13T04:28:55.367Z] 04:28:55     INFO -  raptor-browsertime Info: b'    at Object.throwDecodedError (/home/cltbld/tasks/task_162614619012189/fetches/browsertime/node_modules/selenium-webdriver/lib/error.js:517:15)'
[task 2021-07-13T04:28:55.367Z] 04:28:55     INFO -  raptor-browsertime Info: b'    at parseHttpResponse (/home/cltbld/tasks/task_162614619012189/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:655:13)'
[task 2021-07-13T04:28:55.368Z] 04:28:55     INFO -  raptor-browsertime Info: b'    at Executor.execute (/home/cltbld/tasks/task_162614619012189/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:581:28)'
[task 2021-07-13T04:28:55.368Z] 04:28:55     INFO -  raptor-browsertime Info: b'    at processTicksAndRejections (internal/process/task_queues.js:97:5)'
[task 2021-07-13T04:28:55.369Z] 04:28:55     INFO -  raptor-browsertime Info: b'    at async Driver.execute (/home/cltbld/tasks/task_162614619012189/fetches/browsertime/node_modules/selenium-webdriver/lib/webdriver.js:724:17)'
[task 2021-07-13T04:28:55.369Z] 04:28:55     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-07-13T04:28:55.370Z] 04:28:55 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-07-13T04:28:55.370Z] 04:28:55     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmpkm0gaym9
[task 2021-07-13T04:28:55.376Z] 04:28:55    ERROR -  Traceback (most recent call last):
[task 2021-07-13T04:28:55.376Z] 04:28:55     INFO -    File "/home/cltbld/tasks/task_162614619012189/build/tests/raptor/raptor/raptor.py", line 213, in <module>
[task 2021-07-13T04:28:55.376Z] 04:28:55     INFO -      main()
[task 2021-07-13T04:28:55.376Z] 04:28:55     INFO -    File "/home/cltbld/tasks/task_162614619012189/build/tests/raptor/raptor/raptor.py", line 159, in main
[task 2021-07-13T04:28:55.376Z] 04:28:55     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2021-07-13T04:28:55.377Z] 04:28:55     INFO -    File "/home/cltbld/tasks/task_162614619012189/build/tests/raptor/raptor/perftest.py", line 456, in run_tests
[task 2021-07-13T04:28:55.377Z] 04:28:55     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2021-07-13T04:28:55.377Z] 04:28:55     INFO -    File "/home/cltbld/tasks/task_162614619012189/build/tests/raptor/raptor/browsertime/base.py", line 502, in run_test
[task 2021-07-13T04:28:55.377Z] 04:28:55     INFO -      raise Exception(self.browsertime_failure)
[task 2021-07-13T04:28:55.377Z] 04:28:55     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-07-13T04:28:55.438Z] 04:28:55    ERROR - Return code: 1
[task 2021-07-13T04:28:55.438Z] 04:28:55  WARNING - setting return code to 1
[task 2021-07-13T04:28:55.438Z] 04:28:55     INFO - Copying Raptor results to upload dir:
[task 2021-07-13T04:28:55.438Z] 04:28:55     INFO - /home/cltbld/tasks/task_162614619012189/build/blobber_upload_dir/perfherder-data.json
[task 2021-07-13T04:28:55.438Z] 04:28:55     INFO - Copying raptor results from /home/cltbld/tasks/task_162614619012189/build/raptor.json to /home/cltbld/tasks/task_162614619012189/build/blobber_upload_dir/perfherder-data.json
[task 2021-07-13T04:28:55.438Z] 04:28:55 CRITICAL - Error copying results /home/cltbld/tasks/task_162614619012189/build/raptor.json to upload dir /home/cltbld/tasks/task_162614619012189/build/blobber_upload_dir/perfherder-data.json
[task 2021-07-13T04:28:55.438Z] 04:28:55     INFO - [Errno 2] No such file or directory: '/home/cltbld/tasks/task_162614619012189/build/raptor.json'
[task 2021-07-13T04:28:55.439Z] 04:28:55     INFO - Running post-action listener: _package_coverage_data
[task 2021-07-13T04:28:55.439Z] 04:28:55     INFO - Running post-action listener: _resource_record_post_action
[task 2021-07-13T04:28:55.439Z] 04:28:55     INFO - Running post-action listener: process_java_coverage_data
[task 2021-07-13T04:28:55.439Z] 04:28:55     INFO - Running post-action listener: stop_device
[task 2021-07-13T04:28:55.439Z] 04:28:55     INFO - [mozharness: 2021-07-13 04:28:55.439540Z] Finished run-tests step (success)
[task 2021-07-13T04:28:55.439Z] 04:28:55     INFO - Running post-run listener: _resource_record_post_run
[task 2021-07-13T04:28:55.484Z] 04:28:55     INFO - Total resource usage - Wall time: 55s; CPU: 4%; Read bytes: 13582336; Write bytes: 1423958016; Read time: 6856; Write time: 91924
[task 2021-07-13T04:28:55.484Z] 04:28:55     INFO - TinderboxPrint: CPU usage<br/>4.0%
[task 2021-07-13T04:28:55.484Z] 04:28:55     INFO - TinderboxPrint: I/O read bytes / time<br/>13,582,336 / 6,856
[task 2021-07-13T04:28:55.484Z] 04:28:55     INFO - TinderboxPrint: I/O write bytes / time<br/>1,423,958,016 / 91,924
[task 2021-07-13T04:28:55.484Z] 04:28:55     INFO - TinderboxPrint: CPU idle<br/>419.7 (95.3%)
[task 2021-07-13T04:28:55.484Z] 04:28:55     INFO - TinderboxPrint: CPU user<br/>15.0 (3.4%)
[task 2021-07-13T04:28:55.484Z] 04:28:55     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2021-07-13T04:28:55.484Z] 04:28:55     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 2021-07-13T04:28:55.485Z] 04:28:55     INFO - install - Wall time: 7s; CPU: 13%; Read bytes: 24576; Write bytes: 715640832; Read time: 40; Write time: 61356
[task 2021-07-13T04:28:55.485Z] 04:28:55     INFO - run-tests - Wall time: 48s; CPU: 3%; Read bytes: 10592256; Write bytes: 646811648; Read time: 6784; Write time: 8980
[task 2021-07-13T04:28:55.496Z] 04:28:55  WARNING - returning nonzero exit status 1

These are the only Btime-live tasks on beta which are in tier 2. The other ones are in tier 3 and also fail permanently.

Andi, can you take a look or redirect to :sparky?

Flags: needinfo?(bpostelnicu)

This should be closed since we no longer run this on beta, only on m-c.

Status: NEW → RESOLVED
Closed: 4 years ago
Flags: needinfo?(bpostelnicu)
Resolution: --- → WORKSFORME
Status: RESOLVED → REOPENED
status-firefox90: --- → unaffected
status-firefox91: --- → affected
status-firefox92: --- → fixed
status-firefox-esr78: --- → unaffected
Depends on: 1718230
Resolution: WORKSFORME → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago → 4 years ago
status-firefox91: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → 91 Branch
You need to log in before you can comment on or make changes to this bug.