Call to sys_reboot() on nRF52840 causes hard fault

[GameCodingNinja]

Currently on SDK v2.3.0 but this problem has persisted no matter the SDK version. Here's the fault info.

[00:00:34.898,223] <err> mpsl_init: MPSL ASSERT: 112, 2195
[00:02:03.002,807] <err> os: ***** HARD FAULT *****
[00:02:03.002,807] <err> os: Fault escalation (see below)
[00:02:03.002,838] <err> os: ARCH_EXCEPT with reason 3

[00:02:03.002,838] <err> os: r0/a1: 0x00000003 r1/a2: 0x00000000 r2/a3: 0x000000bf
[00:02:03.002,838] <err> os: r3/a4: 0x00000000 r12/ip: 0x20001918 r14/lr: 0x00000000
[00:02:03.002,868] <err> os: xpsr: 0x61000018
[00:02:03.002,868] <err> os: Faulting instruction address (r15/pc): 0x0002caf8
[00:02:03.002,899] <err> os: >>> ZEPHYR FATAL ERROR 3: Kernel oops on CPU 0
[00:02:03.002,929] <err> os: Fault during interrupt handling

[00:02:03.002,960] <err> os: Current thread: 0x20002d18 (unknown)
[00:02:04.186,157] <err> fatal_error: Resetting system

I have CONFIG_REBOOT=y listed in the prj.conf file. I try to step into sys_reboot and it immediately jumps to arch_irq_lock and faults. I look through the sample projects that reboot and I don't see anything that I'm missing in the prj.conf. Not sure what to think.

Any incite would be appreciated.

[Einar Thorsrud]

Hi,

The log here shows that you get an MPSL assert which is a direct consequence of the MPSL loosing track of time due to continuing from a breakpoint or stepping. So this is a direct consequence of your debugging and not the error you are attempting to debug. Instead of stepping or continuing form a breakpoint, you can mimic the same behavior by using a breakpoint, and moving it before resetting.

Can you say more about the issue you are seeing and what you find by debugging/logging?

[GameCodingNinja]

Hi Einar,

Thanks for taking out the time to help!

Tring to reboot just appears to freeze the 52840 but what I discovered recently is that if I let it sit long enough, it appears to have rebooted. Takes about 2 minutes, 30 seconds.

Within Ozone, it will sit there and not show any signs of anything wrong. Not sure what to make of all this.

[Einar Thorsrud]

How have you verified that the device does not reset? And how do you reset it (how do you call sys_reboot())? What if you simply do a NVIC_SystemReset()?

[GameCodingNinja]

I added log print to the RTT Console every 10 seconds as a heart beat to know it's still active.

for(;;)
{
    static uint32_t counter = 0;

    if(counter == 5)
    {
        LOG_INF("Will now reboot in 2 seconds.");
        k_sleep(K_SECONDS(2));
        NVIC_SystemReset();
        //sys_reboot(SYS_REBOOT_WARM);
    }

    LOG_DBG("Alive 10 second counter: %d", counter++);
    k_sleep(K_SECONDS(10));
}

I then added a counter so that it reboots when it reaches 5. The addition of 

NVIC_SystemReset() made no difference. Behavior is still the same.

Here's my prj.conf

# C++ enable flags. Adds in up to C++20 
CONFIG_CPLUSPLUS=n
CONFIG_LIB_CPLUSPLUS=n

# Optimize for debug
CONFIG_NO_OPTIMIZATIONS=n
CONFIG_DEBUG_OPTIMIZATIONS=n
CONFIG_DEBUG=n

# General config
CONFIG_NEWLIB_LIBC=y
CONFIG_NEWLIB_LIBC_FLOAT_PRINTF=n
CONFIG_ASSERT=n
CONFIG_REBOOT=y
CONFIG_FPU=n

CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC=y
CONFIG_CLOCK_CONTROL_NRF_K32SRC_XTAL=n

# Enable the UART driver
CONFIG_UART_ASYNC_API=y
CONFIG_NRFX_UARTE0=y
CONFIG_SERIAL=y
CONFIG_UART_NRFX=y
CONFIG_UART_INTERRUPT_DRIVEN=y

# Make sure printk is printing to the UART console
CONFIG_PRINTK=n

# Heap and stacks
CONFIG_HEAP_MEM_POOL_SIZE=4096
CONFIG_MAIN_STACK_SIZE=2048
CONFIG_MAIN_THREAD_PRIORITY=-10
CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=4096

CONFIG_BT=y
CONFIG_BT_PERIPHERAL=y
CONFIG_BT_DEVICE_NAME="Orbis_UART_Service"
CONFIG_BT_DEVICE_APPEARANCE=833
CONFIG_BT_MAX_CONN=1
CONFIG_BT_MAX_PAIRED=1

# Enable the NUS service
CONFIG_BT_NUS=y

# Enable bonding
CONFIG_BT_SETTINGS=y
CONFIG_FLASH=y
CONFIG_FLASH_PAGE_LAYOUT=y
CONFIG_FLASH_MAP=y
CONFIG_NVS=y
CONFIG_SETTINGS=y

# Enable DK LED and Buttons library
CONFIG_DK_LIBRARY=y

# Config logger
CONFIG_LOG=y
CONFIG_USE_SEGGER_RTT=y
CONFIG_LOG_BACKEND_RTT=y
CONFIG_LOG_BACKEND_UART=n

# Image manager
CONFIG_IMG_MANAGER=y
CONFIG_FLASH=y
CONFIG_IMG_ERASE_PROGRESSIVELY=y

# DFU Target
CONFIG_DFU_TARGET=y

# Application Upgrade support
CONFIG_BOOTLOADER_MCUBOOT=y

This is the output from the RTT Console.

*** Booting Zephyr OS build v3.2.99-ncs2 ***
[00:00:00.007,171] \033[0m<inf> fs_nvs: 2 Sectors of 4096 bytes\033[0m
[00:00:00.007,171] \033[0m<inf> fs_nvs: alloc wra: 0, fc8\033[0m
[00:00:00.007,171] \033[0m<inf> fs_nvs: data wra: 0, 2c\033[0m
[00:00:00.007,263] \033[0m<inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
                                            d8 0c 2d 2f 36 ae e2 5c  80 26 80 4c 3f 4d 16 53 |..-/6..\ .&.L?M.S
                                            50 96 c7 73                                      |P..s             \033[0m
[00:00:00.010,131] \033[0m<inf> bt_hci_core: No ID address. App must call settings_load()\033[0m
[00:00:00.010,131] \033[0m<inf> MAIN: Bluetooth initialized\033[0m
[00:00:00.010,192] \033[0m<inf> MAIN: Firmware Version: D1.4.24\033[0m
[00:00:00.010,192] \033[0m<dbg> MAIN: main: Settings loaded\033[0m
[00:00:00.010,833] \033[0m<dbg> BLE: uart_init: UART initialized\033[0m
[00:00:00.010,864] \033[0m<dbg> MAIN: main: Alive 10 second counter: 0\033[0m
[00:00:10.010,925] \033[0m<dbg> MAIN: main: Alive 10 second counter: 1\033[0m
[00:00:14.005,340] \033[0m<inf> BLE: Advertising started.\033[0m
[00:00:20.010,986] \033[0m<dbg> MAIN: main: Alive 10 second counter: 2\033[0m
[00:00:30.011,047] \033[0m<dbg> MAIN: main: Alive 10 second counter: 3\033[0m
[00:00:40.011,108] \033[0m<dbg> MAIN: main: Alive 10 second counter: 4\033[0m
[00:00:50.011,169] \033[0m<inf> MAIN: Will now reboot in 2 seconds.\033[0m
*** Booting Zephyr OS build v3.2.99-ncs2 ***
[00:00:00.007,476] \033[0m<inf> fs_nvs: 2 Sectors of 4096 bytes\033[0m
[00:00:00.007,507] \033[0m<inf> fs_nvs: alloc wra: 0, fc8\033[0m
[00:00:00.007,507] \033[0m<inf> fs_nvs: data wra: 0, 2c\033[0m
[00:00:00.007,598] \033[0m<inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
                                            d8 0c 2d 2f 36 ae e2 5c  80 26 80 4c 3f 4d 16 53 |..-/6..\ .&.L?M.S
                                            50 96 c7 73                                      |P..s             \033[0m
[00:00:00.010,467] \033[0m<inf> bt_hci_core: No ID address. App must call settings_load()\033[0m
[00:00:00.010,467] \033[0m<inf> MAIN: Bluetooth initialized\033[0m
[00:00:00.010,498] \033[0m<inf> MAIN: Firmware Version: D1.4.24\033[0m
[00:00:00.010,528] \033[0m<dbg> MAIN: main: Settings loaded\033[0m
[00:00:00.011,169] \033[0m<dbg> BLE: uart_init: UART initialized\033[0m
[00:00:00.011,169] \033[0m<dbg> MAIN: main: Alive 10 second counter: 0\033[0m
[00:00:10.011,260] \033[0m<dbg> MAIN: main: Alive 10 second counter: 1\033[0m
[00:00:20.011,322] \033[0m<dbg> MAIN: main: Alive 10 second counter: 2\033[0m
[00:00:30.011,383] \033[0m<dbg> MAIN: main: Alive 10 second counter: 3\033[0m
[00:00:40.011,444] \033[0m<dbg> MAIN: main: Alive 10 second counter: 4\033[0m
[00:00:50.011,505] \033[0m<inf> MAIN: Will now reboot in 2 seconds.\033[0m
*** Booting Zephyr OS build v3.2.99-ncs2 ***
[00:00:00.007,141] \033[0m<inf> fs_nvs: 2 Sectors of 4096 bytes\033[0m
[00:00:00.007,171] \033[0m<inf> fs_nvs: alloc wra: 0, fc8\033[0m
[00:00:00.007,171] \033[0m<inf> fs_nvs: data wra: 0, 2c\033[0m
[00:00:00.007,263] \033[0m<inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
                                            d8 0c 2d 2f 36 ae e2 5c  80 26 80 4c 3f 4d 16 53 |..-/6..\ .&.L?M.S
                                            50 96 c7 73                                      |P..s             \033[0m
[00:00:00.010,131] \033[0m<inf> bt_hci_core: No ID address. App must call settings_load()\033[0m
[00:00:00.010,131] \033[0m<inf> MAIN: Bluetooth initialized\033[0m
[00:00:00.010,192] \033[0m<inf> MAIN: Firmware Version: D1.4.24\033[0m
[00:00:00.010,192] \033[0m<dbg> MAIN: main: Settings loaded\033[0m
[00:00:00.010,833] \033[0m<dbg> BLE: uart_init: UART initialized\033[0m
[00:00:00.010,864] \033[0m<dbg> MAIN: main: Alive 10 second counter: 0\033[0m
[00:00:10.010,925] \033[0m<dbg> MAIN: main: Alive 10 second counter: 1\033[0m
[00:00:20.010,986] \033[0m<dbg> MAIN: main: Alive 10 second counter: 2\033[0m
[00:00:30.011,047] \033[0m<dbg> MAIN: main: Alive 10 second counter: 3\033[0m
[00:00:40.011,108] \033[0m<dbg> MAIN: main: Alive 10 second counter: 4\033[0m
[00:00:50.011,169] \033[0m<inf> MAIN: Will now reboot in 2 seconds.\033[0m
*** Booting Zephyr OS build v3.2.99-ncs2 ***
[00:00:00.007,476] \033[0m<inf> fs_nvs: 2 Sectors of 4096 bytes\033[0m
[00:00:00.007,507] \033[0m<inf> fs_nvs: alloc wra: 0, fc8\033[0m
[00:00:00.007,507] \033[0m<inf> fs_nvs: data wra: 0, 2c\033[0m
[00:00:00.007,598] \033[0m<inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
                                            d8 0c 2d 2f 36 ae e2 5c  80 26 80 4c 3f 4d 16 53 |..-/6..\ .&.L?M.S
                                            50 96 c7 73                                      |P..s             \033[0m
[00:00:00.010,437] \033[0m<inf> bt_hci_core: No ID address. App must call settings_load()\033[0m
[00:00:00.010,467] \033[0m<inf> MAIN: Bluetooth initialized\033[0m
[00:00:00.010,498] \033[0m<inf> MAIN: Firmware Version: D1.4.24\033[0m
[00:00:00.010,498] \033[0m<dbg> MAIN: main: Settings loaded\033[0m
[00:00:00.011,138] \033[0m<dbg> BLE: uart_init: UART initialized\033[0m
[00:00:00.011,169] \033[0m<dbg> MAIN: main: Alive 10 second counter: 0\033[0m
[00:00:10.011,230] \033[0m<dbg> MAIN: main: Alive 10 second counter: 1\033[0m
[00:00:20.011,291] \033[0m<dbg> MAIN: main: Alive 10 second counter: 2\033[0m
[00:00:30.011,352] \033[0m<dbg> MAIN: main: Alive 10 second counter: 3\033[0m
[00:00:40.011,413] \033[0m<dbg> MAIN: main: Alive 10 second counter: 4\033[0m
[00:00:50.011,474] \033[0m<inf> MAIN: Will now reboot in 2 seconds.\033[0m

[Einar Thorsrud]

Hi,

I see from the log that there are repeated resets, but is it still so that there is a long delay between each of them (you wrote  about 2 minutes, 30 seconds)? I wonder what happens during this time...

Can you read, print and clear the RESETREAS register so that we see that in the log? (You can for instance copy-paste the reset_reason_print() from nrf/samples/bluetooth/peripheral_power_profiling/src/main.c). Are you testing on your custom HW? If so, can you describe it? Also, it would be good if you could test this on a DK to see if you see the same behavior there as on your HW.