xrdp_mm_connect_chansrv: error in trans_connect chan

[ezracelli]

Having a similar issue to #1288, but the client still disconnects after a pause on a black screen. I've built twice: first directly from devel and then with #1393 merged into a forked repo. Seems to also be similar to https://unix.stackexchange.com/questions/532983/arch-linux-issues-with-xorgxrdp-and-xfce4-windows-manager.

System info:

ezra@box
OS: Alpine Linux 
Kernel: x86_64 Linux 4.19.80-0-vanilla
Uptime: 8h 7m
Packages: 768
Shell: bash 5.0.0
Disk: 10.5G / 214.1G (5%)
CPU: AMD Ryzen 7 2700X Eight-Core @ 16x 4GHz
GPU: AMD/ATI Ellesmere [Radeon RX 470/480/570/570X/580/580X/590]
RAM: 19907MiB / 32140MiB

Built with (per https://git.alpinelinux.org/aports/tree/main/xrdp/APKBUILD):

./configure --prefix=/usr --disable-static --sysconfdir=/etc --localstatedir=/var --sbindir=/usr/sbin --enable-fuse --disable-pam --enable-tjpeg

/etc/xrdp/xrdp.ini (default):

[Globals]
; xrdp.ini file version number
ini_version=1

; fork a new process for each incoming connection
fork=true

; ports to listen on, number alone means listen on all interfaces
; 0.0.0.0 or :: if ipv6 is configured
; space between multiple occurrences
;
; Examples:
;   port=3389
;   port=unix://./tmp/xrdp.socket
;   port=tcp://.:3389                           127.0.0.1:3389
;   port=tcp://:3389                            *:3389
;   port=tcp://<any ipv4 format addr>:3389      192.168.1.1:3389
;   port=tcp6://.:3389                          ::1:3389
;   port=tcp6://:3389                           *:3389
;   port=tcp6://{<any ipv6 format addr>}:3389   {FC00:0:0:0:0:0:0:1}:3389
;   port=vsock://<cid>:<port>
port=3389

; 'port' above should be connected to with vsock instead of tcp
; use this only with number alone in port above
; prefer use vsock://<cid>:<port> above
use_vsock=false

; regulate if the listening socket use socket option tcp_nodelay
; no buffering will be performed in the TCP stack
tcp_nodelay=true

; regulate if the listening socket use socket option keepalive
; if the network connection disappear without close messages the connection will be closed
tcp_keepalive=true

; set tcp send/recv buffer (for experts)
#tcp_send_buffer_bytes=32768
#tcp_recv_buffer_bytes=32768

; security layer can be 'tls', 'rdp' or 'negotiate'
; for client compatible layer
security_layer=negotiate

; minimum security level allowed for client for classic RDP encryption
; use tls_ciphers to configure TLS encryption
; can be 'none', 'low', 'medium', 'high', 'fips'
crypt_level=high

; X.509 certificate and private key
; openssl req -x509 -newkey rsa:2048 -nodes -keyout key.pem -out cert.pem -days 365
certificate=
key_file=

; set SSL protocols
; can be comma separated list of 'SSLv3', 'TLSv1', 'TLSv1.1', 'TLSv1.2', 'TLSv1.3'
ssl_protocols=TLSv1.2, TLSv1.3
; set TLS cipher suites
#tls_ciphers=HIGH

; Section name to use for automatic login if the client sends username
; and password. If empty, the domain name sent by the client is used.
; If empty and no domain name is given, the first suitable section in
; this file will be used.
autorun=

allow_channels=true
allow_multimon=true
bitmap_cache=true
bitmap_compression=true
bulk_compression=true
#hidelogwindow=true
max_bpp=32
new_cursors=true
; fastpath - can be 'input', 'output', 'both', 'none'
use_fastpath=both
; when true, userid/password *must* be passed on cmd line
#require_credentials=true
; You can set the PAM error text in a gateway setup (MAX 256 chars)
#pamerrortxt=change your password according to policy at http://url

;
; colors used by windows in RGB format
;
blue=009cb5
grey=dedede
#black=000000
#dark_grey=808080
#blue=08246b
#dark_blue=08246b
#white=ffffff
#red=ff0000
#green=00ff00
#background=626c72

;
; configure login screen
;

; Login Screen Window Title
#ls_title=My Login Title

; top level window background color in RGB format
ls_top_window_bg_color=009cb5

; width and height of login screen
ls_width=350
ls_height=430

; login screen background color in RGB format
ls_bg_color=dedede

; optional background image filename (bmp format).
#ls_background_image=

; logo
; full path to bmp-file or file in shared folder
ls_logo_filename=
ls_logo_x_pos=55
ls_logo_y_pos=50

; for positioning labels such as username, password etc
ls_label_x_pos=30
ls_label_width=65

; for positioning text and combo boxes next to above labels
ls_input_x_pos=110
ls_input_width=210

; y pos for first label and combo box
ls_input_y_pos=220

; OK button
ls_btn_ok_x_pos=142
ls_btn_ok_y_pos=370
ls_btn_ok_width=85
ls_btn_ok_height=30

; Cancel button
ls_btn_cancel_x_pos=237
ls_btn_cancel_y_pos=370
ls_btn_cancel_width=85
ls_btn_cancel_height=30

[Logging]
LogFile=xrdp.log
LogLevel=DEBUG
EnableSyslog=true
SyslogLevel=DEBUG
; LogLevel and SysLogLevel could by any of: core, error, warning, info or debug

[Channels]
; Channel names not listed here will be blocked by XRDP.
; You can block any channel by setting its value to false.
; IMPORTANT! All channels are not supported in all use
; cases even if you set all values to true.
; You can override these settings on each session type
; These settings are only used if allow_channels=true
rdpdr=true
rdpsnd=true
drdynvc=true
cliprdr=true
rail=true
xrdpvr=true
tcutils=true

; for debugging xrdp, in section xrdp1, change port=-1 to this:
#port=/tmp/.xrdp/xrdp_display_10

; for debugging xrdp, add following line to section xrdp1
#chansrvport=/tmp/.xrdp/xrdp_chansrv_socket_7210


;
; Session types
;

; Some session types such as Xorg, X11rdp and Xvnc start a display server.
; Startup command-line parameters for the display server are configured
; in sesman.ini. See and configure also sesman.ini.
[Xorg]
name=Xorg
lib=libxup.so
username=ask
password=ask
ip=127.0.0.1
port=-1
code=20

[Xvnc]
name=Xvnc
lib=libvnc.so
username=ask
password=ask
ip=127.0.0.1
port=-1
#xserverbpp=24
#delay_ms=2000

[vnc-any]
name=vnc-any
lib=libvnc.so
ip=ask
port=ask5900
username=na
password=ask
#pamusername=asksame
#pampassword=asksame
#pamsessionmng=127.0.0.1
#delay_ms=2000

[neutrinordp-any]
name=neutrinordp-any
lib=libxrdpneutrinordp.so
ip=ask
port=ask3389
username=ask
password=ask

; You can override the common channel settings for each session type
#channel.rdpdr=true
#channel.rdpsnd=true
#channel.drdynvc=true
#channel.cliprdr=true
#channel.rail=true
#channel.xrdpvr=true

/var/log/xrdp.log:

[20191103-19:09:52] [INFO ] Socket 12: AF_INET connection received from 192.168.1.8 port 54053
[20191103-19:09:52] [DEBUG] Closed socket 12 (AF_INET 192.168.1.101:3389)
[20191103-19:09:52] [DEBUG] Closed socket 11 (AF_INET 0.0.0.0:3389)
[20191103-19:09:52] [INFO ] Using default X.509 certificate: /etc/xrdp/cert.pem
[20191103-19:09:52] [INFO ] Using default X.509 key file: /etc/xrdp/key.pem
[20191103-19:09:52] [DEBUG] TLSv1.3 enabled
[20191103-19:09:52] [DEBUG] TLSv1.2 enabled
[20191103-19:09:52] [DEBUG] Security layer: requested 3, selected 1
[20191103-19:09:52] [DEBUG] Closed socket 12 (AF_INET 192.168.1.101:3389)
[20191103-19:09:52] [INFO ] Socket 12: AF_INET connection received from 192.168.1.8 port 54054
[20191103-19:09:52] [DEBUG] Closed socket 12 (AF_INET 192.168.1.101:3389)
[20191103-19:09:52] [DEBUG] Closed socket 11 (AF_INET 0.0.0.0:3389)
[20191103-19:09:52] [INFO ] Using default X.509 certificate: /etc/xrdp/cert.pem
[20191103-19:09:52] [INFO ] Using default X.509 key file: /etc/xrdp/key.pem
[20191103-19:09:52] [DEBUG] TLSv1.3 enabled
[20191103-19:09:52] [DEBUG] TLSv1.2 enabled
[20191103-19:09:52] [DEBUG] Security layer: requested 0, selected 0
[20191103-19:09:52] [DEBUG] Closed socket 12 (AF_INET 192.168.1.101:3389)
[20191103-19:09:52] [INFO ] Socket 12: AF_INET connection received from 192.168.1.8 port 54055
[20191103-19:09:52] [DEBUG] Closed socket 12 (AF_INET 192.168.1.101:3389)
[20191103-19:09:52] [DEBUG] Closed socket 11 (AF_INET 0.0.0.0:3389)
[20191103-19:09:52] [INFO ] Using default X.509 certificate: /etc/xrdp/cert.pem
[20191103-19:09:52] [INFO ] Using default X.509 key file: /etc/xrdp/key.pem
[20191103-19:09:52] [DEBUG] TLSv1.3 enabled
[20191103-19:09:52] [DEBUG] TLSv1.2 enabled
[20191103-19:09:52] [DEBUG] Security layer: requested 0, selected 0
[20191103-19:09:52] [INFO ] connected client computer name: box
[20191103-19:09:52] [INFO ] adding channel item name rdpdr chan_id 1004 flags 0xc0800000
[20191103-19:09:52] [INFO ] adding channel item name rdpsnd chan_id 1005 flags 0xc0000000
[20191103-19:09:52] [INFO ] adding channel item name cliprdr chan_id 1006 flags 0xc0a00000
[20191103-19:09:52] [INFO ] adding channel item name drdynvc chan_id 1007 flags 0xc0800000
[20191103-19:09:52] [INFO ] Non-TLS connection established from 192.168.1.8 port 54055: encrypted with standard RDP security
[20191103-19:09:52] [DEBUG] xrdp_000060ce_wm_login_mode_event_00000001
[20191103-19:09:52] [INFO ] Cannot find keymap file /etc/xrdp/km-00000000.ini
[20191103-19:09:52] [INFO ] Cannot find keymap file /etc/xrdp/km-00000000.ini
[20191103-19:09:52] [INFO ] Loading keymap file /etc/xrdp/km-00000409.ini
[20191103-19:09:52] [WARN ] local keymap file for 0x00000000 found and doesn't match built in keymap, using local keymap file
[20191103-19:09:52] [DEBUG] xrdp_wm_log_msg: connecting to sesman ip 127.0.0.1 port 3350
[20191103-19:09:52] [INFO ] xrdp_wm_log_msg: sesman connect ok
[20191103-19:09:52] [DEBUG] xrdp_wm_log_msg: sending login info to session manager, please wait...
[20191103-19:09:52] [DEBUG] return value from xrdp_mm_connect 0
[20191103-19:09:52] [INFO ] xrdp_wm_log_msg: login successful for display 10
[20191103-19:09:52] [DEBUG] xrdp_wm_log_msg: started connecting
[20191103-19:09:52] [INFO ] lib_mod_log_peer: xrdp_pid=24782 connected to X11rdp_pid=24786 X11rdp_uid=1000 X11rdp_gid=1000 client_ip=192.168.1.8 client_port=54055
[20191103-19:09:52] [DEBUG] xrdp_wm_log_msg: connected ok
[20191103-19:09:56] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20191103-19:09:56] [DEBUG] Closed socket 18 (AF_UNIX)
[20191103-19:10:00] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20191103-19:10:00] [DEBUG] Closed socket 18 (AF_UNIX)
[20191103-19:10:04] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20191103-19:10:04] [DEBUG] Closed socket 18 (AF_UNIX)
[20191103-19:10:08] [ERROR] xrdp_mm_connect_chansrv: connect failed trying again...
[20191103-19:10:08] [ERROR] xrdp_mm_connect_chansrv: error in trans_connect chan
[20191103-19:10:08] [DEBUG] Closed socket 16 (AF_INET 127.0.0.1:35660)
[20191103-19:10:08] [DEBUG] Closed socket 12 (AF_INET 192.168.1.101:3389)
[20191103-19:10:08] [DEBUG] xrdp_mm_module_cleanup
[20191103-19:10:08] [DEBUG] Closed socket 17 (AF_UNIX)
[20191103-19:10:08] [DEBUG] Closed socket 18 (AF_UNIX)

With allow_channels=false set and #1393 merged in, the session disconnects immediately with this in the log:

...
[20191103-18:43:19] [DEBUG] xrdp_wm_log_msg: connected ok
[20191103-18:43:19] [DEBUG] xrdp_mm_connect_chansrv: skip connecting to chansrv because all channels are disabled
[20191103-18:43:19] [DEBUG] Closed socket 16 (AF_INET 127.0.0.1:56572)
[20191103-18:43:20] [DEBUG] Closed socket 12 (AF_INET 192.168.1.101:3389)
[20191103-18:43:20] [DEBUG] xrdp_mm_module_cleanup
[20191103-18:43:20] [DEBUG] Closed socket 17 (AF_UNIX)
[20191103-18:44:00] [DEBUG] Closed socket 11 (AF_INET 0.0.0.0:3389)

[metalefty]

Sometimes xrdp-chansrv will get stuck and it causes this issue. I need to find out the root cause of chansrv stuck but I'll merge #1393 ad workaround.

[metalefty]

Oops, when #1393 is merged, the session disconnects.

[metalefty]

@ezracelli With allow_channels=false and get stuck in connecting chansrv, is xrdp-chansrv process running? Let me know your process state.

[ezracelli]

@metalefty Nope, doesn't appear so. Results of ps aux | grep xrdp...

...with no session attempt in progress:

root     29497  0.0  0.0   5256   948 ?        S    20:31   0:00 /usr/sbin/xrdp
root     29581  0.0  0.0   4076   312 ?        S    20:31   0:00 /usr/sbin/xrdp-sesman

...with session attempt in progress (black screen visible on client):

root     29497  0.0  0.0   5256   948 ?        S    20:31   0:00 /usr/sbin/xrdp
root     29581  0.0  0.0   4076   312 ?        S    20:31   0:00 /usr/sbin/xrdp-sesman
root     31087  0.2  0.0  13724  8020 ?        S    20:33   0:00 /usr/sbin/xrdp

[metalefty]

So it appears xrdp-chansrv crashed for some reasons and no longer running. It is reasonable that connecting to chansrv fails because it is not running.

The root cause seems crash of xrdp-chansrv.

The issue is separated into these 3 issues:

1. xrdp-chansrv should not crash, should be more stable and reliable
2. xrdp should be able to connect sessions xrdp-chansrv crashed xrdp: skip connecting to chansrv when no channels enabled #1393
3. xrdp-chansrv should be restarted when crashed chansrv restart #1259

#1393 is a workaround who doesn't need channels. Not a solution.

Then next, we need to find out the cause of chansrv crash.

[lv-gh]

I can consistently reproduce xrdp-chansrv stuck on 18.10 Ubuntu, xrdp-0.9.11. xrdp-chansrv process won't crash, but eats up ~100% cpu and GUI is completely frozen (unresponsive) for some 10-30s. It's somehow closely related to sound redirection, because it usually happens when playing short sounds/beeps (visual bell in terminal/editor, etc). How can i elaborate on this problem? Strace, debug log? To me channel_thread_loop() calling g_obj_wait with INFINITIVE timeout looks suspicious...

[jsorg71]

@lv-gh If you think it's audio related, can you delete the xrdp source and sink and see if it still happens. If not it might be the pulseaudio >= 12 issue. What pulseaudio version is in Ubuntu 18.10?

[lv-gh]

pulseaudio 12.2. This (incompatibility or bug) is known or maybe documented somewhere?
Yes, when xrdp-source xrdp-sink modules are not loaded, then xrdp-chansrv won't stuck.

[jsorg71]

@lv-gh
neutrinolabs/pulseaudio-module-xrdp#31
The issue with Debian 10 is delayed audio, not hang in chansrv, but can you try my possible fix?

[lv-gh]

Well, it kind of works. At least seams so, cause i was unable to hang chansrv, but it might start hanging sometime later (as with orig pulseaudio-module-xrdp). Kind of, because sound is still not very usable/reliable (though better, i'd say): delays, jerks, lost frames. It misses almost all of short audio bells and some of them, that are actually played, are inconsistently delayed about ~3-4 seconds. It's off-topic, though. My major concern is that sound or other auxiliary problems definitely shouldn't hang chansrv/xrdp. Thank you.

[metalefty]

Just to summarize, these issues are related (same root cause).

• xrdp-chansrv stucks "Resource temporarily unavailable" #1265
• No sound on Debian Buster. pulseaudio-module-xrdp#31
• fix for delay in sink pulseaudio-module-xrdp#38

[metalefty]

I also suffered from chansrv high CPU usage and audio redirection instability in #1265. neutrinolabs/pulseaudio-module-xrdp#38 solved the issue.

[moobyfr]

I can consistently reproduce xrdp-chansrv stuck on 18.10 Ubuntu, xrdp-0.9.11. xrdp-chansrv process won't crash, but eats up ~100% cpu and GUI is completely frozen (unresponsive) for some 10-30s. It's somehow closely related to sound redirection, because it usually happens when playing short sounds/beeps (visual bell in terminal/editor, etc). How can i elaborate on this problem? Strace, debug log? To me channel_thread_loop() calling g_obj_wait with INFINITIVE timeout looks suspicious...

I think I have also users with such a problem in debian buster, after ring bell in terminal, session freezed (default packages 0.9.9, was working fine with previous version , or in debian stretch)

[matt335672]

I'm closing this issue now. Version 0.6 of the pulseaudio module has been released with significant changes, and the wiki README has been updated with better build instructions.