xpra icon
Bug tracker and wiki

Opened 4 years ago

Closed 3 months ago

#469 closed defect (wontfix)

Focus issue with mouse on osx client

Reported by: alas Owned by: Antoine Martin
Priority: major Milestone: 2.1
Component: client Version:
Keywords: osx focus Cc:

Description

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.

Attachments (25)

osx-cursor-focus-test1-edited.txt (69.9 KB) - added by alas 4 years ago.
Edited output from cursor/window focus issue
osx-cursor-focus-test1.txt (244.8 KB) - added by alas 4 years ago.
Full -d all output (--no-speaker) of cursor/window focus test
ticket469client-debug3.txt (13.4 KB) - added by alas 4 years ago.
Client-side -d focus output
ticket469-serverOutput3.txt.txt (15.8 KB) - added by alas 4 years ago.
Server-side -d focus output
ticket469-server-output4.txt.txt (17.1 KB) - added by alas 3 years ago.
First gedit test - server output
ticket469-server-output5.txt.txt (15.6 KB) - added by alas 3 years ago.
Second gedit test (with hints of before focus shift) - server output
ticket469-gedit_above_xterm.png (110.9 KB) - added by alas 3 years ago.
screenshot of gedit moved slightly askew from underlying xterm (buttons overlapping)
ticket469-xterm_above_gedit_cursor_shows_button_alt-img_from_underlying_gedit.png (104.4 KB) - added by alas 3 years ago.
screenshot after focus shifted to xterm from gedit, mouse wiggled over buttons until alt-img shows through
ticket469-server-output11.txt.txt (44.1 KB) - added by alas 3 years ago.
ticket469 server output with -d mouse, focus, osx client
ticket469-client-output11.txt (8.0 KB) - added by alas 3 years ago.
ticket469 osx client output -d focus,mouse
ticket469-server-output12.txt (219.5 KB) - added by alas 3 years ago.
ticket 469 server output with windows client and -d focus,mouse
ticket469-client-output12.txt (6.5 KB) - added by alas 3 years ago.
ticket 469 windows client output with -d focus,mouse (expected behavior)
ticket469-server-output13.txt.txt (141.5 KB) - added by alas 3 years ago.
server output, near failed run, 2/21 test
ticket469-client-output13.txt (12.3 KB) - added by alas 3 years ago.
client output, near failed run, 2/21 tests
ticket469-server-output14.txt.txt (55.4 KB) - added by alas 3 years ago.
server output, clean run, 2/21 tests
ticket469-client-output14.txt (9.5 KB) - added by alas 3 years ago.
client output, clean run, 2/21 tests
ticket469-server-output16.txt.txt (122.0 KB) - added by alas 3 years ago.
server output with -d focus,mouse,window,-encoding,-refresh
ticket469-client-output16.txt (25.6 KB) - added by alas 3 years ago.
client output with -d focus,mouse,window,-encoding,-refresh
ticket469-server-output-syncd3.txt.txt (102.2 KB) - added by alas 3 years ago.
server output with syncd time, 2/28 (action starts at 11:49:44,982)
ticket469-client-output-syncd3.txt (29.3 KB) - added by alas 3 years ago.
client output, syncd 2/28 (action starts at 11:49:44,954)
ticket469-repro.mov (1.4 MB) - added by alas 3 years ago.
ticket 469 repro movie (8 seconds)
osx-focus-bug.log (7.7 KB) - added by Antoine Martin 11 months ago.
reproduced with a button click
osx-notification-window.c (622 bytes) - added by Antoine Martin 11 months ago.
example code using the window from the notification object
ticket469_server-1-r13979_d-focus-logs.txt (24.7 KB) - added by alas 11 months ago.
server -d focus logs of a click through (1.0 r13979)
ticket469_client-1-r13977_d-focus-logs.txt (20.2 KB) - added by alas 11 months ago.
concise client logs of click through (1.0 r13977)

Change History (73)

Changed 4 years ago by alas

Edited output from cursor/window focus issue

Changed 4 years ago by alas

Attachment: osx-cursor-focus-test1.txt added

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

comment:1 Changed 4 years ago by Antoine Martin

Owner: changed from Antoine Martin to Antoine Martin
Status: newassigned

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

Last edited 4 years ago by Antoine Martin (previous) (diff)

comment:2 Changed 4 years ago by Antoine Martin

Owner: changed from Antoine Martin to alas
Status: assignednew

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.

Last edited 4 years ago by Antoine Martin (previous) (diff)

comment:3 Changed 4 years ago by alas

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.

Last edited 4 years ago by Antoine Martin (previous) (diff)

Changed 4 years ago by alas

Attachment: ticket469client-debug3.txt added

Client-side -d focus output

Changed 4 years ago by alas

Server-side -d focus output

comment:4 Changed 4 years ago by 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)

Last edited 4 years ago by Antoine Martin (previous) (diff)

comment:5 Changed 4 years ago by alas

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.

Last edited 4 years ago by Antoine Martin (previous) (diff)

comment:6 Changed 4 years ago by 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:

  • 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

comment:7 Changed 3 years ago by 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.

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

Changed 3 years ago by alas

First gedit test - server output

Changed 3 years ago by alas

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

Changed 3 years ago by alas

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

Changed 3 years ago by alas

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

comment:8 Changed 3 years ago by 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.

comment:9 Changed 3 years ago by 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.

comment:10 Changed 3 years ago by 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.

comment:11 Changed 3 years ago by 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.

Last edited 3 years ago by Antoine Martin (previous) (diff)

comment:12 Changed 3 years ago by 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.

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

Last edited 3 years ago by Antoine Martin (previous) (diff)

Changed 3 years ago by alas

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

Changed 3 years ago by alas

ticket469 osx client output -d focus,mouse

comment:13 Changed 3 years ago by alas

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.

Changed 3 years ago by alas

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

Changed 3 years ago by alas

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

comment:14 Changed 3 years ago by Antoine Martin

Owner: changed from alas to Antoine Martin
Status: newassigned

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

comment:15 Changed 3 years ago by Antoine Martin

Owner: changed from Antoine Martin to alas
Status: assignednew

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

  • as I move around gedit, lots of
    move_pointer(2, (226, 221))
    raising WindowModel(0xa00029)
    
  • as the tooltip shows up:
    Discovered new override-redirect window: 0xa00224 (tray=None)
    

followed by damage processing and not much else

  • as I move the mouse over to the xterm:
    move_pointer(1, (234, 144))
    raising WindowModel(0x800022)
    
  • shortly followed by the tooltip window being destroyed:
    lost_window: 3 - OverrideRedirectWindowModel(0xa00224)
    

Client side is straightforward:

  • the tooltip window appears:
    <class 'xpra.client.gtk2.client_window.ClientWindow'>(\
        <XpraClient object at 0x27c8550 (xpra+client+gtk2+client+XpraClient at 0x1f933a0)>, \
        <gtk.gdk.Window object at 0x7f72ac5ba280 (GdkWindow at 0x34ca6c0)>, \
        3, 156, 162, 143, 33, {'fullscreen': False, 'has-alpha': True, \
         'xid': '0xa00224', 'pid': 11722, 'window-type': ('TOOLTIP',), \
         'maximized': False, 'override-redirect': True}, \
        True, {}, 0)
    
  • add it loses focus:
    _unfocus() wid=3
    

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!

comment:16 Changed 3 years ago by 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.)


  • Nearly failed run"

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
  • after xpra info, with gedit window opened and still above xterm
    2014-02-21 14:40:45,378 raising WindowModel(0xc00025)
    2014-02-21 14:40:45,378 move_pointer(3, (460, 266))
    2014-02-21 14:40:45,397 raising WindowModel(0xc00025)
    2014-02-21 14:40:45,397 move_pointer(3, (525, 295))
    2014-02-21 14:40:45,404 raising WindowModel(0xc00025)
    2014-02-21 14:40:45,404 move_pointer(3, (643, 349))
    2014-02-21 14:40:47,103 process_focus: wid=0
    2014-02-21 14:40:47,103 focus wid=0 has_focus=3
    2014-02-21 14:40:47,104 reset_focus() 3 / WindowModel(0xc00025) had focus
    2014-02-21 14:40:47,104 reset_x_focus: widget with focus: None
    2014-02-21 14:40:47,104 Take Focus -> world window
    2014-02-21 14:40:47,104 sending WM_TAKE_FOCUS: 0x40001e, X11 timestamp=1484358L
    2014-02-21 14:40:55,570 New connection received: SocketConnection(/home/jimador/.xpra/elpatron.spikes.eng-23)
    2014-02-21 14:40:55,570 New connection received: SocketConnection(/home/jimador/.xpra/elpatron.spikes.eng-23)
    2014-02-21 14:40:55,573 Connection lost
    
  • and... after getting tooltip to show through (but requiring focus shift to terminal window to open log) - before clicking button
    2014-02-21 14:47:13,813 raising WindowModel(0xc00025)
    2014-02-21 14:47:13,813 move_pointer(3, (478, 463))
    2014-02-21 14:47:13,835 raising WindowModel(0xc00025)
    2014-02-21 14:47:13,835 move_pointer(3, (549, 509))
    2014-02-21 14:47:13,847 raising WindowModel(0xc00025)
    2014-02-21 14:47:13,847 move_pointer(3, (591, 537))
    2014-02-21 14:47:15,141 process_focus: wid=0
    2014-02-21 14:47:15,141 focus wid=0 has_focus=1
    2014-02-21 14:47:15,141 reset_focus() 1 / WindowModel(0xa00022) had focus
    2014-02-21 14:47:15,142 reset_x_focus: widget with focus: None
    2014-02-21 14:47:15,142 Take Focus -> world window
    2014-02-21 14:47:15,142 sending WM_TAKE_FOCUS: 0x40001e, X11 timestamp=1872396L
    

  • Second, cleaner run through

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
  • debugging output once window 2 has been pulled aside and used to create a gedit window, and after pulling the gedit window askew from the underlying xterm
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
  • and more output after clicking on xterm (for focus) and a second click, followed by mousing around over the portion of the xterm overlapping the gedit window buttons - with tooltip visible
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))

Changed 3 years ago by alas

server output, near failed run, 2/21 test

Changed 3 years ago by alas

client output, near failed run, 2/21 tests

Changed 3 years ago by alas

server output, clean run, 2/21 tests

Changed 3 years ago by alas

client output, clean run, 2/21 tests

comment:17 Changed 3 years ago by 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.

comment:18 Changed 3 years ago by 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.

Changed 3 years ago by alas

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

Changed 3 years ago by alas

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

comment:19 Changed 3 years ago by Antoine Martin

Here's what I see happening:

  • the TOOLTIP window appears:
    2014-02-22 09:31:23,393 Discovered new override-redirect window: 0xa00311 (tray=None)
    2014-02-22 09:31:23,397 grab: listening for: ['0xa00311L']
    
  • and disappears (2 minutes later???):
    2014-02-22 09:33:43,908 lost_window: 4 - OverrideRedirectWindowModel(0xa00311)
    2014-02-22 09:33:43,909 grab: unmap
    
  • the client tells us that the xterm has lost focus:
    2014-02-22 09:33:43,998 process_focus: wid=0
    2014-02-22 09:33:43,998 focus wid=0 has_focus=1
    
  • then the client tells us that the gedit window has gained focus:
    2014-02-22 09:33:43,999 process_focus: wid=3
    2014-02-22 09:33:44,000 focus wid=3 has_focus=0
    

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)

Last edited 3 years ago by Antoine Martin (previous) (diff)

comment:20 Changed 3 years ago by 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.

Changed 3 years ago by alas

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

Changed 3 years ago by alas

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

comment:21 Changed 3 years ago by 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.

comment:22 Changed 3 years ago by 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.

comment:23 Changed 3 years ago by 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)

Last edited 3 years ago by Antoine Martin (previous) (diff)

comment:24 Changed 3 years ago by alas

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

  • I'm afraid I find that I'm still able to click "through" one window (an xterm in this case) in order to trigger buttons on a window apparently below (gedit in this case).

comment:25 Changed 3 years ago by Antoine Martin

Milestone: 0.15

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.

Changed 3 years ago by alas

Attachment: ticket469-repro.mov added

ticket 469 repro movie (8 seconds)

comment:26 Changed 3 years ago by Antoine Martin

Owner: changed from alas to Antoine Martin
Status: newassigned

Thanks! I've reproduced it!

comment:27 Changed 3 years ago by Antoine Martin

Owner: changed from Antoine Martin to alas
Status: assignednew

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

  • mouse moving over xterm (wid=1):
    do_motion_notify_event(<gtk.gdk.Event at 0x19229dd0: GDK_MOTION_NOTIFY x=466.00, y=163.00>) wid=1, pointer=(470, 208), modifiers=['mod2'], buttons=[]
    
  • left click on xterm:
    _button_action(1, <gtk.gdk.Event at 0x19229dd0: GDK_BUTTON_PRESS x=466.00, y=163.00, button=1>, True) wid=1, pointer=(470, 208), modifiers=['mod2'], buttons=[]
    _button_action(1, <gtk.gdk.Event at 0x19229f80: GDK_BUTTON_RELEASE x=466.00, y=163.00, button=1>, False) wid=1, pointer=(470, 208), modifiers=['mod2'], buttons=[1]
    
  • next motion event that comes:
    do_motion_notify_event(<gtk.gdk.Event at 0x19229dd0: GDK_MOTION_NOTIFY x=183.00, y=35.00>) wid=3, pointer=(470, 209), modifiers=['mod2'], buttons=[]
    

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.

comment:28 Changed 3 years ago by 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?

comment:29 Changed 3 years ago by 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.

comment:30 Changed 3 years ago by alas

Owner: changed from alas to Antoine Martin

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.

comment:31 Changed 3 years ago by Antoine Martin

Resolution: fixed
Status: newclosed

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

comment:32 Changed 3 years ago by Antoine Martin

Resolution: fixed
Status: closedreopened

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

comment:33 Changed 3 years ago by 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

Last edited 2 years ago by Antoine Martin (previous) (diff)

comment:34 Changed 16 months ago by Antoine Martin

Milestone: 0.150.18

re-scheduling

comment:35 Changed 13 months ago by Antoine Martin

Milestone: 0.181.0

Milestone renamed

comment:36 Changed 11 months ago by Antoine Martin

Last edited 11 months ago by Antoine Martin (previous) (diff)

comment:37 Changed 11 months ago by Antoine Martin

Owner: changed from Antoine Martin to alas
Status: reopenednew

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)

comment:38 Changed 11 months ago by 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.)

comment:39 Changed 11 months ago by Antoine Martin

Last edited 11 months ago by Antoine Martin (previous) (diff)

comment:40 Changed 11 months ago by Antoine Martin

Owner: changed from alas to Antoine Martin
Status: newassigned

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

Last edited 11 months ago by Antoine Martin (previous) (diff)

comment:41 Changed 11 months ago by 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.

Changed 11 months ago by Antoine Martin

Attachment: osx-focus-bug.log added

reproduced with a button click

comment:42 Changed 11 months ago by 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:

  • 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

Changed 11 months ago by Antoine Martin

Attachment: osx-notification-window.c added

example code using the window from the notification object

comment:43 Changed 11 months ago by Antoine Martin

Owner: changed from Antoine Martin to alas
Status: assignednew

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

Last edited 11 months ago by Antoine Martin (previous) (diff)

comment:44 Changed 11 months ago by alas

Owner: changed from alas to Antoine Martin

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.

Changed 11 months ago by alas

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

Changed 11 months ago by alas

concise client logs of click through (1.0 r13977)

comment:45 Changed 5 months ago by Antoine Martin

Milestone: 1.02.1
Status: newassigned

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

comment:46 Changed 5 months ago by 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.

comment:47 Changed 4 months ago by Antoine Martin

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

comment:48 Changed 3 months ago by Antoine Martin

Resolution: wontfix
Status: assignedclosed

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.

Note: See TracTickets for help on using tickets.