Closed Bug 1472186 Opened 6 years ago Closed 6 years ago

Intermittent devtools/client/performance/test/browser_perf-range-changed-render.js | WaterfallView rerendered 3 times. - Got 4, expected 3

Categories

(DevTools :: Performance Tools (Profiler/Timeline), defect, P5)

Product:
DevTools
Component:
Performance Tools (Profiler/Timeline)
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: btara [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=185556538&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/IHRZ5AO6R7WQGcOBUZp-gg/runs/0/artifacts/public/logs/live_backing.log 11:55:30 INFO - 433 INFO Entering test bound 11:55:30 INFO - Buffered messages logged at 11:55:30 11:55:30 INFO - 434 INFO TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Waterfall rerenders when a range in the overview graph is selected. - 11:55:30 INFO - 435 INFO TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Call tree rerenders after its corresponding pane is shown. - 11:55:30 INFO - 436 INFO TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Flamegraph rerenders after its corresponding pane is shown. - 11:55:30 INFO - 437 INFO TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Flamegraph rerenders when a range in the overview graph is removed. - 11:55:30 INFO - 438 INFO TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Call tree rerenders after its corresponding pane is shown. - 11:55:30 INFO - 439 INFO TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Waterfall rerenders after its corresponding pane is shown. - 11:55:30 INFO - Buffered messages finished 11:55:30 ERROR - 440 INFO TEST-UNEXPECTED-FAIL | devtools/client/performance/test/browser_perf-range-changed-render.js | WaterfallView rerendered 3 times. - Got 4, expected 3 11:55:30 INFO - Stack trace: 11:55:30 INFO - chrome://mochikit/content/browser-test.js:test_is:1300 11:55:30 INFO - chrome://mochitests/content/browser/devtools/client/performance/test/browser_perf-range-changed-render.js:null:72 11:55:30 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1098 11:55:30 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1089 11:55:30 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:991 11:55:30 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795 11:55:30 INFO - 441 INFO TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | JsCallTreeView rerendered 2 times. - 11:55:30 INFO - 442 INFO TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | JsFlameGraphView rerendered 2 times. - 11:55:30 INFO - GECKO(4884) | Destroying panel. 11:55:30 INFO - GECKO(4884) | ++DOMWINDOW == 24 (0EB23C00) [pid = 4884] [serial = 657] [outer = 0AB8C410] 11:55:30 INFO - GECKO(4884) | --DOMWINDOW == 2 (0B814C00) [pid = 4460] [serial = 63] [outer = 00000000] [url = about:blank] 11:55:31 INFO - GECKO(4884) | --DOCSHELL 0EB94C00 == 9 [pid = 4884] [id = {4dfebae4-4621-45ee-b8c1-67041dd2d6d9}] 11:55:31 INFO - GECKO(4884) | --DOCSHELL 16B48C00 == 8 [pid = 4884] [id = {9e075417-bbf4-46b1-922b-74d208143522}] 11:55:31 INFO - GECKO(4884) | --DOCSHELL 009B3400 == 7 [pid = 4884] [id = {7f3758ca-71af-4093-b195-772a293548b7}] 11:55:31 INFO - GECKO(4884) | --DOCSHELL 16B49000 == 6 [pid = 4884] [id = {0e26dd59-ea9e-47ec-87d6-3bd14184444f}] 11:55:31 INFO - GECKO(4884) | --DOCSHELL 17942400 == 5 [pid = 4884] [id = {67d548f7-7d6d-4ade-8cb3-a86977f31e32}] 11:55:31 INFO - GECKO(4884) | Removing tab: h
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE

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

Status: REOPENED → RESOLVED
Closed: 6 years ago → 6 years ago
Resolution: --- → INCOMPLETE

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=239497704&repo=autoland&lineNumber=19897

TEST-START | devtools/client/performance/test/browser_perf-range-changed-render.js
00:02:19 INFO - GECKO(893) | Adding tab with url: http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#824911663582389.
00:02:19 INFO - GECKO(893) | ++DOCSHELL 0x11e785000 == 2 [pid = 899] [id = {49c31823-27c4-434c-85f7-cb47591dd9a0}]
00:02:19 INFO - GECKO(893) | ++DOMWINDOW == 5 (0x125536020) [pid = 899] [serial = 146] [outer = 0x0]
00:02:19 INFO - GECKO(893) | ++DOMWINDOW == 6 (0x1144e6000) [pid = 899] [serial = 147] [outer = 0x125536020]
00:02:19 INFO - GECKO(893) | ++DOMWINDOW == 7 (0x11b23b000) [pid = 899] [serial = 148] [outer = 0x125536020]
00:02:19 INFO - GECKO(893) | Initializing a performance panel.
00:02:19 INFO - GECKO(893) | ++DOCSHELL 0x1196be800 == 10 [pid = 893] [id = {6c7ff729-d20f-684c-9263-32bcd9227673}]
00:02:19 INFO - GECKO(893) | ++DOMWINDOW == 20 (0x11969d2e0) [pid = 893] [serial = 640] [outer = 0x0]
00:02:19 INFO - GECKO(893) | ++DOMWINDOW == 21 (0x118b08000) [pid = 893] [serial = 641] [outer = 0x11969d2e0]
00:02:19 INFO - GECKO(893) | ++DOMWINDOW == 22 (0x119cdf000) [pid = 893] [serial = 642] [outer = 0x11969d2e0]
00:02:20 INFO - GECKO(893) | ++DOCSHELL 0x11881f000 == 11 [pid = 893] [id = {e145b308-b855-8a41-890f-da4cc0d6d953}]
00:02:20 INFO - GECKO(893) | ++DOMWINDOW == 23 (0x11acc7d40) [pid = 893] [serial = 643] [outer = 0x0]
00:02:20 INFO - GECKO(893) | ++DOMWINDOW == 24 (0x11ad85000) [pid = 893] [serial = 644] [outer = 0x11acc7d40]
00:02:20 INFO - GECKO(893) | [Parent 893, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x805D0021: file /builds/worker/workspace/build/src/modules/libjar/nsJARChannel.cpp, line 994
00:02:21 INFO - GECKO(893) | Waiting for event: 'Performance:BackendReadyRecordingStart' on [object PerformanceController] for 1 time(s).
00:02:21 INFO - GECKO(893) | Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: ["recording-started"].
00:02:21 INFO - GECKO(893) | Waiting for event: 'Performance:UI:StateChanged' on [object PerformanceView] for 1 time(s) with arguments: [{}].
00:02:21 INFO - GECKO(893) | Waiting for event: 'Performance:UI:OverviewRendered' on [object OverviewView] for 1 time(s) with arguments: [100].
00:02:21 INFO - GECKO(893) | Event: 'Performance:UI:StateChanged' on [object PerformanceView] received.
00:02:21 INFO - GECKO(893) | ++DOCSHELL 0x12fc45000 == 12 [pid = 893] [id = {9450b300-b2f3-9c48-a7e6-5ea683b83625}]
00:02:21 INFO - GECKO(893) | ++DOMWINDOW == 25 (0x12d756a60) [pid = 893] [serial = 645] [outer = 0x0]
00:02:21 INFO - GECKO(893) | Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
00:02:21 INFO - GECKO(893) | Event: 'Performance:BackendReadyRecordingStart' on [object PerformanceController] received.
00:02:21 INFO - GECKO(893) | ++DOMWINDOW == 26 (0x11ad8b400) [pid = 893] [serial = 646] [outer = 0x12d756a60]
00:02:21 INFO - GECKO(893) | [Parent 893, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x805D0021: file /builds/worker/workspace/build/src/modules/libjar/nsJARChannel.cpp, line 994
00:02:21 INFO - GECKO(893) | ++DOCSHELL 0x12d962800 == 13 [pid = 893] [id = {b077c261-c94b-0648-b01e-3d32c3c27533}]
00:02:21 INFO - GECKO(893) | ++DOMWINDOW == 27 (0x1343dc3e0) [pid = 893] [serial = 647] [outer = 0x0]
00:02:21 INFO - GECKO(893) | ++DOMWINDOW == 28 (0x12f03d800) [pid = 893] [serial = 648] [outer = 0x1343dc3e0]
00:02:21 INFO - GECKO(893) | [Parent 893, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x805D0021: file /builds/worker/workspace/build/src/modules/libjar/nsJARChannel.cpp, line 994
00:02:22 INFO - GECKO(893) | Event: 'Performance:UI:OverviewRendered' on [object OverviewView] received.
00:02:22 INFO - GECKO(893) | Waiting for event: 'Performance:BackendReadyRecordingStop' on [object PerformanceController] for 1 time(s).
00:02:22 INFO - GECKO(893) | Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: ["recording-stopping"].
00:02:22 INFO - GECKO(893) | Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: ["recording-stopped"].
00:02:22 INFO - GECKO(893) | Waiting for event: 'Performance:UI:StateChanged' on [object PerformanceView] for 1 time(s) with arguments: ["recorded"].
00:02:22 INFO - GECKO(893) | Waiting for event: 'Performance:UI:OverviewRendered' on [object OverviewView] for 1 time(s) with arguments: [16].
00:02:22 INFO - GECKO(893) | Waiting for event: 'Performance:UI:WaterfallRendered' on [object WaterfallView] for 1 time(s).
00:02:22 INFO - GECKO(893) | Ignoring event 'Performance:UI:StateChanged' with unexpected argument at index 0: loading - expected recorded
00:02:22 INFO - GECKO(893) | Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
00:02:22 INFO - GECKO(893) | Ignoring event 'Performance:RecordingStateChange' with unexpected argument at index 0: recording-stopping - expected recording-stopped
00:02:22 INFO - GECKO(893) | Event: 'Performance:UI:StateChanged' on [object PerformanceView] received.
00:02:22 INFO - GECKO(893) | Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
00:02:22 INFO - GECKO(893) | --DOMWINDOW == 6 (0x1144e6400) [pid = 899] [serial = 144] [outer = 0x0] [url = about:blank]
00:02:22 INFO - GECKO(893) | --DOMWINDOW == 5 (0x11b240c00) [pid = 899] [serial = 142] [outer = 0x0] [url = http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#5407523382160312]
00:02:23 INFO - GECKO(893) | Event: 'Performance:UI:WaterfallRendered' on [object WaterfallView] received.
00:02:23 INFO - GECKO(893) | Event: 'Performance:BackendReadyRecordingStop' on [object PerformanceController] received.
00:02:23 INFO - GECKO(893) | Event: 'Performance:UI:OverviewRendered' on [object OverviewView] received.
00:02:23 INFO - GECKO(893) | Waiting for event: 'Performance:UI:WaterfallRendered' on [object WaterfallView] for 1 time(s).
00:02:23 INFO - GECKO(893) | Event: 'Performance:UI:WaterfallRendered' on [object WaterfallView] received.
00:02:23 INFO - GECKO(893) | Waiting for event: 'Performance:UI:JsCallTreeRendered' on [object JsCallTreeView] for 1 time(s).
00:02:23 INFO - GECKO(893) | Event: 'Performance:UI:JsCallTreeRendered' on [object JsCallTreeView] received.
00:02:23 INFO - GECKO(893) | Waiting for event: 'Performance:UI:JsFlameGraphRendered' on [object JsFlameGraphView] for 1 time(s).
00:02:23 INFO - GECKO(893) | ++DOCSHELL 0x130a31000 == 14 [pid = 893] [id = {5efcef13-7528-b049-b32b-c5f226433132}]
00:02:23 INFO - GECKO(893) | ++DOMWINDOW == 29 (0x130a0cc40) [pid = 893] [serial = 649] [outer = 0x0]
00:02:23 INFO - GECKO(893) | ++DOMWINDOW == 30 (0x12c06c800) [pid = 893] [serial = 650] [outer = 0x130a0cc40]
00:02:23 INFO - GECKO(893) | [Parent 893, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x805D0021: file /builds/worker/workspace/build/src/modules/libjar/nsJARChannel.cpp, line 994
00:02:23 INFO - GECKO(893) | --DOCSHELL 0x11e720000 == 1 [pid = 899] [id = {6cedf2a0-e18c-5944-9c62-b037b04f0d73}] [url = http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#905781893473662]
00:02:23 INFO - GECKO(893) | --DOMWINDOW == 4 (0x125536200) [pid = 899] [serial = 143] [outer = 0x0] [url = http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#905781893473662]
00:02:23 INFO - GECKO(893) | Event: 'Performance:UI:JsFlameGraphRendered' on [object JsFlameGraphView] received.
00:02:23 INFO - GECKO(893) | Waiting for event: 'Performance:UI:JsFlameGraphRendered' on [object JsFlameGraphView] for 1 time(s).
00:02:24 INFO - GECKO(893) | Event: 'Performance:UI:JsFlameGraphRendered' on [object JsFlameGraphView] received.
00:02:24 INFO - GECKO(893) | Waiting for event: 'Performance:UI:JsCallTreeRendered' on [object JsCallTreeView] for 1 time(s).
00:02:24 INFO - GECKO(893) | Event: 'Performance:UI:JsCallTreeRendered' on [object JsCallTreeView] received.
00:02:24 INFO - GECKO(893) | Waiting for event: 'Performance:UI:WaterfallRendered' on [object WaterfallView] for 1 time(s).
00:02:24 INFO - GECKO(893) | Event: 'Performance:UI:WaterfallRendered' on [object WaterfallView] received.
00:02:24 INFO - TEST-INFO | started process screencapture
00:02:24 INFO - TEST-INFO | screencapture: exit 0
00:02:24 INFO - Buffered messages logged at 00:02:19
00:02:24 INFO - Entering test bound
00:02:24 INFO - Buffered messages logged at 00:02:23
00:02:24 INFO - TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Waterfall rerenders when a range in the overview graph is selected. -
00:02:24 INFO - TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Call tree rerenders after its corresponding pane is shown. -
00:02:24 INFO - TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Flamegraph rerenders after its corresponding pane is shown. -
00:02:24 INFO - Buffered messages logged at 00:02:24
00:02:24 INFO - TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Flamegraph rerenders when a range in the overview graph is removed. -
00:02:24 INFO - TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Call tree rerenders after its corresponding pane is shown. -
00:02:24 INFO - TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | Waterfall rerenders after its corresponding pane is shown. -
00:02:24 INFO - Buffered messages finished
00:02:24 INFO - TEST-UNEXPECTED-FAIL | devtools/client/performance/test/browser_perf-range-changed-render.js | WaterfallView rerendered 3 times. - Got 4, expected 3
00:02:24 INFO - Stack trace:
00:02:24 INFO - chrome://mochikit/content/browser-test.js:test_is:1325
00:02:24 INFO - chrome://mochitests/content/browser/devtools/client/performance/test/browser_perf-range-changed-render.js:null:72
00:02:24 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1116
00:02:24 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1144
00:02:24 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1005
00:02:24 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
00:02:24 INFO - TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | JsCallTreeView rerendered 2 times. -
00:02:24 INFO - TEST-PASS | devtools/client/performance/test/browser_perf-range-changed-render.js | JsFlameGraphView rerendered 2 times. -
00:02:24 INFO - GECKO(893) | Destroying panel.
00:02:24 INFO - GECKO(893) | ++DOMWINDOW == 31 (0x11ad8b800) [pid = 893] [serial = 651] [outer = 0x11969d2e0]
00:02:24 INFO - GECKO(893) | console.warn: "Error while detaching the thread front: 'detach' request packet to 'server1.conn58.child1/context18' can't be sent as the connection is closed."
00:02:25 INFO - GECKO(893) | --DOMWINDOW == 3 (0x11f6a0000) [pid = 897] [serial = 95] [outer = 0x0] [url = about:blank]
00:02:25 INFO - GECKO(893) | --DOMWINDOW == 2 (0x1154dc800) [pid = 897] [serial = 97] [outer = 0x0] [url = about:blank]
00:02:25 INFO - GECKO(893) | Removing tab: http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#824911663582389.
00:02:25 INFO - GECKO(893) | --DOCSHELL 0x11f67f000 == 0 [pid = 897] [id = {0a81f24f-c6fe-dc4f-a701-0e05299597b6}] [url = about:blank]
00:02:25 INFO - GECKO(893) | --DOMWINDOW == 1 (0x126535200) [pid = 897] [serial = 96] [outer = 0x0] [url = about:blank]
00:02:26 INFO - Leaving test bound
00:02:26 INFO - finish() was called, cleaning up...
00:02:27 INFO - GECKO(893) | --DOCSHELL 0x119ca5000 == 13 [pid = 893] [id = {333dffa0-6e66-7748-83a8-5031a466e4ee}] [url = about:blank]
00:02:27 INFO - GECKO(893) | --DOCSHELL 0x12b89e800 == 12 [pid = 893] [id = {dd18a517-e8dd-9a45-8624-a130f2c395b5}] [url = chrome://devtools/content/shared/widgets/graphs-frame.xhtml]
00:02:27 INFO - GECKO(893) | --DOCSHELL 0x12d69f800 == 11 [pid = 893] [id = {80eb36df-3d60-d545-9577-28a010a79262}] [url = chrome://devtools/content/shared/widgets/graphs-frame.xhtml]
00:02:27 INFO - GECKO(893) | --DOCSHELL 0x118817800 == 10 [pid = 893] [id = {55a9834b-556f-124e-9006-89ac76174f4a}] [url = chrome://devtools/content/performance/index.xul]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 30 (0x11969d880) [pid = 893] [serial = 630] [outer = 0x0] [url = about:blank]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 29 (0x12d756100) [pid = 893] [serial = 635] [outer = 0x0] [url = chrome://devtools/content/shared/widgets/graphs-frame.xhtml]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 28 (0x13228fc40) [pid = 893] [serial = 637] [outer = 0x0] [url = chrome://devtools/content/shared/widgets/graphs-frame.xhtml]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 27 (0x11acc7020) [pid = 893] [serial = 633] [outer = 0x0] [url = chrome://devtools/content/performance/index.xul]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 26 (0x11ad8d000) [pid = 893] [serial = 639] [outer = 0x0] [url = about:blank]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 25 (0x119c11800) [pid = 893] [serial = 632] [outer = 0x0] [url = about:devtools-toolbox]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 24 (0x11ad86c00) [pid = 893] [serial = 634] [outer = 0x0] [url = about:blank]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 23 (0x118b08000) [pid = 893] [serial = 641] [outer = 0x0] [url = about:blank]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 22 (0x12262d000) [pid = 893] [serial = 636] [outer = 0x0] [url = chrome://devtools/content/shared/widgets/graphs-frame.xhtml]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 21 (0x122d13400) [pid = 893] [serial = 638] [outer = 0x0] [url = chrome://devtools/content/shared/widgets/graphs-frame.xhtml]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 3 (0x1144e6000) [pid = 899] [serial = 147] [outer = 0x0] [url = about:blank]
00:02:27 INFO - GECKO(893) | --DOMWINDOW == 2 (0x11b23a400) [pid = 899] [serial = 145] [outer = 0x0] [url = http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#905781893473662]
00:02:27 INFO - GECKO(893) | MEMORY STAT | vsize 4562MB | residentFast 378MB | heapAllocated 119MB
00:02:27 INFO - TEST-OK | devtools/client/performance/test/browser_perf-range-changed-render.js | took 8767ms

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

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