625149 - With "unclutter" tool running: sometimes when AwesomeBar dropdown appears, keyboard starts being ignored, with "ASSERTION: Unexpected focus on a popup window: 'mWindowType != eWindowType_popup', file widget/src/gtk2/nsWindow.cpp, line 2855"

Status: RESOLVED WONTFIX

(Core :: Widget: Gtk, defect)

Description

[Daniel Holbert [:dholbert]]

STEPS TO REPRODUCE:
 1. Start up a firefox debug build with a fresh profile.  (Keep your terminal somewhere where you can see any assertions scroll by.)
 2. Click away any 'default browser' dialogs.
 3. Ctrl+L to focus URL bar
 4. Type the single character "a"
      --> Frequently, I see an assertion as the awesomebar popup appears
 5. (if you got an assertion) hit Backspace, & then try to type another char

ACTUAL RESULTS:
 * It's somewhat sporadic, but pretty frequently I see this after Step 4:
> ###!!! ASSERTION: Unexpected focus on a popup window: 'mWindowType != eWindowType_popup', file ../../../../mozilla/widget/src/gtk2/nsWindow.cpp, line 2855
 * When that assertion happens, the "Backspace" in step 5 works, but any other typing *after* that does NOT work.  Moreover, keyboard combinations seem to become *completely* ignored at that point -- Ctrl+L, Alt+F, etc.  Only OS-level keyboard combinations work  (e.g. Alt+Tab)
 * Once I alt-tab away and back, things work as expected. (though I can repeat the STR to cause bustage again)

I'm guessing the issue is that some hidden popup window (the AwesomeBar dropdown?) unintentionally gets focus (per the assertion), retains it after it disappears, and sucks up all keyboard events from that point on (until I give focus back to Firefox with Alt+Tab, Alt+Tab).

NOTE: I actually have been hitting this bug (or something like it) for a while quite frequently in nightly builds, when typing URLs in URL bar -- basically the keyboard becomes completely broken at some point soon after the AwesomeBar dropdown appears.  It's a pretty huge usability problem when it manifests.  I'm also pretty sure this is a regression w.r.t. Firefox 3.6.x

Comment 1

[Daniel Holbert [:dholbert]]

> The "Backspace" in step 5 works, but any other
> typing *after* that does NOT work.  Moreover, keyboard combinations seem to
> become *completely* ignored at that point -- Ctrl+L, Alt+F, etc.

From a (keyboard-loving) user's perspective, this has the effect of completely locking up Firefox (until the user manually changes focus), since Firefox apparently stops listening to keyboard commands.

This is on Linux (Ubuntu 10.10) with an up-to-date mozilla-central debug build
(at revision http://hg.mozilla.org/mozilla-central/rev/ae4ee53297b0 )

Comment 2

[Daniel Holbert [:dholbert]]

Attachment: backtrace when assertion fires

Comment 3

[Daniel Holbert [:dholbert]]

(In reply to comment #0)
> STEPS TO REPRODUCE:
>  1. Start up a firefox debug build with a fresh profile.

(doesn't have to be a fresh profile -- just mentioned that because I was able to reproduce it with a fresh profile, as well as existing profiles)

Comment 4

[Timothy Nikkel (:tnikkel)]

Now that you mention it I have seen some weird keyboard behaviour involving the awesome bar recently (Ubuntu 10.04).

Comment 5

[Daniel Holbert [:dholbert]]

I'm pretty sure I've seen it with AwesomeComplete, too (autocomplete popups on basic text fields).

Comment 6

[Daniel Holbert [:dholbert]]

Attachment: slightly different backtrace from today

I've got this assertion caught in GDB right now and I'm seeing what I can find... The backtrace is slightly different from before.  This one has a layer of "js::RunScript" which I've determined is Sync, which I think ends up spinning the event loop...  (at least one level in the stack is for a call to Utils.delay*) -- so I think all that JS code in this stack can basically be ignored.

http://mxr.mozilla.org/mozilla-central/source/services/sync/modules/util.js#1109

Comment 7

[Daniel Holbert [:dholbert]]

So stacklevel 19 in my just-attached backtrace...
> #19 0x00007f0fc4a376df in gtk_widget_event_internal (widget=0x..., event=0x...)
... is the topmost level that deals with a GtkWidget.

At that point, the argument |widget| is a popup, according to gdb:
> (gdb) p get_window_for_gtk_widget(widget)->mWindowType
> $32 = eWindowType_popup
and the |event| is a focus-change:
> (gdb) p event->type
> $33 = GDK_FOCUS_CHANGE

That's not particularly surprising, but it does mean there's probably nothing worth looking at in the GTK stack between levels 19 and 2.

Comment 8

[Daniel Holbert [:dholbert]]

tn points out that the failing assertion was added in bug 526941, here:
  http://hg.mozilla.org/mozilla-central/rev/6811406f7845

Comment 9

[Daniel Holbert [:dholbert]]

Karl & Enn, any tips you could offer on any of the following points would be much appreciated:
 - why don't we allow focus in popup windows? (per the assertion here)
 - how is that supposed to be prevented?
 - how might we be getting around that prevention & hitting this bug?

Comment 10

[Neil Deakin]

(In reply to comment #9)
> Karl & Enn, any tips you could offer on any of the following points would be
> much appreciated:
>  - why don't we allow focus in popup windows? (per the assertion here)

Popups are always associated with a parent window that is focused.

Note that 'focus' here generally means 'is active'. Autocomplete windows do not have titlebars are thus cannot be active; the main window always remains active. 

>  - how is that supposed to be prevented?

The call to gtk_window_set_accept_focus() presumably.

>  - how might we be getting around that prevention & hitting this bug?

When does this assertion happen in relation to other code being called in nsWindow? (Create, Show, the various *_grab*() calls, ...)

If you enable logging you should be able to get some useful info here.

You're using the default window manager?

Comment 11

[Karl Tomlinson (:karlt)]

(In reply to comment #9)
> Karl & Enn, any tips you could offer on any of the following points would be
> much appreciated:
>  - why don't we allow focus in popup windows? (per the assertion here)
>  - how is that supposed to be prevented?

I assume the autocomplete window is a not a noautohide window, so it would be type GTK_WINDOW_POPUP which is "override-redirect", meaning that the window manager does not interact with the window.  Such windows only receive focus if the app requests focus on the window, which we should not be doing.

GDK widens the concept of focus a bit and so keyboard grabs also change GDK's concept of the focus widget.  However, all our popups should have mTransientParent set and so the grab should happen on the parent window.

NSPR_LOG_MODULES=Widget:5,WidgetFocus:5 may give some useful output.

Comment 12

[Karl Tomlinson (:karlt)]

This assertion was also reported in bug 545429 comment 7.

Comment 13

[Karl Tomlinson (:karlt)]

Comment on attachment 503249 [details]
backtrace when assertion fires

>(gdb) bt
>#0  nsWindow::OnContainerFocusInEvent (this=0x7f610fdb0a00, aWidget=0x7f610cfd7b00, aEvent=0x7f61087280b0) at ../../../../mozilla/widget/src/gtk2/nsWindow.cpp:2854
>#1  0x00007f61216c0010 in focus_in_event_cb (widget=0x7f610cfd7b00, event=0x7f61087280b0) at ../../../../mozilla/widget/src/gtk2/nsWindow.cpp:5690

>#40 0x00007f6132febe8b in IA__gtk_widget_show (widget=0x7f610dabe4c0) at /build/buildd/gtk+2.0-2.22.0/gtk/gtkwidget.c:3214
>#41 0x00007f61216bcdcc in nsWindow::NativeShow (this=0x7f610fdb0a00, aAction=1) at ../../../../mozilla/widget/src/gtk2/nsWindow.cpp:4372

This first stack looks a bit strange.  The focus-in signal should only be received if the toplevel window is active.
I don't know how the window could be active before it is shown, unless this is not the first time it is shown.

Comment 14

[Daniel Holbert [:dholbert]]

Thanks for the info, guys.

(In reply to comment #10)
> You're using the default window manager?

Yes. (Ubuntu 10.10, with Compiz enabled (as it is by default)).

(In reply to comment #13)
> I don't know how the window could be active before it is shown,
> unless this is not the first time it is shown.

I don't remember in that specific instance whether it was the first time it was shown.  (However, sometimes when the assertion fires, it is the first time the window is shown, as in Comment 0.)

Tomorrow I'll try running with the NSPR_LOG_MODULES setting from Comment 11, to hopefully hit this again and get some more context.

Comment 15

[Daniel Holbert [:dholbert]]

Attachment: backtrace #3

I've been trying to reproduce this all day - but sadly the one time that I've hit it so far was in a browsing session that didn't have the extra logging enabled.  (I was briefly trying to hit a different bug... and of course that's when I hit _this_ bug. :))

Here's the backtrace from that instance anyway, for the heck of it, since it's slightly different (much shallower) than the previously-attached backtraces.

This backtrace was captured from a browsing session that basically followed Comment 0 exactly -- I started up Firefox with a near-fresh profile, did |Ctrl+L| to focus the awesomebar, started typing a URL, and *bam* I hit this assertion.

Comment 16

[Daniel Holbert [:dholbert]]

karlt has been doing some 1337 remote debugging on my machine, and (among other things) we've determined the following:
 - It seems the cursor needs to be hovering over the rect that the awesomebar will occupy, in order to trigger this bug.
 - This bug is reproducible under both compiz and metacity.
 - The env var "GDK_NATIVE_WINDOWS=1" prevents this bug from occurring (at least under metacity -- presumably under compiz as well).

Comment 17

[Karl Tomlinson (:karlt)]

> 000:>:0983: Event LeaveNotify(8) detail=Inferior(0x02) mode=Normal(0x00) flags=same-screen time=0x0013e007 root=0x0000015a event=0x04a002bb child=None(0x00000000) root-x=2565 root-y=652 event-x=329 event-y=7 state=0

This is a real event from the X server.
detail=Inferior means that focus has moved to a descendant window.
I'd like to know who has created this window, if such a window really exists.

> 000:>:0983: Event (generated) EnterNotify(7) detail=Ancestor(0x00) mode=Normal(0x00) flags=focus,same-screen time=0x00000000 root=0x0000015a event=0x04a002bb child=None(0x00000000) root-x=2565 root-y=652 event-x=329 event-y=7 state=0

Then this is a synthetic event.  The lack of a SendEvent request logged from
this client implies that this event is sent from a different client.
Apparently it is trying to trick the app into thinking that the mouse is still
over the app's window.

However, the focus field of the event is incorrectly always set even if the
window is neither the focus window nor an inferior of the focus window.  Also
the detail=Ancestor is confusing because it says that the mouse has come from
an ancestor window (when really it moved to a descendant window).  The
combination of these factors confuses GDK into thinking the window has focus.

xdpyinfo indicates that the window does not have focus.
xwininfo doesn't see this child window (so either it never existed or has disappeared).

I can't see any code in metacity or compiz that sends this (and I don't see
this behavior with metacity here), so I'm wondering if there could be some
window decorator or theme or mouse-grabbing/tracking client or strange X
extension or something else interfering here.

Comment 18

[Karl Tomlinson (:karlt)]

Attachment: SendEvent watcher

This program uses the RECORD extension to track which clients are sending
synthesized events.  Use Ctrl-C to terminate.

Start the program then reproduce this bug (or maybe just move the mouse
between windows) and hopefully the program will print some lines containing
"event type 7" (for EnterNotify).  Match the corresponding client id printed
with a res_base from the output of "xrestop -b -m 1", and we might get some
info on what is sending the bogus EnterNotify events.

Comment 19

[Daniel Holbert [:dholbert]]

Ok -- with more help from karl, we determined that there was a program creating a 1x1 transparent window as a child of any window that I hovered my mouse over.

It turns out that program was "unclutter", a tool to hide your cursor when you're idle.  (I have no recollection of installing it, but I must have manually installed it at some point, since it's not a default package.)

"unclutter" seems to be both necessary & sufficient to trigger this bug. I booted in a Ubuntu 10.10 LiveCD environment (read: "clean room"), and I verified that I *can* reproduce this bug when unclutter is installed & running (2 out of 5 tries), whereas I *cannot* reproduce when unclutter is not running (0 out of ~15 tries).

The above testing was with an existing mozilla-central debug build, located on a partition that I mounted while booted to the LiveCD, FWIW.

So: this is arguably still a Gecko bug in the same way that bug 594977 is a Gecko bug -- but happily it's a bug that should affect only a very, very small proportion of our users.[1]  It's also a bug for which there's a simple and not-particularly-painful workaround (disable unclutter).  So this bug should remain open, but it certainly doesn't need to block.

[1] http://popcon.ubuntu.com/main/by_inst has numbers to show that only 0.22% of Ubuntu users have unclutter installed. http://qa.debian.org/popcon.php?package=unclutter says that 0.53% of debian users have it installed.  (These stats are among users who've opted in to running "popularity-contest", who I'd assume are the more "power-user" types and are probably more likely to run niche tools like unclutter.  So the percentage among general users is likely to be even lower.)

Comment 20

[Daniel Holbert [:dholbert]]

unassigning myself, since this is no longer blocking per previous comment.

If this ever ends up getting fixed, it'll probably need attention from someone with some serious GTK-fu.

Comment 21

[Karl Tomlinson (:karlt)]

I actually doubt we'd want to fix this in Gecko, as it would be non-simple and possibly detrimental.  unclutter is open source so it would make more sense to correct the focus and detail fields of the synthetic EnterNotify event sent from clutter.