Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Question : Friend & Low power node with nRF52840 #31905

Closed
4ayo opened this issue Feb 3, 2021 · 1 comment
Closed

Question : Friend & Low power node with nRF52840 #31905

4ayo opened this issue Feb 3, 2021 · 1 comment

Comments

@4ayo
Copy link

4ayo commented Feb 3, 2021 •
edited
Loading

Good morning,

I tried to setup a low power node and a friend with two nRF52840 and it doesn't seem to work. Any indication would be helpful.

For this, I used the onoff-app as base project, and changed the Kconfig as follow :

To Reproduce
For the low power node :

CONFIG_BT_MESH_LOW_POWER=y
CONFIG_BT_MESH_DEBUG_LOW_POWER=y
# Other values as default

For the friend :

CONFIG_BT_MESH_FRIEND=y
CONFIG_BT_MESH_FRIEND_ENABLED=y
CONFIG_BT_MESH_FRIEND_QUEUE_SIZE=16
CONFIG_BT_MESH_DEBUG_FRIEND=y
# Other values as default

Logs and console output
Then I provisionned the low power node first, then the friend, with the nRF mesh app. The logs are as follow :

For the low power node :

provisioning complete for net_idx 0x0000 addr 0x0002
[00:00:58.521,240] <inf> bt_mesh_main: Primary Element: 0x0002
[00:00:58.521,240] <dbg> bt_mesh_main.bt_mesh_provision: net_idx 0x0000 flags 0x00 iv_index 0x0000
[00:00:58.527,862] <dbg> bt_mesh_lpn.bt_mesh_lpn_init: 
[00:00:58.527,862] <dbg> bt_mesh_lpn.bt_mesh_lpn_init: Waiting 15000 ms for messages
[00:00:58.527,862] <dbg> bt_mesh_lpn.lpn_set_state: disabled -> timer
[00:01:04.729,492] <dbg> bt_mesh_lpn.bt_mesh_lpn_msg_received: Restarting establishment timer
[00:01:04.818,237] <dbg> bt_mesh_lpn.bt_mesh_lpn_msg_received: Restarting establishment timer
[00:01:05.223,205] <wrn> bt_mesh_transport: No matching TX context for ack
[00:01:05.223,205] <dbg> bt_mesh_lpn.bt_mesh_lpn_msg_received: Restarting establishment timer
[00:01:05.313,507] <dbg> bt_mesh_lpn.bt_mesh_lpn_msg_received: Restarting establishment timer
[00:01:06.888,763] <dbg> bt_mesh_lpn.bt_mesh_lpn_msg_received: Restarting establishment timer
[00:01:08.463,256] <dbg> bt_mesh_lpn.bt_mesh_lpn_msg_received: Restarting establishment timer
[00:01:08.466,308] <dbg> bt_mesh_lpn.bt_mesh_lpn_msg_received: Restarting establishment timer
[00:01:23.466,369] <dbg> bt_mesh_lpn.lpn_timeout: state: timer
[00:01:23.466,369] <dbg> bt_mesh_lpn.lpn_timeout: Starting to look for Friend nodes
[00:01:23.466,400] <dbg> bt_mesh_lpn.lpn_set_state: timer -> enabled
[00:01:23.466,613] <dbg> bt_mesh_lpn.send_friend_req: 
[00:01:23.467,346] <dbg> bt_mesh_lpn.lpn_set_state: enabled -> req wait
[00:01:23.567,413] <dbg> bt_mesh_lpn.lpn_timeout: state: req wait
[00:01:23.567,901] <dbg> bt_mesh_lpn.lpn_set_state: req wait -> wait offer
[00:01:24.657,989] <dbg> bt_mesh_lpn.lpn_timeout: state: wait offer
[00:01:24.657,989] <wrn> bt_mesh_lpn: No acceptable Friend Offers received
[00:01:24.658,233] <dbg> bt_mesh_lpn.lpn_set_state: wait offer -> enabled
[00:01:32.658,294] <dbg> bt_mesh_lpn.lpn_timeout: state: enabled

Then the 8 last lines would repeat as he tries to find a friend. So far, it seems to work.

For the friend :

provisioning complete for net_idx 0x0000 addr 0x0006
[00:00:14.376,708] <inf> bt_mesh_main: Primary Element: 0x0006
[00:00:14.376,708] <dbg> bt_mesh_main.bt_mesh_provision: net_idx 0x0000 flags 0x00 iv_index 0x0000
[00:00:20.808,410] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0006
[00:00:20.808,685] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:20.808,715] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:20.808,715] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:20.808,746] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:20.808,746] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:20.943,420] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0006
[00:00:21.348,419] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0006
[00:00:21.348,449] <wrn> bt_mesh_transport: No matching TX context for ack
[00:00:21.438,385] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0006
[00:00:21.438,568] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:23.013,397] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0006
[00:00:23.013,610] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:24.633,483] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0006
[00:00:24.678,497] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0006
[00:00:24.678,558] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:24.680,175] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001

I tried to play a bit with Kconfig option, for example setting BT_MESH_LPN_RECV_DELAY at 150 but without success. The connexion between the LPN and Friend is never established as the LPN is always sending request packets.

Is there an example somewhere about LPN & Friend ?

Expected behavior
I expected the friend to see the low power node and establish a connexion with it.

Impact
I need the Friend-Low power node feature for a project.

Environment (please complete the following information):

  • Linux Ubuntu 20.04.1 LTS
  • Toolchain : Zephyr SDK
  • Version 2.4.99 as per version file. The command git rev-parse HEAD gives me : 52ad9a468c1a3ae9a00d1e5aac389c5bfcf087ec.

Best regards.
@4ayo
Copy link
Author

4ayo commented Feb 4, 2021 •
edited
Loading

I've tried to change the config for the low power node as follow :

CONFIG_BT_MESH_LOW_POWER=y
CONFIG_BT_MESH_LPN_SCAN_LATENCY=30
CONFIG_BT_MESH_LPN_RECV_DELAY=40
CONFIG_BT_MESH_LPN_POLL_TIMEOUT=300
CONFIG_BT_MESH_DEBUG_LOW_POWER=y
# Other values as default

As I've seen it commented is some nrf config, without success.

==== EDIT :

After some research, it seems there is a problem at the network layer.

The method bt_mesh_net_decode() return an error and the error log is the following one : "Unable to find matching net for packet".

==== EDIT 2 :

The method bt_mesh_net_decode() calls bt_mesh_net_decode() which calls bt_mesh_net_cred_find() in subnet.c file, which returns false because this condition :

if (rx->sub->net_idx == BT_MESH_KEY_UNUSED) {
	continue;
}

is always true and make the program reach the end, returning false. As I'm not an expert of Zephyr or Bluetooth mesh, I dunno why it's like that.

==== EDIT 3 :
I tried with latest version of Zephyr (v2.5.0-rc2) just to see as I've seen change in LPN and Friend. Unfortunately, the sample aren't working anymore as the Kconfig is giving errors. For example :

warning: HAS_NORDIC_DRIVERS (defined at modules/hal_nordic/Kconfig:7) has direct dependencies 0 with value n, but is currently being y-selected by the following symbols:
 - SOC_SERIES_NRF52X (defined at soc/arm/nordic_nrf/nrf52/Kconfig.series:6), with value y, direct dependencies <choice> (value: y), and select condition <choice> (value: y)

==== EDIT 4 :
By using the following commit : c262239680507049a5a8d3c3cb9e18405413cdb3, I'm able to have a friendship connexion, without having the latest problem with Kconfig file. However, when LPN receive packets from Friend, it breaks down the friendship connexion.
For example, let's say, a button from the LPN is the client to turn on/off the LED and the Friend has a server as LED. When pressing the button, the Friend LED turn on but tries to send a message (because it's enqueued), which breaks friendship at next poll. I have the following logs :

From the LPN :

button_press_cnt 0x00
button_press_cnt 0x01 onoff_state 0x01
publish to 0xc000 onoff 0x0001 sw_idx 0x0000
[00:01:08.873,199] <dbg> bt_mesh_lpn.lpn_timeout: state: established
[00:01:08.873,199] <dbg> bt_mesh_lpn.send_friend_poll: lpn->sent_req 0x00
[00:01:08.873,931] <dbg> bt_mesh_lpn.req_sent: req 0x01 duration 90 err 0 state established
[00:01:08.874,084] <dbg> bt_mesh_lpn.lpn_set_state: established -> recv delay
[00:01:08.994,171] <dbg> bt_mesh_lpn.lpn_timeout: state: recv delay
[00:01:08.994,445] <dbg> bt_mesh_lpn.lpn_set_state: recv delay -> wait update
[00:01:09.369,232] <dbg> bt_mesh_lpn.lpn_timeout: state: wait update
[00:01:09.369,232] <wrn> bt_mesh_lpn: No response from Friend during ReceiveWindow
[00:01:09.369,445] <dbg> bt_mesh_lpn.lpn_set_state: wait update -> established
[00:01:09.469,543] <dbg> bt_mesh_lpn.lpn_timeout: state: established
[00:01:09.469,543] <dbg> bt_mesh_lpn.send_friend_poll: lpn->sent_req 0x00
[00:01:09.470,306] <dbg> bt_mesh_lpn.req_sent: req 0x01 duration 90 err 0 state established
[00:01:09.470,306] <dbg> bt_mesh_lpn.lpn_set_state: established -> recv delay
[00:01:09.590,393] <dbg> bt_mesh_lpn.lpn_timeout: state: recv delay
[00:01:09.590,667] <dbg> bt_mesh_lpn.lpn_set_state: recv delay -> wait update
[00:01:09.678,924] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:09.678,955] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:09.701,202] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:09.701,232] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:09.724,853] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:09.724,853] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:09.965,484] <dbg> bt_mesh_lpn.lpn_timeout: state: wait update
[00:01:09.965,484] <wrn> bt_mesh_lpn: No response from Friend during ReceiveWindow
[00:01:09.965,728] <dbg> bt_mesh_lpn.lpn_set_state: wait update -> established
[00:01:10.065,795] <dbg> bt_mesh_lpn.lpn_timeout: state: established
[00:01:10.065,795] <dbg> bt_mesh_lpn.send_friend_poll: lpn->sent_req 0x00
[00:01:10.066,528] <dbg> bt_mesh_lpn.req_sent: req 0x01 duration 90 err 0 state established
[00:01:10.066,680] <dbg> bt_mesh_lpn.lpn_set_state: established -> recv delay
[00:01:10.186,767] <dbg> bt_mesh_lpn.lpn_timeout: state: recv delay
[00:01:10.187,042] <dbg> bt_mesh_lpn.lpn_set_state: recv delay -> wait update
[00:01:10.299,896] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:10.299,926] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:10.330,230] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:10.330,261] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:10.356,445] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:10.356,475] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:10.561,828] <dbg> bt_mesh_lpn.lpn_timeout: state: wait update
[00:01:10.561,828] <wrn> bt_mesh_lpn: No response from Friend during ReceiveWindow
[00:01:10.562,072] <dbg> bt_mesh_lpn.lpn_set_state: wait update -> established
[00:01:10.662,139] <dbg> bt_mesh_lpn.lpn_timeout: state: established
[00:01:10.662,139] <dbg> bt_mesh_lpn.send_friend_poll: lpn->sent_req 0x00
[00:01:10.662,872] <dbg> bt_mesh_lpn.req_sent: req 0x01 duration 90 err 0 state established
[00:01:10.662,872] <dbg> bt_mesh_lpn.lpn_set_state: established -> recv delay
[00:01:10.782,958] <dbg> bt_mesh_lpn.lpn_timeout: state: recv delay
[00:01:10.783,233] <dbg> bt_mesh_lpn.lpn_set_state: recv delay -> wait update
[00:01:10.871,459] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:10.871,459] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:10.891,418] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:10.891,448] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:10.912,872] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:10.912,872] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:11.158,020] <dbg> bt_mesh_lpn.lpn_timeout: state: wait update
[00:01:11.158,020] <wrn> bt_mesh_lpn: No response from Friend during ReceiveWindow
[00:01:11.158,264] <dbg> bt_mesh_lpn.lpn_set_state: wait update -> established
[00:01:11.258,331] <dbg> bt_mesh_lpn.lpn_timeout: state: established
[00:01:11.258,331] <dbg> bt_mesh_lpn.send_friend_poll: lpn->sent_req 0x00
[00:01:11.259,063] <dbg> bt_mesh_lpn.req_sent: req 0x01 duration 90 err 0 state established
[00:01:11.259,063] <dbg> bt_mesh_lpn.lpn_set_state: established -> recv delay
[00:01:11.379,150] <dbg> bt_mesh_lpn.lpn_timeout: state: recv delay
[00:01:11.379,425] <dbg> bt_mesh_lpn.lpn_set_state: recv delay -> wait update
[00:01:11.488,281] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:11.488,311] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:11.512,878] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:11.512,908] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:11.541,625] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:11.541,656] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:11.754,211] <dbg> bt_mesh_lpn.lpn_timeout: state: wait update
[00:01:11.754,211] <wrn> bt_mesh_lpn: No response from Friend during ReceiveWindow
[00:01:11.754,455] <dbg> bt_mesh_lpn.lpn_set_state: wait update -> established
[00:01:11.854,522] <dbg> bt_mesh_lpn.lpn_timeout: state: established
[00:01:11.854,522] <dbg> bt_mesh_lpn.send_friend_poll: lpn->sent_req 0x00
[00:01:11.855,255] <dbg> bt_mesh_lpn.req_sent: req 0x01 duration 90 err 0 state established
[00:01:11.855,255] <dbg> bt_mesh_lpn.lpn_set_state: established -> recv delay
[00:01:11.975,341] <dbg> bt_mesh_lpn.lpn_timeout: state: recv delay
[00:01:11.975,616] <dbg> bt_mesh_lpn.lpn_set_state: recv delay -> wait update
[00:01:12.063,934] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:12.063,964] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:12.085,571] <wrn> bt_mesh_net: Dropping too short mesh packet (len 17)
[00:01:12.085,601] <wrn> bt_mesh_net: 0007000102000c000846f8196a6d749~
[00:01:12.113,464] <wrn> bt_mesh_net: Droppi+-----------------------------+7)
[00:01:12.113,494] <wrn> bt_mesh_net: 000700|                             |
[00:01:12.350,402] <dbg> bt_mesh_lpn.lpn_tim|  Cannot open /dev/ttyACM1!  |
[00:01:12.350,402] <wrn> bt_mesh_lpn: No res|                             |eWindow
[00:01:12.350,646] <dbg> bt_mesh_lpn.lpn_set+-----------------------------+hed
[00:01:12.450,714] <dbg> bt_mesh_lpn.lpn_timeout: state: established
[00:01:12.450,714] <err> bt_mesh_lpn: No response from Friend after 6 retries
[00:01:12.450,714] <dbg> bt_mesh_lpn.clear_friendship: force 0 disable 0
[00:01:12.450,714] <dbg> bt_mesh_lpn.send_friend_clear: 
[00:01:12.571,655] <dbg> bt_mesh_lpn.lpn_set_state: established -> clear
[00:01:13.671,722] <dbg> bt_mesh_lpn.lpn_timeout: state: clear
[00:01:13.671,722] <dbg> bt_mesh_lpn.clear_friendship: force 0 disable 0
[00:01:13.671,752] <dbg> bt_mesh_lpn.send_friend_clear: 
[00:01:13.792,663] <dbg> bt_mesh_lpn.lpn_set_state: clear -> clear
[00:01:14.892,730] <dbg> bt_mesh_lpn.lpn_timeout: state: clear
[00:01:14.892,730] <dbg> bt_mesh_lpn.clear_friendship: force 0 disable 0
[00:01:14.892,761] <dbg> bt_mesh_lpn.send_friend_clear: 
[00:01:15.013,671] <dbg> bt_mesh_lpn.lpn_set_state: clear -> clear
[00:01:16.113,739] <dbg> bt_mesh_lpn.lpn_timeout: state: clear
[00:01:16.113,739] <dbg> bt_mesh_lpn.clear_friendship: force 0 disable 0
[00:01:16.113,769] <dbg> bt_mesh_lpn.lpn_set_state: clear -> enabled

From the Friend :

gen_onoff_set
addr 0x0c state 0x01
addr 0x000c onoff 0x01
gen_onoff_set
addr 0x0c state 0x01
addr 0x000c onoff 0x01
[00:00:50.284,179] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0xc000
[00:00:50.289,642] <dbg> bt_mesh_friend.bt_mesh_friend_match: LPN 0x0008 matched address 0x0008
[00:00:50.289,642] <dbg> bt_mesh_friend.bt_mesh_friend_enqueue_tx: net_idx 0x0000 dst 0x0008 src 0x000c
[00:00:50.289,642] <dbg> bt_mesh_friend.friend_lpn_enqueue_tx: LPN 0x0008
[00:00:50.289,672] <dbg> bt_mesh_friend.enqueue_friend_pdu: type 0
[00:00:50.289,672] <dbg> bt_mesh_friend.friend_lpn_enqueue_tx: Queued message for LPN 0x0008
[00:00:50.504,882] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0xc000
[00:00:50.510,314] <dbg> bt_mesh_friend.bt_mesh_friend_match: LPN 0x0008 matched address 0x0008
[00:00:50.510,314] <dbg> bt_mesh_friend.bt_mesh_friend_enqueue_tx: net_idx 0x0000 dst 0x0008 src 0x000c
[00:00:50.510,345] <dbg> bt_mesh_friend.friend_lpn_enqueue_tx: LPN 0x0008
[00:00:50.510,375] <dbg> bt_mesh_friend.enqueue_friend_pdu: type 0
[00:00:50.510,375] <dbg> bt_mesh_friend.friend_lpn_enqueue_tx: Queued message for LPN 0x0008
[00:01:09.807,250] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x000c
[00:01:09.807,281] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:09.807,281] <dbg> bt_mesh_friend.bt_mesh_friend_poll: msg->fsn 0 frnd->fsn 1
[00:01:09.807,312] <dbg> bt_mesh_friend.friend_recv_delay: Waiting RecvDelay of 201 ms
[00:01:10.008,361] <dbg> bt_mesh_friend.friend_timeout: lpn 0x0008 send_last 0 last (nil)
[00:01:10.008,361] <wrn> bt_mesh_app_keys: Unknown AppKey 0x002
[00:01:10.404,327] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x000c
[00:01:10.404,327] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:10.404,327] <dbg> bt_mesh_friend.bt_mesh_friend_poll: msg->fsn 0 frnd->fsn 0
[00:01:10.404,357] <dbg> bt_mesh_friend.friend_recv_delay: Waiting RecvDelay of 201 ms
[00:01:10.404,388] <dbg> bt_mesh_friend.bt_mesh_friend_poll: Re-sending last PDU
[00:01:10.605,438] <dbg> bt_mesh_friend.friend_timeout: lpn 0x0008 send_last 1 last 0x20008334
[00:01:10.605,468] <dbg> bt_mesh_friend.friend_timeout: Sending frnd->last 0x20008334
[00:01:10.607,116] <dbg> bt_mesh_friend.buf_send_start: err 0
[00:01:10.667,785] <dbg> bt_mesh_friend.buf_send_end: err 0
[00:01:10.667,816] <dbg> bt_mesh_friend.buf_send_end: Waiting 30000 ms for next poll
[00:01:11.026,000] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x000c
[00:01:11.026,031] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:11.026,031] <dbg> bt_mesh_friend.bt_mesh_friend_poll: msg->fsn 0 frnd->fsn 0
[00:01:11.026,062] <dbg> bt_mesh_friend.friend_recv_delay: Waiting RecvDelay of 201 ms
[00:01:11.026,062] <dbg> bt_mesh_friend.bt_mesh_friend_poll: Re-sending last PDU
[00:01:11.227,111] <dbg> bt_mesh_friend.friend_timeout: lpn 0x0008 send_last 1 last 0x20008334
[00:01:11.227,111] <dbg> bt_mesh_friend.friend_timeout: Sending frnd->last 0x20008334
[00:01:11.228,790] <dbg> bt_mesh_friend.buf_send_start: err 0
[00:01:11.289,642] <dbg> bt_mesh_friend.buf_send_end: err 0
[00:01:11.289,672] <dbg> bt_mesh_friend.buf_send_end: Waiting 30000 ms for next poll
[00:01:11.596,923] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x000c
[00:01:11.596,923] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:11.596,954] <dbg> bt_mesh_friend.bt_mesh_friend_poll: msg->fsn 0 frnd->fsn 0
[00:01:11.596,954] <dbg> bt_mesh_friend.friend_recv_delay: Waiting RecvDelay of 201 ms
[00:01:11.596,954] <dbg> bt_mesh_friend.bt_mesh_friend_poll: Re-sending last PDU
[00:01:11.798,034] <dbg> bt_mesh_friend.friend_timeout: lpn 0x0008 send_last 1 last 0x20008334
[00:01:11.798,034] <dbg> bt_mesh_friend.friend_timeout: Sending frnd->last 0x20008334
[00:01:11.799,713] <dbg> bt_mesh_friend.buf_send_start: err 0
[00:01:11.860,412] <dbg> bt_mesh_friend.buf_send_end: err 0
[00:01:11.860,412] <dbg> bt_mesh_friend.buf_send_end: Waiting 30000 ms for next poll
[00:01:12.214,416] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x000c
[00:01:12.214,416] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:12.214,447] <dbg> bt_mesh_friend.bt_mesh_friend_poll: msg->fsn 0 frnd->fsn 0
[00:01:12.214,447] <dbg> bt_mesh_friend.friend_recv_delay: Waiting RecvDelay of 201 ms
[00:01:12.214,477] <dbg> bt_mesh_friend.bt_mesh_friend_poll: Re-sending last PDU
[00:01:12.415,527] <dbg> bt_mesh_friend.friend_timeout: lpn 0x0008 send_last 1 last 0x20008334
[00:01:12.415,557] <dbg> bt_mesh_friend.friend_timeout: Sending frnd->last 0x20008334
[00:01:12.417,144] <dbg> bt_mesh_friend.buf_send_start: err 0
[00:01:12.477,813] <dbg> bt_mesh_friend.buf_send_end: err 0
[00:01:12.477,844] <dbg> bt_mesh_friend.buf_send_end: Waiting 30000 ms for next poll
[00:01:12.789,276] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x000c
[00:01:12.789,306] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:12.789,306] <dbg> bt_mesh_friend.bt_mesh_friend_poll: msg->fsn 0 frnd->fsn 0
[00:01:12.789,337] <dbg> bt_mesh_friend.friend_recv_delay: Waiting RecvDelay of 201 ms
[00:01:12.789,337] <dbg> bt_mesh_friend.bt_mesh_friend_poll: Re-sending last PDU
[00:01:12.990,417] <dbg> bt_mesh_friend.friend_timeout: lpn 0x0008 send_last 1 last 0x20008334
[00:01:12.990,447] <dbg> bt_mesh_friend.friend_timeout: Sending frnd->last 0x20008334
[00:01:12.992,095] <dbg> bt_mesh_friend.buf_+-----------------------------+
[00:01:13.052,764] <dbg> bt_mesh_friend.buf_|                             |
[00:01:13.052,795] <dbg> bt_mesh_friend.buf_|  Cannot open /dev/ttyACM0!  |next poll
[00:01:13.412,658] <dbg> bt_mesh_friend.bt_m|                             |PN for address 0x000c
[00:01:13.412,689] <dbg> bt_mesh_friend.bt_m+-----------------------------+08 counter 0x0001
[00:01:13.412,689] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:13.412,780] <dbg> bt_mesh_friend.bt_mesh_friend_match: LPN 0x0008 matched address 0x0008
[00:01:13.412,780] <dbg> bt_mesh_friend.bt_mesh_friend_enqueue_tx: net_idx 0x0000 dst 0x0008 src 0x000c
[00:01:13.412,811] <dbg> bt_mesh_friend.friend_lpn_enqueue_tx: LPN 0x0008
[00:01:13.412,841] <dbg> bt_mesh_friend.enqueue_friend_pdu: type 0
[00:01:13.412,841] <dbg> bt_mesh_friend.friend_lpn_enqueue_tx: Queued message for LPN 0x0008
[00:01:13.412,841] <dbg> bt_mesh_friend.friend_clear: LPN 0x0008
[00:01:14.606,536] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x000c
[00:01:14.606,567] <dbg> bt_mesh_friend.bt_mesh_friend_clear: LPN addr 0x0008 counter 0x0001
[00:01:14.606,567] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:14.606,597] <wrn> bt_mesh_friend: No matching LPN addr 0x0008
[00:01:15.827,117] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x000c
[00:01:15.827,148] <dbg> bt_mesh_friend.bt_mesh_friend_clear: LPN addr 0x0008 counter 0x0001
[00:01:15.827,148] <dbg> bt_mesh_friend.bt_mesh_friend_find: net_idx 0x0000 lpn_addr 0x0008
[00:01:15.827,148] <wrn> bt_mesh_friend: No matching LPN addr 0x0008

==== EDIT 5 :
I could have the latest version of Zephyr by running west update. It permits me to avoid the errors encoutered in EDIT 4. Unfortunately, I still have the problem described in EDIT 4. For clarity, I'll close this issue and open a new one tagged as bug and explain exactly the problem encoutered.

@4ayo 4ayo closed this as completed Feb 5, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@4ayo