neutrinolabs / xrdp

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

failure to connect to an xrdp server: xrdp_mm_chansrv_connect: error in trans_connect chan #3008

Closed alexbodn closed 6 months ago

alexbodn commented 6 months ago

xrdp version

0.9.21.1

Detailed xrdp version, build options

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 -ffile-prefix-map=/build/xrdp-QTF2mN/xrdp-0.9.21.1=. -fstack-protector-strong -Wformat -Werror=format-security 
      LDFLAGS=-Wl,-z,relro -Wl,-z,now -Wl,--as-needed
      CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2 
      PKG_CONFIG_PATH=/build/xrdp-QTF2mN/xrdp-0.9.21.1/pkgconfig

  Compiled with OpenSSL 3.0.11 19 Sep 2023

Operating system & version

Debian 12 bookworm, current stable

Installation method

dnf / apt / zypper / pkg / etc

Which backend do you use?

Xorg

What desktop environment do you use?

xfce4

Environment xrdp running on

vm

What's your client?

ms rd client, remmina, xfreerdp

Area(s) with issue?

Network

Steps to reproduce

the login process from either client takes to a dialog from xrdp, where i fill user name and password. the user is not logged in to the system, as instructed.

i have added the xrdp user to the group ss-cert, to read the system default certs.

✔️ Expected Behavior

i'd prefer to see my remote desktop. don't mind through which client.

❌ Actual Behavior

the client window goes blank, or the window closes. depends on the client.

Anything else?

xrdp.log:

[20240320-16:34:57] [INFO ] Socket 12: AF_INET6 connection received from ::ffff:31.168.60.70 port 37104 [20240320-16:34:57] [INFO ] Using default X.509 certificate: /etc/xrdp/cert.pem [20240320-16:34:57] [INFO ] Using default X.509 key file: /etc/xrdp/key.pem [20240320-16:34:57] [INFO ] Security protocol: configured [SSL|RDP], requested [SSL|HYBRID|HYBRID_EX|RDP], selected [SSL] [20240320-16:35:04] [INFO ] Connected client computer name: strongbad [20240320-16:35:04] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc006 is unknown (ignored) [20240320-16:35:04] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc00a is unknown (ignored) [20240320-16:35:04] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc00c is unknown (ignored) [20240320-16:35:05] [INFO ] xrdp_load_keyboard_layout: Keyboard information sent by the RDP client, keyboard_type:[0x04], > [20240320-16:35:05] [INFO ] xrdp_load_keyboard_layout: model [] variant [] layout [us] options [] [20240320-16:35:05] [INFO ] TLS connection established from ::ffff:31.168.60.70 port 37104: TLSv1.3 with cipher TLS_AES_25> [20240320-16:35:06] [INFO ] xrdp_caps_process_pointer: client supports new(color) cursor [20240320-16:35:06] [INFO ] xrdp_process_offscreen_bmpcache: support level 0 cache size 0 MB cache entries 0 [20240320-16:35:06] [INFO ] xrdp_caps_process_codecs: nscodec, codec id 1, properties len 3 [20240320-16:35:06] [INFO ] Loading keymap file /etc/xrdp/km-00000409.ini [20240320-16:35:06] [WARN ] local keymap file for 0x00000409 found and doesn't match built in keymap, using local keymap f> [20240320-16:35:30] [INFO ] connecting to sesman on 127.0.0.1:3350 [20240320-16:35:30] [INFO ] xrdp_wm_log_msg: sesman connect ok [20240320-16:35:30] [INFO ] sesman connect ok [20240320-16:35:30] [INFO ] sending login info to session manager. Please wait... [20240320-16:35:30] [INFO ] xrdp_wm_log_msg: login successful for user rmwin on display 10 [20240320-16:35:30] [INFO ] login successful for user rmwin on display 10 [20240320-16:35:30] [INFO ] loaded module 'libxup.so' ok, interface size 10296, version 4 [20240320-16:35:30] [INFO ] started connecting [20240320-16:35:30] [INFO ] lib_mod_connect: connecting via UNIX socket [20240320-16:35:30] [INFO ] lib_mod_log_peer: xrdp_pid=2060858 connected to X11rdp_pid=2061739 X11rdp_uid=1006 X11rdp_gid=> [20240320-16:35:30] [INFO ] connected ok [20240320-16:35:34] [WARN ] xrdp_mm_chansrv_connect: connect failed trying again... [20240320-16:35:38] [WARN ] xrdp_mm_chansrv_connect: connect failed trying again... [20240320-16:35:42] [WARN ] xrdp_mm_chansrv_connect: connect failed trying again... [20240320-16:35:46] [WARN ] xrdp_mm_chansrv_connect: connect failed trying again... [20240320-16:35:46] [ERROR] xrdp_mm_chansrv_connect: error in trans_connect chan [20240320-16:35:46] [ERROR] SSL_shutdown: Failure in SSL library (protocol error?) [20240320-16:35:46] [ERROR] SSL: error:0A000123:SSL routines::application data after close notify

xrdp-sesman.log

[20240320-16:35:30] [INFO ] Socket 12: AF_INET6 connection received from ::1 port 34582 [20240320-16:35:30] [INFO ] Terminal Server Users group is disabled, allowing authentication [20240320-16:35:30] [INFO ] ++ created session (access granted): username rmwin, ip ::ffff:31.168.60.70:37104 - socket: 12 [20240320-16:35:30] [INFO ] starting Xorg session... [20240320-16:35:30] [INFO ] Starting session: session_pid 2061737, display :10.0, width 1800, height 1080, bpp 24, client ip ::ffff:31.168.60.70:37104 - socket: 12, user name rmwin [20240320-16:35:30] [INFO ] [session start] (display 10): calling auth_start_session from pid 2061737 [20240320-16:35:30] [ERROR] sesman_data_in: scp_process_msg failed [20240320-16:35:30] [ERROR] sesman_main_loop: trans_check_wait_objs failed, removing trans [20240320-16:35:30] [INFO ] Starting X server on display 10: /usr/lib/xorg/Xorg :10 -auth .Xauthority -config xrdp/xorg.conf -noreset -nolisten tcp -logfile .xorgxrdp.%s.log
[20240320-16:35:30] [INFO ] Found X server running at /tmp/.X11-unix/X10 [20240320-16:35:30] [INFO ] Found X server running at /tmp/.X11-unix/X10 [20240320-16:35:30] [INFO ] Found X server running at /tmp/.X11-unix/X10 [20240320-16:35:30] [INFO ] Starting the xrdp channel server for display 10 [20240320-16:35:30] [INFO ] Session started successfully for user rmwin on display 10 [20240320-16:35:30] [INFO ] Starting the default window manager on display 10: /etc/xrdp/startwm.sh [20240320-16:35:30] [INFO ] Session in progress on display 10, waiting until the window manager (pid 2061738) exits to end the session [20240320-16:35:30] [WARN ] Window manager (pid 2061738, display 10) exited with non-zero exit code 2 and signal 0. This could indicate a window manager config problem [20240320-16:35:30] [WARN ] Window manager (pid 2061738, display 10) exited quickly (0 secs). This could indicate a window manager config problem [20240320-16:35:30] [INFO ] Calling auth_stop_session and auth_end from pid 2061737 [20240320-16:35:30] [INFO ] Terminating X server (pid 2061739) on display 10 [20240320-16:35:30] [INFO ] Terminating the xrdp channel server (pid 2061748) on display 10 [20240320-16:35:30] [INFO ] X server on display 10 (pid 2061739) returned exit code 0 and signal number 0 [20240320-16:35:30] [INFO ] xrdp channel server for display 10 (pid 2061748) exit code 0 and signal number 0 [20240320-16:35:30] [INFO ] cleanup_sockets: [20240320-16:35:30] [INFO ] Process 2061737 has exited [20240320-16:35:30] [INFO ] ++ terminated session: username rmwin, display :10.0, session_pid 2061737, ip ::ffff:31.168.60.70:37104 - socket: 12

ufw firewall relevant status:

[11] 3389 ALLOW IN 127.0.0.1
[12] 3389 ALLOW IN 31.168.60.70
[16] 3389 ALLOW IN ::ffff:31.168.60.70

the /home/rmwin/.xorgxrdp.10.log shows no (EE) errors.

the xfreerdp command line:

xfreerdp +auto-reconnect /auto-reconnect-max-retries:0 +glyph-cache +clipboard /cert:ignore /relax-order-checks /u:rmwin /v:vmi939059.contaboserver.net /size:1920x1080 /log-level:DEBUG

the xfreerdp output tail:

[18:01:06:719] [2136:2137] [INFO][com.freerdp.core] - ERRINFO_LOGOFF_BY_USER (0x0000000C):The disconnection was initiated by the user logging off their session on the server. [18:01:06:719] [2136:2137] [ERROR][com.freerdp.core] - rdp_set_error_info:freerdp_set_last_error_ex ERRINFO_LOGOFF_BY_USER [0x0001000C] [18:01:06:719] [2136:2137] [DEBUG][com.freerdp.core.rdp] - DisconnectProviderUltimatum: reason: 3 [18:01:06:719] [2136:2137] [DEBUG][com.freerdp.core.rdp] - transport_check_fds() - -1 [18:01:06:719] [2136:2137] [DEBUG][com.freerdp.core] - rdp_check_fds() - -1 [18:01:06:720] [2136:2137] [DEBUG][com.freerdp.core.connection] - rdp_client_transition_to_state CONNECTION_STATE_ACTIVE --> CONNECTION_STATE_INITIAL [18:01:06:732] [2136:2137] [DEBUG][com.freerdp.client.x11] - xf_Pointer_Free: 0x0000007f7c708c80 [18:01:06:732] [2136:2137] [DEBUG][com.freerdp.client.x11] - xf_Pointer_Free: 0x0000007f7c708a90

here is xrdp.log with xfreerdp:

[20240320-16:35:46] [ERROR] SSL_shutdown: Failure in SSL library (protocol error?) [20240320-16:35:46] [ERROR] SSL: error:0A000123:SSL routines::application data after close notify [20240320-17:00:41] [INFO ] Socket 12: AF_INET6 connection received from ::ffff:31.168.60.70 port 43120 [20240320-17:00:42] [INFO ] Using default X.509 certificate: /etc/xrdp/cert.pem [20240320-17:00:42] [INFO ] Using default X.509 key file: /etc/xrdp/key.pem [20240320-17:00:42] [INFO ] Security protocol: configured [SSL|RDP], requested [SSL|HYBRID|RDP], selected [SSL] [20240320-17:00:42] [INFO ] Connected client computer name: penguin [20240320-17:00:42] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc006 is unknown (ignored) [20240320-17:00:42] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc00a is unknown (ignored) [20240320-17:00:43] [INFO ] xrdp_load_keyboard_layout: Keyboard information sent by the RDP client, keyboard_type:[0x04], > [20240320-17:00:43] [INFO ] xrdp_load_keyboard_layout: model [] variant [] layout [us] options [] [20240320-17:00:43] [INFO ] TLS connection established from ::ffff:31.168.60.70 port 43120: TLSv1.3 with cipher TLS_AES_25> [20240320-17:00:43] [INFO ] xrdp_caps_process_pointer: client supports new(color) cursor [20240320-17:00:43] [INFO ] xrdp_caps_process_codecs: RemoteFX, codec id 3, properties len 49 [20240320-17:00:43] [INFO ] Loading keymap file /etc/xrdp/km-00000409.ini [20240320-17:00:43] [WARN ] local keymap file for 0x00000409 found and doesn't match built in keymap, using local keymap f> [20240320-17:00:43] [ERROR] dynamic_monitor_open_response: error [20240320-17:00:43] [ERROR] xrdp_rdp_recv: xrdp_channel_process failed [20240320-17:01:06] [INFO ] connecting to sesman on 127.0.0.1:3350 [20240320-17:01:06] [INFO ] xrdp_wm_log_msg: sesman connect ok [20240320-17:01:06] [INFO ] sesman connect ok [20240320-17:01:06] [INFO ] sending login info to session manager. Please wait... [20240320-17:01:06] [INFO ] xrdp_wm_log_msg: login successful for user rmwin on display 10 [20240320-17:01:06] [INFO ] login successful for user rmwin on display 10 [20240320-17:01:06] [INFO ] loaded module 'libxup.so' ok, interface size 10296, version 4 [20240320-17:01:06] [INFO ] started connecting [20240320-17:01:06] [INFO ] lib_mod_connect: connecting via UNIX socket [20240320-17:01:06] [INFO ] lib_mod_log_peer: xrdp_pid=2106433 connected to X11rdp_pid=2107284 X11rdp_uid=1006 X11rdp_gid=> [20240320-17:01:06] [INFO ] connected ok

xrdp-sesman.log with xfreerdp:

[20240320-17:01:06] [INFO ] Socket 12: AF_INET6 connection received from ::1 port 58318 [20240320-17:01:06] [INFO ] Terminal Server Users group is disabled, allowing authentication [20240320-17:01:06] [INFO ] ++ created session (access granted): username rmwin, ip ::ffff:31.168.60.70:43120 - socket: 12 [20240320-17:01:06] [INFO ] starting Xorg session... [20240320-17:01:06] [INFO ] Starting session: session_pid 2107271, display :10.0, width 1920, height 1080, bpp 24, client ip ::ffff:31.168.60.70:43120 - socket: 12, user name rmwin [20240320-17:01:06] [INFO ] [session start] (display 10): calling auth_start_session from pid 2107271 [20240320-17:01:06] [ERROR] sesman_data_in: scp_process_msg failed [20240320-17:01:06] [ERROR] sesman_main_loop: trans_check_wait_objs failed, removing trans [20240320-17:01:06] [INFO ] Starting X server on display 10: /usr/lib/xorg/Xorg :10 -auth .Xauthority -config xrdp/xorg.conf -noreset -nolisten tcp -logfile .xorgxrdp.%s.log
[20240320-17:01:07] [INFO ] Found X server running at /tmp/.X11-unix/X10 [20240320-17:01:07] [INFO ] Found X server running at /tmp/.X11-unix/X10 [20240320-17:01:07] [INFO ] Found X server running at /tmp/.X11-unix/X10 [20240320-17:01:07] [INFO ] Starting the default window manager on display 10: /etc/xrdp/startwm.sh [20240320-17:01:07] [INFO ] Starting the xrdp channel server for display 10 [20240320-17:01:07] [INFO ] Session started successfully for user rmwin on display 10 [20240320-17:01:07] [INFO ] Session in progress on display 10, waiting until the window manager (pid 2107283) exits to end the session [20240320-17:01:07] [WARN ] Window manager (pid 2107283, display 10) exited with non-zero exit code 2 and signal 0. This could indicate a window manager config problem [20240320-17:01:07] [WARN ] Window manager (pid 2107283, display 10) exited quickly (0 secs). This could indicate a window manager config problem [20240320-17:01:07] [INFO ] Calling auth_stop_session and auth_end from pid 2107271 [20240320-17:01:07] [INFO ] Terminating X server (pid 2107284) on display 10 [20240320-17:01:07] [INFO ] Terminating the xrdp channel server (pid 2107315) on display 10 [20240320-17:01:07] [INFO ] X server on display 10 (pid 2107284) returned exit code 0 and signal number 0 [20240320-17:01:07] [INFO ] xrdp channel server for display 10 (pid 2107315) exit code 0 and signal number 0 [20240320-17:01:07] [INFO ] cleanup_sockets: [20240320-17:01:07] [INFO ] Process 2107271 has exited [20240320-17:01:07] [INFO ] ++ terminated session: username rmwin, display :10.0, session_pid 2107271, ip ::ffff:31.168.60.70:43120 - socket: 12

matt335672 commented 6 months ago

Thanks @alexbodn

You say there are no errors in your xorgxrdp.10.log, so it's highly likely that your /etc/xrdp/startwm.sh invocation is failing.

Let's try tracing it through from the command line. What do you get for this command when logged in as rmwin? There's a space after DISPLAY= :-

DISPLAY= /bin/sh -x /etc/xrdp/startwm.sh
Sergiolisis commented 6 months ago

xrdp version 0.9.25.1

DISPLAY= /bin/sh -x /etc/xrdp/startwm.sh
+ test -r /etc/profile
+ . /etc/profile
+ [ $  ]
+ [  ]
+ id -u
+ [ 1000 -eq 0 ]
+ PS1=$ 
+ [ -d /etc/profile.d ]
+ [ -r /etc/profile.d/01-locale-fix.sh ]
+ . /etc/profile.d/01-locale-fix.sh
+ /usr/bin/locale-check C.UTF-8
+ eval
+ [ -r /etc/profile.d/bash_completion.sh ]
+ . /etc/profile.d/bash_completion.sh
+ [ x != x -a x$  != x -a x = x ]
+ [ -r /etc/profile.d/debuginfod.sh ]
+ [ -r /etc/profile.d/flatpak.sh ]
+ . /etc/profile.d/flatpak.sh
+ command -v flatpak
+ unset G_MESSAGES_DEBUG
+ echo /home/cynteka/.local/share/flatpak
+ GIO_USE_VFS=local flatpak --installations
+ new_dirs=
+ read -r install_path
+ share_path=/home/cynteka/.local/share/flatpak/exports/share
+ :
+ read -r install_path
+ share_path=/var/lib/flatpak/exports/share
+ :
+ read -r install_path
+ echo 
+ new_dirs=
+ export XDG_DATA_DIRS
+ XDG_DATA_DIRS=/home/cynteka/.local/share/flatpak/exports/share:/var/lib/flatpak/exports/share:/usr/local/share:/usr/share
+ [ -r /etc/profile.d/gawk.sh ]
+ . /etc/profile.d/gawk.sh
+ [ -r /etc/profile.d/im-config_wayland.sh ]
+ . /etc/profile.d/im-config_wayland.sh
+ [ tty != wayland ]
+ return
+ [ -r /etc/profile.d/vte-2.91.sh ]
+ . /etc/profile.d/vte-2.91.sh
+ [ -n  -o -n  ]
+ return 0
+ unset i
+ test -r /home/cynteka/.profile
+ . /home/cynteka/.profile
+ [ -n  ]
+ [ -d /home/cynteka/bin ]
+ [ -d /home/cynteka/.local/bin ]
+ unset DBUS_SESSION_BUS_ADDRESS
+ unset XDG_RUNTIME_DIR
+ test -x /etc/X11/Xsession
+ exec /etc/X11/Xsession
matt335672 commented 6 months ago

So far so good.

You should have more in /home/rmwin/.xsession-errors. Can you post that?

These may not be a good idea:-

+ unset DBUS_SESSION_BUS_ADDRESS
+ unset XDG_RUNTIME_DIR

They're coming from /home/cynteka/.profile. The variables themselves are set when you log on, and unsetting them may result in odd behaviour.

Sergiolisis commented 6 months ago

Any Ideas? trmsrv01 xrdp[22478]: [ERROR] VNC error 1 after security negotiation trmsrv01 xrdp[22478]: [ERROR] VNC error before sending share flag trmsrv01 xrdp[22478]: [ERROR] VNC error before receiving server init rmsrv01 xrdp[22478]: [ERROR] VNC error before receiving pixel format trmsrv01 xrdp[22478]: [ERROR] VNC error before receiving name length trmsrv01 xrdp[22478]: [ERROR] VNC error before receiving name trmsrv01 xrdp[22478]: [INFO ] VNC error - problem connecting trmsrv01 xrdp[22478]: [INFO ] some problem trmsrv01 xrdp[22478]: [ERROR] xrdp_wm_log_msg: Error connecting to user session rmsrv01 xrdp[22478]: [INFO ] Error connecting to user session

matt335672 commented 6 months ago

Your original logs above relate to an Xorg session and these are from a VNC session. Can we stick with the Xorg session for now and my question above?

Thanks.

alexbodn commented 6 months ago

Thanks @alexbodn

You say there are no errors in your xorgxrdp.10.log, so it's highly likely that your /etc/xrdp/startwm.sh invocation is failing.

Let's try tracing it through from the command line. What do you get for this command when logged in as rmwin? There's a space after DISPLAY= :-

DISPLAY= /bin/sh -x /etc/xrdp/startwm.sh

thank you very much for your help!

indeed this was my exact problem. i had a bash file with an .sh extension in /etc/profile.d. it was enough to change it's extension to .bash.

matt335672 commented 6 months ago

Sorry - I just realised that @Sergiolisis has tried to hijack this thread.

@alexbodn - please close this issue if you're sorted. @Sergiolisis - open your own thread if you need help. Your details are not relevant to this discussion, and are just confusing things. They certainly confused me!

alexbodn commented 6 months ago

Thank you very much for your help, @matt335672 . And a big thank for generally providing xrdp.