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

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.

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


Here is the code where a fatal error occurs.
void bt_mesh_adv_unref(struct bt_mesh_adv *adv)
{
	__ASSERT_NO_MSG(adv->__ref > 0);

	if (--adv->__ref > 0) {
		return;
	}

"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.

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)
{
	LOG_INF( "%p unref: %u -> %u ( %s %s %u )", (void*)adv, ( adv->__ref ), ( adv->__ref - 1 ), file, func, line ) ;	// @@@
	__ASSERT_NO_MSG(adv->__ref > 0);

	if (--adv->__ref > 0) {
		return;
	}
	LOG_INF( "%p free", (void*)adv ) ;																					// @@@
    // some code...
}


Result(The message content is masked.):
[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
[00:02:14.865,112] <dbg> bt_mesh_access: bt_mesh_model_recv: len 5: **********
[00:02:14.865,142] <dbg> bt_mesh_access: bt_mesh_model_recv: OpCode 0x********
[00:02:14.868,835] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0x0000 dst 0x0001
[00:02:14.868,865] <dbg> bt_mesh_access: bt_mesh_access_send: len 7: **************
[00:02:14.869,598] <inf> bt_mesh_adv: 0x20027050 create
[00:02:14.870,513] <inf> bt_mesh_adv: 0x20027050 ref  : 1 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c bt_mesh_proxy_relay_send 251 )
[00:02:14.870,574] <inf> bt_mesh_adv: 0x20027050 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv.c bt_mesh_adv_send 302 )
[00:02:14.870,635] <inf> bt_mesh_adv: 0x20027050 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/net.c bt_mesh_net_send 596 )
[00:02:14.870,666] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0x0000 dst 0x0001
[00:02:14.870,697] <dbg> bt_mesh_access: bt_mesh_access_send: len 4: ********
[00:02:14.871,429] <inf> bt_mesh_adv: 0x20027014 create
[00:02:14.872,375] <inf> bt_mesh_adv: 0x20027014 ref  : 1 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c bt_mesh_proxy_relay_send 251 )
[00:02:14.872,406] <inf> bt_mesh_adv: 0x20027014 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv.c bt_mesh_adv_send 302 )
[00:02:14.872,467] <inf> bt_mesh_adv: 0x20027014 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/net.c bt_mesh_net_send 596 )
[00:02:14.873,596] <inf> bt_mesh_adv: 0x2002708c ref  : 1 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv_ext.c adv_send 271 )
[00:02:14.873,626] <inf> bt_mesh_adv: 0x2002708c unref: 2 -> 1 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv_ext.c send_pending_adv 356 )
[00:02:14.873,687] <inf> bt_mesh_adv: 0x20027050 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.873,809] <inf> bt_mesh_adv: 0x20027050 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_msg_send_pending 274 )
[00:02:14.873,901] <inf> bt_mesh_adv: 0x20027014 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.874,023] <inf> bt_mesh_adv: 0x20027014 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_msg_send_pending 274 )
[00:02:14.874,084] <inf> bt_mesh_adv: 0x20027014 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.874,206] <inf> bt_mesh_adv: 0x20027014 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_msg_send_pending 274 )
[00:02:14.874,267] <inf> bt_mesh_adv: 0x20027014 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.874,389] <inf> bt_mesh_adv: 0x20027014 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_msg_send_pending 274 )
[00:02:14.874,481] <inf> bt_mesh_adv: 0x20027014 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.890,625] <inf> bt_mesh_adv: 0x20027050 unref: 2 -> 1 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c buf_send_end 211 )
[00:02:14.890,747] <inf> bt_mesh_adv: 0x20027014 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_msg_send_pending 274 )
[00:02:14.890,808] <inf> bt_mesh_adv: 0x20027014 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.891,601] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0x0000 dst 0x0001
[00:02:14.891,632] <dbg> bt_mesh_access: bt_mesh_access_send: len 7: **************
[00:02:14.892,364] <inf> bt_mesh_adv: 0x20026fd8 create
[00:02:14.893,280] <inf> bt_mesh_adv: 0x20026fd8 ref  : 1 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c bt_mesh_proxy_relay_send 251 )
[00:02:14.893,341] <inf> bt_mesh_adv: 0x20026fd8 ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv.c bt_mesh_adv_send 302 )
[00:02:14.893,371] <inf> bt_mesh_adv: 0x20026fd8 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/net.c bt_mesh_net_send 596 )
[00:02:14.909,515] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0x0000 dst 0x0001
[00:02:14.909,545] <dbg> bt_mesh_access: bt_mesh_access_send: len 7: **************
[00:02:14.910,278] <inf> bt_mesh_adv: 0x20026f9c create
[00:02:14.911,224] <inf> bt_mesh_adv: 0x20026f9c ref  : 1 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c bt_mesh_proxy_relay_send 251 )
[00:02:14.911,254] <inf> bt_mesh_adv: 0x20026f9c ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv.c bt_mesh_adv_send 302 )
[00:02:14.911,315] <inf> bt_mesh_adv: 0x20026f9c unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/net.c bt_mesh_net_send 596 )
[00:02:14.920,471] <inf> bt_mesh_adv: 0x20027014 unref: 3 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c buf_send_end 211 )
[00:02:14.920,593] <inf> bt_mesh_adv: 0x20027014 unref: 2 -> 1 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_msg_send_pending 274 )
[00:02:14.920,654] <inf> bt_mesh_adv: 0x20027014 ref  : 1 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.950,469] <inf> bt_mesh_adv: 0x20027014 unref: 2 -> 1 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c buf_send_end 211 )
[00:02:14.950,592] <inf> bt_mesh_adv: 0x20027014 unref: 1 -> 0 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_msg_send_pending 274 )
[00:02:14.950,592] <inf> bt_mesh_adv: 0x20027014 free
[00:02:14.950,653] <inf> bt_mesh_adv: 0x2002708c unref: 1 -> 0 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv_ext.c send_pending_adv 337 )
[00:02:14.950,683] <inf> bt_mesh_adv: 0x2002708c free
[00:02:14.954,345] <inf> bt_mesh_adv: 0x20027050 ref  : 1 -> 2 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv_ext.c adv_send 271 )
[00:02:14.954,376] <inf> bt_mesh_adv: 0x20027050 unref: 2 -> 1 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv_ext.c send_pending_adv 356 )
[00:02:14.954,437] <inf> bt_mesh_adv: 0x20026f9c ref  : 2 -> 3 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c proxy_relay_send 228 )
[00:02:14.980,255] <inf> bt_mesh_adv: 0x20027014 unref: 0 -> 4294967295 ( WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/proxy_msg.c buf_send_end 211 )
ASSERTION FAIL @ WEST_TOPDIR/zephyr/subsys/bluetooth/mesh/adv.c:137
[00:02:14.980,316] <err> os: r0/a1:  0x00000004  r1/a2:  0x00000089  r2/a3:  0x00000041
[00:02:14.980,316] <err> os: r3/a4:  0x00000004 r12/ip:  0x00000010 r14/lr:  0x000212af
[00:02:14.980,346] <err> os:  xpsr:  0x21000000
[00:02:14.980,346] <err> os: s[ 0]:  0x000000d3  s[ 1]:  0x00000000  s[ 2]:  0x20016170  s[ 3]:  0x0002ea51
[00:02:14.980,346] <err> os: s[ 4]:  0x00000001  s[ 5]:  0x0001c32f  s[ 6]:  0x20026b8c  s[ 7]:  0x00000000
[00:02:14.980,377] <err> os: s[ 8]:  0x200053c4  s[ 9]:  0x00000034  s[10]:  0x2001ef88  s[11]:  0x200181a8
[00:02:14.980,377] <err> os: s[12]:  0x200035c8  s[13]:  0x00000001  s[14]:  0x20016230  s[15]:  0x00014751
[00:02:14.980,407] <err> os: fpscr:  0x20025258
[00:02:14.980,407] <err> os: Faulting instruction address (r15/pc): 0x0004067a
[00:02:14.980,438] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
[00:02:14.980,468] <err> os: Current thread: 0x200173b8 (unknown)
[00:02:15.808,959] <err> fatal_error: Resetting system


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

  • 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

  • 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

  • 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.

    [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

    *** 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: 
    [00:00:00.291,595] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,595] <dbg> bt_mesh_access: mod_rel_register: 
    [*** 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.259,002] <inf> fs_nvs: 8 Sectors of 4096 bytes
    [00:00:00.259,002] <inf> fs_nvs: alloc wra: 0, fe8
    [00:00:00.259,002] <inf> fs_nvs: data wra: 0, 0
    [00:00:00.290,740] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
    [00:00:00.290,771] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
    [00:00:00.290,771] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 45.41337 Build 3074452168
    [00:00:00.291,290] <inf> bt_hci_core: No ID address. App must call settings_load()
    Bluetooth initialized
    [00:00:00.291,564] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,564] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,595] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,595] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,625] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,656] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,687] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,687] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,717] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,748] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,778] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,809] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,839] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,870] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,931] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,931] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,961] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.291,992] <dbg> bt_mesh_access: mod_rel_register: 
    [00:00:00.292,022] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,053] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 3
    [00:00:00.292,053] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 5
    [00:00:00.292,083] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,083] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 5
    [00:00:00.292,114] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 6
    [00:00:00.292,114] <dbg> bt_mesh_access: bt_mesh_comp_register: registered correspondence
    [00:00:00.292,144] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 5
    [00:00:00.292,144] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 6
    [00:00:00.292,175] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,205] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 4
    [00:00:00.292,205] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 6
    [00:00:00.292,236] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,236] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 5
    [00:00:00.292,266] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 7
    [00:00:00.292,266] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,297] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 2
    [00:00:00.292,297] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 7
    [00:00:00.292,327] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,358] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 7
    [00:00:00.292,358] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 8
    [00:00:00.292,388] <dbg> bt_mesh_access: bt_mesh_comp_register: registered correspondence
    [00:00:00.292,388] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 7
    [00:00:00.292,419] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 8
    [00:00:00.292,419] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,449] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 6
    [00:00:00.292,449] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 8
    [00:00:00.292,480] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,510] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 4
    [00:00:00.292,510] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 10
    [00:00:00.292,541] <dbg> bt_mesh_access: bt_mesh_comp_register: registered correspondence
    [00:00:00.292,541] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 9
    [00:00:00.292,572] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 10
    [00:00:00.292,572] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,602] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 9
    [00:00:00.292,602] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 10
    [00:00:00.292,633] <dbg> bt_mesh_access: bt_mesh_comp_register: registered correspondence
    [00:00:00.292,633] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 11
    [00:00:00.292,663] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 12
    [00:00:00.292,694] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,694] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 11
    [00:00:00.292,724] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 0 idx 12
    [00:00:00.292,724] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,755] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 0 idx 7
    [00:00:00.292,755] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 1 idx 1
    [00:00:00.292,785] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,785] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 1 idx 0
    [00:00:00.292,816] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 1 idx 1
    [00:00:00.292,846] <dbg> bt_mesh_access: bt_mesh_comp_register: registered extension
    [00:00:00.292,846] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 1 idx 1
    [00:00:00.292,877] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 1 idx 2
    [00:00:00.292,877] <dbg> bt_mesh_access: bt_mesh_comp_register: registered correspondence
    [00:00:00.292,907] <dbg> bt_mesh_access: bt_mesh_comp_register: 	base: elem 1 idx 1
    [00:00:00.292,907] <dbg> bt_mesh_access: bt_mesh_comp_register: 	ext: elem 1 idx 2
    [00:00:00.524,475] <inf> bt_hci_core: Identity: CC:F3:DF:C0:C2:8E (random)
    [00:00:00.524,505] <inf> bt_hci_core: HCI: version 6.0 (0x0e) revision 0x206b, manufacturer 0x0059
    [00:00:00.524,505] <inf> bt_hci_core: LMP: version 6.0 (0x0e) subver 0x206b
    [00:00:00.526,641] <inf> bt_mesh_provisionee: Device UUID: 4aac9165-01e3-433b-b553-6e9afe1c6cc4
    Mesh initialized
    [00:00:00.541,625] <dbg> bt_mesh_access: bt_mesh_model_publish: 
    Successfully enabled LC server
    [00:00:02.542,541] <dbg> bt_mesh_access: bt_mesh_model_data_store: Stored bt/mesh/s/5/data value
    [00:00:08.588,806] <wrn> bt_l2cap: Ignoring data for unknown channel ID 0x003a
    [00:00:21.292,785] <inf> bt_mesh_main: Primary Element: 0x06b5
    [00:00:21.300,140] <dbg> bt_mesh_access: bt_mesh_comp_provision: addr 0x06b5 elem_count 2
    [00:00:21.300,140] <dbg> bt_mesh_access: bt_mesh_comp_provision: addr 0x06b5 mod_count 13 vnd_mod_count 0
    [00:00:21.300,170] <dbg> bt_mesh_access: bt_mesh_comp_provision: addr 0x06b6 mod_count 3 vnd_mod_count 0
    [00:00:22.586,395] <wrn> bt_l2cap: Ignoring data for unknown channel ID 0x003a
    [00:00:25.108,917] <wrn> bt_l2cap: Ignoring data for unknown channel ID 0x003a
    [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
    [00:00:38.317,993] <dbg> bt_mesh_access: bt_mesh_model_recv: app_idx 0xfffe src 0x0001 dst 0x06b5
    [00:00:38.318,054] <dbg> bt_mesh_access: bt_mesh_model_recv: len 3: 800800
    [00:00:38.318,054] <dbg> bt_mesh_access: bt_mesh_model_recv: OpCode 0x00008008
    [00:00:38.347,778] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0xfffe dst 0x0001
    [00:00:38.347,869] <dbg> bt_mesh_access: bt_mesh_access_send: len 52: 0200590000000000ff00070001000d0000000200021000100410061007100013011303120412001101110200030000100f131013
    [00:00:38.349,670] <err> bt_mesh_transport: No multi-segment message contexts available
    [00:00:38.357,818] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0xfffe dst 0x0001
    [00:00:38.357,910] <dbg> bt_mesh_access: bt_mesh_access_send: len 52: 0200590000000000ff00070001000d0000000200021000100410061007100013011303120412001101110200030000100f131013
    [00:00:38.359,710] <err> bt_mesh_transport: No multi-segment message contexts available
    [00:00:38.367,858] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0xfffe dst 0x0001
    [00:00:38.367,950] <dbg> bt_mesh_access: bt_mesh_access_send: len 52: 0200590000000000ff00070001000d0000000200021000100410061007100013011303120412001101110200030000100f131013
    [00:00:38.369,781] <err> bt_mesh_transport: No multi-segment message contexts available
    [00:00:38.377,899] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0xfffe dst 0x0001
    [00:00:38.377,960] <dbg> bt_mesh_access: bt_mesh_access_send: len 52: 0200590000000000ff00070001000d0000000200021000100410061007100013011303120412001101110200030000100f131013
    [00:00:38.379,791] <err> bt_mesh_transport: No multi-segment message contexts available
    [00:00:38.387,939] <dbg> bt_mesh_access: bt_mesh_access_send: net_idx 0x0000 app_idx 0xfffe dst 0x0001
    [00:00:38.388,000] <dbg> bt_mesh_access: bt_mesh_access_send: len 52: 0200590000000000ff00070001000d0000000200021000100410061007100013011303120412001101110200030000100f131013
    [00:00:38.389,801] <err> bt_mesh_transport: No multi-segment message contexts available
    

    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

  • 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".

    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;
    	}

    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

Related