Closed Bug 1536312 Opened 5 years ago Closed 5 years ago

Intermittent browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Uncaught exception - undefined - timed out after 50 tries.

Categories

(Firefox :: Toolbars and Customization, defect, P1)

defect
Points:
1

Tracking

()

RESOLVED FIXED
Iteration:
71.2 - Sept 16 - 29
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox69 --- unaffected
firefox70 --- wontfix
firefox71 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: fixed by bug 1580538)

Attachments

(2 files)

#[markdown(off)]
Filed by: btara [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=234665686&repo=autoland

https://queue.taskcluster.net/v1/task/CmqRGW3qSMy-0R9MCc-x4A/runs/0/artifacts/public/logs/live_backing.log

23:26:00 INFO - TEST-START | browser/components/customizableui/test/browser_884402_customize_from_overflow.js
23:26:00 INFO - GECKO(4952) | --DOMWINDOW == 12 (0809E400) [pid = 4204] [serial = 7] [outer = 00000000] [url = about:blank]
23:26:00 INFO - GECKO(4952) | --DOMWINDOW == 11 (080A1400) [pid = 4204] [serial = 9] [outer = 00000000] [url = about:blank]
23:26:00 INFO - GECKO(4952) | --DOMWINDOW == 10 (08D33C00) [pid = 4204] [serial = 11] [outer = 00000000] [url = about:blank]
23:26:00 INFO - GECKO(4952) | --DOMWINDOW == 9 (08D3A000) [pid = 4204] [serial = 14] [outer = 00000000] [url = about:blank]
23:26:00 INFO - GECKO(4952) | --DOMWINDOW == 8 (08D36C00) [pid = 4204] [serial = 12] [outer = 00000000] [url = data:text/html,<html><body></body></html>]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 37 (0D6AB400) [pid = 4452] [serial = 38] [outer = 00000000] [url = about:blank]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 36 (1F48BC00) [pid = 4452] [serial = 31] [outer = 00000000] [url = about:blank]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 35 (1EE8A000) [pid = 4452] [serial = 30] [outer = 00000000] [url = about:blank]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 34 (23E57400) [pid = 4452] [serial = 28] [outer = 00000000] [url = about:blank]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 33 (23688C00) [pid = 4452] [serial = 26] [outer = 00000000] [url = about:blank]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 32 (1DDBF800) [pid = 4452] [serial = 24] [outer = 00000000] [url = about:blank]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 31 (2368C000) [pid = 4452] [serial = 22] [outer = 00000000] [url = about:blank]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 30 (23684400) [pid = 4452] [serial = 20] [outer = 00000000] [url = about:blank]
23:26:01 INFO - GECKO(4952) | --DOMWINDOW == 29 (13DEB000) [pid = 4452] [serial = 18] [outer = 00000000] [url = about:blank]
...
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Should start with a non-overflowing toolbar. -
23:26:07 INFO - Buffered messages logged at 23:26:01
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Should have an overflowing toolbar. -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | sidebar-button was found -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Sidebar button is overflowing -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | The widget overflow panel should still be open. -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | menuitem should match .customize-context-moveToPanel selector -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | disabled state for .customize-context-moveToPanel -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | menuitem should match .customize-context-removeFromPanel selector -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | disabled state for .customize-context-removeFromPanel -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | menuseparator expected -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | menuitem should match .viewCustomizeToolbar selector -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | disabled state for .viewCustomizeToolbar -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Sidebar button should still have a placement -
23:26:07 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Sidebar button should be pinned now -
23:26:07 INFO - Buffered messages finished
23:26:07 INFO - TEST-UNEXPECTED-FAIL | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Uncaught exception - undefined - timed out after 50 tries.
23:26:07 INFO - Leaving test bound
23:26:07 INFO - GECKO(4952) | MEMORY STAT | vsize 801MB | vsizeMaxContiguous 684MB | residentFast 257MB | heapAllocated 105MB
23:26:07 INFO - TEST-OK | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | took 6454ms

Priority: -- → P3
Flags: needinfo?(jhofmann)
Flags: needinfo?(danielleleb12)
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Pushed by ccoroiu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/62b80ebeac32
disabled browser_884402_customize_from_overflow.js on windows and mac for frequest failures r=egao

It's pretty unfortunate we keep disabling tests without pinging triage owners or at least clearing priority so it shows up in queues...

Priority: P3 → --

We shouldn't be losing so much test coverage here.

Regressed by: 1577000

I ran this test and it passes TV on my Mac, so I unfortunately don't have any immediate solutions. I'll grab Windows/Linux loaners and see what's going on there. I'm leaving n-i because I'll continue to look into this. I'm hoping that a solution will come up as I look into bug 1578485.

(In reply to Harry Twyford [:harry] from comment #32)

I ran this test and it passes TV on my Mac, so I unfortunately don't have any immediate solutions. I'll grab Windows/Linux loaners and see what's going on there. I'm leaving n-i because I'll continue to look into this. I'm hoping that a solution will come up as I look into bug 1578485.

Did that happen? It's quite possible that the failure is dependent on the screen resolution (and thus window size) in use during the test. It's also odd that some of the test screenshots on some platforms show that the window is failing to resize, while on others the window has resized but it seems the overflow code has not (yet?) caught up...

Oh, and the other possibility is that there's some relation to tests that run before this one. Something like:

./mach mochitest browser/components/customizableui/test/ --end-at browser/components/customizableui/test/browser_884402_customize_from_overflow.js

may help with checking if that's the case. You'll need to re-enable the offending test in the manifest first for this to work.

I changed my screen resolution a couple of times and ran the preceding tests and still couldn't get the test to fail on on macOS. I did get the test to fail on an Ubuntu VM, but I locally backed out all the changes in bug 1577000 and the test still failed so that wasn't much help :/

The fix for bug 1578485 was to add an extra parameter to simulateItemDrag, which isn't used in the failing test.

Do you have any other ideas as to possible causes? Or ways I can test your screen resolution hypothesis?

Flags: needinfo?(gijskruitbosch+bugs)

(In reply to Harry Twyford [:harry] from comment #36)

I changed my screen resolution a couple of times and ran the preceding tests and still couldn't get the test to fail on on macOS. I did get the test to fail on an Ubuntu VM, but I locally backed out all the changes in bug 1577000 and the test still failed so that wasn't much help :/

The fix for bug 1578485 was to add an extra parameter to simulateItemDrag, which isn't used in the failing test.

Do you have any other ideas as to possible causes?

Add logging to OverflowableToolbar code and push to try to figure out whether we get resize/overflow events at all here? See if waiting longer helps? (ie there's optional extra arguments to waitForCondition that allow you to wait longer than it currently does) The Linux case isn't so interesting as the test was disabled on Linux prior to your change regressing something, and we never found out what triggered that.

Basically, if we're failing in terms of CustomizableUI.reset() not triggering overflow when it should, either onOverflow is not being called or it's not doing the right thing. Figuring out which will likely help with fixing the test and/or code.

It's probably not unrelated that now there are 2 resize handlers - one is from the overflowable toolbar code and one is from the awesomebar code, and they both influence what's happening to layout inside the navbar.

The other explanation I can think of is that margins around the address bar would have collapsed prior to your change, but aren't now, so that'll alter layout on its own.

Or ways I can test your screen resolution hypothesis?

Well, that hypothesis could explain why things don't fail locally even when they fail on infra, but apart from "make your machine's setup match infra" or "use a loaner", I don't know what else you could try...

Flags: needinfo?(gijskruitbosch+bugs)

Concur. It's unfortunate, but when you're in a situation where you can't (despite best efforts) reproduce the issue locally, but can reproduce reliably in automation, logging is often the most fruitful approach, at least according to my experience.

Incidentally, I wonder if we should try to land some logging in OverflowableToolbar that can be turned on via a pref to more easily diagnose this sort of thing. Bugs like this and bug 1571236 suggest that there are likely some edge cases we're not considering, and getting logging might help both for intermittents and when users hit reproducible issues.

I re-enabled the test, added a couple of console logs to the OverflowableToolbar overflow and resize events and both the UrlbarView and Urlbar Input resize events and... nothing failed on try :/ The intermittent robot indicates that this test fails more on autoland than try. Is there a difference between the try config and the autoland config that might make this test more temperamental on autoland?

With that said, reading the logs, it appears the UrlbarInput resize handler (the new one) is stopping the UrlbarView resize handler from firing. The work in bug 1577472 removes the UrlbarInput resize handler so I'll take another look when that lands to see if it fixes the issue.

I think bug 1577472 fixed this issue. Here's a try run: https://treeherder.mozilla.org/#/jobs?repo=try&revision=b260e746dbfe5d2d260db7951b4f01e0d3815f31. I ran the customizableui tests a bunch of times and they all look good.

Flags: needinfo?(htwyford)
Assignee: nobody → htwyford
Status: NEW → ASSIGNED
Pushed by gijskruitbosch@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/21ee43d26d0f
Reenable browser/components/customizableui/test/browser_884402_customize_from_overflow.js on Mac and Windows. r=Gijs
Backout by csabou@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/c88498487074
Backed out changeset 21ee43d26d0f for turning bug 1536312 into permafail.

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=testfailed%2Cbusted%2Cexception&revision=21ee43d26d0f0c73e7283897018ff9eaa3a172c5&selectedJob=266623367&searchStr=OS%2CX%2C10.14%2Cdebug%2CMochitests%2Ctest-macosx1014-64%2Fdebug-mochitest-browser-chrome-e10s-4%2CM%28bc4%29

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=266623367&repo=autoland&lineNumber=5825

Backout link: https://hg.mozilla.org/integration/autoland/rev/c88498487074dc73e38cd51b728df763fc6b19bb

[task 2019-09-13T22:14:05.592Z] 22:14:05 INFO - TEST-PASS | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Sidebar button should be pinned now -
[task 2019-09-13T22:14:05.592Z] 22:14:05 INFO - Buffered messages finished
[task 2019-09-13T22:14:05.592Z] 22:14:05 INFO - TEST-UNEXPECTED-FAIL | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | Uncaught exception - undefined - timed out after 50 tries.
[task 2019-09-13T22:14:05.592Z] 22:14:05 INFO - Leaving test bound
[task 2019-09-13T22:14:05.744Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource://testing-common/PromiseTestUtils.jsm, line 112: uncaught exception: Object
[task 2019-09-13T22:14:05.745Z] 22:14:05 INFO - Console message: [JavaScript Error: "uncaught exception: Object" {file: "resource://testing-common/PromiseTestUtils.jsm" line: 112}]
[task 2019-09-13T22:14:05.745Z] 22:14:05 INFO - GECKO(1759) | MEMORY STAT | vsize 7672MB | residentFast 373MB | heapAllocated 125MB
[task 2019-09-13T22:14:05.745Z] 22:14:05 INFO - TEST-OK | browser/components/customizableui/test/browser_884402_customize_from_overflow.js | took 11720ms
[task 2019-09-13T22:14:05.772Z] 22:14:05 INFO - GECKO(1759) | ++DOCSHELL 0x10c63a800 == 1 [pid = 1763] [id = {8ab42b8b-1412-304c-a20c-f95e79b7fb49}]
[task 2019-09-13T22:14:05.772Z] 22:14:05 INFO - GECKO(1759) | ++DOMWINDOW == 1 (0x10c6cf020) [pid = 1763] [serial = 24] [outer = 0x0]
[task 2019-09-13T22:14:05.772Z] 22:14:05 INFO - GECKO(1759) | ++DOMWINDOW == 2 (0x10d02a800) [pid = 1763] [serial = 25] [outer = 0x10c6cf020]
[task 2019-09-13T22:14:05.805Z] 22:14:05 INFO - GECKO(1759) | ++DOMWINDOW == 3 (0x11312dc00) [pid = 1763] [serial = 26] [outer = 0x10c6cf020]
[task 2019-09-13T22:14:05.810Z] 22:14:05 INFO - checking window state
[task 2019-09-13T22:14:05.811Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.811Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.811Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.811Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.811Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.812Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.812Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.812Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.812Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.812Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.812Z] 22:14:05 INFO - GECKO(1759) | JavaScript error: resource:///modules/UrlbarInput.jsm, line 138: TypeError: this.textbox is undefined
[task 2019-09-13T22:14:05.812Z] 22:14:05 INFO - GECKO(1759) | [Parent 1759, Main Thread] WARNING: NS_ENSURE_TRUE(!aStringURI.IsEmpty()) failed: file /builds/worker/workspace/build/src/docshell/base/nsDefaultURIFixup.cpp, line 120
[task 2019-09-13T22:14:05.864Z] 22:14:05 INFO - TEST-START | browser/components/customizableui/test/browser_885530_showInPrivateBrowsing.js

Flags: needinfo?(htwyford)

Harry have you been able to look in to this more?

Priority: -- → P1

It looks like the issue simply stems from how urlbar-container's horizontal margins are now padding. Gijs' other hunch was that the resize/overflow handlers weren't firing but it seems that isn't the case.

Try run with nothing changed: https://treeherder.mozilla.org/#/jobs?repo=try&revision=346d596551fb31e4aefdc8c820f641bf1c653b8&selectedJob=268009689

Try run with the padding turned back into margins: https://treeherder.mozilla.org/#/jobs?repo=try&revision=9502659e5f215dfc9b919a915932e12ed3d027c9&selectedJob=268017206

Jared or Gijs, do you have any recommendations on how to fix this? Gijs mentioned in comment 37 that it might be because the margins would have collapsed before, whereas they can't now. Is there a way to compensate for this effect in either the test or in the customizableui code itself?

Flags: needinfo?(htwyford) → needinfo?(jaws)

tbh I'd see if bug 1580538 accidentally fixed this first, so repush to try but with a more recent m-c revision.

(In reply to Dão Gottwald [::dao] from comment #51)

This is probably fixed judging by https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1536312&startday=2019-09-16&endday=2019-09-24&tree=all

No, the test got disabled before people were pinged. I'm trying to get us to fix the test so we can re-enable it.

Gijs, I think you're right -- looks like bug 1580538 accidentally fixed this. Green try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=4973d8a265b866bf6a5d3b20aadf0a7b6c954e2f. Do you think it's safe to try re-enabling this test again?

Flags: needinfo?(jaws) → needinfo?(gijskruitbosch+bugs)

(In reply to Harry Twyford [:harry] from comment #53)

Gijs, I think you're right -- looks like bug 1580538 accidentally fixed this. Green try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=4973d8a265b866bf6a5d3b20aadf0a7b6c954e2f. Do you think it's safe to try re-enabling this test again?

Yep! Worst that can happen is it gets backed out again and we have to do some more investigation...

Flags: needinfo?(gijskruitbosch+bugs)
Pushed by gijskruitbosch@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/39d672682497
Reenable browser/components/customizableui/test/browser_884402_customize_from_overflow.js on Mac and Windows. r=Gijs
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Depends on: 1580538
Keywords: leave-open
Resolution: --- → FIXED
Whiteboard: [stockwell disabled] → fixed by bug 1580538
Iteration: --- → 71.2 - Sept 16 - 29
Points: --- → 1
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: