Closed Bug 1562945 Opened 5 years ago Closed 11 months ago

Intermittent TV tools/profiler/tests/browser/browser_test_feature_jsallocations.js | Test timed out -

Categories

(Core :: Gecko Profiler, defect, P4)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Filed by: ccoroiu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=254398079&repo=mozilla-inbound
Full log: https://queue.taskcluster.net/v1/task/dNqV9YgCQ3iXWowFETQUlA/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/dNqV9YgCQ3iXWowFETQUlA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


task 2019-07-02T10:47:41.253Z] 10:47:41 INFO - TEST-UNEXPECTED-FAIL | tools/profiler/tests/browser/browser_test_feature_jsallocations.js | Test timed out -
[task 2019-07-02T10:47:44.016Z] 10:47:44 INFO - GECKO(5391) | JavaScript error: resource://testing-common/PromiseTestUtils.jsm, line 110: uncaught exception: Object
[task 2019-07-02T10:47:44.073Z] 10:47:44 INFO - GECKO(5391) | MEMORY STAT | vsize 3589MB | residentFast 816MB | heapAllocated 421MB
[task 2019-07-02T10:47:44.089Z] 10:47:44 INFO - TEST-OK | tools/profiler/tests/browser/browser_test_feature_jsallocations.js | took 106951ms
[task 2019-07-02T10:47:44.125Z] 10:47:44 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-07-02T10:47:44.127Z] 10:47:44 INFO - TEST-UNEXPECTED-FAIL | tools/profiler/tests/browser/browser_test_feature_jsallocations.js | Found a tab after previous test timed out: http://example.com/browser/tools/profiler/tests/browser/do_work_500ms.html -
[task 2019-07-02T10:47:44.264Z] 10:47:44 INFO - GECKO(5391) | [Parent 5391, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
[task 2019-07-02T10:47:44.266Z] 10:47:44 INFO - GECKO(5391) | [Parent 5391, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
[task 2019-07-02T10:47:44.645Z] 10:47:44 INFO - GECKO(5391) | [Child 5685, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
[task 2019-07-02T10:47:45.066Z] 10:47:45 INFO - GECKO(5391) | ++DOCSHELL 0x7f6714848000 == 1 [pid = 5770] [id = {4ae77e08-04f3-4786-bdfb-8ab11a00c6ac}]
[task 2019-07-02T10:47:45.609Z] 10:47:45 INFO - GECKO(5391) | ++DOMWINDOW == 1 (0x7f67148b9660) [pid = 5770] [serial = 1] [outer = (nil)]
[task 2019-07-02T10:47:45.710Z] 10:47:45 INFO - GECKO(5391) | [Child 5770, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
[task 2019-07-02T10:47:46.434Z] 10:47:46 INFO - checking window state
[task 2019-07-02T10:47:47.021Z] 10:47:47 INFO - GECKO(5391) | ++DOMWINDOW == 2 (0x7f67278a0400) [pid = 5770] [serial = 2] [outer = 0x7f67148b9660]
[task 2019-07-02T10:47:53.444Z] 10:47:53 INFO - GECKO(5391) | --DOCSHELL 0x7f2d59648000 == 0 [pid = 5742] [id = {c63be3f0-068d-4c15-aac6-f4127269be8e}] [url = http://example.com/browser/tools/profiler/tests/browser/do_work_500ms.html]
[task 2019-07-02T10:47:53.825Z] 10:47:53 INFO - GECKO(5391) | --DOMWINDOW == 1 (0x7f2d596c2660) [pid = 5742] [serial = 1] [outer = (nil)] [url = http://example.com/browser/tools/profiler/tests/browser/do_work_500ms.html]
[task 2019-07-02T10:47:54.751Z] 10:47:54 INFO - GECKO(5391) | --DOCSHELL 0x7ff7ae84c000 == 0 [pid = 5685] [id = {331e1a30-e715-4831-b113-6d95caec4c10}] [url = about:blank]
[task 2019-07-02T10:47:57.646Z] 10:47:57 INFO - GECKO(5391) | --DOMWINDOW == 0 (0x7f2d5a3cc000) [pid = 5742] [serial = 3] [outer = (nil)] [url = http://example.com/browser/tools/profiler/tests/browser/do_work_500ms.html]
[task 2019-07-02T10:47:59.179Z] 10:47:59 INFO - GECKO(5391) | --DOMWINDOW == 1 (0x7ff7ae8be660) [pid = 5685] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-07-02T10:48:03.106Z] 10:48:03 INFO - GECKO(5391) | --DOMWINDOW == 0 (0x7ff7ae8e6000) [pid = 5685] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-07-02T10:49:12.277Z] 10:49:12 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-07-02T10:49:12.279Z] 10:49:12 INFO - TEST-UNEXPECTED-FAIL | tools/profiler/tests/browser/browser_test_feature_jsallocations.js | Uncaught exception received from previously timed out test - at chrome://mochitests/content/browser/tools/profiler/tests/browser/browser_test_feature_jsallocations.js:29 - TypeError: Assert is null
[task 2019-07-02T10:49:12.279Z] 10:49:12 INFO - Stack trace:
[task 2019-07-02T10:49:12.280Z] 10:49:12 INFO - test_profile_feature_jsallocations/<@chrome://mochitests/content/browser/tools/profiler/tests/browser/browser_test_feature_jsallocations.js:29:9
[task 2019-07-02T10:49:12.280Z] 10:49:12 INFO - asyncwithNewTab@resource://testing-common/BrowserTestUtils.jsm:111:24
[task 2019-07-02T10:49:12.281Z] 10:49:12 INFO - async
test_profile_feature_jsallocations@chrome://mochitests/content/browser/tools/profiler/tests/browser/browser_test_feature_jsallocations.js:19:26
[task 2019-07-02T10:49:12.281Z] 10:49:12 INFO - Tester_execTest/<@chrome://mochikit/content/browser-test.js:1115:34
[task 2019-07-02T10:49:12.281Z] 10:49:12 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1143:12
[task 2019-07-02T10:49:12.281Z] 10:49:12 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:999:14
[task 2019-07-02T10:49:12.281Z] 10:49:12 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
[task 2019-07-02T10:49:12.282Z] 10:49:12 INFO - Console message: [JavaScript Error: "uncaught exception: Object" {file: "resource://testing-common/PromiseTestUtils.jsm" line: 110}]
[task 2019-07-02T10:49:12.329Z] 10:49:12 INFO - GECKO(5391) | ++DOMWINDOW == 16 (0x7f7f02590800) [pid = 5391] [serial = 18] [outer = 0x7f7f12259b30]
[task 2019-07-02T10:49:12.377Z] 10:49:12 INFO - GECKO(5391) | [Child 5770, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
[task 2019-07-02T10:49:12.479Z] 10:49:12 INFO - GECKO(5391) | ++DOMWINDOW == 17 (0x7f7ed8a2cc00) [pid = 5391] [serial = 19] [outer = 0x7f7f12259b30]
[task 2019-07-02T10:49:13.567Z] 10:49:13 INFO - GECKO(5391) | --DOCSHELL 0x7f78ae7c4800 == 0 [pid = 5545] [id = {d63a9af4-d660-4b91-87ba-c9da90a69a60}] [url = about:newtab]
[task 2019-07-02T10:49:13.567Z] 10:49:13 INFO - GECKO(5391) | --DOMWINDOW == 1 (0x7f78af075660) [pid = 5545] [serial = 1] [outer = (nil)] [url = about:newtab]
[task 2019-07-02T10:49:13.569Z] 10:49:13 INFO - GECKO(5391) | --DOMWINDOW == 0 (0x7f78af77d400) [pid = 5545] [serial = 3] [outer = (nil)] [url = about:newtab]
[task 2019-07-02T10:49:16.815Z] 10:49:16 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5685
[task 2019-07-02T10:49:16.912Z] 10:49:16 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5521
[task 2019-07-02T10:49:17.033Z] 10:49:17 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5576
[task 2019-07-02T10:49:17.195Z] 10:49:17 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5468
[task 2019-07-02T10:49:17.216Z] 10:49:17 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5620
[task 2019-07-02T10:49:17.225Z] 10:49:17 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5742
[task 2019-07-02T10:49:17.243Z] 10:49:17 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5659
[task 2019-07-02T10:49:17.260Z] 10:49:17 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5770
[task 2019-07-02T10:49:17.451Z] 10:49:17 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5545
[task 2019-07-02T10:49:17.774Z] 10:49:17 INFO - GECKO(5391) | Completed ShutdownLeaks collections in process 5445

Type: -- → defect
Flags: needinfo?(gtatum)
Priority: P5 → P2
Regressed by: 1545582

Edit, wrong bug.

Assignee: nobody → gtatum
Flags: needinfo?(gtatum)

I wonder if I should write do_work_500ms.html to be non-blocking, and implement some kind of re-queuing micro-task thing, were I setTimeout(fn, 0) over and over.

Assignee: gtatum → nobody
Priority: P2 → P4

I'm un-assigning myself and de-prioritizing this as Bug 1564150 lowered the failure rate.

Has Regression Range: --- → yes
Severity: normal → S3
Status: NEW → RESOLVED
Closed: 11 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.