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

Significant delay when closing any app window/dialog which was started with Wine #3478

Closed
vrzh opened this issue Feb 28, 2022 · 15 comments
Closed
Labels
bug Something isn't working

Comments

@vrzh
Copy link

vrzh commented Feb 28, 2022

Describe the bug
When using the built-in window manager in Xpra and launching an application under Wine, there is a significant delay (for me it is around 3 seconds) when closing any window or dialog box.

To Reproduce
Steps to reproduce the behavior:

  1. server command xpra start --daemon=no --start=winecfg
  2. client command xpra attach
  3. specific action to trigger the bug

winecfg is a built-in configuration app which comes with Wine, but the issue can be reproduced with any app running under Wine. To reproduce (when winecfg loads), click "Add application..." to open up a dialog box, then click "Cancel". There will be a delay of approximately 3 seconds before the dialog box closes and on the server console, a Wine log message will be printed:

0104:fixme:event:wait_for_withdrawn_state window 0x2007c/1800006 wait timed out

This issue does not happen if I use another window manager, e.g. Openbox. But, I would really prefer to use the built-in window manager of Xpra.

System Information (please complete the following information):

  • Server OS: Ubuntu 20.04
  • Client OS: Ubuntu 20.04 (same machine)
  • Xpra Server Version xpra v4.4-r31013 (g4e0fec250)
  • Xpra Client Version xpra v4.4-r31013 (g4e0fec250) (same machine)

Additional context
Add any other context about the problem here.
Please see "reporting bugs" in the wiki section.

@vrzh vrzh added the bug Something isn't working label Feb 28, 2022
@totaam
Copy link
Collaborator

totaam commented Mar 1, 2022

With full debug enabled:

processing packet close-window
process ui packet close-window
client closed window 42 - WindowModel(0x220000b)
sending WM_DELETE_WINDOW to 0x220000b
sendClientMessage(0x220000b, 0x220000b, 0x0, 0x0, WM_PROTOCOLS, WM_DELETE_WINDOW, 0, 0, 0, 0)
x_event_filter event=('xpra-damage-event', None)/DamageNotify window=0x220000b

The window itself:

xwininfo: Window id: 0x2200010 "Select an executable file"

  Absolute upper-left X:  4449
  Absolute upper-left Y:  255
  Relative upper-left X:  0
  Relative upper-left Y:  0
  Width: 422
  Height: 248
  Depth: 24
  Visual: 0x21
  Visual Class: TrueColor
  Border width: 0
  Class: InputOutput
  Colormap: 0x2000001 (not installed)
  Bit Gravity State: NorthWestGravity
  Window Gravity State: NorthWestGravity
  Backing Store State: NotUseful
  Save Under State: yes
  Map State: IsViewable
  Override Redirect State: no
  Corners:  +4449+255  -3321+255  -3321-3593  +4449-3593
  -geometry 422x248+4449+255
_NET_WM_DESKTOP(CARDINAL) = 0
_XPRA_WID(CARDINAL) = 43
WM_STATE(WM_STATE):
		window state: Normal
		icon window: <field not available>
_NET_FRAME_EXTENTS(CARDINAL) = 0, 0, 37, 0
_NET_WM_ALLOWED_ACTIONS(ATOM) = _NET_WM_ACTION_CLOSE, _NET_WM_ACTION_MOVE, _NET_WM_ACTION_RESIZE, _NET_WM_ACTION_FULLSCREEN, _NET_WM_ACTION_MINIMIZE, _NET_WM_ACTION_SHADE, _NET_WM_ACTION_STICK, _NET_WM_ACTION_MAXIMIZE_HORZ, _NET_WM_ACTION_MAXIMIZE_VERT, _NET_WM_ACTION_CHANGE_DESKTOP, _NET_WM_ACTION_ABOVE, _NET_WM_ACTION_BELOW
_NET_WM_ICON(CARDINAL) = 	Icon (32 x 32):
	                                
	           ░░░░░░░░░░           
	          ░░       ░░░          
	          ░░░░░  ░░░░░          
	          ░          ░          
	          ░          ░          
	                     ░          
	         ░         ░ ░░         
	         ░      ░░░░░ ░         
	         ░    ░▒▒▒░░░ ░         
	         ░▒░░░▓▓▓▓▓▓▓░░         
	         ▒▓░░░▓▓▓▒▒▒▒▒░         
	         ▒▓░░░▒▒░░░▒▒▒░         
	         ▒▓░░▒▓▓▓▓▓▓▓▒░         
	         ░▓▓░▒▓▓▓▓▓▓▓░░         
	         ░▒▓▒▒▓▓▓▓▓▓▒░░         
	          ░▒▓▓▓▓▓▓▓▒░░          
	           ░▒▒▓▓▓▒░░░           
	            ░░░▒░░░░            
	             ░░░░░░             
	              ░░▒░              
	              ░░░░              
	               ░░               
	               ░░               
	               ░░               
	               ░░               
	             ░░░▒░░░            
	           ░   ░░   ░           
	          ░   ░░░░░  ░          
	          ░░        ░░          
	           ░░░░░░░░░░           
	                                


_NET_WM_STATE(ATOM) = _NET_WM_STATE_FOCUSED, _NET_WM_STATE_SKIP_TASKBAR
_NET_WM_NAME(UTF8_STRING) = "Select an executable file"
WM_ICON_NAME(STRING) = "Select an executable file"
WM_NAME(STRING) = "Select an executable file"
WM_HINTS(WM_HINTS):
		Client accepts input or input focus: False
		Initial state is Normal State.
		bitmap id # to use for icon: 0x2000427
		bitmap id # of mask for icon: 0x2000429
		window id # of group leader: 0x2200003
_NET_WM_WINDOW_TYPE(ATOM) = _NET_WM_WINDOW_TYPE_DIALOG
WM_TRANSIENT_FOR(WINDOW): window id # 0x2200003
_MOTIF_WM_HINTS(_MOTIF_WM_HINTS) = 0x3, 0x26, 0x1a, 0x0, 0x0
WM_NORMAL_HINTS(WM_SIZE_HINTS):
		program specified location: 4301, 258
		window gravity: Static
_NET_WM_USER_TIME_WINDOW(WINDOW): window id # 0x2000010
XdndAware(ATOM) = BITMAP
_NET_WM_PID(CARDINAL) = 721789
WM_LOCALE_NAME(STRING) = "en_GB.UTF-8"
WM_CLIENT_MACHINE(STRING) = "localhost.localdomain"
WM_CLASS(STRING) = "winecfg.exe", "winecfg.exe"
WM_PROTOCOLS(ATOM): protocols  WM_DELETE_WINDOW, _NET_WM_PING, WM_TAKE_FOCUS

So the window claims to support WM_DELETE_WINDOW, which we dutifully send when the close button is clicked.
What action to take when it receives WM_DELETE_WINDOW is entirely up to the application. Some applications will show a confirmation dialog, ask the user if documents should be saved, etc..

Based on this wine ticket: Lot of wait_for_withdrawn_state when running with xvfb-run and wine fixme wait_for_withdrawn_state window - the claim made there is that the window is withdrawn.

Unfortunately, as can be seen above, the window is definitely not in a withdrawn state:

# xprop | grep -i state
WM_STATE(WM_STATE):
		window state: Normal
_NET_WM_STATE(ATOM) = _NET_WM_STATE_FOCUSED, _NET_WM_STATE_SKIP_TASKBAR
		Initial state is Normal State.
# xwininfo | grep "Map State:"
Map State: IsViewable

Unless wine is waiting for the window to be withdrawn by xpra instead?
(I think that this would be an unreasonable expectation - not the window manager's job at this point)
Here are the only X11 messages we receive after sending WM_DELETE_WINDOW:

DamageNotify event 0x1f78 : <X11:DamageNotify {'send_event': '0', 'serial': '0x1f78', 'delivered_to': '0x1600006', 'window': '0x1600006', 'damage': '2097415', 'x': '102', 'y': '170', 'width': '197', 'height': '13'}>
PropertyNotify event 0x1f7d : <X11:PropertyNotify {'send_event': '0', 'serial': '0x1f7d', 'delivered_to': '0x1600003', 'window': '0x1600003', 'atom': 'WM_NORMAL_HINTS', 'time': '268486243'}>
WM_NORMAL_HINTS={'position': (3979, 298), 'min_size': (410, 411), 'max_size': (410, 411), 'win_gravity': 10}
PropertyNotify event 0x1f7d : <X11:PropertyNotify {'send_event': '0', 'serial': '0x1f7d', 'delivered_to': '0x1600003', 'window': '0x1600003', 'atom': '_MOTIF_WM_HINTS', 'time': '268486243'}>
_MOTIF_WM_HINTS=MotifWMHints({'flags': ('functions', 'decorations'), 'functions': ('move', 'close'), 'decorations': ('border', 'title', 'menu'), 'input_mode': 'modeless', 'status': ()})
PropertyNotify event 0x1f7d : <X11:PropertyNotify {'send_event': '0', 'serial': '0x1f7d', 'delivered_to': '0x1600003', 'window': '0x1600003', 'atom': '_NET_WM_WINDOW_TYPE', 'time': '268486243'}>
_NET_WM_WINDOW_TYPE=['_NET_WM_WINDOW_TYPE_NORMAL']
PropertyNotify event 0x1f7d : <X11:PropertyNotify {'send_event': '0', 'serial': '0x1f7d', 'delivered_to': '0x1600003', 'window': '0x1600003', 'atom': 'WM_HINTS', 'time': '268486243'}>
getWMHints(0x1600003)={'input': 0, 'initial_state': 1, 'icon_pixmap': 20971581, 'icon_mask': 20971583, 'window_group': 23068675}
PropertyNotify event 0x1f7d : <X11:PropertyNotify {'send_event': '0', 'serial': '0x1f7d', 'delivered_to': '0x1600003', 'window': '0x1600003', 'atom': '_NET_WM_ICON', 'time': '268486243'}>
_NET_WM_ICON changed on 0x1600003, re-reading
DamageNotify event 0x1f7d : <X11:DamageNotify {'send_event': '0', 'serial': '0x1f7d', 'delivered_to': '0x1600006', 'window': '0x1600006', 'damage': '2097415', 'x': '6', 'y': '30', 'width': '408', 'height': '153'}>

And I don't see any message in there that should make us withdraw the window..
After the 2 second delay, the window is withdrawn by wine:

UnmapNotify event 0x1c72 : <X11:UnmapNotify {'send_event': '0', 'serial': '0x1c72', 'delivered_to': '0x160000a', 'window': '0x160000a'}>

@vrzh
Copy link
Author

vrzh commented Mar 2, 2022

Thanks @totaam, this helps a lot to understand what is going on. I initially thought that this is an xpra issue because when explicitly using a different window manager (openbox) then everything works fine:

xpra start-desktop --daemon=no --start=openbox

I think for now, I will use openbox.

@totaam
Copy link
Collaborator

totaam commented Mar 3, 2022

Further, none of the X11 property messages should affect the window's visibility:

  • WM_NORMAL_HINTS={'position': (4303, 309), 'min_size': (410, 411), 'max_size': (410, 411), 'win_gravity': 10} - that's unchanged and still on-screen
  • _MOTIF_WM_HINTS=MotifWMHints({'flags': ('functions', 'decorations'), 'functions': ('move', 'close'), 'decorations': ('border', 'title', 'menu'), 'input_mode': 'modeless', 'status': ()})
  • _NET_WM_WINDOW_TYPE=['_NET_WM_WINDOW_TYPE_NORMAL'] (unchanged)
  • getWMHints(0x1800003)={'input': 0, 'initial_state': 1, 'icon_pixmap': 23068733, 'icon_mask': 23068735, 'window_group': 25165827}

@totaam
Copy link
Collaborator

totaam commented Sep 5, 2022

With fluxbox (which is simpler than openbox) and running x11trace --timestamps winecfg:

1662393651.245 008:>:00ff: Event (generated) ClientMessage(33) format=0x20 window=0x01e00003 type=0xed("WM_PROTOCOLS") data=0xeb,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00;

(0xeb corresponds to WM_DELETE_WINDOW)
This is the only message that the window manager sends to the application before it unmaps the window with a Request(10): UnmapWindow window=0x01a00003.

And xpra sends a 100% identical message:

1662393897.039 008:>:015f: Event (generated) ClientMessage(33) format=0x20 window=0x01a00003 type=0xed("WM_PROTOCOLS") data=0xeb,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00;

So whatever logic makes wine behave differently is not related to the WM_DELETE_WINDOW message we send, but to some other window property, window hierarchy, etc..


Looking at this from the other end.
The wine handler for WM_DELETE_WINDOW is not particularly enlightening.

wait_for_withdrawn_state is the function that triggers the warning, it is called from:

Only the latter is relevant here and is called from:

It's really not clear to me which one is being called!

@totaam
Copy link
Collaborator

totaam commented Sep 11, 2022

Upstream wine ticket: wait_for_withdrawn_state

@totaam
Copy link
Collaborator

totaam commented Oct 13, 2022

I don't think winehq's bug tracker is very active. Without clarifications from the developers, there is absolutely nothing I can do here.

@totaam totaam closed this as not planned Won't fix, can't repro, duplicate, stale Oct 13, 2022
@totaam
Copy link
Collaborator

totaam commented Feb 13, 2024

Running with x11trace under Xephyr + fluxbox, I see when closing the window:

007:>:00d5: Event KeyRelease(3) keycode=0x40 time=0x0f579431 root=0x000003fd event=0x01200001 child=None(0x00000000) root-x=949 root-y=67 event-x=791 event-y=-17 state=Mod1,Mod2 same-screen=true(0x01)
001:>:011f: Event Generic(35) XInputExtension(131) RawButtonPress(15) extension=0x83 length=14 evtype=0x000f data=0x02,0x00,0x31,0x94,0x57,0x0f,0x01,0x00,0x00,0x00,0x07,0x00,0x02,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x07,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00;
001:>:011f: Event Generic(35) XInputExtension(131) RawButtonRelease(16) extension=0x83 length=14 evtype=0x0010 data=0x02,0x00,0xd8,0x94,0x57,0x0f,0x01,0x00,0x00,0x00,0x07,0x00,0x02,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x07,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00;
007:>:00d5: Event (generated) ClientMessage(33) format=0x20 window=0x01200001 type=0xe5("WM_PROTOCOLS") data=0xe8,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00;
007:<:00d6:  8: Request(10): UnmapWindow window=0x01200001
007:<:00d7: 44: Request(25): SendEvent propagate=false(0x00) destination=0x000003fd event-mask=SubstructureNotify,SubstructureRedirect UnmapNotify(18) event=0x000003fd window=0x01200001 from-configure=false(0x00)
007:<:00d8: 96: Request(18): ChangeProperty mode=Replace(0x00) window=0x01200001 property=0x28("WM_NORMAL_HINTS") type=0x29("WM_SIZE_HINTS") data=0x00000204,0x0000009e,0x00000054,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x00000000,0x0000000a;
007:<:00d9: 44: Request(18): ChangeProperty mode=Replace(0x00) window=0x01200001 property=0xeb("_MOTIF_WM_HINTS") type=0xeb("_MOTIF_WM_HINTS") data=0x00000003,0x0000003e,0x0000007a,0x00000000,0x00000000;
007:<:00da: 24: Request(18): ChangeProperty mode=Replace(0x00) window=0x01200001 property=0x11d("_NET_WM_STATE") type=0x4("ATOM") data=;
007:>:00da: Event UnmapNotify(18) event=0x01200001 window=0x01200001 from-configure=false(0x00)
007:>:00da: Event FocusOut(10) detail=Ancestor(0x00) event=0x01200001 mode=Normal(0x00)
007:<:00db: 28: Request(12): ConfigureWindow window=0x01200001 values={x=158 y=84 width=800 height=415}
007:>:00db: Event PropertyNotify(28) window=0x01200001 atom=0x28("WM_NORMAL_HINTS") time=0x0f5794de state=NewValue(0x00)
007:>:00db: Event PropertyNotify(28) window=0x01200001 atom=0xeb("_MOTIF_WM_HINTS") time=0x0f5794de state=NewValue(0x00)
007:>:00db: Event PropertyNotify(28) window=0x01200001 atom=0x11d("_NET_WM_STATE") time=0x0f5794de state=NewValue(0x00)
007:>:00db: Event ReparentNotify(21) event=0x01200001 window=0x01200001 parent=0x000003fd x=158 y=84 override-redirect=false(0x00)
007:>:00db: Event PropertyNotify(28) window=0x01200001 atom=0x11d("_NET_WM_STATE") time=0x0f5794de state=Deleted(0x01)
007:>:00db: Event PropertyNotify(28) window=0x01200001 atom=0x114(unrecognized atom) time=0x0f5794de state=Deleted(0x01)
007:>:00db: Event PropertyNotify(28) window=0x000003fd atom=0x109("_NET_ACTIVE_WINDOW") time=0x0f5794df state=NewValue(0x00)
007:>:00db: Event PropertyNotify(28) window=0x000003fd atom=0x103(unrecognized atom) time=0x0f5794df state=NewValue(0x00)
007:>:00db: Event PropertyNotify(28) window=0x000003fd atom=0x104(unrecognized atom) time=0x0f5794df state=NewValue(0x00)
006:<:02ef:  8: Request(60): FreeGC gc=0x0100005d
006:<:02f0: 16: Request(55): CreateGC cid=0x01000075 drawable=0x01200001 values={}
006:<:02f1: 12: Request(59): SetClipRectangles ordering=YXBanded(0x03) gc=0x01000075 clip-x-origin=-4 clip-y-origin=-30 rectangles=;
006:<:02f2: 12: Request(59): SetClipRectangles ordering=YXBanded(0x03) gc=0x01000075 clip-x-origin=-4 clip-y-origin=-30 rectangles=;
006:<:02f3: 12: Request(59): SetClipRectangles ordering=YXBanded(0x03) gc=0x01000075 clip-x-origin=-4 clip-y-origin=-30 rectangles=;
006:<:02f4:  4: Request(43): GetInputFocus 
006:>:02f4:32: Reply to GetInputFocus: revert-to=PointerRoot(0x01) focus=0x0060000c
007:<:00dc:  8: Request(4): DestroyWindow window=0x01200003
007:>:00dc: Event DestroyNotify(17) event=0x01200003 window=0x01200003
006:<:02f5:  4: Request(43): GetInputFocus 
006:>:02f5:32: Reply to GetInputFocus: revert-to=PointerRoot(0x01) focus=0x0060000c
007:<:00dd:  8: Request(4): DestroyWindow window=0x01200002
007:>:00dd: Event DestroyNotify(17) event=0x01200002 window=0x01200002
007:>:00dd: Event PropertyNotify(28) window=0x000003fd atom=0x103(unrecognized atom) time=0x0f5794e8 state=NewValue(0x00)
007:>:00dd: Event PropertyNotify(28) window=0x000003fd atom=0x104(unrecognized atom) time=0x0f5794e8 state=NewValue(0x00)
006:<:02f6:  4: Request(43): GetInputFocus 
006:>:02f6:32: Reply to GetInputFocus: revert-to=PointerRoot(0x01) focus=0x0060000c
007:<:00de:  8: Request(4): DestroyWindow window=0x01200001

TILS:

  • RawButtonRelease
  • WM_PROTOCOLS is a WM_DELETE
  • UnmapWindow
  • UnmapNotify

@totaam totaam reopened this Feb 13, 2024
@totaam
Copy link
Collaborator

totaam commented Feb 14, 2024

wine is sending the UnmapNotify event to the root window instead of the parent window of its window - with x11trace within the xpra session:

007:<:0155: 44: Request(25): SendEvent propagate=false(0x00) destination=0x0000044c event-mask=SubstructureNotify,SubstructureRedirect UnmapNotify(18) event=0x0000044c window=0x01600003 from-configure=false(0x00)
$ xwininfo -id 0x44c | grep xwininfo
xwininfo: Window id: 0x44c (the root window) "Xpra"

Which is why we never see this event and x11trace does.
As per the spec 10.10.9 UnmapNotify Events: The event member is set either to the unmapped window or to its parent, depending on whether StructureNotify or SubstructureNotify was selected. This is the window used by the X server to report the event.

I will have a workaround for this.

@totaam
Copy link
Collaborator

totaam commented Feb 15, 2024

Maybe nothing to do with the root window, we just don't get the UnmapNotify event.
Despite selecting for it, and verifying that the corral window has it in its mask (as does the root window):

client window 1600003 mask: ['StructureNotify', 'FocusChange', 'PointerMotion', 'PointerMotionHint', 'ButtonMotion', 'PropertyChange'], do-not-propagate: []
corral 400064 mask: ['StructureNotify', 'SubstructureNotify', 'SubstructureRedirect', 'PropertyChange'], do-not-propagate: []
root 44c mask: ['StructureNotify', 'SubstructureNotify', 'SubstructureRedirect', 'FocusChange'], do-not-propagate: []

But when the application calls UnmapWindow (as seen with x11trace), we don't get any events on the root or corral window...
The do-not-propagate mask is not relevant here since it only applies to key / button / motion events - but shown for completeness.

The spec says: To receive UnmapNotify events, set the StructureNotifyMask bit in the event-mask attribute of the window or the SubstructureNotifyMask bit in the event-mask attribute of the parent window (in which case, unmapping any child window generates an event).


Similar symptoms in other projects:

The difference is that they were not withdrawing the window by updating WM_STATE.
Our problem is that we don't get the UnmapNotify event. Same result.

@totaam
Copy link
Collaborator

totaam commented Feb 15, 2024

Looking at the X11 server source:
UnmapWindow:
https://gitlab.freedesktop.org/xorg/xserver/-/blob/a8bb924af19f8666a39db2cf50b0c7f00564db06/dix/window.c#L2836-L2875
calls DeliverUnmapNotify:
https://gitlab.freedesktop.org/xorg/xserver/-/blob/a8bb924af19f8666a39db2cf50b0c7f00564db06/dix/window.c#L2825-L2834
if SubStrSend(pWin, pParent) which is:

#define SubSend(pWin) \
    ((pWin->eventMask|wOtherEventMasks(pWin)) & SubstructureNotifyMask)

#define StrSend(pWin) \
    ((pWin->eventMask|wOtherEventMasks(pWin)) & StructureNotifyMask)

#define SubStrSend(pWin,pParent) (StrSend(pWin) || SubSend(pParent))

So it checks StructureNotifyMask on the window or SubstructureNotifyMask on the parent window.
There is a shortcut if the window is not mapped, or does not have a parent.


DeliverEvents
The event is set to the window: https://gitlab.freedesktop.org/xorg/xserver/-/blob/a8bb924af19f8666a39db2cf50b0c7f00564db06/dix/events.c#L2945
Events are delivered to that window with StructureNotifyMask: https://gitlab.freedesktop.org/xorg/xserver/-/blob/a8bb924af19f8666a39db2cf50b0c7f00564db06/dix/events.c#L2967-L2968 and to its parent with SubstructureNotifyMask: https://gitlab.freedesktop.org/xorg/xserver/-/blob/a8bb924af19f8666a39db2cf50b0c7f00564db06/dix/events.c#L2971-L2972 via DeliverEventsToWindow which then calls DeliverEventToWindowMask.
GetClientsForDelivery first verifies that at least one client has a matching input mask then DeliverEventToInputClients goes through this list of clients and TryClientEvents delegates to WriteEventsToClient which calls WriteToClient

@totaam
Copy link
Collaborator

totaam commented Feb 15, 2024

Running xpra via x11trace (rather than the application itself):

  • start a vfb on :200 (ie: xpra start :200 followed by xpra exit)
  • x11trace -d :200 -D :400 -n -k -o trace
  • xpra start :400 --use-display

Does not show the UnmapNotify event being sent from the vfb to xpra - only the one that comes later after the timeout:

005:>:25ed: Event UnmapNotify(18) event=0x01800003 window=0x01800003 from-configure=false(0x00)
005:>:25ed: Event UnmapNotify(18) event=0x004000b4 window=0x01800003 from-configure=false(0x00)
005:>:25ed: Event (generated) UnmapNotify(18) event=0x0000044c window=0x01800003 from-configure=false(0x00)
005:>:25ed: Event PropertyNotify(28) window=0x01800003 atom=0x28("WM_NORMAL_HINTS") time=0x1485d9ce state=NewValue(0x00)
005:>:25ed: Event PropertyNotify(28) window=0x01800003 atom=0x146("_MOTIF_WM_HINTS") time=0x1485d9ce state=NewValue(0x00)
005:>:25ed: Event PropertyNotify(28) window=0x01800003 atom=0xf2("_NET_WM_STATE") time=0x1485d9ce state=NewValue(0x00)
005:>:25ed: Event ConfigureRequest(23) parent=0x004000b4 window=0x01800003 value-mask=x,y,width,height stack-mode=Above(0x00) sibling=None(0x00000000) x=718 y=287 width=800 height=415 border-width=0
005:<:25ee: 16: Request(16): InternAtom only-if-exists=false(0x00) name='WINDOW'
005:>:25ee:32: Reply to InternAtom: atom=0x21("WINDOW")
005:<:25ef: 28: Request(18): ChangeProperty mode=Replace(0x00) window=0x0000044c property=0x135("_NET_CLIENT_LIST") type=0x21("WINDOW") data=0x0020000c;
005:<:25f0:  4: Request(43): GetInputFocus 

So the event is not forwarded by the X11 server. Why?

@totaam
Copy link
Collaborator

totaam commented Feb 16, 2024

Running a modified Xvfb binary to see the events, I eventually (..) noticed that the window wine uses with UnmapWindow following the delete request is this one:

     0xe00003 (has no name): ()  1x1+0+0  +0+0

And not the main window.
And since this event window is not mapped in the first place... the UnmapNotify doesn't make it past this check:
https://gitlab.freedesktop.org/xorg/xserver/-/blob/a8bb924af19f8666a39db2cf50b0c7f00564db06/dix/window.c#L2852

    if ((!pWin->mapped) || (!(pParent = pWin->parent)))
        return Success;

When running under openbox, wine uses the main window with UnmapNotify.


So my new working hypothesis is that despite us sending the correct window with the WM_DELETE_WINDOW message - just like openbox, wine picks a different window to wait on - perhaps they're stored in a different order somewhere? Is it closing all the windows and not just the one we requested?

I believe this is where it ends up calling unmap_window:
https://github.com/wine-mirror/wine/blob/bbf222ca726db1efaa7c0a4d33194b03e45cea0f/dlls/winex11.drv/window.c#L2728-L2739
And unmap_window:
https://github.com/wine-mirror/wine/blob/bbf222ca726db1efaa7c0a4d33194b03e45cea0f/dlls/winex11.drv/window.c#L1250-L1273
Will wait wait_for_withdrawn_state:
https://github.com/wine-mirror/wine/blob/bbf222ca726db1efaa7c0a4d33194b03e45cea0f/dlls/winex11.drv/event.c#L1326-L1381
But we have no reason to change the state of this window - it's just a 1x1 event window that we never forward, which is never mapped (by us or wine) and never registered.

@totaam
Copy link
Collaborator

totaam commented Feb 16, 2024

Also tried via winedbg - I hit the wait_for_withdrawn_state timeout but not any XUnmapWindow or XWithdrawWindow!?
So where is the event I am seeing in x11trace coming from then?

Wine-gdb> break XWithdrawWindow
Breakpoint 1 at 0x7f6114a83190: file /usr/src/debug/libX11-1.8.7-1.fc39.x86_64/src/Withdraw.c, line 69.
Wine-gdb> break XUnmapWindow
Breakpoint 2 at 0x7f6114a83120: file /usr/src/debug/libX11-1.8.7-1.fc39.x86_64/src/UnmapWin.c, line 36.
Wine-gdb> cont
Continuing.
0128:012c: loads DLL C:\windows\system32\ole32.dll @00006FFFFE460000 (5763072<15022>)
0128:012c: loads DLL C:\windows\system32\combase.dll @00006FFFFE2B0000 (1675264<7925>)
0128:012c: loads DLL C:\windows\system32\rpcrt4.dll @00006FFFFD790000 (2662400<9710>)
0128:012c: loads DLL C:\windows\system32\coml2.dll @00006FFFFD730000 (307200<3977>)
0128:012c: loads DLL C:\windows\system32\msimg32.dll @00006FFFFB950000 (94208<661>)
012c:fixme:event:wait_for_withdrawn_state window 0x10074/1800003 wait timed out

Breakpoint 1, XWithdrawWindow (dpy=0x7d7d004d3730, w=25165827, screen=0) at /usr/src/debug/libX11-1.8.7-1.fc39.x86_64/src/Withdraw.c:69
69      {
Wine-gdb> bt
#0  XWithdrawWindow (dpy=0x7d7d004d3730, w=25165827, screen=0) at /usr/src/debug/libX11-1.8.7-1.fc39.x86_64/src/Withdraw.c:69
#1  0x00007f6114beaff4 in unmap_window (hwnd=hwnd@entry=0x10074) at dlls/winex11.drv/window.c:1293
#2  0x00007f6114bf001b in X11DRV_WindowPosChanged (hwnd=0x10074, insert_after=<optimized out>, swp_flags=6335, rectWindow=0x1000fedf0, rectClient=<optimized out>, visible_rect=<optimized out>, valid_rects=0x0, 
    surface=0x7f6115498480 <dummy_surface>) at dlls/winex11.drv/window.c:2833
#3  0x00007f611544a13c in apply_window_pos (hwnd=0x10074, insert_after=0x0, swp_flags=6335, window_rect=window_rect@entry=0x1000fedf0, client_rect=client_rect@entry=0x1000fee00, valid_rects=0x0, 
    valid_rects@entry=0x1000fee10) at dlls/win32u/window.c:1937
#4  0x00007f611544c977 in set_window_pos (winpos=winpos@entry=0x1000feef0, parent_x=parent_x@entry=0, parent_y=parent_y@entry=0) at dlls/win32u/window.c:3451
#5  0x00007f611544bbbd in NtUserSetWindowPos (hwnd=hwnd@entry=0x10074, after=after@entry=0x0, x=x@entry=0, y=y@entry=0, cx=cx@entry=0, cy=cy@entry=0, flags=151) at dlls/win32u/window.c:3546
#6  0x00007f61154515b5 in NtUserDestroyWindow (hwnd=0x10074) at dlls/win32u/window.c:4815
#7  0x00007f6122fa754d in __wine_syscall_dispatcher () from /usr/bin/../lib64/wine/x86_64-unix/ntdll.so
#8  0x00007f611541461a in dispatch_win_proc_params (params=params@entry=0x1000ff540, size=size@entry=80, client_ret=client_ret@entry=0x1000ff4e0, client_ret_size=client_ret_size@entry=0x1000ff4e8)
    at dlls/win32u/message.c:428
#9  0x00007f611541b4ff in call_window_proc (hwnd=0x10074, msg=16, wparam=0, lparam=0, type=MSG_UNICODE, same_thread=<optimized out>, mapping=WMCHAR_MAP_SENDMESSAGETIMEOUT, ansi_dst=0)
    at dlls/win32u/message.c:2220
#10 0x00007f611541aad3 in process_message (info=info@entry=0x1000ff6a0, res_ptr=res_ptr@entry=0x1000ff698, ansi=ansi@entry=0) at dlls/win32u/message.c:4033
#11 0x00007f611541adf1 in send_message_timeout (hwnd=hwnd@entry=0x10074, msg=msg@entry=16, wparam=wparam@entry=0, lparam=lparam@entry=0, flags=flags@entry=0, timeout=timeout@entry=0, ansi=0)
    at dlls/win32u/message.c:4203
#12 0x00007f611541b9b5 in send_message (hwnd=hwnd@entry=0x10074, msg=msg@entry=16, wparam=wparam@entry=0, lparam=lparam@entry=0) at dlls/win32u/message.c:4210
#13 0x00007f611539abd1 in handle_sys_command (lparam=0, wparam=61536, hwnd=0x10074) at dlls/win32u/defwnd.c:988
#14 default_window_proc (hwnd=0x10074, msg=<optimized out>, wparam=61536, lparam=0, ansi=0) at dlls/win32u/defwnd.c:2725
#15 0x00007f6122fa754d in __wine_syscall_dispatcher () from /usr/bin/../lib64/wine/x86_64-unix/ntdll.so
#16 0x00007f6122fa5cb2 in server_init_process_done () at dlls/ntdll/unix/server.c:1764
#17 0x00007f6123275258 in main (argc=argc@entry=2, argv=argv@entry=0x7fffc7917aa8) at loader/main.c:183
#18 0x00007f612306514a in __libc_start_call_main (main=main@entry=0x7f6123275160 <main>, argc=argc@entry=2, argv=argv@entry=0x7fffc7917aa8) at ../sysdeps/nptl/libc_start_call_main.h:58
#19 0x00007f612306520b in __libc_start_main_impl (main=0x7f6123275160 <main>, argc=2, argv=0x7fffc7917aa8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffc7917a98)
    at ../csu/libc-start.c:360
#20 0x00007f61232753a5 in _start () from /usr/bin/wine64

totaam added a commit that referenced this issue Feb 17, 2024
@totaam
Copy link
Collaborator

totaam commented Feb 17, 2024

ICCCM 4.1.3.1. WM_STATE Property:
The contents of the WM_STATE property are defined as follows:

state | CARD32 | (see the next table)
icon | WINDOW | ID of icon window

So we were causing short reads, and wine defaults to NormalState and not Withdrawn.

This was another 16 year old bug!
I believe that most applications don't notice because they either read the state without caring about the icon window, or they have different defaults or they fallback to calling XGetWindowAttributes to get the correct state.

@totaam totaam closed this as completed Feb 17, 2024
totaam added a commit that referenced this issue Feb 17, 2024
totaam added a commit that referenced this issue Feb 19, 2024
@vrzh
Copy link
Author

vrzh commented Feb 27, 2024

Thanks a lot for your dedication and the significant amount of time you spent on this issue, I really appreciate it! Looking forward to upgrading to v5.0.6

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants