Closed Bug 1559679 Opened 7 years ago Closed 6 years ago

Intermittent raptor-main Critical: TEST-UNEXPECTED-FAIL: test 'raptor-tp6m-aframeio-animation-geckoview' timed out loading test page: https://aframe.io/examples/showcase/animation pending metrics: fcp, fnb paint, dcf, load time

Categories

(Testing :: Raptor, defect, P5)

Product:
Testing
Component:
Raptor
Version:
Version 3
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 1571245

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, regression)

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=252090496&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/KY1wBouJRtK2yVHm2eeZ_w/runs/0/artifacts/public/logs/live_backing.log

10:50:27 INFO - raptor-results-handler Info: summarizing raptor test results
10:50:27 INFO - raptor-output Info: ignoring the first dcf value due to initial pageload noise
10:50:27 INFO - raptor-output Info: ignoring the first fcp value due to initial pageload noise
10:50:27 INFO - raptor-output Info: turning on subtest alerting for measurement type: fcp
10:50:27 INFO - raptor-output Info: ignoring the first fnbpaint value due to initial pageload noise
10:50:27 INFO - raptor-output Info: ignoring the first loadtime value due to initial pageload noise
10:50:27 INFO - raptor-output Info: turning on subtest alerting for measurement type: loadtime
10:50:27 INFO - raptor-output Info: PERFHERDER_DATA: {"framework": {"name": "raptor"}, "suites": [{"extraOptions": [], "name": "raptor-tp6m-aframeio-animation-geckoview", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1966.65, "subtests": [{"name": "dcf", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1237.0, "replicates": [846, 10371, 13292, 733, 16827, 747, 20247, 903, 20816, 1443, 985, 1031, 923, 963, 37825], "unit": "ms"}, {"name": "fcp", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1271.0, "shouldAlert": true, "replicates": [777, 10415, 13327, 598, 16941, 616, 20111, 938, 20852, 1477, 848, 1065, 986, 1029, 37891], "unit": "ms"}, {"name": "fnbpaint", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 1216.0, "replicates": [680, 10350, 13272, 546, 16886, 559, 20060, 881, 20794, 1422, 796, 1010, 934, 972, 37836], "unit": "ms"}, {"name": "loadtime", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 7820.5, "shouldAlert": true, "replicates": [4544, 14856, 21063, 4762, 23673, 4671, 24326, 4882, 32356, 4775, 4689, 10759, 4550, 4556, 41371], "unit": "ms"}], "type": "pageload", "unit": "ms"}]}
10:50:27 INFO - raptor-output Info: results can also be found locally at: /builds/task_1560681637/workspace/build/raptor.json
10:50:27 INFO - raptor-main Info: removing test folder for raptor: /sdcard/raptor
10:50:27 INFO - adb shell_output: adb -s ZY3222CFLM wait-for-device shell rm -r /sdcard/raptor; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output:
10:50:27 INFO - raptor-control-server Info: shutting down control server
10:50:28 INFO - raptor-main Info: finished
10:50:28 ERROR - raptor-main Critical: TEST-UNEXPECTED-FAIL: test 'raptor-tp6m-aframeio-animation-geckoview' timed out loading test page: https://aframe.io/examples/showcase/animation pending metrics: fcp, fnb paint, dcf, load time
10:50:28 ERROR - Return code: 1
10:50:28 WARNING - setting return code to 1
10:50:28 INFO - Killing logcat pid 494.
10:50:28 INFO - Validating PERFHERDER_DATA against /builds/task_1560681637/workspace/mozharness/external_tools/performance-artifact-schema.json
10:50:28 INFO - copying raptor results to upload dir:
10:50:28 INFO - /builds/task_1560681637/workspace/build/blobber_upload_dir/perfherder-data.json
10:50:28 INFO - copying raptor results from /builds/task_1560681637/workspace/build/raptor.json to /builds/task_1560681637/workspace/build/blobber_upload_dir/perfherder-data.json
10:50:28 INFO - Running post-action listener: _package_coverage_data
10:50:28 INFO - Running post-action listener: _resource_record_post_action
10:50:28 INFO - Running post-action listener: process_java_coverage_data
10:50:28 INFO - Running post-action listener: stop_device
10:50:34 INFO - /data/anr/traces.txt deleted
10:50:40 INFO - /data/tombstones/dsps deleted
10:50:42 INFO - /data/tombstones/lpass deleted
10:50:44 INFO - /data/tombstones/modem deleted
10:50:46 INFO - /data/tombstones/wcnss deleted
10:50:46 INFO - Killing logcat pid 494.
10:50:46 INFO - [mozharness: 2019-06-16 10:50:46.348591Z] Finished run-tests step (success)
10:50:46 INFO - Running post-run listener: _resource_record_post_run
10:50:46 INFO - Total resource usage - Wall time: 553s; CPU: 10.0%; Read bytes: 53248; Write bytes: 3184975872; Read time: 132; Write time: 2476564
10:50:46 INFO - TinderboxPrint: CPU usage<br/>10.3%
10:50:46 INFO - TinderboxPrint: I/O read bytes / time<br/>53,248 / 132
10:50:46 INFO - TinderboxPrint: I/O write bytes / time<br/>3,184,975,872 / 2,476,564
10:50:46 INFO - TinderboxPrint: CPU idle<br/>1,936.2 (88.4%)
10:50:46 INFO - TinderboxPrint: CPU iowait<br/>27.6 (1.3%)
10:50:46 INFO - TinderboxPrint: CPU system<br/>66.3 (3.0%)
10:50:46 INFO - TinderboxPrint: CPU user<br/>153.9 (7.0%)
10:50:46 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
10:50:46 INFO - install - Wall time: 13s; CPU: 9.0%; Read bytes: 0; Write bytes: 334372864; Read time: 0; Write time: 303400
10:50:46 INFO - run-tests - Wall time: 523s; CPU: 10.0%; Read bytes: 53248; Write bytes: 2592059392; Read time: 132; Write time: 1987164
10:50:46 WARNING - returning nonzero exit status 1

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE

This is still happening.

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

[task 2020-03-02T21:58:56.034Z] 21:57:39     INFO -  raptor-control-server Info: received webext_status: update tab: 0
[task 2020-03-02T21:58:56.034Z] 21:57:39     INFO -  raptor-control-server Info: received webext_status: test tab updated: 0
[task 2020-03-02T21:58:56.034Z] 21:58:52     INFO -  raptor-control-server Info: received webext_raptor-page-timeout: [u'raptor-tp6m-aframeio-animation-geckoview', u'https://aframe.io/examples/showcase/animation/', {u'fcp': True, u'hero': False, u'dcf': False, u'fnb paint': True, u'ttfi': False, u'load time': False}]
[task 2020-03-02T21:58:56.034Z] 21:58:52     INFO -  raptor-control-server Info: received webext_screenshot
[task 2020-03-02T21:58:56.034Z] 21:58:52     INFO -  perftest-results-handler Info: received screenshot
[task 2020-03-02T21:58:56.034Z] 21:58:52     INFO -  raptor-control-server Info: received request to shutdown the browser
[task 2020-03-02T21:58:56.034Z] 21:58:52     INFO -  raptor-control-server Info: shutting down android app org.mozilla.geckoview_example
[task 2020-03-02T21:58:56.034Z] 21:58:53     INFO -  adb shell_output: adb -s ZY322MQ8RN wait-for-device shell am force-stop org.mozilla.geckoview_example, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2020-03-02T21:58:56.034Z] 21:58:54     INFO -  raptor-webext-android Info: removing reverse socket connections
[task 2020-03-02T21:58:56.034Z] 21:58:54     INFO -  adb command_output: adb -s ZY322MQ8RN wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
[task 2020-03-02T21:58:56.034Z] 21:58:54     INFO -  adb shell_bool: adb -s ZY322MQ8RN wait-for-device shell test -d /sdcard/raptor/profile/minidumps, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2020-03-02T21:58:56.034Z] 21:58:54     INFO -  adb shell_output: adb -s ZY322MQ8RN wait-for-device shell sync, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2020-03-02T21:58:56.034Z] 21:58:54     INFO -  adb shell_bool: adb -s ZY322MQ8RN wait-for-device shell test -d /sdcard/raptor/profile/minidumps, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2020-03-02T21:58:56.034Z] 21:58:54     INFO -  adb command_output: adb -s ZY322MQ8RN wait-for-device pull /sdcard/raptor/profile/minidumps /tmp/tmpa_gHKL/minidumps, timeout: None, timedout: None, exitcode: 0, output: /sdcard/raptor/profile/minidumps/: 0 files pulled, 0 skipped.
[task 2020-03-02T21:58:56.034Z] 21:58:54     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 825
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  raptor-webext Info: removing webext /builds/task_1583185803/workspace/build/tests/raptor/raptor/webextension/../../webext/raptor
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  perftest-results-handler Info: summarizing raptor test results
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  perftest-output Error: no raptor test results found for raptor-tp6m-aframeio-animation-geckoview
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  perftest-output Info: error: no raptor test results found, so no need to combine browser cycles
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  perftest-output Error: no summarized raptor results found for raptor-tp6m-aframeio-animation-geckoview
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  perftest-output Info: screen captures can be found locally at: /builds/task_1583185803/workspace/build/screenshots.html
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  perftest-results-handler Critical: PERFHERDER_DATA was seen 0 times, expected 1.
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  raptor-webext-android Info: removing test folder for raptor: /sdcard/raptor
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  adb shell_output: adb -s ZY322MQ8RN wait-for-device shell sync, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  adb shell_output: adb -s ZY322MQ8RN wait-for-device shell rm -r /sdcard/raptor, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  adb shell_output: adb -s ZY322MQ8RN wait-for-device shell sync, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  adb shell_bool: adb -s ZY322MQ8RN wait-for-device shell test -e /sdcard/raptor, timeout: None, root: False, timedout: None, exitcode: 1, output:
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  raptor-control-server Info: shutting down control server
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO -  raptor-webext Info: finished
[task 2020-03-02T21:58:56.034Z] 21:58:55    ERROR -  raptor-main Critical: TEST-UNEXPECTED-FAIL: test 'raptor-tp6m-aframeio-animation-geckoview' timed out loading test page: https://aframe.io/examples/showcase/animation/ pending metrics: fcp, fnb paint
[task 2020-03-02T21:58:56.034Z] 21:58:55    ERROR - Return code: 1
[task 2020-03-02T21:58:56.034Z] 21:58:55  WARNING - setting return code to 1
[task 2020-03-02T21:58:56.034Z] 21:58:55     INFO - Killing logcat pid 598.
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 7 years ago → 6 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.