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]

I get compilation errors when I try to build with 3.1.0. Sure this is the fixed code for 3.1.0 ?

Regards, Joel 

[Achim Kraus]

Fullscreen 0118.build.log Download

west build -b nrf9151dk/nrf9151/ns -p -- -DSNIPPET="nrf91-modem-trace-uart"
-- west build: generating a build system
Loading Zephyr module(s) (Zephyr base): sysbuild_default
-- Found Python3: /usr/bin/python3 (found suitable version "3.10.12", minimum required is "3.10") found components: Interpreter
-- Cache files will be written to: /home/achim/.cache/zephyr
-- Found west (found suitable version "1.2.0", minimum required is "0.14.0")
-- Board: nrf9151dk, qualifiers: nrf9151/ns
-- Snippet(s): nrf91-modem-trace-uart
Parsing /home/achim/repos/zephyr/zephyr-coaps-client/zephyr/share/sysbuild/Kconfig
Loaded configuration '/home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/_sysbuild/empty.conf'
Merged configuration '/home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/_sysbuild/empty.conf'
Configuration saved to '/home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/zephyr/.config'
Kconfig header saved to '/home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/_sysbuild/autoconf.h'
-- 
   ***************************************************
   * Running CMake for cellfund_less5_exer2_solution *
   ***************************************************

Loading Zephyr default modules (Zephyr base).
-- Application: /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution
-- CMake version: 4.1.2
-- Found Python3: /usr/bin/python3 (found suitable version "3.10.12", minimum required is "3.10") found components: Interpreter
-- Cache files will be written to: /home/achim/.cache/zephyr
-- Zephyr version: 4.1.99 (/home/achim/repos/zephyr/zephyr-coaps-client/zephyr)
-- Found west (found suitable version "1.2.0", minimum required is "0.14.0")
-- Board: nrf9151dk, qualifiers: nrf9151/ns
-- Snippet(s): nrf91-modem-trace-uart
-- ZEPHYR_TOOLCHAIN_VARIANT not set, trying to locate Zephyr SDK
-- Found host-tools: zephyr 0.17.2 (/home/achim/zephyr-sdk-0.17.2)
-- Found toolchain: zephyr 0.17.2 (/home/achim/zephyr-sdk-0.17.2)
-- Found Dtc: /home/achim/zephyr-sdk-0.17.2/sysroots/x86_64-pokysdk-linux/usr/bin/dtc (found suitable version "1.7.0", minimum required is "1.4.6")
-- Found BOARD.dts: /home/achim/repos/zephyr/zephyr-coaps-client/zephyr/boards/nordic/nrf9151dk/nrf9151dk_nrf9151_ns.dts
-- Found devicetree overlay: /home/achim/repos/zephyr/zephyr-coaps-client/nrf/snippets/nrf91-modem-trace-uart/modem-trace-uart-nrf91.overlay
-- Generated zephyr.dts: /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution/zephyr/zephyr.dts
-- Generated pickled edt: /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution/zephyr/edt.pickle
-- Generated devicetree_generated.h: /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution/zephyr/include/generated/zephyr/devicetree_generated.h
Parsing /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/Kconfig
Loaded configuration '/home/achim/repos/zephyr/zephyr-coaps-client/zephyr/boards/nordic/nrf9151dk/nrf9151dk_nrf9151_ns_defconfig'
Merged configuration '/home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/prj.conf'
Merged configuration '/home/achim/repos/zephyr/zephyr-coaps-client/nrf/snippets/nrf91-modem-trace-uart/modem-trace-uart-common.conf'
Merged configuration '/home/achim/repos/zephyr/zephyr-coaps-client/nrf/snippets/nrf91-modem-trace-uart/modem-trace-uart-nrf91.conf'
Merged configuration '/home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution/zephyr/.config.sysbuild'
Configuration saved to '/home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution/zephyr/.config'
Kconfig header saved to '/home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution/zephyr/include/generated/zephyr/autoconf.h'
-- Found GnuLd: /home/achim/zephyr-sdk-0.17.2/arm-zephyr-eabi/arm-zephyr-eabi/bin/ld.bfd (found version "2.38")
-- The C compiler identification is GNU 12.2.0
-- The CXX compiler identification is GNU 12.2.0
-- The ASM compiler identification is GNU
-- Found assembler: /home/achim/zephyr-sdk-0.17.2/arm-zephyr-eabi/bin/arm-zephyr-eabi-gcc
=========== Generating psa_crypto_config ===============
Backup: CONFIG_MBEDTLS_PSA_CRYPTO_SPM: False
Backup: CONFIG_MBEDTLS_PSA_CRYPTO_C: False
Backup: CONFIG_MBEDTLS_PSA_CRYPTO_KEY_ID_ENCODES_OWNER: False
Backup: CONFIG_MBEDTLS_PLATFORM_SETUP_TEARDOWN_ALT: False
Backup: CONFIG_MBEDTLS_THREADING_C: True
Backup: CONFIG_MBEDTLS_THREADING_ALT: False
=========== Checkpoint: backup ===============
Restore: CONFIG_MBEDTLS_PSA_CRYPTO_SPM: False
Restore: CONFIG_MBEDTLS_PSA_CRYPTO_C: False
Restore: CONFIG_MBEDTLS_PSA_CRYPTO_KEY_ID_ENCODES_OWNER: False
Restore: CONFIG_MBEDTLS_PLATFORM_SETUP_TEARDOWN_ALT: False
Restore: CONFIG_MBEDTLS_THREADING_C: True
Restore: CONFIG_MBEDTLS_THREADING_ALT: False
=========== End psa_crypto_config ===============
=========== Generating psa_crypto_library_config ===============
Backup: CONFIG_MBEDTLS_PSA_CRYPTO_C: False
Backup: CONFIG_MBEDTLS_PSA_CRYPTO_KEY_ID_ENCODES_OWNER: False
Backup: CONFIG_MBEDTLS_PSA_CRYPTO_SPM: False
Backup: CONFIG_MBEDTLS_USE_PSA_CRYPTO: True
Backup: CONFIG_MBEDTLS_PLATFORM_PRINTF_ALT: False
Backup: CONFIG_MBEDTLS_THREADING_C: True
Backup: CONFIG_MBEDTLS_THREADING_ALT: False
=========== Checkpoint: backup ===============
Restore: CONFIG_MBEDTLS_PSA_CRYPTO_C: False
Restore: CONFIG_MBEDTLS_PSA_CRYPTO_KEY_ID_ENCODES_OWNER: False
Restore: CONFIG_MBEDTLS_PSA_CRYPTO_SPM: False
Restore: CONFIG_MBEDTLS_USE_PSA_CRYPTO: True
Restore: CONFIG_MBEDTLS_PLATFORM_PRINTF_ALT: False
Restore: CONFIG_MBEDTLS_THREADING_C: True
Restore: CONFIG_MBEDTLS_THREADING_ALT: False
=========== End psa_crypto_library_config ===============
-- Using ccache: /usr/bin/ccache
-- Found gen_kobject_list: /home/achim/repos/zephyr/zephyr-coaps-client/zephyr/scripts/build/gen_kobject_list.py
-- Configuring done (8.2s)
-- Generating done (0.3s)
-- Build files have been written to: /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution
Dropping partition 'nonsecure_storage' since it is empty.
-- Configuring done (12.2s)
-- Generating done (0.0s)
-- Build files have been written to: /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build
-- west build: building application
[5/10] Performing build step for 'cellfund_less5_exer2_solution'
[1/342] Preparing syscall dependency handling

[5/342] Generating include/generated/zephyr/version.h
-- Zephyr version: 4.1.99 (/home/achim/repos/zephyr/zephyr-coaps-client/zephyr), build: ncs-v3.1.0-1-gecccacad8c3a
[12/342] Generating ../../tfm/CMakeCache.txt
-- Found Git: /usr/bin/git (found version "2.34.1")
-- The C compiler identification is GNU 12.2.0
-- The CXX compiler identification is GNU 12.2.0
-- The ASM compiler identification is GNU
-- Found assembler: /home/achim/zephyr-sdk-0.17.2/arm-zephyr-eabi/bin/arm-zephyr-eabi-gcc
-- Found Python3: /usr/bin/python3 (found version "3.10.12") found components: Interpreter
-- Found Python3: /usr/bin/python3 (found suitable version "3.10.12", minimum required is "3.10") found components: Interpreter
-- Cache files will be written to: /home/achim/.cache/zephyr
CMake Warning (dev) at /home/achim/repos/zephyr/zephyr-coaps-client/nrf/modules/trusted-firmware-m/tfm_boards/nrf9120/CMakeLists.txt:24 (install):
  Policy CMP0177 is not set: install() DESTINATION paths are normalized.  Run
  "cmake --help-policy CMP0177" for policy details.  Use the cmake_policy
  command to set the policy and suppress this warning.
This warning is for project developers.  Use -Wno-dev to suppress it.

-- Configuring done (0.8s)
-- Generating done (0.1s)
-- Build files have been written to: /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution/tfm
[17/342] Performing build step for 'tfm'
[137/141] Linking C executable bin/tfm_s.axf
Memory region         Used Size  Region Size  %age Used
           FLASH:       32092 B        32 KB     97.94%
             RAM:       10404 B        32 KB     31.75%
[141/141] Linking C static library secure_fw/libtfm_s_veneers.a
[19/342] Performing install step for 'tfm'
-- Install configuration: "MinSizeRel"
----- Installing platform NS -----
[342/342] Linking C executable zephyr/zephyr.elf
Memory region         Used Size  Region Size  %age Used
           FLASH:       88928 B       992 KB      8.75%
             RAM:       25200 B     195224 B     12.91%
        IDT_LIST:          0 GB        32 KB      0.00%
Generating files from /home/achim/repos/zephyr/zephyr-coaps-client/cellfund_less5_exer2_solution/build/cellfund_less5_exer2_solution/zephyr/zephyr.elf for board: nrf9151dk
[10/10] Generating ../merged.hex

I don't get build errors.

If the "nrf_modem_at_printf" are added, it may require to add 

#include <nrf_modem_at.h>

as well. With that it builds again without errors.

Just to mention: for the very first tests you don't need your own server, just take leshan or californium. Both will do the handshake. Therefore I only added the lines for the PIN:

        /* 3) Bring modem online */
    nrf_modem_at_printf("AT+CFUN=41");
    k_msleep(2000);
    /* My IoT sim has a PIN */
    nrf_modem_at_printf("AT+CPIN=\"xyza\"");
    k_msleep(1000);

    err = lte_lc_connect_async(lte_handler);

( I used to CFUN=41 for SIM only stuff, but I've also tested it with CFUN=1).

Also with that modification, the client works.

5808.merged.hex

(Prebuild image with enabled modem trace and your PIN. If you like use that and check the modem trace with the cellular monitor.)

[JOEBRE]

Thanks ... at this point I was able to get the DTLS handshake succeed with this code. If I change the server url to point to my DTLS UDP server or a oepenSSL server instance,I get the usual error 111. 

[Achim Kraus]

If you would use the Cellular Monitor and provide the ip capture (wireshark), I would easily see, that the error 111 is caused by different things. This ticket started with PSK credentials but the wrong cipher suites (only no PSK). I'm not sure, if this is still the case. I can now change the to your server url, to see, if that really changes the proposed cipher suites, but I would prefer, if you start to provide the traces.

Once a Nordic engineer works on this, you may anyway need a modem trace.

[Achim Kraus]

If I use your "GIMSServer", I still get a list with PSK cipher suites.

#define ECONNREFUSED 111    /* Connection refused */

tells, that the connection is refused. But there are many reasons for that. One maybe, that even if PSK cipher suites are proposed, the server doesn't support one of the proposed. Then the server may send an handshake alert instead of a Server_Hello. Or the identity/secret doesn't match. The the handshake may timeout or fail after the FINISH.

(I would test to use a slightly shorter psk, your's has 17 bytes. Remove the last one.)

Without current ip-capture, it stays unclear, where it fails.   

[JOEBRE]

I changed PSK removing the final "123". I also configured the GO DTLS server  to use TLS_PSK_WITH_AES_128_CCM_8. This changed the behavior...

dtls_handshake_capture.pcapng

Fullscreen DTLS_DEbug.txt Download

No.	Time	Source	Destination	Protocol	Length	Info
1	0.000000			AT	30	Sent AT Command: AT%XMODEMTRACE=1,2
2	0.001068			AT	16	Rcvd AT Command: OK  
3	0.001587			AT	35	Sent AT Command: AT%XCOEX0=1,1,1565,1586
4	0.001740			AT	16	Rcvd AT Command: OK  
5	0.002564			AT	34	Sent AT Command: AT%XSYSTEMMODE=1,0,0,0
6	0.002808			AT	16	Rcvd AT Command: OK  
7	0.003479			AT	28	Sent AT Command: AT%FEACONF=0,3,1
8	0.003510			AT	16	Rcvd AT Command: OK  
9	0.010163			AT	20	Sent AT Command: AT+CFUN?
10	0.010224			AT	26	Rcvd AT Command: +CFUN: 0  OK  
11	0.010803			AT	21	Sent AT Command: AT+CFUN=1
12	0.043213			AT	16	Rcvd AT Command: OK  
13	2.043671			AT	19	Sent AT Command: AT+CPIN
14	2.043671			AT	32	Rcvd AT Command: +CPIN: SIM PIN  OK  
15	2.044190			AT	19	Sent AT Command: AT+CPIN
16	2.075653			AT	16	Rcvd AT Command: OK  
17	2.538819			LTE RRC BCCH_BCH	28	MasterInformationBlock (SFN=18)
18	2.542755			LTE RRC DL_SCH	117	SystemInformationBlockType1
19	2.546784			LTE RRC DL_SCH	103	SystemInformation [ SIB2 ]
20	2.550873			NAS-EPS	118	Attach request, PDN connectivity request
21	2.553192			LTE RRC UL_CCCH	30	RRCConnectionRequest
22	2.631012			LTE RRC DL_CCCH	74	RRCConnectionSetup
23	2.632385			LTE RRC UL_DCCH/NAS-EPS	137	RRCConnectionSetupComplete, Attach request, PDN connectivity request
24	2.742096			LTE RRC DL_DCCH/NAS-EPS	30	DLInformationTransfer, Identity request
25	2.742188			NAS-EPS	19	Identity request
26	2.742218			NAS-EPS	27	Identity response
27	2.742371			LTE RRC UL_DCCH/NAS-EPS	44	ULInformationTransfer, Identity response
28	2.814087			LTE RRC DL_DCCH/NAS-EPS	63	DLInformationTransfer, Authentication request
29	2.814179			NAS-EPS	52	Authentication request
30	2.873871			NAS-EPS	27	Authentication response
31	2.874024			LTE RRC UL_DCCH/NAS-EPS	44	ULInformationTransfer, Authentication response
32	2.971131			LTE RRC DL_DCCH/NAS-EPS	41	DLInformationTransfer, Security mode command
33	2.971192			NAS-EPS	30	Security mode command
34	2.973023			NAS-EPS	29	Security mode complete
35	2.973175			LTE RRC UL_DCCH/NAS-EPS	46	ULInformationTransfer, Ciphered message
36	3.554230			LTE RRC DL_DCCH	27	SecurityModeCommand
37	3.555969			LTE RRC UL_DCCH	26	SecurityModeComplete
38	3.603150			LTE RRC DL_DCCH	55	UECapabilityEnquiry
39	3.605133			LTE RRC UL_DCCH	150	UECapabilityInformation
40	3.715424			LTE RRC DL_DCCH/NAS-EPS	260	RRCConnectionReconfiguration, Ciphered message
41	3.716919			LTE RRC UL_DCCH	26	RRCConnectionReconfigurationComplete
42	3.717346			NAS-EPS	189	Ciphered message, Attach accept, Activate default EPS bearer context request (PDN type IPv4 only allowed)
43	3.717987			NAS-EPS	23	Attach complete, Activate default EPS bearer context accept
44	3.718201			LTE RRC UL_DCCH/NAS-EPS	40	ULInformationTransfer, Ciphered message, Deactivate EPS bearer context request (Unknown)
45	3.774140			LTE RRC DL_DCCH/NAS-EPS	54	DLInformationTransfer, Ciphered message
46	3.774262			NAS-EPS	43	Ciphered message, EMM information
47	3.835266			LTE RRC DL_DCCH	37	RRCConnectionReconfiguration
48	3.836029			LTE RRC UL_DCCH	26	RRCConnectionReconfigurationComplete
49	5.076172			AT	19	Sent AT Command: AT+CPIN
50	5.076203			AT	30	Rcvd AT Command: +CPIN: READY  OK  
51	5.076630			AT	21	Sent AT Command: AT+CFUN=4
52	5.078217			NAS-EPS	31	Detach request (Combined EPS/IMSI detach / switch-off)
53	5.078369			LTE RRC UL_DCCH/NAS-EPS	48	ULInformationTransfer, Ciphered message(DTAP) (TP) Update UE Location Information [Malformed Packet]
54	5.300354			LTE RRC DL_DCCH	38	RRCConnectionRelease [cause=other]
55	5.419403			AT	16	Rcvd AT Command: OK  
56	6.428681			AT	20	Sent AT Command: AT+CMEE?
57	6.428711			AT	26	Rcvd AT Command: +CMEE: 0  OK  
58	6.435211			AT	21	Sent AT Command: AT+CMEE=1
59	6.435242			AT	16	Rcvd AT Command: OK  
60	6.435974			AT	19	Sent AT Command: AT%CMNG
61	7.161163			AT	16	Rcvd AT Command: OK  
62	7.161621			AT	21	Sent AT Command: AT+CMEE=0
63	7.161652			AT	16	Rcvd AT Command: OK  
64	7.162110			AT	20	Sent AT Command: AT+CMEE?
65	7.162140			AT	26	Rcvd AT Command: +CMEE: 0  OK  
66	7.162598			AT	21	Sent AT Command: AT+CMEE=1
67	7.162628			AT	16	Rcvd AT Command: OK  
68	7.163147			AT	19	Sent AT Command: AT%CMNG
69	7.236633			AT	16	Rcvd AT Command: OK  
70	7.237091			AT	21	Sent AT Command: AT+CMEE=0
71	7.237122			AT	16	Rcvd AT Command: OK  
72	7.237518			AT	21	Sent AT Command: AT+CFUN=1
73	7.270172			AT	16	Rcvd AT Command: OK  
74	9.270691			AT	19	Sent AT Command: AT+CPIN
75	9.302124			AT	16	Rcvd AT Command: OK  
76	9.769104			LTE RRC BCCH_BCH	28	MasterInformationBlock (SFN=198)
77	9.783020			LTE RRC DL_SCH	117	SystemInformationBlockType1
78	9.783692			LTE RRC DL_SCH	103	SystemInformation [ SIB2 ]
79	9.786499			NAS-EPS	118	Attach request, PDN connectivity request
80	9.788605			LTE RRC UL_CCCH	30	RRCConnectionRequest
81	9.826325			LTE RRC DL_CCCH	74	RRCConnectionSetup
82	9.827698			LTE RRC UL_DCCH/NAS-EPS	137	RRCConnectionSetupComplete, Attach request, PDN connectivity request
83	10.302674			AT	21	Sent AT Command: AT+CEREG?
84	10.302826			AT	49	Rcvd AT Command: +CEREG: 0,2,"057D","01017406",7  OK  
85	10.303589			AT	20	Sent AT Command: AT+CFUN?
86	10.303650			AT	26	Rcvd AT Command: +CFUN: 1  OK  
87	10.304260			AT	22	Sent AT Command: AT+CEREG=5
88	10.304260			AT	16	Rcvd AT Command: OK  
89	10.304688			AT	22	Sent AT Command: AT+CSCON=1
90	10.304718			AT	16	Rcvd AT Command: OK  
91	10.305206			AT	21	Sent AT Command: AT+CFUN=1
92	10.305786			AT	16	Rcvd AT Command: OK  
93	10.381409			LTE RRC DL_DCCH	27	SecurityModeCommand
94	10.383301			LTE RRC UL_DCCH	26	SecurityModeComplete
95	10.488281			LTE RRC DL_DCCH	55	UECapabilityEnquiry
96	10.490326			LTE RRC UL_DCCH	150	UECapabilityInformation
97	10.594574			LTE RRC DL_DCCH/NAS-EPS	260	RRCConnectionReconfiguration, Ciphered message
98	10.596344			LTE RRC UL_DCCH	26	RRCConnectionReconfigurationComplete
99	10.596802			NAS-EPS	189	Ciphered message, Attach accept, Activate default EPS bearer context request (PDN type IPv4 only allowed)
100	10.597809			NAS-EPS	23	Attach complete, Activate default EPS bearer context accept
101	10.597992			LTE RRC UL_DCCH/NAS-EPS	40	ULInformationTransfer, Ciphered message
102	10.645844			AT	67	Rcvd AT Command: +CEREG: 1,"057D","01017406",7,,,"00001111","00101101"  
103	10.647064	10.238.101.106	193.5.23.8	DNS	77	Standard query 0x17be A GIMSServer.mooo.com
104	10.656433			LTE RRC DL_DCCH/NAS-EPS	54	DLInformationTransfer, Ciphered message
105	10.656555			NAS-EPS	43	Ciphered message, EMM information
106	10.724518			LTE RRC DL_DCCH	37	RRCConnectionReconfiguration
107	10.725281			LTE RRC UL_DCCH	26	RRCConnectionReconfigurationComplete
108	10.874237	193.5.23.8	10.238.101.106	DNS	93	Standard query response 0x17be A GIMSServer.mooo.com A 84.55.253.71
109	10.880158	10.238.101.106	84.55.253.71	DTLSv1.2	176	Client Hello (SNI=GIMSServer.mooo.com)
110	10.989227	84.55.253.71	10.238.101.106	DTLSv1.2	88	Hello Verify Request
111	10.990021	10.238.101.106	84.55.253.71	DTLSv1.2	196	Client Hello (SNI=GIMSServer.mooo.com)
112	11.090820	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
113	11.097626	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
114	12.199555	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
115	13.225708	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
116	13.226288	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
117	15.138642	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
118	15.139160	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
119	17.090851	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
120	17.091431	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
121	19.192413	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
122	19.302979	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
123	19.303375	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
124	21.217987	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
125	21.218445	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
126	23.143097	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
127	23.143524	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
128	25.086151	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
129	25.086579	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
130	27.298218	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
131	27.298676	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
132	29.217224	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
133	29.217560	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
134	31.137268	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
135	31.137634	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
136	33.088379	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
137	33.088715	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
138	35.334473	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
139	35.334809	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
140	37.217529	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
141	37.217865	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
142	39.136658	84.55.253.71	10.238.101.106	DTLSv1.2	171	Server Hello, Server Key Exchange, Server Hello Done
143	39.137238	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
144	43.238281	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
145	51.339935	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message
146	67.441742	10.238.101.106	84.55.253.71	DTLSv1.2	143	Client Key Exchange, Change Cipher Spec, Encrypted Handshake Message

See dtls_handshake_capture.pcapng wireshark capture (I hope this contains everything) and DTLS_DEbug.txt which shows the message sequence in Wireshark.

As mentioned Lesson5_Exercise2 is connecting successfully to the public COAP server.

Joel

[Achim Kraus]

I would check, if the go server really wants the psk in hex or how to pass it in as hex. Otherwise, just pass "secret" into go (plain) and "736563726574" to the modem (hex) and see what's happen.

[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