search

neutrinolabs / xrdp

xrdp: an open source RDP server
http://www.xrdp.org/
Apache License 2.0
5.62k stars 1.73k forks source link

Reconnect on display resize slow #1912

Closed mboehm21 closed 2 years ago

mboehm21 commented 3 years ago

I'm using Ubuntu 20.04 with xrdp in containers as terminalservers for Apache Guacamole. Base image is danielguerra/ubuntu-xrdp:20.04 and the issue can be reproduced using this image with default settings.

When I change the browser size of Guacamole, it takes about 15 seconds to reconnect. Until then the connection to the xrdp container freezes. Guacamole is configured to use "Reconnect" as the "Resize Method" as "Display Update" does not work.

root@initial-setup-1:/# cat /etc/os-release 
NAME="Ubuntu"
VERSION="20.04.2 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.2 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal
root@initial-setup-1:/# xrdp --version
xrdp 0.9.12
  A Remote Desktop Protocol Server.
  Copyright (C) 2004-2018 Jay Sorg, Neutrino Labs, and all contributors.
  See https://github.com/neutrinolabs/xrdp for more information.

  Configure options:
      --enable-ipv6
      --enable-jpeg
      --enable-fuse
      --enable-rfxcodec
      --enable-opus
      --enable-painter
      --enable-vsock
      --build=x86_64-linux-gnu
      --prefix=/usr
      --includedir=${prefix}/include
      --mandir=${prefix}/share/man
      --infodir=${prefix}/share/info
      --sysconfdir=/etc
      --localstatedir=/var
      --disable-silent-rules
      --libdir=${prefix}/lib/x86_64-linux-gnu
      --libexecdir=${prefix}/lib/x86_64-linux-gnu
      --disable-maintainer-mode
      --disable-dependency-tracking
      --with-socketdir=/run/xrdp/sockdir
      build_alias=x86_64-linux-gnu
      CFLAGS=-g -O2 -fdebug-prefix-map=/build/xrdp-GJgww4/xrdp-0.9.12=. -fstack-protector-strong -Wformat -Werror=format-security 
      LDFLAGS=-Wl,-Bsymbolic-functions -Wl,-z,relro -Wl,-z,now -Wl,--as-needed
      CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2 
      PKG_CONFIG_PATH=/build/xrdp-GJgww4/xrdp-0.9.12/pkgconfig

  Compiled with OpenSSL 1.1.1f  31 Mar 2020

Logs while resizing browser window:

==> xrdp-sesman-stderr---supervisor-wsrbb80n.log <==
rdpClientConRecv: g_sck_recv failed(returned 0)
rdpClientConRecvMsg: error
rdpClientConCheck: rdpClientConGotData failed
rdpClientConDisconnect:
rdpRemoveClientConFromDev: removing clientCon 0x55ce2dd21800
rdpClientConGotConnection:
rdpClientConGotConnection: g_sck_accept ok new_sck 7
rdpClientConGetConnection: idle_disconnect_timeout set to non-positive value, idle timer turned off
rdpAddClientConToDev: adding first clientCon 0x55ce2dd21800
rdpClientConProcessMsgVersion: version 0 0 0 1
rdpClientConProcessScreenSizeMsg: set width 3314 height 1158 bpp 16
rdpClientConProcessScreenSizeMsg: shmemid 753664 shmemptr 0x7f03bc0a7000
rdpRRScreenSetSize: width 3314 height 1158 mmWidth 877 mmHeight 306
rdpRRGetInfo:
  screen resized to 3314x1158
rdpClientConProcessScreenSizeMsg: RRScreenSizeSet ok=[1]
rdpClientConProcessMsgClientInput: invalidate x 0 y 0 cx 3314 cy 1158

==> xrdp-stdout---supervisor-vqquu4r1.log <==
[20210604-10:52:12] [INFO ] starting xrdp with pid 1237
[20210604-10:52:12] [INFO ] address [0.0.0.0] port [3389] mode 1
[20210604-10:52:12] [INFO ] listening to port 3389 on 0.0.0.0
[20210604-10:52:12] [INFO ] IPv6 not supported, falling back to IPv4
[20210604-10:52:12] [INFO ] xrdp_listen_pp done
[20210604-10:52:22] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 55316
[20210604-10:52:22] [DEBUG] Closed socket 11 (AF_INET 172.35.199.23:3389)
[20210604-10:52:27] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 46716
[20210604-10:52:27] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210604-10:52:48] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 46788
[20210604-10:52:48] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210604-10:52:59] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 55456
[20210604-10:52:59] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210604-10:52:59] [DEBUG] TLSv1.3 enabled
[20210604-10:52:59] [DEBUG] TLSv1.2 enabled
[20210604-10:52:59] [DEBUG] Security layer: requested 1, selected 1
ssl_tls_accept: TLS connection accepted
colorDepth 0xca01 (0xca00 4bpp 0xca01 8bpp)
[20210604-10:52:59] [INFO ] connected client computer name: Guacamole RDP
postBeta2ColorDepth 0xca01 (0xca00 4bpp 0xca01 8bpp 0xca02 15bpp 0xca03 16bpp 0xca04 24bpp)
highColorDepth 0x0010 (0x0004 4bpp 0x0008 8bpp 0x000f 15bpp 0x0010 16 bpp 0x0018 24bpp)
supportedColorDepths 0x0007 (0x0001 24bpp 0x0002 16bpp 0x0004 15bpp 0x0008 32bpp)
earlyCapabilityFlags 0x04a1 (0x0002 want32)
got client client connection type 0x00000006
xrdp_sec_process_mcs_data_CS_SECURITY:
  client and server support none crypt, using none crypt
[20210604-10:52:59] [INFO ] adding channel item name cliprdr chan_id 1004 flags 0xc0a00000
error unknown xrdp_sec_process_mcs_data tag 0xc006 size 8
error unknown xrdp_sec_process_mcs_data tag 0xc00a size 8
xrdp_sec_out_mcs_data: using no security
xrdp_load_keyboard_layout: keyboard_type [4] keyboard_subtype [0]
xrdp_load_keyboard_layout: model [] variant [] layout [de] options []
[20210604-10:52:59] [INFO ] TLS connection established from 172.35.199.3 port 55456: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384
xrdp_caps_process_order: not enough orders supported by client, using painter.
xrdp_caps_process_pointer: client supports new(color) cursor
xrdp_caps_process_glyphcache: support level 2 
xrdp_process_offscreen_bmpcache: support level 1 cache size 7864320 MB cache entries 2000
xrdp_caps_process_surface_cmds:
  cmdFlags 0x00000052
xrdp_caps_process_frame_ack:
  max_unacknowledged_frame_count 2
xrdp_caps_process_confirm_active: not enough orders supported by client, client wants off screen bitmap but offscreen bitmaps disabled
yeah, up_and_running
xrdp_channel_drdynvc_start:
xrdp:xrdp_bitmap [3594109274]: xrdp_bitmap_create: noorders
[20210604-10:52:59] [DEBUG] xrdp_00000629_wm_login_mode_event_00000001
xrdp:xrdp_mm [3594109285]: xrdp_mm_create: bpp 16 mcs_connection_type 6 jpeg_codec_id 0 v3_codec_id 0 rfx_codec_id 0 h264_codec_id 0
[20210604-10:52:59] [INFO ] Loading keymap file /etc/xrdp/km-00000407.ini
[20210604-10:52:59] [WARN ] local keymap file for 0x00000407 found and doesn't match built in keymap, using local keymap file
xrdp_wm_login_mode_changed: login_mode is 0
in xrdp_wm_init: 
xrdp_wm_init: channel cliprdr channel id 0 is allowed
out xrdp_wm_init: 
xrdp_wm_login_mode_changed: login_mode is 2
[20210604-10:52:59] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
connecting to sesman ip 127.0.0.1 port 3350
[20210604-10:52:59] [INFO ] IPv6 not supported, falling back to IPv4
[20210604-10:52:59] [INFO ] xrdp_wm_log_msg: sesman connect ok
sesman connect ok
[20210604-10:52:59] [DEBUG] xrdp_wm_log_msg: sending login info to session manager, please wait...
sending login info to session manager, please wait...
[20210604-10:52:59] [DEBUG] return value from xrdp_mm_connect 0
xrdp_wm_login_mode_changed: login_mode is 3
[20210604-10:53:00] [INFO ] xrdp_wm_log_msg: login successful for display 11
login successful for
==> xrdp-sesman-stderr---supervisor-wsrbb80n.log <==
rdpClientConGotConnection:
rdpClientConGotConnection: g_sck_accept ok new_sck 18
rdpClientConGotConnection: marking only clientCon 0x55ce2dd21800 for disconnect
rdpClientConGetConnection: idle_disconnect_timeout set to non-positive value, idle timer turned off
rdpAddClientConToDev: adding clientCon 0x55ce30b54890
rdpClientConDisconnect:
rdpRemoveClientConFromDev: removing clientCon 0x55ce2dd21800
rdpClientConProcessMsgVersion: version 0 0 0 1
rdpClientConProcessScreenSizeMsg: set width 3346 height 1158 bpp 16
rdpClientConProcessScreenSizeMsg: shmemid 786432 shmemptr 0x7f03bc095000
rdpRRScreenSetSize: width 3346 height 1158 mmWidth 885 mmHeight 306
rdpRRGetInfo:
  screen resized to 3346x1158
rdpClientConProcessScreenSizeMsg: RRScreenSizeSet ok=[1]
rdpClientConProcessMsgClientInput: invalidate x 0 y 0 cx 3346 cy 1158

==> xrdp-stdout---supervisor-vqquu4r1.log <==
[20210604-10:52:12] [INFO ] starting xrdp with pid 1237
[20210604-10:52:12] [INFO ] address [0.0.0.0] port [3389] mode 1
[20210604-10:52:12] [INFO ] listening to port 3389 on 0.0.0.0
[20210604-10:52:12] [INFO ] IPv6 not supported, falling back to IPv4
[20210604-10:52:12] [INFO ] xrdp_listen_pp done
[20210604-10:52:22] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 55316
[20210604-10:52:22] [DEBUG] Closed socket 11 (AF_INET 172.35.199.23:3389)
[20210604-10:52:27] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 46716
[20210604-10:52:27] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210604-10:52:48] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 46788
[20210604-10:52:48] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210604-10:52:59] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 55456
[20210604-10:52:59] [DEBUG] Closed socket 11 (AF_INET 172.35.199.23:3389)
[20210604-10:53:00] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 55460
[20210604-10:53:00] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210604-10:53:00] [DEBUG] TLSv1.3 enabled
[20210604-10:53:00] [DEBUG] TLSv1.2 enabled
[20210604-10:53:00] [DEBUG] Security layer: requested 1, selected 1
ssl_tls_accept: TLS connection accepted
colorDepth 0xca01 (0xca00 4bpp 0xca01 8bpp)
[20210604-10:53:00] [INFO ] connected client computer name: Guacamole RDP
postBeta2ColorDepth 0xca01 (0xca00 4bpp 0xca01 8bpp 0xca02 15bpp 0xca03 16bpp 0xca04 24bpp)
highColorDepth 0x0010 (0x0004 4bpp 0x0008 8bpp 0x000f 15bpp 0x0010 16 bpp 0x0018 24bpp)
supportedColorDepths 0x0007 (0x0001 24bpp 0x0002 16bpp 0x0004 15bpp 0x0008 32bpp)
earlyCapabilityFlags 0x04a1 (0x0002 want32)
got client client connection type 0x00000006
xrdp_sec_process_mcs_data_CS_SECURITY:
  client and server support none crypt, using none crypt
[20210604-10:53:00] [INFO ] adding channel item name cliprdr chan_id 1004 flags 0xc0a00000
error unknown xrdp_sec_process_mcs_data tag 0xc006 size 8
error unknown xrdp_sec_process_mcs_data tag 0xc00a size 8
xrdp_sec_out_mcs_data: using no security
xrdp_load_keyboard_layout: keyboard_type [4] keyboard_subtype [0]
xrdp_load_keyboard_layout: model [] variant [] layout [de] options []
[20210604-10:53:01] [INFO ] TLS connection established from 172.35.199.3 port 55460: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384
xrdp_caps_process_order: not enough orders supported by client, using painter.
xrdp_caps_process_pointer: client supports new(color) cursor
xrdp_caps_process_glyphcache: support level 2 
xrdp_process_offscreen_bmpcache: support level 1 cache size 7864320 MB cache entries 2000
xrdp_caps_process_surface_cmds:
  cmdFlags 0x00000052
xrdp_caps_process_frame_ack:
  max_unacknowledged_frame_count 2
xrdp_caps_process_confirm_active: not enough orders supported by client, client wants off screen bitmap but offscreen bitmaps disabled
yeah, up_and_running
xrdp_channel_drdynvc_start:
xrdp:xrdp_bitmap [3594110950]: xrdp_bitmap_create: noorders
[20210604-10:53:01] [DEBUG] xrdp_0000062b_wm_login_mode_event_00000001
xrdp:xrdp_mm [3594110960]: xrdp_mm_create: bpp 16 mcs_connection_type 6 jpeg_codec_id 0 v3_codec_id 0 rfx_codec_id 0 h264_codec_id 0
[20210604-10:53:01] [INFO ] Loading keymap file /etc/xrdp/km-00000407.ini
[20210604-10:53:01] [WARN ] local keymap file for 0x00000407 found and doesn't match built in keymap, using local keymap file
xrdp_wm_login_mode_changed: login_mode is 0
in xrdp_wm_init: 
xrdp_wm_init: channel cliprdr channel id 0 is allowed
out xrdp_wm_init: 
xrdp_wm_login_mode_changed: login_mode is 2
[20210604-10:53:01] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
connecting to sesman ip 127.0.0.1 port 3350
[20210604-10:53:01] [INFO ] IPv6 not supported, falling back to IPv4
[20210604-10:53:01] [INFO ] xrdp_wm_log_msg: sesman connect ok
sesman connect ok
[20210604-10:53:01] [DEBUG] xrdp_wm_log_msg: sending login info to session manager, please wait...
sending login info to session manager, please wait...
[20210604-10:53:01] [DEBUG] return 
==> xrdp-sesman-stderr---supervisor-wsrbb80n.log <==
rdpClientConProcessMsgClientInfo:
  got client info bytes 5752
  jpeg support 0
  offscreen support 0
  offscreen size 0
  offscreen entries 0
  client supports glyph cache but server disabled
  client can not do offscreen to offscreen blits
  client can do new(color) cursor
  client can not do multimon
rdpRRSetRdpOutputs: numCrtcs 1 numOutputs 1 monitorCount 0
rdpRRSetRdpOutputs: update output 0 left 0 top 0 width 3346 height 1158
rdpRRUpdateOutput:
rdpLoadLayout: keylayout 0x00000407 variant  display 11
rdpkeybChangeKeyboardControl:
rdpkeybChangeKeyboardControl: autoRepeat on
rdpkeybChangeKeyboardControl:
rdpkeybChangeKeyboardControl: autoRepeat on
rdpInDeferredRepeatCallback:
rdpkeybChangeKeyboardControl:
rdpkeybChangeKeyboardControl: autoRepeat off
rdpInDeferredRepeatCallback:
rdpkeybChangeKeyboardControl:
rdpkeybChangeKeyboardControl: autoRepeat off

How can I troubleshoot this? Please note, that the first login of the client is fast, only the reconnect on resize is slow, so it is no general authentication issue. I used the 18.04 version of the image with an old version of xrdp before. There were no issues with the same settings in Guacamole.

Thanks.

mboehm21 commented 3 years ago

Hi. Do I need to provide any more details? Any idea what I could look up?

matt335672 commented 3 years ago

Hi @mboehm21

There's a lot of connections going on here, e.g. client to guacamole, guacamole to xrdp, xrdp to xrdp-sesman, xrdp to X server, xrdp to chansrv and any one of these could be creating the delay you're seeing.

Looking at your log, the connection from the client to xrdp happens and the connection from xrdp to xrdp-sesman happens fairly swiftly:-

[20210604-10:52:59] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 55456
. . .
[20210604-10:52:59] [DEBUG] xrdp_00000629_wm_login_mode_event_00000001
[20210604-10:52:59] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
. . .
[20210604-10:53:00] [INFO ] xrdp_wm_log_msg: login successful for display 11

I can't tell you any more than that from the information you have available.

On the xrdp side, the only thing I can think of which would cause a delay like this is if the chansrv process running in the session had failed. There would then be a timeout before the session was reconnected as xrdp tries to connect to the non-existent process.

If this is the case, you should have something error messages mentioning xrdp_mm_connect_chansrv: in the xrdp log. There's not enough of the log to make that determination however. That's worth looking for though.

I'd suggest a more holistic approach may be necessary here: 1) Synchronise all the clocks on the hosts and containers involved - I believe it;s possible that the system time could be namespaced in the containers, so you'll need to check this. 2) Attempt the reconnect at a known time (i.e at 0 seconds past the hour). 3) Check the logs you've got available to find out where the delay is being incurred.

Hope that's useful.

mboehm21 commented 3 years ago

Hi @matt335672

thank you, you got a good point here.

There is a tail -f of /var/log/xrdp.log showing two screen resizes:

[20210622-12:58:01] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-12:58:01] [DEBUG] xrdp_mm_module_cleanup
[20210622-12:58:01] [DEBUG] Closed socket 18 (AF_UNIX)
[20210622-12:58:01] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:02] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 32884
[20210622-12:58:02] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-12:58:02] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-12:58:02] [DEBUG] TLSv1.3 enabled
[20210622-12:58:02] [DEBUG] TLSv1.2 enabled
[20210622-12:58:02] [DEBUG] Security layer: requested 1, selected 1
[20210622-12:58:02] [INFO ] connected client computer name: Guacamole RDP
[20210622-12:58:02] [INFO ] adding channel item name cliprdr chan_id 1004 flags 0xc0a00000
[20210622-12:58:02] [INFO ] TLS connection established from 172.35.199.3 port 32884: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384
[20210622-12:58:02] [DEBUG] xrdp_0000911c_wm_login_mode_event_00000001
[20210622-12:58:02] [INFO ] Loading keymap file /etc/xrdp/km-00000407.ini
[20210622-12:58:02] [WARN ] local keymap file for 0x00000407 found and doesn't match built in keymap, using local keymap file
[20210622-12:58:02] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
[20210622-12:58:02] [INFO ] IPv6 not supported, falling back to IPv4
[20210622-12:58:02] [INFO ] xrdp_wm_log_msg: sesman connect ok
[20210622-12:58:02] [DEBUG] xrdp_wm_log_msg: sending login info to session manager, please wait...
[20210622-12:58:02] [DEBUG] return value from xrdp_mm_connect 0
[20210622-12:58:02] [INFO ] xrdp_wm_log_msg: login successful for display 10
[20210622-12:58:02] [DEBUG] xrdp_wm_log_msg: started connecting
[20210622-12:58:02] [INFO ] lib_mod_log_peer: xrdp_pid=37148 connected to X11rdp_pid=36820 X11rdp_uid=1066 X11rdp_gid=1066 client_ip=172.35.199.3 client_port=32884
[20210622-12:58:02] [DEBUG] xrdp_wm_log_msg: connected ok
[20210622-12:58:06] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:06] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:10] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:10] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:14] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 40740
[20210622-12:58:14] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-12:58:14] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-12:58:14] [DEBUG] TLSv1.3 enabled
[20210622-12:58:14] [DEBUG] TLSv1.2 enabled
[20210622-12:58:14] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-12:58:14] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:14] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:18] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:18] [ERROR] xrdp_mm_connect_chansrv: error in trans_connect chan
[20210622-12:58:18] [DEBUG] Closed socket 17 (AF_INET 127.0.0.1:37972)
[20210622-12:58:34] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 40812
[20210622-12:58:34] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-12:58:34] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-12:58:34] [DEBUG] TLSv1.3 enabled
[20210622-12:58:34] [DEBUG] TLSv1.2 enabled
[20210622-12:58:34] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)

[20210622-12:58:45] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-12:58:45] [DEBUG] xrdp_mm_module_cleanup
[20210622-12:58:45] [DEBUG] Closed socket 18 (AF_UNIX)
[20210622-12:58:45] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:45] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 33036
[20210622-12:58:45] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-12:58:45] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-12:58:45] [DEBUG] TLSv1.3 enabled
[20210622-12:58:45] [DEBUG] TLSv1.2 enabled
[20210622-12:58:45] [DEBUG] Security layer: requested 1, selected 1
[20210622-12:58:45] [INFO ] connected client computer name: Guacamole RDP
[20210622-12:58:45] [INFO ] adding channel item name cliprdr chan_id 1004 flags 0xc0a00000
[20210622-12:58:46] [INFO ] TLS connection established from 172.35.199.3 port 33036: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384
[20210622-12:58:46] [DEBUG] xrdp_00009134_wm_login_mode_event_00000001
[20210622-12:58:46] [INFO ] Loading keymap file /etc/xrdp/km-00000407.ini
[20210622-12:58:46] [WARN ] local keymap file for 0x00000407 found and doesn't match built in keymap, using local keymap file
[20210622-12:58:46] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
[20210622-12:58:46] [INFO ] IPv6 not supported, falling back to IPv4
[20210622-12:58:46] [INFO ] xrdp_wm_log_msg: sesman connect ok
[20210622-12:58:46] [DEBUG] xrdp_wm_log_msg: sending login info to session manager, please wait...
[20210622-12:58:46] [DEBUG] return value from xrdp_mm_connect 0
[20210622-12:58:46] [INFO ] xrdp_wm_log_msg: login successful for display 10
[20210622-12:58:46] [DEBUG] xrdp_wm_log_msg: started connecting
[20210622-12:58:46] [INFO ] lib_mod_log_peer: xrdp_pid=37172 connected to X11rdp_pid=36820 X11rdp_uid=1066 X11rdp_gid=1066 client_ip=172.35.199.3 client_port=33036
[20210622-12:58:46] [DEBUG] xrdp_wm_log_msg: connected ok
[20210622-12:58:47] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 33040
[20210622-12:58:47] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-12:58:47] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-12:58:47] [DEBUG] TLSv1.3 enabled
[20210622-12:58:47] [DEBUG] TLSv1.2 enabled
[20210622-12:58:47] [DEBUG] Security layer: requested 1, selected 1
[20210622-12:58:47] [INFO ] connected client computer name: Guacamole RDP
[20210622-12:58:47] [INFO ] adding channel item name cliprdr chan_id 1004 flags 0xc0a00000
[20210622-12:58:47] [INFO ] TLS connection established from 172.35.199.3 port 33040: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384
[20210622-12:58:48] [DEBUG] xrdp_00009136_wm_login_mode_event_00000001
[20210622-12:58:48] [INFO ] Loading keymap file /etc/xrdp/km-00000407.ini
[20210622-12:58:48] [WARN ] local keymap file for 0x00000407 found and doesn't match built in keymap, using local keymap file
[20210622-12:58:48] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
[20210622-12:58:48] [INFO ] IPv6 not supported, falling back to IPv4
[20210622-12:58:48] [INFO ] xrdp_wm_log_msg: sesman connect ok
[20210622-12:58:48] [DEBUG] xrdp_wm_log_msg: sending login info to session manager, please wait...
[20210622-12:58:48] [DEBUG] return value from xrdp_mm_connect 0
[20210622-12:58:48] [INFO ] xrdp_wm_log_msg: login successful for display 10
[20210622-12:58:48] [DEBUG] xrdp_wm_log_msg: started connecting
[20210622-12:58:48] [INFO ] lib_mod_log_peer: xrdp_pid=37174 connected to X11rdp_pid=36820 X11rdp_uid=1066 X11rdp_gid=1066 client_ip=172.35.199.3 client_port=33040
[20210622-12:58:48] [DEBUG] xrdp_wm_log_msg: connected ok
[20210622-12:58:50] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:50] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:52] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:52] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:54] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:54] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:54] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 40892
[20210622-12:58:54] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-12:58:54] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-12:58:54] [DEBUG] TLSv1.3 enabled
[20210622-12:58:54] [DEBUG] TLSv1.2 enabled
[20210622-12:58:54] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-12:58:56] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:56] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:58:58] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:58:58] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:59:00] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:59:00] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:59:02] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:59:02] [ERROR] xrdp_mm_connect_chansrv: error in trans_connect chan
[20210622-12:59:02] [DEBUG] Closed socket 17 (AF_INET 127.0.0.1:38124)
[20210622-12:59:02] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-12:59:02] [DEBUG] xrdp_mm_module_cleanup
[20210622-12:59:02] [DEBUG] Closed socket 18 (AF_UNIX)
[20210622-12:59:02] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-12:59:04] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-12:59:04] [ERROR] xrdp_mm_connect_chansrv: error in trans_connect chan
[20210622-12:59:04] [DEBUG] Closed socket 17 (AF_INET 127.0.0.1:38128)
[20210622-12:59:14] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 40960
[20210622-12:59:14] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-12:59:14] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-12:59:14] [DEBUG] TLSv1.3 enabled
[20210622-12:59:14] [DEBUG] TLSv1.2 enabled
[20210622-12:59:14] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)

[ERROR] xrdp_mm_connect_chansrv: connect failed trying again... seems that it has something to do with xrdp_mm_connect_chansrv indeed. How can I debug this further?

xrdp-chansrv is a zombie process:

root      2734  0.0  0.0  10460  5344 ?        S    Jun21   0:04 /usr/sbin/xrdp --nodaemon
root      2735  0.0  0.0  12824  5176 ?        S    Jun21   0:00 /usr/sbin/xrdp-sesman --nodaemon
root     36818  0.0  0.0  12544  3940 ?        S    12:57   0:00 /usr/sbin/xrdp-sesman --nodaemon
mboehm21 36820  1.4  0.4 1911300 158616 ?      Sl   12:57   0:06 /usr/lib/xorg/Xorg :10 -auth .Xauthority -config xorg.conf -noreset -nolisten tcp -logfile .xorgxrdp.%s.log
mboehm21 36847  0.0  0.0      0     0 ?        Z    12:57   0:00 [xrdp-chansrv] <defunct>
root     38765  0.4  0.0  34016 28084 ?        S    13:02   0:00 /usr/sbin/xrdp --nodaemon
root     38848  0.0  0.0   3308   664 pts/0    S+   13:04   0:00 grep --color=auto xrdp

It becomes defunct right at the first resize event:

root@initial-setup-1:/# ps -aux | grep xrdp
root      1505  0.0  0.0  10460  5244 ?        S    13:07   0:00 /usr/sbin/xrdp --nodaemon
root      1506  0.1  0.0  12188  5052 ?        S    13:07   0:00 /usr/sbin/xrdp-sesman --nodaemon
root      1517  5.9  0.0  34476 28640 ?        S    13:07   0:00 /usr/sbin/xrdp --nodaemon
root      1518  0.0  0.0  12540  3976 ?        S    13:07   0:00 /usr/sbin/xrdp-sesman --nodaemon
mboehm21  1520 12.2  0.3 1762224 119536 ?      Sl   13:07   0:01 /usr/lib/xorg/Xorg :11 -auth .Xauthority -config xorg.conf -noreset -nolisten tcp -logfile .xorgxrdp.%s.log
mboehm21  1547  0.0  0.0  89220  5308 ?        Sl   13:07   0:00 /usr/sbin/xrdp-chansrv
root      1846  0.0  0.0   3308   740 pts/0    S+   13:07   0:00 grep --color=auto xrdp
root@initial-setup-1:/# 
root@initial-setup-1:/# 
root@initial-setup-1:/# 
root@initial-setup-1:/# ps -aux | grep xrdp
root      1505  0.0  0.0  10460  5244 ?        S    13:07   0:00 /usr/sbin/xrdp --nodaemon
root      1506  0.1  0.0  12560  5128 ?        S    13:07   0:00 /usr/sbin/xrdp-sesman --nodaemon
root      1518  0.0  0.0  12540  3976 ?        S    13:07   0:00 /usr/sbin/xrdp-sesman --nodaemon
mboehm21  1520  7.7  0.3 1763032 114376 ?      Sl   13:07   0:01 /usr/lib/xorg/Xorg :11 -auth .Xauthority -config xorg.conf -noreset -nolisten tcp -logfile .xorgxrdp.%s.log
mboehm21  1547  0.0  0.0      0     0 ?        Z    13:07   0:00 [xrdp-chansrv] <defunct>
root      1847  2.0  0.0  26784 15180 ?        S    13:07   0:00 /usr/sbin/xrdp --nodaemon
root      1849  0.0  0.0  10884  3400 ?        S    13:07   0:00 /usr/sbin/xrdp --nodaemon
root      1851  0.0  0.0   3308   672 pts/0    S+   13:07   0:00 grep --color=auto xrdp
matt335672 commented 3 years ago

chansrv has nothing to do with resizing - something else will be causing it to crash. Consequently the reconnnects are trying to connect and timing out.

The chansrv log for X server display number $DISPLAY is in ~/.local/share/xrdp/xrdp-chansrv.$DISPLAY.log .

I suspect the root cause of your problem is #1487 which was a regression introduced in v0.9.12 and not fixed until v0.9.13. Because you're running in a container, /dev/fuse is likely inaccessible, and so the redirected drive can't be supported.

Can you try running your container with --device /dev/fuse? That might fix it.

A few other references for you:-

mboehm21 commented 3 years ago

I've added the device and SYS_ADMIN capabilities. Unfortunately, the behavior is the same.

matt335672 commented 3 years ago

What does the chansrv log look like?

mboehm21 commented 3 years ago

In xrdp.log or is there a separate file?

[20210622-14:13:24] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-14:13:24] [DEBUG] xrdp_mm_module_cleanup
[20210622-14:13:24] [DEBUG] Closed socket 18 (AF_UNIX)
[20210622-14:13:24] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-14:13:24] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 53302
[20210622-14:13:25] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-14:13:25] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-14:13:25] [DEBUG] TLSv1.3 enabled
[20210622-14:13:25] [DEBUG] TLSv1.2 enabled
[20210622-14:13:25] [DEBUG] Security layer: requested 1, selected 1
[20210622-14:13:25] [INFO ] connected client computer name: Guacamole RDP
[20210622-14:13:25] [INFO ] adding channel item name cliprdr chan_id 1004 flags 0xc0a00000
[20210622-14:13:25] [INFO ] TLS connection established from 172.35.199.3 port 53302: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384
[20210622-14:13:25] [DEBUG] xrdp_00000cb4_wm_login_mode_event_00000001
[20210622-14:13:25] [INFO ] Loading keymap file /etc/xrdp/km-00000407.ini
[20210622-14:13:25] [WARN ] local keymap file for 0x00000407 found and doesn't match built in keymap, using local keymap file
[20210622-14:13:25] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
[20210622-14:13:25] [INFO ] IPv6 not supported, falling back to IPv4
[20210622-14:13:25] [INFO ] xrdp_wm_log_msg: sesman connect ok
[20210622-14:13:25] [DEBUG] xrdp_wm_log_msg: sending login info to session manager, please wait...
[20210622-14:13:25] [DEBUG] return value from xrdp_mm_connect 0
[20210622-14:13:25] [INFO ] xrdp_wm_log_msg: login successful for display 10
[20210622-14:13:25] [DEBUG] xrdp_wm_log_msg: started connecting
[20210622-14:13:25] [INFO ] lib_mod_log_peer: xrdp_pid=3252 connected to X11rdp_pid=2946 X11rdp_uid=1068 X11rdp_gid=1068 client_ip=172.35.199.3 client_port=53302
[20210622-14:13:25] [DEBUG] xrdp_wm_log_msg: connected ok
[20210622-14:13:26] [INFO ] Socket 11: AF_INET connection received from 172.35.199.3 port 53314
[20210622-14:13:26] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-14:13:26] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-14:13:26] [DEBUG] TLSv1.3 enabled
[20210622-14:13:26] [DEBUG] TLSv1.2 enabled
[20210622-14:13:26] [DEBUG] Security layer: requested 1, selected 1
[20210622-14:13:26] [INFO ] connected client computer name: Guacamole RDP
[20210622-14:13:26] [INFO ] adding channel item name cliprdr chan_id 1004 flags 0xc0a00000
[20210622-14:13:27] [INFO ] TLS connection established from 172.35.199.3 port 53314: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384
[20210622-14:13:27] [DEBUG] xrdp_00000cb6_wm_login_mode_event_00000001
[20210622-14:13:27] [INFO ] Loading keymap file /etc/xrdp/km-00000407.ini
[20210622-14:13:27] [WARN ] local keymap file for 0x00000407 found and doesn't match built in keymap, using local keymap file
[20210622-14:13:27] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
[20210622-14:13:27] [INFO ] IPv6 not supported, falling back to IPv4
[20210622-14:13:27] [INFO ] xrdp_wm_log_msg: sesman connect ok
[20210622-14:13:27] [DEBUG] xrdp_wm_log_msg: sending login info to session manager, please wait...
[20210622-14:13:27] [DEBUG] return value from xrdp_mm_connect 0
[20210622-14:13:27] [INFO ] xrdp_wm_log_msg: login successful for display 10
[20210622-14:13:27] [DEBUG] xrdp_wm_log_msg: started connecting
[20210622-14:13:27] [INFO ] lib_mod_log_peer: xrdp_pid=3254 connected to X11rdp_pid=2946 X11rdp_uid=1068 X11rdp_gid=1068 client_ip=172.35.199.3 client_port=53314
[20210622-14:13:27] [DEBUG] xrdp_wm_log_msg: connected ok
[20210622-14:13:29] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-14:13:29] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-14:13:31] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 32914
[20210622-14:13:31] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-14:13:31] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-14:13:31] [DEBUG] TLSv1.3 enabled
[20210622-14:13:31] [DEBUG] TLSv1.2 enabled
[20210622-14:13:31] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-14:13:31] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-14:13:31] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-14:13:33] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-14:13:33] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-14:13:35] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-14:13:35] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-14:13:37] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-14:13:37] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-14:13:39] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-14:13:39] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-14:13:41] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-14:13:41] [ERROR] xrdp_mm_connect_chansrv: error in trans_connect chan
[20210622-14:13:41] [DEBUG] Closed socket 17 (AF_INET 127.0.0.1:58390)
[20210622-14:13:41] [DEBUG] Closed socket 11 (AF_INET 172.35.199.20:3389)
[20210622-14:13:41] [DEBUG] xrdp_mm_module_cleanup
[20210622-14:13:41] [DEBUG] Closed socket 18 (AF_UNIX)
[20210622-14:13:41] [DEBUG] Closed socket 19 (AF_UNIX)
[20210622-14:13:43] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20210622-14:13:43] [ERROR] xrdp_mm_connect_chansrv: error in trans_connect chan
[20210622-14:13:43] [DEBUG] Closed socket 17 (AF_INET 127.0.0.1:58402)
[20210622-14:13:51] [INFO ] Socket 11: AF_INET connection received from 127.0.0.1 port 32982
[20210622-14:13:51] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
[20210622-14:13:51] [DEBUG] Closed socket 10 (AF_INET 0.0.0.0:3389)
[20210622-14:13:51] [DEBUG] TLSv1.3 enabled
[20210622-14:13:51] [DEBUG] TLSv1.2 enabled
[20210622-14:13:51] [DEBUG] Closed socket 11 (AF_INET 127.0.0.1:3389)
root@initial-setup-1:/# ps -aux | grep xrdp
root      2909  0.0  0.0  10460  5268 ?        S    14:12   0:00 /usr/sbin/xrdp --nodaemon
root      2910  0.0  0.0  12560  5140 ?        S    14:12   0:00 /usr/sbin/xrdp-sesman --nodaemon
root      2944  0.0  0.0  12536  4020 ?        S    14:13   0:00 /usr/sbin/xrdp-sesman --nodaemon
mboehm21  2946  1.6  0.5 1927736 166468 ?      Sl   14:13   0:02 /usr/lib/xorg/Xorg :10 -auth .Xauthority -config xorg.conf -noreset -nolisten tcp -logfile .xorgxrdp.%s.log
mboehm21  2973  0.0  0.0      0     0 ?        Z    14:13   0:00 [xrdp-chansrv] <defunct>
root      3254  0.5  0.0  36956 31132 ?        S    14:13   0:00 /usr/sbin/xrdp --nodaemon
root      3349  0.0  0.0   3308   736 pts/0    S+   14:16   0:00 grep --color=auto xrdp
matt335672 commented 3 years ago

As per my post above, the chansrv log for X server display number $DISPLAY is in ~/.local/share/xrdp/xrdp-chansrv.$DISPLAY.log for the logged-in user. Sorry if I wasn't clear.

mboehm21 commented 3 years ago

Oh thanks, here is the output of this log:

mboehm21@initial-setup-1:~$ cat ~/.local/share/xrdp/xrdp-chansrv.10.log 
[20210622-14:33:51] [CORE ] main: app started pid 3097(0x00000c19)
[20210622-14:33:51] [INFO ] main: DISPLAY env var set to :10.0
[20210622-14:33:51] [INFO ] main: using DISPLAY 10
[20210622-14:33:51] [INFO ] channel_thread_loop: thread start
[20210622-14:33:51] [INFO ] Socket 12: AF_UNIX connection received
[20210622-14:34:26] [INFO ] channel_thread_loop: trans_check_wait_objs error resetting

The last entry is while resizing.

matt335672 commented 3 years ago

Ta.

It's not hugely informative. The last entry is fine as it just indicates the disconnect before the reconnect.

Can you find the [ChansrvLogging] section in /etc/xrdp/sesman.ini and set LogLevel=DEBUG?

Thanks.

mboehm21 commented 3 years ago

Unfortunately, there is still no more output in the log.

;; See `man 5 sesman.ini` for details

[Globals]
ListenAddress=127.0.0.1
ListenPort=3350
EnableUserWindowManager=true
; Give in relative path to user's home directory
UserWindowManager=startwm.sh
; Give in full path or relative path to /etc/xrdp
DefaultWindowManager=startwm.sh
; Give in full path or relative path to /etc/xrdp
ReconnectScript=reconnectwm.sh

[Security]
AllowRootLogin=true
MaxLoginRetry=4
TerminalServerUsers=tsusers
TerminalServerAdmins=tsadmins
; When AlwaysGroupCheck=false access will be permitted
; if the group TerminalServerUsers is not defined.
AlwaysGroupCheck=false
; When RestrictOutboundClipboard=true clipboard from the
; server is not pushed to the client.
RestrictOutboundClipboard=false

[Sessions]
;; X11DisplayOffset - x11 display number offset
; Type: integer
; Default: 10
X11DisplayOffset=10

;; MaxSessions - maximum number of connections to an xrdp server
; Type: integer
; Default: 0
MaxSessions=50

;; KillDisconnected - kill disconnected sessions
; Type: boolean
; Default: false
; if 1, true, or yes, kill session after 60 seconds
KillDisconnected=false

;; DisconnectedTimeLimit - when to kill idle sessions
; Type: integer
; Default: 0
; if not zero, the seconds before a disconnected session is killed
; min 60 seconds
DisconnectedTimeLimit=0

;; IdleTimeLimit (specify in second) - wait before disconnect idle sessions
; Type: integer
; Default: 0
; Set to 0 to disable idle disconnection.
IdleTimeLimit=0

;; Policy - session allocation policy
; Type: enum [ "Default" | "UBD" | "UBI" | "UBC" | "UBDI" | "UBDC" ]
; Default: Xrdp:<User,BitPerPixel> and Xvnc:<User,BitPerPixel,DisplaySize>
; "UBD" session per <User,BitPerPixel,DisplaySize>
; "UBI" session per <User,BitPerPixel,IPAddr>
; "UBC" session per <User,BitPerPixel,Connection>
; "UBDI" session per <User,BitPerPixel,DisplaySize,IPAddr>
; "UBDC" session per <User,BitPerPixel,DisplaySize,Connection>
Policy=Default

[Logging]
LogFile=xrdp-sesman.log
LogLevel=DEBUG
EnableSyslog=1
SyslogLevel=DEBUG

;
; Session definitions - startup command-line parameters for each session type
;

[Xorg]
; Specify the path of non-suid Xorg executable. It might differ depending
; on your distribution and version. The typical path is shown as follows:
;
; Fedora 26 or later    :  param=/usr/libexec/Xorg
; Debian 9 or later     :  param=/usr/lib/xorg/Xorg
; Ubuntu 16.04 or later :  param=/usr/lib/xorg/Xorg
; Arch Linux            :  param=/usr/lib/xorg-server/Xorg
; CentOS 7              :  param=/usr/bin/Xorg or param=Xorg
;
param=/usr/lib/xorg/Xorg
; Leave the rest paramaters as-is unless you understand what will happen.
param=-config
param=xorg.conf
param=-noreset
param=-nolisten
param=tcp
param=-logfile
param=.xorgxrdp.%s.log

[Xvnc]
param=Xvnc
param=-bs
param=-nolisten
param=tcp
param=-localhost
param=-dpi
param=96

[Chansrv]
; drive redirection, defaults to xrdp_client if not set
FuseMountName=thinclient_drives
; this value allows only the user to acess their own mapped drives.
; Make this more permissive (e.g. 022) if required.
FileUmask=077

[SessionVariables]
PULSE_SCRIPT=/etc/xrdp/pulse/default.pa

[ChansrvLogging]
LogLevel=DEBUG

Did I edit the correct section? Does is matter that the daemons are startet by supervisord and not by systemd?

matt335672 commented 3 years ago

Apologies - I've just has a look at the sources for 0.9.12 rather than the latest version. The log is set by environment variable CHANSRV_LOG_LEVEL for this version.

Can you add this line to [SessionVariables] instead and try again?

CHANSRV_LOG_LEVEL=LOG_LEVEL_DEBUG

I think that will do it.

mboehm21 commented 3 years ago

I've added the line:

[SessionVariables]
PULSE_SCRIPT=/etc/xrdp/pulse/default.pa
CHANSRV_LOG_LEVEL=LOG_LEVEL_DEBUG

Now there is a bit more output in the log file:

[20210622-15:19:23] [CORE ] main: app started pid 1623(0x00000657)
[20210622-15:19:23] [INFO ] main: DISPLAY env var set to :12.0
[20210622-15:19:23] [INFO ] main: using DISPLAY 12
[20210622-15:19:23] [INFO ] channel_thread_loop: thread start
[20210622-15:19:23] [INFO ] Socket 12: AF_UNIX connection received
[20210622-15:19:23] [DEBUG] my_trans_conn_in:
[20210622-15:19:23] [DEBUG] Closed socket 11 (AF_UNIX)
[20210622-15:19:23] [DEBUG] my_trans_data_in:
[20210622-15:19:23] [DEBUG] process_message_channel_setup:
[20210622-15:19:23] [DEBUG] process_message_channel_setup: num_chans 1
[20210622-15:19:23] [DEBUG] process_message_channel_setup: chan name 'cliprdr' id 0 flags 00000000
[20210622-15:19:23] [DEBUG] my_trans_data_in:
[20210622-15:19:23] [DEBUG] process_message_channel_data: chan_id 0 chan_flags 19
[20210622-15:19:24] [DEBUG] my_trans_data_in:
[20210622-15:19:24] [DEBUG] process_message_channel_data: chan_id 0 chan_flags 19
[20210622-15:19:24] [DEBUG] my_trans_data_in:
[20210622-15:19:24] [DEBUG] process_message_channel_data: chan_id 0 chan_flags 19
[20210622-15:19:28] [INFO ] channel_thread_loop: trans_check_wait_objs error resetting
matt335672 commented 3 years ago

Still not hugely informative I'm afraid.

A couple more questions:-

Thanks

mboehm21 commented 3 years ago

It is written to files. stdout is empty, stderr gives the following:

root@initial-setup-1:/# tail -f /var/log/supervisor/xrdp-sesman-stdout---supervisor-6yobg5h6.log 

^C
root@initial-setup-1:/# 
root@initial-setup-1:/# 
root@initial-setup-1:/# tail -f /var/log/supervisor/xrdp-sesman-stderr---supervisor-rf5z1nv9.log 
rdpClientConRecv: g_sck_recv failed(returned 0)
rdpClientConRecvMsg: error
rdpClientConCheck: rdpClientConGotData failed
rdpClientConDisconnect:
rdpRemoveClientConFromDev: removing clientCon 0x55ae75099420
rdpClientConGotConnection:
rdpClientConGotConnection: g_sck_accept ok new_sck 7
rdpClientConGetConnection: idle_disconnect_timeout set to non-positive value, idle timer turned off
rdpAddClientConToDev: adding first clientCon 0x55ae73806cb0
rdpClientConProcessMsgVersion: version 0 0 0 1
rdpClientConProcessScreenSizeMsg: set width 2974 height 1052 bpp 16
rdpClientConProcessScreenSizeMsg: shmemid 884736 shmemptr 0x7f26840c0000
rdpRRScreenSetSize: width 2974 height 1052 mmWidth 787 mmHeight 278
rdpRRGetInfo:
  screen resized to 2974x1052
rdpClientConProcessScreenSizeMsg: RRScreenSizeSet ok=[1]
rdpClientConProcessMsgClientInput: invalidate x 0 y 0 cx 2974 cy 1052
rdpClientConGotConnection:
rdpClientConGotConnection: g_sck_accept ok new_sck 17
rdpClientConGotConnection: marking only clientCon 0x55ae73806cb0 for disconnect
rdpClientConGetConnection: idle_disconnect_timeout set to non-positive value, idle timer turned off
rdpAddClientConToDev: adding clientCon 0x55ae7393a310
rdpClientConDisconnect:
rdpRemoveClientConFromDev: removing clientCon 0x55ae73806cb0
rdpClientConProcessMsgVersion: version 0 0 0 1
rdpClientConProcessScreenSizeMsg: set width 3000 height 1052 bpp 16
rdpClientConProcessScreenSizeMsg: shmemid 917504 shmemptr 0x7f26840b2000
rdpRRScreenSetSize: width 3000 height 1052 mmWidth 794 mmHeight 278
rdpRRGetInfo:
  screen resized to 3000x1052
rdpClientConProcessScreenSizeMsg: RRScreenSizeSet ok=[1]
rdpClientConProcessMsgClientInput: invalidate x 0 y 0 cx 3000 cy 1052
rdpClientConProcessMsgClientInfo:
  got client info bytes 5752
  jpeg support 0
  offscreen support 0
  offscreen size 0
  offscreen entries 0
  client supports glyph cache but server disabled
  client can not do offscreen to offscreen blits
  client can do new(color) cursor
  client can not do multimon
rdpRRSetRdpOutputs: numCrtcs 1 numOutputs 1 monitorCount 0
rdpRRSetRdpOutputs: update output 0 left 0 top 0 width 3000 height 1052
rdpRRUpdateOutput:
rdpLoadLayout: keylayout 0x00000407 variant  display 12
rdpkeybChangeKeyboardControl:
rdpkeybChangeKeyboardControl: autoRepeat on
rdpkeybChangeKeyboardControl:
rdpkeybChangeKeyboardControl: autoRepeat on
rdpInDeferredRepeatCallback:
rdpkeybChangeKeyboardControl:
rdpkeybChangeKeyboardControl: autoRepeat off
rdpInDeferredRepeatCallback:
rdpkeybChangeKeyboardControl:
rdpkeybChangeKeyboardControl: autoRepeat off
root@initial-setup-1:/# ls -l /dev/fuse 
crw-rw-rw- 1 root root 10, 229 Jun 22 15:46 /dev/fuse

Thanks for your time and dedication to the project and my issue by the way.

matt335672 commented 3 years ago

That's fine - I'm just sorry we seem unable to get any more info out of this v0.9.12 system!

The fuse stuff all looks fine, so I'm at a loss to see what is going on here.

In the supervisord config, is xrdp-sesman definitely being started with the -n flag to prevent daemonisation? That's one reason why the stdout file would be empty.

Another possible workaround I can see in the v0.9.12 code is to disable channels. That will prevent chansrv from starting at all, but resize on reconnect should still work I think. You can do that by setting allow_channels=false in /etc/xrdp/xrdp.ini.

mboehm21 commented 3 years ago

supervisor seems fine:

root@initial-setup-1:/# cat /etc/supervisor/conf.d/xrdp-sesman.conf 
[program:xrdp-sesman]
command=/usr/sbin/xrdp-sesman --nodaemon
user=root
autorestart=true
priority=400
root@initial-setup-1:/# cat /etc/supervisor/conf.d/xrdp.conf        
[program:xrdp]
command=/usr/sbin/xrdp --nodaemon
user=root
autorestart=true
priority=400

I set allow_channels=false and resizing is as speedy as it should be, great. However, copy / and paste is not working anymore which I also need :/. I think this feature relies on chansrv? Is there anything that could be done differently in @danielguerra69's Dockerfile to not stumble across this issue?

danielguerra69 commented 3 years ago

Could it be a docker problem ? My simple solution for this problem is restarting the container and everything works fine again. I noticed this problem with ubuntu 18.04 but not with ubuntu 20.04

mboehm21 commented 3 years ago

@danielguerra69 It might be related to Docker but cannot be solved by restarting the container. I think we have to find out the root cause for chansrv crashing on specific events like reconnects.

matt335672 commented 3 years ago

As I mentioned, I'm pretty sure the root cause is #1487 which is fixed in xrdp v0.9.13 and later. Copy-paste needs chansrv, so that's going to be broken anyway.

If it is #1487, the problem should be fixable by making sure the fuse stuff connects properly.

Here's something which might give us more info. It's a bit fiddly I'm afraid. 1) Log in to a session 2) Start a terminal window 3) Kill the existing chansrv process 4) fusermount -u ~/thinclient_drives (ignore any error) 5) Run xrdp-chansrv in the terminal window. It will display some debug info on stdout. 6) Disconnect and reconnect to the session so xrdp connects to xrdp-chansrv 7) Resize the session until we get a crash

Another option; download xrdp-0.9.15 from debian unstable and try that package. I managed to get the basic executables up on my Mint machine, but I needed to install libjpeg62.

danielguerra69 commented 3 years ago

In docker fuser only works when the container is running in privileged mode. On the ubuntu 18.04 when I close the rdp session by closing my client program the chansrv crashes . 20.04 doesn't ..

mboehm21 commented 3 years ago

With further testing I can confirm that chansrv does not crash when the container based on danielguerra/ubuntu-xrdp:20.04 is running in privileged mode. Resizing is speedy, copy / paste works. Great.

However, I don't want to run those containers as fully privileged if not absolutely necessary. Is there a way to find out which capabilities out of man 7 capabilities are really needed by xrdp / chansrv / fuse?

matt335672 commented 3 years ago

From what I've read SYS_ADMIN should be sufficient, but I'm not an expert.

There's also the host system. Does the container user have privilege to access /dev/fuse on the host?

mboehm21 commented 3 years ago

SYS_ADMIN does not seem enough unfortunately.

    cap_add:
      - SYS_ADMIN
    devices:
      - /dev/fuse
root@initial-setup-1:/# ls -lah /dev/fuse 
crw-rw-rw- 1 root root 10, 229 Jun 24 15:31 /dev/fuse
matt335672 commented 3 years ago

Can't really think of much else that isn't flailing about:- 1) Check the access logs on the host to see if they contain any useful info 2) Try adding all capabilities. If that doesn't work we've not got a capabilities issue.

The correct fix is to install a version of xrdp > 0.9.12. You won't have to grant any privileges to the container then.

mboehm21 commented 3 years ago

@danielguerra69, would it possible to add the version @matt335672 mentioned in a future release of your image?

danielguerra69 commented 3 years ago

@mboehm21 The debian unstable packages for xrdp 0.9.15 ? Ubuntu 18.04 uses xrdp 0.9.5-2 and ubuntu 20.04 xrdp 0.9.12-1

danielguerra69 commented 3 years ago

Is there a version from git for xrdp which works with ubuntu 18.04 ?

metalefty commented 3 years ago

@danielguerra69 It's up to Ubuntu team. We xrdp team is not responsible distro's package.

mboehm21 commented 3 years ago

The workaround to give the container full privileges worked for me for the last few days.

However, the final solution should be to use unprivileged containers. Can I help somehow to get xrdp > 0.9.12 into the image?

danielguerra69 commented 3 years ago

I used devel

danielguerra69 commented 3 years ago

Changed the master to v0.9.16 everything works fine on ubuntu 18.04, @mboehm21 can you confirm ?

mboehm21 commented 3 years ago

@danielguerra69: How do I get the image version with 0.9.16?

I still have 0.9.5 and 0.9.12 (on 20.04) after pulling from Dockerhub:

[11:21:53] mboehm21 :: dws-mboehm21  ➜  ~ » docker run -it --entrypoint /bin/bash --rm danielguerra/ubuntu-xrdp:latest
root@4e5364e75a05:/# cat /etc/os-release 
NAME="Ubuntu"
VERSION="18.04.5 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.5 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic
root@4e5364e75a05:/# xrdp --version

xrdp: A Remote Desktop Protocol server.
Copyright (C) Jay Sorg 2004-2014
See http://www.xrdp.org for more information.
Version 0.9.5

root@4e5364e75a05:/# exit
exit                                                                                                                                                                                                                                                                                      [15,69s]
[11:22:21] mboehm21 :: dws-mboehm21  ➜  ~ » docker run -it --entrypoint /bin/bash --rm danielguerra/ubuntu-xrdp:18.04 
root@777dbc956b89:/# cat /etc/os-release 
NAME="Ubuntu"
VERSION="18.04.5 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.5 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic
root@777dbc956b89:/# xrdp --version

xrdp: A Remote Desktop Protocol server.
Copyright (C) Jay Sorg 2004-2014
See http://www.xrdp.org for more information.
Version 0.9.5

[11:24:42] mboehm21 :: dws-mboehm21  ➜  ~ » docker run -it --entrypoint /bin/bash --rm danielguerra/ubuntu-xrdp:20.04
root@f6f0a426f922:/# cat /etc/os-release 
NAME="Ubuntu"
VERSION="20.04.2 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.2 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal
root@f6f0a426f922:/# xrdp --version
xrdp 0.9.12
  A Remote Desktop Protocol Server.
  Copyright (C) 2004-2018 Jay Sorg, Neutrino Labs, and all contributors.
  See https://github.com/neutrinolabs/xrdp for more information.

  Configure options:
      --enable-ipv6
      --enable-jpeg
      --enable-fuse
      --enable-rfxcodec
      --enable-opus
      --enable-painter
      --enable-vsock
      --build=x86_64-linux-gnu
      --prefix=/usr
      --includedir=${prefix}/include
      --mandir=${prefix}/share/man
      --infodir=${prefix}/share/info
      --sysconfdir=/etc
      --localstatedir=/var
      --disable-silent-rules
      --libdir=${prefix}/lib/x86_64-linux-gnu
      --libexecdir=${prefix}/lib/x86_64-linux-gnu
      --disable-maintainer-mode
      --disable-dependency-tracking
      --with-socketdir=/run/xrdp/sockdir
      build_alias=x86_64-linux-gnu
      CFLAGS=-g -O2 -fdebug-prefix-map=/build/xrdp-GJgww4/xrdp-0.9.12=. -fstack-protector-strong -Wformat -Werror=format-security 
      LDFLAGS=-Wl,-Bsymbolic-functions -Wl,-z,relro -Wl,-z,now -Wl,--as-needed
      CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2 
      PKG_CONFIG_PATH=/build/xrdp-GJgww4/xrdp-0.9.12/pkgconfig

  Compiled with OpenSSL 1.1.1f  31 Mar 2020

Is there another tag or do I have to build it myself from github?

danielguerra69 commented 3 years ago

My mistake , the proper xrdp is used in the builder but not in the final image. I will fix it and let you know.

mboehm21 commented 3 years ago

Hi @danielguerra69, did you have a chance to work on the image, yet?

mboehm21 commented 2 years ago

Hi everyone,

now I built my own images based on ubuntu 22.04. There I can install xrdp 0.9.17 which works really really smooth. Resizing is lightning fast.

However, I could not get this to work without "privileged: true" in docker. Is there any way to give it less or no capabilities?

matt335672 commented 2 years ago

Hi @mboehm21.

The only privilege you need that I'm aware of if is for /dev/fuse which is needed for remote drives and clipboard support.

We added the ability to disable FUSE mounts in XRDP v0.9.15. See the manpage for sesman.ini and look for EnableFuseMount. This should let you run without privilege, but you will lose the features I've just mentioned.

mboehm21 commented 2 years ago

Hi @matt335672.

Thanks for your reply. I did some further research and found out that on my Ubuntu 20.04 laptop with kernel 5.4.0-97-generic I can run xrdp + xfce4 in Docker just fine without privileges. However, my server is still 18.04 with kernel 4.15.0-166-generic. When I run the container there, I need the privileges. When I don't run xfce4 but openbox, it works without privileges.

So I assume that this is not a xrdp problem at all but related to xfce4 with the old kernel or something. I'll have to update my servers to 20.04 or even 22.04 when it's out and retry.

I'll close the issue for now and thank you for all the support and the great software.