Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Focus issue with mouse on osx client #469

Closed
totaam opened this issue Dec 11, 2013 · 101 comments
Closed

Focus issue with mouse on osx client #469

totaam opened this issue Dec 11, 2013 · 101 comments

Comments

@totaam
Copy link
Collaborator

totaam commented Dec 11, 2013

Issue migrated from trac ticket # 469

component: client | priority: major | resolution: wontfix | keywords: osx focus

2013-12-11 02:15:18: afarr created the issue


With osx client 4905 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.

@totaam
Copy link
Collaborator Author

totaam commented Dec 11, 2013

2013-12-11 22:29:16: afarr uploaded file osx-cursor-focus-test1-edited.txt (69.9 KiB)

Edited output from cursor/window focus issue

@totaam
Copy link
Collaborator Author

totaam commented Dec 11, 2013

2013-12-11 22:29:55: afarr uploaded file osx-cursor-focus-test1.txt (244.8 KiB)

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

@totaam
Copy link
Collaborator Author

totaam commented Dec 12, 2013

2013-12-12 02:07:29: totaam changed status from new to assigned

@totaam
Copy link
Collaborator Author

totaam commented Dec 12, 2013

2013-12-12 02:07:29: totaam changed owner from antoine to totaam

@totaam
Copy link
Collaborator Author

totaam commented Dec 12, 2013

2013-12-12 02:07:29: totaam commented


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."

@totaam
Copy link
Collaborator Author

totaam commented Feb 13, 2014

2014-02-13 14:46:10: antoine changed status from assigned to new

@totaam
Copy link
Collaborator Author

totaam commented Feb 13, 2014

2014-02-13 14:46:10: antoine changed owner from totaam to afarr

@totaam
Copy link
Collaborator Author

totaam commented Feb 13, 2014

2014-02-13 14:46:10: antoine commented


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.

@totaam
Copy link
Collaborator Author

totaam commented Feb 14, 2014

2014-02-14 00:28:44: afarr commented


Did the following:

  • Start server (--start-child=xterm x2) & client session.
  • Moved one xterm (window[2]) to the side.
  • Started chrome in other xterm (window[1]) & navigated to youtube (lots of handy buttons).
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
  • Moved xterm (window[2]) back over an area of youtube (window[3]) that had a button (video link).
  • Click on window[2] on area "over" the button - behavior as expected (focus remains on xterm, link not triggered).
  • Click back on youtube (window[3]) - space with no links.
  • Click back on xterm (window[2]), "above" button - focus shifts back to window[2]
  • Move mouse a tiny bit "above" button (still within boundaries of, and focus on, window[2])
    • Mouse icon changes to a "hand" as would be expected if scrolling over a link.
  • Click again on xterm (window[2]), "above" link on window[3] (still within boundaries of window[2] xterm).
    • The link is triggered.

Attaching client and server debug output.

@totaam
Copy link
Collaborator Author

totaam commented Feb 14, 2014

2014-02-14 00:30:15: afarr uploaded file ticket469client-debug3.txt (13.4 KiB)

Client-side -d focus output

@totaam
Copy link
Collaborator Author

totaam commented Feb 14, 2014

2014-02-14 00:37:50: afarr uploaded file ticket469-serverOutput3.txt.txt (15.8 KiB)

Server-side -d focus output

@totaam
Copy link
Collaborator Author

totaam commented Feb 14, 2014

2014-02-14 06:14:58: totaam commented


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)

@totaam
Copy link
Collaborator Author

totaam commented Feb 14, 2014

2014-02-14 21:17:25: afarr commented


I was not able to reproduce this on windows.

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

  • Start (--start-child=gedit --start-child=xterm) server & client
  • Move gedit (still overlapping xterm)
xpra info | grep window
window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[2].position=(40, 259)
window[2].title=Unsaved Document 1 - gedit
  • Type some garbage into gedit
  • Click on xterm (above gedit top menu buttons)
  • Move mouse around a bit (until an alt-img tag shows, print in this case)

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
  • Click where the alt img tag is showing through xterm

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.

@totaam
Copy link
Collaborator Author

totaam commented Feb 15, 2014

2014-02-15 08:03:59: totaam commented


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:

  • what is window id 3? (2014-02-14 12:23:36,574 _unfocus() wid=3 - I assume this is one of those tooltips, why does it lose focus if it never had it, odd) - maybe your test showed two tooltips (wid 4 has more details)
  • maybe we get mouse position events when moving the windows around - r5476 adds server-side mouse event logging, so please use "-d mouse,focus" to the server command line

@totaam
Copy link
Collaborator Author

totaam commented Feb 18, 2014

2014-02-18 19:54:12: afarr commented


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.

  • Firstly:
xpra info | grep window
window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[2].position=(49, 186)
window[2].title=Unsaved Document 1 - gedit
  • Output before "juggling focus":
2014-02-18 11:28:19,356 process_focus: wid=2
2014-02-18 11:28:19,356 focus wid=2 has_focus=0
2014-02-18 11:28:19,356 focus: giving focus to WindowModel(0xa00025)
2014-02-18 11:28:19,356 focus: will set modified mask to ('mod2',)
2014-02-18 11:28:19,356 Giving focus to <gtk.gdk.Window object at 0x26c2b90 (GdkWindow at 0x26bf360)>
2014-02-18 11:28:19,356 ... using XSetInputFocus
2014-02-18 11:28:19,356 ... using WM_TAKE_FOCUS
2014-02-18 11:28:19,356 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x26c2b90 (GdkWindow at 0x26bf360)>, 52062866$
  • Output after:
2014-02-18 11:31:28,920 process_focus: wid=0
2014-02-18 11:31:28,920 focus wid=0 has_focus=2
2014-02-18 11:31:28,920 reset_focus() 2 / WindowModel(0xa00025) had focus
2014-02-18 11:31:28,920 reset_x_focus: widget with focus: None
2014-02-18 11:31:28,920 Take Focus -> world window
2014-02-18 11:31:28,921 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x27991e0 (GdkWindow at 0x1840a20)>, 520818227L
2014-02-18 11:31:28,927 process_focus: wid=1
2014-02-18 11:31:28,927 focus wid=1 has_focus=0
2014-02-18 11:31:28,928 focus: giving focus to WindowModel(0x800022)
2014-02-18 11:31:28,928 focus: will set modified mask to ('mod2',)
2014-02-18 11:31:28,928 Giving focus to <gtk.gdk.Window object at 0x26c2280 (GdkWindow at 0x26bf000)>
2014-02-18 11:31:28,928 ... using XSetInputFocus
2014-02-18 11:31:37,760 process_focus: wid=0
2014-02-18 11:31:37,760 focus wid=0 has_focus=1
2014-02-18 11:31:37,760 reset_focus() 1 / WindowModel(0x800022) had focus
2014-02-18 11:31:37,761 reset_x_focus: widget with focus: None
2014-02-18 11:31:37,761 Take Focus -> world window
2014-02-18 11:31:37,761 sending WM_TAKE_FOCUS: <gtk.gdk.Window object at 0x27991e0 (GdkWindow at 0x1840a20)>, 520827067L
2014-02-18 11:31:37,765 process_focus: wid=2
2014-02-18 11:31:37,765 focus wid=2 has_focus=0
2014-02-18 11:31:37,765 focus: giving focus to WindowModel(0xa00025)
2014-02-18 11:31:37,765 focus: will set modified mask to ('mod2',)
2014-02-18 11:31:37,766 Giving focus to <gtk.gdk.Window object at 0x26c2b90 (GdkWindow at 0x26bf360)>

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

@totaam
Copy link
Collaborator Author

totaam commented Feb 18, 2014

2014-02-18 20:00:57: afarr uploaded file ticket469-server-output4.txt.txt (17.1 KiB)

First gedit test - server output

@totaam
Copy link
Collaborator Author

totaam commented Feb 18, 2014

2014-02-18 20:01:58: afarr uploaded file ticket469-server-output5.txt.txt (15.6 KiB)

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

@totaam
Copy link
Collaborator Author

totaam commented Feb 18, 2014

2014-02-18 20:06:22: afarr uploaded file ticket469-gedit_above_xterm.png (110.9 KiB)

screenshot of gedit moved slightly askew from underlying xterm (buttons overlapping)
ticket469-gedit_above_xterm.png

@totaam
Copy link
Collaborator Author

totaam commented Feb 18, 2014

2014-02-18 20:08:02: afarr uploaded file ticket469-xterm_above_gedit_cursor_shows_button_alt-img_from_underlying_gedit.png (104.4 KiB)

screenshot after focus shifted to xterm from gedit, mouse wiggled over buttons until alt-img shows through
ticket469-xterm_above_gedit_cursor_shows_button_alt-img_from_underlying_gedit.png

@totaam
Copy link
Collaborator Author

totaam commented Feb 18, 2014

2014-02-18 20:20:45: afarr commented


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||
|| [[Image(ticket469-gedit_above_xterm.png)]] || [[Image(ticket469-xterm_above_gedit_cursor_shows_button_alt-img_from_underlying_gedit.png)]] ||

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.

@totaam
Copy link
Collaborator Author

totaam commented Feb 18, 2014

2014-02-18 20:59:01: afarr commented


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.

@totaam
Copy link
Collaborator Author

totaam commented Feb 19, 2014

2014-02-19 03:36:05: totaam commented


Just to clarify:

I'm not sure what window 3 was
(...)
I find an alt-img tag showing through
[[BR]]
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.

@totaam
Copy link
Collaborator Author

totaam commented Feb 19, 2014

2014-02-19 14:57:28: totaam commented


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.

@totaam
Copy link
Collaborator Author

totaam commented Feb 19, 2014

2014-02-19 21:01:25: afarr commented


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.

  • In the test that failed to produce the bug I had the following xpra info:
window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[1].xid=0x800022
window[2].position=(55, 172)
window[2].title=Unsaved Document 1 - gedit
window[2].xid=0xa00025

... 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.

  • Info:
window[1].position=(0, 44)
window[1].title=jimador@elpatron:~
window[1].xid=0x800022
window[2].position=(22, 252)
window[2].title=Unsaved Document 1 - gedit
window[2].xid=0xa00025
  • Portion of logs (server-side) before shifting focus to the initially underlying xterm:
2014-02-19 12:34:10,249 ... using WM_TAKE_FOCUS
2014-02-19 12:34:10,249 sending WM_TAKE_FOCUS: 0xa00025, 610979554L
2014-02-19 12:34:18,511 process_focus: wid=2
2014-02-19 12:34:18,511 focus wid=2 has_focus=0
2014-02-19 12:34:18,511 focus: giving focus to WindowModel(0xa00025)
2014-02-19 12:34:18,511 focus: will set modified mask to ('mod2',)
2014-02-19 12:34:18,512 Giving focus to 0xa00025
2014-02-19 12:34:18,512 ... using XSetInputFocus
2014-02-19 12:34:18,512 ... using WM_TAKE_FOCUS
2014-02-19 12:34:18,512 sending WM_TAKE_FOCUS: 0xa00025, 610987818L
  • Portion of logs where the mouse seems to perceive a shift of window focus:
2014-02-19 12:35:36,953 raising WindowModel(0x800022)
2014-02-19 12:35:36,954 move_pointer(1, (54, 295))
2014-02-19 12:35:37,068 raising WindowModel(0x800022)
2014-02-19 12:35:37,068 move_pointer(1, (55, 295))
2014-02-19 12:35:38,162 raising WindowModel(0xa00025)
2014-02-19 12:35:38,162 move_pointer(2, (56, 295))
2014-02-19 12:35:38,331 raising WindowModel(0xa00025)
  • And the end-portion of the (server-side) logs once the tooltip appears, before clicking on it.
2014-02-19 12:35:42,018 raising WindowModel(0xa00025)
2014-02-19 12:35:42,018 move_pointer(2, (145, 310))
2014-02-19 12:35:42,019 raising WindowModel(0xa00025)
2014-02-19 12:35:42,020 move_pointer(2, (146, 311))
2014-02-19 12:35:42,056 raising WindowModel(0xa00025)
2014-02-19 12:35:42,056 move_pointer(2, (146, 313))
2014-02-19 12:35:42,082 raising WindowModel(0xa00025)
2014-02-19 12:35:42,082 move_pointer(2, (147, 314))

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.

@totaam
Copy link
Collaborator Author

totaam commented Feb 19, 2014

2014-02-19 21:03:15: afarr uploaded file ticket469-server-output11.txt.txt (44.1 KiB)

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

@totaam
Copy link
Collaborator Author

totaam commented Feb 19, 2014

2014-02-19 21:07:23: afarr uploaded file ticket469-client-output11.txt (8.0 KiB)

ticket469 osx client output -d focus,mouse

@totaam
Copy link
Collaborator Author

totaam commented Feb 19, 2014

2014-02-19 21:48:05: afarr commented


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

  • Xpra info
window[1].position=(8, 30)
window[1].title=jimador@elpatron:~
window[1].xid=0x800022
window[2].position=(44, 262)
window[2].title=Unsaved Document 1 - gedit
window[2].xid=0xa00025
  • clippings from output with gedit window moved, but before shifting focus to xterm:
2014-02-19 13:28:13,075 raising WindowModel(0xa00025)
2014-02-19 13:28:13,075 move_pointer(2, (451, 36))
2014-02-19 13:28:13,076 raising WindowModel(0xa00025)
2014-02-19 13:28:13,076 move_pointer(2, (451, 35))
2014-02-19 13:28:13,077 raising WindowModel(0xa00025)
2014-02-19 13:28:13,077 move_pointer(2, (450, 35))
2014-02-19 13:28:13,077 raising WindowModel(0xa00025)
2014-02-19 13:28:13,077 move_pointer(2, (450, 34))
2014-02-19 13:28:13,162 raising WindowModel(0xa00025)
2014-02-19 13:28:13,162 move_pointer(2, (449, 32))
  • Peeking into output, there's never any sign of raising window 0xa00025 afterward (with osx the mouse cursor noticeably shifts display ... from a ']['-like cursor... to an arrow, after which tooltip windows can be found/raised... presumably at the same point in which the raising WindowModel() corresponds to a shift from the xid of the xterm back to the "underlying" gedit window).

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.

@totaam
Copy link
Collaborator Author

totaam commented Feb 19, 2014

2014-02-19 21:49:04: afarr uploaded file ticket469-server-output12.txt (219.5 KiB)

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

@totaam
Copy link
Collaborator Author

totaam commented Feb 19, 2014

2014-02-19 21:50:02: afarr uploaded file ticket469-client-output12.txt (6.5 KiB)

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

@totaam
Copy link
Collaborator Author

totaam commented Feb 20, 2014

2014-02-20 13:54:04: totaam changed status from new to assigned

@totaam
Copy link
Collaborator Author

totaam commented Sep 17, 2016

2016-09-17 06:34:33: antoine commented


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

@totaam
Copy link
Collaborator Author

totaam commented Sep 19, 2016

2016-09-19 17:46:05: afarr commented


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.

@totaam
Copy link
Collaborator Author

totaam commented Sep 26, 2016

2016-09-26 09:42:39: antoine uploaded file osx-focus-bug.log (7.7 KiB)

reproduced with a button click

@totaam
Copy link
Collaborator Author

totaam commented Sep 26, 2016

2016-09-26 11:01:52: antoine commented


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:

  • patch gtk - may have undesirable side-effects, tried it and it didn't help
  • implement our own window lookup (and match the nsview with the gdk window's undocumented "nsview" attribute)
  • hack the window id only if we "know" it to be wrong, ie: if the focused window contains the pointer - then the event should be on this window

@totaam
Copy link
Collaborator Author

totaam commented Sep 26, 2016

2016-09-26 14:25:12: antoine uploaded file osx-notification-window.c (0.6 KiB)

example code using the window from the notification object

@totaam
Copy link
Collaborator Author

totaam commented Sep 26, 2016

2016-09-26 14:30:39: antoine changed status from assigned to new

@totaam
Copy link
Collaborator Author

totaam commented Sep 26, 2016

2016-09-26 14:30:39: antoine changed owner from antoine to afarr

@totaam
Copy link
Collaborator Author

totaam commented Sep 26, 2016

2016-09-26 14:30:39: antoine commented


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 NSWindowDidBecomeKeyNotification (for "focus-in") and 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:

  • report the correct window
  • force this window up to the top of the window stack
    Unfortunately, GTK is so messed up at that point that we cannot use gdk.Window.raise_() (this raises the wrong window!) and so we have to 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...

@totaam
Copy link
Collaborator Author

totaam commented Oct 3, 2016

2016-10-03 20:51:24: afarr changed owner from afarr to antoine

@totaam
Copy link
Collaborator Author

totaam commented Oct 3, 2016

2016-10-03 20:51:24: afarr commented


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").

  • One big note - it looks like I'm only able to repro if I am switching focus directly between the xpra windows. If I click on one of the xpra windows (say a 'gedit' window), then click to a local application, then click to one of the xpra windows (say an 'xterm' window), then I am able to click and scroll to my heart's delight with no clicks "going through". If, however, I click on an xpra window (say, the 'gedit' window again) and then click next on another xpra window (you guessed it, the 'xterm' window)... that is when I am able to "click through" as above.

@totaam
Copy link
Collaborator Author

totaam commented Oct 3, 2016

2016-10-03 20:52:14: afarr uploaded file ticket469_server-1-r13979_d-focus-logs.txt (24.7 KiB)

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

@totaam
Copy link
Collaborator Author

totaam commented Oct 3, 2016

2016-10-03 20:52:50: afarr uploaded file ticket469_client-1-r13977_d-focus-logs.txt (20.2 KiB)

concise client logs of click through (1.0 r13977)

@totaam
Copy link
Collaborator Author

totaam commented Mar 10, 2017

2017-03-10 12:00:27: antoine changed status from new to assigned

@totaam
Copy link
Collaborator Author

totaam commented Mar 10, 2017

2017-03-10 12:00:27: antoine commented


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

@totaam
Copy link
Collaborator Author

totaam commented Mar 10, 2017

2017-03-10 12:33:12: antoine commented


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).
15265 does the same for the v1.0.x branch.

@totaam
Copy link
Collaborator Author

totaam commented Apr 14, 2017

2017-04-14 07:46:20: antoine commented


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

@totaam
Copy link
Collaborator Author

totaam commented May 13, 2017

2017-05-13 08:01:03: antoine changed status from assigned to closed

@totaam
Copy link
Collaborator Author

totaam commented May 13, 2017

2017-05-13 08:01:03: antoine set resolution to wontfix

@totaam
Copy link
Collaborator Author

totaam commented May 13, 2017

2017-05-13 08:01:03: antoine commented


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.

@totaam totaam closed this as completed May 13, 2017
@totaam
Copy link
Collaborator Author

totaam commented Dec 31, 2019

2019-12-31 10:33:23: antoine commented


See also #1999#comment:15.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant