Closed Bug 1527404 Opened 6 years ago Closed 6 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/components/telemetry/tests/unit/test_TelemetryController.js | Test timed out

Categories

(Toolkit :: Telemetry, defect, P5)

Product:
Toolkit
Component:
Telemetry
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, regression)

#[markdown(off)]
Filed by: rmaries [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=227980109&repo=mozilla-central

https://queue.taskcluster.net/v1/task/GpT0WacUSDSLogm5oLtm3g/runs/0/artifacts/public/logs/live_backing.log

[task 2019-02-12T18:21:16.904Z] 18:21:16 INFO - TEST-START | toolkit/components/telemetry/tests/unit/test_TelemetryController.js
[task 2019-02-12T18:21:50.711Z] 18:21:50 INFO - TEST-PASS | toolkit/components/telemetry/tests/unit/test_TelemetryController.js | took 33807ms
[task 2019-02-12T18:21:51.337Z] 18:21:51 INFO - adb Ignoring attempt to chmod external storage
[task 2019-02-12T18:21:51.857Z] 18:21:51 INFO - adb Ignoring attempt to chmod external storage
[task 2019-02-12T18:21:52.172Z] 18:21:52 INFO - adb Ignoring attempt to chmod external storage
[task 2019-02-12T18:21:52.276Z] 18:21:52 INFO - adb Ignoring attempt to chmod external storage
[task 2019-02-12T18:21:52.277Z] 18:21:52 INFO - TEST-START | toolkit/components/telemetry/tests/unit/test_TelemetryController.js
[task 2019-02-12T18:26:52.278Z] 18:26:52 WARNING - TEST-UNEXPECTED-TIMEOUT | toolkit/components/telemetry/tests/unit/test_TelemetryController.js | Test timed out
[task 2019-02-12T18:26:52.278Z] 18:26:52 INFO - TEST-INFO took 300001ms
[task 2019-02-12T18:27:15.604Z] 18:27:15 INFO - Following exceptions were raised:
[task 2019-02-12T18:27:15.605Z] 18:27:15 INFO - Traceback (most recent call last):
[task 2019-02-12T18:27:15.605Z] 18:27:15 INFO - File "/builds/worker/workspace/build/tests/xpcshell/runxpcshelltests.py", line 185, in run
[task 2019-02-12T18:27:15.605Z] 18:27:15 INFO - self.run_test()
[task 2019-02-12T18:27:15.606Z] 18:27:15 INFO - File "/builds/worker/workspace/build/tests/xpcshell/runxpcshelltests.py", line 702, in run_test
[task 2019-02-12T18:27:15.606Z] 18:27:15 INFO - timeout=testTimeoutInterval)
[task 2019-02-12T18:27:15.607Z] 18:27:15 INFO - File "/builds/worker/workspace/build/tests/xpcshell/remotexpcshelltests.py", line 171, in launchProcess
[task 2019-02-12T18:27:15.607Z] 18:27:15 INFO - self.device.pkill("xpcshell")
[task 2019-02-12T18:27:15.608Z] 18:27:15 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb.py", line 2453, in pkill
[task 2019-02-12T18:27:15.608Z] 18:27:15 INFO - pids = self._pidof(appname, timeout=timeout)
[task 2019-02-12T18:27:15.608Z] 18:27:15 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb.py", line 842, in _pidof
[task 2019-02-12T18:27:15.608Z] 18:27:15 INFO - procs = self.get_process_list(timeout=timeout)
[task 2019-02-12T18:27:15.608Z] 18:27:15 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb.py", line 2340, in get_process_list
[task 2019-02-12T18:27:15.609Z] 18:27:15 CRITICAL - raise ADBTimeoutError("%s" % adb_process)
[task 2019-02-12T18:27:15.609Z] 18:27:15 CRITICAL - ADBTimeoutError: args: adb-5554 wait-for-device shell ps; echo adb_returncode=$?, exitcode: None, stdout:
[task 2019-02-12T18:27:15.610Z] 18:27:15 INFO - Traceback (most recent call last):
[task 2019-02-12T18:27:15.610Z] 18:27:15 INFO - File "/builds/worker/workspace/build/tests/xpcshell/remotexpcshelltests.py", line 615, in <module>
[task 2019-02-12T18:27:15.611Z] 18:27:15 INFO - main()
[task 2019-02-12T18:27:15.611Z] 18:27:15 INFO - File "/builds/worker/workspace/build/tests/xpcshell/remotexpcshelltests.py", line 610, in main
[task 2019-02-12T18:27:15.611Z] 18:27:15 INFO - mobileArgs=xpcsh.mobileArgs):
[task 2019-02-12T18:27:15.611Z] 18:27:15 INFO - File "/builds/worker/workspace/build/tests/xpcshell/runxpcshelltests.py", line 1485, in runTests
[task 2019-02-12T18:27:15.612Z] 18:27:15 INFO - status = step()
[task 2019-02-12T18:27:15.612Z] 18:27:15 INFO - File "/builds/worker/workspace/build/tests/xpcshell/runxpcshelltests.py", line 1447, in step1
[task 2019-02-12T18:27:15.612Z] 18:27:15 INFO - testClass, mobileArgs, **kwargs)
[task 2019-02-12T18:27:15.613Z] 18:27:15 INFO - File "/builds/worker/workspace/build/tests/xpcshell/runxpcshelltests.py", line 1625, in runTestList
[task 2019-02-12T18:27:15.613Z] 18:27:15 INFO - raise exceptions[0]
[task 2019-02-12T18:27:15.613Z] 18:27:15 CRITICAL - mozdevice.adb.ADBTimeoutError: args: adb-5554 wait-for-device shell ps; echo adb_returncode=$?, exitcode: None, stdout:
[task 2019-02-12T18:27:15.630Z] 18:27:15 ERROR - Return code: 1
[task 2019-02-12T18:27:15.631Z] 18:27:15 ERROR - No tests run or test summary not found
[task 2019-02-12T18:27:15.631Z] 18:27:15 INFO - TinderboxPrint: xpcshell<br/><em class="testfail">T-FAIL</em>
[task 2019-02-12T18:27:15.631Z] 18:27:15 INFO - ##### xpcshell log ends
[task 2019-02-12T18:27:15.631Z] 18:27:15 WARNING - # TBPL WARNING #
[task 2019-02-12T18:27:15.632Z] 18:27:15 WARNING - setting return code to 1
[task 2019-02-12T18:27:15.632Z] 18:27:15 WARNING - TinderboxPrint: Per-test run of .../unit/test_TelemetryController.js<br/>: WARNING
[task 2019-02-12T18:27:15.632Z] 18:27:15 INFO - Running post-action listener: _package_coverage_data
[task 2019-02-12T18:27:15.632Z] 18:27:15 INFO - Running post-action listener: _resource_record_post_action
[task 2019-02-12T18:27:15.633Z] 18:27:15 INFO - Running post-action listener: process_java_coverage_data
[task 2019-02-12T18:27:15.633Z] 18:27:15 INFO - Running post-action listener: stop_device
[task 2019-02-12T18:27:15.633Z] 18:27:15 INFO - Killing logcat pid 878.
[task 2019-02-12T18:27:15.633Z] 18:27:15 INFO - Killing every process called emulator64-arm
[task 2019-02-12T18:27:15.646Z] 18:27:15 INFO - Killing pid 467.
[task 2019-02-12T18:27:15.646Z] 18:27:15 INFO - [mozharness: 2019-02-12 18:27:15.646280Z] Finished run-tests step (success)
[task 2019-02-12T18:27:15.646Z] 18:27:15 INFO - Running post-run listener: _resource_record_post_run
[task 2019-02-12T18:27:15.776Z] 18:27:15 INFO - Total resource usage - Wall time: 1903s; CPU: 21.0%; Read bytes: 0; Write bytes: 1975091200; Read time: 0; Write time: 246264
[task 2019-02-12T18:27:15.776Z] 18:27:15 INFO - TinderboxPrint: CPU usage<br/>20.8%
[task 2019-02-12T18:27:15.777Z] 18:27:15 INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2019-02-12T18:27:15.777Z] 18:27:15 INFO - TinderboxPrint: I/O write bytes / time<br/>1,975,091,200 / 246,264
[task 2019-02-12T18:27:15.777Z] 18:27:15 INFO - TinderboxPrint: CPU idle<br/>5,965.5 (79.0%)
[task 2019-02-12T18:27:15.778Z] 18:27:15 INFO - TinderboxPrint: CPU user<br/>1,552.0 (20.6%)
[task 2019-02-12T18:27:15.778Z] 18:27:15 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2019-02-12T18:27:15.779Z] 18:27:15 INFO - verify-device - Wall time: 5s; CPU: 7.0%; Read bytes: 0; Write bytes: 86949888; Read time: 0; Write time: 10936
[task 2019-02-12T18:27:15.781Z] 18:27:15 INFO - install - Wall time: 55s; CPU: 25.0%; Read bytes: 0; Write bytes: 384606208; Read time: 0; Write time: 56268
[task 2019-02-12T18:27:15.802Z] 18:27:15 INFO - run-tests - Wall time: 1843s; CPU: 21.0%; Read bytes: 0; Write bytes: 1503535104; Read time: 0; Write time: 179060
[task 2019-02-12T18:27:16.397Z] 18:27:16 WARNING - returning nonzero exit status 1
[task 2019-02-12T18:27:16.424Z] cleanup
[task 2019-02-12T18:27:16.424Z] + cleanup
[task 2019-02-12T18:27:16.424Z] + local rv=1
[task 2019-02-12T18:27:16.424Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2019-02-12T18:27:16.424Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2019-02-12T18:27:16.426Z] + true
[task 2019-02-12T18:27:16.426Z] + cleanup_xvfb
[task 2019-02-12T18:27:16.427Z] pidof Xvfb
[task 2019-02-12T18:27:16.427Z] ++ pidof Xvfb
[task 2019-02-12T18:27:16.430Z] + local xvfb_pid=26
[task 2019-02-12T18:27:16.430Z] + local vnc=false
[task 2019-02-12T18:27:16.430Z] + local interactive=false
[task 2019-02-12T18:27:16.430Z] + '[' -n 26 ']'
[task 2019-02-12T18:27:16.430Z] + [[ false == false ]]
[task 2019-02-12T18:27:16.430Z] + [[ false == false ]]
[task 2019-02-12T18:27:16.430Z] + kill 26
[task 2019-02-12T18:27:16.430Z] + screen -XS xvfb quit
[task 2019-02-12T18:27:16.432Z] XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0"
[task 2019-02-12T18:27:16.432Z] after 1066 requests (1066 known processed) with 0 events remaining.
[task 2019-02-12T18:27:16.433Z] compizconfig - Info: Backend : ini
[task 2019-02-12T18:27:16.433Z] compizconfig - Info: Integration : true
[task 2019-02-12T18:27:16.434Z] compizconfig - Info: Profile : default
[task 2019-02-12T18:27:16.613Z] No screen session found.
[task 2019-02-12T18:27:16.613Z] + true
[task 2019-02-12T18:27:16.613Z] + exit 1
[taskcluster 2019-02-12 18:27:16.941Z] === Task Finished ===
[taskcluster 2019-02-12 18:27:26.057Z] Unsuccessful task run with exit code: 1 completed in 2167.786 seconds

Component: Activity Stream → Telemetry
Product: Firefox for Android → Toolkit

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

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.