Closed Bug 1396196 Opened 7 years ago Closed 23 days ago

Intermittent browser/components/customizableui/test/browser_editcontrols_update.js | single tracking bug

Categories

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

Product:
Firefox
Component:
Toolbars and Customization
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [stockwell unknown])

Attachments

(1 obsolete file)

https://wiki.mozilla.org/Bugmasters#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Looks to me like this is now effectively permafailing on macOS after bug 1486824 landed.
Assignee: nobody → gijskruitbosch+bugs
Blocks: 1486824
Status: REOPENED → ASSIGNED
Keywords: leave-open
After the changes to window opening code, initial focus is now in the URL bar. The test (on macOS) expects some update to happen to the state of the edit controls once the URL bar is focused. But because it is now initially focused, that state change doesn't happen. This patch fixes that issue by forcing focus to go to the selected tab first.
Attachment #9005169 - Attachment is obsolete: true
Assignee: gijskruitbosch+bugs → nobody
Status: ASSIGNED → NEW
No longer blocks: 1486824
This was all because of the first landing of bug 1486824, so downprio'ing again.
Priority: -- → P5
Whiteboard: [stockwell needswork:owner]

This bug failed 37 times in the last 7 days. Occurs on Linux32 and Linux64 on opt and pgo build type.

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

Flags: needinfo?(gijskruitbosch+bugs)

This bug has failed 46 times in the last 7 days. Occurs on linux32 and linux64 pgo and opt build type.

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=228497978&repo=mozilla-inbound&lineNumber=2451

https://treeherder.mozilla.org/#/jobs?repo=try&revision=3092428cbf12b46270fef97370727d7a4c6bb089&selectedJob=229080382 This didn't seem to help... will need to add some debug logging to find out why the popup is being dismissed or not shown or whatever.

So it seems we sometimes get a focus change notification from the OS that prompts us to close the popup:

[task 2019-02-19T16:27:12.526Z] 16:27:12 INFO - GECKO(3596) | #01: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x2cbdf7f]
[task 2019-02-19T16:27:12.527Z] 16:27:12 INFO - GECKO(3596) | #02: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x2cc1457]
[task 2019-02-19T16:27:12.527Z] 16:27:12 INFO - GECKO(3596) | #03: ???[/usr/lib/x86_64-linux-gnu/libgtk-3.so.0 +0x212fac]
[task 2019-02-19T16:27:12.528Z] 16:27:12 INFO - GECKO(3596) | #04: g_closure_invoke[/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0 +0xffa5]
[task 2019-02-19T16:27:12.528Z] 16:27:12 INFO - GECKO(3596) | #05: ???[/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0 +0x21fc1]
[task 2019-02-19T16:27:12.528Z] 16:27:12 INFO - GECKO(3596) | #06: g_signal_emit_valist[/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0 +0x2a7f9]
[task 2019-02-19T16:27:12.529Z] 16:27:12 INFO - GECKO(3596) | #07: g_signal_emit[/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0 +0x2b08f]
[task 2019-02-19T16:27:12.529Z] 16:27:12 INFO - GECKO(3596) | #08: ???[/usr/lib/x86_64-linux-gnu/libgtk-3.so.0 +0x350c3c]
[task 2019-02-19T16:27:12.529Z] 16:27:12 INFO - GECKO(3596) | #09: gtk_widget_send_focus_change[/usr/lib/x86_64-linux-gnu/libgtk-3.so.0 +0x36103e]

Unfortunately stack symbols on infra are busted for libxul, see bug 1528668, but the gtk stuff paints a clear enough picture; this is the top of output from a stack dump from nsXULPopupManager::HidePopup(nsIContent* aPopup, bool aHideChain, bool aDeselectMenu, bool aAsynchronous, bool aIsCancel, nsIContent* aLastPopup).

I don't really understand this; we wait for the window to be focused as part of harness start up. I tried making it also wait for window activation, but the intermittent still happens.

Neil, do you know what would be the source of these focus events / what we should be waiting for instead? Thanks.

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

At which point within the test does stack described get hit? HidePopup won't be called unless a popup is open, so I'm assuming part of the test has already run? Do you know which window/widget the gtk focus signal is being sent to?

Can I reproduce this on try just by running it multiple times? Perhaps I can add some debugging.

Flags: needinfo?(enndeakin)

(In reply to Neil Deakin from comment #52)

At which point within the test does stack described get hit?

Looking at the failures from orangefactor and where we time out, either when attempting to open the popup here:

https://searchfox.org/mozilla-central/rev/b36e97fc776635655e84f2048ff59f38fa8a4626/browser/components/customizableui/test/browser_editcontrols_update.js#55

or here:

https://searchfox.org/mozilla-central/rev/b36e97fc776635655e84f2048ff59f38fa8a4626/browser/components/customizableui/test/browser_editcontrols_update.js#66

I think. In the log I linked in comment 51, I think it's the second, because the initial opening/closing of the popup worked. The CUI test helper does some assertions that show up in the test log (cf. https://searchfox.org/mozilla-central/source/browser/components/customizableui/test/CustomizableUITestUtils.jsm#34 ) that you can use to correlate to the stdout logging from WalkTheStack.

HidePopup won't be called unless a popup is open, so I'm assuming part of the test has already run? Do you know which window/widget the gtk focus signal is being sent to?

No, I'm afraid not, but I can only assume it's the parent process (because the child process can't be calling hidepopup) and the main browser window (because that's where the popup is). Are there other options?

Can I reproduce this on try just by running it multiple times? Perhaps I can add some debugging.

That would be a great help, yes. linux32 opt and linux64 opt/pgo see this fairly regularly though you probably need some retriggers still. --rebuild 10 or whatever in the try syntax will save you some clicking.

My debugging and testing here shows that the following happens:

  1. The browser-harness.xul window is created and opened.
  2. A window lowered type of event is sent from the system indicating that the main browser window browser.xul is lowered.
  3. The browser-harness believes that the browser-harness.xul window is not yet focused, so it requests that browser-harness.xul be focused.
  4. The focus change to browser-harness.xul happens, then the test harness continues, focuses the test window again, then starts running the test
  5. The system sends the window raised event for browser-harness.xul that it never got to send out yet from step 2.
  6. The test stops and fails as we now believe that browser-harness.xul is supposed to be focused.

When successful, step 5 happens immediately after step 2 and no confusion happens.

Flags: needinfo?(gijskruitbosch+bugs)

(In reply to Neil Deakin from comment #55)

My debugging and testing here shows that the following happens:

  1. The browser-harness.xul window is created and opened.
  2. A window lowered type of event is sent from the system indicating that the main browser window browser.xul is lowered.
  3. The browser-harness believes that the browser-harness.xul window is not yet focused, so it requests that browser-harness.xul be focused.
  4. The focus change to browser-harness.xul happens, then the test harness continues, focuses the test window again, then starts running the test
  5. The system sends the window raised event for browser-harness.xul that it never got to send out yet from step 2.
  6. The test stops and fails as we now believe that browser-harness.xul is supposed to be focused.

When successful, step 5 happens immediately after step 2 and no confusion happens.

FWIW, I'm having trouble reconciling this with your comment in bug 1523234 that "focus always happens after activate". It seems that once focus moves around a bit, events happen in any which order GTK fancies (in particular, (5) is a window raise event that happens after a focus event that happens after the original focus event that tripped the window lowering event on the other window that corresponds to our window being raised)... :-(

What's the right solution here? From your description, it sounds like the checks for (3) are wrong (ie we're determining that we're not yet focused, but we really are, or something?). Or at least, perhaps we could avoid explicitly asking for the harness to be focused. But perhaps I'm misreading this...

Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(enndeakin)
Priority: -- → P5
Flags: needinfo?(enndeakin)
Severity: normal → S3
Keywords: intermittent-testcase
Summary: Intermittent browser/components/customizableui/test/browser_editcontrols_update.js | Test timed out - → Intermittent browser/components/customizableui/test/browser_editcontrols_update.js | single tracking bug

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

Status: NEW → RESOLVED
Closed: 7 years ago → 4 months ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=487995224&repo=try

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

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

Attachment

General

Creator:
Created:
Updated:
Size: