SDK for Meshv v4.1.0 :: access_model_publish() triggers an assert on bearer_event_in_correct_irq_priority() .... but same code is in prod on SDK for Meshv v3.2.0

[sirio]

Sequence of events:

1. A GPIOTE button interrupt in LPN schedules a handler routine.

2. Handler routine (called by app_scheduler()) makes a call to access_model_publish() (to send an unacknowledged message).

3. Somewhere in the call stack for access_model_publish(), the assert in mesh/core/src/timer_scheduler.c:214 is triggered.

It seems we are failing the check in bearer_event_in_correct_irq_priority(), but this call is made from a function called by app_scheduler() (aka: outside of any interrupt context).

To try to debug the issue further, I printed the interrupt values:

volatile IRQn_Type active_irq = hal_irq_active_get();
volatile uint32_t prio = NVIC_GetPriority(active_irq);

/* log, then wait 5ms for buffer to flush before triggering assert */
LOG_FLUSH("active irq %d with NVIC priority %d\n", active_irq, prio);
/* log output:
 * "active irq -16 with NVIC priority 0"
 */

/* assert triggered here */
access_model_publish(/* ... */);

This code builds as-is with no warnings (using -Wall and -Wextra) on both SDK for Meshv v3.2.0 and v4.1.0.

This code runs with no issues (and is in production) on v3.2.0, but on v4.1.0 throws the above error.

Full build spec for v3.2.0:

-- Configuring CMake for nRF5 SDK for Bluetooth Mesh 3.2.0
-- SDK: nRF5_SDK_15.3.0_59ac345
-- Platform: nrf52832_xxAA
-- Arch: cortex-m4f
-- SoftDevice: s132_6.1.1
-- The C compiler identification is GNU 8.3.1

Full build spec for v4.1.0:

-- Configuring CMake for nRF5 SDK for Bluetooth Mesh 4.1.0
-- SDK: nRF5_SDK_16.0.0_98a08e2
-- Platform: nrf52832_xxAA
-- Arch: cortex-m4f
-- SoftDevice: s132_7.0.1
-- Board: pca10040
-- The C compiler identification is GNU 8.3.1

[sirio]

This is the compilation for v4.1.

-- Configuring CMake for nRF5 SDK for Bluetooth Mesh 4.1.0
-- SDK: nRF5_SDK_16.0.0_98a08e2
-- Platform: nrf52832_xxAA
-- Arch: cortex-m4f
-- SoftDevice: s132_7.0.1
-- Board: pca10040
-- The C compiler identification is GNU 8.3.1

lpn_irq_issue/src/main.c: In function 'main':
lpn_irq_issue/src/main.c:666:5: warning: implicit declaration of function 'APP_SCHED_INIT'; did you mean 'APP_USBD_VID'? [-Wimplicit-function-declaration]
     APP_SCHED_INIT(APP_SCHED_EVENT_SIZE, APP_SCHED_QUEUE_SIZE);
     ^~~~~~~~~~~~~~
     APP_USBD_VID
lpn_irq_issue/src/main.c:677:9: warning: implicit declaration of function 'app_sched_execute'; did you mean 'app_scheduler_init'? [-Wimplicit-function-declaration]
         app_sched_execute();
         ^~~~~~~~~~~~~~~~~
         app_scheduler_init

nRF5_SDK_16.0.0_98a08e2/components/softdevice/common/nrf_sdh.c: In function 'SWI2_EGU2_IRQHandler':
nRF5_SDK_16.0.0_98a08e2/components/softdevice/common/nrf_sdh.c:390:27: warning: implicit declaration of function 'app_sched_event_put'; did you mean 'appsh_events_poll'? [-Wimplicit-function-declaration]
     ret_code_t ret_code = app_sched_event_put(NULL, 0, appsh_events_poll);
                           ^~~~~~~~~~~~~~~~~~~
                           appsh_events_poll

nrf5SDKforMeshv410src/external/app_timer/app_timer_mesh.c: In function 'timeout_handler_exec':
nrf5SDKforMeshv410src/external/app_timer/app_timer_mesh.c:393:25: warning: implicit declaration of function 'app_sched_event_put'; did you mean 'app_scheduler_init'? [-Wimplicit-function-declaration]
     uint32_t err_code = app_sched_event_put(&timer_event, sizeof(timer_event), timeout_handler_scheduled_exec);
                         ^~~~~~~~~~~~~~~~~~~
                         app_scheduler_init

FAILED: lpn_irq_issue_nrf52832_xxAA_s132_7.0.1.elf lpn_irq_issue_nrf52832_xxAA_s132_7.0.1.hex
arm-none-eabi/bin/ld: lpn_irq_issue/CMakeFiles/lpn_irq_issue_nrf52832_xxAA_s132_7.0.1.dir/src/main.c.obj: in function `main':
lpn_irq_issue/src/main.c:666: undefined reference to `APP_SCHED_INIT'

However, if you examine diff #3 given in my previous post, you will see that I followed the documentation exactly and that:

1. lpn_irq_issue/include/app_config.h contains:

#define APP_SCHEDULER_ENABLED 1
#define NRF_SDH_DISPATCH_MODEL 1
#define APP_TIMER_CONFIG_USE_SCHEDULER 1
#define APP_SCHED_EVENT_SIZE APP_TIMER_SCHED_EVENT_DATA_SIZE
#define APP_SCHED_QUEUE_SIZE 32

2. lpn_irq_issue/src/main.c contains:

/* nRF5 SDK */
#include "nrf_soc.h"
#include "nrf_pwr_mgmt.h"
#include "app_scheduler.h"

3. lpn_irq_issue/CMakeLists.txt contains:

add_executable(${target}
    "${CMAKE_CURRENT_SOURCE_DIR}/src/main.c"

    "${CMAKE_SOURCE_DIR}/mesh/stack/src/mesh_stack.c"
    "${CMAKE_SOURCE_DIR}/examples/common/src/mesh_app_utils.c"
    "${CMAKE_SOURCE_DIR}/examples/common/src/mesh_provisionee.c"
    "${CMAKE_SOURCE_DIR}/examples/common/src/rtt_input.c"

    "${CMAKE_SOURCE_DIR}/examples/common/src/simple_hal.c"

    "${SDK_ROOT}/components/libraries/scheduler/app_scheduler.c"

and also contains:

target_include_directories(${target} PUBLIC
    "${CMAKE_CURRENT_SOURCE_DIR}/include"
    "${CMAKE_SOURCE_DIR}/examples/common/include"
    "${CMAKE_SOURCE_DIR}/external/rtt/include"
    "${SDK_ROOT}/components/libraries/scheduler"

So there may be an error in the SDK or the documentation?

For future reference, if a bug report contains an exact Diff from a stock Nordic example that recreates the issue, it would be helpful to see you:

- take the stock Nordic example

- apply the diff

- build the example

If you prefer a different diff/patch format or a different bug report format that lets you more easily reproduce and run the build on your system, please let me know and I will provide that.

[Hung Bui]

I don't think the compilation error has anything related to the change you made. It's complaining about the  missing definition  of app_sched_event_put() and APP_SCHED_INIT. Have you made sure you include path to app_scheduler.h in the project ? and include the file in main.c? 

app_scheduler.c also needed in the project/Makefile. 

[sirio]

Thank you.

Please review points 1-3 in my previous reply. From those you can see that:

- "app_scheduler.h" in included in main.c

- "app_scheduler.c" is added to the target executable in CMakeLists.txt

- "${SDK_ROOT}/components/libraries/scheduler" is added to the include dirs in CMakeLists.txt

- APP_SCHEDULER_ENABLED 1 is defined in app_config.h

Diff #3 in my reply before the last includes all of these changes.

Were you able to take the stock example and apply Diffs 1, 2 and 3 to them to reproduce the issue?

I am sure it's probably a trivial problem, but from following the documentation exactly (see above) I'm not able to make it build.

Would be great if you could tell me your outcome from applying the diffs and attempting the build on your side :)

[Hung Bui]

Hi Sirio, 

I have applied the patch and compiled without any issue. Please make sure you used the correct SDK_ROOT. 

Attached is my lpn project. 

My tip is to generate the SES project when you call cmake ninja (-DGENERATE_SES_PROJECTS=ON). It would be easier to debug

lpn.zip. 

[sirio]

Thank you very much, your example helped me to find the problem:

In SDK v3.2.0 (I am building against both so that I can verify migration of existing projects), there are 2 DIFFERENT files both named app_scheduler.h and both defining APP_SCHEDULER_H__

- nRF5_SDK_16.0.0_98a08e2/components/libraries/scheduler/app_scheduler.h

- nrf5SDKforMeshv320src/examples/common/include/app_scheduler.h

... this created the issue where a slight difference in include priority will result in the wrong file being included.

I see you have already fixed this in the v4.1.0 SDK by removing examples/common/include/app_scheduler.h; very good, thank you.

I will now try to migrate our code to run with this NRF_MESH_IRQ_PRIORITY_THREAD model.