Closed Bug 1172120 Opened 9 years ago Closed 8 years ago

Intermittent browser_perf-marker-details-01.js | Got an error: $name is null | Found an unexpected tab at the end of test run

Categories

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

Product:
DevTools
Component:
Performance Tools (Profiler/Timeline)
Platform:
x86_64
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox39 unaffected, firefox40 unaffected, firefox41 affected, firefox-esr31 unaffected, firefox-esr38 unaffected)

Status:
RESOLVED FIXED
Tracking Flags:
Tracking Status
firefox39 --- unaffected
firefox40 --- unaffected
firefox41 --- affected
firefox-esr31 --- unaffected
firefox-esr38 --- unaffected

People

(Reporter: RyanVM, Assigned: jsantell)

References

Details

(Keywords: intermittent-failure, Whiteboard: [test disabled on linux])

Attachments

(1 file, 2 obsolete files)

1172120-intermittent.patch
4.86 KB, patch
vporof
: review+
Details | Diff | Splinter Review 
07:25:16 INFO - 351 INFO TEST-START | browser/devtools/performance/test/browser_perf-marker-details-01.js
07:25:30 INFO - *************************
07:25:30 INFO - A coding exception was thrown and uncaught in a Task.
07:25:30 INFO - Full message: TypeError: $name is null
07:25:30 INFO - Full stack: shouldHaveLabel@chrome://mochitests/content/browser/browser/devtools/performance/test/browser_perf-marker-details-01.js:111:7
07:25:30 INFO - spawnTest/tests.ConsoleTime@chrome://mochitests/content/browser/browser/devtools/performance/test/browser_perf-marker-details-01.js:48:1
07:25:30 INFO - spawnTest@chrome://mochitests/content/browser/browser/devtools/performance/test/browser_perf-marker-details-01.js:87:30
07:25:30 INFO - test@chrome://mochitests/content/browser/browser/devtools/performance/test/head.js:169:3
07:25:30 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:770:9
07:25:30 INFO - Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:664:7
07:25:30 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:746:59
07:25:30 INFO - *************************
07:25:31 INFO - 352 INFO checking window state
07:25:31 INFO - 353 INFO Initializing a performance pane.
07:25:31 INFO - 354 INFO Adding tab: http://example.com/browser/browser/devtools/performance/test/doc_markers.html
07:25:31 INFO - 355 INFO Tab added and finished loading: http://example.com/browser/browser/devtools/performance/test/doc_markers.html
07:25:31 INFO - 356 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should not be checked yet.
07:25:31 INFO - 357 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should not be locked yet.
07:25:31 INFO - 358 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should now be checked.
07:25:31 INFO - 359 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should be locked.
07:25:31 INFO - 360 INFO Waiting for event: 'Performance:UI:StateChanged' on [object PerformanceView]
07:25:31 INFO - 361 INFO Received event: 'Performance:UI:StateChanged' on [object PerformanceView]
07:25:31 INFO - 362 INFO Waiting for event: 'Performance:UI:OverviewRendered' on [object OverviewView]
07:25:31 INFO - 363 INFO Received event: 'Performance:UI:OverviewRendered' on [object OverviewView]
07:25:31 INFO - 364 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The current state is 'recording'.
07:25:31 INFO - 365 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should still be checked.
07:25:31 INFO - 366 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should not be locked.
07:25:31 INFO - 367 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should already be checked.
07:25:31 INFO - 368 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should not be locked yet.
07:25:31 INFO - 369 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should not be checked.
07:25:31 INFO - 370 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should be locked.
07:25:31 INFO - 371 INFO Waiting for event: 'Performance:UI:StateChanged' on [object PerformanceView]
07:25:31 INFO - 372 INFO Received event: 'Performance:UI:StateChanged' on [object PerformanceView]
07:25:31 INFO - 373 INFO Waiting for event: 'Performance:UI:OverviewRendered' on [object OverviewView]
07:25:31 INFO - 374 INFO Received event: 'Performance:UI:OverviewRendered' on [object OverviewView]
07:25:31 INFO - 375 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The current state is 'recorded'.
07:25:31 INFO - 376 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should not be checked.
07:25:31 INFO - 377 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | The record button should not be locked.
07:25:31 INFO - 378 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | Got at least 5 markers (1)
07:25:31 INFO - 379 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | Got at least 5 markers (2)
07:25:31 INFO - 380 INFO TODO: Need to add marker details tests for GarbageCollection
07:25:31 INFO - 381 INFO TODO: Need to add marker details tests for GarbageCollection
07:25:31 INFO - 382 INFO TODO: Need to add marker details tests for Javascript
07:25:31 INFO - 383 INFO Restyle Hint:
07:25:31 INFO - 384 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | Styles has correct label for Restyle Hint::StyleAttribute
07:25:31 INFO - 385 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | Styles has a stack: stack
07:25:31 INFO - 386 INFO TEST-PASS | browser/devtools/performance/test/browser_perf-marker-details-01.js | Reflow has a stack: stack
07:25:31 INFO - 387 INFO TODO: Need to add marker details tests for Styles
07:25:31 INFO - 388 INFO TODO: Need to add marker details tests for Reflow
07:25:31 INFO - 389 INFO TODO: Need to add marker details tests for Styles
07:25:31 INFO - 390 INFO TODO: Need to add marker details tests for Reflow
07:25:31 INFO - 391 INFO TODO: Need to add marker details tests for Styles
07:25:31 INFO - 392 INFO TODO: Need to add marker details tests for Reflow
07:25:31 INFO - 393 INFO TODO: Need to add marker details tests for Styles
07:25:31 INFO - 394 INFO TODO: Need to add marker details tests for Reflow
07:25:31 INFO - 395 INFO TODO: Need to add marker details tests for Styles
07:25:31 INFO - 396 INFO TODO: Need to add marker details tests for Reflow
07:25:31 INFO - 397 INFO TODO: Need to add marker details tests for Styles
07:25:31 INFO - 398 INFO TODO: Need to add marker details tests for Reflow
07:25:31 INFO - 399 INFO TODO: Need to add marker details tests for Styles
07:25:31 INFO - 400 INFO TODO: Need to add marker details tests for Reflow
07:25:31 INFO - 401 INFO Timer Name:
07:25:31 INFO - 402 INFO TEST-UNEXPECTED-FAIL | browser/devtools/performance/test/browser_perf-marker-details-01.js | Got an error: $name is null
07:25:31 INFO - shouldHaveLabel@chrome://mochitests/content/browser/browser/devtools/performance/test/browser_perf-marker-details-01.js:111:7
07:25:31 INFO - spawnTest/tests.ConsoleTime@chrome://mochitests/content/browser/browser/devtools/performance/test/browser_perf-marker-details-01.js:48:1
07:25:31 INFO - spawnTest@chrome://mochitests/content/browser/browser/devtools/performance/test/browser_perf-marker-details-01.js:87:30
07:25:31 INFO - test@chrome://mochitests/content/browser/browser/devtools/performance/test/head.js:169:3
07:25:31 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:770:9
07:25:31 INFO - Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:664:7
07:25:31 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:746:59
07:25:31 INFO - -
07:25:31 INFO - Stack trace:
07:25:31 INFO - chrome://mochitests/content/browser/browser/devtools/performance/test/head.js:handleError:133
07:25:31 INFO - resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:Handler.prototype.process:890
07:25:31 INFO - resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:this.PromiseWalker.walkerLoop:766
07:25:31 INFO - resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:this.PromiseWalker.scheduleWalkerLoop/<:707
07:25:31 INFO - null:null:0
07:25:31 INFO - 403 INFO finish() was called, cleaning up...
07:25:32 INFO - MEMORY STAT vsize after test: 1267277824
07:25:32 INFO - MEMORY STAT residentFast after test: 518033408
07:25:32 INFO - MEMORY STAT heapAllocated after test: 345235656
07:25:32 INFO - 404 INFO TEST-OK | browser/devtools/performance/test/browser_perf-marker-details-01.js | took 15572ms
07:25:32 INFO - 405 INFO TEST-UNEXPECTED-FAIL | browser/devtools/performance/test/browser_perf-marker-details-01.js | Found an unexpected tab at the end of test run: http://example.com/browser/browser/devtools/performance/test/doc_markers.html - expected PASS
Assignee: nobody → jsantell
Status: NEW → ASSIGNED
Attached patch 1172120-intermittent.patch (obsolete) — — Splinter Review 
Looks solid on the try push. If anyone sees this, will land after a review
Attachment #8616238 - Attachment is obsolete: true
Attachment #8616314 - Flags: review?(vporof)
Attachment #8616314 - Flags: review?(vporof) → review+
https://hg.mozilla.org/mozilla-central/rev/cef01eb8b1af
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
status-firefox41: --- → fixed
Resolution: --- → FIXED
Whiteboard: [fixed-in-fx-team]
Target Milestone: --- → Firefox 41
Still happening :(
Status: RESOLVED → REOPENED
status-firefox41: fixed → affected
Flags: needinfo?(jsantell)
Resolution: FIXED → ---
Target Milestone: Firefox 41 → ---
I'll look into this.
Assignee: jsantell → vporof
Status: REOPENED → ASSIGNED
Flags: needinfo?(jsantell)
Any news on this? It's currently the #2 failure on OrangeFactor. Can we disable the test in the mean time?
Flags: needinfo?(vporof)
Lets disable this -- 300 failures in less than 2 weeks
Disabled on Linux.
https://hg.mozilla.org/integration/fx-team/rev/08fe9014f002
Flags: needinfo?(vporof)
Whiteboard: [test disabled on linux][leave open]
Somehow this test didn't appear in my bugzilla-todos so I didn't take a close enough look at it :/

Landing some more logging.
Attachment #8616314 - Attachment is obsolete: true
This doesn't happen anymore outside try. Unassigning.
Assignee: vporof → nobody
Status: ASSIGNED → NEW
This started being very chatty again for some reason...
Started going crazy after bug 963005, bug 1197613 and bug  landed, maybe these will help us identify the problem here.
Assignee: nobody → jsantell
Blocks: 1243573
Status: NEW → ASSIGNED
Was able to reproduce this consistently with e10s -- hopefully fixes on linux too. This will be a huge relief to fix.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=60984a530902
Attachment #8716670 - Flags: review?(vporof)
Comment on attachment 8716670 [details] [diff] [review]
1172120-intermittent.patch

Review of attachment 8716670 [details] [diff] [review]:
-----------------------------------------------------------------

::: devtools/client/performance/test/browser_perf-marker-details-01.js
@@ +37,5 @@
>    info("No need to select everything in the timeline.");
>    info("All the markers should be displayed by default.");
>  
> +  let bars = Array.prototype.filter.call($$(".waterfall-marker-bar"),
> +             (bar) => MARKER_TYPES.indexOf(bar.getAttribute("type")) !== -1);

Could just Array.filter here.

@@ +51,5 @@
>  
> +  // Sanity check that markers are in chronologically ascending order
> +  markers.reduce((previous, m) => {
> +    if (m.start <= previous) {
> +      throw new Error("Markers are not in order.");

Should ok(false) here instead maybe and dump the marker types?
Attachment #8716670 - Flags: review?(vporof) → review+
Comment on attachment 8716670 [details] [diff] [review]
1172120-intermittent.patch

Review of attachment 8716670 [details] [diff] [review]:
-----------------------------------------------------------------

::: devtools/client/performance/test/browser_perf-marker-details-01.js
@@ +37,5 @@
>    info("No need to select everything in the timeline.");
>    info("All the markers should be displayed by default.");
>  
> +  let bars = Array.prototype.filter.call($$(".waterfall-marker-bar"),
> +             (bar) => MARKER_TYPES.indexOf(bar.getAttribute("type")) !== -1);

I don't believe that's standard

@@ +51,5 @@
>  
> +  // Sanity check that markers are in chronologically ascending order
> +  markers.reduce((previous, m) => {
> +    if (m.start <= previous) {
> +      throw new Error("Markers are not in order.");

sgtm
Looks good.
Status: ASSIGNED → RESOLVED
Closed: 9 years ago → 8 years ago
Resolution: --- → FIXED
Whiteboard: [test disabled on linux][leave open] → [test disabled on linux]
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: