After DFU update, device fail to initialize mesh stack configuration

[Danish_Riaz]

Hi, I am using light lightness server example for the testing of DFU OTA over mesh. I have successfully transferred the DFU archive over serial with nRF Util tool and follow the steps as described in the nrf5 SDK for mesh. After DFU update device restart and return "app_error_weak.c,  105, Mesh assert at 0x0002AC42 (:0)" when initializating mesh stack.

This is light lightness example with DFU functionality:

#include <stdint.h>

/* HAL */
//#include "boards.h"

/* Core */
#include "nrf_mesh_config_core.h"
#include "nrf_mesh_gatt.h"
#include "nrf_mesh_configure.h"
#include "nrf_mesh_events.h"
#include "nrf_mesh_config_examples.h"
#include "nrf_mesh.h"
#include "mesh_stack.h"
#include "mesh_config.h"
#include "device_state_manager.h"
#include "access_config.h"
#include "proxy.h"

/* Provisioning and configuration */
#include "mesh_provisionee.h"
#include "mesh_app_utils.h"

/* Logging and RTT */
#include "log.h"
#include "rtt_input.h"

/* Example specific includes */
#include "app_light_lightness.h"
#include "app_config.h"
#include "example_common.h"
#include "pwm_utils.h"
#include "light_lightness_utils.h"
#include "ble_softdevice_support.h"
#include "model_config_file.h"
#include "app_timer.h"
#include "app_scene.h"


#include "nrf_mesh_dfu.h"
#include "app_util.h"
#include "nrf_mesh_events.h"
#include "nrf_mesh_serial.h"

/*****************************************************************************
 * Definitions
 *****************************************************************************/
/* Client lightness parameter step size */
#define APP_LIGHTNESS_STEP_SIZE     (16384L)
/* Controls if the model instance should force all mesh messages to be segmented messages. */
#define APP_FORCE_SEGMENTATION      (false)
/* Controls the MIC size used by the model instance for sending the mesh messages. */
#define APP_MIC_SIZE                (NRF_MESH_TRANSMIC_SIZE_SMALL)
/* Gives the light lightness element index. */
#define APP_LL_ELEMENT_INDEX        (0)


/*****************************************************************************
 * Forward declaration of static functions
 *****************************************************************************/
static void mesh_events_handle(const nrf_mesh_evt_t * p_evt);
static void set_lightness_cb(const app_light_lightness_setup_server_t * p_app, uint16_t lightness);
static void get_lightness_cb(const app_light_lightness_setup_server_t * p_app, uint16_t * p_lightness);
static void transition_time_lightness_cb(const app_light_lightness_setup_server_t * p_server,
                                         uint32_t transition_time_ms, uint16_t target_lightness);
#if SCENE_SETUP_SERVER_INSTANCES_MAX > 0
static void scene_transition_lightness_cb(const app_scene_setup_server_t * p_app,
                                          uint32_t transition_time_ms,
                                          uint16_t target_scene);
#endif
/*****************************************************************************
 * Static variables
 *****************************************************************************/

static bool m_device_provisioned;
static nrf_mesh_evt_handler_t m_evt_handler;
static const uint8_t led = 4;
static nrf_mesh_evt_handler_t m_event_handler =
{
    .evt_cb = mesh_events_handle,
};

/* Light Lightness Setup Server related variables */

/* Light Lightness Setup Server structure definition and initialization */
APP_LIGHT_LIGHTNESS_SETUP_SERVER_DEF(m_light_lightness_server_0,
                                     APP_FORCE_SEGMENTATION,
                                     APP_MIC_SIZE,
                                     set_lightness_cb,
                                     get_lightness_cb,
                                     transition_time_lightness_cb)

#if SCENE_SETUP_SERVER_INSTANCES_MAX > 0
/* Scene Setup server structure definition and initialization */
APP_SCENE_SETUP_SERVER_DEF(m_scene_server_0,
                           APP_FORCE_SEGMENTATION,
                           APP_MIC_SIZE,
                           scene_transition_lightness_cb,
                           &m_light_lightness_server_0.light_lightness_setup_server.generic_ponoff_setup_srv.generic_dtt_srv)
#endif

/* Application variable for holding instantaneous lightness value */
static uint16_t m_pwm0_present_actual_lightness;

/* PWM hardware instance and associated variables */
/* Note: PWM cycle period determines the the max value that can be used to represent 100%
 * duty cycles, therefore value scaling is required to get pwm tick value
 * between 0 and max.
 */
static APP_PWM_INSTANCE(PWM0, 1);
static app_pwm_config_t m_pwm0_config = APP_PWM_DEFAULT_CONFIG_1CH(200, led);
static pwm_utils_contex_t m_pwm = {
                                    .p_pwm = &PWM0,
                                    .p_pwm_config = &m_pwm0_config,
                                    .channel = 0
                                  };


/* Private function definitions. */

/* Callback for updating the hardware state */
static void set_lightness_cb(const app_light_lightness_setup_server_t * p_app, uint16_t lightness)
{
    m_pwm0_present_actual_lightness = lightness;
    (void)pwm_utils_level_set_unsigned(&m_pwm, m_pwm0_present_actual_lightness);
}

/* Callback for reading the hardware state */
static void get_lightness_cb(const app_light_lightness_setup_server_t * p_app, uint16_t * p_lightness)
{
    *p_lightness = (m_pwm0_present_actual_lightness);
}

/* Callback for receiveing transition time. */
static void transition_time_lightness_cb(const app_light_lightness_setup_server_t * p_server,
                                         uint32_t transition_time_ms, uint16_t target_lightness)
{
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Transition time: %d, Target lightness: %d\n",
                                       transition_time_ms, target_lightness);
}

#if SCENE_SETUP_SERVER_INSTANCES_MAX > 0
static void scene_transition_lightness_cb(const app_scene_setup_server_t * p_app,
                                          uint32_t transition_time_ms,
                                          uint16_t target_scene)
{
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Transition time: %d, Target Scene: %d\n",
                                       transition_time_ms, target_scene);
}
#endif

static void models_init_cb(void)
{
    /* Initialize the Light Lightness Setup Server */
    APP_ERROR_CHECK(app_light_lightness_model_init(&m_light_lightness_server_0, APP_LL_ELEMENT_INDEX));
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "App Light Lightness Model handle: %d, Element index: %d\n",
          m_light_lightness_server_0.light_lightness_setup_server.model_handle,
          m_light_lightness_server_0.light_lightness_setup_server.settings.element_index);

#if SCENE_SETUP_SERVER_INSTANCES_MAX > 0
    /* Instantiate scene server and register light lightness server to have scene support */
    ERROR_CHECK(app_scene_model_init(&m_scene_server_0, APP_LL_ELEMENT_INDEX));
    ERROR_CHECK(app_scene_model_add(&m_scene_server_0, &m_light_lightness_server_0.scene_if));
    ERROR_CHECK(app_light_lightness_scene_context_set(&m_light_lightness_server_0,
                                                      &m_scene_server_0));
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "App Scene Model handle: %d, Element index: %d\n",
          m_scene_server_0.scene_setup_server.model_handle,
          m_scene_server_0.scene_setup_server.settings.element_index);
#endif
}

/*************************************************************************************************/

static void mesh_events_handle(const nrf_mesh_evt_t * p_evt)
{
    if (p_evt->type == NRF_MESH_EVT_ENABLED)
    {
        /* The onpowerup/last/actual binding is required at boot time to restore the correct state
         * of the lightness model. */
        APP_ERROR_CHECK(app_light_lightness_binding_setup(&m_light_lightness_server_0));
    }
#if NRF_MESH_LOG_ENABLE
    else if (p_evt->type == NRF_MESH_EVT_CONFIG_LOAD_FAILURE)
    {
        const nrf_mesh_evt_config_load_failure_t * p_details = &p_evt->params.config_load_failure;
        __LOG(LOG_SRC_APP, LOG_LEVEL_DBG1, "Corrupted entry: file:%d record:%d reason:%d\n",
              p_details->id.file, p_details->id.record, p_details->reason);
        __LOG_XB(LOG_SRC_APP, LOG_LEVEL_DBG1, "Raw data:", (const uint8_t *)p_details->p_data, p_details->data_len);
    }
#endif
}


static bool fw_updated_event_is_for_me(const nrf_mesh_evt_dfu_t * p_evt)
{
    switch (p_evt->fw_outdated.transfer.dfu_type)
    {
        case NRF_MESH_DFU_TYPE_APPLICATION:
            __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "DFU type Application\n");
            return (p_evt->fw_outdated.current.application.app_id == p_evt->fw_outdated.transfer.id.application.app_id &&
                    p_evt->fw_outdated.current.application.company_id == p_evt->fw_outdated.transfer.id.application.company_id &&
                    p_evt->fw_outdated.current.application.app_version < p_evt->fw_outdated.transfer.id.application.app_version);

        case NRF_MESH_DFU_TYPE_BOOTLOADER:
            __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "DFU type Bootloader\n");
            return (p_evt->fw_outdated.current.bootloader.bl_id == p_evt->fw_outdated.transfer.id.bootloader.bl_id &&
                    p_evt->fw_outdated.current.bootloader.bl_version < p_evt->fw_outdated.transfer.id.bootloader.bl_version);

        case NRF_MESH_DFU_TYPE_SOFTDEVICE:
            __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "DFU type Softdevice\n");
            return false;

        default:
            return false;
    }
}

static const uint32_t * optimal_bank_address(void)
{
    /* The incoming transfer has to fit on both sides of the bank address: First it needs to fit
     * above the bank address when we receive it, then it needs to fit below the bank address when
     * we install it. We want to put the bank address in the middle of the available application
     * code area, to maximize the potential transfer size we can accept. */
    const uint32_t * p_start;
    uint32_t dummy;
    ERROR_CHECK(mesh_stack_persistence_flash_usage(&p_start, &dummy));

    uint32_t middle_of_app_area = (CODE_START + (intptr_t) p_start) / 2;

    /* The bank can't start in the middle of the application code, and should be page aligned: */
    return (const uint32_t *) ALIGN_VAL(MAX(middle_of_app_area, CODE_END), PAGE_SIZE);
}

static void mesh_evt_handler(const nrf_mesh_evt_t* p_evt)
{
    switch (p_evt->type)
    {
        case NRF_MESH_EVT_DFU_FIRMWARE_OUTDATED:
        case NRF_MESH_EVT_DFU_FIRMWARE_OUTDATED_NO_AUTH:
            if (fw_updated_event_is_for_me(&p_evt->params.dfu))
            {
                const uint32_t * p_bank = optimal_bank_address();
                __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Requesting DFU transfer with bank at 0x%p\n", p_bank);

                ERROR_CHECK(nrf_mesh_dfu_request(p_evt->params.dfu.fw_outdated.transfer.dfu_type,
                                                 &p_evt->params.dfu.fw_outdated.transfer.id,
                                                 p_bank));
            }
            else
            {
                /**
                 * While preparing for the start of the DFU process, the DFU module
                 * will notify about any other ongoing DFU transfers by sending
                 * @ref NRF_MESH_EVT_DFU_FIRMWARE_OUTDATED_NO_AUTH or
                 * @ref NRF_MESH_EVT_DFU_FIRMWARE_OUTDATED.
                 *
                 * Check the current DFU state to avoid reverting the target state
                 * to the relay state.
                 */
                nrf_mesh_dfu_transfer_state_t state;
                uint32_t error_code = nrf_mesh_dfu_state_get(&state);
                if (error_code == NRF_SUCCESS && (state.state == NRF_MESH_DFU_STATE_INITIALIZED ||
                                                  state.state == NRF_MESH_DFU_STATE_FIND_FWID ||
                                                  state.state == NRF_MESH_DFU_STATE_RELAY_CANDIDATE ||
                                                  state.state == NRF_MESH_DFU_STATE_RELAY))
                {
                    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Starting relay\n");
                    ERROR_CHECK(nrf_mesh_dfu_relay(p_evt->params.dfu.fw_outdated.transfer.dfu_type,
                                                    &p_evt->params.dfu.fw_outdated.transfer.id));
                }
            }
            break;

        case NRF_MESH_EVT_DFU_START:
            break;

        case NRF_MESH_EVT_DFU_END:
            break;

        case NRF_MESH_EVT_DFU_BANK_AVAILABLE:
            ERROR_CHECK(nrf_mesh_dfu_bank_flash(p_evt->params.dfu.bank.transfer.dfu_type));
            break;

        default:
            break;

    }
}


static void node_reset(void)
{
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "----- Node reset  -----\n");
    model_config_file_clear();
    /* This function may return if there are ongoing flash operations. */
    mesh_stack_device_reset();
}

static void config_server_evt_cb(const config_server_evt_t * p_evt)
{
    if (p_evt->type == CONFIG_SERVER_EVT_NODE_RESET)
    {
        node_reset();
    }
}

#if NRF_MESH_LOG_ENABLE
static const char m_usage_string[] =
    "\n"
    "\t\t--------------------------------------------------------------\n"
    "\t\t RTT 1) Decrease LED state, until min value is reached.\n"
    "\t\t RTT 2) Increase LED state, until max value is reached.\n"
    "\t\t RTT 4) Clear all the states to reset the node.\n"
    "\t\t--------------------------------------------------------------\n";
#endif

static void button_event_handler(uint32_t button_number)
{
    /* Increase button number because the buttons on the board is marked with 1 to 4 */
    button_number++;
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Button %u pressed\n", button_number);
    switch (button_number)
    {
        /* Sending value `1` or `2` via RTT will result in LED state to change and trigger
        the STATUS message to inform client about the state change. This is a demonstration of
        state change publication due to local event. */
        case 1:
        {
            m_pwm0_present_actual_lightness = MAX(0, (int32_t)m_pwm0_present_actual_lightness - APP_LIGHTNESS_STEP_SIZE);
            break;
        }

        case 2:
        {
            m_pwm0_present_actual_lightness = MIN(UINT16_MAX,
                                                  (int32_t)m_pwm0_present_actual_lightness + APP_LIGHTNESS_STEP_SIZE);
            break;
        }

        /* Initiate node reset */
        case 4:
        {
            /* Clear all the states to reset the node. */
            if (mesh_stack_is_device_provisioned())
            {
#if MESH_FEATURE_GATT_PROXY_ENABLED
                (void) proxy_stop();
#endif
                mesh_stack_config_clear();
                node_reset();
            }
            else
            {
                __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "The device is unprovisioned. Resetting has no effect.\n");
            }
            break;
        }

        default:
            __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, m_usage_string);
            break;
    }

    if (button_number == 1 || button_number == 2)
    {
        (void)pwm_utils_level_set_unsigned(&m_pwm, m_pwm0_present_actual_lightness);
        uint32_t status = app_light_lightness_current_value_publish(&m_light_lightness_server_0);
        __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "lightness: %d\n", m_pwm0_present_actual_lightness);
        if ( status != NRF_SUCCESS)
        {
            __LOG(LOG_SRC_APP, LOG_LEVEL_WARN, "Unable to publish status message, status: %d\n", status);
        }
    }
}

static void app_rtt_input_handler(int key)
{
    if (key >= '1' && key <= '4')
    {
        uint32_t button_number = key - '1';
        button_event_handler(button_number);
    }
    else
    {
        __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, m_usage_string);
    }
}

static void unicast_address_print(void)
{
    dsm_local_unicast_address_t node_address;
    dsm_local_unicast_addresses_get(&node_address);
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Node Address: 0x%04x \n", node_address.address_start);
}

static void provisioning_complete_cb(void)
{
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Successfully provisioned\n");

#if MESH_FEATURE_GATT_ENABLED
    /* Restores the application parameters after switching from the Provisioning service to the
     * Proxy */
    gap_params_init();
    conn_params_init();
#endif

    unicast_address_print();
}

static void mesh_init(void)
{
    /* Initialize the application storage for models */
    model_config_file_init();

    mesh_stack_init_params_t init_params =
    {
        .core.irq_priority       = NRF_MESH_IRQ_PRIORITY_LOWEST,
        .core.lfclksrc           = DEV_BOARD_LF_CLK_CFG,
        .core.p_uuid             = NULL,
        .models.models_init_cb   = models_init_cb,
        .models.config_server_cb = config_server_evt_cb
    };

    uint32_t status = mesh_stack_init(&init_params, &m_device_provisioned);

    if (status == NRF_SUCCESS)
    {
        /* Check if application stored data is valid, if not clear all data and use default values. */
        status = model_config_file_config_apply();
    }

    switch (status)
    {
        case NRF_ERROR_INVALID_DATA:
            /* Clear model config file as loading failed */
            model_config_file_clear();
            __LOG(LOG_SRC_APP, LOG_LEVEL_INFO,
                  "Data in the persistent memory was corrupted. Device starts as unprovisioned.\n");
            __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Reboot device before starting of the provisioning process.\n");
            break;
        case NRF_SUCCESS:
            break;
        default:
            APP_ERROR_CHECK(status);
    }

#if NRF_MESH_SERIAL_ENABLE
    ERROR_CHECK(nrf_mesh_serial_init(NULL));
#endif

    m_evt_handler.evt_cb = mesh_evt_handler;
    nrf_mesh_evt_handler_add(&m_evt_handler);
}

static void initialize(void)
{
    __LOG_INIT(LOG_SRC_APP | LOG_SRC_ACCESS, LOG_LEVEL_INFO, LOG_CALLBACK_DEFAULT);
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "----- BLE Mesh Light Lightness Setup Server Demo -----\n");

    pwm_utils_enable(&m_pwm);
    APP_ERROR_CHECK(app_timer_init());
    ble_stack_init();

#if MESH_FEATURE_GATT_ENABLED
    gap_params_init();
    conn_params_init();
#endif

    mesh_init();
}

static void start(void)
{
    rtt_input_enable(app_rtt_input_handler, RTT_INPUT_POLL_PERIOD_MS);

    if (!m_device_provisioned)
    {
        static const uint8_t static_auth_data[NRF_MESH_KEY_SIZE] = STATIC_AUTH_DATA;
        mesh_provisionee_start_params_t prov_start_params =
        {
            .p_static_data    = static_auth_data,
            .prov_complete_cb = provisioning_complete_cb,
            .prov_device_identification_start_cb = NULL,
            .prov_device_identification_stop_cb = NULL,
            .prov_abort_cb = NULL,
            .p_device_uri = EX_URI_LL_SERVER
        };
        APP_ERROR_CHECK(mesh_provisionee_prov_start(&prov_start_params));
    }
    else
    {
        unicast_address_print();
    }

#if NRF_MESH_SERIAL_ENABLE
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Enabling serial interface...\n");
    ERROR_CHECK(nrf_mesh_serial_enable());
#endif

    mesh_app_uuid_print(nrf_mesh_configure_device_uuid_get());

    /* NRF_MESH_EVT_ENABLED is triggered in the mesh IRQ context after the stack is fully enabled.
     * This event is used to call Model APIs for establishing bindings and publish a model state information. */
    nrf_mesh_evt_handler_add(&m_event_handler);
    APP_ERROR_CHECK(mesh_stack_start());

    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, m_usage_string);
}

/* Entry-point */

int main(void)
{
    initialize();
    start();

    for (;;)
    {
        (void)sd_app_evt_wait();
    }
}

DFU update using nrf Util tool:

Device output logs:

Device is provisioned using static provisioner.

Thanks 

[tesc]

Hi,

The assert happens on address 0x0002AC42. You will need to either use a tool such as addr2line, or to investigate the .map file (part of the output files of your build), in order to figure out what instructions (file and line of code) lead to the assert. This mapping will be different for different toolchains and for different modifications to the application. It would be best if you reproduce the issue with a debug build, with debug symbols available, and possibly also if you do a debug session in order to get the exact location and/or a full stack trace.

Regards,
Terje

[Danish_Riaz]

Hi Terje

I have debug and take logs. 

This image indicates that at this point device execution without essertion. 

But after this it return following essersion:

Let me know if there is any further necessary logs needed.

Thanks & Regards: Danish Riaz

[tesc]

Hi,

You should see under "Output Files" in the side bar several files that are generated when you build the project. In particular the .map file and the .elf file are useful, for seeing where things are laid out in the binary. Can you share those two files?

If you don't want to share those files in an open case, then please provide the files in a private case and refer to this case.

Regards,
Terje

[Danish_Riaz]

Hi Terje 

Please find attached files.

debug_files.zip

The code works fine without DFU update, mesh stack initialization fails only when we apply DFU update. And I am following steps as given nrf5SDK for mesh "Configuring and performing DFU over Mesh".

Regards: Danish Riaz

[tesc]

Hi,

In order for the files to contain proper debug information, you must build the project as Debug:

Then you should be able to use addr2line to get the exact file and line of the assert, like this:

addr2line.exe -e light_lightness_server_nrf52833_xxAA_s113_7.2.0.elf 0x2AC42

With the current files, without proper debug info, you only get the file name, and a question mark indicating addr2line does not know what is the line number:

flash_manager.c:?

Please note that for a rebuild, the address of the assert will most likely differ, so you will have to do another test to see at what address the assert now happens, and use addr2line to figure out what file and line number correspond to that new address.

If you have difficulties using addr2line, please make sure to do a DEBUG build of the project, and resend the files and provide the new assert address for me to have another look.

Regards,
Terje

[Danish_Riaz]

Hi Terje 

addr2line shows assertion is trigger from file flash_manager.c  line number 255.

Please find attached image:

Regards,

Danish Riaz

[tesc]

Hi,

This error indicates that a Flash page used by Flash manager is corrupted. This may happen in a few different situations:

It may happen if the flash configuration differs between the old and the new application. This could be that the flash area locations differ between the two versions of the application, or that the defragmentation recovery page is located at a different flash page.

It may happen if the new application is larger than the old one, and the new application overwrites parts of flash pages previously used by flash manager. Those pages could have been outside of the application flash before, but now are inside the application flash space and therefore now holds part of the applicaiton instead.

It may happen if during the firmware transfer, the bank for receiving the new applicaiton overlaps with pages used by the flash manager.

If I recall correctly it could also happen if the bootloader itslef is updated, but for some reason the new bootloader is larger than the previous one. However this should not normally happen and so this is less likely to be the cause of the error that you see.

Regards,
Terje