Closed Bug 1676269 Opened 5 years ago Closed 5 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | dom/base/test/test_caretPositionFromPoint.html | application timed out after 370 seconds with no output

Categories

(Core :: DOM: Core & HTML, defect, P5)

Product:
Core
Component:
DOM: Core & HTML
Type:
defect

Tracking

()

Status:
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=321214821&repo=mozilla-release
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZLdGhD6DQfKLIMO5IpDrTg/runs/2/artifacts/public/logs/live_backing.log

[task 2020-11-09T18:21:55.374Z] 18:21:55     INFO - TEST-START | dom/base/test/test_caretPositionFromPoint.html
[task 2020-11-09T18:28:08.692Z] 18:28:07     INFO - Buffered messages finished
[task 2020-11-09T18:28:12.750Z] 18:28:11    ERROR - TEST-UNEXPECTED-TIMEOUT | dom/base/test/test_caretPositionFromPoint.html | application timed out after 370 seconds with no output
[task 2020-11-09T18:28:15.696Z] 18:28:14    ERROR - Force-terminating active process(es).
[task 2020-11-09T18:28:21.377Z] 18:28:20     INFO - Determining child pids from psutil...
[task 2020-11-09T18:28:40.584Z] 18:28:39     INFO - [1575, 1651, 1677, 1750, 1831, 1776]
[task 2020-11-09T18:28:48.886Z] 18:28:48     INFO - ==> process 1537 launched child process 1552
[task 2020-11-09T18:28:53.978Z] 18:28:53     INFO - ==> process 1537 launched child process 1651
[task 2020-11-09T18:28:56.920Z] 18:28:56     INFO - ==> process 1537 launched child process 1677
[task 2020-11-09T18:29:02.219Z] 18:29:00     INFO - ==> process 1537 launched child process 1750
[task 2020-11-09T18:29:05.063Z] 18:29:03     INFO - ==> process 1537 launched child process 1776
[task 2020-11-09T18:29:09.343Z] 18:29:08     INFO - ==> process 1537 launched child process 1831
[task 2020-11-09T18:29:14.250Z] 18:29:13     INFO - Found child pids: set([1552, 1831, 1575, 1677, 1776, 1651, 1750])
[task 2020-11-09T18:29:19.092Z] 18:29:17     INFO - Failed to get child procs
[task 2020-11-09T18:29:21.800Z] 18:29:20     INFO - Killing process: 1552
[task 2020-11-09T18:29:26.082Z] 18:29:24     INFO - TEST-INFO | started process screentopng
[task 2020-11-09T18:46:04.941Z] 18:46:04     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', u'dom/base/test/mochitest.ini', '--setpref=media.peerconnection.mtransport_process=false', '--setpref=network.process.enabled=false', '--appname=/builds/worker/workspace/build/application/firefox/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', u'--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/EZO1HCIrRfWuvw-b6pJPIg/artifacts/public/build/target.crashreporter-symbols.zip', '--certificate-path=tests/certs', '--setpref=webgl.force-enabled=true', '--quiet', '--log-raw=/builds/worker/workspace/build/blobber_upload_dir/mochitest-plain_raw.log', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/mochitest-plain_errorsummary.log', '--use-test-media-devices', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/builds/worker/workspace/build', '--log-raw=-', '--chunk-by-dir=4']
[task 2020-11-09T18:46:04.952Z] 18:46:04    ERROR - timed out after 1000 seconds of no output
[task 2020-11-09T18:46:04.952Z] 18:46:04    ERROR - Return code: -15
[task 2020-11-09T18:46:04.952Z] 18:46:04    ERROR - No suite end message was emitted by this harness.
[task 2020-11-09T18:46:04.952Z] 18:46:04     INFO - TinderboxPrint: mochitest-mochitest-plain<br/>352/0/0
[task 2020-11-09T18:46:04.952Z] 18:46:04    ERROR - # TBPL FAILURE #
[task 2020-11-09T18:46:04.952Z] 18:46:04  WARNING - setting return code to 2
[task 2020-11-09T18:46:04.952Z] 18:46:04    ERROR - The mochitest suite: mochitest-plain ran with return status: FAILURE
[task 2020-11-09T18:46:04.952Z] 18:46:04     INFO - Running post-action listener: _package_coverage_data
[task 2020-11-09T18:46:04.952Z] 18:46:04     INFO - Running post-action listener: _resource_record_post_action
[task 2020-11-09T18:46:04.952Z] 18:46:04     INFO - Running post-action listener: process_java_coverage_data
[task 2020-11-09T18:46:04.952Z] 18:46:04     INFO - [mozharness: 2020-11-09 18:46:04.887598Z] Finished run-tests step (success)
[task 2020-11-09T18:46:04.952Z] 18:46:04     INFO - Running post-run listener: _resource_record_post_run
[task 2020-11-09T18:46:05.527Z] 18:46:05     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2020-11-09T18:46:05.535Z] 18:46:05     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 16.41328855140185}, {"name": "io_write_bytes", "value": 1983033344}, {"name": "io.read_bytes", "value": 580857090048}, {"name": "io_write_time", "value": 226020}, {"name": "io_read_time", "value": 46729988}], "extraOptions": ["e10s", "taskcluster-c5.xlarge"], "name": "mochitest.mochitest-plain.overall"}, {"subtests": [{"name": "time", "value": 0.022377967834472656}], "name": "mochitest.mochitest-plain.start-pulseaudio"}, {"subtests": [{"name": "time", "value": 35.999101877212524}, {"name": "cpu_percent", "value": 25.19044117647059}], "name": "mochitest.mochitest-plain.install"}, {"subtests": [{"name": "time", "value": 0.00018310546875}], "name": "mochitest.mochitest-plain.stage-files"}, {"subtests": [{"name": "time", "value": 2335.8328688144684}, {"name": "cpu_percent", "value": 16.224522673031007}], "name": "mochitest.mochitest-plain.run-tests"}]}
[task 2020-11-09T18:46:05.535Z] 18:46:05     INFO - Total resource usage - Wall time: 2372s; CPU: 16.0%; Read bytes: 580857090048; Write bytes: 1983033344; Read time: 46729988; Write time: 226020
[task 2020-11-09T18:46:05.536Z] 18:46:05     INFO - TinderboxPrint: CPU usage<br/>16.2%
[task 2020-11-09T18:46:05.536Z] 18:46:05     INFO - TinderboxPrint: I/O read bytes / time<br/>580,857,090,048 / 46,729,988
[task 2020-11-09T18:46:05.536Z] 18:46:05     INFO - TinderboxPrint: I/O write bytes / time<br/>1,983,033,344 / 226,020
[task 2020-11-09T18:46:05.536Z] 18:46:05     INFO - TinderboxPrint: CPU idle<br/>2,482.8 (26.5%)
[task 2020-11-09T18:46:05.537Z] 18:46:05     INFO - TinderboxPrint: CPU iowait<br/>5,663.1 (60.4%)
[task 2020-11-09T18:46:05.537Z] 18:46:05     INFO - TinderboxPrint: CPU system<br/>331.0 (3.5%)
[task 2020-11-09T18:46:05.538Z] 18:46:05     INFO - TinderboxPrint: CPU user<br/>898.4 (9.6%)
[task 2020-11-09T18:46:05.538Z] 18:46:05     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2020-11-09T18:46:05.539Z] 18:46:05     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-11-09T18:46:05.540Z] 18:46:05     INFO - install - Wall time: 36s; CPU: 25.0%; Read bytes: 4096; Write bytes: 1568870400; Read time: 0; Write time: 174252
[task 2020-11-09T18:46:05.541Z] 18:46:05     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2020-11-09T18:46:05.564Z] 18:46:05     INFO - run-tests - Wall time: 2336s; CPU: 16.0%; Read bytes: 580857069568; Write bytes: 400302080; Read time: 46729988; Write time: 46652
[task 2020-11-09T18:46:05.972Z] 18:46:05  WARNING - returning nonzero exit status 2```

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

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