Attachments (3) Download All
Nordic Case Info
  • Case ID: 338228
Options

ASSERTION FAIL @ WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv.c

a.da

Hello.

I am developing using nRF5340DK and nRF Connect SDK v2.9.0.
A fatal error occurred on the board when sending some Mesh Model Messages to the smartphone app.
It doesn't happen every time. I think it is more likely to occur when sending repeatedly.

Fullscreen
1
ASSERTION FAIL @ WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv.c
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX


Here is the code where a fatal error occurs.
Fullscreen
1
2
3
4
5
6
7
void bt_mesh_adv_unref(struct bt_mesh_adv *adv)
{
__ASSERT_NO_MSG(adv->__ref > 0);
if (--adv->__ref > 0) {
return;
}
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

"adv->__ref" was underflowing. I thought the number of calls to "bt_mesh_adv_ref()" and "bt_mesh_adv_unref()" had an effect.
However, since the detailed sequence is unclear, I added debug logs to "adv.c". The at symbol represents the location I modified.
I output the address of the "struct bt_mesh_adv", ref, and the caller's file name, function name, and line number.

Fullscreen
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
static struct bt_mesh_adv *adv_create_from_pool(struct k_mem_slab *buf_pool,
enum bt_mesh_adv_type type,
enum bt_mesh_adv_tag tag,
uint8_t xmit, k_timeout_t timeout)
{
// some code...
LOG_INF( "%p create", (void*)adv ) ; // @@@
return adv;
}
struct bt_mesh_adv *bt_mesh_adv_ref(struct bt_mesh_adv *adv, const char *file, const char *func, int line)
{
LOG_INF( "%p ref : %u -> %u ( %s %s %u )", (void*)adv, ( adv->__ref ), ( adv->__ref + 1 ), file, func, line ) ; // @@@
__ASSERT_NO_MSG(adv->__ref < UINT8_MAX);
adv->__ref++;
return adv;
}
void bt_mesh_adv_unref(struct bt_mesh_adv *adv, const char *file, const char *func, int line)
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX


Result(The message content is masked.):
Fullscreen
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
[00:02:14.832,489] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0x0000 src 0x0001 dst 0x016d
[00:02:14.832,550] <dbg> bt_mesh_access: bt_mesh_model_recv: len 2: ****
[00:02:14.832,580] <dbg> bt_mesh_access: bt_mesh_model_recv: OpCode 0x********
[00:02:14.836,273] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0x0000 src 0x0001 dst 0x0170
[00:02:14.836,303] <dbg> bt_mesh_access: bt_mesh_model_recv: len 5: **********
[00:02:14.836,334] <dbg> bt_mesh_access: bt_mesh_model_recv: OpCode 0x********
[00:02:14.840,057] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0x0000 src 0x0001 dst 0x016b
[00:02:14.840,087] <dbg> bt_mesh_access: bt_mesh_model_recv: len 2: ****
[00:02:14.840,087] <dbg> bt_mesh_access: bt_mesh_model_recv: OpCode 0x********
[00:02:14.843,811] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0x0000 src 0x0001 dst 0x0172
[00:02:14.843,841] <dbg> bt_mesh_access: bt_mesh_model_recv: len 5: **********
[00:02:14.860,504] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0x0000 dst 0x0001
[00:02:14.860,534] <dbg> bt_mesh_access: bt_mesh_access_send: len 6: ************
[00:02:14.861,267] <inf> bt_mesh_adv: 0x2002708c create
[00:02:14.862,182] <inf> bt_mesh_adv: 0x2002708c ref : 1 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c bt_mesh_proxy_relay_send 251 )
[00:02:14.862,243] <inf> bt_mesh_adv: 0x2002708c ref : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv.c bt_mesh_adv_send 302 )
[00:02:14.862,304] <inf> bt_mesh_adv: 0x2002708c unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/net.c bt_mesh_net_send 596 )
[00:02:14.862,396] <inf> bt_mesh_adv: 0x2002708c ref : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.862,548] <inf> bt_mesh_adv: 0x2002708c unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_msg_send_pending 274 )
[00:02:14.862,915] <inf> bt_mesh_adv: 0x2002708c unref: 2 -> 1 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c buf_send_end 211 )
[00:02:14.865,081] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0x0000 src 0x0001 dst 0x0171
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX


About the address of the "struct bt_mesh_adv" for the Message.
1st message(0x2002708c) : The Address has been freed.
2nd message(0x20027050) : The Address has not been freed yet.
3rd message(0x20027014) : After the address has been freed, "bt_mesh_adv_unref()" was called.

Do you know what the cause is?
Is it expected that changing the configuration parameters will lead to improvement?
It might be due to communication load, but I would like to avoid it causing a reset.

Thanks for reading.
Season's Greetings!

a.da

Parents
  • 0

    Hi,

    Thank you for the report, it is highly appreciated.

    You have done some thorough investigations and provided us with what looks like the relevant information. Hopefully this is enough for us to figure out what leads to the assert. I will ask for more information here in this thread, if we need more.

    From what I can tell, this type of issue is most likely a bug in the stack itself. Configuration changes may or may not change the prevalence of the issue, but we will likely not know until we find the root cause. I am afraid I do not have any time estimate for when we will know more, but rest assured we are looking into the issue and I will provide an update here when more is known at our side.

    Regards,
    Terje

  • 0 in reply to tesc

    Hi Terje,

    Thank you for your continued support. I will respond as quickly as possible as well.

    Kind regards,

    a.da

  • 0 in reply to tesc

    Hi Terje,

    Project:
    Our project is a custom application based on SDK samples(Light fixture).
    The "prj.conf" has been modified based on the sample.
    The smartphone app is not "nRF Mesh," it is custom-built(iOS).

    Steps to reproduce:
    There is one device in the mesh network.
    The smartphone app sends four Mesh Messages simultaneously.
    0x82 0x4b Light Lightness Get,
    0x82 0x61 Light CTL Temperature Get,
    and two Vendor Model Message that requests a status response like "Light Lightness Get".
    But it doesn't happen every time.

    First, I will strip it down to a minimal example that is closer to the sample.
    I will also consider applying the pull request.
    Please give me a moment.

    Kind regards,

    a.da

  • 0 in reply to tesc

    Hi Terje,

    I stripped it down to a minimal example. Please overwrite the Light fixture SDK sample.

    8117.project.zip

    The issue also occurred when receiving two SIG Model Messages and one Vendor Model Message.
    Light Lightness Get, Light CTL Temperature Get, and one more.
    This is a log from the 1st boot to the occurrence of the Fatal Error, using a minimal example.
    Some of the data is masked.
    The issue occurred on the 6th transmission after binding the Application Key, line 1001.

    250110_adv.log

    The issue could not be reproduced in the "nRF Mesh", as there is no way to send messages simultaneously.
    Can the investigation continue with this information?
    Please let me know if you need anything else.

    a.da

  • +1 in reply to a.da

    Hi,

    Thank you for the additional information. We now have a fix, in the following pull request: https://github.com/zephyrproject-rtos/zephyr/pull/83934. The changes are listed on the files changed page of that pull request.

    Please check if applying those changes fixes the issue also for your application.

    Regards,
    Terje

  • 0 in reply to tesc

    Hi Terje,

    Unfortunately, the situation has worsened.
    I overwrote the file attached to the pull request with the Light fixture SDK sample.
    It’s just "adv.h" and "proxy_msg.c".
    When I provisioned it using the "nRF Mesh" app, it was unable to allocate beacon adv.

    Fullscreen
    1
    2
    3
    4
    5
    6
    7
    [00:00:29.251,403] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0xfffe src 0x0001 dst 0x06b5
    [00:00:29.251,464] <dbg> bt_mesh_access: bt_mesh_model_recv: len 3: 800800
    [00:00:29.251,464] <dbg> bt_mesh_access: bt_mesh_model_recv: OpCode 0x00008008
    [00:00:29.293,182] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0xfffe dst 0x0001
    [00:00:29.293,273] <dbg> bt_mesh_access: bt_mesh_access_send: len 52: 0200590000000000ff00070001000d0000000200021000100410061007100013011303120412001101110200030000100f131013
    [00:00:31.339,904] <err> bt_mesh_beacon: Unable to allocate beacon adv
    [00:00:31.339,904] <err> bt_mesh_beacon: Failed to advertise subnet 0: err -12
    XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

    Fullscreen 250115_adv.log Download
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    *** Booting Mesh Light Fixture v2.9.0-30712dd3f2dd ***
    *** Using nRF Connect SDK v2.9.0-7787b2649840 ***
    *** Using Zephyr OS v3.7.99-1f8f3dc29142 ***
    Initializing...
    [00:00:00.258,880] <inf> fs_nvs: 8 Sectors of 4096 bytes
    [00:00:00.258,880] <inf> fs_nvs: alloc wra: 0, fb0
    [00:00:00.258,880] <inf> fs_nvs: data wra: 0, 44
    [00:00:00.290,618] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
    [00:00:00.290,649] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
    [00:00:00.290,679] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 45.41337 Build 3074452168
    [00:00:00.291,168] <inf> bt_hci_core: No ID address. App must call settings_load()
    Bluetooth initialized
    [00:00:00.291,442] <dbg> bt_mesh_access: mod_rel_register:
    [00:00:00.291,442] <dbg> bt_mesh_access: mod_rel_register:
    [00:00:00.291,473] <dbg> bt_mesh_access: mod_rel_register:
    [00:00:00.291,503] <dbg> bt_mesh_access: mod_rel_register:
    [00:00:00.291,534] <dbg> bt_mesh_access: mod_rel_register:
    [00:00:00.291,534] <dbg> bt_mesh_access: mod_rel_register:
    [00:00:00.291,564] <dbg> bt_mesh_access: mod_rel_register:
    XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

    It seems that other files committed to "zephyrproject-rtos:main" are also needed.
    However, I have not been able to identify which ones they are.
    I will continue the investigation, so could you please provide support?

    Just to keep you informed.

    a.da

  • 0 in reply to a.da

    This is an update.

    After modifying "proxy_msg.c" attached to the pull request, the issue with be unable to allocate beacon adv has been resolved.
    I merged the changes committed to "zephyrproject-rtos:main".

    Fullscreen
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    static void proxy_msg_send_pending(struct k_work *work)
    {
    struct bt_mesh_proxy_role *role = CONTAINER_OF(work, struct bt_mesh_proxy_role, work);
    struct bt_mesh_adv *adv;
    if (!role->conn) {
    return;
    }
    adv = proxy_queue_get(role);
    if (!adv) {
    return;
    }
    XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

    After using the modified "proxy_msg.c", the fatal error mentioned in the title has not occurred so far.
    I will continue to monitor the situation.

    Thank you for your support.

    a.da

Reply
  • 0 in reply to a.da

    This is an update.

    After modifying "proxy_msg.c" attached to the pull request, the issue with be unable to allocate beacon adv has been resolved.
    I merged the changes committed to "zephyrproject-rtos:main".

    Fullscreen
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    static void proxy_msg_send_pending(struct k_work *work)
    {
    struct bt_mesh_proxy_role *role = CONTAINER_OF(work, struct bt_mesh_proxy_role, work);
    struct bt_mesh_adv *adv;
    if (!role->conn) {
    return;
    }
    adv = proxy_queue_get(role);
    if (!adv) {
    return;
    }
    XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

    After using the modified "proxy_msg.c", the fatal error mentioned in the title has not occurred so far.
    I will continue to monitor the situation.

    Thank you for your support.

    a.da

Children
No Data
Terms of service