MQTT Connect fails with error -116 when using TLS

I'm building the `nrf/samples/net/mqtt` sample for the nrf9160dk, specifying a custom certificate inside `src/modules/transport/credentials` as directed in the Kconfig file.

The CA and client certificate / key are specified in the "correct" PEM format, formatted as a C string with newline characters. Sending `at AT%CMNG=2,24,0` correctly reads back the CA certificate.

I'm building with the following flags:

west build -t flash -b nrf9160dk_nrf9160_ns nrf/samples/net/mqtt -DCONFIG_MQTT_HELPER_PORT=8883 -DCONFIG_MQTT_SAMPLE_TRANSPORT_BROKER_HOSTNAME=\"mqtt.preview.playerdata.co.uk\" -DCONFIG_SHELL_BACKEND_RTT=y -DCONFIG_USE_SEGGER_RTT=y -DCONFIG_SHELL=y -DCONFIG_MQTT_HELPER_LOG_LEVEL_DBG=y -DCONFIG_MQTT_LOG_LEVEL_DBG=y -DCONFIG_NRF_MODEM_LIB_LOG_LEVEL_DBG=y -DCONFIG_NRF_MODEM_LOG=y -DCONFIG_MODEM_KEY_MGMT=y -DCONFIG_MQTT_HELPER_SEC_TAG=24 -DCONFIG_MQTT_LIB_TLS=y -DCONFIG_MQTT_LIB=y -DCONFIG_NRF_MODEM_LIB_TRACE=y -DCONFIG_MODEM_KEY_MGMT_LOG_LEVEL_DBG=y -DCONFIG_AT_SHELL=y

The result is that `mqtt_connect` fails with error code -116:

rtt:~$

*** Booting Zephyr OS build v3.3.99-ncs1-1 ***
[00:00:00.327,972] <inf> network: Bringing network interface up
[00:00:00.328,002] <inf> nrf_modem: Initializing libmodem 2.4.1-lte-7821d3f67ae9
[00:00:00.328,430] <dbg> nrf_modem: Control region at 0x20008000 (0x4e8 bytes)
[00:00:00.328,460] <dbg> nrf_modem: TX region at 0x200084e8 (0x2000 bytes)
[00:00:00.328,491] <dbg> nrf_modem: RX region at 0x2000a568 (0x2000 bytes)
[00:00:00.328,521] <dbg> nrf_modem: Trace region at 0x2000c568 (0x4000 bytes)
[00:00:00.329,132] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_UNINIT --> MQTT_STATE_DISCONNECTED
[00:00:00.330,352] <dbg> mqtt_helper: mqtt_helper_poll_loop: Waiting for connection_poll_sem
--- 14 messages dropped ---
[00:00:00.565,216] <dbg> nrf_modem: AT+CEDRXS=3
[00:00:00.565,551] <dbg> nrf_modem: _nrf_modem_lib_init: Modem init callback: 0x30eb7
[00:00:00.565,643] <dbg> nrf_modem: AT%XEPCO=1
[00:00:00.566,070] <dbg> nrf_modem: _nrf_modem_lib_init: Modem init callback: 0xa7cd
[00:00:00.566,131] <dbg> nrf_modem: AT+CMEE?
[00:00:00.566,589] <dbg> nrf_modem: AT+CMEE=1
[00:00:00.820,465] <dbg> nrf_modem: AT+CMEE=0
[00:00:00.820,861] <dbg> nrf_modem: AT+CMEE?
[00:00:00.821,380] <dbg> nrf_modem: AT+CMEE=1
[00:00:02.239,044] <dbg> nrf_modem: AT+CMEE=0
[00:00:02.239,471] <dbg> nrf_modem: AT+CMEE?
[00:00:02.239,990] <dbg> nrf_modem: AT+CMEE=1
[00:00:02.297,821] <dbg> nrf_modem: AT+CMEE=0
[00:00:02.298,156] <dbg> nrf_modem: _nrf_modem_lib_init: Modem init callback: 0x30b61
[00:00:02.298,217] <inf> nrf_modem_lib_trace: Trace thread ready
[00:00:02.298,339] <dbg> nrf_modem: AT%XMODEMTRACE=1,2
[00:00:02.299,713] <inf> nrf_modem_lib_trace: Trace level override: 2
[00:00:02.299,835] <dbg> nrf_modem: AT%XSYSTEMMODE?
[00:00:02.300,384] <dbg> nrf_modem: AT+CEREG=5
[00:00:02.306,823] <dbg> nrf_modem: AT+CSCON=1
[00:00:02.307,250] <inf> network: Connecting...
[00:00:02.307,373] <dbg> nrf_modem: AT+CEREG=5
[00:00:02.307,769] <dbg> nrf_modem: AT+CSCON=1
[00:00:02.308,197] <dbg> nrf_modem: AT+CFUN=21
[00:00:02.339,050] <dbg> nrf_modem: AT+CNEC=16
[00:00:02.339,538] <dbg> nrf_modem: AT+CGEREP=1
[00:00:04.756,774] <dbg> nrf_modem: AT+CGPADDR=0
[00:00:04.858,642] <inf> network: IP Up
[00:00:09.858,978] <dbg> nrf_modem: AT+CGSN
[00:00:09.859,649] <dbg> mqtt_helper: broker_init: Resolving IP address for mqtt.preview.playerdata.co.uk
[00:00:09.859,741] <inf> nrf_modem: getaddrinfo() fam: 0x0, type 0x1, proto 0x6
[00:00:10.010,253] <inf> nrf_modem: RPC_IP_GETADDRINFO_RES, result RPC_IP_ERR_OK
[00:00:10.010,345] <dbg> nrf_modem: ai_length 0x39, ai_family 0x1, ai_addrlen 0x4, ai_namelen 0x1d
[00:00:10.010,437] <inf> nrf_modem: Resolved 34.105.196.147
[00:00:10.010,681] <dbg> mqtt_helper: broker_init: IPv4 Address found 34.105.196.147 (AF_INET)
[00:00:10.010,742] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_DISCONNECTED --> MQTT_STATE_TRANSPORT_CONNECTING
[00:00:10.010,803] <inf> nrf_modem: socket() fam 0x1, type 0x1, proto 0x102
[00:00:10.011,108] <inf> nrf_modem: RPC_IP_OPEN_RES, result RPC_IP_ERR_OK
[00:00:10.011,230] <dbg> nrf_modem: TLS peer verification 2, fd 0x0
[00:00:10.011,291] <dbg> nrf_modem: TLS tags: 1, fd 0x0
[00:00:10.011,413] <dbg> nrf_modem: TLS hostname: mqtt.preview.playerdata.co.uk, fd 0x0
[00:00:10.011,444] <inf> nrf_modem: connect() fd 0x0
[00:00:10.011,505] <inf> nrf_modem: sa_family 0x1, destaddr_len 0x4, destport 8883
[00:00:10.071,563] <inf> nrf_modem: RPC_IP_CONNECT_RES fd 0x0, result RPC_IP_ERR_OK
[00:00:10.071,655] <dbg> nrf_modem: Waiting for handshake semaphore
[00:00:10.071,746] <inf> nrf_modem: Attaching sock fd 0x0
[00:00:10.071,777] <dbg> nrf_modem: Hostname: mqtt.preview.playerdata.co.uk
[00:00:10.071,838] <dbg> nrf_modem: role 0x2, verify 0x2, cache 0x0, tags count 1
[00:00:10.071,868] <dbg> nrf_modem: tag[0]: 24
[00:00:10.115,631] <inf> nrf_modem: RPC_IP_TLS_ATTACH_RES fd 0x0, result RPC_IP_ERR_OK
[00:00:27.930,206] <inf> nrf_modem: RPC_IP_CLOSED_NTF fd 0x0
[00:00:27.930,236] <inf> nrf_modem: Close reason RPC_IP_ERR_CONN_RESET
[00:00:27.931,030] <inf> nrf_modem: RPC_IP_TLS_HANDSHAKE_COMPLETE_NTF fd 0x0, result RPC_IP_ERR_TIMEOUT
[00:00:27.931,121] <inf> nrf_modem: close() fd 0x0
[00:00:27.932,403] <inf> nrf_modem: RPC_IP_CLOSE_RES fd 0x0, result RPC_IP_ERR_OK
[00:00:27.932,525] <err> mqtt_helper: mqtt_connect, error: -116
[00:00:27.932,556] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_TRANSPORT_CONNECTING --> MQTT_STATE_DISCONNECTED
[00:00:27.932,586] <err> transport: Failed connecting to MQTT, error code: -116

Checking the server logs, it doesn't appear that the board has attempted to make a connection with the MQTT server.

  • I can prove that the certificate is valid using `openssl`:

    $ openssl s_client -cert client.crt -key client.key -CAfile ca.crt -tls1_2 mqtt.preview.playerdata.co.uk:8883
    CONNECTED(00000005)
    depth=1 C = GB, ST = Edinburgh, L = Edinburgh, O = PlayerData, CN = tls1
    verify return:1
    depth=0
    verify return:1
    ---
    Certificate chain
     0 s:
       i:C = GB, ST = Edinburgh, L = Edinburgh, O = PlayerData, CN = tls1
       a:PKEY: rsaEncryption, 2048 (bit); sigalg: RSA-SHA256
       v:NotBefore: Jul 28 13:08:17 2023 GMT; NotAfter: Oct 26 13:08:17 2023 GMT
     1 s:C = GB, ST = Edinburgh, L = Edinburgh, O = PlayerData, CN = tls1
       i:C = GB, ST = Edinburgh, L = Edinburgh, O = PlayerData, CN = tls1
       a:PKEY: rsaEncryption, 2048 (bit); sigalg: RSA-SHA256
       v:NotBefore: Nov 30 10:11:06 2022 GMT; NotAfter: Nov  6 10:11:06 2122 GMT
    ---
    Server certificate
    -----BEGIN CERTIFICATE-----
    MIIDnjCCAoagAwIBAgIRAM2D/68G7+KDCxXHTd4RXQ4wDQYJKoZIhvcNAQELBQAw
    WTELMAkGA1UEBhMCR0IxEjAQBgNVBAgTCUVkaW5idXJnaDESMBAGA1UEBxMJRWRp
    bmJ1cmdoMRMwEQYDVQQKEwpQbGF5ZXJEYXRhMQ0wCwYDVQQDEwR0bHMxMB4XDTIz
    MDcyODEzMDgxN1oXDTIzMTAyNjEzMDgxN1owADCCASIwDQYJKoZIhvcNAQEBBQAD
    ggEPADCCAQoCggEBAKnBmYMsEweXzKzEMnYR8/csMS7ZPx+xMY6WClJHeg+Kk3Uo
    l41FKhkci7soG92HJILJUkZqLHkBkWpb+MgANpX1fYaVunTt4JsTf6XPe7aMfn/N
    zh1F6tle8MsvpPvK62Rt5XIgky9bzjVkrHBdhsDX6JoQeoutjipoD5qNnl/KDLbr
    hxjxHCXucOHsdr2u283j8pL7Pg5kG9j7Cgb++leMQqQqqTPzcJ6XJVvyBF3FUET7
    6sl65h2vsuCAhapKPgpgUe5rqMUKEHCGPhI71MSr4oRkkGlyp3aFHkk/Vw+j9FI9
    vT58MbqTWkuVpxczzenmDhYaswhqHEG55FWl1NkCAwEAAaOBuTCBtjAOBgNVHQ8B
    Af8EBAMCBaAwDAYDVR0TAQH/BAIwADAfBgNVHSMEGDAWgBRQsPR3x27NrcEt5y0P
    lVT1KLzicDB1BgNVHREBAf8EazBpgh1tcXR0LnByZXZpZXcucGxheWVyZGF0YS5j
    by51a4IccmFiYml0bXEtcHJldmlldy5wcmV2aWV3LnN2Y4IqcmFiYml0bXEtcHJl
    dmlldy5wcmV2aWV3LnN2Yy5jbHVzdGVyLmxvY2FsMA0GCSqGSIb3DQEBCwUAA4IB
    AQAIYEU9AYjj4XVmIaJnCSmrQpgneOlQ8GPgzWR+uRN8U8veWVQLfOV105Rq6kWc
    3b0CRfhueHTaww8DvjXhbKSVHk5aOSp0j0JbUvR55LaLxiJblnsaw8lBUC1uRw11
    r59eK4/OY8afXNLWsGajQF8eqlmCEwaT1rwXsJGwyEKZaNdPxQ3vQycKaiv1YRfE
    UsdKZGLi4m93MraYWSENNfWipWrbtdJ0+vUZEluit0amlKb8Q3XCXqHxc4Q5UGQg
    idBylnzxf0vDjvMmV5Y28FwxYcPOQMYDvSwMQxut/L7lzbjjAaM1jc75lQX1uwW5
    3K+BRIdzo29RSd0KNUelOT9N
    -----END CERTIFICATE-----
    subject=
    issuer=C = GB, ST = Edinburgh, L = Edinburgh, O = PlayerData, CN = tls1
    ---
    Acceptable client certificate CA names
    C = GB, ST = Edinburgh, L = Edinburgh, O = PlayerData, CN = tls1
    Client Certificate Types: ECDSA sign, RSA sign, DSA sign
    Requested Signature Algorithms: RSA-PSS+SHA512:RSA-PSS+SHA384:RSA-PSS+SHA256:RSA-PSS+SHA512:RSA-PSS+SHA384:RSA-PSS+SHA256:ECDSA+SHA512:RSA+SHA512:ECDSA+SHA384:RSA+SHA384:ECDSA+SHA256:RSA+SHA256:ECDSA+SHA224:RSA+SHA224:ECDSA+SHA1:RSA+SHA1:DSA+SHA1
    Shared Requested Signature Algorithms: RSA-PSS+SHA512:RSA-PSS+SHA384:RSA-PSS+SHA256:RSA-PSS+SHA512:RSA-PSS+SHA384:RSA-PSS+SHA256:ECDSA+SHA512:RSA+SHA512:ECDSA+SHA384:RSA+SHA384:ECDSA+SHA256:RSA+SHA256:ECDSA+SHA224:RSA+SHA224
    Peer signing digest: SHA256
    Peer signature type: RSA-PSS
    Server Temp Key: ECDH, prime256v1, 256 bits
    ---
    SSL handshake has read 2617 bytes and written 3029 bytes
    Verification: OK
    ---
    New, TLSv1.2, Cipher is ECDHE-RSA-AES256-GCM-SHA384
    Server public key is 2048 bit
    Secure Renegotiation IS supported
    Compression: NONE
    Expansion: NONE
    No ALPN negotiated
    SSL-Session:
        Protocol  : TLSv1.2
        Cipher    : ECDHE-RSA-AES256-GCM-SHA384
        Session-ID: E2B7FB08AFA43131F694BACAFED6DD1DF91A793BA3966CB60FC729018F4754FB
        Session-ID-ctx:
        Master-Key: F51D40ABAD27C9970B86D98E510974EB34EAE011525F4F69C032EC41E839FE5DAE23A058C33FD42E0C18BA84AA405EE7
        PSK identity: None
        PSK identity hint: None
        SRP username: None
        Start Time: 1695137268
        Timeout   : 7200 (sec)
        Verify return code: 0 (ok)
        Extended master secret: no
    ---

    In this case I see a log server-side showing that the connection was terminated because no username was provided.

  • Digging more, I've managed to get a Wireshark trace from the other end.

    It looks like the nRF9160 never properly completes the Client Key Exchange step:

  • Hi,

    Which NCS version do you use?

    Which modem firmware version do you use?

    Best regards,
    Dejan

  • Hi Dejan,

    It's `sdk-nrf` version `v2.4.2` and modem firmware `1.3.5`

  • I'll add that I've validated that there is a common cipher suite - both the modem and the server accept at least `ECDHE-RSA-AES256-GCM-SHA384` (if I've understood the modem documentation correctly).

Related