redemption icon indicating copy to clipboard operation
redemption copied to clipboard

Published 20 hours ago • verified publisher icon wallix

7.2.23: unable to connect to any Windows 2008 R2 RDP

Open dtouzeau opened this issue 4 years ago • 2 comments

Hi,

I'm unable to connect to any Windows 2008 R2 server using 7.2.23

'RDP' failed at RDP_NEGO state. Fail during TLS security exchange

Is there a way to fix it ?

Aug 15 13:37:12 rdprx01 rdpproxy: [rdpproxy] psid="156586903227308" type="INCOMING_CONNECTION" src_ip="192.168.1.214" src_port="65534" Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- Redemption 7.2.23 Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- src=192.168.1.214 sport=65534 dst=192.168.1.19 dport=3389 Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- New session on 5 (pid=27308) from 192.168.1.214 to 192.168.1.19 Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- CR Recv: PROTOCOL TLS Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- CR Recv: PROTOCOL HYBRID Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- CR Recv: PROTOCOL HYBRID EX Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- -----------------> Front::incoming: TLS Support Enabled Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- CC Send: PROTOCOL TLS Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- SocketTransport::enable_server_tls() start Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- TLSContext::enable_server_tls() set SSL options Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- TLSContext::X509_get_pubkey() Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- TLSContext::i2d_PublicKey() Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- TLSContext::i2d_PublicKey() Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- Incoming connection to Bastion using TLS version TLSv1.2 Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- TLSContext::Negociated cipher used ECDHE-RSA-AES256-GCM-SHA384 Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- SocketTransport::enable_server_tls() done Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- partial_recv_tls error:00000005:lib(0):func(0):DH lib Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- got SIGPIPE(13) : ignoring Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- Failure in SSL library, error=5, Broken pipe [32] Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- partial_send_tls error:00000005:lib(0):func(0):DH lib Aug 15 13:37:12 rdprx01 rdpproxy: WARNING (27308/27308) -- SocketTransport::Send failed on RDP Client (5) errno=32 [Broken pipe] Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- Session::Session Init exception = Exception ERR_TRANSPORT_WRITE_FAILED no: 1502! Aug 15 13:37:12 rdprx01 rdpproxy: INFO (27308/27308) -- Session::Client Session Disconnected Aug 15 13:37:12 rdprx01 rdpproxy: [rdpproxy] psid="156586903227308" type="DISCONNECT" reason="Exception ERR_TRANSPORT_WRITE_FAILED no: 1502" Aug 15 13:37:14 rdprx01 rdpproxy: [rdpproxy] psid="156586903427309" type="INCOMING_CONNECTION" src_ip="192.168.1.214" src_port="49152" Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Redemption 7.2.23 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- src=192.168.1.214 sport=49152 dst=192.168.1.19 dport=3389 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- New session on 5 (pid=27309) from 192.168.1.214 to 192.168.1.19 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- CR Recv: PROTOCOL TLS Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- CR Recv: PROTOCOL HYBRID Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- CR Recv: PROTOCOL HYBRID EX Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- -----------------> Front::incoming: TLS Support Enabled Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- CC Send: PROTOCOL TLS Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- SocketTransport::enable_server_tls() start Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- TLSContext::enable_server_tls() set SSL options Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- TLSContext::X509_get_pubkey() Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- TLSContext::i2d_PublicKey() Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- TLSContext::i2d_PublicKey() Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Incoming connection to Bastion using TLS version TLSv1.2 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- TLSContext::Negociated cipher used ECDHE-RSA-AES256-GCM-SHA384 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- SocketTransport::enable_server_tls() done Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- GCC::UserData tag=c001 length=234 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- GCC::UserData tag=c004 length=12 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- GCC::UserData tag=c002 length=12 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- GCC::UserData tag=c003 length=56 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- GCC::UserData tag=c006 length=8 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- GCC::UserData tag=c00a length=8 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Front::incoming: TLS mode: exchange packet disabled Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Front::incoming: Secure Settings Exchange Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- RDP-5 Style logon Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Front::incoming: Keyboard Layout = 0x40c Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Front::incoming: ACTIVATED (new license request) Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Front::incoming: (Fast-Path) Synchronize Event toggleFlags=0x2 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Front::process_data: asking for selector Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- connecting to /var/run/rdpproxy/auth.sock Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- connection to /var/run/rdpproxy/auth.sock succeeded : socket 4 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::internal module 'Transition' loaded Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- ===========> MODULE_NEXT Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- ----------> ACL next_module <-------- Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- ===========> MODULE_INTERACTIVE_TARGET Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- ----------> ACL new_mod <-------- Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- target_module=MODULE_INTERNAL_TARGET(12) Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::Creation of internal module 'Interactive Target' Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::internal module 'Interactive Target' ready Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Front::incoming: (Fast-Path) Synchronize Event toggleFlags=0x2 Aug 15 13:37:14 rdprx01 rdpproxy: INFO (27309/27309) -- Front::incoming: (Fast-Path) Synchronize Event toggleFlags=0x2 Aug 15 13:37:19 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::internal module 'Transition' loaded Aug 15 13:37:19 rdprx01 rdpproxy: INFO (27309/27309) -- ===========> MODULE_NEXT Aug 15 13:37:19 rdprx01 rdpproxy: INFO (27309/27309) -- ----------> ACL next_module <-------- Aug 15 13:37:19 rdprx01 rdpproxy: INFO (27309/27309) -- ===============> MODULE_SELECTOR Aug 15 13:37:19 rdprx01 rdpproxy: INFO (27309/27309) -- ----------> ACL new_mod <-------- Aug 15 13:37:19 rdprx01 rdpproxy: INFO (27309/27309) -- target_module=MODULE_INTERNAL_WIDGET_SELECTOR(15) Aug 15 13:37:19 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::Creation of internal module 'selector' Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::internal module 'Transition' loaded Aug 15 13:37:21 rdprx01 rdpproxy: WARNING (27309/27309) -- parsing error with parameter 'mode_console' in section [context] for "deny": unknown value Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ===========> MODULE_NEXT Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ----------> ACL next_module <-------- Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ===========> MODULE_RDP Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ----------> ACL new_mod <-------- Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- target_module=MODULE_RDP(2) Aug 15 13:37:21 rdprx01 rdpproxy: WARNING (27309/27309) -- AclSerializer::start_session_log: failed to extract date Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::Creation of new mod 'RDP' Aug 15 13:37:21 rdprx01 rdpproxy: [rdpproxy] psid="156586903427309" user="Administrateur" type="TARGET_CONNECTION" target="Administrateur" host="192.168.1.46" port="3389" Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- connecting to 192.168.1.46:3389 Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- connection to 192.168.1.46:3389 (192.168.1.46) succeeded : socket 7 Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- Remote RDP Server domain="" login="Administrateur" host="DESKTOP-DTOUZEA" Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- RdpNego: TLS=Enabled NLA=Enabled adminMode=Disabled Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- Server key layout is 40c Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::Creation of new mod 'RDP' suceeded Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- RdpNego::NEGO_STATE_INITIAL Aug 15 13:37:21 rdprx01 rdpproxy: WARNING (27309/27309) -- parsing error with parameter 'mode_console' in section [context] for "deny": unknown value Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- RdpNego::NEGO_STATE_NLA Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- NEG_RSP_TYPE=2 NEG_RSP_FLAGS=9 NEG_RSP_LENGTH=8 NEG_RSP_SELECTED_PROTOCOL=2 Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- CC Recv: PROTOCOL HYBRID Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- activating TLS (HYBRID) Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- Client TLS start Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- SSL_connect() Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- RdpNego::recv_next_data::SslHybrid Aug 15 13:37:21 rdprx01 rdpproxy: ERR (27309/27309) -- TLSContext::enable_client_tls: I/O error Aug 15 13:37:21 rdprx01 rdpproxy: ERR (27309/27309) -- enable_client_tls fail Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- activating CREDSSP Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- Credssp: NTLM Authentication Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- Credssp TSCredentials::emit() Local Version 6 Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- got SIGPIPE(13) : ignoring Aug 15 13:37:21 rdprx01 rdpproxy: WARNING (27309/27309) -- SocketTransport::Send failed on RDP Target (7) errno=32 [Broken pipe] Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- NLA/CREDSSP NTLM Authentication Failed (1) Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- RdpNego::fallback_to_tls Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- connecting to 192.168.1.46:3389 Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- connection to 192.168.1.46:3389 (192.168.1.46) succeeded : socket 7 Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- Can't activate NLA Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- falling back to SSL only Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- RdpNego::NEGO_STATE_NLA Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- NEG_RSP_TYPE=2 NEG_RSP_FLAGS=9 NEG_RSP_LENGTH=8 NEG_RSP_SELECTED_PROTOCOL=1 Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- CC Recv: PROTOCOL TLS Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- activating TLS Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- Client TLS start Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- SSL_connect() Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- RdpNego::recv_next_data::TLS Aug 15 13:37:21 rdprx01 rdpproxy: ERR (27309/27309) -- TLSContext::enable_client_tls: I/O error Aug 15 13:37:21 rdprx01 rdpproxy: ERR (27309/27309) -- enable_client_tls fail Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- CS_Cluster: Server Redirection Supported Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- got SIGPIPE(13) : ignoring Aug 15 13:37:21 rdprx01 rdpproxy: WARNING (27309/27309) -- SocketTransport::Send failed on RDP Target (7) errno=32 [Broken pipe] Aug 15 13:37:21 rdprx01 rdpproxy: ERR (27309/27309) -- Creation of new mod 'RDP' failed at RDP_NEGO state. Fail during TLS security exchange. Aug 15 13:37:21 rdprx01 rdpproxy: ERR (27309/27309) -- Session::Session exception (2) = Unknown Backend Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ----------> ACL invoke_close_box <-------- Aug 15 13:37:21 rdprx01 rdpproxy: [RDP Session] session_id="2019-08-15-13-37:1-2-1" client_ip="192.168.1.214" target_ip="192.168.1.46" user="Administrateur" device="" service="" account="Administrateur" type="SESSION_DISCONNECTION" duration="0:00:00" Aug 15 13:37:21 rdprx01 rdpproxy: [rdpproxy] psid="156586903427309" user="Administrateur" type="TARGET_DISCONNECTION" reason="Unknown backend failure." Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ----------> ACL new_mod <-------- Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- target_module=MODULE_INTERNAL_CLOSE(5) Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::Creation of new mod 'INTERNAL::Close' Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- WabCloseMod: Ending session in 5 seconds Aug 15 13:37:21 rdprx01 rdpproxy: INFO (27309/27309) -- ModuleManager::internal module Close ready Aug 15 13:37:26 rdprx01 rdpproxy: INFO (27309/27309) -- Session::Client Session Disconnected Aug 15 13:37:26 rdprx01 rdpproxy: [rdpproxy] psid="156586903427309" type="DISCONNECT"

dtouzeau avatar Aug 15 '19 11:08 dtouzeau

Notice: Event error on windows server :

Une demande de connexion TLS 1.2 a été reçue à partir d’une application cliente distante, mais aucune des suites de chiffrement prises en charge par l’application cliente n’est prise en charge par le serveur. La demande de connexion SSL a échoué.

dtouzeau avatar Aug 15 '19 12:08 dtouzeau

This is probably fixed in future branch. The problem is related to TLS level between proxy and targets. Modern Linux are using stronger cipher algorithm than those allowed in old Windows 2008 Server. The server needs to get a connection policy argument from authentifier specifying Cipher_string=@SECLEVEL=1 or you can enable weaker TLS algorithms on proxy host in file /etc/ssl/openssl.conf

CipherString=@SECLEVEL=1

Tell me if it solves the problem.

pykoder avatar Nov 13 '19 10:11 pykoder