Server example: [failed to negotiate security protocol] general error

[allsey87]

Testing the server example from the latest release ironrdp-v0.7.3 against Remmina Remote Desktop Client (libfreerdp 3.10.3), I keep running into these errors while trying to connect:

     Running `target/debug/examples/server`
2025-01-28T14:45:15.333805Z ERROR ironrdp_server::server: Connection error error=accept_begin failed

Caused by:
    [failed to negotiate security protocol] general error
2025-01-28T14:45:15.338022Z ERROR ironrdp_server::server: Connection error error=accept_begin failed

Caused by:
    [failed to negotiate security protocol] general error

In Remmina, I set the host to 127.0.0.1 and leave the username/password at their default settings. In addition to these messages, the client fails to connect.

[elmarco]

The server uses "user"/"pass" as username and password by default. This mode is quite insecure, and thus not really well supported. Furthermore, it's not clear how to indicate to the client wrong credentials, and right now the connection is simply closed.

We may want to explore other options, better defaults, though.

[allsey87]

I did login with "user"/"pass" so I don't think the problem was caused by wrong credentials. Is there a known working configuration for the server example?

Here is a more complete trace of what happens when connecting with the default username and password:

$ IRONRDP_LOG="trace" cargo run --features="cliprdr rdpsnd server" --example server -- --bind-addr 0.0.0.0:3389
    Finished `dev` profile [optimized + debuginfo] target(s) in 0.91s
     Running `target/debug/examples/server --bind-addr '0.0.0.0:3389'`
2025-01-29T08:17:09.004043Z  INFO server: run bind_addr=0.0.0.0:3389 cert=None key=None
2025-01-29T08:17:09.008626Z DEBUG ironrdp_server::server: Changing credentials creds=Some(Credentials { username: "user", domain: None, .. })
2025-01-29T08:17:09.008722Z DEBUG ironrdp_server::server: Listening for connections on 0.0.0.0:3389
2025-01-29T08:17:33.696703Z DEBUG ironrdp_server::server: Received connection peer=127.0.0.1:41764
2025-01-29T08:17:33.696806Z DEBUG ironrdp_async::framed: Wait for PDU connector.state="InitiationWaitRequest" hint=X224Hint
2025-01-29T08:17:33.698821Z TRACE ironrdp_async::framed: PDU received length=42
2025-01-29T08:17:33.698856Z DEBUG ironrdp_acceptor::connection: Received ConnectionRequest { nego_data: Some(Cookie(Cookie("user"))), flags: RequestFlags(0x0), protocol: SecurityProtocol(SSL | HYBRID) }
2025-01-29T08:17:33.703704Z ERROR ironrdp_server::server: Connection error error=accept_begin failed

Caused by:
    [failed to negotiate security protocol] general error
2025-01-29T08:17:33.748746Z DEBUG ironrdp_server::server: Received connection peer=127.0.0.1:41774
2025-01-29T08:17:33.748934Z DEBUG ironrdp_async::framed: Wait for PDU connector.state="InitiationWaitRequest" hint=X224Hint
2025-01-29T08:17:33.749014Z TRACE ironrdp_async::framed: PDU received length=42
2025-01-29T08:17:33.749040Z DEBUG ironrdp_acceptor::connection: Received ConnectionRequest { nego_data: Some(Cookie(Cookie("user"))), flags: RequestFlags(0x0), protocol: SecurityProtocol(SSL | HYBRID) }
2025-01-29T08:17:33.749200Z ERROR ironrdp_server::server: Connection error error=accept_begin failed

Caused by:
    [failed to negotiate security protocol] general error

[elmarco]

It works on fc41(remmina-1.4.35-3.fc41.x86_64), and freerdp git. What version are you using? Maybe you could try enabling the client log?

[allsey87]

Ok, now we have something to work with! This is the output from running in the terminal which shows the errors from freerdp.

[13:01:56:740] [211051:0003386b] [ERROR][com.winpr.crypto.hash] - [winpr_Digest_Init_Internal]: Failed to initialize digest md4
[13:01:56:740] [211051:0003386b] [WARN][com.freerdp.core.rdp] - [log_build_warn_hash][0x5b5eac06d8e0]: *************************************************
[13:01:56:740] [211051:0003386b] [WARN][com.freerdp.core.rdp] - [log_build_warn_hash][0x5b5eac06d8e0]: [SSL] {Digest} build or configuration missing:
[13:01:56:740] [211051:0003386b] [WARN][com.freerdp.core.rdp] - [log_build_warn_hash][0x5b5eac06d8e0]:  * md4: NTLM support not available
[13:01:56:740] [211051:0003386b] [WARN][com.freerdp.core.rdp] - [log_build_warn_hash][0x5b5eac06d8e0]: *************************************************
[13:01:56:740] [211051:0003386b] [WARN][com.freerdp.core.rdp] - [log_build_warn_cipher][0x5b5eac06d8e0]: *************************************************
[13:01:56:740] [211051:0003386b] [WARN][com.freerdp.core.rdp] - [log_build_warn_cipher][0x5b5eac06d8e0]: [SSL] {Cipher} build or configuration missing:
[13:01:56:740] [211051:0003386b] [WARN][com.freerdp.core.rdp] - [log_build_warn_cipher][0x5b5eac06d8e0]: * rc4: assistance files with encrypted passwords, NTLM, RDP licensing and RDP security will not work
[13:01:56:740] [211051:0003386b] [WARN][com.freerdp.core.rdp] - [log_build_warn_cipher][0x5b5eac06d8e0]: *************************************************
[13:01:56:052] [211051:0003387c] [ERROR][com.freerdp.core.transport] - [transport_read_layer]: BIO_read returned a system error 11: Resource temporarily unavailable
[13:01:56:052] [211051:0003387c] [ERROR][com.freerdp.core] - [transport_read_layer]: ERRCONNECT_CONNECT_TRANSPORT_FAILED [0x0002000D]
[13:01:56:056] [211051:0003387c] [ERROR][com.freerdp.core.transport] - [transport_read_layer]: BIO_read returned a system error 11: Resource temporarily unavailable
[13:01:56:056] [211051:0003387c] [ERROR][com.freerdp.core] - [transport_read_layer]: ERRCONNECT_CONNECT_TRANSPORT_FAILED [0x0002000D]
[13:01:56:056] [211051:0003387c] [ERROR][com.freerdp.core] - [freerdp_connect]: freerdp_post_connect failed
libfreerdp returned code is 0002000D

Following the instructions in openssl/openssl#21247 (comment), I am able to re-enable the md4 cipher, however I still have these last couple errors:

[13:15:41:853] [211051:00033c9c] [ERROR][com.freerdp.core.transport] - [transport_read_layer]: BIO_read returned a system error 11: Resource temporarily unavailable
[13:15:41:853] [211051:00033c9c] [ERROR][com.freerdp.core] - [transport_read_layer]: ERRCONNECT_CONNECT_TRANSPORT_FAILED [0x0002000D]
[13:15:41:856] [211051:00033c9c] [ERROR][com.freerdp.core.transport] - [transport_read_layer]: BIO_read returned a system error 11: Resource temporarily unavailable
[13:15:41:856] [211051:00033c9c] [ERROR][com.freerdp.core] - [transport_read_layer]: ERRCONNECT_CONNECT_TRANSPORT_FAILED [0x0002000D]
[13:15:41:856] [211051:00033c9c] [ERROR][com.freerdp.core] - [freerdp_connect]: freerdp_post_connect failed
libfreerdp returned code is 0002000D

Remmina version: 1.4.39 (git n/a)
Librdpfree version: 3.10.3
OpenSSL version: 3.4.0

[allsey87]

On the server side, I also see very similar errors when connecting from the Windows 11 RDP client:

2025-01-29T12:24:52.718016Z  INFO server: run bind_addr=0.0.0.0:3389 cert=None key=None
2025-01-29T12:24:52.718056Z DEBUG ironrdp_server::server: Changing credentials creds=Some(Credentials { username: "user", domain: None, .. })
2025-01-29T12:24:52.718106Z DEBUG ironrdp_server::server: Listening for connections on 0.0.0.0:3389
2025-01-29T12:25:00.456002Z DEBUG ironrdp_server::server: Received connection peer=192.168.57.100:49703
2025-01-29T12:25:00.456104Z DEBUG ironrdp_async::framed: Wait for PDU connector.state="InitiationWaitRequest" hint=X224Hint
2025-01-29T12:25:00.456437Z TRACE ironrdp_async::framed: PDU received length=42
2025-01-29T12:25:00.456451Z DEBUG ironrdp_acceptor::connection: Received ConnectionRequest { nego_data: Some(Cookie(Cookie("user"))), flags: RequestFlags(0x0), protocol: SecurityProtocol(SSL | HYBRID | HYBRID_EX) }
2025-01-29T12:25:00.456540Z ERROR ironrdp_server::server: Connection error error=accept_begin failed

Caused by:
    [failed to negotiate security protocol] general error

The error on the Window client side is:

Error code: 0x904
Extended error code: 0x7

[allsey87]

@elmarco were you able to reproduce this issue with either Remina (1.4.39 with librdpfree 3.10.3) or the Windows 11 RDP client?