TF-M crash with certain UART baud rate settings in nRF9160

[e-va]

Dear Nordic Team!

We are struggling with a fatal error occurring during boot phase before entering the application main. When setting the baud rate of UART2 to 38400 or higher, the SPU detects some kind of violation, leading to SPU fault. This also occurs when we copy the device tree in the attachment and some of our prj.conf contents to the lwm2m_client example project. This occurs in both SDK 2.4.2 and 2.5.99-dev1. When running at a baud rate below 38400, the application works as intended and UART communication is ok on UART2.

*** Booting nRF Connect SDK v2.5.99-dev1 ***
I: Starting bootloader
I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: none
I: Image index: 0, Swap type: none
I: Bootloader chainload address offset: 0x10000
FATAL ERROR: Platform Exceptionlot
Platform Exception: SPU Fault

The prj.conf lines, which we added to cause the error.

# LTE link control
CONFIG_LTE_LINK_CONTROL=y

# Modem info
CONFIG_MODEM_INFO=y

# Enable settings storage
CONFIG_SETTINGS=y
CONFIG_FCB=y
CONFIG_SETTINGS_FCB=y
CONFIG_FLASH_MAP=y
CONFIG_STREAM_FLASH=y

# Allow FOTA downloads using download-client
CONFIG_LWM2M_CLIENT_UTILS=y
CONFIG_LWM2M_CLIENT_UTILS_FIRMWARE_UPDATE_OBJ_SUPPORT=y
CONFIG_DOWNLOAD_CLIENT=y
CONFIG_DOWNLOAD_CLIENT_STACK_SIZE=4096
CONFIG_DOWNLOAD_CLIENT_HTTP_FRAG_SIZE_1024=y
CONFIG_FOTA_DOWNLOAD=y

We cannot find out how the fatal error could be caused by the UART baud rate setting. Does UART in some way interfere with the boot process?

Thank you

pcb_v70_common.dts

[Øyvind]

Hello, 

Are you using a custom board? Do you see the same behavior on the nRF9160DK or Thingy:91? What are you using UART2 for? 

Please provide more details for me to reproduce.

Kind regards,
Øyvind

[e-va]

Yes we are using a custom board, and it also happens when we flash the binary to the Nordic nRF9160 Devkit. We created a custom Devicetree, which is attached in the initial post. UART2 is intended to be used for inter-processor communication with a Silicon Labs Bluetooth device.

[Øyvind]

Can you please provide you whole project which works for the nRF9160DK?

[e-va]

Here's the lwm2m_client sample + modified board definition. A TODO in nrf9160dk_nrf9160_common.dts states how to trigger (current setting) and disable the problem.

5344.lwm2m_client.zip

[Øyvind]

Hello, 
I'm not seeing the SPU fault on my side. I do however see the following errors:

uart:~$ *** Booting Zephyr OS build v3.3.99-ncs1-1 ***


*** Booting Zephyr OS build v3.3.99-ncs1-1 ***
[00:00:00.255,126] <dbg> net_lwm2m_engine: lwm2m_engine_init: LWM2M engine socket receive thread started
[00:00:00.255,218] <dbg> net_lwm2m_obj_security: security_create: Create LWM2M security instance: 0
[00:00:00.255,279] <dbg> net_lwm2m_obj_server: server_create: Create LWM2M server instance: 0
[00:00:00.255,401] <dbg> net_lwm2m_obj_device: device_create: Create LWM2M device instance: 0
[00:00:00.255,462] <dbg> net_lwm2m_obj_conn_mon: connmon_create: Create LWM2M connectivity monitoring instance: 0
[00:00:00.255,523] <dbg> net_lwm2m_obj_firmware: firmware_create: Create LWM2M firmware instance: 0
[00:00:00.255,554] <dbg> net_lwm2m_obj_location: location_create: Create Location instance: 0
[00:00:00.255,767] <inf> net_config: Initializing network
[00:00:00.255,767] <inf> net_config: Waiting interface 1 (0x2000d488) to be up...
[00:00:30.256,744] <err> net_config: Timeout while waiting network interface
[00:00:30.256,774] <err> net_config: Network initialization failed (-115)
[00:00:30.256,805] <inf> net_lwm2m_client_app: Run LWM2M client
[00:00:30.256,805] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:0/0/0, buf:0x49473, len:21
[00:00:30.256,866] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:0/0/2, buf:0x2001960f, len:1
[00:00:30.256,896] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:0/0/10, buf:0x2001960e, len:2
[00:00:30.256,927] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:1/0/0, buf:0x2001960e, len:2
[00:00:30.257,263] <dbg> net_ipso_temp_sensor: temp_sensor_create: Create IPSO Temperature Sensor instance: 0
[00:00:30.257,324] <dbg> net_ipso_light_control: light_control_create: Create IPSO Light Control instance: 0
[00:00:30.257,446] <dbg> net_ipso_timer: timer_inst_create: Create IPSO Timer instance: 0
[00:00:30.257,598] <inf> net_lwm2m_rd_client: Start LWM2M Client: nrf9160dk_nrf9160
[00:00:30.258,148] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:3303/0/5700, buf:0x20019de8, len:8
[00:00:30.758,422] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/1/0, level 3, buf:0x200188bf, buflen:1
[00:00:30.758,483] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/10/0, level 3, buf:0x200188ee, buflen:2
[00:00:30.758,514] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x200188a8, buflen:4
[00:00:30.758,575] <inf> net_lwm2m_rd_client: RD Client started with endpoint 'nrf9160dk_nrf9160' with client lifetime 30
[00:00:30.758,636] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coap://192.0.2.2:5683
[00:00:30.758,728] <err> net_lwm2m_engine: Failed to create socket: 23
[00:00:30.758,758] <err> net_lwm2m_rd_client: Cannot init LWM2M engine (-23)
[00:00:31.758,972] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/1/0, level 3, buf:0x200188bf, buflen:1
[00:00:31.759,002] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/10/0, level 3, buf:0x200188ee, buflen:2
[00:00:31.759,033] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x200188a8, buflen:4
[00:00:31.759,094] <inf> net_lwm2m_rd_client: RD Client started with endpoint 'nrf9160dk_nrf9160' with client lifetime 30
[00:00:31.759,155] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coap://192.0.2.2:5683
[00:00:31.759,277] <err> net_lwm2m_engine: Failed to create socket: 23
[00:00:31.759,277] <err> net_lwm2m_rd_client: Cannot init LWM2M engine (-23)
[00:00:33.259,582] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/1/0, level 3, buf:0x200188bf, buflen:1
[00:00:33.259,643] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/10/0, level 3, buf:0x200188ee, buflen:2
[00:00:33.259,674] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x200188a8, buflen:4
[00:00:33.259,735] <inf> net_lwm2m_rd_client: RD Client started with endpoint 'nrf9160dk_nrf9160' with client lifetime 30
[00:00:33.259,765] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coap://192.0.2.2:5683
[00:00:33.259,887] <err> net_lwm2m_engine: Failed to create socket: 23
[00:00:33.259,887] <err> net_lwm2m_rd_client: Cannot init LWM2M engine (-23)
[00:00:35.760,375] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/1/0, level 3, buf:0x200188bf, buflen:1
[00:00:35.760,437] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/10/0, level 3, buf:0x200188ee, buflen:2
[00:00:35.760,467] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x200188a8, buflen:4
[00:00:35.760,528] <inf> net_lwm2m_rd_client: RD Client started with endpoint 'nrf9160dk_nrf9160' with client lifetime 30
[00:00:35.760,559] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coap://192.0.2.2:5683
[00:00:35.760,681] <err> net_lwm2m_engine: Failed to create socket: 23
[00:00:35.760,681] <err> net_lwm2m_rd_client: Cannot init LWM2M engine (-23)
[00:00:40.261,657] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/1/0, level 3, buf:0x200188bf, buflen:1
[00:00:40.261,718] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/10/0, level 3, buf:0x200188ee, buflen:2
[00:00:40.261,749] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x200188a8, buflen:4
[00:00:40.261,779] <inf> net_lwm2m_rd_client: RD Client started with endpoint 'nrf9160dk_nrf9160' with client lifetime 30
[00:00:40.261,840] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coap://192.0.2.2:5683
[00:00:40.261,962] <err> net_lwm2m_engine: Failed to create socket: 23
[00:00:40.261,962] <err> net_lwm2m_rd_client: Cannot init LWM2M engine (-23)
[00:00:48.763,580] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/1/0, level 3, buf:0x200188bf, buflen:1
[00:00:48.763,641] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/0/10/0, level 3, buf:0x200188ee, buflen:2
[00:00:48.763,671] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x200188a8, buflen:4
[00:00:48.763,732] <inf> net_lwm2m_rd_client: RD Client started with endpoint 'nrf9160dk_nrf9160' with client lifetime 30
[00:00:48.763,763] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coap://192.0.2.2:5683
[00:00:48.763,885] <err> net_lwm2m_engine: Failed to create socket: 23
[00:00:48.763,885] <err> net_lwm2m_rd_client: Cannot init LWM2M engine (-23)
[00:00:48.763,916] <err> net_lwm2m_client_app: LwM2M engine reported a network error.

Is your project based on our Lwm2m_client? Do you build with any of the included overlays? 

[e-va]

Hello,

we have found out that the error occurs on the provided sample always if the uart2 RX pin 23 is tied 'high' (IO supply voltage). It does not occur when setting to 'low' (GND). The same behavior can be observed when swapping the pin control assignments between uart1 and uart2 as follows. In this case, the error is triggered by setting pin 0 to 'high'.

arduino_serial: &uart1 {
	status = "okay";
	current-speed = <115200>;
	pinctrl-0 = <&uart2_default>;
	pinctrl-1 = <&uart2_sleep>;
	pinctrl-names = "default", "sleep";
};

&uart2 {
	status = "okay";
	current-speed = <115200>; /* TODO: change baudrate here 28800 (working) <=> 38400 (not working) */
	pinctrl-0 = <&uart1_default>;
	pinctrl-1 = <&uart1_sleep>;
	pinctrl-names = "default", "sleep";
};

This strange behavior was observed on two devkits with the B1 revision and also on one devkit with the B0 revision nRF9160. The modem firmware was 1.3.5 in all cases. We could not try it on the nRF9161 as we were not able to obtain one yet. A binary is attached at the end.

Kind regards

8228.merged.hex

[Hieu]

Hi e-va,

Could you please try to enable TF-M logging to see if it can give us any clues?

Best regards,

Hieu

[e-va]

Hi,

this is the entire uart1 TFM output.

FATAL ERROR: Platform Exception
Platform Exception: SPU Fault

Best regards

[Hieu]

Hi e-va,

Ok... it is very unfortunate that there is no clear clue there.

We will continue to investigate this and follow-up with you.

Best regards,

Hieu

---

P.s: I actually also think about increasing the log level, but as the default level is already INFO, I don't have high hope for it. If it's not too much, do you mind retrying with increased log level as well? You can use these configs:

CONFIG_TFM_PARTITION_LOG_LEVEL_DEBUG
CONFIG_TFM_SPM_LOG_LEVEL_DEBUG