Intermittent browser/components/places/tests/browser/browser_stayopenmenu.js | Bookmarks Menu Button's Popup should still be open. -

REOPENED
Unassigned

Status

()

Firefox
Bookmarks & History
P2
normal
REOPENED
5 months ago
2 months ago

People

(Reporter: Treeherder Bug Filer, Unassigned)

Tracking

(Blocks: 1 bug, {intermittent-failure})

unspecified
Unspecified
Mac OS X
intermittent-failure
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox57 disabled, firefox58 disabled)

Details

(Whiteboard: [fxsearch][stockwell disabled])

(Reporter)

Description

5 months ago
treeherder
Filed by: archaeopteryx [at] coole-files.de

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

https://queue.taskcluster.net/v1/task/H2vt-g-ESQGUxZ5F1XHcbw/runs/0/artifacts/public/logs/live_backing.log

This issue already hits both autoland and inbound.

10:04:51     INFO -  947 INFO Entering test bound testStayopenBookmarksClicks
10:04:51     INFO -  Buffered messages logged at 10:04:49
10:04:51     INFO -  948 INFO Popupshown on Bookmarks-Menu-Button
10:04:51     INFO -  Buffered messages logged at 10:04:50
10:04:51     INFO -  949 INFO TEST-PASS | browser/components/places/tests/browser/browser_stayopenmenu.js | Bookmark ctrl-click opened new tab. -
10:04:51     INFO -  Buffered messages logged at 10:04:51
10:04:51     INFO -  950 INFO Console message: [JavaScript Warning: "Unknown property ‘-moz-window-opacity’.  Declaration dropped." {file: "chrome://global/content/xul.css" line: 438}]
10:04:51     INFO -  951 INFO Console message: [JavaScript Warning: "Unknown property ‘-moz-window-transform’.  Declaration dropped." {file: "chrome://global/content/xul.css" line: 439}]
10:04:51     INFO -  952 INFO Console message: [JavaScript Warning: "Unknown property ‘-moz-window-transform’.  Declaration dropped." {file: "chrome://global/content/xul.css" line: 447}]
10:04:51     INFO -  953 INFO Console message: [JavaScript Warning: "Unknown property ‘-moz-window-opacity’.  Declaration dropped." {file: "chrome://global/content/xul.css" line: 451}]
10:04:51     INFO -  954 INFO Console message: [JavaScript Warning: "Unknown property ‘-moz-window-transform’.  Declaration dropped." {file: "chrome://global/content/xul.css" line: 453}]
10:04:51     INFO -  955 INFO Console message: [JavaScript Warning: "Unknown property ‘-moz-window-transform’.  Declaration dropped." {file: "chrome://global/content/xul.css" line: 459}]
10:04:51     INFO -  956 INFO Console message: [JavaScript Warning: "Unknown pseudo-class or pseudo-element ‘-moz-tree-line’.  Ruleset ignored due to bad selector." {file: "chrome://global/content/xul.css" line: 658}]
10:04:51     INFO -  Buffered messages finished
10:04:51    ERROR -  957 INFO TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/browser_stayopenmenu.js | Bookmarks Menu Button's Popup should still be open. -
10:04:51     INFO -  Stack trace:
10:04:51     INFO -  chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_stayopenmenu.js:testStayopenBookmarksClicks:105
Hi custom.firefox.lady, bug 260611 added this tests which fails (relatively) frequent, at least 4 days during the last day on OS X 10.10 debug automation:

https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323

Can you take a look at the issue and maybe fix it, please? Thank you.
Blocks: 260611
Flags: needinfo?(stayopenmenu)
I authored the original tests, but Marco [::mak] and Mark (:standard8) collaborated on making them work with OSX, since I have no access or experience with Mac. (See Bug 260611 comment #123 etc.) So it's unlikely I can be of much help on this, sorry.
Flags: needinfo?(stayopenmenu)
Mark, can you take a look at this, please?
Flags: needinfo?(standard8)

Comment 4

5 months ago
5 failures in 1032 pushes (0.005 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 2
* try: 1
* mozilla-beta: 1
* autoland: 1

Platform breakdown:
* osx-10-10: 5

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323&startday=2017-09-11&endday=2017-09-17&tree=all
At a first look I can't see anything obvious. The screenshot shows the menu as being closed already. My first (and currently only) guess is that removing the tab from behind the scenes might affect the menu in some weird manner, but I'd be surprised based on what I've seen with tests in the past.

The timing of debug builds is unlikely to affect this as everything is happening < 1 second according to the timestamps.

I can see if I can get back to this in a week or two, once 57 items have eased off, although there's more frequent intermittents that we need to fix in the meantime.
Flags: needinfo?(standard8)

Comment 6

5 months ago
25 failures in 943 pushes (0.027 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 11
* mozilla-beta: 8
* mozilla-central: 3
* mozilla-inbound: 2
* try: 1

Platform breakdown:
* osx-10-10: 19
* macosx64-stylo-disabled: 6

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323&startday=2017-09-18&endday=2017-09-24&tree=all

Comment 7

5 months ago
32 failures in 885 pushes (0.036 failures/push) were associated with this bug in the last 7 days.   

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **  

Repository breakdown:
* autoland: 12
* mozilla-beta: 11
* mozilla-inbound: 9

Platform breakdown:
* macosx64-stylo-disabled: 18
* osx-10-10: 14

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323&startday=2017-09-25&endday=2017-10-01&tree=all
Priority: P5 → P2
Whiteboard: [fxsearch]

Comment 8

5 months ago
16 failures in 144 pushes (0.111 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-beta: 7
* autoland: 5
* mozilla-inbound: 4

Platform breakdown:
* osx-10-10: 10
* macosx64-stylo-disabled: 5
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323&startday=2017-10-02&endday=2017-10-02&tree=all
this bug has increased in the last week, all on debug, mostly on osx.

here is a osx debug log:
https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=134824435

and related text to the failure:
20:23:21     INFO - TEST-START | browser/components/places/tests/browser/browser_stayopenmenu.js
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x12797e000 == 39 [pid = 756] [id = {0d9329dd-8ac3-fc4e-b15e-fa38cb87d05d}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x1242cd800 == 38 [pid = 756] [id = {1b4ee6c2-fa6c-4b45-a52f-c6705a8ffd51}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x138d5b000 == 37 [pid = 756] [id = {bcb7ef6e-fda7-a349-86d0-74324515e4c5}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x1396a1800 == 36 [pid = 756] [id = {4d357423-be3c-964d-8b30-229062941762}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x137920000 == 35 [pid = 756] [id = {b3129e00-6ed0-fc44-8f85-bd5b6a0c9c22}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x1394b4800 == 34 [pid = 756] [id = {87c56a9d-1a2f-174a-a29e-ff4e96db9b11}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x116a8c800 == 33 [pid = 756] [id = {ef0da24b-e641-8d4b-aecd-063bae1bfacf}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x12f793800 == 32 [pid = 756] [id = {c08087b9-bd0a-1349-a7bd-253b855b4323}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x1373e2800 == 31 [pid = 756] [id = {4f51d68f-0fae-fa41-a561-5823459e9dda}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x12787b800 == 30 [pid = 756] [id = {b247e50b-68c7-d24a-8d92-866456330019}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x1373f3000 == 29 [pid = 756] [id = {4e4b64ab-0595-a14d-b73f-6bfcbfc07f7e}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x1373e1800 == 28 [pid = 756] [id = {bd606238-ce9d-c74d-8898-ba3f94ae94a0}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x127869000 == 27 [pid = 756] [id = {00348339-71fc-814a-8673-08d466175a37}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x137911000 == 26 [pid = 756] [id = {1a7d9ecf-5c01-0f49-93e2-46562081e3d1}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x123daa800 == 25 [pid = 756] [id = {1b272d92-872e-bc43-a672-f584bd1cb6a6}]
20:23:22     INFO - GECKO(756) | --DOCSHELL 0x12d3e0000 == 24 [pid = 756] [id = {a6f3b5c1-7013-4742-816c-cb7533a145a0}]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 141 (0x11a675000) [pid = 756] [serial = 54] [outer = 0x0] [url = about:blank]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 140 (0x118375000) [pid = 756] [serial = 68] [outer = 0x0] [url = about:blank]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 139 (0x1172e5000) [pid = 756] [serial = 46] [outer = 0x0] [url = about:blank]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 138 (0x1289bf000) [pid = 756] [serial = 64] [outer = 0x0] [url = about:blank]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 137 (0x1288d8800) [pid = 756] [serial = 41] [outer = 0x0] [url = about:blank]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 136 (0x124b3c800) [pid = 756] [serial = 24] [outer = 0x0] [url = about:blank]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 135 (0x1252e8800) [pid = 756] [serial = 39] [outer = 0x0] [url = chrome://browser/content/bookmarks/bookmarksPanel.xul]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 134 (0x12f613800) [pid = 756] [serial = 14] [outer = 0x0] [url = about:blank]
20:23:22     INFO - GECKO(756) | --DOMWINDOW == 133 (0x122385800) [pid = 756] [serial = 16] [outer = 0x0] [url = about:blank]
20:23:23     INFO - GECKO(756) | --DOMWINDOW == 5 (0x129109800) [pid = 758] [serial = 55] [outer = 0x0] [url = about:blank]
20:23:23     INFO - GECKO(756) | --DOMWINDOW == 4 (0x1222c4000) [pid = 758] [serial = 53] [outer = 0x0] [url = about:blank]
20:23:23     INFO - GECKO(756) | ++DOCSHELL 0x120434800 == 2 [pid = 758] [id = {55fa7990-114d-7942-b474-2dd4b3283c24}]
20:23:23     INFO - GECKO(756) | ++DOMWINDOW == 5 (0x1206d0000) [pid = 758] [serial = 60] [outer = 0x0]
20:23:23     INFO - GECKO(756) | ++DOMWINDOW == 6 (0x128b07000) [pid = 758] [serial = 61] [outer = 0x1206d0000]
20:23:23     INFO - GECKO(756) | [Parent 756, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file /builds/worker/workspace/build/src/netwerk/base/nsChannelClassifier.cpp, line 344
20:23:23     INFO - GECKO(756) | ++DOMWINDOW == 7 (0x117d20800) [pid = 758] [serial = 62] [outer = 0x1206d0000]
20:23:23     INFO - GECKO(756) | --DOCSHELL 0x129078800 == 1 [pid = 758] [id = {c861fe8a-cc38-8945-8d48-d9da570c90f4}]
20:23:24     INFO - TEST-INFO | started process screencapture
20:23:24     INFO - TEST-INFO | screencapture: exit 0
20:23:24     INFO - Buffered messages logged at 20:23:21
20:23:24     INFO - Entering test bound test_setup
20:23:24     INFO - Bookmarks toolbar made visible
20:23:24     INFO - Leaving test bound test_setup
20:23:24     INFO - Entering test bound testStayopenBookmarksClicks
20:23:24     INFO - Buffered messages logged at 20:23:22
20:23:24     INFO - Popupshown on Bookmarks-Menu-Button
20:23:24     INFO - Buffered messages logged at 20:23:23
20:23:24     INFO - TEST-PASS | browser/components/places/tests/browser/browser_stayopenmenu.js | Bookmark ctrl-click opened new tab. - 
20:23:24     INFO - Buffered messages finished
20:23:24     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/browser_stayopenmenu.js | Bookmarks Menu Button's Popup should still be open. - 
20:23:24     INFO - Stack trace:
20:23:24     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_stayopenmenu.js:testStayopenBookmarksClicks:105
20:23:24     INFO - GECKO(756) | --DOMWINDOW == 132 (0x12c849800) [pid = 756] [serial = 89] [outer = 0x0] [url = about:mozilla]
20:23:24     INFO - GECKO(756) | --DOMWINDOW == 131 (0x1298dc800) [pid = 756] [serial = 132] [outer = 0x0] [url = about:buildconfig]


I don't think the log is a lot of help necessarily, but I do see some info statements that might help pinpoint the problem.

:standard8, is this something you could help set the proper priority and ensure the right developer(s) knows about this?
Flags: needinfo?(standard8)
Whiteboard: [fxsearch] → [fxsearch][stockwell needswork]
The logs aren't useful, the only thing I can think of is timing. I'm not sure it increased, but maybe a peak.

Might be better for someone who knows a bit more about the menu system to take a look at this. I'll pass it onto Panos.
Flags: needinfo?(standard8) → needinfo?(past)
I believe Paolo has some experience there. Could you please take a look?
Flags: needinfo?(past) → needinfo?(paolo.mozmail)

Comment 12

4 months ago
55 failures in 824 pushes (0.067 failures/push) were associated with this bug in the last 7 days. 

This is the #39 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **  

Repository breakdown:
* autoland: 23
* mozilla-beta: 17
* mozilla-inbound: 14
* mozilla-central: 1

Platform breakdown:
* osx-10-10: 34
* macosx64-stylo-disabled: 20
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323&startday=2017-10-02&endday=2017-10-08&tree=all

Comment 13

4 months ago
So, this fails almost exclusively on OS X 10.10. Like Mark, I've looked at the test and it seems correct in when and how it waits for events to happen.

The only thing that comes to my mind is that a background event in the operating system is causing all popups to be closed at a random point. In this case, I don't know if there is anything we can do in the code, but Neil may remember if he's ever observed anything similar with popups in infrastructure before.
Flags: needinfo?(paolo.mozmail) → needinfo?(enndeakin)
OS: Unspecified → Mac OS X

Comment 14

4 months ago
When I debug this, it suggests that the popup is closing due to the menuitem being clicked with the mouse. This is what the test appears to be testing, so that behaviour is correct. The bug that added this 260611 suggests that it is modifying how the menus close when their items are clicked.

Note also bug 1401364 where this same test times out. That test timeout is easy to reproduce.

Also, this suspicious bit of code from the original bug:

setTimeout(() => {
        target.removeAttribute("closemenu");
}, 500);

I didn't look at it in detail but I would guess that patch in bug 260611 isn't correct.
Flags: needinfo?(enndeakin)
(In reply to Neil Deakin from comment #14)
> The bug that added this 260611 suggests that
> it is modifying how the menus close when their items are clicked.

Right, we don't want to close the menu when one of its items is opened in a new tab by any means.

> Also, this suspicious bit of code from the original bug:
> 
> setTimeout(() => {
>         target.removeAttribute("closemenu");
> }, 500);

That was indeed added to try to workaround a Macos problem, it looks like there is a long timeout between the click event and the time at which the menus are actually auto-closed, that on other platforms doesn't exist.
Though, it's indeed possible that same timeout is the cause of this intermittent, we should probably wait for the attribute to be removed before moving to the next test?

> I didn't look at it in detail but I would guess that patch in bug 260611
> isn't correct.

we're happy to evaluate alternatives if you can suggest a different approach. We want to be able to control whether the menus should close or not, but at the same time, making closing popups completely "manual" looks scary, so the bug retained the usual behavior, and disabled auto closing when the pref if set and the items are opened in a new tab.
(In reply to Marco Bonardo [::mak] from comment #15)
> > Also, this suspicious bit of code from the original bug:
> > 
> > setTimeout(() => {
> >         target.removeAttribute("closemenu");
> > }, 500);
> 
> That was indeed added to try to workaround a Macos problem, it looks like
> there is a long timeout between the click event and the time at which the
> menus are actually auto-closed, that on other platforms doesn't exist.
> Though, it's indeed possible that same timeout is the cause of this
> intermittent, we should probably wait for the attribute to be removed before
> moving to the next test?

> we're happy to evaluate alternatives if you can suggest a different
> approach.

*If* the problem is that the timeout is not always long enough, I'd like to get your opinion on an alternative. I was thinking that there's really no rush to remove the attr as long as we're doing the correct thing for the user. So maybe adding:

if (!modiKey) {
  target.removeAttribute("closemenu");
}

to onMouseUp

while deleting that attr removal code (including the timeout) from onClick might be feasible. (It would not necessarily remove the attr from the same menuitem we previously set it on, just ensure it is not present when the menu should close.) But I don't know how the bookmark menus get built/rebuilt. Once the menu chain is closed, we don't want to leave incorrect closemenu attr's lying around (especially since the user may change the pref). If the menu gets rebuilt to its default state next time it's opened, it doesn't really matter. This approach might be too close to "brute forcing" for your comfort; just throwing the idea on the table.
Flags: needinfo?(mak77)

Comment 17

4 months ago
I didn't actually look at the code in detail; I only noticed that a timeout was added by that bug which generally raises red flags when tests fail intermittently. But I have now looked at it in more detail.

If the test is relying on clicking on several menuitems in sequence while timers are occurring that change the closemenu attribute, then that sounds like an issue if you aren't waiting for those timers. It could, for instance, run the entire test and then fire the timers all at once. Or, several of them could run in quick succession while a test step in occurring. Meaning that the closemenu attribute could change at any time.

Within the menu code, the closemenu attribute is checked after the menu has finished blinking but before the popup has started hiding. I would suggest instead just resetting the closemenu attribute during the popuphiding or popuphidden event rather than using a timer.

Comment 18

4 months ago
43 failures in 947 pushes (0.045 failures/push) were associated with this bug in the last 7 days.   

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **  

Repository breakdown:
* mozilla-inbound: 15
* autoland: 14
* mozilla-beta: 8
* mozilla-central: 5
* try: 1

Platform breakdown:
* macosx64-stylo-disabled: 22
* osx-10-10: 21

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323&startday=2017-10-09&endday=2017-10-15&tree=all

Comment 19

4 months ago
31 failures in 864 pushes (0.036 failures/push) were associated with this bug in the last 7 days. 

This is the #47 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **  

Repository breakdown:
* autoland: 12
* mozilla-inbound: 10
* mozilla-beta: 6
* mozilla-central: 3

Platform breakdown:
* macosx64-stylo-disabled: 16
* osx-10-10: 15

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323&startday=2017-10-16&endday=2017-10-22&tree=all
This test keeps failing.
::mak, do you think you can look into this?
(In reply to custom.firefox.lady from comment #16)
> *If* the problem is that the timeout is not always long enough, I'd like to
> get your opinion on an alternative.

comment 17 has one involving popuphiding. But I don't recall if we already investigated that originally.

The problem is not "long" timeouts, the problem is the test doesn't wait for any of these timeouts, and thus it can easily fail when they don't fire as (not) expected.

> But I don't know how the bookmark menus get
> built/rebuilt. Once the menu chain is closed, we don't want to leave
> incorrect closemenu attr's lying around 

Right. IIRC the bookmarks popups are never destroyed/rebuilt, but most often just updated.
(In reply to Henrietta Maior [:henrietta_maior] from comment #20)
> This test keeps failing.
> ::mak, do you think you can look into this?

I think we should temporarily disable the test on macosx. The reason of the failure is known, we just don't have resources to fix it properly for now.
Flags: needinfo?(mak77)

Comment 23

4 months ago
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/511604f49a82
Disable test browser_stayopenmenu.js on osx/debug for on-going intermittent failures; r=me,test-only
https://hg.mozilla.org/mozilla-central/rev/511604f49a82
Status: NEW → RESOLVED
Last Resolved: 4 months ago
status-firefox58: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 58
status-firefox57: --- → affected
This is not fixed, it's just disabled, right?
Status: RESOLVED → REOPENED
status-firefox58: fixed → disabled
Resolution: FIXED → ---
Whiteboard: [fxsearch][stockwell needswork] → [fxsearch][stockwell disabled]
yes, this is correct- we should have marked the bug as leave-open
https://hg.mozilla.org/releases/mozilla-beta/rev/5c30a6ef0888
status-firefox57: affected → disabled
Target Milestone: Firefox 58 → ---

Comment 28

4 months ago
28 failures in 912 pushes (0.031 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 13
* mozilla-beta: 8
* mozilla-inbound: 5
* try: 1
* mozilla-central: 1

Platform breakdown:
* osx-10-10: 18
* macosx64-stylo-disabled: 10

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1400323&startday=2017-10-23&endday=2017-10-29&tree=all
You need to log in before you can comment on or make changes to this bug.