[winswitch] Xpra GL and gtkglext woes

Ben Sferrazza bsferrazza at avnera.com
Tue Aug 28 21:23:41 BST 2018


Hi. I'm including my previous correspondence below, as it will at least
offer some history about my setup and prior issues.

I stopped using Xpra a few months ago due to numerous bugs that made it
unusable (this is using a Linux server and Windows client).

1. windows get stuck with on-top focus
2. disappearing mouse cursor when using X11-only no-toolkit apps that use
inverted black mouse pointer after clicking on something
3. some windows don't show window bar until resized (e.g. gvim always gets
placed in upper-left without window bar)
4. dialog box black bars (appears to be trying to add scrollbars?).
5. windows are all blank (white) when returning into work after several
hours (requires restarting client)
6. flickering clipboard icon in systray

I'm inclined to give Xpra another chance, with the newer versions, and can
hopefully provide actual debugging log information for these bugs to be
fixed (if they haven't already).

But I'm now not even able to connect to the server from the client using
version 2.3.3. It reports Connection Lost immediately. I can ssh into the
same host without issue. And have made sure that the shell rc file no
longer outputs anything, which was the source of my issue a few months ago.
I have included the relevant sections of the server log and client log
below.

*Server Log:*
2018-08-28 18:44:12,058 add_listen_socket(unix-domain,
<socket._socketobject object at 0x2b6ceb374f30>)
info=/home/bsferrazza/.local/run/xpra/l-server-13-100
2018-08-28 18:44:12,058 add_listen_socket(unix-domain,
<socket._socketobject object at 0x2b6ceb374fa0>)
info=/home/bsferrazza/.xpra/l-server-13-100
2018-08-28 18:44:12,059 reset_server_timeout(True) server_idle_timeout=0,
server_idle_timer=None
2018-08-28 18:44:12,059 add_process(<subprocess.Popen object at
0x2b6cf2e9eb10>, xterm, ['xterm'], True, False) pid=17703
2018-08-28 18:44:12,059 xpra is ready.
2018-08-28 18:44:12,059 pid(['xterm'])=17703
2018-08-28 18:44:12,060 org.xpra.Server.Event(ready, [])
2018-08-28 18:44:12,060 VideoHelper.init()
2018-08-28 18:44:12,061 server-event: ('ready',)
2018-08-28 18:44:12,061 VideoHelper.init() initialized=False
2018-08-28 18:44:12,061 poll() procinfo list: [ProcInfo({'returncode':
None, 'name': 'xterm', 'process': <subprocess.Popen object at
0x2b6cf2e9eb10>, 'pid': 17703, 'dead': False, 'ignore': True, 'callback':
None, 'command': ['xterm'], 'forget': False})]
2018-08-28 18:44:12,061 init_video_encoders_options()
2018-08-28 18:44:12,062  will try video encoders: x264, vpx
2018-08-28 18:44:12,062 guess_session_name() commands=['xterm']
2018-08-28 18:44:12,062  modules for x264: enc_x264
2018-08-28 18:44:12,062 poll() procinfo list: [ProcInfo({'returncode':
None, 'name': 'xterm', 'process': <subprocess.Popen object at
0x2b6cf2e9eb10>, 'pid': 17703, 'dead': False, 'ignore': True, 'callback':
None, 'command': ['xterm'], 'forget': False})]
2018-08-28 18:44:12,063 init_video_encoder_option(enc_x264)
2018-08-28 18:44:12,063 check() alive=[], quit callback=<bound method
XpraServer.reaper_exit of <XpraServer object at 0x2b6ced9f70a0
(xpra+x11+server+XpraServer at 0x7570e60)>>
2018-08-28 18:44:12,063  module=<module 'xpra.codecs.enc_x264.encoder' from
'/home/tools/lib/python/xpra/codecs/enc_x264/encoder.so'>
2018-08-28 18:44:12,064 enc_x264.init_module()
2018-08-28 18:44:12,064  x264 encodings=h264
2018-08-28 18:44:12,064  x264 input colorspaces for h264: BGRX, YUV422P,
YUV420P, BGRA, YUV444P
2018-08-28 18:44:12,064  modules for vpx: enc_vpx
2018-08-28 18:44:12,064 init_video_encoder_option(enc_vpx)
2018-08-28 18:44:12,065  module=<module 'xpra.codecs.vpx.encoder' from
'/home/tools/lib/python/xpra/codecs/vpx/encoder.so'>
2018-08-28 18:44:12,065 vpx_codec_version_str()=v1.7.0
2018-08-28 18:44:12,065 vpx.encoder.init_module() info={'vp9.max-size':
(8192, 4096), 'generation': 3, 'vp8.colorspaces': ['YUV420P'], 'version':
'v1.7.0', 'abi_version': 14, 'encodings': ['vp8', 'vp9'], 'vp8.max-size':
(8192, 4096), 'build_config': '--prefix=/home/tools --enable-shared
--disable-static', 'vp9.colorspaces': ['YUV420P', 'YUV444P']}
2018-08-28 18:44:12,065 supported codecs: ['vp8', 'vp9']
2018-08-28 18:44:12,065 supported colorspaces: {'vp9': ['YUV420P',
'YUV444P'], 'vp8': ['YUV420P']}
2018-08-28 18:44:12,065  vpx encodings=vp8, vp9
2018-08-28 18:44:12,065  vpx input colorspaces for vp8: YUV420P
2018-08-28 18:44:12,066  vpx input colorspaces for vp9: YUV420P, YUV444P
2018-08-28 18:44:12,066 found 3 video encoders: h264, vp9, vp8
2018-08-28 18:44:12,066 init_csc_options()
2018-08-28 18:44:12,066  will try csc modules:
2018-08-28 18:44:12,066  csc specs:
2018-08-28 18:44:12,066 init_video_decoders_options()
2018-08-28 18:44:12,066  will try video decoders:
2018-08-28 18:44:12,066 found 0 video decoders:
2018-08-28 18:44:12,067 VideoHelper.init() done
2018-08-28 18:44:12,067 init_encodings() adding video encodings: ('h264',
'vp9', 'vp8')
2018-08-28 18:44:12,067 found lossless mode for encoding h264 with
video_spec(x264) and colorspace YUV444P
2018-08-28 18:44:12,067 allowed encodings=['h264', 'vp9', 'vp8', 'mpeg4',
'mpeg4+mp4', 'h264+mp4', 'vp8+webm', 'vp9+webm', 'png', 'png/P', 'png/L',
'webp', 'rgb', 'rgb24', 'rgb32', 'jpeg', 'h265', 'jpeg2000'],
encodings=['rgb', 'h264', 'vp9', 'vp8', 'png', 'png/L', 'png/P', 'jpeg',
'webp'], core encodings=['rgb24', 'rgb32', 'h264', 'vp9', 'vp8', 'png',
'png/L', 'png/P', 'jpeg', 'webp'], lossless encodings=['rgb24', 'rgb32',
'png', 'png/L', 'png/P', 'webp']
2018-08-28 18:44:12,067 251.9GB of system memory
2018-08-28 18:44:12,068 threaded_init() end
2018-08-28 18:44:12,080 x_event_filter event=('xpra-create-event',
None)/CreateNotify window=0x299
2018-08-28 18:44:12,082 parse_event(..)=<X11:CreateNotify {'delivered_to':
'0x299', 'send_event': '0', 'height': '1', 'width': '1', 'window':
'0x60000d', 'serial': '0x3b1', 'type': '16', 'display': ':100'}>
2018-08-28 18:44:12,082 x_event_filter event=('xpra-create-event',
None)/CreateNotify took 1.4ms
2018-08-28 18:44:12,082 x_event_filter event=(None,
'child-configure-request-event')/ConfigureRequest window=0x299
2018-08-28 18:44:12,082 parse_event(..)=<X11:ConfigureRequest
{'delivered_to': '0x299', 'send_event': '0', 'type': '23', 'detail': '0',
'height': '316', 'width': '484', 'window': '0x60000d', 'above': '0', 'y':
'0', 'x': '0', 'serial': '0x3b5', 'border_width': '1', 'value_mask': '12',
'display': ':100'}>
2018-08-28 18:44:12,083
do_child_configure_request_event(<X11:ConfigureRequest {'delivered_to':
'0x299', 'send_event': '0', 'type': '23', 'detail': '0', 'height': '316',
'width': '484', 'window': '0x60000d', 'above': '0', 'y': '0', 'x': '0',
'serial': '0x3b5', 'border_width': '1', 'value_mask': '12', 'display':
':100'}>) value_mask=Width|Height, reconfigure on withdrawn window
2018-08-28 18:44:12,083 updated window geometry for window 0x60000d from
(0, 0, 1, 1) to (0, 0, 484, 316)
2018-08-28 18:44:12,083 x_event_filter event=(None,
'child-configure-request-event')/ConfigureRequest took 1.2ms
2018-08-28 18:44:12,083 x_event_filter event=('xpra-configure-event',
None)/ConfigureNotify window=0x299
2018-08-28 18:44:12,084 parse_event(..)=<X11:ConfigureNotify
{'delivered_to': '0x299', 'send_event': '0', 'height': '316', 'width':
'484', 'window': '0x60000d', 'above': '4194344', 'y': '0', 'x': '0',
'serial': '0x3bb', 'border_width': '0', 'type': '22', 'display': ':100'}>
2018-08-28 18:44:12,084 x_event_filter event=('xpra-configure-event',
None)/ConfigureNotify took 0.4ms
2018-08-28 18:44:12,099 x_event_filter event=(None,
'child-map-request-event')/MapRequest window=0x299
2018-08-28 18:44:12,099 parse_event(..)=<X11:MapRequest {'delivered_to':
'0x299', 'send_event': '0', 'window': '0x60000d', 'serial': '0x3c2',
'type': '20', 'display': ':100'}>
2018-08-28 18:44:12,100 Found a potential client
2018-08-28 18:44:12,100 _manage_client(<gtk.gdk.Window object at
0x2b6cf2e92dc0 (GdkWindow at 0x78cd000)>)
2018-08-28 18:44:12,100 new window 0x60000d
2018-08-28 18:44:12,101 read_initial_X11_properties() window
2018-08-28 18:44:12,101 Window.read_initial_X11_properties()
2018-08-28 18:44:12,101 read _NET_WM_STATE=None
2018-08-28 18:44:12,101 updateprop(state, frozenset([])) previous value=None
2018-08-28 18:44:12,101 not sending notify(state) (setup done=False,
managed=False)
2018-08-28 18:44:12,101 read_initial_X11_properties() core
2018-08-28 18:44:12,102 initial X11 properties: xid=0x60000d, depth=24
2018-08-28 18:44:12,102 updateprop(depth, 24) previous value=None
2018-08-28 18:44:12,102 not sending notify(depth) (setup done=False,
managed=False)
2018-08-28 18:44:12,102 updateprop(xid, 6291469) previous value=None
2018-08-28 18:44:12,102 not sending notify(xid) (setup done=False,
managed=False)
2018-08-28 18:44:12,102 updateprop(has-alpha, False) previous value=None
2018-08-28 18:44:12,102 not sending notify(has-alpha) (setup done=False,
managed=False)
2018-08-28 18:44:12,102 updateprop(allowed-actions,
['_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']) previous value=None
2018-08-28 18:44:12,102 not sending notify(allowed-actions) (setup
done=False, managed=False)
2018-08-28 18:44:12,102 displayHasXShape()=True
2018-08-28 18:44:12,103 read_shape for window 0x60000d: extents=((0, 0, 0,
484, 316), (0, 0, 0, 484, 316))
2018-08-28 18:44:12,103 read_shape for window 0x60000d: none enabled
2018-08-28 18:44:12,103 updateprop(shape, {}) previous value=None
2018-08-28 18:44:12,103 not sending notify(shape) (setup done=False,
managed=False)
2018-08-28 18:44:12,103 initial X11_properties: querying ['_NET_WM_PID',
'WM_CLIENT_MACHINE', 'WM_NAME', '_NET_WM_NAME', 'WM_PROTOCOLS', 'WM_CLASS',
'WM_WINDOW_ROLE', 'WM_TRANSIENT_FOR', '_NET_WM_WINDOW_TYPE',
'_NET_WM_DESKTOP', '_NET_WM_FULLSCREEN_MONITORS',
'_NET_WM_BYPASS_COMPOSITOR', '_NET_WM_STRUT', '_NET_WM_STRUT_PARTIAL',
'_NET_WM_WINDOW_OPACITY', 'WM_HINTS', '_GTK_APP_MENU_OBJECT_PATH',
'_GTK_APPLICATION_ID', '_GTK_UNIQUE_BUS_NAME',
'_GTK_APPLICATION_OBJECT_PATH', '_GTK_APP_MENU_OBJECT_PATH',
'_GTK_WINDOW_OBJECT_PATH', 'WM_HINTS', 'WM_NORMAL_HINTS',
'_MOTIF_WM_HINTS', 'WM_ICON_NAME', '_NET_WM_ICON_NAME', '_NET_WM_ICON',
'_NET_WM_STRUT', '_NET_WM_STRUT_PARTIAL']
2018-08-28 18:44:12,103 _NET_WM_PID=17703
2018-08-28 18:44:12,104 updateprop(pid, 17703) previous value=None
2018-08-28 18:44:12,104 not sending notify(pid) (setup done=False,
managed=False)
2018-08-28 18:44:12,104 WM_CLIENT_MACHINE=l-server-13
2018-08-28 18:44:12,104 updateprop(client-machine, l-server-13) previous
value=None
2018-08-28 18:44:12,104 not sending notify(client-machine) (setup
done=False, managed=False)
2018-08-28 18:44:12,105 _NET_WM_NAME=None
2018-08-28 18:44:12,105 WM_NAME=xterm
2018-08-28 18:44:12,105 updateprop(title, xterm) previous value=None
2018-08-28 18:44:12,105 not sending notify(title) (setup done=False,
managed=False)
2018-08-28 18:44:12,105 wm_name changed
2018-08-28 18:44:12,105 WM_PROTOCOLS=['WM_DELETE_WINDOW']
2018-08-28 18:44:12,105 updateprop(protocols, ['WM_DELETE_WINDOW'])
previous value=None
2018-08-28 18:44:12,106 not sending notify(protocols) (setup done=False,
managed=False)
2018-08-28 18:44:12,106 XGetClassHint(0x60000d) classhints: xterm, XTerm
2018-08-28 18:44:12,106 WM_CLASS=('xterm', 'XTerm')
2018-08-28 18:44:12,106 updateprop(class-instance, ('xterm', 'XTerm'))
previous value=None
2018-08-28 18:44:12,106 not sending notify(class-instance) (setup
done=False, managed=False)
2018-08-28 18:44:12,106 WM_WINDOW_ROLE=None
2018-08-28 18:44:12,106 updateprop(role, None) previous value=None
2018-08-28 18:44:12,106 not sending notify(role) (setup done=False,
managed=False)
2018-08-28 18:44:12,107 WM_TRANSIENT_FOR=None
2018-08-28 18:44:12,107 updateprop(transient-for, None) previous value=None
2018-08-28 18:44:12,107 not sending notify(transient-for) (setup
done=False, managed=False)
2018-08-28 18:44:12,107 _NET_WM_WINDOW_TYPE=None
2018-08-28 18:44:12,107 get(override-redirect, False) returning default
value=False
2018-08-28 18:44:12,107 guessed window type=_NET_WM_WINDOW_TYPE_NORMAL
2018-08-28 18:44:12,108 updateprop(window-type, ['NORMAL']) previous
value=None
2018-08-28 18:44:12,108 not sending notify(window-type) (setup done=False,
managed=False)
2018-08-28 18:44:12,108 _NET_WM_DESKTOP=UNSET for window 0x60000d
2018-08-28 18:44:12,108 updateprop(workspace, 65535) previous value=None
2018-08-28 18:44:12,108 not sending notify(workspace) (setup done=False,
managed=False)
2018-08-28 18:44:12,109 _NET_WM_FULLSCREEN_MONITORS=None
2018-08-28 18:44:12,109 updateprop(fullscreen-monitors, None) previous
value=None
2018-08-28 18:44:12,109 not sending notify(fullscreen-monitors) (setup
done=False, managed=False)
2018-08-28 18:44:12,109 _NET_WM_BYPASS_COMPOSITOR=0
2018-08-28 18:44:12,109 updateprop(bypass-compositor, 0) previous value=None
2018-08-28 18:44:12,109 not sending notify(bypass-compositor) (setup
done=False, managed=False)
2018-08-28 18:44:12,109 _NET_WM_STRUT_PARTIAL=None
2018-08-28 18:44:12,110 _NET_WM_STRUT=None
2018-08-28 18:44:12,110 updateprop(strut, None) previous value=None
2018-08-28 18:44:12,110 not sending notify(strut) (setup done=False,
managed=False)
2018-08-28 18:44:12,110 _NET_WM_WINDOW_OPACITY=-1
2018-08-28 18:44:12,110 updateprop(opacity, -1) previous value=None
2018-08-28 18:44:12,110 not sending notify(opacity) (setup done=False,
managed=False)
2018-08-28 18:44:12,110 updateprop(group-leader, None) previous value=None
2018-08-28 18:44:12,110 not sending notify(group-leader) (setup done=False,
managed=False)
2018-08-28 18:44:12,111 updateprop(attention-requested, False) previous
value=None
2018-08-28 18:44:12,111 not sending notify(attention-requested) (setup
done=False, managed=False)
2018-08-28 18:44:12,111 wm_hints.input = 1
2018-08-28 18:44:12,111 updateprop(can-focus, True) previous value=None
2018-08-28 18:44:12,111 not sending notify(can-focus) (setup done=False,
managed=False)
2018-08-28 18:44:12,111 _GTK_APP_MENU_OBJECT_PATH=None
2018-08-28 18:44:12,111 _GTK_APPLICATION_ID=None
2018-08-28 18:44:12,112 _GTK_APPLICATION_OBJECT_PATH=None
2018-08-28 18:44:12,112 _GTK_UNIQUE_BUS_NAME=None
2018-08-28 18:44:12,112 _GTK_WINDOW_OBJECT_PATH=None
2018-08-28 18:44:12,112 updateprop(menu, {}) previous value=None
2018-08-28 18:44:12,112 not sending notify(menu) (setup done=False,
managed=False)
2018-08-28 18:44:12,112 WM_NORMAL_HINTS={'min_size': (10, 17),
'win_gravity': 1, 'resize_inc': (6, 13), 'base_size': (4, 4), 'size': (484,
316)}
2018-08-28 18:44:12,113 updateprop(size-hints, {'base-size': (4, 4),
'minimum-size': (10, 17), 'gravity': 1, 'increment': (6, 13), 'size': (484,
316)}) previous value=None
2018-08-28 18:44:12,113 not sending notify(size-hints) (setup done=False,
managed=False)
2018-08-28 18:44:12,113 Missing property _MOTIF_WM_HINTS (motif-hints)
2018-08-28 18:44:12,113 _MOTIF_WM_HINTS=None
2018-08-28 18:44:12,113 _NET_WM_ICON_NAME=None
2018-08-28 18:44:12,113 WM_ICON_NAME=xterm
2018-08-28 18:44:12,114 updateprop(icon-title, xterm) previous value=None
2018-08-28 18:44:12,114 not sending notify(icon-title) (setup done=False,
managed=False)
2018-08-28 18:44:12,114 _NET_WM_ICON changed on 0x60000d, re-reading
2018-08-28 18:44:12,114 icon is now None, pixmap=None
2018-08-28 18:44:12,114 initial X11 position and size: requested((0, 0,
484, 316), {'base-size': (4, 4), 'minimum-size': (10, 17), 'gravity': 1,
'increment': (6, 13), 'size': (484, 316)})=(0, 0, 484, 316)
2018-08-28 18:44:12,114 get_wm_state(modal)
state_names=('_NET_WM_STATE_MODAL',)
2018-08-28 18:44:12,115 WindowDamageHandler.__init__(0x60000d, True)
2018-08-28 18:44:12,115 invalidating named pixmap, contents handle=None
2018-08-28 18:44:12,115 damage handle(0x60000d)=0x40002c
2018-08-28 18:44:12,115 displayHasXShape()=True
2018-08-28 18:44:12,116 setup_property_sync()
2018-08-28 18:44:12,116 sync_allowed_actions: setting
_NET_WM_ALLOWED_ACTIONS=['_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'] on 0x60000d
2018-08-28 18:44:12,116 sync_frame: frame(0x60000d)=None
2018-08-28 18:44:12,117 get(override-redirect, False) returning default
value=False
2018-08-28 18:44:12,117 get(tray, False) returning default value=False
2018-08-28 18:44:12,117 sync_frame: setting _NET_FRAME_EXTENTS=(0, 0, 0, 0)
on 0x60000d
2018-08-28 18:44:12,117 sync_state: setting _NET_WM_STATE=frozenset([]) on
0x60000d
2018-08-28 18:44:12,117 get(iconic, None) using get_property=False
2018-08-28 18:44:12,118 _handle_iconic_update: set_state(1)
2018-08-28 18:44:12,118 setup() corral_window=0x40002d
2018-08-28 18:44:12,118 setup() adding to save set
2018-08-28 18:44:12,118 setup() reparenting
2018-08-28 18:44:12,119 setup() geometry
2018-08-28 18:44:12,119 setup() hints={'base-size': (4, 4), 'minimum-size':
(10, 17), 'gravity': 1, 'increment': (6, 13), 'size': (484, 316)}
size=484x316
2018-08-28 18:44:12,119 updateprop(geometry, (0, 0, 484, 316)) unchanged
2018-08-28 18:44:12,119 setup() resizing windows to 484x316
2018-08-28 18:44:12,120 adding window WindowModel(0x60000d)
2018-08-28 18:44:12,120 add_new_window_common(WindowModel(0x60000d))
watching for dynamic properties: ['title', 'command', 'shape',
'class-instance', 'protocols', 'attention-requested', 'menu', 'workspace',
'opacity', 'fullscreen', 'focused', 'maximized', 'above', 'below',
'shaded', 'skip-taskbar', 'skip-pager', 'sticky', 'size-hints',
'icon-title', 'icon', 'decorations', 'modal', 'iconic']
2018-08-28 18:44:12,120 get(tray, False) returning default value=False
2018-08-28 18:44:12,121 Discovered new ordinary window:
WindowModel(0x60000d) (geometry=(0, 0, 484, 316))
2018-08-28 18:44:12,121 ownership_election() winner=None, old owner=None,
candidates=[(-1, DesktopManager(1))]
2018-08-28 18:44:12,121 x_event_filter event=(None,
'child-map-request-event')/MapRequest took 22.1ms
2018-08-28 18:44:12,121 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify window=0x60000d
2018-08-28 18:44:12,122 parse_event(..)=<X11:PropertyNotify
{'delivered_to': '0x60000d', 'send_event': '0', 'window': '0x60000d',
'atom': '_NET_WM_ALLOWED_ACTIONS', 'serial': '0x40d', 'type': '28',
'display': ':100'}>
2018-08-28 18:44:12,122 Property changed on 0x60000d:
_NET_WM_ALLOWED_ACTIONS
2018-08-28 18:44:12,122 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify took 0.7ms
2018-08-28 18:44:12,122 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify window=0x60000d
2018-08-28 18:44:12,122 parse_event(..)=<X11:PropertyNotify
{'delivered_to': '0x60000d', 'send_event': '0', 'window': '0x60000d',
'atom': '_NET_FRAME_EXTENTS', 'serial': '0x411', 'type': '28', 'display':
':100'}>
2018-08-28 18:44:12,122 Property changed on 0x60000d: _NET_FRAME_EXTENTS
2018-08-28 18:44:12,123 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify took 0.6ms
2018-08-28 18:44:12,123 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify window=0x60000d
2018-08-28 18:44:12,123 parse_event(..)=<X11:PropertyNotify
{'delivered_to': '0x60000d', 'send_event': '0', 'window': '0x60000d',
'atom': '_NET_WM_STATE', 'serial': '0x413', 'type': '28', 'display':
':100'}>
2018-08-28 18:44:12,123 Property changed on 0x60000d: _NET_WM_STATE
2018-08-28 18:44:12,123 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify took 0.6ms
2018-08-28 18:44:12,123 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify window=0x60000d
2018-08-28 18:44:12,124 parse_event(..)=<X11:PropertyNotify
{'delivered_to': '0x60000d', 'send_event': '0', 'window': '0x60000d',
'atom': 'WM_STATE', 'serial': '0x415', 'type': '28', 'display': ':100'}>
2018-08-28 18:44:12,124 Property changed on 0x60000d: WM_STATE
2018-08-28 18:44:12,124 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify took 0.6ms
2018-08-28 18:44:12,124 x_event_filter event=('xpra-create-event',
None)/CreateNotify window=0x299
2018-08-28 18:44:12,124 parse_event(..)=<X11:CreateNotify {'delivered_to':
'0x299', 'send_event': '0', 'height': '316', 'width': '484', 'window':
'0x40002d', 'serial': '0x417', 'type': '16', 'display': ':100'}>
2018-08-28 18:44:12,124 x_event_filter event=('xpra-create-event',
None)/CreateNotify took 0.3ms
2018-08-28 18:44:12,125 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify window=0x40002d
2018-08-28 18:44:12,125 parse_event(..)=<X11:PropertyNotify
{'delivered_to': '0x40002d', 'send_event': '0', 'window': '0x40002d',
'atom': '_NET_WM_NAME', 'serial': '0x419', 'type': '28', 'display': ':100'}>
2018-08-28 18:44:12,125 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify took 0.4ms
2018-08-28 18:44:12,125 x_event_filter event=('xpra-reparent-event',
None)/ReparentNotify window=0x60000d
2018-08-28 18:44:12,125 parse_event(..)=<X11:ReparentNotify
{'delivered_to': '0x60000d', 'send_event': '0', 'window': '0x60000d',
'serial': '0x420', 'type': '21', 'display': ':100'}>
2018-08-28 18:44:12,126 invalidating named pixmap, contents handle=None
2018-08-28 18:44:12,126 x_event_filter event=('xpra-reparent-event',
None)/ReparentNotify took 0.5ms
2018-08-28 18:44:12,126 x_event_filter event=('xpra-reparent-event',
None)/ReparentNotify window=0x299
2018-08-28 18:44:12,126 parse_event(..)=<X11:ReparentNotify
{'delivered_to': '0x299', 'send_event': '0', 'window': '0x60000d',
'serial': '0x420', 'type': '21', 'display': ':100'}>
2018-08-28 18:44:12,126 x_event_filter event=('xpra-reparent-event',
None)/ReparentNotify took 0.4ms
2018-08-28 18:44:12,126 x_event_filter event=('xpra-map-event',
'xpra-child-map-event')/MapNotify window=0x60000d
2018-08-28 18:44:12,126 parse_event(..)=<X11:MapNotify {'delivered_to':
'0x60000d', 'send_event': '0', 'override_redirect': '0', 'window':
'0x60000d', 'serial': '0x425', 'type': '19', 'display': ':100'}>
2018-08-28 18:44:12,127 x_event_filter event=('xpra-map-event',
'xpra-child-map-event')/MapNotify took 0.3ms
2018-08-28 18:44:12,127 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify window=0x60000d
2018-08-28 18:44:12,127 parse_event(..)=<X11:PropertyNotify
{'delivered_to': '0x60000d', 'send_event': '0', 'window': '0x60000d',
'atom': '_XPRA_WID', 'serial': '0x42d', 'type': '28', 'display': ':100'}>
2018-08-28 18:44:12,127 Property changed on 0x60000d: _XPRA_WID
2018-08-28 18:44:12,127 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify took 0.6ms
2018-08-28 18:44:12,305 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify window=0x60000d
2018-08-28 18:44:12,305 parse_event(..)=<X11:PropertyNotify
{'delivered_to': '0x60000d', 'send_event': '0', 'window': '0x60000d',
'atom': 'WM_ICON_NAME', 'serial': '0x448', 'type': '28', 'display': ':100'}>
2018-08-28 18:44:12,306 Property changed on 0x60000d: WM_ICON_NAME
2018-08-28 18:44:12,306 _NET_WM_ICON_NAME=None
2018-08-28 18:44:12,306 WM_ICON_NAME=~
2018-08-28 18:44:12,307 updateprop(icon-title, ~) previous value=xterm
2018-08-28 18:44:12,307 updating metadata on WindowModel(0x60000d):
<GParamBoxed 'icon-title'>
2018-08-28 18:44:12,307 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify took 2.0ms
2018-08-28 18:44:12,307 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify window=0x60000d
2018-08-28 18:44:12,307 parse_event(..)=<X11:PropertyNotify
{'delivered_to': '0x60000d', 'send_event': '0', 'window': '0x60000d',
'atom': 'WM_NAME', 'serial': '0x448', 'type': '28', 'display': ':100'}>
2018-08-28 18:44:12,308 Property changed on 0x60000d: WM_NAME
2018-08-28 18:44:12,308 _NET_WM_NAME=None
2018-08-28 18:44:12,308 WM_NAME=~
2018-08-28 18:44:12,308 updateprop(title, ~) previous value=xterm
2018-08-28 18:44:12,308 updating metadata on WindowModel(0x60000d):
<GParamBoxed 'title'>
2018-08-28 18:44:12,308 wm_name changed
2018-08-28 18:44:12,308 x_event_filter event=('xpra-property-notify-event',
None)/PropertyNotify took 1.4ms


*Client Log:*
2018-08-28 11:37:54,084 LoadImage(C:\Program Files\Xpra\icons\xpra.ico)
using image type=ICON
2018-08-28 11:37:54,086 LoadImage(C:\Program
Files\Xpra\icons\xpra.ico)=3408641
2018-08-28 11:37:54,087 do_set_icon(0x340301)
2018-08-28 11:37:54,088
make_nid(..)=<xpra.platform.win32.win32_NotifyIcon.NOTIFYICONDATA object at
0x000000001862ff80> tooltip='ssh://bsferrazza@l-server-13/:100', app_id=0,
actual flags=ICON, GUID
2018-08-28 11:37:54,090
make_nid(..)=<xpra.platform.win32.win32_NotifyIcon.NOTIFYICONDATA object at
0x000000001862ff80> tooltip='ssh://bsferrazza@l-server-13/:100', app_id=0,
actual flags=ICON, GUID
2018-08-28 11:37:55,166 poll() procinfo list: [ProcInfo({'returncode':
None, 'name': 'ssh', 'process': <subprocess.Popen object at
0x00000000186c8890>, 'pid': 3936, 'dead': False, 'ignore': True,
'callback': None, 'command': ['plink', '-ssh', '-agent', '-l',
'bsferrazza', '-T', 'l-server-13', '#run-xpra _proxy :100\nxpra initenv;if
[ -x ~/.xpra/run-xpra ]; then ~/.xpra/run-xpra _proxy :100;elif [ -x
$XDG_RUNTIME_DIR/xpra/run-xpra ]; then $XDG_RUNTIME_DIR/xpra/run-xpra
_proxy :100;elif type "xpra" > /dev/null 2>&1; then xpra _proxy :100;elif [
-x /usr/local/bin/xpra ]; then /usr/local/bin/xpra _proxy :100;else echo
"no run-xpra command found"; exit 1; fi'], 'forget': False})]
2018-08-28 11:37:57,167 poll() procinfo list: [ProcInfo({'returncode':
None, 'name': 'ssh', 'process': <subprocess.Popen object at
0x00000000186c8890>, 'pid': 3936, 'dead': False, 'ignore': True,
'callback': None, 'command': ['plink', '-ssh', '-agent', '-l',
'bsferrazza', '-T', 'l-server-13', '#run-xpra _proxy :100\nxpra initenv;if
[ -x ~/.xpra/run-xpra ]; then ~/.xpra/run-xpra _proxy :100;elif [ -x
$XDG_RUNTIME_DIR/xpra/run-xpra ]; then $XDG_RUNTIME_DIR/xpra/run-xpra
_proxy :100;elif type "xpra" > /dev/null 2>&1; then xpra _proxy :100;elif [
-x /usr/local/bin/xpra ]; then /usr/local/bin/xpra _proxy :100;else echo
"no run-xpra command found"; exit 1; fi'], 'forget': False})]
2018-08-28 11:37:58,987 read_parse_thread_loop starting
2018-08-28 11:37:58,987 read thread: eof
2018-08-28 11:37:58,989 parse thread: empty marker, exiting
2018-08-28 11:37:58,992 io_thread_loop(read, <bound method Protocol._read
of Protocol(Pipe(ssh://bsferrazza@l-server-13/:100))>) loop ended,
closed=False
2018-08-28 11:37:58,993 Protocol.close() closed=False,
connection=Pipe(ssh://bsferrazza@l-server-13/:100)
2018-08-28 11:37:58,996 Protocol.close() calling <bound method
TwoFileConnection.close of Pipe(ssh://bsferrazza@l-server-13/:100)>
2018-08-28 11:37:58,998 Pipe(ssh://bsferrazza@l-server-13/:100).close()
close callback=<function stop_tunnel at 0x000000001861fde8>, readable=<open
file '<fdopen>', mode 'rb' at 0x000000001862f810>, writeable=<open file
'<fdopen>', mode 'wb' at 0x000000001862f9c0>
2018-08-28 11:37:59,003 Pipe(ssh://bsferrazza@l-server-13/:100).close()
calling <function stop_tunnel at 0x000000001861fde8>
2018-08-28 11:37:59,003 Pipe(ssh://bsferrazza@l-server-13/:100).close() done
2018-08-28 11:37:59,004 terminate_queue_threads()
2018-08-28 11:37:59,005 write thread: empty marker, exiting
2018-08-28 11:37:59,005 Protocol.close() done
2018-08-28 11:37:59,005 Protocol.close() closed=True, connection=None
2018-08-28 11:37:59,006 check_server_echo(0) last=True, server_ok=True
(last_ping_echoed_time=0)
2018-08-28 11:37:59,006 io_thread_loop(write, <bound method Protocol._write
of Protocol(None)>) loop ended, closed=True
2018-08-28 11:37:59,006 Error: failed to receive anything, not an xpra
server?
2018-08-28 11:37:59,010   could also be the wrong protocol, username,
password or port
2018-08-28 11:37:59,010   or the session was not found
2018-08-28 11:37:59,010 Connection lost
2018-08-28 11:37:59,011 GTKXpraClient.quit(1) current exit_code=None
2018-08-28 11:37:59,012 UIXpraClient.cleanup()
2018-08-28 11:37:59,012 poll() procinfo list: [ProcInfo({'returncode':
None, 'name': 'ssh', 'process': <subprocess.Popen object at
0x00000000186c8890>, 'pid': 3936, 'dead': False, 'ignore': True,
'callback': None, 'command': ['plink', '-ssh', '-agent', '-l',
'bsferrazza', '-T', 'l-server-13', '#run-xpra _proxy :100\nxpra initenv;if
[ -x ~/.xpra/run-xpra ]; then ~/.xpra/run-xpra _proxy :100;elif [ -x
$XDG_RUNTIME_DIR/xpra/run-xpra ]; then $XDG_RUNTIME_DIR/xpra/run-xpra
_proxy :100;elif type "xpra" > /dev/null 2>&1; then xpra _proxy :100;elif [
-x /usr/local/bin/xpra ]; then /usr/local/bin/xpra _proxy :100;else echo
"no run-xpra command found"; exit 1; fi'], 'forget': False})]


On Tue, Mar 6, 2018 at 9:46 AM Ben Sferrazza <bsferrazza at avnera.com> wrote:

> On Tue, Mar 6, 2018 at 9:24 AM, Antoine Martin via shifter-users <
> shifter-users at lists.devloop.org.uk> wrote:
>
>> > OK thanks. Xpra server is running as shown here. Its own log file
>> doesn't
>> > seem to react to the client connecting from below.
>> That's because it never gets a connection from the client, see below.
>> So, it seems that you're using SSH. I always advise to try with plain
>> TCP or SSL first before introducing a transport intermediary like SSH.
>>
>
>  OK. I thought as a regular user I wouldn't have access to bind to TCP
> ports. I at least know I can SSH into these machines.
>
>
>>
>> (..)
>> > Here's the relevant output from the client. The 'no run-xpra' command
>> found
>> > seems to be the most glaring.
>> If you started the server using the same user account, it should have
>> placed a "run-xpra" script in one of the locations that the client will
>> attempt to use. From your debug output, this will include:
>> ~/.xpra/run-xpra
>> $XDG_RUNTIME_DIR/xpra/run-xpra
>> xpra
>> /usr/local/bin/xpra
>>
>> Note that XDG_RUNTIME_DIR may not be set when logging in via ssh if you
>> had to hack it previously. But ~/.xpra/run-xpra should exist anyway.
>> I'm just mentioning for completeness.
>>
>
> OK, yes those files do indeed exist.
>
>
>>
>> (..)
>> > 2018-03-06 08:44:04,610 poll() procinfo list: [ProcInfo({'returncode':
>> > None, 'name': 'ssh', 'process': <subprocess.Popen object at
>> > 0x000000001a2d3250>, 'pid': 15132, 'dead': False, 'ignore': True,
>> > 'callback': None, 'command': ['plink', '-ssh', '-agent', '-T',
>> > 'l-server-13', 'xpra initenv;if [ -x ~/.xpra/run-xpra ]; then
>> > ~/.xpra/run-xpra _proxy :100;elif [ -x $XDG_RUNTIME_DIR/xpra/run-xpra ];
>> > then $XDG_RUNTIME_DIR/xpra/run-xpra _proxy :100;elif type "xpra" >
>> > /dev/null 2>&1; then xpra _proxy :100;elif [ -x /usr/local/bin/xpra ];
>> then
>> > /usr/local/bin/xpra _proxy :100;else echo "no run-xpra command found";
>> exit
>> (..)
>>
>> > 2018-03-06 08:44:12,788 process_gibberish(['gibberish', "invalid packet
>> > header byte C: '436164656e636520' read buffer='Cadence digital tool
>> > setup\\n' (27 bytes)", 'Cadence digital tool setup\n'])
>> And here is your problem.
>> Something in your user environment is printing out some text to the SSH
>> terminal connection which xpra uses to communicate with the xpra server.
>> When it sees that this isn't xpra's protocol, it drops the connection.
>>
>> Either clean this up from your user's login scripts or use TCP / SSL
>> connections instead.
>
>
> I commented out the line that sources a tool setup script (for Cadence CAD
> software that echos back stuff) in my shell rc file. I can now launch an
> xterm window!! Thank you. I suppose I can always source that too setup
> script on demand when I actually need it, as opposed to sourcing it always
> in my shell's rc file.
>



More information about the shifter-users mailing list