NRF54L15 AWS IoT MQTT connection issues. Where to store device cert files.

Hi everyone,

I’ve been following the AWS IoT sample, but so far I haven’t been able to establish a connection.

We’re running on a custom board using the nRF54L15, connected to a Quectel EG915 modem via UART. We have a thread managing the PPP connection: it brings the interface up (net_if_up()) and waits for the L4 connection events. Once the connection is established, we perform an SNTP sync using the IPv4 address resolved with zsock_getaddrinfo(). After the time sync completes, a callback notifies the AWS IoT MQTT worker to start the MQTT connection.

Issue 1: DNS Resolution for the AWS IoT Broker

DNS resolution for the broker fails unless we force a static IP.
This is the logic:

	if (sizeof(CONFIG_MQTT_HELPER_STATIC_IP_ADDRESS) > 1) {
		conn_params->hostname.ptr = CONFIG_MQTT_HELPER_STATIC_IP_ADDRESS;

		LOG_DBG("Using static IP address: %s", CONFIG_MQTT_HELPER_STATIC_IP_ADDRESS);
	} else {
		LOG_DBG("Resolving IP address for %s", conn_params->hostname.ptr);
	}

	err = zsock_getaddrinfo(conn_params->hostname.ptr, NULL, &hints, &result);
	if (err) {
		LOG_ERR("getaddrinfo() failed, error %d", err);
		return -err;
	}


zsock_getaddrinfo() returns -3, which is strange because the same function works fine for resolving the NTP server.
Even more confusing: on the SIM card portal, we can see the DNS query for the AWS broker happening correctly — yet our code still times out.

To move forward, we tried defining CONFIG_MQTT_HELPER_STATIC_IP_ADDRESS with the IPv4 address, but we still cannot connect.
The connection returns -116 (timeout). Initially we suspected a certificate issue, but again, from the SIM portal we can see a response coming back from the server — but since it’s TLS, we can’t decode it.

Has anyone experienced this? Could it be related to the PPP setup?

I've attached the key parts of my prj.conf below.

Issue 2: Handling Certificates in Production

What is the recommended way to manage certificates securely on the nRF54L15?

We’ve looked at the TF-M examples, but we’re still unsure how this should work in a real production workflow.

Key questions:

  • How should certificates be provisioned on a production device?

  • Can they be embedded in the firmware image and then stored securely by TF-M at runtime?

  • Should they be erased from normal flash afterwards?

  • What’s the typical workflow for securely flashing these assets when manufacturing devices?

Any insight from someone who has already implemented this would be extremely helpful.

# CONFIG_SENSOR=y
CONFIG_I2C=y
CONFIG_GPIO=y
CONFIG_GPIO_PCA953X=y
CONFIG_COUNTER=y
CONFIG_COUNTER_MICROCHIP_MCP7940N=y
CONFIG_NFCT_PINS_AS_GPIOS=y
CONFIG_RTC=y

CONFIG_LOG=y
CONFIG_USE_SEGGER_RTT=y
CONFIG_CONSOLE=y
CONFIG_RTT_CONSOLE=y
CONFIG_UART_CONSOLE=n

CONFIG_SERIAL=y
CONFIG_UART_INTERRUPT_DRIVEN=y

CONFIG_ADC=y
CONFIG_NRFX_SAADC=y
CONFIG_NRFX_GPPI=y

CONFIG_NRFX_TIMER22=y

CONFIG_BT=y
CONFIG_BT_DEVICE_NAME="smart"
# CONFIG_BT_CTLR_TX_PWR_0=y
# CONFIG_BT_CTLR_TX_PWR_PLUS_3=y
CONFIG_BT_CTLR_TX_PWR_PLUS_4=y
# CONFIG_BT_CTLR_TX_PWR_MINUS_40=y

# FOTA over Bluetooth
# CONFIG_BT_PERIPHERAL=y
CONFIG_BOOTLOADER_MCUBOOT=y
# CONFIG_BT_SMP=y
# CONFIG_MCUMGR=y
# CONFIG_NET_BUF=y
# CONFIG_ZCBOR=y
# CONFIG_MCUMGR_TRANSPORT_BT=y
# CONFIG_MCUMGR_TRANSPORT_BT_CONN_PARAM_CONTROL=y
# CONFIG_MCUMGR_GRP_IMG=y
# CONFIG_MCUMGR_GRP_OS=y
# CONFIG_MCUMGR_GRP_OS_BOOTLOADER_INFO=y
# CONFIG_MCUMGR_TRANSPORT_BT_REASSEMBLY=y
# CONFIG_MCUMGR_TRANSPORT_BT_PERM_RW_AUTHEN=y

CONFIG_PWM=y
CONFIG_CLOCK_CONTROL=y
# CONFIG_SPI=y

CONFIG_WDT_LOG_LEVEL_INF=n
CONFIG_WATCHDOG=y
CONFIG_WDT_DISABLE_AT_BOOT=n

CONFIG_REQUIRES_FLOAT_PRINTF=y

CONFIG_CRC=y

CONFIG_ENTROPY_GENERATOR=y
CONFIG_REQUIRES_FULL_LIBC=y
CONFIG_JSON_LIBRARY=y
CONFIG_TEST_RANDOM_GENERATOR=y
CONFIG_INIT_STACKS=y
CONFIG_HW_STACK_PROTECTION=y

# NVS for persistent storage
CONFIG_ZMS=y

# Flash for FOTA
CONFIG_FLASH=y
CONFIG_FLASH_MAP=y
CONFIG_STREAM_FLASH=y
CONFIG_IMG_MANAGER=y

# POSIX
CONFIG_POSIX_API=y
CONFIG_POSIX_NETWORKING=y
CONFIG_ZVFS_OPEN_MAX=21
CONFIG_POSIX_FD_MGMT=n
CONFIG_POSIX_MESSAGE_PASSING=n
CONFIG_POSIX_THREAD_THREADS_MAX=0

# Networking over PPP
CONFIG_NETWORKING=y
CONFIG_NET_NATIVE=y
CONFIG_NET_L2_PPP=y
CONFIG_NET_IPV4=y
CONFIG_NET_UDP=y
CONFIG_NET_TCP=y
CONFIG_NET_SOCKETS=y
CONFIG_NET_SOCKETS_SOCKOPT_TLS=y

# DNS
CONFIG_NET_LOG=y
CONFIG_DNS_RESOLVER=y
CONFIG_NET_L2_PPP_OPTION_DNS_USE=n
CONFIG_DNS_SERVER_IP_ADDRESSES=y
CONFIG_DNS_SERVER1="8.8.8.8"
CONFIG_DNS_RESOLVER_MAX_SERVERS=1
CONFIG_DNS_RESOLVER_ADDITIONAL_BUF_CTR=2
CONFIG_NET_SOCKETS_DNS_TIMEOUT=5000
CONFIG_DNS_RESOLVER_LOG_LEVEL_DBG=y

# SNTP
CONFIG_SNTP=y

# Network management
CONFIG_NET_MGMT=y
CONFIG_NET_MGMT_EVENT=y
CONFIG_NET_CONNECTION_MANAGER=y
CONFIG_NET_CONFIG_SETTINGS=y
CONFIG_NET_CONFIG_NEED_IPV4=y
CONFIG_NET_DHCPV4=y
CONFIG_NET_MAX_CONN=6
CONFIG_NET_SOCKETS_POLL_MAX=8
CONFIG_NET_SOCKETS_OFFLOAD=n
CONFIG_NET_CONTEXT_SNDTIMEO=y
CONFIG_NET_CONTEXT_RCVTIMEO=y
CONFIG_NET_MAX_CONTEXTS=3

# PSA Crypto for SHA-1 (recommended over legacy mbedtls)
CONFIG_NRF_SECURITY=y
CONFIG_PSA_WANT_ALG_SHA_1=y

# AWS IoT Core
CONFIG_AWS_IOT=y
CONFIG_AWS_IOT_BROKER_HOST_NAME="aaaaaaa.eu-west-1.amazonaws.com"
CONFIG_MQTT_HELPER_STATIC_IP_ADDRESS="100.100.100.100"
CONFIG_AWS_IOT_CLIENT_ID_STATIC="" # Should be fetched directly in runtime
CONFIG_AWS_IOT_CLIENT_ID_MAX_LEN=40
CONFIG_AWS_IOT_TOPIC_UPDATE_DELTA_SUBSCRIBE=y
CONFIG_AWS_IOT_TOPIC_GET_ACCEPTED_SUBSCRIBE=y
CONFIG_AWS_IOT_TOPIC_GET_REJECTED_SUBSCRIBE=y
CONFIG_AWS_IOT_LOG_LEVEL_DBG=y

# MQTT helper library
CONFIG_MQTT_HELPER=y
CONFIG_MQTT_HELPER_SEC_TAG=201
CONFIG_MQTT_HELPER_LAST_WILL=y
CONFIG_MQTT_HELPER_LOG_LEVEL_DBG=y
CONFIG_MQTT_HELPER_PORT=8883
CONFIG_MQTT_HELPER_PROVISION_CERTIFICATES=n

# MQTT - Maximum MQTT keepalive timeout specified by AWS IoT Core
CONFIG_MQTT_KEEPALIVE=1200
CONFIG_MQTT_CLEAN_SESSION=y

# TLS (provided by nRF Security, not builtin)
CONFIG_NRF_SECURITY_ADVANCED=y
CONFIG_NORDIC_SECURITY_BACKEND=y
CONFIG_MBEDTLS_TLS_LIBRARY=y
CONFIG_MBEDTLS_X509_LIBRARY=y
CONFIG_NET_SOCKETS_SOCKOPT_TLS=y
CONFIG_NET_SOCKETS_TLS_MAX_CONTEXTS=1
CONFIG_MBEDTLS=y
CONFIG_MBEDTLS_ENABLE_HEAP=y
CONFIG_MBEDTLS_SSL_KEEP_PEER_CERTIFICATE=n
CONFIG_MBEDTLS_SSL_SERVER_NAME_INDICATION=y

CONFIG_TLS_CREDENTIALS=y
CONFIG_TLS_CREDENTIALS_BACKEND_VOLATILE=y
CONFIG_MBEDTLS_LOG_LEVEL_DBG=y
# CONFIG_BUILD_WITH_TFM=y
# CONFIG_TLS_CREDENTIALS_BACKEND_PROTECTED_STORAGE=y

# Modem subsystem
CONFIG_MODEM=y
CONFIG_PM_DEVICE=y
CONFIG_MODEM_CELLULAR=y
CONFIG_MODEM_CELLULAR_APN="onomondo"

# Statistics
CONFIG_MODEM_STATS=n
CONFIG_SHELL=n

# Logging
CONFIG_MODEM_MODULES_LOG_LEVEL_DBG=y

# NET buffers
CONFIG_NET_PKT_TX_COUNT=6
CONFIG_NET_PKT_RX_COUNT=6
CONFIG_NET_BUF_TX_COUNT=12
CONFIG_NET_BUF_RX_COUNT=6

# Modem buffers
CONFIG_MODEM_CMUX_MTU=512
CONFIG_MODEM_CMUX_WORK_BUFFER_SIZE=520

# Stack Sizes
CONFIG_NET_TX_STACK_SIZE=2048
CONFIG_NET_RX_STACK_SIZE=2048
CONFIG_NET_MGMT_EVENT_STACK_SIZE=1024
## For workers
CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=4096
CONFIG_ISR_STACK_SIZE=512
CONFIG_MQTT_HELPER_STACK_SIZE=4096

# Heap sizes
CONFIG_HEAP_MEM_POOL_IGNORE_MIN=y
CONFIG_MBEDTLS_HEAP_SIZE=45000
CONFIG_HEAP_MEM_POOL_SIZE=32000

Best regards,

Fernando Fontes

Parents
  • Hi Fernando,

    I am looking into this, and hope to give some answers by end of this week.

    Regards,
    Sigurd Hellesvik

  • Hi  ,

    Thank you for replying. In the meanwhile I'm adding extra debug that I was able to do.

    DNS issue:

    I've enabled debug on net_sockets and on net_dns and this is what I see when I call the zsock_getaddrinfo() inside a thread with priority 5:

    [00:00:54.417,900] <dbg> net_sock_addr: exec_query: (): Timeout 5000
    [00:00:54.418,135] <dbg> net_dns_resolve: dns_resolve_name_internal: (): DNS id will be 37718
    [00:00:54.418,418] <dbg> net_dns_resolve: dns_write: (): [0] submitting work to server idx 0 for id 37718 hash 43467
    [00:00:54.715,776] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004788, pkt=0x20027e6c, st=0, user_data=0
    [00:00:54.716,238] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.716,484] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.716,718] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.716,950] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.717,195] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.717,427] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.717,668] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.717,897] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.718,138] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.718,365] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.723,595] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.723,827] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.724,072] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.724,303] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.724,547] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -103

    Normal DNS_EAI_INPROGRESS and DNS_EAI_ALLDONE status.

    When zsock_getaddrinfo() is called from sysworkq priority -1 I guess:

    [00:00:54.089,481] <dbg> net_sock_addr: exec_query: (sysworkq): Timeout 5000
    [00:00:54.089,726] <dbg> net_dns_resolve: dns_resolve_name_internal: (sysworkq): DNS id will be 34236
    [00:00:54.090,020] <dbg> net_dns_resolve: dns_write: (sysworkq): [0] submitting work to server idx 0 for id 34236 hash 43467
    [00:00:59.190,527] <dbg> net_dns_resolve: dns_resolve_cancel_with_hash: (sysworkq): Cancelling DNS req 34236 (name <unknown> type 1 hash 0)
    [00:00:59.190,845] <dbg> net_sock_addr: dns_resolve_cb: (sysworkq): dns status: -101
    [00:00:59.191,067] <err> mqtt_helper: getaddrinfo() failed, error -3
    [00:00:59.191,257] <dbg> mqtt_helper: mqtt_state_set: Skipping transition to the same state (MQTT_STATE_DISCONNECTED)
    [00:00:59.191,506] <err> aws_iot: mqtt_helper_connect, error: 3
    [00:00:59.191,675] <err> connection: aws_iot_connect, error: 3
    [00:00:59.430,549] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004788, pkt=0x20027e90, st=0, user_data=0

    No dns status logs, and after the 5 seconds timeout I get the DNS_EAI_CANCELED which comes from timeout implementation. On the sim card portal I see the DNS requests.

    So, is this somehow related to priorities? Is the sysworkq preempting the modem handler functions, like cmux? 

    Connection issue:

    For the connection to the MQTT itself it might be a similar issue? Forcing the IP I still get -116  ETIMEDOUT, but on the SIM card portal I see the SYN attempts and re.transmissions and the reply.

    [00:00:54.184,142] <dbg> mqtt_helper: broker_init: Using static IP address: 52.48.246.214
    [00:00:54.184,408] <dbg> mqtt_helper: broker_init: IPv4 Address found 52.48.246.214 (AF_INET)
    [00:00:54.184,647] <dbg> mqtt_helper: client_connect: Using build-time provided security tag value from Kconfig
    [00:00:54.184,893] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_DISCONNECTED --> MQTT_STATE_TRANSPORT_CONNECTING
    [00:00:54.185,255] <dbg> net_sock_tls: tls_alloc: (sysworkq): Allocated TLS context, 0x20003fd0
    [00:00:54.185,651] <dbg> net_tcp: tcp_conn_ref: (sysworkq): conn: 0x20028004, ref_count: 1
    [00:00:54.185,883] <dbg> net_tcp: tcp_conn_alloc: (sysworkq): conn: 0x20028004
    [00:00:54.186,104] <dbg> net_sock: zsock_socket_internal: (sysworkq): socket: ctx=0x20004830, fd=6
    [00:00:54.186,385] <dbg> net_tcp: net_tcp_recv: (sysworkq): context: 0x20004830, cb: 0x23fc9, user_data: 0
    [00:00:54.191,698] <dbg> net_ctx: net_context_bind: (sysworkq): Context 0x20004830 binding to TCP 0.0.0.0:52302 iface 1 (0x20002da8)
    [00:00:54.192,040] <dbg> net_tcp: net_tcp_connect: (sysworkq): context: 0x20004830, local: 0.0.0.0, remote: 52.48.246.214
    [00:00:54.192,468] <dbg> net_tcp: net_tcp_connect: (sysworkq): conn: 0x20028004 src: 100.69.36.249, dst: 52.48.246.214
    [00:00:54.192,888] <dbg> net_tcp: tcp_start_handshake: (sysworkq): LISTEN->SYN_SENT
    [00:00:54.193,114] <dbg> net_tcp: tcp_conn_ref: (sysworkq): conn: 0x20028004, ref_count: 2
    [00:00:55.256,951] <dbg> net_tcp: tcp_resend_data: (tcp_work): send_data_retries=0
    [00:00:56.853,335] <dbg> net_tcp: tcp_resend_data: (tcp_work): send_data_retries=1
    [00:00:57.193,401] <dbg> net_tcp: tcp_conn_close_debug: (sysworkq): conn: 0x20028004 closed by TCP stack (net_tcp_connect():3857)
    [00:00:57.193,709] <dbg> net_tcp: tcp_conn_close_debug: (sysworkq): SYN_SENT->CLOSED
    [00:00:57.193,934] <dbg> net_sock: zsock_received_cb: (sysworkq): ctx=0x20004830, pkt=0, st=-116, user_data=0
    [00:00:57.194,206] <dbg> net_sock: zsock_received_cb: (sysworkq): Marked socket 0x20004830 as peer-closed
    [00:00:57.194,459] <dbg> net_tcp: tcp_conn_unref: (sysworkq): conn: 0x20028004, ref_count=2
    [00:00:57.194,687] <dbg> net_tcp: net_tcp_connect: (sysworkq): conn: 0x20028004, ret=-116
    [00:00:57.195,008] <dbg> net_sock: zsock_close_ctx: (sysworkq): close: ctx=0x20004830, fd=6
    [00:00:57.195,246] <dbg> net_tcp: net_tcp_recv: (sysworkq): context: 0x20004830, cb: 0, user_data: 0
    [00:00:57.195,547] <dbg> net_tcp: net_tcp_put: (sysworkq):  [CLOSED Seq=578338025 Ack=0]
    [00:00:57.195,765] <dbg> net_tcp: net_tcp_put: (sysworkq): context 0x20004830 CONNECTING
    [00:00:57.195,989] <dbg> net_tcp: tcp_conn_unref: (sysworkq): conn: 0x20028004, ref_count=1
    [00:00:57.201,213] <err> mqtt_helper: mqtt_connect, error: -116
    [00:00:57.201,400] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_TRANSPORT_CONNECTING --> MQTT_STATE_DISCONNECTED
    [00:00:57.201,680] <err> aws_iot: mqtt_helper_connect, error: -116
    [00:00:57.201,861] <err> connection: aws_iot_connect, error: -116
    [00:00:57.202,079] <dbg> net_ctx: net_context_unref: (tcp_work): Context 0x20004830 released
    [00:00:57.389,007] <dbg> net_tcp: net_tcp_reply_rst: (rx_q[0]): RST Seq=578338025 Len=0
    [00:00:57.389,477] <dbg> net_tcp: net_tcp_reply_rst: (rx_q[0]): RST Seq=578338025 Len=0

    I will try to change the implementation to use priority defined values for the workqueues instead and see if that fix it. 

    Best regards,

    Fernando Fontes

  • Ok, I've updated the thread sizes to 5 (using (void)k_work_schedule_for_queue(&connection_work_queue, &connect_work, K_SECONDS(5))) and now I finally was able to have the DNS working and some progress on the connection. It's still returning -116 but now I finally see client hello on the wireshark. 

    [00:00:53.882,124] <inf> connection: Connecting to AWS IoT
    [00:00:53.882,306] <dbg> aws_iot: aws_iot_connect: No hostname provided, using Kconfig value: aaaaaaa-ats.iot.eu-west-1.amazonaws.com
    [00:00:53.882,710] <dbg> mqtt_helper: broker_init: Resolving IP address for aaaaaaa-ats.iot.eu-west-1.amazonaws.com
    [00:00:53.883,002] <dbg> net_sock_addr: exec_query: (): Timeout 5000
    [00:00:53.883,228] <dbg> net_dns_resolve: dns_resolve_name_internal: (): DNS id will be 23366
    [00:00:53.883,509] <dbg> net_dns_resolve: dns_write: (): [0] submitting work to server idx 0 for id 23366 hash 43467
    [00:00:54.200,012] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004958, pkt=0x2002a01c, st=0, user_data=0
    [00:00:54.200,470] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.200,714] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.200,946] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.201,176] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.201,416] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.201,642] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.201,880] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.202,106] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.202,344] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.202,569] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.207,797] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.208,027] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.208,269] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -100
    [00:00:54.208,497] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): getaddrinfo entries overflow
    [00:00:54.208,735] <dbg> net_sock_addr: dns_resolve_cb: (net_socket_service): dns status: -103
    [00:00:54.208,997] <dbg> mqtt_helper: broker_init: IPv4 Address found 52.210.195.156 (AF_INET)
    [00:00:54.209,235] <dbg> mqtt_helper: client_connect: Using build-time provided security tag value from Kconfig
    [00:00:54.209,616] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_DISCONNECTED --> MQTT_STATE_TRANSPORT_CONNECTING
    [00:00:54.209,964] <dbg> net_sock_tls: tls_alloc: (): Allocated TLS context, 0x200041a0
    [00:00:54.210,326] <dbg> net_tcp: tcp_conn_ref: (): conn: 0x2002a1b4, ref_count: 1
    [00:00:54.215,526] <dbg> net_tcp: tcp_conn_alloc: (): conn: 0x2002a1b4
    [00:00:54.215,733] <dbg> net_sock: zsock_socket_internal: (): socket: ctx=0x20004a00, fd=6
    [00:00:54.216,005] <dbg> net_tcp: net_tcp_recv: (): context: 0x20004a00, cb: 0x23a19, user_data: 0
    [00:00:54.216,290] <dbg> net_ctx: net_context_bind: (): Context 0x20004a00 binding to TCP 0.0.0.0:54963 iface 1 (0x20002da8)
    [00:00:54.216,610] <dbg> net_tcp: net_tcp_connect: (): context: 0x20004a00, local: 0.0.0.0, remote: 52.210.195.156
    [00:00:54.217,085] <dbg> net_tcp: net_tcp_connect: (): conn: 0x2002a1b4 src: 100.69.36.249, dst: 52.210.195.156
    [00:00:54.217,869] <dbg> net_tcp: tcp_start_handshake: (): LISTEN->SYN_SENT
    [00:00:54.218,072] <dbg> net_tcp: tcp_conn_ref: (): conn: 0x2002a1b4, ref_count: 2
    [00:00:54.450,937] <dbg> net_tcp: tcp_resend_data: (tcp_work): send_data_retries=0
    [00:00:54.499,470] <dbg> net_tcp: tcp_in: (rx_q[0]): SYN,ACK Seq=430370318 Ack=578723489 Len=0 [SYN_SENT Seq=578723489 Ack=0]
    [00:00:54.499,754] <dbg> net_tcp: tcp_options_check: (rx_q[0]): len=4
    [00:00:54.499,942] <dbg> net_tcp: tcp_options_check: (rx_q[0]): opt: 2, opt_len: 4
    [00:00:54.500,147] <dbg> net_tcp: tcp_options_check: (rx_q[0]): MSS=1460
    [00:00:54.500,339] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 26883 to 1280
    [00:00:54.500,589] <dbg> net_tcp: tcp_new_reno_log: (rx_q[0]): conn: 0x2002a1b4, ca init, cwnd=1460, ssthres=4380, fast_pend=0
    [00:00:54.500,996] <dbg> net_tcp: tcp_in: (rx_q[0]): SYN_SENT->ESTABLISHED
    [00:00:54.501,565] <dbg> net_tcp: net_tcp_connect: (): conn: 0x2002a1b4, ret=0
    [00:00:54.515,495] <dbg> net_tcp: net_tcp_recv: (): context: 0x20004a00, cb: 0x23a19, user_data: 0
    [00:00:54.517,641] <dbg> net_tcp: tcp_send_data: (): conn: 0x2002a1b4 total=244, unacked_len=244, send_win=1280, mss=1460
    [00:00:54.517,954] <dbg> net_tcp: tcp_send_data: (): conn: 0x2002a1b4 send_data_timer=0, send_data_retries=1
    [00:00:54.712,571] <dbg> net_tcp: tcp_in: (rx_q[0]): SYN,ACK Seq=430370318 Ack=578723489 Len=0 [ESTABLISHED Seq=578723489 Ack=430370319]
    [00:00:54.712,873] <dbg> net_tcp: tcp_options_check: (rx_q[0]): len=4
    [00:00:54.713,059] <dbg> net_tcp: tcp_options_check: (rx_q[0]): opt: 2, opt_len: 4
    [00:00:54.713,260] <dbg> net_tcp: tcp_options_check: (rx_q[0]): MSS=1460
    [00:00:54.713,453] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 26883 to 1280
    [00:00:54.713,700] <dbg> net_tcp: tcp_new_reno_log: (rx_q[0]): conn: 0x2002a1b4, ca dup_ack, cwnd=2920, ssthres=4380, fast_pend=0
    [00:00:54.751,288] <dbg> net_tcp: tcp_resend_data: (tcp_work): send_data_retries=0
    [00:00:54.751,523] <dbg> net_tcp: tcp_new_reno_log: (tcp_work): conn: 0x2002a1b4, ca timeout, cwnd=1460, ssthres=2920, fast_pend=0
    [00:00:54.752,019] <dbg> net_tcp: tcp_send_data: (tcp_work): conn: 0x2002a1b4 total=244, unacked_len=244, send_win=1280, mss=1460
    [00:00:54.752,343] <dbg> net_tcp: tcp_send_data: (tcp_work): conn: 0x2002a1b4 send_data_timer=0, send_data_retries=0
    [00:00:54.829,783] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=430370319 Ack=578723733 Len=0 [ESTABLISHED Seq=578723489 Ack=430370319]
    [00:00:54.830,094] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:54.830,350] <dbg> net_tcp: tcp_in: (rx_q[0]): conn: 0x2002a1b4 len_acked=244
    [00:00:54.830,608] <dbg> net_tcp: tcp_new_reno_log: (rx_q[0]): conn: 0x2002a1b4, ca pkts_acked, cwnd=1704, ssthres=2920, fast_pend=0
    [00:00:54.830,947] <dbg> net_tcp: tcp_in: (rx_q[0]): conn: 0x2002a1b4 total=0, unacked_len=0, send_win=1280, mss=1460
    [00:00:54.831,265] <dbg> net_tcp: tcp_in: (rx_q[0]): conn: 0x2002a1b4 send_data_timer=1, send_data_retries=1
    [00:00:54.870,398] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430370319 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430370319]
    [00:00:54.870,703] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:54.870,979] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:55.061,520] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=430370575 Ack=578723733 Len=0 [ESTABLISHED Seq=578723733 Ack=430370575]
    [00:00:55.061,814] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:55.168,123] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430370575 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430370575]
    [00:00:55.168,427] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:55.168,704] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:55.599,180] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430370831 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430370831]
    [00:00:55.599,484] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:55.599,761] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:55.920,382] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430371087 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430371087]
    [00:00:55.920,681] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:55.920,953] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:56.239,304] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430371343 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430371343]
    [00:00:56.239,609] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:56.239,886] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:56.544,305] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430371599 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430371599]
    [00:00:56.544,610] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:56.544,887] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:56.840,380] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430371855 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430371855]
    [00:00:56.840,684] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:56.841,101] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:57.162,143] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430372111 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430372111]
    [00:00:57.162,448] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:57.162,725] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:57.480,255] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430372367 Ack=578723733 Len=256 [ESTABLISHED Seq=578723733 Ack=430372367]
    [00:00:57.480,561] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:57.480,835] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a060, st=0, user_data=0
    [00:00:57.517,123] <dbg> net_sock: zsock_close_ctx: (): close: ctx=0x20004a00, fd=6
    [00:00:57.517,355] <dbg> net_tcp: net_tcp_recv: (): context: 0x20004a00, cb: 0, user_data: 0
    [00:00:57.517,633] <dbg> net_tcp: net_tcp_put: ():  [ESTABLISHED Seq=578723733 Ack=430372623]
    [00:00:57.517,855] <dbg> net_tcp: net_tcp_put: (): context 0x20004a00 CONNECTED
    [00:00:57.518,071] <dbg> net_tcp: net_tcp_put: (): TCP connection in active close, not disposing yet (waiting 22753ms)
    [00:00:57.518,954] <dbg> net_tcp: net_tcp_put: (): ESTABLISHED->FIN_WAIT_1
    [00:00:57.519,161] <dbg> net_tcp: tcp_conn_unref: (): conn: 0x2002a1b4, ref_count=2
    [00:00:57.519,379] <err> mqtt_helper: mqtt_connect, error: -116
    [00:00:57.519,561] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_TRANSPORT_CONNECTING --> MQTT_STATE_DISCONNECTED
    [00:00:57.519,835] <err> aws_iot: mqtt_helper_connect, error: -116
    [00:00:57.520,009] <err> connection: aws_iot_connect, error: -116
    [00:00:57.756,024] <dbg> net_tcp: tcp_resend_data: (tcp_work): send_data_retries=0
    [00:00:57.800,254] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430372623 Ack=578723733 Len=256 [FIN_WAIT_1 Seq=578723734 Ack=430372623]
    [00:00:57.800,557] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:57.800,918] <dbg> net_tcp: net_tcp_reply_rst: (rx_q[0]): RST Seq=578723733 Len=0
    [00:00:57.801,170] <dbg> net_tcp: tcp_in: (rx_q[0]): FIN_WAIT_1->TIME_WAIT
    [00:00:57.824,139] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=430372879 Ack=578723734 Len=0 [TIME_WAIT Seq=578723734 Ack=430372623]
    [00:00:57.824,432] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:58.058,255] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=430372879 Ack=578723734 Len=0 [TIME_WAIT Seq=578723734 Ack=430372623]
    [00:00:58.058,542] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:58.438,976] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=430372623 Ack=578723734 Len=256 [TIME_WAIT Seq=578723734 Ack=430372623]
    [00:00:58.439,277] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27392 to 1280
    [00:00:58.439,517] <err> net_tcp: conn: 0x2002a1b4, new bytes 257 during TIME-WAIT state sending reset
    [00:00:58.439,881] <dbg> net_tcp: net_tcp_reply_rst: (rx_q[0]): RST Seq=578723734 Len=0
    [00:00:59.300,900] <dbg> net_tcp: tcp_timewait_timeout: (tcp_work): conn: 0x2002a1b4  [TIME_WAIT Seq=578723734 Ack=430372623]
    [00:00:59.301,194] <dbg> net_tcp: tcp_conn_close_debug: (tcp_work): conn: 0x2002a1b4 closed by TCP stack (tcp_timewait_timeout():1867)
    [00:00:59.301,494] <dbg> net_tcp: tcp_conn_close_debug: (tcp_work): TIME_WAIT->CLOSED
    [00:00:59.301,708] <dbg> net_tcp: tcp_conn_unref: (tcp_work): conn: 0x2002a1b4, ref_count=1
    [00:00:59.301,973] <dbg> net_ctx: net_context_unref: (tcp_work): Context 0x20004a00 released

    Any ideas? 

    Best regards,

  • I will first answer Issue 2 and then help with Issue 1.

    Issue 2

    • How should certificates be provisioned on a production device?

    • Can they be embedded in the firmware image and then stored securely by TF-M at runtime?

    • Should they be erased from normal flash afterwards?

    • What’s the typical workflow for securely flashing these assets when manufacturing devices?

    It depends on your risk model.

    But let me explain a a bit around how TLS works on the nRF54L15.
    So it goes something like this.

    As you can see, Mbed TLS runs in NSPE, meaning that the certificates has to be in NSPE when you run TLS, no matter what. 

    So, the the question is, do you want to secure the certificates during rest by for example storing them in the SPE?

    But before you answer that, let me ask you about your risk model:
    What do you want to protect your certificates against?

    Do you want to protect certs from being read?
    Do you want to protect certs from being deleted?
    Do you want to be able to update the certs yourself?
    Do you want to protect the certs from someone else writing them?

    And for each of the points, why?

    Issue 2

    From your latest comment, do I understand correctly that you only get the -116 disconnect error now?

    Do you have any way to get logs from the server?

    What TLS crypto do your server support? 
    And what settings have you enabled on your device to make sure the nRF54L also supports the same?

Reply
  • I will first answer Issue 2 and then help with Issue 1.

    Issue 2

    • How should certificates be provisioned on a production device?

    • Can they be embedded in the firmware image and then stored securely by TF-M at runtime?

    • Should they be erased from normal flash afterwards?

    • What’s the typical workflow for securely flashing these assets when manufacturing devices?

    It depends on your risk model.

    But let me explain a a bit around how TLS works on the nRF54L15.
    So it goes something like this.

    As you can see, Mbed TLS runs in NSPE, meaning that the certificates has to be in NSPE when you run TLS, no matter what. 

    So, the the question is, do you want to secure the certificates during rest by for example storing them in the SPE?

    But before you answer that, let me ask you about your risk model:
    What do you want to protect your certificates against?

    Do you want to protect certs from being read?
    Do you want to protect certs from being deleted?
    Do you want to be able to update the certs yourself?
    Do you want to protect the certs from someone else writing them?

    And for each of the points, why?

    Issue 2

    From your latest comment, do I understand correctly that you only get the -116 disconnect error now?

    Do you have any way to get logs from the server?

    What TLS crypto do your server support? 
    And what settings have you enabled on your device to make sure the nRF54L also supports the same?

Children
  • Hi  ,

    Thank you for the reply.

    Regarding your questions:

    What TLS crypto do your server support? 
    And what settings have you enabled on your device to make sure the nRF54L also supports the same?

    Aws IoT core supports:

    • TLS 1.3

    • TLS 1.2

    For TLS I've these settings:

    CONFIG_MBEDTLS_TLS_LIBRARY=y
    CONFIG_MBEDTLS_X509_LIBRARY=y
    CONFIG_MBEDTLS_RSA_C=y
    CONFIG_MBEDTLS_PKCS1_V15=y
    CONFIG_NET_SOCKETS_TLS_MAX_CONTEXTS=1
    CONFIG_MBEDTLS=y
    CONFIG_MBEDTLS_ENABLE_HEAP=y
    CONFIG_MBEDTLS_SSL_KEEP_PEER_CERTIFICATE=n
    CONFIG_MBEDTLS_SSL_SERVER_NAME_INDICATION=y
    Do you want to protect certs from being read?
    Do you want to protect certs from being deleted?
    Do you want to be able to update the certs yourself?
    Do you want to protect the certs from someone else writing them?

    I want to protect certs from being read essentially, to avoid impersonating of the machine.

    Best regards,

    Fernando Fontes

  • Fernando Fontes said:

    For TLS I've these settings:

    CONFIG_MBEDTLS_TLS_LIBRARY=y
    CONFIG_MBEDTLS_X509_LIBRARY=y
    CONFIG_MBEDTLS_RSA_C=y
    CONFIG_MBEDTLS_PKCS1_V15=y
    CONFIG_NET_SOCKETS_TLS_MAX_CONTEXTS=1
    CONFIG_MBEDTLS=y
    CONFIG_MBEDTLS_ENABLE_HEAP=y
    CONFIG_MBEDTLS_SSL_KEEP_PEER_CERTIFICATE=n
    CONFIG_MBEDTLS_SSL_SERVER_NAME_INDICATION=y

    I dont see any enabling of PSA algorithms in either this or your above prj.conf. 

    Try to enable the same algorithms as the PSA TLS sample.
    PS: Keep an eye out for Kconfig Override Warnings

    Fernando Fontes said:
    I want to protect certs from being read essentially, to avoid impersonating of the machine.

    Good and clear answer!

    So as I said below:
    "As you can see, Mbed TLS runs in NSPE, meaning that the certificates has to be in NSPE when you run TLS, no matter what. "

    That said, you can still store the certs in SPE during rest.
    Looking a bit around to explain this I remembered that we do have provisioning support for credentials for our Wi-Fi solution. And that is "cert handling in the nRF application", which is essentially the same as you do. 

    So I recommend that you have a look at how we do it in the SoftAP Wi-Fi provision sample and the SoftAP Wi-Fi provision library, as well as the docs on Wi-Fi Management.

    Does this explain what you need?

  • Hi, thank you for the ongoing support,

    I dont see any enabling of PSA algorithms in either this or your above prj.conf. 

    Try to enable the same algorithms as the PSA TLS sample.
    PS: Keep an eye out for Kconfig Override Warnings

    I had these:

    CONFIG_NRF_SECURITY=y
    CONFIG_PSA_WANT_ALG_SHA_1=y
    CONFIG_PSA_WANT_ALG_RSA_PKCS1V15_CRYPT=y
    CONFIG_PSA_WANT_ALG_RSA_PKCS1V15_SIGN=y
    CONFIG_PSA_WANT_KEY_TYPE_RSA_PUBLIC_KEY=y
    But I've enabled all the others that you mentioned but still, I'm getting -116.
    I also have a TLS error now sometimes:
    [00:00:25.510,201] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:25.510,477] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a44c, st=0, user_data=0
    [00:00:25.750,041] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=1905346554 Ack=573331281 Len=512 [ESTABLISHED Seq=573331281 Ack=1905346554]
    [00:00:25.750,348] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:25.750,624] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a44c, st=0, user_data=0
    [00:00:25.989,981] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=1905347066 Ack=573331281 Len=512 [ESTABLISHED Seq=573331281 Ack=1905347066]
    [00:00:25.990,288] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:25.990,565] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a44c, st=0, user_data=0
    [00:00:26.229,805] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=1905347578 Ack=573331281 Len=512 [ESTABLISHED Seq=573331281 Ack=1905347578]
    [00:00:26.230,112] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:26.230,388] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a44c, st=0, user_data=0
    [00:00:26.470,041] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=1905348090 Ack=573331281 Len=512 [ESTABLISHED Seq=573331281 Ack=1905348090]
    [00:00:26.470,341] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:26.470,614] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a44c, st=0, user_data=0
    [00:00:26.472,440] <dbg> net_tcp: net_tcp_recv: (): context: 0x20004a00, cb: 0x23a21, user_data: 0
    [00:00:26.473,245] <dbg> net_tcp: tcp_send_data: (): conn: 0x2002a55c total=7, unacked_len=7, send_win=1280, mss=1460
    [00:00:26.473,547] <dbg> net_tcp: tcp_send_data: (): conn: 0x2002a55c send_data_timer=0, send_data_retries=0
    [00:00:26.473,964] <err> net_sock_tls: TLS handshake error: -0x3b00
    [00:00:26.478,312] <dbg> net_sock: zsock_close_ctx: (): close: ctx=0x20004a00, fd=6
    [00:00:26.478,678] <dbg> net_tcp: net_tcp_recv: (): context: 0x20004a00, cb: 0, user_data: 0
    [00:00:26.478,912] <dbg> net_sock: zsock_flush_queue: (): discarding pkt 0x2002a44c
    [00:00:26.479,184] <dbg> net_tcp: net_tcp_put: ():  [ESTABLISHED Seq=573331281 Ack=1905348602]
    [00:00:26.479,408] <dbg> net_tcp: net_tcp_put: (): context 0x20004a00 CONNECTED
    [00:00:26.479,613] <dbg> net_tcp: net_tcp_put: (): conn 0x2002a55c pending 7 bytes
    [00:00:26.479,844] <dbg> net_tcp: tcp_conn_unref: (): conn: 0x2002a55c, ref_count=2
    [00:00:26.480,059] <err> mqtt_helper: mqtt_connect, error: -113
    [00:00:26.480,254] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_TRANSPORT_CONNECTING --> MQTT_STATE_DISCONNECTED
    [00:00:26.480,523] <err> aws_iot: mqtt_helper_connect, error: -113
    [00:00:26.480,697] <err> connection: aws_iot_connect, error: -113
    [00:00:26.692,924] <dbg> net_tcp: tcp_resend_data: (tcp_work): send_data_retries=0
    [00:00:26.693,176] <dbg> net_tcp: tcp_new_reno_log: (tcp_work): conn: 0x2002a55c, ca timeout, cwnd=1460, ssthres=2920, fast_pend=0
    [00:00:26.693,680] <dbg> net_tcp: tcp_send_data: (tcp_work): conn: 0x2002a55c total=7, unacked_len=7, send_win=1280, mss=1460
    [00:00:26.694,021] <dbg> net_tcp: tcp_send_data: (tcp_work): conn: 0x2002a55c send_data_timer=0, send_data_retries=0
    [00:00:26.730,618] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=1905348602 Ack=573331281 Len=371 [ESTABLISHED Seq=573331281 Ack=1905348602]
    [00:00:26.730,926] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:26.731,533] <dbg> net_tcp: tcp_in: (rx_q[0]): FIN,ACK Seq=1905348973 Ack=573331288 Len=0 [ESTABLISHED Seq=573331281 Ack=1905348973]
    [00:00:26.731,836] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:26.732,204] <dbg> net_tcp: tcp_setup_last_ack_timer: (rx_q[0]): TCP connection in passive close, not disposing yet (waiting 22753ms)
    [00:00:26.732,525] <dbg> net_tcp: tcp_in: (rx_q[0]): ESTABLISHED->LAST_ACK
    [00:00:26.852,418] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=1905348974 Ack=573331288 Len=0 [LAST_ACK Seq=573331289 Ack=1905348974]
    [00:00:26.852,711] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:26.912,202] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=1905348974 Ack=573331288 Len=0 [LAST_ACK Seq=573331289 Ack=1905348974]
    [00:00:26.912,496] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:26.945,272] <dbg> net_tcp: tcp_resend_data: (tcp_work): send_data_retries=0
    [00:00:27.129,325] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=1905348974 Ack=573331289 Len=0 [LAST_ACK Seq=573331289 Ack=1905348974]
    [00:00:27.129,617] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:27.129,876] <dbg> net_tcp: tcp_conn_close_debug: (rx_q[0]): conn: 0x2002a55c closed by TCP stack (tcp_in():3489)
    [00:00:27.130,157] <dbg> net_tcp: tcp_conn_close_debug: (rx_q[0]): LAST_ACK->CLOSED
    [00:00:27.130,369] <dbg> net_tcp: tcp_conn_unref: (rx_q[0]): conn: 0x2002a55c, ref_count=1
    [00:00:27.130,643] <dbg> net_ctx: net_context_unref: (tcp_work): Context 0x20004a00 released
    I also still see timeouts on different attempts:
    [00:00:27.379,960] <dbg> net_sock: zsock_received_cb: (rx_q[0]): ctx=0x20004a00, pkt=0x2002a44c, st=0, user_data=0
    [00:00:27.416,641] <dbg> net_sock: zsock_close_ctx: (): close: ctx=0x20004a00, fd=6
    [00:00:27.416,873] <dbg> net_tcp: net_tcp_recv: (): context: 0x20004a00, cb: 0, user_data: 0
    [00:00:27.417,152] <dbg> net_tcp: net_tcp_put: ():  [ESTABLISHED Seq=578166781 Ack=3654714008]
    [00:00:27.417,376] <dbg> net_tcp: net_tcp_put: (): context 0x20004a00 CONNECTED
    [00:00:27.417,592] <dbg> net_tcp: net_tcp_put: (): TCP connection in active close, not disposing yet (waiting 22753ms)
    [00:00:27.418,278] <dbg> net_tcp: net_tcp_put: (): ESTABLISHED->FIN_WAIT_1
    [00:00:27.418,483] <dbg> net_tcp: tcp_conn_unref: (): conn: 0x2002a55c, ref_count=2
    [00:00:27.418,703] <err> mqtt_helper: mqtt_connect, error: -116
    [00:00:27.418,882] <dbg> mqtt_helper: mqtt_state_set: State transition: MQTT_STATE_TRANSPORT_CONNECTING --> MQTT_STATE_DISCONNECTED
    [00:00:27.419,154] <err> aws_iot: mqtt_helper_connect, error: -116
    [00:00:27.419,328] <err> connection: aws_iot_connect, error: -116
    [00:00:27.703,358] <dbg> net_tcp: tcp_resend_data: (tcp_work): send_data_retries=0
    [00:00:27.739,331] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=3654714008 Ack=578166781 Len=512 [FIN_WAIT_1 Seq=578166782 Ack=3654714008]
    [00:00:27.739,636] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:27.739,996] <dbg> net_tcp: net_tcp_reply_rst: (rx_q[0]): RST Seq=578166781 Len=0
    [00:00:27.740,247] <dbg> net_tcp: tcp_in: (rx_q[0]): FIN_WAIT_1->TIME_WAIT
    [00:00:27.740,825] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=3654714520 Ack=578166782 Len=0 [TIME_WAIT Seq=578166782 Ack=3654714008]
    [00:00:27.741,118] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:27.998,799] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK Seq=3654714520 Ack=578166782 Len=0 [TIME_WAIT Seq=578166782 Ack=3654714008]
    [00:00:27.999,088] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:28.030,475] <inf> sanitation_handler: [KP] Msta.: IDLE
    [00:00:28.030,673] <inf> sanitation_handler: [IC] Msta.: RUNNING
    [00:00:28.030,865] <inf> sanitation_handler: [CC] Msta.: IDLE
    [00:00:28.031,058] <inf> sanitation_handler: [WF] Msta.: IDLE
    [00:00:28.331,047] <inf> sanitation_handler: [DP] Msta.: IDLE
    [00:00:28.331,256] <inf> sanitation_handler: [FJ] Msta.: IDLE
    [00:00:28.379,026] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,PSH Seq=3654714008 Ack=578166782 Len=512 [TIME_WAIT Seq=578166782 Ack=3654714008]
    [00:00:28.379,329] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 27648 to 1280
    [00:00:28.379,569] <err> net_tcp: conn: 0x2002a55c, new bytes 513 during TIME-WAIT state sending reset
    [00:00:28.379,932] <dbg> net_tcp: net_tcp_reply_rst: (rx_q[0]): RST Seq=578166782 Len=0
    [00:00:29.239,974] <dbg> net_tcp: tcp_timewait_timeout: (tcp_work): conn: 0x2002a55c  [TIME_WAIT Seq=578166782 Ack=3654714008]
    [00:00:29.240,269] <dbg> net_tcp: tcp_conn_close_debug: (tcp_work): conn: 0x2002a55c closed by TCP stack (tcp_timewait_timeout():1867)
    [00:00:29.240,569] <dbg> net_tcp: tcp_conn_close_debug: (tcp_work): TIME_WAIT->CLOSED
    [00:00:29.240,784] <dbg> net_tcp: tcp_conn_unref: (tcp_work): conn: 0x2002a55c, ref_count=1
    [00:00:29.241,049] <dbg> net_ctx: net_context_unref: (tcp_work): Context 0x20004a00 released
    Could it still be priority issues related for the timeouts at least?
    What about the TLS error? It seems that the MCU is rejecting the CA certs from AWS. But I've checked more than once and I'm doing the provision as the examples:
        ret = tls_credential_add(CONFIG_MQTT_HELPER_SEC_TAG, TLS_CREDENTIAL_SERVER_CERTIFICATE, public_cert, public_cert_len);
        if (ret < 0)
        {
            LOG_ERR("Failed to add device certificate: %d", ret);
            goto exit;
        }
    
        ret = tls_credential_add(CONFIG_MQTT_HELPER_SEC_TAG, TLS_CREDENTIAL_PRIVATE_KEY, private_key, private_key_len);
        if (ret < 0)
        {
            LOG_ERR("Failed to add device private key: %d", ret);
            goto exit;
        }
    
        ret = tls_credential_add(CONFIG_MQTT_HELPER_SEC_TAG, TLS_CREDENTIAL_CA_CERTIFICATE, ca_cert, ca_cert_len);
        if (ret < 0)
        {
            LOG_ERR("Failed to add device private key: %d", ret);
            goto exit;
        }
    and I've used the convertkeys.py to generate the ca.c, cert.c and key.c files which are properly imported on the CMAKE:
    # Copyright (c) 2023 Lucas Dietrich <[email protected]>
    # SPDX-License-Identifier: Apache-2.0
    
    import glob
    import os
    
    
    def bin2array(name, fin, fout):
        with open(fin, 'rb') as f:
            data = f.read()
    
        data += b'\0'  # add null terminator
    
        with open(fout, 'w') as f:
            f.write("#include <stdint.h>\n")
            f.write(f"const uint8_t {name}[] = {{")
            for i in range(0, len(data), 16):
                f.write("\n\t")
                f.write(", ".join(f"0x{b:02x}" for b in data[i:i+16]))
                f.write(",")
            f.write("\n};\n")
            f.write(f"const uint32_t {name}_len = sizeof({name});\n")
    
        print(
            f"[{name.center(13, ' ')}]: {os.path.relpath(fin)} -> {os.path.relpath(fout)}")
    
    
    if __name__ == "__main__":
        creds_dir = os.path.dirname(os.path.realpath(__file__))
    
        creds = glob.glob(f"{creds_dir}/*.pem.*")
    
        cert_found, key_found = False, False
    
        for cred in creds:
            if cred.endswith('-certificate.pem.crt'):
                bin2array("public_cert", cred, os.path.join(creds_dir, "cert.c"))
                cert_found = True
            elif cred.endswith('-private.pem.key'):
                bin2array("private_key", cred, os.path.join(creds_dir, "key.c"))
                key_found = True
    
        if not cert_found:
            print("No certificate found !")
        if not key_found:
            print("No private key found !")
    
        bin2array("ca_cert", os.path.join(creds_dir, "AmazonRootCA1.pem"),
                  os.path.join(creds_dir, "ca.c"))
    

    I see that the CA certfile is received correctly by the MCU...
    Best regards,
  • I want to protect certs from being read essentially, to avoid impersonating of the machine.

    This does not make sense. A certificate does not contain any secret credentials; just identity information, public keys and signatures etc. Note that certificates are also typically sent in plaintext over the air (at least with TLS 1.2). What would make sense to store in a secure storage is the private key matching a certificate's public key, which is only useful in case you want that the server should authenticate the client (assuming nRF54 is the TLS client).

  • I see that the CA certfile is received correctly by the MCU...
    Best regards,

    Ok, I was actually able to trace the TLS error that was mentioning that the cert file was not supported and after going through multiple samples and comparing the proj.conf I finally got it working and the Handshake was successufully done. 

    However, I was still hitting error -116 which was timeout?? Then at some point it worked without changing anything... 

    I've increased CONFIG_MBEDTLS_HEAP_SIZE=90000 and now it seems to work at first attempt most of the times, but still not sure if that was it. The value before was 45000. The problem is that my ram is now at 93%... And I'm afraid I will not have enough for the rest of the application.

    Will leave it for now this way and after having the FOTA working I might go back to this and try to optimize... 

Related