High Frequency unity-webgl raptor-perftest Critical: Test failed to finish. Application timed out after 520 seconds
Categories
(Testing :: Raptor, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Regression)
Details
(Keywords: intermittent-failure)
Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=312305484&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JL6slEeKSoKRbfQM1TWEww/runs/0/artifacts/public/logs/live_backing.log
[task 2020-08-06T20:13:47.821Z] 20:12:38 INFO - raptor-control-server Info: received webext_raptor-page-timeout: [u'raptor-unity-webgl-geckoview', u'http://127.0.0.1:38529/unity-webgl/index.html?raptor', 1]
[task 2020-08-06T20:13:47.821Z] 20:12:38 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:40 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:42 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:44 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:46 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:48 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:50 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:52 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:54 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:56 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:12:58 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:00 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:02 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:04 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:06 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:08 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:10 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:12 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:14 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:16 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:18 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:20 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:22 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:24 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:26 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:28 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:30 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:32 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:34 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:36 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:38 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "pidof org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output: 8344
[task 2020-08-06T20:13:47.821Z] 20:13:41 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "am force-stop org.mozilla.geckoview_example", timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:13:47.821Z] 20:13:42 INFO - adb shell_bool: adb -s ZY32259STL wait-for-device shell su -c "test -d /data/local/tmp/test_root/raptor/profile/minidumps", timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:13:47.821Z] 20:13:43 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c sync, timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:13:47.821Z] 20:13:44 INFO - adb shell_bool: adb -s ZY32259STL wait-for-device shell su -c "test -d /data/local/tmp/test_root/raptor/profile/minidumps", timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:13:47.821Z] 20:13:44 INFO - adb chmod: path=/data/local/tmp/test_root/raptor/profile/minidumps, recursive=True, mask=777
[task 2020-08-06T20:13:47.821Z] 20:13:45 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "chmod -R 777 /data/local/tmp/test_root/raptor/profile/minidumps", timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:13:47.821Z] 20:13:45 INFO - adb command_output: adb -s ZY32259STL wait-for-device pull /data/local/tmp/test_root/raptor/profile/minidumps /tmp/tmpkdcdgF/minidumps, timeout: None, timedout: None, exitcode: 0, output: /data/local/tmp/test_root/raptor/profile/minidumps/: 0 files pulled, 0 skipped.
[task 2020-08-06T20:13:47.821Z] 20:13:45 CRITICAL - raptor-perftest Critical: Test failed to finish. Application timed out after 520 seconds
[task 2020-08-06T20:13:47.821Z] 20:13:45 INFO - raptor-webext-android Info: removing reverse socket connections
[task 2020-08-06T20:13:47.821Z] 20:13:45 INFO - adb command_output: adb -s ZY32259STL wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:13:47.821Z] 20:13:45 INFO - raptor-webext-android Info: skipping check_for_crashes: application has not been launched
[task 2020-08-06T20:13:47.821Z] 20:13:45 INFO - raptor-webext Info: removing webext /builds/task_159674300785960/workspace/build/tests/raptor/raptor/webextension/../../webext/raptor
[task 2020-08-06T20:13:47.821Z] 20:13:45 INFO - raptor-webext-android Info: removing test folder for raptor: /data/local/tmp/test_root/raptor
[task 2020-08-06T20:13:47.821Z] 20:13:46 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c sync, timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:14:23.833Z] 20:13:47 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c "rm -r /data/local/tmp/test_root/raptor", timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:14:23.833Z] 20:13:48 INFO - adb shell_output: adb -s ZY32259STL wait-for-device shell su -c sync, timeout: None, timedout: None, exitcode: 0, output:
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - adb shell_bool: adb -s ZY32259STL wait-for-device shell su -c "test -e /data/local/tmp/test_root/raptor", timeout: None, timedout: None, exitcode: 1, output:
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - raptor-control-server Info: shutting down control server
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - raptor-webext Info: finished
[task 2020-08-06T20:14:23.833Z] 20:13:49 ERROR - Return code: 1
[task 2020-08-06T20:14:23.833Z] 20:13:49 WARNING - setting return code to 1
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - Killing logcat pid 779.
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - Copying Raptor results to upload dir:
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - /builds/task_159674300785960/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - Copying raptor results from /builds/task_159674300785960/workspace/build/raptor.json to /builds/task_159674300785960/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2020-08-06T20:14:23.833Z] 20:13:49 CRITICAL - Error copying results /builds/task_159674300785960/workspace/build/raptor.json to upload dir /builds/task_159674300785960/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - [Errno 2] No such file or directory: u'/builds/task_159674300785960/workspace/build/raptor.json'
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - Running post-action listener: _package_coverage_data
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - Running post-action listener: _resource_record_post_action
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - Running post-action listener: process_java_coverage_data
[task 2020-08-06T20:14:23.833Z] 20:13:49 INFO - Running post-action listener: stop_device
[task 2020-08-06T20:14:23.833Z] 20:14:04 INFO - /data/anr/traces.txt deleted
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - Killing logcat pid 779.
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - [mozharness: 2020-08-06 20:14:17.487627Z] Finished run-tests step (success)
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - Running post-run listener: _resource_record_post_run
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - Total resource usage - Wall time: 695s; CPU: 1.0%; Read bytes: 0; Write bytes: 401223680; Read time: 0; Write time: 358020
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - TinderboxPrint: CPU usage<br/>0.8%
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - TinderboxPrint: I/O write bytes / time<br/>401,223,680 / 358,020
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - TinderboxPrint: CPU idle<br/>2,743.6 (99.0%)
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - install-chrome-android - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-08-06T20:14:23.833Z] 20:14:17 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 2020-08-06T20:14:23.833Z] 20:14:17 INFO - install - Wall time: 43s; CPU: 1.0%; Read bytes: 0; Write bytes: 295698432; Read time: 0; Write time: 292724
[task 2020-08-06T20:14:23.833Z] 20:14:17 INFO - run-tests - Wall time: 625s; CPU: 1.0%; Read bytes: 0; Write bytes: 103620608; Read time: 0; Write time: 65076
[task 2020-08-06T20:14:23.833Z] 20:14:17 WARNING - returning nonzero exit status 1
Comment 1•4 years ago
|
||
This started appearing on today's merge on central - nightly (August 6th):
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&group_state=expanded&resultStatus=testfailed%2Cbusted%2Cexception%2Csuccess%2Cusercancel%2Crunning%2Cpending%2Crunnable&searchStr=android%2C7.0%2Cmotog5%2Cshippable%2Copt%2Craptor%2Cperformance%2Ctests%2Con%2Cfirefox%2Ctest-android-hw-g5-7-0-arm7-api-16-shippable%2Fopt-raptor-unity-webgl-geckoview-e10s%2Cugl&fromchange=6e35e01646d7c465893a172a0b4fb116c2293d2a&tochange=af63ceb254223ee0868fb3ee05f17c50fd7938d4&selectedTaskRun=GcrK0CJCSI2-veQ8ub_1NQ.0
sparky, could you please take a look?
Bug 1657692 and Bug 1657686 started appearing on this push as well, they may be related.
Comment 2•4 years ago
|
||
Yup, looking into it now. Starting with some autoland backfills to see if we can find a root cause.
Comment 3•4 years ago
|
||
Fixed by backout of bug 1639153.
Updated•4 years ago
|
Comment hidden (Intermittent Failures Robot) |
Description
•