Closed Bug 1657730 Opened 4 years ago Closed 4 years ago

High Frequency unity-webgl raptor-perftest Critical: Test failed to finish. Application timed out after 520 seconds

Categories

(Testing :: Raptor, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED FIXED

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

Yup, looking into it now. Starting with some autoland backfills to see if we can find a root cause.

Fixed by backout of bug 1639153.

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Flags: needinfo?(gmierz2)
You need to log in before you can comment on or make changes to this bug.