Closed
Bug 1823588
Opened 2 years ago
Closed 2 years ago
Intermittent [Tier2] 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 120000 ms NoSuchSessionError: Tried to run command wit
Categories
(Testing :: Raptor, defect, P5)
Testing
Raptor
Tracking
(Not tracked)
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=409573485&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/QADqoMidQf2G4Hjn0gB-uQ/runs/0/artifacts/public/logs/live_backing.log
[task 2023-03-21T03:51:36.511Z] 03:51:36 INFO - raptor-perftest Info: starting test: cnn
[task 2023-03-21T03:51:36.514Z] 03:51:36 INFO - raptor-browsertime Info: test: {'here': '/home/cltbld/tasks/task_167936384595989/build/tests/raptor/raptor/tests/tp6/desktop', 'alert_on': ['ContentfulSpeedIndex', 'FirstVisualChange', 'LastVisualChange', 'PerceptualSpeedIndex', 'SpeedIndex', 'fcp', 'loadtime'], 'alert_threshold': '2.0', 'apps': 'firefox, chrome, chromium, safari', 'browser_cycles': 5, 'lower_is_better': True, 'owner': 'PerfTest Team', 'page_cycles': 2, 'page_timeout': 72000.0, 'playback': None, 'playback_pageset_manifest': 'mitm7-linux-firefox-{subtest}.manifest', 'playback_version': '8.1.1', 'type': 'pageload', 'unit': 'ms', 'use_live_sites': 'true', 'secondary_url': 'https://www.cnn.com/weather', 'test_url': 'https://www.cnn.com/2021/03/22/weather/climate-change-warm-waters-lake-michigan/index.html', 'name': 'cnn', 'manifest': '/home/cltbld/tasks/task_167936384595989/build/tests/raptor/raptor/tests/tp6/desktop/browsertime-tp6.ini', 'manifest_relpath': 'tests/tp6/desktop/browsertime-tp6.ini', 'path': '/home/cltbld/tasks/task_167936384595989/build/tests/raptor/raptor/tests/tp6/desktop/cnn', 'relpath': 'tests/tp6/desktop/cnn', 'ancestor_manifest': 'raptor.ini', 'expected': 'pass', 'extra_profiler_run': True, 'extra_profiler_run_browser_cycles': 1, 'extra_profiler_run_page_cycles': 2, 'cold': True, 'expected_browser_cycles': 5, 'browser_cycle': 1, 'measure': ['fnbpaint', 'fcp', 'dcf', 'loadtime', 'ContentfulSpeedIndex', 'PerceptualSpeedIndex', 'SpeedIndex', 'FirstVisualChange', 'LastVisualChange']}
[task 2023-03-21T03:51:36.514Z] 03:51:36 INFO - raptor-browsertime-desktop Info: binary_path: /home/cltbld/tasks/task_167936384595989/build/application/firefox/firefox
[task 2023-03-21T03:51:36.515Z] 03:51:36 INFO - raptor-browsertime Info: Using Firefox Window Recorder for videos
[task 2023-03-21T03:51:36.515Z] 03:51:36 INFO - raptor-browsertime Info: timeout (s): 72000
[task 2023-03-21T03:51:36.515Z] 03:51:36 INFO - raptor-browsertime Info: browsertime cwd: /home/cltbld/tasks/task_167936384595989/build
[task 2023-03-21T03:51:36.518Z] 03:51:36 INFO - raptor-browsertime Info: browsertime cmd: /home/cltbld/tasks/task_167936384595989/fetches/node/bin/node /home/cltbld/tasks/task_167936384595989/fetches/browsertime/node_modules/browsertime/bin/browsertime.js --firefox.geckodriverPath /home/cltbld/tasks/task_167936384595989/fetches/geckodriver /home/cltbld/tasks/task_167936384595989/build/tests/raptor/raptor/browsertime/../../browsertime/browsertime_pageload.js --firefox.noDefaultPrefs --browsertime.page_cycle_delay 5000 --skipHar --pageLoadStrategy none --webdriverPageload true --firefox.disableBrowsertimeExtension true --pageCompleteCheckStartWait 5000 --pageCompleteCheckPollTimeout 1000 --timeouts.pageLoad 72000 --timeouts.script 144000 --browsertime.page_cycles 2 --pageCompleteWaitTime 5000 --browsertime.url https://www.cnn.com/2021/03/22/weather/climate-change-warm-waters-lake-michigan/index.html --browsertime.post_startup_delay 1000 --iterations 5 --videoParams.androidVideoWaitTime 20000 --browsertime.chimera true --browsertime.test_bytecode_cache false --firefox.perfStats false --browsertime.secondary_url https://www.cnn.com/weather --browsertime.commands --viewPort 1280x1024 --browser firefox --firefox.binaryPath /home/cltbld/tasks/task_167936384595989/build/application/firefox/firefox --resultDir /home/cltbld/tasks/task_167936384595989/build/blobber_upload_dir/browsertime-results/cnn --firefox.profileTemplate /tmp/tmp5zf3zz1w/profile --video true --visualMetrics true --visualMetricsContentful true --visualMetricsPerceptual true --visualMetricsPortable true --videoParams.keepOriginalVideo true --firefox.windowRecorder true --browsertime.testName cnn --browsertime.liveSite True --browsertime.loginRequired False
[task 2023-03-21T03:51:36.519Z] 03:51:36 INFO - raptor-browsertime Info: browsertime_ffmpeg: /home/cltbld/tasks/task_167936384595989/fetches/ffmpeg-4.4.1-i686-static/ffmpeg
[task 2023-03-21T03:51:36.519Z] 03:51:36 INFO - raptor-browsertime Info: PATH: b'/home/cltbld/tasks/task_167936384595989/fetches/ffmpeg-4.4.1-i686-static:/home/cltbld/tasks/task_167936384595989/build/venv/bin:/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/bin'
[task 2023-03-21T03:51:36.519Z] 03:51:36 INFO - raptor-browsertime Info: Calling browsertime with proc_timeout=2250, and output_timeout=240
[task 2023-03-21T03:51:37.225Z] 03:51:37 INFO - raptor-browsertime Info: Running tests using Firefox - 5 iteration(s)
[task 2023-03-21T03:51:37.250Z] 03:51:37 INFO - raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2023-03-21T03:51:39.979Z] 03:51:39 INFO - raptor-browsertime Info: Starting a browsertime pageload
[task 2023-03-21T03:51:39.979Z] 03:51:39 INFO - raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2023-03-21T03:51:40.982Z] 03:51:40 INFO - raptor-browsertime Info: Navigating to about:blank, count: 0
[task 2023-03-21T03:51:40.982Z] 03:51:40 INFO - raptor-browsertime Info: Navigating to url about:blank iteration 1
[task 2023-03-21T03:51:46.041Z] 03:51:46 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 2023-03-21T03:51:46.042Z] 03:51:46 INFO - raptor-browsertime Info: Cycle 0, waiting for 5000 ms
[task 2023-03-21T03:51:51.042Z] 03:51:51 INFO - raptor-browsertime Info: Cycle 0, starting the measure
[task 2023-03-21T03:51:51.044Z] 03:51:51 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 2023-03-21T03:51:51.045Z] 03:51:51 INFO - raptor-browsertime Info: Start firefox window recorder.
[task 2023-03-21T03:54:14.318Z] 03:54:13 INFO - raptor-browsertime Info: The page did not finished loading in 120000 ms. You can adjust the timeout by setting the --maxLoadTime option (in ms).
[task 2023-03-21T03:57:05.849Z] 03:57:05 INFO - raptor-browsertime Info: URL failed to load, trying 5 more time(s): Failed to decode response from marionette
[task 2023-03-21T03:57:06.868Z] 03:57:06 ERROR - raptor-browsertime Error: Browsertime failed to run
[task 2023-03-21T03:57:06.888Z] 03:57:06 INFO - raptor-browsertime Info: at Object.throwDecodedError (/home/cltbld/tasks/task_167936384595989/fetches/browsertime/node_modules/selenium-webdriver/lib/error.js:524:15)
[task 2023-03-21T03:57:06.889Z] 03:57:06 INFO - raptor-browsertime Info: at parseHttpResponse (/home/cltbld/tasks/task_167936384595989/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:587:13)
[task 2023-03-21T03:57:06.889Z] 03:57:06 INFO - raptor-browsertime Info: at Executor.execute (/home/cltbld/tasks/task_167936384595989/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:515:28)
[task 2023-03-21T03:57:06.890Z] 03:57:06 INFO - raptor-browsertime Info: at processTicksAndRejections (node:internal/process/task_queues:96:5)
[task 2023-03-21T03:57:06.890Z] 03:57:06 INFO - raptor-browsertime Info: at async Driver.execute (/home/cltbld/tasks/task_167936384595989/fetches/browsertime/node_modules/selenium-webdriver/lib/webdriver.js:742:17)
[task 2023-03-21T03:57:06.891Z] 03:57:06 INFO - raptor-browsertime Info: URL failed to load, trying 4 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 120000 ms
[task 2023-03-21T03:57:06.892Z] 03:57:06 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 120000 ms NoSuchSessionError: Tried to run command without establishing a connection
[task 2023-03-21T03:57:06.892Z] 03:57:06 INFO - raptor-perftest Info: Removing temporary directory: /tmp/tmp5zf3zz1w
[task 2023-03-21T03:57:06.922Z] 03:57:06 ERROR - Traceback (most recent call last):
[task 2023-03-21T03:57:06.924Z] 03:57:06 INFO - File "/home/cltbld/tasks/task_167936384595989/build/tests/raptor/raptor/raptor.py", line 204, in <module>
[task 2023-03-21T03:57:06.924Z] 03:57:06 INFO - main()
[task 2023-03-21T03:57:06.925Z] 03:57:06 INFO - File "/home/cltbld/tasks/task_167936384595989/build/tests/raptor/raptor/raptor.py", line 150, in main
[task 2023-03-21T03:57:06.926Z] 03:57:06 INFO - success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2023-03-21T03:57:06.928Z] 03:57:06 INFO - File "/home/cltbld/tasks/task_167936384595989/build/tests/raptor/raptor/perftest.py", line 469, in run_tests
[task 2023-03-21T03:57:06.929Z] 03:57:06 INFO - self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2023-03-21T03:57:06.930Z] 03:57:06 INFO - File "/home/cltbld/tasks/task_167936384595989/build/tests/raptor/raptor/browsertime/base.py", line 811, in run_test
[task 2023-03-21T03:57:06.931Z] 03:57:06 INFO - raise Exception(self.browsertime_failure)
[task 2023-03-21T03:57:06.933Z] 03:57:06 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 120000 ms NoSuchSessionError: Tried to run command without establishing a connection
[task 2023-03-21T03:57:07.034Z] 03:57:07 INFO - Return code: 1
[task 2023-03-21T03:57:07.035Z] 03:57:07 WARNING - setting return code to 1
[task 2023-03-21T03:57:07.035Z] 03:57:07 INFO - Copying Raptor results to upload dir:
[task 2023-03-21T03:57:07.035Z] 03:57:07 INFO - /home/cltbld/tasks/task_167936384595989/build/blobber_upload_dir/perfherder-data.json
[task 2023-03-21T03:57:07.035Z] 03:57:07 INFO - Copying raptor results from /home/cltbld/tasks/task_167936384595989/build/raptor.json to /home/cltbld/tasks/task_167936384595989/build/blobber_upload_dir/perfherder-data.json
[task 2023-03-21T03:57:07.035Z] 03:57:07 CRITICAL - Error copying results /home/cltbld/tasks/task_167936384595989/build/raptor.json to upload dir /home/cltbld/tasks/task_167936384595989/build/blobber_upload_dir/perfherder-data.json
[task 2023-03-21T03:57:07.035Z] 03:57:07 INFO - [Errno 2] No such file or directory: '/home/cltbld/tasks/task_167936384595989/build/raptor.json'
[task 2023-03-21T03:57:07.037Z] 03:57:07 INFO - Running post-action listener: _package_coverage_data
[task 2023-03-21T03:57:07.037Z] 03:57:07 INFO - Running post-action listener: _resource_record_post_action
[task 2023-03-21T03:57:07.037Z] 03:57:07 INFO - Running post-action listener: process_java_coverage_data
[task 2023-03-21T03:57:07.037Z] 03:57:07 INFO - Running post-action listener: stop_device
[task 2023-03-21T03:57:07.038Z] 03:57:07 INFO - [mozharness: 2023-03-21 03:57:07.038024Z] Finished run-tests step (success)
[task 2023-03-21T03:57:07.038Z] 03:57:07 INFO - Running post-run listener: _resource_record_post_run
[task 2023-03-21T03:57:07.166Z] 03:57:07 INFO - Total resource usage - Wall time: 373s; CPU: 28%; Read bytes: 601289105408; Write bytes: 3244056576; Read time: 8599216; Write time: 2046916
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•