DTLS PSK Handshake Failure on nRF9151 DK

[JOEBRE]

7762.wireshark_trace_clienthello_only_scsv.pcapng

Summary

We are trying to perform a DTLS 1.2 handshake using PSK (Pre-Shared Key)
from an **nRF9151 module running NCS v3.0.2, using modem-offloaded DTLS (IPPROTO_DTLS_1_2).

• LTE connects successfully
• PSK Identity + Key are provisioned to security tag 42
• The socket is configured with `TLS_SEC_TAG_LIST` and `TLS_PEER_VERIFY_NONE`
• DTLS handshake always fails with `errno = 111` (`ECONNREFUSED`)
• Wireshark trace shows the modem sends a DTLS ClientHello containing only: that means no usable cipher suites get advertised.

Expected Behavior

The client should send a DTLS ClientHello advertising PSK cipher suites such as:

• - `TLS_PSK_WITH_AES_128_CCM_8`
• - `TLS_PSK_WITH_AES_128_CCM`

And the server should reply with ServerHello → PSK Key Exchange.

This works correctly using:
 OpenSSL-based client  
 Go client (Pion/dtls)  
 Fails only with the nRF91 modem-based DTLS client

Actual Behavior

• Although PSK identity and key are provisioned correctly inside the modem, the ClientHello sent by the nRF9151 does not include any PSK cipher suite (e.g., TLS_PSK_WITH_AES_128_CCM_8). Instead, it offers only ECDHE-based certificate cipher suites followed by TLS_EMPTY_RENEGOTIATION_INFO_SCSV (0x00FF). As a result, the DTLS handshake fails with no shared cipher suite.
• Server (Go or OpenSSL) rejects handshake
• Client receives errno=111.

Files Included

| File | Description |
|------|-------------|
| `main.c` | Full C source used on nRF9151 |
| `prj.conf` | Project configuration |
| `wireshark_trace_clienthello_only_scsv.pcapng` | Modem trace export |
| `server_log.txt` | Output from Go/openssl servers (no shared cipher) |


Test with OpenSSL

> openssl s_server -dtls -accept 5684 -nocert -psk 73757065727365637265746b6579313233 -psk_identity device001 -cipher "PSK-AES128-CCM8:PSK-AES128-CCM:PSK-AES128-CBC-HA"
Returns:

Using default temp DH parameters
ACCEPT
ERROR
4057EA2E827B0000:error:0A0000C1:SSL routines:tls_post_process_client_hello:no shared cipher:../ssl/statem/statem_srvr.c:2220:
shutting down SSL
CONNECTION CLOSED

PSK Used

Identity: device001
Key: supersecretkey123
Confirmed stored under SEC_TAG=42.

Questions to Nordic

Why does modem DTLS not include PSK ciphers in ClientHello?

Is IPPROTO_DTLS_1_2 + TLS_SEC_TAG_LIST enough to enable PSK?

Do we need to explicitly set TLS_DTLS_VERSION, TLS_CIPHERSUITE_LIST, or something undocumented?

Is this a known issue in nRF9151 modem firmware v1.x?

Can you help me to get the DTLS handshake complete with success?

In the final product, the DTLS stuff must coexist with the LwM2M (which I already successfully tested 0m nRF9161 platform using Eclipse Leshan together with lwm2m client sample) one on nRF9151.

Thank you in advance for your support!

[Achim Kraus]

Cannot connect to LwM2M server with X509 DTLS. Wireshark shows empty client certificate.

That's the vice versa. It doesn't work, if certificate and PSK credentials are mixed into one sec_tag.

You may check, if that applies with

AT%CMNG=1,42

If that show's more than your PSK credentials, remove the others.

[JOEBRE]

Hello,  AT%%CMNG=1,42 returned:

42,3,"A4E05CEFA49CFFE2BB25E5E0793625C1199CB4ED83FF1B155BD6591EB043E9F1"

42,4,"54CCD4B043ECEC38BFB890596F7BD99FC8E6058517882A75F3BF37B9475972A1"

Which are the result of:

    modem_key_mgmt_write(SEC_TAG, MODEM_KEY_MGMT_CRED_TYPE_IDENTITY,

                         PSK_ID, strlen(PSK_ID));

    modem_key_mgmt_write(SEC_TAG, MODEM_KEY_MGMT_CRED_TYPE_PSK,

                         PSK_KEY, strlen(PSK_KEY));

So no other credentials than PSK ID and KEY. To be 100% sure the right stuff is injected into the modem now always delete all credentials for tag 42 and then re-enter them using modem_key_mgmt_write.

*** Booting nRF Connect SDK v3.0.2-89ba1294ac9b ***
*** Using Zephyr OS v4.0.99-f791c49f492c ***
[00:00:00.388,000] <inf> main: === LTE + DTLS Handshake Test ===
[00:00:00.388,000] <inf> main: Client PSK Key (ASCII) hex:
73 75 70 65 72 73 65 63 72 65 74 6B 65 79 31 32 33 
[00:00:00.388,336] <inf> main: Initializing modem...
[00:00:00.646,270] <inf> nrf_modem_lib_trace: Trace thread ready
[00:00:00.648,071] <inf> nrf_modem_lib_trace: Trace level override: 2
[00:00:00.792,694] <inf> main: Set CFUN to 0 to reset the SIM: OK

[00:00:03.031,860] <inf> main: Cleared credentials type 3 fotr Tag 42
[00:00:03.136,932] <inf> main: Cleared credentials type 4 fotr Tag 42
[00:00:03.260,986] <inf> main: Credentials of Tag 42 are wiped
[00:00:03.261,016] <inf> main: Provisioning  Tag 42 with new credentials
[00:00:03.474,914] <inf> main: New credentials for Tag 42 -> ID:1 PSK:1
[00:00:06.546,813] <inf> main: Connecting LTE...
+CEREG: 1,"057D","01017406",7,,,"00001111","00101101"
[00:00:07.181,976] main:  LTE connected!
[00:00:07.375,427] <inf> main: Connecting to GIMSServer.mooo.com (84.55.253.71):5684
[00:00:07.375,732] <inf> main: Performing DTLS handshake with GIMSServer.mooo.com:5684...
[00:00:07.527,954] main:  DTLS handshake failed, errno=111

Nothing changed I still get errno=111.

[JOEBRE]

mmm, I don't think the issue is the PSK. The handshake fails for both OpensSSL and the go server. To exclude entirely any issue related to the go server (I'll go back to it once I'm able to get a successful DTLS handshake) I switched to ssl_server2 demo server of mbed (build version: Mbed TLS 3.5.2). Since NRF is using mbed dtsl too, there shouldn't by any incompatibilities between client and sever. 

By running:./programs/ssl/ssl_server2 server_port=5685 dtls=1 psk=73757065727365637265746b6579 psk_identity=device001 force_ciphersuite=TLS-PSK-WITH-AES-128-CCM-8 debug_level=3

I get the following handshake error:

  . Seeding the random number generator... ok
  . Loading the CA root certificate ... ok (0 skipped)
  . Loading the server cert. and key... ok (key types: RSA, EC)
  . Setting up the SSL/TLS structure...ssl_tls.c:0111: |3| Disable use of CID extension.
ssl_msg.c:0291: |3| set_timer to 0 ms
 ok
  . Bind on udp://*:5685/ ... ok
ssl_msg.c:0291: |3| set_timer to 0 ms
ssl_msg.c:0291: |3| set_timer to 0 ms
  . Waiting for a remote connection ... ok
  . Performing the SSL/TLS handshake...ssl_tls.c:3919: |2| => handshake
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 0
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 1
ssl_tls12_server.c:0911: |2| => parse client hello
ssl_msg.c:2160: |2| => fetch input
ssl_msg.c:2206: |2| in_left: 0, nb_want: 5
ssl_msg.c:2245: |3| f_recv_timeout: 0 ms
ssl_msg.c:0323: |1| => mbedtls_ssl_check_record
ssl_msg.c:0324: |3| dumping 'record buffer' (136 bytes)
ssl_msg.c:0324: |3| 0000:  16 fe fd 00 00 00 00 00 00 00 00 00 7b 01 00 00  ............{...
ssl_msg.c:0324: |3| 0010:  6f 00 00 00 00 00 00 00 6f fe fd 69 12 dd 81 96  o.......o..i....
ssl_msg.c:0324: |3| 0020:  b8 ed a1 5d 89 18 8f d7 9b 16 93 3a 2e 0e df fa  ...].......:....
ssl_msg.c:0324: |3| 0030:  f2 22 76 9f ea 51 f2 10 84 52 98 00 00 00 0a 00  ."v..Q...R......
ssl_msg.c:0324: |3| 0040:  8d 00 ae 00 8c c0 a8 00 ff 01 00 00 3b 00 00 00  ............;...
ssl_msg.c:0324: |3| 0050:  18 00 16 00 00 13 47 49 4d 53 53 65 72 76 65 72  ......GIMSServer
ssl_msg.c:0324: |3| 0060:  2e 6d 6f 6f 6f 2e 63 6f 6d 00 0d 00 0e 00 0c 06  .mooo.com.......
ssl_msg.c:0324: |3| 0070:  03 06 01 05 03 05 01 04 03 04 01 00 36 00 09 08  ............6...
ssl_msg.c:0324: |3| 0080:  52 19 9a 7b 4d cb de 44                          R..{M..D
ssl_msg.c:3869: |3| input record: msgtype = 22, version = [0x303], msglen = 123
ssl_msg.c:0365: |1| <= mbedtls_ssl_check_record
ssl_msg.c:0323: |1| => mbedtls_ssl_check_record
ssl_msg.c:0324: |3| dumping 'record buffer' (136 bytes)
ssl_msg.c:0324: |3| 0000:  16 fe fd 00 00 00 00 00 00 00 00 00 7b 01 00 00  ............{...
ssl_msg.c:0324: |3| 0010:  6f 00 00 00 00 00 00 00 6f fe fd 69 12 dd 81 96  o.......o..i....
ssl_msg.c:0324: |3| 0020:  b8 ed a1 5d 89 18 8f d7 9b 16 93 3a 2e 0e df fa  ...].......:....
ssl_msg.c:0324: |3| 0030:  f2 22 76 9f ea 51 f2 10 84 52 98 00 00 00 0a 00  ."v..Q...R......
ssl_msg.c:0324: |3| 0040:  8d 00 ae 00 8c c0 a8 00 ff 01 00 00 3b 00 00 00  ............;...
ssl_msg.c:0324: |3| 0050:  18 00 16 00 00 13 47 49 4d 53 53 65 72 76 65 72  ......GIMSServer
ssl_msg.c:0324: |3| 0060:  2e 6d 6f 6f 6f 2e 63 6f 6d 00 0d 00 0e 00 0c 06  .mooo.com.......
ssl_msg.c:0324: |3| 0070:  03 06 01 05 03 05 01 04 03 04 01 00 36 00 09 08  ............6...
ssl_msg.c:0324: |3| 0080:  52 19 9a 7b 4d cb de 44                          R..{M..D
ssl_msg.c:3869: |3| input record: msgtype = 22, version = [0x303], msglen = 123
ssl_msg.c:0365: |1| <= mbedtls_ssl_check_record
ssl_msg.c:2254: |2| ssl->f_recv(_timeout)() returned 136 (-0xffffff78)
ssl_msg.c:2345: |2| <= fetch input
ssl_tls12_server.c:0951: |3| client hello, message type: 22
ssl_tls12_server.c:0959: |3| client hello, message len.: 123
ssl_tls12_server.c:0962: |3| client hello, protocol version: [254:253]
ssl_msg.c:2160: |2| => fetch input
ssl_msg.c:2206: |2| in_left: 136, nb_want: 136
ssl_msg.c:2214: |2| <= fetch input
ssl_tls12_server.c:1052: |3| client hello v3, handshake type: 1
ssl_tls12_server.c:1060: |3| client hello v3, handshake len.: 111
ssl_tls12_server.c:1159: |3| dumping 'client hello, version' (2 bytes)
ssl_tls12_server.c:1159: |3| 0000:  fe fd                                            ..
ssl_tls12_server.c:1175: |3| dumping 'client hello, random bytes' (32 bytes)
ssl_tls12_server.c:1175: |3| 0000:  69 12 dd 81 96 b8 ed a1 5d 89 18 8f d7 9b 16 93  i.......].......
ssl_tls12_server.c:1175: |3| 0010:  3a 2e 0e df fa f2 22 76 9f ea 51 f2 10 84 52 98  :....."v..Q...R.
ssl_tls12_server.c:1192: |3| dumping 'client hello, session id' (0 bytes)
ssl_tls12_server.c:1215: |3| dumping 'client hello, cookie' (0 bytes)
ssl_tls12_server.c:1227: |2| cookie verification failed
ssl_tls12_server.c:1266: |3| dumping 'client hello, ciphersuitelist' (10 bytes)
ssl_tls12_server.c:1266: |3| 0000:  00 8d 00 ae 00 8c c0 a8 00 ff                    ..........
ssl_tls12_server.c:1288: |3| dumping 'client hello, compression' (1 bytes)
ssl_tls12_server.c:1288: |3| 0000:  00                                               .
ssl_tls12_server.c:1317: |3| dumping 'client hello extensions' (59 bytes)
ssl_tls12_server.c:1317: |3| 0000:  00 00 00 18 00 16 00 00 13 47 49 4d 53 53 65 72  .........GIMSSer
ssl_tls12_server.c:1317: |3| 0010:  76 65 72 2e 6d 6f 6f 6f 2e 63 6f 6d 00 0d 00 0e  ver.mooo.com....
ssl_tls12_server.c:1317: |3| 0020:  00 0c 06 03 06 01 05 03 05 01 04 03 04 01 00 36  ...............6
ssl_tls12_server.c:1317: |3| 0030:  00 09 08 52 19 9a 7b 4d cb de 44                 ...R..{M..D
ssl_tls12_server.c:1340: |3| found ServerName extension
ssl_tls.c:9366: |3| parse ServerName extension
ssl_tls12_server.c:1363: |3| found signature_algorithms extension
ssl_tls12_server.c:1423: |3| found CID extension
ssl_tls12_server.c:0400: |3| Client sent CID extension, but CID disabled
ssl_tls12_server.c:1531: |3| received TLS_EMPTY_RENEGOTIATION_INFO 
ssl_tls12_server.c:0810: |3| trying ciphersuite: 0xc0a8 (TLS-PSK-WITH-AES-128-CCM-8)
ssl_tls12_server.c:1655: |2| selected ciphersuite: TLS-PSK-WITH-AES-128-CCM-8
ssl_msg.c:0291: |3| set_timer to 0 ms
ssl_tls12_server.c:1678: |3| no hash algorithm for signature algorithm 0 - should not happen
ssl_tls12_server.c:1683: |2| <= parse client hello
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 2
ssl_tls12_server.c:2170: |2| => write server hello
ssl_tls12_server.c:2175: |2| client hello was not authenticated
ssl_tls12_server.c:2176: |2| <= write server hello
ssl_tls12_server.c:2049: |2| => write hello verify request
ssl_tls12_server.c:2061: |3| dumping 'server version' (2 bytes)
ssl_tls12_server.c:2061: |3| 0000:  fe fd                                            ..
ssl_tls12_server.c:2082: |3| dumping 'cookie sent' (32 bytes)
ssl_tls12_server.c:2082: |3| 0000:  69 12 dd 82 b9 71 3b a1 84 06 5e f0 98 5f 85 bf  i....q;...^.._..
ssl_tls12_server.c:2082: |3| 0010:  c8 37 61 20 9d e9 ff 58 7e d8 15 9b cb ad 5f 53  .7a ...X~....._S
ssl_msg.c:2788: |2| => write handshake message
ssl_msg.c:2422: |2| => ssl_flight_append
ssl_msg.c:2457: |2| <= ssl_flight_append
ssl_msg.c:2909: |2| <= write handshake message
ssl_msg.c:2539: |2| => mbedtls_ssl_flight_transmit
ssl_msg.c:2542: |2| initialise flight transmission
ssl_msg.c:2489: |3| skip swap epochs
ssl_msg.c:2643: |3| dumping 'handshake header' (12 bytes)
ssl_msg.c:2643: |3| 0000:  03 00 00 23 00 00 00 00 00 00 00 23              ...#.......#
ssl_msg.c:2948: |2| => write record
ssl_msg.c:3032: |3| output record: msgtype = 22, version = [254:253], msglen = 47
ssl_msg.c:3072: |2| Still 16324 bytes available in current datagram
ssl_msg.c:3085: |2| <= write record
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2372: |2| message length: 60, out_left: 60
ssl_msg.c:2379: |2| ssl->f_send() returned 60 (-0xffffffc4)
ssl_msg.c:2406: |2| <= flush output
ssl_msg.c:0291: |3| set_timer to 0 ms
ssl_msg.c:2684: |2| <= mbedtls_ssl_flight_transmit
ssl_tls12_server.c:2103: |2| <= write hello verify request
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 17
ssl_tls.c:3930: |2| <= handshake
 hello verification requested
ssl_msg.c:0291: |3| set_timer to 0 ms
ssl_msg.c:0291: |3| set_timer to 0 ms
  . Waiting for a remote connection ... ok
  . Performing the SSL/TLS handshake...ssl_tls.c:3919: |2| => handshake
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 0
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 1
ssl_tls12_server.c:0911: |2| => parse client hello
ssl_msg.c:2160: |2| => fetch input
ssl_msg.c:2206: |2| in_left: 0, nb_want: 5
ssl_msg.c:2245: |3| f_recv_timeout: 0 ms
ssl_msg.c:0323: |1| => mbedtls_ssl_check_record
ssl_msg.c:0324: |3| dumping 'record buffer' (168 bytes)
ssl_msg.c:0324: |3| 0000:  16 fe fd 00 00 00 00 00 00 00 01 00 9b 01 00 00  ................
ssl_msg.c:0324: |3| 0010:  8f 00 01 00 00 00 00 00 8f fe fd 69 12 dd 81 96  ...........i....
ssl_msg.c:0324: |3| 0020:  b8 ed a1 5d 89 18 8f d7 9b 16 93 3a 2e 0e df fa  ...].......:....
ssl_msg.c:0324: |3| 0030:  f2 22 76 9f ea 51 f2 10 84 52 98 00 20 69 12 dd  ."v..Q...R.. i..
ssl_msg.c:0324: |3| 0040:  82 b9 71 3b a1 84 06 5e f0 98 5f 85 bf c8 37 61  ..q;...^.._...7a
ssl_msg.c:0324: |3| 0050:  20 9d e9 ff 58 7e d8 15 9b cb ad 5f 53 00 0a 00   ...X~....._S...
ssl_msg.c:0324: |3| 0060:  8d 00 ae 00 8c c0 a8 00 ff 01 00 00 3b 00 00 00  ............;...
ssl_msg.c:0324: |3| 0070:  18 00 16 00 00 13 47 49 4d 53 53 65 72 76 65 72  ......GIMSServer
ssl_msg.c:0324: |3| 0080:  2e 6d 6f 6f 6f 2e 63 6f 6d 00 0d 00 0e 00 0c 06  .mooo.com.......
ssl_msg.c:0324: |3| 0090:  03 06 01 05 03 05 01 04 03 04 01 00 36 00 09 08  ............6...
ssl_msg.c:0324: |3| 00a0:  52 19 9a 7b 4d cb de 44                          R..{M..D
ssl_msg.c:3869: |3| input record: msgtype = 22, version = [0x303], msglen = 155
ssl_msg.c:0365: |1| <= mbedtls_ssl_check_record
ssl_msg.c:0323: |1| => mbedtls_ssl_check_record
ssl_msg.c:0324: |3| dumping 'record buffer' (168 bytes)
ssl_msg.c:0324: |3| 0000:  16 fe fd 00 00 00 00 00 00 00 01 00 9b 01 00 00  ................
ssl_msg.c:0324: |3| 0010:  8f 00 01 00 00 00 00 00 8f fe fd 69 12 dd 81 96  ...........i....
ssl_msg.c:0324: |3| 0020:  b8 ed a1 5d 89 18 8f d7 9b 16 93 3a 2e 0e df fa  ...].......:....
ssl_msg.c:0324: |3| 0030:  f2 22 76 9f ea 51 f2 10 84 52 98 00 20 69 12 dd  ."v..Q...R.. i..
ssl_msg.c:0324: |3| 0040:  82 b9 71 3b a1 84 06 5e f0 98 5f 85 bf c8 37 61  ..q;...^.._...7a
ssl_msg.c:0324: |3| 0050:  20 9d e9 ff 58 7e d8 15 9b cb ad 5f 53 00 0a 00   ...X~....._S...
ssl_msg.c:0324: |3| 0060:  8d 00 ae 00 8c c0 a8 00 ff 01 00 00 3b 00 00 00  ............;...
ssl_msg.c:0324: |3| 0070:  18 00 16 00 00 13 47 49 4d 53 53 65 72 76 65 72  ......GIMSServer
ssl_msg.c:0324: |3| 0080:  2e 6d 6f 6f 6f 2e 63 6f 6d 00 0d 00 0e 00 0c 06  .mooo.com.......
ssl_msg.c:0324: |3| 0090:  03 06 01 05 03 05 01 04 03 04 01 00 36 00 09 08  ............6...
ssl_msg.c:0324: |3| 00a0:  52 19 9a 7b 4d cb de 44                          R..{M..D
ssl_msg.c:3869: |3| input record: msgtype = 22, version = [0x303], msglen = 155
ssl_msg.c:0365: |1| <= mbedtls_ssl_check_record
ssl_msg.c:2254: |2| ssl->f_recv(_timeout)() returned 168 (-0xffffff58)
ssl_msg.c:2345: |2| <= fetch input
ssl_tls12_server.c:0951: |3| client hello, message type: 22
ssl_tls12_server.c:0959: |3| client hello, message len.: 155
ssl_tls12_server.c:0962: |3| client hello, protocol version: [254:253]
ssl_msg.c:2160: |2| => fetch input
ssl_msg.c:2206: |2| in_left: 168, nb_want: 168
ssl_msg.c:2214: |2| <= fetch input
ssl_tls12_server.c:1052: |3| client hello v3, handshake type: 1
ssl_tls12_server.c:1060: |3| client hello v3, handshake len.: 143
ssl_tls12_server.c:1159: |3| dumping 'client hello, version' (2 bytes)
ssl_tls12_server.c:1159: |3| 0000:  fe fd                                            ..
ssl_tls12_server.c:1175: |3| dumping 'client hello, random bytes' (32 bytes)
ssl_tls12_server.c:1175: |3| 0000:  69 12 dd 81 96 b8 ed a1 5d 89 18 8f d7 9b 16 93  i.......].......
ssl_tls12_server.c:1175: |3| 0010:  3a 2e 0e df fa f2 22 76 9f ea 51 f2 10 84 52 98  :....."v..Q...R.
ssl_tls12_server.c:1192: |3| dumping 'client hello, session id' (0 bytes)
ssl_tls12_server.c:1215: |3| dumping 'client hello, cookie' (32 bytes)
ssl_tls12_server.c:1215: |3| 0000:  69 12 dd 82 b9 71 3b a1 84 06 5e f0 98 5f 85 bf  i....q;...^.._..
ssl_tls12_server.c:1215: |3| 0010:  c8 37 61 20 9d e9 ff 58 7e d8 15 9b cb ad 5f 53  .7a ...X~....._S
ssl_tls12_server.c:1230: |2| cookie verification passed
ssl_tls12_server.c:1266: |3| dumping 'client hello, ciphersuitelist' (10 bytes)
ssl_tls12_server.c:1266: |3| 0000:  00 8d 00 ae 00 8c c0 a8 00 ff                    ..........
ssl_tls12_server.c:1288: |3| dumping 'client hello, compression' (1 bytes)
ssl_tls12_server.c:1288: |3| 0000:  00                                               .
ssl_tls12_server.c:1317: |3| dumping 'client hello extensions' (59 bytes)
ssl_tls12_server.c:1317: |3| 0000:  00 00 00 18 00 16 00 00 13 47 49 4d 53 53 65 72  .........GIMSSer
ssl_tls12_server.c:1317: |3| 0010:  76 65 72 2e 6d 6f 6f 6f 2e 63 6f 6d 00 0d 00 0e  ver.mooo.com....
ssl_tls12_server.c:1317: |3| 0020:  00 0c 06 03 06 01 05 03 05 01 04 03 04 01 00 36  ...............6
ssl_tls12_server.c:1317: |3| 0030:  00 09 08 52 19 9a 7b 4d cb de 44                 ...R..{M..D
ssl_tls12_server.c:1340: |3| found ServerName extension
ssl_tls.c:9366: |3| parse ServerName extension
ssl_tls12_server.c:1363: |3| found signature_algorithms extension
ssl_tls12_server.c:1423: |3| found CID extension
ssl_tls12_server.c:0400: |3| Client sent CID extension, but CID disabled
ssl_tls12_server.c:1531: |3| received TLS_EMPTY_RENEGOTIATION_INFO 
ssl_tls12_server.c:0810: |3| trying ciphersuite: 0xc0a8 (TLS-PSK-WITH-AES-128-CCM-8)
ssl_tls12_server.c:1655: |2| selected ciphersuite: TLS-PSK-WITH-AES-128-CCM-8
ssl_msg.c:0291: |3| set_timer to 0 ms
ssl_tls12_server.c:1678: |3| no hash algorithm for signature algorithm 0 - should not happen
ssl_tls12_server.c:1683: |2| <= parse client hello
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 2
ssl_tls12_server.c:2170: |2| => write server hello
ssl_tls12_server.c:2200: |3| server hello, chosen version: [254:253]
ssl_tls12_server.c:2208: |3| server hello, current time: 1762844034
ssl_tls12_server.c:2252: |3| dumping 'server hello, random bytes' (32 bytes)
ssl_tls12_server.c:2252: |3| 0000:  69 12 dd 82 bf 92 35 b2 b4 bd ab 2e 69 06 a0 48  i.....5.....i..H
ssl_tls12_server.c:2252: |3| 0010:  2a d0 47 d7 72 e4 f9 7c 93 f7 45 24 91 1c a9 bb  *.G.r..|..E$....
ssl_tls12_server.c:2305: |3| server hello, session id len.: 32
ssl_tls12_server.c:2306: |3| dumping 'server hello, session id' (32 bytes)
ssl_tls12_server.c:2306: |3| 0000:  20 37 d6 6a db 86 1a 91 05 8e f3 91 92 28 19 ac   7.j.........(..
ssl_tls12_server.c:2306: |3| 0010:  f4 b9 33 03 9e 8d 52 ec 1f a9 3e 4b f8 9c df 9d  ..3...R...>K....
ssl_tls12_server.c:2307: |3| no session has been resumed
ssl_tls12_server.c:2314: |3| server hello, chosen ciphersuite: TLS-PSK-WITH-AES-128-CCM-8
ssl_tls12_server.c:2316: |3| server hello, compress alg.: 0x00
ssl_tls12_server.c:1838: |3| server hello, secure renegotiation extension
ssl_tls12_server.c:2381: |3| server hello, total extension length: 5
ssl_msg.c:2788: |2| => write handshake message
ssl_msg.c:2422: |2| => ssl_flight_append
ssl_msg.c:2457: |2| <= ssl_flight_append
ssl_msg.c:2909: |2| <= write handshake message
ssl_tls12_server.c:2395: |2| <= write server hello
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 3
ssl_tls.c:6915: |2| => write certificate
ssl_tls.c:6918: |2| <= skip write certificate
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 4
ssl_tls12_server.c:3223: |2| => write server key exchange
ssl_tls12_server.c:3243: |2| <= skip write server key exchange
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 5
ssl_tls12_server.c:2432: |2| => write certificate request
ssl_tls12_server.c:2445: |2| <= skip write certificate request
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 6
ssl_tls12_server.c:3314: |2| => write server hello done
ssl_msg.c:0518: |3| update timeout value to 1000 millisecs
ssl_msg.c:0291: |3| set_timer to 1000 ms
ssl_msg.c:2788: |2| => write handshake message
ssl_msg.c:2422: |2| => ssl_flight_append
ssl_msg.c:2457: |2| <= ssl_flight_append
ssl_msg.c:2909: |2| <= write handshake message
ssl_msg.c:2539: |2| => mbedtls_ssl_flight_transmit
ssl_msg.c:2542: |2| initialise flight transmission
ssl_msg.c:2489: |3| skip swap epochs
ssl_msg.c:2643: |3| dumping 'handshake header' (12 bytes)
ssl_msg.c:2643: |3| 0000:  02 00 00 4d 00 01 00 00 00 00 00 4d              ...M.......M
ssl_msg.c:2948: |2| => write record
ssl_msg.c:3032: |3| output record: msgtype = 22, version = [254:253], msglen = 89
ssl_msg.c:3072: |2| Still 16282 bytes available in current datagram
ssl_msg.c:3085: |2| <= write record
ssl_msg.c:2643: |3| dumping 'handshake header' (12 bytes)
ssl_msg.c:2643: |3| 0000:  0e 00 00 00 00 02 00 00 00 00 00 00              ............
ssl_msg.c:2948: |2| => write record
ssl_msg.c:3032: |3| output record: msgtype = 22, version = [254:253], msglen = 12
ssl_msg.c:3072: |2| Still 16257 bytes available in current datagram
ssl_msg.c:3085: |2| <= write record
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2372: |2| message length: 25, out_left: 127
ssl_msg.c:2379: |2| ssl->f_send() returned 127 (-0xffffff81)
ssl_msg.c:2406: |2| <= flush output
ssl_msg.c:0291: |3| set_timer to 1000 ms
ssl_msg.c:2684: |2| <= mbedtls_ssl_flight_transmit
ssl_tls12_server.c:3341: |2| <= write server hello done
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 7
ssl_tls.c:7510: |2| => parse certificate
ssl_tls.c:7514: |2| <= skip parse certificate
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 8
ssl_tls12_server.c:3639: |2| => parse client key exchange
ssl_msg.c:4122: |2| => read record
ssl_msg.c:4221: |2| => ssl_load_buffered_message
ssl_msg.c:4289: |2| Next handshake message 2 not or only partially bufffered
ssl_msg.c:4297: |2| <= ssl_load_buffered_message
ssl_msg.c:2160: |2| => fetch input
ssl_msg.c:2206: |2| in_left: 0, nb_want: 13
ssl_msg.c:2245: |3| f_recv_timeout: 1000 ms
ssl_msg.c:0323: |1| => mbedtls_ssl_check_record
ssl_msg.c:0324: |3| dumping 'record buffer' (103 bytes)
ssl_msg.c:0324: |3| 0000:  16 fe fd 00 00 00 00 00 00 00 02 00 17 10 00 00  ................
ssl_msg.c:0324: |3| 0010:  0b 00 02 00 00 00 00 00 0b 00 09 64 65 76 69 63  ...........devic
ssl_msg.c:0324: |3| 0020:  65 30 30 31 14 fe fd 00 00 00 00 00 00 00 03 00  e001............
ssl_msg.c:0324: |3| 0030:  01 01 16 fe fd 00 01 00 00 00 00 00 00 00 28 00  ..............(.
ssl_msg.c:0324: |3| 0040:  01 00 00 00 00 00 00 05 9a 4a 52 25 26 c4 df 9f  .........JR%&...
ssl_msg.c:0324: |3| 0050:  f9 f1 8e db 0e d3 17 c4 25 b4 23 fd 80 6c 1b ad  ........%.#..l..
ssl_msg.c:0324: |3| 0060:  be d3 c1 20 60 f8 72                             ... `.r
ssl_msg.c:3869: |3| input record: msgtype = 22, version = [0x303], msglen = 23
ssl_msg.c:0365: |1| <= mbedtls_ssl_check_record
ssl_msg.c:0323: |1| => mbedtls_ssl_check_record
ssl_msg.c:0324: |3| dumping 'record buffer' (103 bytes)
ssl_msg.c:0324: |3| 0000:  16 fe fd 00 00 00 00 00 00 00 02 00 17 10 00 00  ................
ssl_msg.c:0324: |3| 0010:  0b 00 02 00 00 00 00 00 0b 00 09 64 65 76 69 63  ...........devic
ssl_msg.c:0324: |3| 0020:  65 30 30 31 14 fe fd 00 00 00 00 00 00 00 03 00  e001............
ssl_msg.c:0324: |3| 0030:  01 01 16 fe fd 00 01 00 00 00 00 00 00 00 28 00  ..............(.
ssl_msg.c:0324: |3| 0040:  01 00 00 00 00 00 00 05 9a 4a 52 25 26 c4 df 9f  .........JR%&...
ssl_msg.c:0324: |3| 0050:  f9 f1 8e db 0e d3 17 c4 25 b4 23 fd 80 6c 1b ad  ........%.#..l..
ssl_msg.c:0324: |3| 0060:  be d3 c1 20 60 f8 72                             ... `.r
ssl_msg.c:3869: |3| input record: msgtype = 22, version = [0x303], msglen = 23
ssl_msg.c:0365: |1| <= mbedtls_ssl_check_record
ssl_msg.c:2254: |2| ssl->f_recv(_timeout)() returned 103 (-0xffffff99)
ssl_msg.c:2345: |2| <= fetch input
ssl_msg.c:3869: |3| input record: msgtype = 22, version = [0x303], msglen = 23
ssl_msg.c:4864: |3| more than one record within datagram
ssl_msg.c:3242: |3| handshake message: msglen = 23, type = 16, hslen = 23
ssl_msg.c:4194: |2| <= read record
ssl_tls.c:6529: |2| => derive keys
ssl_tls.c:6512: |3| dumping 'premaster secret' (32 bytes)
ssl_tls.c:6512: |3| 0000:  00 0e 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
ssl_tls.c:6512: |3| 0010:  00 0e 73 75 70 65 72 73 65 63 72 65 74 6b 65 79  ..supersecretkey
ssl_tls.c:8261: |3| ciphersuite = TLS-PSK-WITH-AES-128-CCM-8
ssl_tls.c:8263: |3| dumping 'master secret' (48 bytes)
ssl_tls.c:8263: |3| 0000:  0b ce c4 61 32 c1 20 11 77 92 bd 3c e0 9b a0 de  ...a2. .w..<....
ssl_tls.c:8263: |3| 0010:  84 38 44 08 ee 85 16 a2 ea af 1a 88 4d 8b 79 84  .8D.........M.y.
ssl_tls.c:8263: |3| 0020:  ce b2 dc d3 a2 35 99 0d 9f ce 2f de 76 76 12 0f  .....5..../.vv..
ssl_tls.c:8385: |3| keylen: 16, minlen: 16, ivlen: 12, maclen: 0
ssl_tls.c:6580: |2| <= derive keys
ssl_tls12_server.c:4046: |2| <= parse client key exchange
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 9
ssl_tls12_server.c:4084: |2| => parse certificate verify
ssl_tls12_server.c:4087: |2| <= skip parse certificate verify
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 10
ssl_msg.c:5146: |2| => parse change cipher spec
ssl_msg.c:4122: |2| => read record
ssl_msg.c:2160: |2| => fetch input
ssl_msg.c:2195: |2| next record in same datagram, offset: 36
ssl_msg.c:2206: |2| in_left: 67, nb_want: 13
ssl_msg.c:2214: |2| <= fetch input
ssl_msg.c:3869: |3| input record: msgtype = 20, version = [0x303], msglen = 1
ssl_msg.c:4864: |3| more than one record within datagram
ssl_msg.c:4194: |2| <= read record
ssl_msg.c:5167: |3| switching to new transform spec for inbound data
ssl_msg.c:5194: |2| <= parse change cipher spec
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2367: |2| <= flush output
ssl_tls12_server.c:4290: |2| server state: 11
ssl_tls.c:7968: |2| => parse finished
ssl_tls.c:7688: |2| => calc finished tls
ssl_tls.c:7715: |3| dumping 'calc finished result' (12 bytes)
ssl_tls.c:7715: |3| 0000:  d0 ab 43 85 e8 fd 77 27 02 ed da 9b              ..C...w'....
ssl_tls.c:7719: |2| <= calc finished
ssl_msg.c:4122: |2| => read record
ssl_msg.c:2160: |2| => fetch input
ssl_msg.c:2195: |2| next record in same datagram, offset: 14
ssl_msg.c:2206: |2| in_left: 53, nb_want: 13
ssl_msg.c:2214: |2| <= fetch input
ssl_msg.c:3869: |3| input record: msgtype = 22, version = [0x303], msglen = 40
ssl_msg.c:1514: |2| => decrypt buf
ssl_msg.c:1650: |1| mbedtls_cipher_auth_decrypt_ext() returned -25344 (-0x6300)
ssl_msg.c:3998: |1| ssl_decrypt_buf() returned -29056 (-0x7180)
ssl_msg.c:5103: |2| => send alert message
ssl_msg.c:5104: |3| send alert level=2 message=20
ssl_msg.c:2948: |2| => write record
ssl_msg.c:3032: |3| output record: msgtype = 21, version = [254:253], msglen = 2
ssl_msg.c:2358: |2| => flush output
ssl_msg.c:2372: |2| message length: 15, out_left: 15
ssl_msg.c:2379: |2| ssl->f_send() returned 15 (-0xfffffff1)
ssl_msg.c:2406: |2| <= flush output
ssl_msg.c:3085: |2| <= write record
ssl_msg.c:5115: |2| <= send alert message
ssl_msg.c:4153: |1| ssl_get_next_record() returned -29056 (-0x7180)
ssl_tls.c:7976: |1| mbedtls_ssl_read_record() returned -29056 (-0x7180)
ssl_tls.c:3930: |2| <= handshake
 failed
  ! mbedtls_ssl_handshake returned -0x7180

Last error was: -29056 - SSL - Verification of the message MAC failed

Things seems to work till the end when I get the:

Last error was: -29056 - SSL - Verification of the message MAC failed

error.

Wireshark says:

No.	Time	Source	Destination	Protocol	Length	Info
102	10.196838			LTE RRC BCCH_BCH	28	MasterInformationBlock (SFN=228)
103	10.210754			LTE RRC DL_SCH	117	SystemInformationBlockType1
104	10.266845			LTE RRC DL_SCH	103	SystemInformation [ SIB2 ]
105	10.271911			NAS-EPS	118	Attach request, PDN connectivity request
106	10.274200			LTE RRC UL_CCCH	30	RRCConnectionRequest
107	10.313049			LTE RRC DL_CCCH	74	RRCConnectionSetup
108	10.314422			LTE RRC UL_DCCH/NAS-EPS	137	RRCConnectionSetupComplete, Attach request, PDN connectivity request
109	10.906128			LTE RRC DL_DCCH	27	SecurityModeCommand
110	10.908020			LTE RRC UL_DCCH	26	SecurityModeComplete
111	11.015106			LTE RRC DL_DCCH	55	UECapabilityEnquiry
112	11.016967			LTE RRC UL_DCCH	150	UECapabilityInformation
113	11.126342			LTE RRC DL_DCCH/NAS-EPS	260	RRCConnectionReconfiguration, Ciphered message
114	11.128082			LTE RRC UL_DCCH	26	RRCConnectionReconfigurationComplete
115	11.128540			NAS-EPS	189	Ciphered message, Attach accept, Activate default EPS bearer context request (PDN type IPv4 only allowed)
116	11.129516			NAS-EPS	23	Attach complete, Activate default EPS bearer context accept
117	11.129699			LTE RRC UL_DCCH/NAS-EPS	40	ULInformationTransfer, Ciphered message
118	11.186157			LTE RRC DL_DCCH/NAS-EPS	54	DLInformationTransfer, Ciphered message
119	11.186279			NAS-EPS	43	Ciphered message, EMM information
120	11.246154			LTE RRC DL_DCCH	37	RRCConnectionReconfiguration
121	11.246917			LTE RRC UL_DCCH	26	RRCConnectionReconfigurationComplete
122	11.728393			AT	21	Sent AT Command: AT+CEREG?
123	11.728576			AT	49	Rcvd AT Command: +CEREG: 0,1,"057D","01017406",7  OK  
124	11.729248	10.52.31.125	193.5.23.8	DNS	77	Standard query 0x2d90 A GIMSServer.mooo.com
125	11.935974	193.5.23.8	10.52.31.125	DNS	93	Standard query response 0x2d90 A GIMSServer.mooo.com A 84.55.253.71
126	11.941436	10.52.31.125	84.55.253.71	DTLS	176	Client Hello (SNI=GIMSServer.mooo.com)
127	12.042328	84.55.253.71	10.52.31.125	DTLSv1.2	100	Hello Verify Request
128	12.043243	10.52.31.125	84.55.253.71	DTLSv1.2	208	Client Hello (SNI=GIMSServer.mooo.com)
129	12.167419	84.55.253.71	10.52.31.125	DTLSv1.2	167	Server Hello, Server Hello Done
130	12.173523	10.52.31.125	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
131	12.274414	84.55.253.71	10.52.31.125	DTLSv1.2	55	Alert (Level: Fatal, Description: Bad Record MAC)
132	13.646393			LTE RRC DL_DCCH	38	RRCConnectionRelease [cause=other]
133	13.750885			LTE RRC DL_SCH	117	SystemInformationBlockType1
134	13.751526			LTE RRC DL_SCH	103	SystemInformation [ SIB2 ]

2727.dtls_handshake_capture.pcapng

As a  double check I also verified using gnutls. the result is the same handshake fails at the first encrypted message exchange. PSK in the modem is matching PSK used on the server.

Joel

[Achim Kraus]

Strange.

mbed_tls uses hex to pass in the secret to their demo-server, so that should work.

But the MAC error in the Finish indicates, that somehow different psk are used. At least, that's one of the sources for MAC errors of the Finish, and in my experience as committer in Eclipse/Californium, it's the very most common one. Anyway, agreed, here the cause may be different.

In general, I'm not aware of some interoperability issues in mbed_tls. In Eclipse/Californium I'm tracking that now for a couple of years. I use the ssl_server2, but I don't think, this makes a difference, If you like, provide your capture.

But though you're using other one's implementation, I think, also others may be more helpful ;-).

Edited: I had a short look at mbed_tls/programs/ssl/ssl_server, and now I have the feeling, that using ssl_server2 may make sense. But overall, that are questions to mbed_tls. 

[JOEBRE]

Same problem also with gnutls. Because of this, I think the problem is on nRF side... isn't it ?

The wiresark capture:

7870.dtls_handshake_capture.pcapng

Joel

[Achim Kraus]

The difference to using Californium seems to be the selected cipher suite. 

I'm currently too short at time, maybe I can spend some time next week to check it also with TLS-PSK-WITH-AES-128-CCM-8. 

(In my apps I don't use the DTLS support of the modem. I use Eclipse/tinydtls on the client and Eclipse/Californium on the server. Both are proactively developed by me and so I'm not aware of such issues.)

But maybe it's anyway time, that someone from Nordic jumps in.

[JOEBRE]

The problem has been resolved! The root cause of the problem was that  we entered the key in clear text on nRF9151.

We were using:  err = modem_key_mgmt_write(SEC_TAG, MODEM_KEY_MGMT_CRED_TYPE_PSK, "supersecretkey", //supersecretkey
strlen("supersecretkey"));

instead of:

err = modem_key_mgmt_write(SEC_TAG, MODEM_KEY_MGMT_CRED_TYPE_PSK, "73757065727365637265746B6579",
strlen("73757065727365637265746B6579"));

As soon as we entered the key in hex the DTLS handshake succeeded.

Thanks for the precious help!

Joel

[Achim Kraus]

Once more, in a decade, that it's the psk encoding ;-).