Xpra: Ticket #469: Focus issue with mouse on osx client

With osx client r4905 mouse cursor focus seems to become confused when there is a single click on an xpra session window overlapping a second xpra session window.

Testing with windows client (0.11.0r4903) against a fedora 19 server (0.11.0r4904) the erratic cursor/focus behavior does not occur.

In the edited logs that I included in #438 (I'll load those logs into this ticket when I get a chance), there is an initial focus on window 55 (first drawn on line 31 of the log, comes into focus line 139), followed by a focus shift to window 82 (first drawn on line 43, comes into initial focus on line 157, I think)... then there follows what I assume are indications of mouse-wheel scrolling events occurring on window 55 (lines 174 on). That is the 'event'. The logs aren't clear that focus shifted to window 82, from what I can tell, but what I did was to click on 55, then click 82, then click 82 again on a portion of the window which, once 82 'rose' to focus, was now overlapping 55. From then on, I never clicked on window 55 again, nor did I scroll the mouse off of window 82. From the point of line 157 in the log on, my cursor remained hovering over window 82 ... but the mouse scrolling events all seem to register on the lower window (55) despite the appearance of focus being on window 82. Testing this with xterms showed that the keystrokes would register on the apparently focused window, but also that clicking on a portion of an 'upper' window (with apparent focus) which was 'above' a window space with a link would trigger the link 'through' the apparent-focus window.



Wed, 11 Dec 2013 22:29:16 GMT - alas: attachment set

Edited output from cursor/window focus issue


Wed, 11 Dec 2013 22:29:54 GMT - alas: attachment set

Full -d all output (--no-speaker) of cursor/window focus test


Thu, 12 Dec 2013 02:07:29 GMT - Antoine Martin: owner, status changed

Moving text from wrong ticket, afarr wrote: "It looks like window focus, as far as the cursor is concerned, is being confused when one xpra session window overlaps another xpra session window (have only tested so far with osx).

If there is an xterm overlapping a chrome window, and the focus is on the chrome window, then the mouse scrolls over to a portion of the xterm window which overlaps the chrome window and the mouse is clicked- then the mouse focus returns to the chrome window (the window that previously had focus) while the focus for the keyboard (as well as the moving to the 'front' display) shifts to the xterm (the window newly clicked on).

At this point, the cursor will display as it would in the window with the cursor focus, the mousewheel will scroll the window with the cursor focus, and clicking will activate any links on the window with the cursor focus ... while keystrokes will register on the top-displayed window which 'should' have focus. (In the case of the example above, keystrokes will register on the xterm that is 'above' the chrome window, while wheel scrolling or link clicking will register on the chrome window which is 'below' the xterm.

Repeating the experiment in various permutations shows the same behavior... shifting from an xterm to a chrome window will reverse the above described behavior; shifting from a firefox window to a chrome window will result in the same behavior, etc.

I am not sure if it is a coincidence, but this seems to be similar to the behavior with pop-up menu behaviors."


Is this a regression? - I am not sure, to be honest. It seems to remain an issue specific to the osx client


Partial answer: "It may be a case of focus-follows-mouse, which may or may not be a bug. OTOH: the top-level window should always have keyboard focus and receive key events (even when the mouse is somewhere else - local platform event delivery allowing), but mouse-wheel and key modifier changes can be delivered to non-top-level windows without raising them to the top."


Thu, 13 Feb 2014 14:46:09 GMT - Antoine Martin: owner, status changed

r5444 adds focus debugging loggers, which means we can get all the focus debug logging (and nothing else), by starting both the client and server with:

xpra -d focus ...

Please post logs of the problematic behaviour, and doing exactly the same thing but on a machine which does not exhibit the problem, hopefully we can spot the difference.

Note: this may also be related to #214, worth checking.


Fri, 14 Feb 2014 00:28:43 GMT - alas:

Did the following:

xpra info | grep window
window[1].focused=False
window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[2].focused=False
window[2].position=(1227, 490)
window[2].title=jimador@elpatron:~
window[3].focused=False
window[3].position=(0, 44)
window[3].title=YouTube - Google Chrome

Attaching client and server debug output.


Fri, 14 Feb 2014 00:30:14 GMT - alas: attachment set

Client-side -d focus output


Fri, 14 Feb 2014 00:37:50 GMT - alas: attachment set

Server-side -d focus output


Fri, 14 Feb 2014 06:14:57 GMT - Antoine Martin:

Trying to reproduce the problem with something a bit easier to manage (gnome-calculator instead of chrome) and moving the xterm over it I got an xpra client crash:

python[21006:10b] *** -[NSCFType convertScreenToBase:]: unrecognized selector sent to instance 0x1b3cf9d0
python[21006:10b] An uncaught exception was raised
python[21006:10b] *** -[NSCFType convertScreenToBase:]: unrecognized selector sent to instance 0x1b3cf9d0
python[21006:10b] *** Terminating app due to uncaught exception 'NSInvalidArgumentException', \
    reason: '*** -[NSCFType convertScreenToBase:]: unrecognized selector sent to instance 0x1b3cf9d0'
2014-02-14 03:26:17.222 python[21006:10b] Stack: (
    7090155,
    10059323,
    ...

Can you find me an application I can test with more easily? I've tried gnome-calculator, gedit and chromium. I just cannot reproduce the focus problem.

I am a bit unclear on whether this is specific to youtube or if it occurs on other sites, does it require a page using flash?

Does it do that exclusively on OSX? (I have only tested 10.5.8)


Fri, 14 Feb 2014 21:17:24 GMT - alas:

I was not able to reproduce this on windows.

I was, however, able to reproduce it with gedit.

Clipping of server output file at point in time while alt img showing "through" xterm, but before clicking:

2014-02-14 12:21:07,166 focus wid=2 has_focus=2
2014-02-14 12:21:07,286 focus wid=2 has_focus=2
2014-02-14 12:22:04,266 process_focus: wid=0
2014-02-14 12:22:04,266 focus wid=0 has_focus=2
2014-02-14 12:22:04,266 reset_focus() 2 / WindowModel(0xa00025) had focus
2014-02-14 12:22:04,267 reset_x_focus: widget with focus: None
2014-02-14 12:22:04,267 Take Focus -> world window
2014-02-14 12:22:04,267 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x36c35a0 (GdkWindow at 0x27b2a20)>, 178253574L
2014-02-14 12:22:04,273 process_focus: wid=1
2014-02-14 12:22:04,273 focus wid=1 has_focus=0
2014-02-14 12:22:04,273 focus: giving focus to WindowModel(0x800022)
2014-02-14 12:22:04,273 focus: will set modified mask to ('mod2',)
2014-02-14 12:22:04,274 Giving focus to <gtk.gdk.Window object at 0x7f59ec015280 (GdkWin$
2014-02-14 12:22:04,274 ... using XSetInputFocus

Immediate server output:

2014-02-14 12:23:36,572 process_focus: wid=0
2014-02-14 12:23:36,572 focus wid=0 has_focus=1
2014-02-14 12:23:36,572 reset_focus() 1 / WindowModel(0x800022) had focus
2014-02-14 12:23:36,572 reset_x_focus: widget with focus: None
2014-02-14 12:23:36,573 Take Focus -> world window
2014-02-14 12:23:36,573 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x36c35a0 (GdkWindow at 0x27b2a20)>, 178345879L
2014-02-14 12:23:36,577 process_focus: wid=2
2014-02-14 12:23:36,577 focus wid=2 has_focus=0
2014-02-14 12:23:36,577 focus: giving focus to WindowModel(0xa00025)
2014-02-14 12:23:36,577 focus: will set modified mask to ('mod2',)
2014-02-14 12:23:36,578 Giving focus to <gtk.gdk.Window object at 0x7f59ec015b90 (GdkWindow at 0x3631360)>
2014-02-14 12:23:36,578 ... using XSetInputFocus
2014-02-14 12:23:36,579 ... using WM_TAKE_FOCUS
2014-02-14 12:23:36,579 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x7f59ec015b90 (GdkWindow at 0x3631360)>, 178345885L
(gedit:25104): Gtk-WARNING **: Calling Inhibit failed: GDBus.Error:org.freedesktop.DBus.Err$
2014-02-14 12:23:36,933 process_focus: wid=0
2014-02-14 12:23:36,933 focus wid=0 has_focus=2
2014-02-14 12:23:36,934 reset_focus() 2 / WindowModel(0xa00025) had focus
2014-02-14 12:23:36,934 reset_x_focus: widget with focus: None
2014-02-14 12:23:36,935 Take Focus -> world window
2014-02-14 12:23:36,935 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x36c35a0 (GdkWindow at 0x27b2a20)>, 178346242L
2014-02-14 12:23:36,950 process_focus: wid=4
2014-02-14 12:23:36,950 focus wid=4 has_focus=0
2014-02-14 12:23:36,950 focus: giving focus to WindowModel(0xa003a2)
2014-02-14 12:23:36,950 focus: will set modified mask to ('mod2',)
2014-02-14 12:23:36,950 focus: giving focus to WindowModel(0xa003a2)
2014-02-14 12:23:36,950 focus: will set modified mask to ('mod2',)
2014-02-14 12:23:36,951 Giving focus to <gtk.gdk.Window object at 0x7f599c0420f0 (GdkWindow at 0x3631d80)>
2014-02-14 12:23:36,951 ... using XSetInputFocus
2014-02-14 12:23:36,953 ... using WM_TAKE_FOCUS
2014-02-14 12:23:36,953 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x7f599c0420f0 (GdkWindow at 0x3631d80)>, 178346258L

Client output for same portion:

2014-02-14 12:23:36,570 focus-out-event for wid=1
2014-02-14 12:23:36,570 _focus_change((<GLClientWindow object at 0x7ab2bc0 (xpra+client+gtk2+client_window+ClientWindow at 0x140$
2014-02-14 12:23:36,570 update_focus(1, False) _focused=1
2014-02-14 12:23:36,570 send_focus(0)
2014-02-14 12:23:36,571 focus-in-event for wid=2
2014-02-14 12:23:36,571 _focus_change((<GLClientWindow object at 0x7ac0468 (xpra+client+gtk2+client_window+ClientWindow at 0x140$
2014-02-14 12:23:36,571 update_focus(2, True) _focused=None
2014-02-14 12:23:36,571 send_focus(2)
2014-02-14 12:23:36,574 _unfocus() wid=3
2014-02-14 12:23:36,920 focus-out-event for wid=2
2014-02-14 12:23:36,920 _focus_change((<GLClientWindow object at 0x7ac0468 (xpra+client+gtk2+client_window+ClientWindow at 0x140$
2014-02-14 12:23:36,921 update_focus(2, False) _focused=2
2014-02-14 12:23:36,921 send_focus(0)
2014-02-14 12:23:36,921 focus-in-event for wid=4
2014-02-14 12:23:36,921 _focus_change((<ClientWindow object at 0x905c5d0 (xpra+client+gtk2+client_window+ClientWindow at 0xf68b2$
2014-02-14 12:23:36,927 _focus_change(('initial',)) wid=4, has-toplevel-focus=True, _been_mapped=True
2014-02-14 12:23:36,927 update_focus(4, True) _focused=None
2014-02-14 12:23:36,927 send_focus(4)
2014-02-14 12:25:11,883 focus-out-event for wid=4
2014-02-14 12:25:11,884 _focus_change((<ClientWindow object at 0x905c5d0 (xpra+client+gtk2+client_window+ClientWindow at 0xf68b2$
2014-02-14 12:25:11,884 update_focus(4, False) _focused=4
2014-02-14 12:25:11,884 send_focus(0)

Since there are already full output files from previous test, I will spare you the attachment of more. Let me know if the full output files are liable to be useful though, and I can attach them.


Sat, 15 Feb 2014 08:03:58 GMT - Antoine Martin:

How easy is it to reproduce? I don't understand why I am not seeing it... I don't think virtualbox interferes in my testing. I must be doing it wrong. Maybe a screenshot showing the exact position of the windows would help?

Please include the focus events before the problem manifests itself: by the time the log sample starts, the gedit window already has the focus (focus wid=2 has_focus=2). We need to find out why it did get the focus since you said the last click was to focus the xterm.

Your log samples are truncated just where it gets interesting! (looks like an 80 character limit?) You should redirect to a file if your terminal application is not capable of respecting line width.

The _focus_change lines in particular are missing the crucial bits of information.. Please also include the "xid" for each window (from xpra info) so we can try to reconcile this with the value found in the logging for WindowModel (which sits in a different layer and does not know about window ID). Newer versions of the server also include the window's xid (for log lines like the WM_TAKE_FOCUS), which will be useful too.

What looks suspicious so far:


Tue, 18 Feb 2014 19:54:11 GMT - alas:

I'm not sure what window 3 was. In this run there were (supposed to be) only 2 xpra windows. I was using a separate machine entirely to pull clippings from the server, so there shouldn't've been any focus shifts to other windows at all. (Note, there are the connection and disconnection messages in the output logs where the other machine queried for xpra info.)

I'll post the entire server log for that run through.

I ran through once more though (without the -d mouse), to isolate the log info from before I wiggled my mouse sufficiently to pull up the alt-img tag from the menu of the lower window - I'll post that entire log as well, but I'll here note before and after, and I'll also post a before and after screenshot, after including the alt-img showing "through" the xterm.

I'll also try to run the same test again with -d mouse, focus as soon as I get a chance.


Tue, 18 Feb 2014 20:00:57 GMT - alas: attachment set

First gedit test - server output


Tue, 18 Feb 2014 20:01:58 GMT - alas: attachment set

Second gedit test (with hints of before focus shift) - server output


Tue, 18 Feb 2014 20:06:21 GMT - alas: attachment set

screenshot of gedit moved slightly askew from underlying xterm (buttons overlapping)


Tue, 18 Feb 2014 20:08:02 GMT - alas: attachment set

screenshot after focus shifted to xterm from gedit, mouse wiggled over buttons until alt-img shows through


Tue, 18 Feb 2014 20:20:45 GMT - alas:

Using the command dbus-launch xpra --no-daemon --bind-tcp=0.0.0.0:1201 --start-child=xterm --start-child=gedit start :23 -d focus > ticket469-server-output5.txt 2>&1, I get an xterm window and a gedit window atop that when the client connects.

gedit window pulled askew focus shift to xterm and wiggled the mouse
screenshot of gedit moved slightly askew from underlying xterm (buttons overlapping) screenshot after focus shifted to xterm from gedit, mouse wiggled over buttons until alt-img shows through

Pull it askew enough so that focus can shift to the xterm (but still overlap the save, print, etc. buttons); click to shift focus to the xterm, and then just drag the mouse back and forth a bit over the portion of the xterm that overlaps the buttons. Within a second, two at most, I find an alt-img tag showing through (I can often click the buttons "through" the xterm prior to seeing the alt-img... but the alt-img is a particularly dramatic indication that the buttons are being seen "through" the xterm).

With two windows that each have buttons, the focus issue will work either way, it is not just something occurring with xterms.


Tue, 18 Feb 2014 20:59:01 GMT - alas:

Odd, using the command dbus-launch xpra --no-daemon --bind-tcp=0.0.0.0:1201 --start-child=xterm --start-child=gedit start :23 -d focus,mouse > ticket469-server-output6.txt 2>&1 the server output includes the following:

GLib-GIO-Message: Using the 'memory' GSettings backend.  Your settings will not be saved or shared with other applications.
** (gedit:10584): WARNING **: AT-SPI: Could not obtain desktop path or name
** (gedit:10584): WARNING **: atk-bridge: get_device_events_reply: unknown signature
** (gedit:10584): WARNING **: atk-bridge: get_device_events_reply: unknown signature
** (gedit:10584): WARNING **: atk-bridge: GetRegisteredEvents returned message with unknown signature
** (gedit:10584): WARNING **: AT-SPI: Could not obtain desktop path or name
** (gedit:10584): WARNING **: AT-SPI: Could not obtain desktop path or name

... and client-side I get:

Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "xpra/scripts/main.pyc", line 62, in main
  File "xpra/scripts/main.pyc", line 197, in parse_cmdline
UnboundLocalError: local variable 'enabled_str' referenced before assignment

... and the client won't connect.

Trying again with just -d mouse produces the same results.


Wed, 19 Feb 2014 03:36:04 GMT - Antoine Martin:

Just to clarify:

I'm not sure what window 3 was

(...)

I find an alt-img tag showing through


This is not a browser so there are no "alt-img" tags here. I believe this is in fact a tooltip window (should have window type set to "TOOLTIP").

The enabled_str error is fixed in r5500. The gedit server side warnings are not new and can safely be ignored - starting the gnome-settings daemon should fix those.


Wed, 19 Feb 2014 14:57:28 GMT - Antoine Martin:

So... I wasn't being dumb or anything, I have followed your steps exactly and I just cannot reproduce the bug. Which means that I am going to have to figure it out with logs alone.. So please post logs with updated client and server, without forgetting the "xid" from xpra info so I can reconcile the logs more easily.

It could be useful to do the exact same steps on a system that does not have the bug (ie: windows or linux) and post the exact same debug log (both client and server for completeness). Something should be different.


Wed, 19 Feb 2014 21:01:25 GMT - alas:

Ok, I went through the routine with r5515 with -d focus,mouse enabled. The first time through I wasn't able to reproduce the bug, but I think I might have just not found the right space for the buttons. Looking at the output with the -d mouse, I notice that the window xid does indeed seem to have shifted.

... and part way through the logs I do notice the following:

2014-02-19 12:31:09,320 raising WindowModel(0x800022)
2014-02-19 12:31:09,320 move_pointer(1, (310, 297))
2014-02-19 12:31:09,360 raising WindowModel(0x800022)
2014-02-19 12:31:09,361 move_pointer(1, (309, 297))
2014-02-19 12:31:09,522 raising WindowModel(0x800022)
2014-02-19 12:31:09,522 move_pointer(1, (308, 297))
2014-02-19 12:31:11,141 raising WindowModel(0xa00025)
2014-02-19 12:31:11,142 move_pointer(2, (307, 297))
2014-02-19 12:31:11,262 raising WindowModel(0xa00025)
2014-02-19 12:31:11,262 move_pointer(2, (306, 297))

I won't post any of the rest of that output, since the test that produced the bug is more interesting.

I will attach the entirety of the server-side and client side logs (output11)... and then go through the whole process again with a windows client.


Wed, 19 Feb 2014 21:03:15 GMT - alas: attachment set

ticket469 server output with -d mouse, focus, osx client


Wed, 19 Feb 2014 21:07:23 GMT - alas: attachment set

ticket469 osx client output -d focus,mouse


Wed, 19 Feb 2014 21:48:05 GMT - alas:

Testing with a windows client, r5515, there isn't much of anything interesting going on.

The question seems to be why the WindowModel? changes... I hope you can see something in this output to give you a hint, because I don't.

Let me know if you need me to resort to a -d all.


Wed, 19 Feb 2014 21:49:04 GMT - alas: attachment set

ticket 469 server output with windows client and -d focus,mouse


Wed, 19 Feb 2014 21:50:01 GMT - alas: attachment set

ticket 469 windows client output with -d focus,mouse (expected behavior)


Thu, 20 Feb 2014 13:54:03 GMT - Antoine Martin: owner, status changed

(Hooray - I can reproduce it)


First, I've edited the samples slightly to remove some cruft that should never have been there (some left over from yesterday's nvenc debugging I forgot to take out, now more permanently removed by r5516 + r5517, and some sound stuff - which you should disable unless it is relevant, which is very doubtful)


Portion of logs where the mouse seems to perceive a shift of window focus


All you have to do to see this, is move over a window then over another one.
There is some confusion here over "focus" and "raising"... The raising of windows isn't the same as the input focus... You can have a window raised (on top of all windows) and it doesn't necessarily have the focus... And a window at the bottom of the stack, may still have the focus. Those are two separate, yet overlapping concepts. We raise the window to ensure that the window which is under the mouse movement is the one that will receive the events.


More on this subject here: wikipedia: Focus (see "focus follows pointer" for example)


The client OS (via GTK) is the one that tells us where the mouse cursor is, and what window received the motion (or click) event. Which brings me to this really puzzling bit:

And the end-portion of the (server-side) logs once the tooltip appears, before clicking on it.

move_pointer(2, (56, 295))

This event is on the gedit window (window id=2). OSX is telling us at this point that the mouse is *over* gedit and not the xterm. That could be the source of the problems and would be a bug in gtk-osx.

And that finally helped me reproduce the bug: one has to wait for the first gedit tooltip window to appear before moving the mouse back to the xterm. This is what causes the bug. Somehow... but now I can investigate properly at least.


Fri, 21 Feb 2014 05:38:50 GMT - Antoine Martin: owner, status changed

On Linux (no bug), here's what I see (sanitized) with: -d mouse,focus,window,-encoding,-refresh on the server:

followed by damage processing and not much else

Client side is straightforward:

And then I switch over to OSX... and I just cannot reproduce the bug again. WTH? I had made lots of improvements to the debug logging (see r5521), hoping to spot the cause... and now I get nothing! Help!


Fri, 21 Feb 2014 23:45:25 GMT - alas:

Heh... I had the same problem my first time running through it again with the logs running. Neglected to have a second machine handy to pull the logs... and after I'd gone to another window to connect and grab info once I had the tooltip up, when I returned to click on the xterm it behaved properly. I had to click back on the gedit, then click back on the xterm, then click on it a second time near the button-overlap region, then mouse around a bit more before I got the cursor to change to an arrow and was able to click through.

In case there's anything useful in that run through, I'll present that info and output files (output13)... followed by a second run through with "cleaner" output logs (output14).

Client & server r5531

(Note, an attempt to fix our libraries to solve the clipboard issue has now broken the ability to start a server with -—start-child=gedit, so I’m starting with two xterms and using one to create a gedit instance. The xterm used to fire up gedit is the one whose position is obviously well out of the action.)


xpra info | grep windows

window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[1].xid=0xa00022
window[2].position=(475, 953)
window[2].title=jimador@elpatron:~
window[2].xid=0x800022
window[3].position=(36, 256)
window[3].title=Unsaved Document 1 - gedit
window[3].xid=0xc00025

xpra info | grep window

window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[1].xid=0x800022
window[2].position=(495, 940)
window[2].title=jimador@elpatron:~
window[2].xid=0xa00022
window[3].position=(33, 258)
window[3].title=Unsaved Document 1 - gedit
window[3].xid=0xc00025
2014-02-21 15:01:39,900 raising WindowModel(0xc00025)
2014-02-21 15:01:39,900 move_pointer(3, (399, 270))
2014-02-21 15:01:39,929 raising WindowModel(0xc00025)
2014-02-21 15:01:39,929 move_pointer(3, (395, 273))
2014-02-21 15:01:39,949 raising WindowModel(0xc00025)
2014-02-21 15:01:39,949 move_pointer(3, (394, 275))
2014-02-21 15:01:39,950 raising WindowModel(0xc00025)
2014-02-21 15:01:39,950 move_pointer(3, (393, 276))
2014-02-21 15:01:46,676 New connection received: SocketConnection(/home/jimador$
2014-02-21 15:01:46,676 New connection received: SocketConnection(/home/jimador$
2014-02-21 15:01:46,679 Connection lost
2014-02-21 15:01:46,685 processing info request from SocketConnection(/home/jim$
2014-02-21 15:01:46,686 processing info request from SocketConnection(/home/jim$
2014-02-21 15:01:46,993 Connection lost
2014-02-21 15:03:03,039 raising WindowModel(0xc00025)
2014-02-21 15:03:03,039 move_pointer(3, (221, 309))
2014-02-21 15:03:03,059 raising WindowModel(0xc00025)
2014-02-21 15:03:03,059 move_pointer(3, (220, 310))
2014-02-21 15:03:03,089 raising WindowModel(0xc00025)
2014-02-21 15:03:03,089 move_pointer(3, (219, 310))
2014-02-21 15:03:03,109 raising WindowModel(0xc00025)
2014-02-21 15:03:03,109 move_pointer(3, (216, 311))
2014-02-21 15:03:03,139 raising WindowModel(0xc00025)
2014-02-21 15:03:03,139 move_pointer(3, (215, 311))
2014-02-21 15:03:03,140 raising WindowModel(0xc00025)
2014-02-21 15:03:03,140 move_pointer(3, (213, 311))
2014-02-21 15:03:03,140 raising WindowModel(0xc00025)
2014-02-21 15:03:03,140 move_pointer(3, (213, 311))

Fri, 21 Feb 2014 23:52:41 GMT - alas: attachment set

server output, near failed run, 2/21 test


Fri, 21 Feb 2014 23:53:43 GMT - alas: attachment set

client output, near failed run, 2/21 tests


Fri, 21 Feb 2014 23:55:05 GMT - alas: attachment set

server output, clean run, 2/21 tests


Fri, 21 Feb 2014 23:56:39 GMT - alas: attachment set

client output, clean run, 2/21 tests


Sat, 22 Feb 2014 01:58:20 GMT - Antoine Martin:

an attempt to fix our libraries to solve the clipboard issue has now broken the ability to start a server with --start-child


The clipboard issue is client side (OSX), and --start-child is server side... I don't understand how one could affect the other.


I had to click back on the gedit, then click back on...


No amount of clicking allows me to reproduce the bug here. Yesterday it was reliable, today the exact same steps do not work. Weird, and frustrating.


Please post the server logs with the same debug flags as comment:15

And please keep an eye on the client log file as you do it to verify that the window id shown in the move_pointer events is the one that is meant to be there.


Sat, 22 Feb 2014 17:51:08 GMT - alas:

Sorry, didn't fully digest those debug flags (or think to add them to my own run through).

The clipboard issue is client side (OSX), and --start-child is server side...

I could have been more precise. For some reason, with our r5531 build that included some library work in an attempt to fix our osx clipboard issues, when I try to connect to a server which has a --startchild=gedit with an osx client, the gedit window fails to properly start, leaving a frame which is non-interactive... and in the process making it impossible to focus on any of the other xpra session windows (xterms, in my case). The server is fine with other clients with a --start-child=xterm ... but with an osx client at the moment, not-so-much.

But that is neither here nor there.

I went through the test case with the newer flags in place. Again, I am running the gedit out of an xterm, so there are 3 windows to grep.

xpra info | grep window

window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[1].xid=0x800022
window[2].position=(245, 473)
window[2].title=jimador@elpatron:~
window[2].xid=0xc00022
window[2].position=(33, 244)
window[2].title=Unsaved Document 1 - gedit
window[2].xid=0xa00025

I have commented the points of interest in the logs and will attach both server and client.


Sat, 22 Feb 2014 18:04:03 GMT - alas: attachment set

server output with -d focus,mouse,window,-encoding,-refresh


Sat, 22 Feb 2014 18:05:20 GMT - alas: attachment set

client output with -d focus,mouse,window,-encoding,-refresh


Thu, 27 Feb 2014 10:23:01 GMT - Antoine Martin:

Here's what I see happening:

I assume the events after that aren't relevant. Hard to tell.
Assuming this is the case, then I don't see too much wrong here (server side), unless the client is wrong about which window has the focus? (the one on top). It is a little bit odd how this all happens within 100ms.. And why does the xterm window lose its focus only when the tooltip disappears? More questions than answers.


This log doesn't seem to match the client log, which has a different timeline (Window 4 appears at 09:30:00 in the client log for example). To debug, I need matching logs.

We want to know why the client is telling the server that the xterm window has lost focus.




I'm not sure it will make much of a difference (still unable to reproduce the bug here), but it is worth trying r5615 (server side change). (it would be more of a workaround than an actual fix since the server only seems to be doing exactly what the client is asking for)


Fri, 28 Feb 2014 00:26:06 GMT - alas:

Testing with r5616 client-side and r5618 server-side ... I was able to reproduce the bug, unfortunately.

Both the client-output16 and server-output16 were from the same test... however, a quick check of date with the server and one of the machines I was using for the test shows a time difference of about a minute and a half (though, I think I was using a different machine for the client-side tests with the 16 output logs, so I'm not certain what the time differences there might be).

I will do a rdate -s time.nist.gov before doing another run through the tests in order to post some logs that should actually match up timewise (should've checked on how to do that before, yes... oops).

In the meantime, a few words about how I found the points I commented in the output logs. The cleint-side I had streaming with a tail -f and I went in after the fact to comment following the bits of output I saw at the various points. Meanwhile, on the server side I was using another machine to nano the output logs and copy the output at the point after whatever action, in order to go back in later and mark the interesting points. Assuming the difference to also be about a minute and a half, the logs do actually seem to match up. (2014-02-22 09:31:22,771 server-side seems to about match up with 2014-02-22 09:30:00,985 client side.)

Since you probably, understandably, don't feel like sorting through that hassle... I'll post matching time logs tomorrow.


Fri, 28 Feb 2014 20:23:29 GMT - alas: attachment set

server output with syncd time, 2/28 (action starts at 11:49:44,982)


Fri, 28 Feb 2014 20:25:36 GMT - alas: attachment set

client output, syncd 2/28 (action starts at 11:49:44,954)


Fri, 28 Feb 2014 20:33:59 GMT - alas:

Ok, ran a syncd test. Commented within the output logs the interesting points. Note, I was clipping bits of the tailings from the server-side logs after the cursor changed from an xterm style cursor to an arrow... and when I turned back to the client machine, a tooltip had appeared. That point of action on the client-side logs is clearly marked, but the change of cursor, obviously, occurred a couple of seconds before.

In any case, the final piece of the puzzle (we can hope):

xpra info | grep window
window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[1].xid=0xc00022
window[2].position=(919, 972)
window[2].title=jimador@elpatron:~
window[2].xid=0xa00022
window[3].position=(28, 238
window[3].title=Unsaved Document 1 - gedit
window[3].xid=0x800025

I can't think of anything else to add, except it was, again, server r5618 and client r5616.


Tue, 18 Mar 2014 11:19:43 GMT - Antoine Martin:

I am still unable to reproduce this, and I can't see anything suspicious in the logs (only it gives me a minor headache each time..)

One thing I have noticed is that on every other platform we do get mouse events when the mouse is over one of our windows, even if those windows are not currently focused. On OSX, we get nothing unless an Xpra window has top level focus. This may be related, or even be causing this problem somehow if we are missing some events that normally end up setting the correct window as being on top.


Tue, 10 Jun 2014 08:35:37 GMT - Antoine Martin:

afarr: please re-test trunk, does #589 make any difference? (it might)

You can find a beta build here: http://xpra.org/beta/osx/x86 (made today, also with an updated gtk+ build - I have not tested opengl with it, I hope it doesn't need a rebuild)


Tue, 10 Jun 2014 21:59:32 GMT - alas:

Testing with our 0.14.0 r6713 osx build against a fedora 20 0.14.0 r6713 server...


Tue, 19 Aug 2014 04:55:01 GMT - Antoine Martin: milestone set

As per ticket:490#comment:10, please provide a short video of how to reproduce this. The platform_window_focus code in that ticket may be useful here too.


Tue, 19 Aug 2014 23:14:23 GMT - alas: attachment set

ticket 469 repro movie (8 seconds)


Wed, 20 Aug 2014 03:10:20 GMT - Antoine Martin: owner, status changed

Thanks! I've reproduced it!


Wed, 20 Aug 2014 10:10:42 GMT - Antoine Martin: owner, status changed

Running with full debug and then looking for the point where the new window popped up, then working back up from there I hit:

With nothing relevant in between (just paints). So we tell the server that the window 3 has the focus at that position, it raises it and that's why the click ends up on the wrong window. Looks like a GTK bug on OSX.

r7361 should fix this problem, works-for-me. (could be backported after some time). Problem is that this changes the behaviour of the client on all platforms, not just on OSX. I would much rather not have to add a per-platform check there. So, please test thoroughly with anything that relies on mouse movements and focus, especially on platforms that have had good behaviour all along (mostly *nix) so that this does not cause regressions.


Thu, 21 Aug 2014 20:32:36 GMT - alas:

Unfortunately, it's still not working for me.

Testing a 0.14.2-r7389 osx client (both on a 10.6.8 and a 10.9 OS, with --opengl=on as well as with it blacklisted to off) against a 0.15.0-r7376 fedora 20 server ... I'm still able to reproduce exactly as with the above video.

I assume you don't need any new logs?


Fri, 22 Aug 2014 01:44:23 GMT - Antoine Martin:

afarr: you have not tested the fix. r7361 is a trunk commit, which 0.14.x does not have.

If you do reproduce it with the patch applied (either trunk or backported), please post the log samples containing do_motion_notify_event and _button_action as a summary, and maybe the full log attached.


Fri, 22 Aug 2014 20:17:20 GMT - alas: owner changed

Ahh, I was wondering what had gone wrong.

Testing again with osx 0.15.0-r7416 against a fedora 20 0.15.0-r7416 ... Clicks no longer register "through" the xterm window!!

I am still able to make the cursor change from a "][" to a pointer, and I'm still able to get the underlying window's tooltips window to render... but I see that sort of behavior with local chrome regularly.

I think this is ready to close at last.


Sat, 23 Aug 2014 01:02:55 GMT - Antoine Martin: status changed; resolution set

Backport to v0.14.x in r7417. Closing.


Thu, 11 Dec 2014 21:52:14 GMT - Antoine Martin: status changed; resolution deleted

Not fixed: I have just seen it again. (could be related to #490 ?)

It seems that the first click is registered on the right window (the one in front), but subsequent motion and click events are registered on the wrong one (the one behind) causing us to raise it. We have a workaround for using the focused window id when sending motion events (a really ugly hack), maybe we need the same hack for click events...

r8239 tries to uses the same workaround we already had for motion events, but now also for click events: we ignore the window that GTK tells us the event occurred on and use the one that has focus instead (if there is one - otherwise, we hope that the value is correct..). Sadly, this does not work: we also get a focus event from GTK telling us to focus the window in the background!? Looks to me like this is a GTK bug...


Thu, 12 Feb 2015 11:57:10 GMT - Antoine Martin:

r8652 undoes r8239 for all platforms except osx, as this was causing all sorts of focus / window layer problems. Maybe we should take it out altogether and find a better solution for osx? No idea what that would be though!

Still TODO: limit the scope of this hack, so maybe it won't apply to OR / non-OR windows? (still need to figure out which ones cause problems and in which direction!)

See also: #770, #713, #139


Sun, 10 Apr 2016 06:28:25 GMT - Antoine Martin: milestone changed

re-scheduling


Tue, 12 Jul 2016 16:52:22 GMT - Antoine Martin: milestone changed

Milestone renamed


Wed, 07 Sep 2016 10:09:01 GMT - Antoine Martin:

See also ticket:1293#comment:15.


Tue, 13 Sep 2016 11:38:23 GMT - Antoine Martin: owner, status changed

I cannot reproduce this, but then again I struggled at the best of times...

@afarr: I think we should just close this and re-open if we ever manage to reproduce this. (and include "-d mouse,focus" then)


Sat, 17 Sep 2016 01:50:15 GMT - alas:

I just reproduced while testing fixes in #770.

Do you want the "-d mouse,focus" on the client, server, or both... sides? (It's currently late, but I seem to have a magic touch for repro'ing this... let me know and I'll get some logs.)


Sat, 17 Sep 2016 05:30:01 GMT - Antoine Martin:

Movie here: attachment/ticket/469/ticket469-repro.mov


Sat, 17 Sep 2016 05:34:33 GMT - Antoine Martin: owner, status changed

Will try again now that I found the movie. Maybe the ugly code in "get_mouse_event_wid" of r13690 is still needed.


Mon, 19 Sep 2016 16:46:05 GMT - alas:

A quick note about the movie... it doesn't seem to have shown it, but one sure way to know you'll be able to "click through" a window (in this case the xterm) is to watch for the alt-text popup to appear for the window below when the mouse is "also" hovering over the button below.


Mon, 26 Sep 2016 08:42:38 GMT - Antoine Martin: attachment set

reproduced with a button click


Mon, 26 Sep 2016 10:01:52 GMT - Antoine Martin:

I seem to be able to reproduce this more easily by clicking in the window, over the window that should be in the background, from that point onwards the motion events we get from macos come from the wrong window id.

Excerpts from the log above (wid=1 has focus and we click on it, wid=2 should never get any events.. but it does):

do_motion_notify_event(<gtk.gdk.Event at 0x133ac710: GDK_MOTION_NOTIFY x=363.00, y=54.00>) wid=1 / focus=1, device=Core Pointer, pointer=(435, 99), modifiers=['mod2'], buttons=[]
_button_action(1, <gtk.gdk.Event at 0x133ac710: GDK_BUTTON_PRESS x=363.00, y=54.00, button=1>, True) wid=1 / focus=1, device=Core Pointer, pointer=(435, 99), modifiers=['mod2'], buttons=[]
_button_action(1, <gtk.gdk.Event at 0x1343d650: GDK_BUTTON_RELEASE x=363.00, y=54.00, button=1>, False) wid=1 / focus=1, device=Core Pointer, pointer=(435, 99), modifiers=['mod2'], buttons=[1]
do_motion_notify_event(<gtk.gdk.Event at 0x133ac710: GDK_MOTION_NOTIFY x=149.00, y=22.00>) wid=2 / focus=1, device=Core Pointer, pointer=(434, 99), modifiers=['mod2'], buttons=[]

I was hoping that maybe there was a packet or event we were handling between the button click and the next motion notify, but there isn't (was running with "-d all"). So we're not doing anything wrong.

Also spotted this: How to find a window under the cursor: Tracking mouseMoved events works fine for me, there is no problem. But it tells me nothing about the window under the cursor! Events passed to mouseMoved: method contain a pointer to the main window, not the window under the cursor. yep.

So it's pretty bad, I added code to log the gdk window-at-pointer, and it's pretty much always wrong if there are stacked windows. The macos implementation in _gdk_windowing_window_at_pointer uses gdk_window_quartz_get_pointer_helper which then calls find_child_window_helper (via _gdk_quartz_window_find_child). It first calls update_toplevel_order, then goes through the sorted_children list of windows. This function prepends the windows to the list but the orderedwindows API it uses returns front to back... so back will be first?

Solutions:


Mon, 26 Sep 2016 13:25:12 GMT - Antoine Martin: attachment set

example code using the window from the notification object


Mon, 26 Sep 2016 13:30:38 GMT - Antoine Martin: owner, status changed

Some posts mention a MacFindWindow function, but this isn't documented anywhere.

I noticed that we do get focus change events as we click right in the middle of the top level window and that's probably the source of it all. From that point onwards, we're out of sync and no patching can save us. The events come from _gdk_quartz_events_update_focus_window which fires from windowDidResignKey (for "focus-out"). It uses the gdk window in scope, I thought that maybe it should be using NSWindow *win = [notification object]; instead so I tried this: attachment/ticket/469/osx-notification-window.c, but that doesn't make any difference to the window being reported in the focus event. And in any case, these focus events are bogus: we're clicking in the top level window - which already has focus, so no focus events should fire. (what window overlap behind this window should not make any difference at all)

Another interesting thing is that the first click on the overlapping area does not trigger a focus event, but it does change the window that motion events get reported against. The second click triggers even more of a mess by triggering window focus events.


So r13881 takes a rather brutal approach: we detect when the GTK focus is going wrong on osx (ie: when the pointer event is within the area of the current window in focus, but this is not the window it is reported against) and we patch it up:

Unfortunately, GTK is so messed up at that point that we cannot use gtk.Window.present(), which has side effects: it makes the window flicker as we process a brand new map event for every mouse movement... this stops as soon as you move the mouse outside of the window. (maybe we could re-write this using Cython to call makeKeyAndOrderFront directly on the nswindow - assuming we can get the handle of the correct one..)

This workaround can be disabled by running the client with XPRA_OSX_FOCUS_WORKAROUND=0.

@afarr: this should fix the problem you reported (more than 3 years ago now!), hopefully this nasty fix does not cause more problems than it solves...


Mon, 03 Oct 2016 19:51:23 GMT - alas: owner changed

Well, tested with osx client 1.0 r13977 against a fedora 23 server 1.0 r13979.

In first test I wasn't able to "click through" my xterm to the gedit window below, but I was also unable to get the gedit window to get any focus at all, even when clicking on it (in this case with a gedit application launched from the start-new-commands option from the application menu. Noticed an odd xxhash warning on server output (#1331). Haven't been able to repro this, just mention it in case it helps clarify #1331.

Tried again, launching the server with two xterm start childs, and was able to rather promptly click through, though in that event I was able to shift focus as expected (well, until I clicked through).

Repro'd that consistently - client logs are rather brief, but this ticket is messy enough, so I'll attach those as logs, as well as server side logs (note, for server side I connected, set up everything, then disconnected & re-connected client to keep client logs as clean as possible - so the "client 2" portion of the server logs should be where the interesting stuff is... though the use of the start-command to launch the gedit window might be of interest, done with "client 1").


Mon, 03 Oct 2016 19:52:14 GMT - alas: attachment set

server -d focus logs of a click through (1.0 r13979)


Mon, 03 Oct 2016 19:52:49 GMT - alas: attachment set

concise client logs of click through (1.0 r13977)


Fri, 10 Mar 2017 12:00:26 GMT - Antoine Martin: status, milestone changed

Taking this back: I've undone the change in r15262 because this caused #1453.


Fri, 10 Mar 2017 12:33:11 GMT - Antoine Martin:

The focus problems with GTK on macos are very real, so r15264 takes the "conservative" approach and re-enables the workaround, just not for OR windows (so #1453 remains fixed). r15265 does the same for the v1.0.x branch.


Fri, 14 Apr 2017 06:46:20 GMT - Antoine Martin:

See also the focus workaround in ticket:490#comment:12


Sat, 13 May 2017 07:01:02 GMT - Antoine Martin: status changed; resolution set

I'm closing this because this is probably as good as it is going to get unless GTK2 is fixed, the real long term solution is to move to a better toolkit.


Tue, 31 Dec 2019 10:33:23 GMT - Antoine Martin:

See also ticket:1999#comment:15.


Sat, 23 Jan 2021 04:56:32 GMT - migration script:

this ticket has been moved to: https://github.com/Xpra-org/xpra/issues/469