Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

7.2.23: unable to connect to any Windows 2008 R2 RDP #46

Open
dtouzeau opened this issue Aug 15, 2019 · 2 comments
Open

7.2.23: unable to connect to any Windows 2008 R2 RDP #46

dtouzeau opened this issue Aug 15, 2019 · 2 comments

Comments

@dtouzeau
Copy link

dtouzeau commented Aug 15, 2019

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
Copy link
Author

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é.

@pykoder
Copy link
Contributor

pykoder commented Nov 13, 2019

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants