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.

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

Bluetooth: Mesh: Add some actual behavior in sample #33476

Merged
merged 1 commit into from
Mar 26, 2021

Conversation

trond-snekvik
Copy link
Contributor

Populates the onoff server stubs in the Bluetooth Mesh sample, and
implements generic LED based hardware support to include more boards.

Fixes #31031.

Signed-off-by: Trond Einar Snekvik [email protected]

#include "board.h"

static uint32_t oob_number;
static const struct device *gpio;
static struct mb_image onoff[] = {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I realize this is partially a copy-paste, but I think this can be put into ROM by making it const

Copy link
Collaborator

@pabigot pabigot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please incorporate the "fixup" patch from https:/pabigot/zephyr/commits/pr/33476 into this, so it works on a wider range of boards. This is the blocking change requested.

As a comment: This doesn't quite complete the documented plan #31031 (comment) which I failed to read closely enough: I'd hoped for instructions on how to do provisioning using Zephyr, rather than an unnamed and undocumented application.

samples/bluetooth/mesh_provisioner does find and provision a device with this sample, but pressing the button produces:

The Generic OnOff Client must be bound to a key before sending.

Also there are a lot of diagnostics, including this warning:

00:02:31.743,804] <wrn> bt_mesh_health_srv: No callback for getting faults

So this still isn't as helpful as one might want in getting new users up to speed with how to use Bluetooth Mesh in Zephyr.

Perhaps the provisioner app could be extended in concert with this to provide a self-contained Zephyr sample.

@trond-snekvik
Copy link
Contributor Author

Thanks for providing the right DeviceTree macros, I have incorporated them into the PR.
To expand the provisioner sample, I decided to add some functionality to the Config Client API, so I made a separate PR for this instead of adding scope creep to this one: #33614.

@pabigot
Copy link
Collaborator

pabigot commented Mar 23, 2021

@trond-snekvik Thanks for the updates. This still isn't going well.

I combined #33614 with this in a development branch https:/pabigot/zephyr/commits/nordic/mesh and installed the provisioner on one node, then the mesh sample on another, making sure to add --erase to the flash command to get rid of the previous configurations. The test devices are particle_xenon which are nRF52840 boards.

The provisioner provided:

Waiting for unprovisioned beacon...
Waiting for unprovisioned beacon...
Provisioning dddd0000000000000000000000000000
Waiting for node to be added...
Added node 0x0002
Configuring node 0x0002...

Note the unusual UUID.

The mesh sample produced the output below, showing successful provision then dying.

Show node provisioning details
Initializing...
Bluetooth initialized
[00:00:04.644,897] <inf> fsMesh initialized
_nvs: 8 Sectors of 4096 bytes
[00:00:04.644,927] <inf> fs_nvs: alloc wra: 0, ff0
[00:00:04.644,927] <inf> fs_nvs: data wra: 0, 0
[00:00:04.646,148] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:04.646,148] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
[00:00:04.646,148] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 2.5 Build 99
[00:00:04.646,362] <inf> bt_hci_core: No ID address. App must call settings_load()
[00:00:04.650,207] <inf> bt_hci_core: Identity: C1:EB:A0:99:5A:E2 (random)
[00:00:04.650,238] <inf> bt_hci_core: HCI: version 5.2 (0x0b) revision 0x0000, manufacturer 0x05f1
[00:00:04.650,238] <inf> bt_hci_core: LMP: version 5.2 (0x0b) subver 0xffff
[00:00:04.665,191] <inf> bt_mesh_prov_device: Device UUID: 00000000-0000-0000-0000-00000000dddd
[00:00:07.003,143] <inf> bt_mesh_main: Primary Element: 0x0002
[00:00:07.003,173] <dbg> bt_mesh_main.bt_mesh_provision: net_idx 0x0000 flags 0x00 iv_index 0x0000
[00:00:07.003,204] <dbg> bt_mesh_net.bt_mesh_net_create: idx 0 flags 0x00 iv_index 0
[00:00:07.003,234] <dbg> bt_mesh_net.bt_mesh_net_create: NetKey 992718565fa06c9104cf8a7725bf5d38
[00:00:07.009,765] <dbg> bt_mesh_net.bt_mesh_net_create: Storing network information persistently
[00:00:07.009,765] <dbg> bt_mesh_settings.bt_mesh_settings_store_schedule: Waiting 2000 ms vs rem 0 ms
[00:00:07.009,796] <dbg> bt_mesh_settings.bt_mesh_settings_store_schedule: Waiting 0 ms vs rem 2000 ms
[00:00:07.009,796] <dbg> bt_mesh_settings.bt_mesh_settings_store_schedule: Waiting 0 ms vs rem 0 ms
[00:00:07.009,826] <dbg> bt_mesh_net.store_pending_net: addr 0x0002 DevKey 31b08e02ba134c55c549429af7ab9083
[00:00:07.010,711] <dbg> bt_mesh_settings.store_pending: 
[00:00:07.030,914] <dbg> bt_mesh_net.store_pending_net: Stored Network value
[00:00:07.141,510] <dbg> bt_mesh_net.store_pending_iv: Stored IV value
[00:00:07.178,100] <dbg> bt_mesh_net.bt_mesh_net_pending_seq_store: Stored Seq value
[00:00:07.518,280] <dbg> bt_mesh_transport.trans_seg: Received 1/1
--- 34 messages dropped ---
[00:00:07.518,310] <dbg> bt_mesh_transport.trans_seg: Complete SDU
[00:00:07.518,310] <dbg> bt_mesh_settings.bt_mesh_settings_store_schedule: Waiting 2000 ms vs rem 0 ms
--- 39 messages dropped ---
[00:00:07.609,405] <dbg> bt_mesh_transport.send_seg: src 0x0002 dst 0x0001 app_idx 0xfffe aszmic 1 sdu_len 32
[00:00:07.609,405] <dbg> bt_mesh_transport.send_seg: SeqZero 0x0002 (segs: 3)
[00:00:07.609,436] <dbg> bt_mesh_transport.send_seg: seg 0: 9628833767610e17305a9777
[00:00:07.609,466] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:07.609,497] <dbg> bt_mesh_transport.send_seg: seg 1: 22d3e196ed5e17920c97dcfa
[00:00:07.609,497] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:07.609,527] <dbg> bt_mesh_transport.send_seg: seg 2: c1f3e5134a325cdc
[00:00:07.609,558] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0x0001
[00:00:07.609,558] <dbg> bt_mesh_transport.seg_tx_send_unacked: SeqZero: 0x0002 Attempts: 4
[00:00:07.609,619] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 0/2
[00:00:07.609,649] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 16 headroom 9 tailroom 4
[00:00:07.609,680] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 16: 808008029628833767610e17305a9777
[00:00:07.609,680] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000002
[00:00:07.609,710] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x000002
[00:00:07.609,863] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 1/2
[00:00:07.609,893] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 16 headroom 9 tailroom 4
[00:00:07.609,924] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 16: 8080082222d3e196ed5e17920c97dcfa
[00:00:07.609,924] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000003
[00:00:07.609,954] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x000003
[00:00:07.610,107] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 2/2
[00:00:07.610,137] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 12 headroom 9 tailroom 8
[00:00:07.610,168] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 12: 80800842c1f3e5134a325cdc
[00:00:07.610,198] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000004
[00:00:07.610,198] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x000004
[00:00:07.634,063] <dbg> bt_mesh_net.bt_mesh_net_recv: rssi -75 net_if 0
[00:00:07.683,441] <dbg> bt_mesh_net.bt_mesh_net_recv: rssi -69 net_if 0
[00:00:07.711,090] <dbg> bt_mesh_net.bt_mesh_net_recv: rssi -75 net_if 0
[00:00:08.129,302] <dbg> bt_mesh_transport.schedule_retransmit: 
[00:00:08.879,394] <dbg> bt_mesh_transport.seg_tx_send_unacked: SeqZero: 0x0002 Attempts: 3
[00:00:08.879,425] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 0/2
[00:00:08.879,425] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 16 headroom 9 tailroom 4
[00:00:08.879,455] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 16: 808008029628833767610e17305a9777
[00:00:08.879,455] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000005
[00:00:08.879,455] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x000005
[00:00:08.879,608] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 1/2
[00:00:08.879,638] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 16 headroom 9 tailroom 4
[00:00:08.879,669] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 16: 8080082222d3e196ed5e17920c97dcfa
[00:00:08.879,669] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000006
[00:00:08.879,699] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x000006
[00:00:08.879,852] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 2/2
[00:00:08.879,852] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 12 headroom 9 tailroom 8
[00:00:08.879,882] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 12: 80800842c1f3e5134a325cdc
[00:00:08.879,882] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000007
[00:00:08.879,882] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x000007
[00:00:09.245,452] <dbg> bt_mesh_transport.schedule_retransmit: 
[00:00:09.518,371] <dbg> bt_mesh_settings.store_pending: 
[00:00:09.995,544] <dbg> bt_mesh_transport.seg_tx_send_unacked: SeqZero: 0x0002 Attempts: 2
[00:00:09.995,574] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 0/2
[00:00:09.995,574] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 16 headroom 9 tailroom 4
[00:00:09.995,605] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 16: 808008029628833767610e17305a9777
[00:00:09.995,605] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000008
[00:00:09.995,605] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x000008
[00:00:09.995,788] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 1/2
[00:00:09.995,788] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 16 headroom 9 tailroom 4
[00:00:09.995,819] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 16: 8080082222d3e196ed5e17920c97dcfa
[00:00:09.995,819] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000009
[00:00:09.995,849] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x000009
[00:00:09.996,002] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 2/2
[00:00:09.996,002] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 12 headroom 9 tailroom 8
[00:00:09.996,032] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 12: 80800842c1f3e5134a325cdc
[00:00:09.996,032] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x00000a
[00:00:09.996,032] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x00000a
[00:00:10.361,694] <dbg> bt_mesh_transport.schedule_retransmit: 
[00:00:11.111,785] <dbg> bt_mesh_transport.seg_tx_send_unacked: SeqZero: 0x0002 Attempts: 1
[00:00:11.111,816] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 0/2
[00:00:11.111,816] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 16 headroom 9 tailroom 4
[00:00:11.111,846] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 16: 808008029628833767610e17305a9777
[00:00:11.111,846] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x00000b
[00:00:11.111,877] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x00000b
[00:00:11.112,030] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 1/2
[00:00:11.112,030] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 16 headroom 9 tailroom 4
[00:00:11.112,060] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 16: 8080082222d3e196ed5e17920c97dcfa
[00:00:11.112,060] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x00000c
[00:00:11.112,060] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x00000c
[00:00:11.112,213] <dbg> bt_mesh_transport.seg_tx_send_unacked: Sending 2/2
[00:00:11.112,243] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x0002 dst 0x0001 len 12 headroom 9 tailroom 8
[00:00:11.112,243] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 12: 80800842c1f3e5134a325cdc
[00:00:11.112,243] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x00000d
[00:00:11.112,274] <dbg> bt_mesh_net.net_header_encode: src 0x0002 dst 0x0001 ctl 0 seq 0x00000d
[00:00:11.477,691] <dbg> bt_mesh_transport.schedule_retransmit: 
[00:00:12.227,783] <err> bt_mesh_transport: Ran out of retransmit attempts

After resetting the mesh node I get the following. What happens is that it doesn't seem to notice that it's provisioned right away. When I press the button to switch the LED on, it self-provisions.

Show node restart details
Bluetooth initialized
[00:00:04.953,399] <inf> fs_nvsMesh initialized
: 8 Sectors of 4096 bytes
[00:00:04.953,430] <inf> fs_nvs: alloc wra: 0, ff0
[00:00:04.953,430] <inf> fs_nvs: data wra: 0, 0
[00:00:04.954,620] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:04.954,650] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
[00:00:04.954,650] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 2.5 Build 99
[00:00:04.954,864] <inf> bt_hci_core: No ID address. App must call settings_load()
[00:00:04.958,862] <inf> bt_hci_core: Identity: C1:EB:A0:99:5A:E2 (random)
[00:00:04.958,862] <inf> bt_hci_core: HCI: version 5.2 (0x0b) revision 0x0000, manufacturer 0x05f1
[00:00:04.958,862] <inf> bt_hci_core: LMP: version 5.2 (0x0b) subver 0xffff
[00:00:04.973,785] <inf> bt_mesh_prov_device: Device UUID: 00000000-0000-0000-0000-00000000dddd
Self-provisioning with address 0x5978
Provisioned and config[ured!
00:00:22.911,346] <inf> bt_mesh_main: Primary Element: 0x5978
[00:00:22.911,376] <dbg> bt_mesh_main.bt_mesh_provision: net_idx 0x0000 flags 0x00 iv_index 0x0000
[00:00:22.911,407] <dbg> bt_mesh_net.bt_mesh_net_create: idx 0 flags 0x00 iv_index 0
[00:00:22.911,437] <dbg> bt_mesh_net.bt_mesh_net_create: NetKey 00000000000000000000000000000000
[00:00:22.917,816] <dbg> bt_mesh_net.bt_mesh_net_create: Storing network information persistently
[00:00:22.917,816] <dbg> bt_mesh_settings.bt_mesh_settings_store_schedule: Waiting 2000 ms vs rem 0 ms
[00:00:22.917,846] <dbg> bt_mesh_settings.bt_mesh_settings_store_schedule: Waiting 0 ms vs rem 2000 ms
[00:00:22.917,877] <dbg> bt_mesh_settings.bt_mesh_settings_store_schedule: Waiting 0 ms vs rem 0 ms
[00:00:22.917,877] <dbg> bt_mesh_net.store_pending_net: addr 0x5978 DevKey 00000000000000000000000000000000
[00:00:22.938,659] <dbg> bt_mesh_net.store_pending_net: Stored Network value
[00:00:22.940,307] <dbg> bt_mesh_settings.bt_mesh_settings_store_schedule: Waiting 0 ms vs rem 0 ms
[00:00:22.945,861] <dbg> bt_mesh_settings.store_pending: 
[00:00:23.017,913] <dbg> bt_mesh_net.store_pending_iv: Stored IV value
[00:00:23.031,494] <dbg> bt_mesh_net.bt_mesh_net_pending_seq_store: Stored Seq value
Sending OnOff Set: on
set: on delay: 0 ms time: 0 ms
[00:00:32.801,574] <dbg> bt_mesh_transport.bt_mesh_trans_send: net_idx 0x0000 app_idx 0x0000 dst 0xffff
[00:00:32.801,574] <dbg> bt_mesh_transport.bt_mesh_trans_send: len 4: 82030100
[00:00:32.801,696] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0xffff
[00:00:32.801,696] <dbg> bt_mesh_net.bt_mesh_net_send: src 0x5978 dst 0xffff len 9 headroom 9 tailroom 11
[00:00:32.801,727] <dbg> bt_mesh_net.bt_mesh_net_send: Payload len 9: 781806fe79c9e3b773
[00:00:32.801,727] <dbg> bt_mesh_net.bt_mesh_net_send: Seq 0x000000
[00:00:32.801,727] <dbg> bt_mesh_net.net_header_encode: src 0x5978 dst 0xffff ctl 0 seq 0x000000
[00:00:32.801,757] <dbg> bt_mesh_net.loopback: 
[00:00:32.802,612] <dbg> bt_mesh_net.bt_mesh_net_local: src: 0x5978 dst: 0x5978 seq 0x000000 sub 0x20000540
[00:00:32.802,612] <dbg> bt_mesh_friend.bt_mesh_friend_match: No matching LPN for address 0xffff
[00:00:32.802,642] <dbg> bt_mesh_transport.bt_mesh_trans_recv: src 0x5978 dst 0xffff seq 0x00000000 friend_match 0
[00:00:32.802,642] <dbg> bt_mesh_transport.bt_mesh_trans_recv: Payload 781806fe79c9e3b773
[00:00:32.802,642] <dbg> bt_mesh_transport.trans_unseg: AFK 1 AID 0x38
[00:00:32.802,673] <dbg> bt_mesh_transport.sdu_recv: AKF 1 AID 0x38
[00:00:32.802,734] <dbg> bt_mesh_transport.sdu_recv: Decrypted (AppIdx: 0x000)

If I install the mesh sample on another device I get this:

Show second node provisioning details
Bluetooth initialized
[00:00:04.513,885] <inf> fs_nvs: 8 SeMesh initialized
ctors of 4096 bytes
[00:00:04.513,916] <inf> fs_nvs: alloc wra: 0, ff0
[00:00:04.513,916] <inf> fs_nvs: data wra: 0, 0
[00:00:04.515,106] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:04.515,136] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
[00:00:04.515,136] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 2.5 Build 99
[00:00:04.515,350] <inf> bt_hci_core: No ID address. App must call settings_load()
[00:00:04.519,195] <inf> bt_hci_core: Identity: D2:3B:A9:F8:C5:E7 (random)
[00:00:04.519,226] <inf> bt_hci_core: HCI: version 5.2 (0x0b) revision 0x0000, manufacturer 0x05f1
[00:00:04.519,226] <inf> bt_hci_core: LMP: version 5.2 (0x0b) subver 0xffff
[00:00:04.534,088] <inf> bt_mesh_prov_device: Device UUID: 00000000-0000-0000-0000-00000000dddd

This device also uses the bizarre UUID, so doesn't get provisioned.

@pabigot pabigot dismissed their stale review March 23, 2021 15:01

Changes integrated so no changes requested at this time, but sample still doesn't work as expected.

@jhedberg
Copy link
Member

Note the unusual UUID.

There's really nothing particularly unusual about it. Many mesh samples have used that from the beginning, since it made it easy to provision them using available Linux mesh tools (instead of copy-pasting or typing the entire UUID you just typed "prov dddd" in the Linux tool.

@pabigot
Copy link
Collaborator

pabigot commented Mar 23, 2021

Note the unusual UUID.

There's really nothing particularly unusual about it.

OK, but a hard-coded constant UUID in an auto-provisioning solution is not useful, because a mesh with one node is not useful.

A UUID based on the BT identity (assuming it's the one that comes from FICR, not some random thing that goes away when the flash is erased) would make the sample usable.

@jhedberg
Copy link
Member

A UUID based on the BT identity (assuming it's the one that comes from FICR, not some random thing that goes away when the flash is erased) would make the sample usable.

@pabigot agreed. I just wanted to stress that the hardcoded value in itself doesn’t indicate a bug somewhere, in case that’s what you were suspecting.

@trond-snekvik
Copy link
Contributor Author

There appears to be some instabilities in the provisioner sample, primarily caused by preemptive operation of the Bluetooth APIs. I have pushed two commits in #33614 to address this and the loopback warning. With these changes, I'm unable to reproduce the errors you have listed in the logs.

I have left the UUID as-is, as I agree with @jhedberg that this hardcoding is useful. It also does not affect the provisioner sample in any meaningful way.

@pabigot
Copy link
Collaborator

pabigot commented Mar 24, 2021

I have left the UUID as-is, as I agree with @jhedberg that this hardcoding is useful. It also does not affect the provisioner sample in any meaningful way.

Agreed, it doesn't affect the provisioner sample. It does mean the mesh sample using the Zephyr provisioner will work only for a mesh of size one. I don't understand why that would be a good thing. So https:/pabigot/zephyr/commits/nordic/mesh now has a patch to fix this.

Fixing the UUID I still have problems. I can get two nodes to provision, but when a third is added I get:

Waiting for unprovisioned beacon...
Provisioning e619c9844625e9b10000000000000000
Waiting for node to be added...
Timeout waiting for node to be added
Waiting for unprovisioned beacon...
Provisioning e619c9844625e9b10000000000000000
Waiting for node to be added...
Timeout waiting for node to be added

That may be due to CONFIG_BT_MESH_CDB_NODE_COUNT=3 in the mesh provisioner sample. Maybe it would be good to have the provisioner by default able to handle meshes of a reasonable size? 16 seems to be a limit that new users aren't likely to run into immediately.

Also the two nodes that do get provisioned have abysmal performance: pressing the button on one causes the other's LED to sometimes change immediately, but more often change one or two seconds later; then one or two seconds after that LED on the node where the button was pushed changes. That second problem may be partially influenced by to CONFIG_BT_DEBUG_LOG=y in the mesh sample causing deadlines to be missed.

But after changing the configs above to stop blasting out log messages and to possibly support 16 nodes, this sample is still far from providing a satisfactory out-of-box experience. Back in spring 2019 I had a Zephyr mesh sample in C++ that I managed to make work, and it was far more responsive. After several attempts at wiping out state and starting over, I still can't get a reliable 3-node mesh running where button presses are visible across the mesh in less than one second.

@pabigot
Copy link
Collaborator

pabigot commented Mar 24, 2021

Part of the confusion is because of the logic in button_pressed(), which ignores the actual local state of the LED in favor of only tracking the state of local button presses: if the local button pressed state is off, and the local LED state is on, pressing the button will transit an ON request rather than an OFF request, resulting in the press having no effect. This is not what people will expect.

@trond-snekvik
Copy link
Contributor Author

I have added the hwinfo based UUID by default. It can be disabled in prj.conf if we need to run with the static UUID. This is what we're doing in Nordic's SDK as well, and although it's a bit more cumbersome, it's causing any disruptive behavior, like the dddd UUID does with the provisioner sample.

I have turned off all core logging in favor of foundation model logging, which I find is the most useful when debugging. It's also not very verbose.

I have also altered the button logic to invert its own LED state, good suggestion.

Also the two nodes that do get provisioned have abysmal performance: pressing the button on one causes the other's LED to sometimes change immediately, but more often change one or two seconds later

This surprises me, as I have not been able to reproduce on my devices at all. Is this just because of the button issue, or are you still seeing this after the latest push? Does your USB changes affect this in any way? This sample now runs purely in the work handler and BT event handler thread after the initialization - is the USB module interfering with these threads?

@@ -139,7 +280,7 @@ static void prov_reset(void)
bt_mesh_prov_enable(BT_MESH_PROV_ADV | BT_MESH_PROV_GATT);
}

static const uint8_t dev_uuid[16] = { 0xdd, 0xdd };
static uint8_t dev_uuid[16] = { 0xdd, 0xdd };
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

FYI this could waste flash relative to the runtime assignment I suggested, since the 16-byte initial value has to be stored in flash then copied into this address during startup.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually, the instructions required to do this assignment at runtime adds up to exactly 16 bytes of flash on my setup 😄 There might be small variations on other platforms and compiler versions, but I think this falls into the personal preference category

static uint8_t app_key[16];
int err;

printk("Self-provisioning with address 0x%04x\n", addr);
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why not use the low two bytes of the device id, so it's consistent with what a provisioner would use?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good point, I'll change this

@pabigot
Copy link
Collaborator

pabigot commented Mar 26, 2021

Also the two nodes that do get provisioned have abysmal performance: pressing the button on one causes the other's LED to sometimes change immediately, but more often change one or two seconds later

This surprises me, as I have not been able to reproduce on my devices at all.

I could easily reproduce when I moved the devices away from each other. Turned out to be another hidden instance of #24416 and is resolved (for this case) by #33740.

At this point it appears things are working, and I'm getting decent range. Thanks.

Populates the onoff server stubs in the Bluetooth Mesh sample, and
implements generic LED based hardware support to include more boards.

Fixes zephyrproject-rtos#31031.

Signed-off-by: Trond Einar Snekvik <[email protected]>
@jhedberg jhedberg merged commit e1656ee into zephyrproject-rtos:master Mar 26, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

samples/bluetooth/mesh is not helpful
4 participants