1705782 - Intermittent TEST-UNEXPECTED-TIMEOUT | browser/components/privatebrowsing/test/browser/browser_privatebrowsing_history_shift_click.js | application timed out after 370 seconds with no output

Status: RESOLVED INCOMPLETE

(Firefox :: Private Browsing, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=336804017&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/VL4qgrXqR0G9AD__7O39jQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2021-04-16T16:31:35.715Z] 16:31:35     INFO - TEST-START | browser/components/privatebrowsing/test/browser/browser_privatebrowsing_history_shift_click.js
[task 2021-04-16T16:37:46.652Z] 16:37:46     INFO - Buffered messages logged at 16:31:35
[task 2021-04-16T16:37:48.081Z] 16:37:46     INFO - Entering test bound 
[task 2021-04-16T16:37:50.015Z] 16:37:47     INFO - Buffered messages finished
[task 2021-04-16T16:37:51.108Z] 16:37:48    ERROR - TEST-UNEXPECTED-TIMEOUT | browser/components/privatebrowsing/test/browser/browser_privatebrowsing_history_shift_click.js | application timed out after 370 seconds with no output
[task 2021-04-16T16:37:52.063Z] 16:37:48    ERROR - Force-terminating active process(es).
[task 2021-04-16T16:37:53.760Z] 16:37:49     INFO - Determining child pids from psutil...
[task 2021-04-16T16:37:56.229Z] 16:37:55     INFO - [1631, 1655, 1713, 1778, 1752, 1813]
[task 2021-04-16T16:37:58.161Z] 16:37:57     INFO - ==> process 1565 launched child process 1580
[task 2021-04-16T16:38:00.243Z] 16:37:59     INFO - ==> process 1565 launched child process 1631
[task 2021-04-16T16:38:02.090Z] 16:38:00     INFO - ==> process 1565 launched child process 1655
[task 2021-04-16T16:38:04.629Z] 16:38:03     INFO - ==> process 1565 launched child process 1713
[task 2021-04-16T16:38:07.072Z] 16:38:06     INFO - ==> process 1565 launched child process 1752
[task 2021-04-16T16:38:08.154Z] 16:38:07     INFO - ==> process 1565 launched child process 1778
[task 2021-04-16T16:38:09.726Z] 16:38:07     INFO - ==> process 1565 launched child process 1813
[task 2021-04-16T16:38:10.685Z] 16:38:08     INFO - Found child pids: set([1580, 1713, 1778, 1813, 1655, 1752, 1631])
[task 2021-04-16T16:38:12.037Z] 16:38:10     INFO - Failed to get child procs
[task 2021-04-16T16:38:13.372Z] 16:38:11     INFO - Killing process: 1580
[task 2021-04-16T16:38:14.969Z] 16:38:14     INFO - TEST-INFO | started process screentopng
[task 2021-04-16T16:55:03.173Z] 16:55:03     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'browser/components/privatebrowsing/test/browser/browser.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/BT58blC7QR6cFx8ViQEzcA/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-browser-chrome_raw.log', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/mochitest-browser-chrome_errorsummary.log', '--use-test-media-devices', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/builds/worker/workspace/build', '--log-raw=-', '--flavor=browser', '--chunk-by-runtime']
[task 2021-04-16T16:55:03.192Z] 16:55:03    ERROR - timed out after 1000 seconds of no output
[task 2021-04-16T16:55:03.192Z] 16:55:03    ERROR - Return code: -15
[task 2021-04-16T16:55:03.192Z] 16:55:03    ERROR - No suite end message was emitted by this harness.
[task 2021-04-16T16:55:03.192Z] 16:55:03     INFO - TinderboxPrint: mochitest-mochitest-browser-chrome<br/>16/0/0
[task 2021-04-16T16:55:03.192Z] 16:55:03    ERROR - # TBPL FAILURE #
[task 2021-04-16T16:55:03.192Z] 16:55:03  WARNING - setting return code to 2
[task 2021-04-16T16:55:03.193Z] 16:55:03    ERROR - The mochitest suite: mochitest-browser-chrome ran with return status: FAILURE
[task 2021-04-16T16:55:03.193Z] 16:55:03     INFO - Running post-action listener: _package_coverage_data
[task 2021-04-16T16:55:03.193Z] 16:55:03     INFO - Running post-action listener: _resource_record_post_action
[task 2021-04-16T16:55:03.193Z] 16:55:03     INFO - Running post-action listener: process_java_coverage_data
[task 2021-04-16T16:55:03.193Z] 16:55:03     INFO - [mozharness: 2021-04-16 16:55:03.104738Z] Finished run-tests step (success)
[task 2021-04-16T16:55:03.193Z] 16:55:03     INFO - Running post-run listener: _resource_record_post_run
[task 2021-04-16T16:55:03.545Z] 16:55:03     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 14.2860492845787}, {"name": "io_write_bytes", "value": 2120323072}, {"name": "io.read_bytes", "value": 466918682624}, {"name": "io_write_time", "value": 237204}, {"name": "io_read_time", "value": 59800908}], "extraOptions": ["e10s", "taskcluster-c5.xlarge"], "name": "mochitest.mochitest-browser-chrome.overall"}, {"subtests": [{"name": "time", "value": 0.018617868423461914}], "name": "mochitest.mochitest-browser-chrome.start-pulseaudio"}, {"subtests": [{"name": "time", "value": 30.196293115615845}, {"name": "cpu_percent", "value": 25.20603448275862}], "name": "mochitest.mochitest-browser-chrome.install"}, {"subtests": [{"name": "time", "value": 0.00015282630920410156}], "name": "mochitest.mochitest-browser-chrome.stage-files"}, {"subtests": [{"name": "time", "value": 1548.0759189128876}, {"name": "cpu_percent", "value": 13.743436454849496}], "name": "mochitest.mochitest-browser-chrome.run-tests"}]}
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - Total resource usage - Wall time: 1578s; CPU: 14.0%; Read bytes: 466918682624; Write bytes: 2120323072; Read time: 59800908; Write time: 237204
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - TinderboxPrint: CPU usage<br/>13.7%
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - TinderboxPrint: I/O read bytes / time<br/>466,918,682,624 / 59,800,908
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - TinderboxPrint: I/O write bytes / time<br/>2,120,323,072 / 237,204
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - TinderboxPrint: CPU idle<br/>859.5 (13.7%)
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - TinderboxPrint: CPU iowait<br/>4,690.5 (74.8%)
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - TinderboxPrint: CPU system<br/>419.9 (6.7%)
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - TinderboxPrint: CPU user<br/>299.0 (4.8%)
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - install - Wall time: 30s; CPU: 25.0%; Read bytes: 8192; Write bytes: 1267548160; Read time: 112; Write time: 110092
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-04-16T16:55:03.547Z] 16:55:03     INFO - run-tests - Wall time: 1548s; CPU: 14.0%; Read bytes: 466918322176; Write bytes: 584044544; Read time: 59799420; Write time: 87848
[task 2021-04-16T16:55:03.650Z] 16:55:03  WARNING - returning nonzero exit status 2
[task 2021-04-16T16:55:03.720Z] cleanup```

Comment 1

[Intermittent Failures Robot]

1 failures in 4255 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-tsan: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1705782&startday=2021-04-12&endday=2021-04-18&tree=all

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

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