Closed Bug 1582655 Opened 5 months ago Closed 5 months ago

Intermittent tools/profiler/tests/browser/browser_test_feature_preferencereads.js | Found a tab after previous test timed out: http://example.com/browser/tools/profiler/tests/browser/fixed_height.html -

Categories

(Core :: Gecko Profiler, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla71
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox69 --- unaffected
firefox70 --- fixed
firefox71 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: smaug)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=267592398&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/fLGMTdb9TUmSzBSwhRPQXw/runs/0/artifacts/public/logs/live_backing.log


[task 2019-09-20T06:27:30.701Z] 06:27:30 INFO - TEST-START | tools/profiler/tests/browser/browser_test_feature_preferencereads.js
[task 2019-09-20T06:27:30.883Z] 06:27:30 INFO - GECKO(5129) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpT0aEwM.mozrunner/runtests_leaks_tab_pid5373.log
[task 2019-09-20T06:27:30.883Z] 06:27:30 INFO - GECKO(5129) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-20T06:27:31.125Z] 06:27:31 INFO - GECKO(5129) | [2019-09-20T06:27:31Z WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-20T06:27:31.125Z] 06:27:31 INFO - GECKO(5129) | [2019-09-20T06:27:31Z WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-20T06:27:31.141Z] 06:27:31 INFO - GECKO(5129) | ++DOCSHELL 0x7f2a6bcb5800 == 1 [pid = 5357] [id = {a78770ae-145d-4b88-97b3-d4c3102b558d}]
[task 2019-09-20T06:27:31.289Z] 06:27:31 INFO - GECKO(5129) | ++DOMWINDOW == 1 (0x7f2a6cbc3f20) [pid = 5357] [serial = 1] [outer = (nil)]
[task 2019-09-20T06:27:31.306Z] 06:27:31 INFO - GECKO(5129) | ++DOMWINDOW == 2 (0x7f2a6bb05400) [pid = 5357] [serial = 2] [outer = 0x7f2a6cbc3f20]
[task 2019-09-20T06:27:33.943Z] 06:27:33 INFO - GECKO(5129) | --DOMWINDOW == 2 (0x7f1ac63c6c00) [pid = 5284] [serial = 3] [outer = (nil)] [url = http://example.com/browser/tools/profiler/tests/browser/do_work_500ms.html]
[task 2019-09-20T06:27:33.963Z] 06:27:33 INFO - GECKO(5129) | --DOCSHELL 0x7f1ac595e000 == 0 [pid = 5284] [id = {c0cbf0d7-b1b6-4405-9305-2afeffbff3fd}] [url = http://example.com/browser/tools/profiler/tests/browser/do_work_500ms.html]
[task 2019-09-20T06:27:36.296Z] 06:27:36 INFO - GECKO(5129) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-20T06:27:36.493Z] 06:27:36 INFO - GECKO(5129) | [2019-09-20T06:27:36Z WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-20T06:27:36.493Z] 06:27:36 INFO - GECKO(5129) | [2019-09-20T06:27:36Z WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-20T06:27:36.509Z] 06:27:36 INFO - GECKO(5129) | ++DOCSHELL 0x7f44e835e000 == 1 [pid = 5373] [id = {7ab591c8-3d73-4f05-973b-3e6fe7838d8e}]
[task 2019-09-20T06:27:36.610Z] 06:27:36 INFO - GECKO(5129) | ++DOMWINDOW == 1 (0x7f44f9efdf20) [pid = 5373] [serial = 1] [outer = (nil)]
[task 2019-09-20T06:27:36.611Z] 06:27:36 INFO - GECKO(5129) | ++DOMWINDOW == 2 (0x7f44e82d9400) [pid = 5373] [serial = 2] [outer = 0x7f44f9efdf20]
[task 2019-09-20T06:27:36.908Z] 06:27:36 INFO - GECKO(5129) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpT0aEwM.mozrunner/runtests_leaks_tab_pid5407.log
[task 2019-09-20T06:27:37.105Z] 06:27:37 INFO - GECKO(5129) | ++DOMWINDOW == 3 (0x7f44e8dcb400) [pid = 5373] [serial = 3] [outer = 0x7f44f9efdf20]
[task 2019-09-20T06:27:46.294Z] 06:27:46 INFO - GECKO(5129) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-20T06:27:46.887Z] 06:27:46 INFO - GECKO(5129) | [2019-09-20T06:27:46Z WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-20T06:27:46.888Z] 06:27:46 INFO - GECKO(5129) | [2019-09-20T06:27:46Z WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-20T06:27:48.313Z] 06:27:48 INFO - GECKO(5129) | --DOCSHELL 0x7f69e5db2000 == 0 [pid = 5255] [id = {845b2af2-99ec-4720-8a6e-825783b9b455}] [url = about:blank]
[task 2019-09-20T06:27:48.509Z] 06:27:48 INFO - GECKO(5129) | --DOCSHELL 0x7f760ec5c800 == 0 [pid = 5316] [id = {04ad5197-0d29-49ae-9803-f9167757795d}] [url = about:blank]
[task 2019-09-20T06:27:49.121Z] 06:27:49 INFO - GECKO(5129) | --DOMWINDOW == 1 (0x7f1ac5902f20) [pid = 5284] [serial = 1] [outer = (nil)] [url = http://example.com/browser/tools/profiler/tests/browser/do_work_500ms.html]
[task 2019-09-20T06:28:01.264Z] 06:28:01 INFO - GECKO(5129) | --DOMWINDOW == 0 (0x7f1ac63c5000) [pid = 5284] [serial = 4] [outer = (nil)] [url = http://example.com/browser/tools/profiler/tests/browser/do_work_500ms.html]
[task 2019-09-20T06:28:05.940Z] 06:28:05 INFO - GECKO(5129) | --DOMWINDOW == 1 (0x7f69e5dc3f20) [pid = 5255] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-09-20T06:28:06.036Z] 06:28:06 INFO - GECKO(5129) | --DOMWINDOW == 1 (0x7f76383b6f20) [pid = 5316] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-09-20T06:28:07.502Z] 06:28:07 INFO - GECKO(5129) | --DOMWINDOW == 2 (0x7f44e82d9400) [pid = 5373] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-20T06:28:32.707Z] 06:28:32 INFO - GECKO(5129) | --DOMWINDOW == 0 (0x7f760f74ec00) [pid = 5316] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-20T06:28:36.284Z] 06:28:36 INFO - GECKO(5129) | --DOMWINDOW == 0 (0x7f69e5d23400) [pid = 5255] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-20T06:29:01.227Z] 06:29:01 INFO - TEST-INFO | started process screentopng
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - TEST-INFO | screentopng: exit 0
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - Buffered messages logged at 06:27:30
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - Entering test bound test_profile_feature_preferencereads
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - TEST-PASS | tools/profiler/tests/browser/browser_test_feature_preferencereads.js | The profiler is not currently active - true == true -
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - Buffered messages finished
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - TEST-UNEXPECTED-FAIL | tools/profiler/tests/browser/browser_test_feature_preferencereads.js | Test timed out -
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - GECKO(5129) | MEMORY STAT | vsize 3244MB | residentFast 527MB | heapAllocated 265MB
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - TEST-OK | tools/profiler/tests/browser/browser_test_feature_preferencereads.js | took 90843ms
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - TEST-UNEXPECTED-FAIL | tools/profiler/tests/browser/browser_test_feature_preferencereads.js | Found a tab after previous test timed out: http://example.com/browser/tools/profiler/tests/browser/fixed_height.html -
[task 2019-09-20T06:29:04.987Z] 06:29:04 INFO - checking window state

See Also: → 1563063

It wasn't perma-failure

Status: NEW → RESOLVED
Closed: 5 months ago
Resolution: --- → FIXED

No. There were failures when bug 1563063 wasn't in. See https://bugzilla.mozilla.org/show_bug.cgi?id=1582655#c1

Status: RESOLVED → REOPENED
Resolution: FIXED → ---

FWIW, the test fails locally rather reliably on debug linux64 even without bug 1563063

Regressed by: 1551313
Pushed by opettay@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/988fe150d3a2
try to make browser_test_feature_preferencereads.js less racy and let browser_test_feature_jsallocations.js to run a bit longer, r=whawkins
Status: REOPENED → RESOLVED
Closed: 5 months ago5 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla71
You need to log in before you can comment on or make changes to this bug.