No callback if DTLS connection with OpenSSL server and client fails due to PSK mismatch

[anyc]

Hello,

I have a requirement that my CoAP server has to create log entries if a login/connection fails. I registered callbacks with coap_register_event_handler() and coap_register_nack_handler() but I only receive the regular "session closed" and "DTLS closed" events if I try to connect with a wrong PSK over DTLS:

Jun 22 12:56:38.417 DEBG ***[::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: session 0x48dc40: new incoming session
Jun 22 12:56:38.417 DEBG ***EVENT: COAP_EVENT_SERVER_SESSION_NEW
session [::ffff:192.168.178.36]:5684 <- [::ffff:192.168.178.130]:54440 created (0x48dc40 (nil))
Jun 22 12:56:38.417 DEBG *  [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: netif: recv   67 bytes
Jun 22 12:56:38.418 DEBG *  [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: netif: sent   60 bytes
Jun 22 12:56:38.418 DEBG *  [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: netif: recv   99 bytes
login SNI: ""
Jun 22 12:56:38.419 DEBG *  [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: netif: sent  152 bytes
Jun 22 12:56:38.420 DEBG *  [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: netif: recv   32 bytes
Jun 22 12:56:38.420 DEBG got psk_identity: 'admin'
login ID "admin" hint "" from [::ffff:192.168.178.130]:54440
Jun 22 12:56:38.421 DEBG *  [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: netif: recv   14 bytes
Jun 22 12:56:38.422 DEBG *  [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: netif: recv   53 bytes
Jun 22 12:56:39.419 DEBG ** [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: DTLS retransmit timeout

[...]

Jun 22 12:57:09.419 DEBG ** [::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: DTLS retransmit timeout
Jun 22 12:57:09.419 DEBG ***[::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: session disconnected (COAP_NACK_TLS_FAILED)
Jun 22 12:57:09.420 DEBG ***EVENT: COAP_EVENT_DTLS_CLOSED
dtls closed
Jun 22 12:57:09.420 DEBG ***EVENT: COAP_EVENT_SERVER_SESSION_DEL
session [::ffff:192.168.178.36]:5684 <- [::ffff:192.168.178.130]:54440 closed (0x48dc40 0x49f7a8)
Jun 22 12:57:09.420 DEBG ***[::ffff:192.168.178.36]:5684 <-> [::ffff:192.168.178.130]:54440 (if8) DTLS: session 0x48dc40: closed
Jun 22 12:57:40.419 DEBG coap_dtls_hello: ContentType 22 Handshake 16 dropped
Jun 22 12:57:40.419 DEBG coap_dtls_hello: ContentType 20 Handshake 1 dropped
Jun 22 12:57:40.419 DEBG coap_dtls_hello: ContentType 22 Handshake 0 dropped

Hence, I cannot distinguish if the connection was successful and willfully terminated or if there was any issue. Shouldn't COAP_NACK_TLS_FAILED also be reported to the nack callback here as it is logged by libcoap internally? The code I am using should print all callback calls like the "dtls closed" string.

According to https://github.com/openssl/openssl/issues/10906#issuecomment-578057628 it seems to be impossible to distinguish between a PSK mismatch and a corrupted packet and it is advised by the RFC to not send an error message to the client. So the client retries to connect for some time. I can live with that but I need to at least log such events on the server side if the connection failed and the client (or the server) eventually gave up.

I am using libcoap 4.3.4-1.1 on a ARMv7 Yocto/Poky Linux system with OpenSSL 3.0.13.

Thank you!

[mrdeep1]

See fix in #1384.

[mrdeep1]

@anyc Does #1384 work for you?

[anyc]

Yes, now the nack handler is called. Thank you!