Zephyr: Samples: BluetoothMesh: not able to connect with device over GATT to provision it

[vikrant8051]

I'm successfully able to build & flash apps (with latest things) available in samples/boards/nrf52/mesh directory. After that they are advertising itself as unprovisioned BluetoothMesh Devices.

But as soon as we try to connect it with nRFMesh App, after that provisioning process does not get completed. Plus device stops advertising as Bluetooth Device so we have to reset it.

[cvinayak]

@vikrant8051 could you give more details on which commit this was last working? Did you try bisecting?

[George-Stefan]

I have the same problem with a MESH app created to test Vega board.
test_mesh_2.zip

[George-Stefan]

Debugging shows that the continuous advertising (started from MESH) causes the connection for provisioning to fail.
I reproduced the issue in a simpler scenario wih peripheral_hr.
main_peripheral_hr.zip

[cvinayak]

@George-Stefan I tested your main.c file and I dont see any connection loss. Is this 100% reproducible or random?

Below is the logic trace of advertisements transition to peripheral and then when heartrate is 160, continuous scanning is started, the link stays stable.

[George-Stefan]

I use NXP IoT Toolbox running on iphone to connect to the peripheral_hr running on Vega board.
The reproducibility is 100%.
Current connection fails with timeout (0x8 error code) and new connections fail with 0x3e (on slave side)

[cvinayak]

What is the connection interval in these connections?

[George-Stefan]

@cvinayak 48.7 ms (iphone), tried with an windows app too (50ms)

Checked all combinations of controller/ticker.
Enabled BT_CTLR_XTAL_ADVANCED, BT_CTLR_SCHED_ADVANCED.

It didn't make any difference, it fails as before

[cvinayak]

@George-Stefan I may know the issue (in the new split controller scheduling pipeline), if the intervals of two overlapping events are similar and are to be scheduled within a gap of 1.5 ms (pre-empt timeout) then the second in the pipeline is not able to pre-empt the currently occupying BLE event in the 'unreserved timespace' (in this case the continuous scanner does not yield and is not being pre-empted). The reason for this being, there is only one pre-empt ticker instance that is scheduled in 1.5 ms interval, and the other event in the pipeline cannot start it when it has been already started by the previous event in the pipeline.

The solution could be to chain the pre-empt ticker to start (on each expiry) with the ticks_to_expire of next in pipeline (if any).

@pskhansen ^^ @mtpr-ot ^^

@George-Stefan Please confirm that the issue is reproducible with CONFIG_BT_TICKER_COMPATIBILITY_MODE=y too?

No action from others in this issue, until I come back with more updates on a fix.

[George-Stefan]

@George-Stefan Please confirm that the issue is reproducible with CONFIG_BT_TICKER_COMPATIBILITY_MODE=y too?

Yes, it is

[George-Stefan]

test_mesh_2.zip
I use the nRF Mesh app running on iphone to do the provisioning. The provisioning never completes

[vikrant8051]

Is any PR under pipeline to solve this issue. ?
Till now with latest master branch not able to get rid off from this issue.

[carlescufi]

@vikrant8051 which board are you running this on?

[vikrant8051]

@carlescufi nrf52840_pca10056 board. But I think issue is board independent. Right ?

[George-Stefan]

@vikrant8051 Can you check my scenario?

I use NXP IoT Toolbox running on iphone to connect to the peripheral_hr running on Vega board.
The reproducibility is 100%.
Current connection fails with timeout (0x8 error code) and new connections fail with 0x3e (on slave side)

Debugging shows that the continuous advertising (started from MESH) causes the connection for provisioning to fail.
I reproduced the issue in a simpler scenario wih peripheral_hr.
main_peripheral_hr.zip

[carlescufi]

@carlescufi nrf52840_pca10056 board. But I think issue is board independent. Right ?

@vikrant8051
Possibly, yes. Could you let us know exactly how to reproduce the issue with nrf52840_pca10056? We don't have Vega boards to test.

[carlescufi]

@vikrant8051 could you please give us detailed steps on how to reproduce this problem? And if possible the version of master that you are using (commit SHA).

[vikrant8051]

@carlescufi
I have tested the things with latest master branch for all available #BluetoothMesh App in it on nrf52_pca10056 board.

You have to just build & flash the code as usual using West build & West flash & that's it.

After that Mesh Device not allow you to provision it.

(I also tried to erase entire flash & then burn the new image. Even after that getting same result)

I always prefer to do testing with Apps available in samples/boards/nrf52/mesh/ directory.

Kindly build & flash any one out of the two on nRF52_pca10056 board for confirmation.

Thank You!!

[trond-snekvik]

@vikrant8051
I wasn't able to reproduce this on nrf52_pca10056 with the Nordic Mesh Android app in any of the mesh or board samples. @George-Stefan mentioned he's using the iOS app, is this the case for you as well?

[vikrant8051]

@trond-snekvik
I've just upgraded my local repo & again tried but facing same issue.

Is your local repo sync with latest master branch ?

I also tried with Nordic, Silicon & Dialog Semiconductors Mesh Apps (on Android) but not able to complete Provisioning in any case.

[vikrant8051]

@trond-snekvik
I tried with following Apps:

1. zephyr/samples/bluetooth/mesh
2. zephyr/samples/boards/nrf52/mesh/onoff-app
3. zephyr/samples/boards/nrf52/mesh/onoff_level_lighting_vnd_app

None of these are allowing me to provision the nrf52840_pca10056 board.

[vikrant8051]

@trond-snekvik
To avoid any confusion,

1. deleted my GitHub forked version of Zephyr
2. Local repo on Laptop
3. Forked new Zephyr using GitHub's forked GUI button
4. Clone this latest forked version on my laptop

Even after that getting same result. Your comments now surprising me !!

(Also test the things for thingy52: nrf52_pca20020)

@jhedberg @carlescufi @cvinayak Are you able to provision nrf52_pca10056 by flashing apps in samples/boards/nrf52/mesh ?

[trond-snekvik]

@vikrant8051
I tested samples/bluetooth/mesh and samples/boards/nrf52/mesh/onoff-app on commit 19d4caaaab. I've observed strange GATT behavior when changing the configuration, but it works consistently with the default config in both apps. Using the nRF Mesh App v2.0.5 on Android 9. Could you upload a compiled hexfile, so we can narrow it down a bit?

[vikrant8051]

@trond-snekvik
Why don't you test the things for latest Master branch (samples/boards/nrf52/mesh/onoff-app) ?
I had put default configurations. Even after that couldn't provision the board.

Please do the same to get that hexfile & share your result if you are successful.

Once I reach the home (at today evening), I will checkout with https://github.com/zephyrproject-rtos/zephyr/commit/19d4caaaabf751347c5289a1e6c05a1a2d86d24a this commit & inform you.

[vikrant8051]

@trond-snekvik
https://github.com/zephyrproject-rtos/zephyr/commit/19d4caaaabf751347c5289a1e6c05a1a2d86d24a it has merged just before 23 hours. Means you are using almost latest master branch.

Then why I was facing the issue (I just checked yesterday night) ? Strange !!

[George-Stefan]

@vikrant8051 Can you check my scenario?

I use NXP IoT Toolbox running on iphone to connect to the peripheral_hr running on Vega board.
The reproducibility is 100%.
Current connection fails with timeout (0x8 error code) and new connections fail with 0x3e (on slave side)

Debugging shows that the continuous advertising (started from MESH) causes the connection for provisioning to fail.
I reproduced the issue in a simpler scenario wih peripheral_hr.
main_peripheral_hr.zip

[vikrant8051]

@George-Stefan
Sorry but at present it is out of the scope for me. I am in process of submitting new PRs but waiting to solve this issue so that I can test my new changes.

Today I am going to execute 'West update' command & hope that may solve this issue.

[vikrant8051]

@vikrant8051
I tested samples/bluetooth/mesh and samples/boards/nrf52/mesh/onoff-app on commit 19d4caa. I've observed strange GATT behavior when changing the configuration, but it works consistently with the default config in both apps. Using the nRF Mesh App v2.0.5 on Android 9. Could you upload a compiled hexfile, so we can narrow it down a bit?

@trond-snekvik

I installed entire 'zephyrproject' on freshly installed ubuntu 18.04 by following Zephyr Getting started guide & flash all Apps available in samples/boards/nrf52/mesh directory one by one.
None of them allowing me to provision nrf52840_pca10056 board..

Then I jump on this https://github.com/zephyrproject-rtos/zephyr/commit/19d4caaaabf751347c5289a1e6c05a1a2d86d24a commit & again test the things for two Apps in same directory. Result is same. Now how this can be possible that things are working for you & not for me ?

Each time I have put default configuration setting.

@jhedberg @carlescufi @cvinayak @nashif Please test one of the App from following list on nrf52840_pca10056 board & confirm about whether they are allowing to provision it or not with latest master branch?

1. zephyr/samples/bluetooth/mesh
2. zephyr/samples/boards/nrf52/mesh/onoff-app
3. zephyr/samples/boards/nrf52/mesh/onoff_level_lighting_vnd_app

Plz find attachment of my zephyr/samples/boards/nrf52/mesh directory for your ref. which has hex files .....
mesh.zip

[vikrant8051]

Is that mean, no one else facing this issue ?

[vikrant8051]

Booting Zephyr OS build zephyr-v2.0.0-1633-gdbb561fd2fe2
Initializing...
Bluetooth initialized
[00:00:00.00Mesh initialized
power-> 100, color-> 100
Reset Counter -> 0
9,429] fs_nvs: 8 Sectors of 4096 bytes
[00:00:00.009,429] fs_nvs: alloc wra: 1, 918
[00:00:00.009,460] fs_nvs: data wra: 1, 801
[00:00:00.012,268] bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.012,268] bt_hci_core: HW Variant: nRF52x (0x0002)
[00:00:00.012,268] bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 2.0 Build 99
[00:00:00.012,481] bt_hci_core: No ID address. App must call settings_load()
[00:00:00.014,648] bt_mesh_proxy.bt_mesh_proxy_adv_start:
[00:00:00.029,693] bt_hci_core: Identity: d3:c8:85:af:dc:a2 (random)
[00:00:00.029,724] bt_hci_core: HCI: version 5.1 (0x0a) revision 0x0000, manufacturer 0x05f1
[00:00:00.029,724] bt_hci_core: LMP: version 5.1 (0x0a) subver 0xffff
[00:00:00.045,471] bt_settings: Saving ID
[00:00:00.052,642] bt_mesh_main: Device UUID: 00000000-0000-0000-0000-d3c885a~
[00:00:00.053,100] bt_mesh_proxy.bt_mesh_proxy_adv_stop: adv_enabled 0
[00:00:00.053,710] bt_mesh_proxy.bt_mesh_proxy_prov_enable:
[00:00:00.173,889] bt_mesh_proxy.bt_mesh_proxy_adv_start:
[00:00:00.435,760] bt_mesh_prov.pub_key_ready: Local public key ready
[00:00:05.053,100] bt_mesh_proxy.bt_mesh_proxy_adv_stop: adv_enabled 1
[00:00:05.053,222] bt_mesh_proxy: Failed to stop advertising (err -5)
[00:00:05.053,222] bt_mesh_adv: Advertising failed: err -69
[00:00:05.053,253] bt_mesh_proxy.bt_mesh_proxy_adv_start:
Reset Counter set to Zero
[00:00:10.053,192] bt_mesh_proxy.bt_mesh_proxy_adv_stop: adv_enabled 1
[00:00:10.053,314] bt_mesh_proxy: Failed to stop advertising (err -5)
[00:00:10.053,314] bt_mesh_adv: Advertising failed: err -69

In case of onoff_level_lighting_vnd_app, getting this log after enabling these config parameter ..
CONFIG_BT_DEBUG_LOG=y
CONFIG_BT_MESH_DEBUG=y
CONFIG_BT_MESH_DEBUG_PROV=y
CONFIG_BT_MESH_DEBUG_PROXY=y

[jhedberg]

[00:00:10.053,314] bt_mesh_proxy: Failed to stop advertising (err -5)

That's proxy.c that's failing to stop advertising, and the return value is EIO. The only place in hci_core.c that can return EIO is the bt_hci_cmd_send_sync() call. This will happen when the HCI_LE_Set_Adv_Enable(disable) command returns a non-zero command complete status. You'd need to add some more debug logs to the controller side to figure out why this HCI command is failing.

[00:00:10.053,314] bt_mesh_adv: Advertising failed: err -69

That's EALREADY and it's coming from adv.c i.e. the advertising bearer. Most likely cause is the previous error from proxy.c, i.e. since proxy.c was unable to stop connectable advertising adv.c is unable to start non-connectable advertising.

[jhedberg]

@vikrant8051 the useful debugs to enable in this case are CONFIG_BT_DEBUG_HCI_CORE and CONFIG_BT_DEBUG_HCI_DRIVER. Disable any higher level stuff like the mesh debug logs - those are only causing unnecessary noise.

[carlescufi]

@jhedberg @carlescufi @cvinayak @nashif Please test one of the App from following list on nrf52840_pca10056 board & confirm about whether they are allowing to provision it or not with latest master branch?

1. zephyr/samples/bluetooth/mesh
2. zephyr/samples/boards/nrf52/mesh/onoff-app
3. zephyr/samples/boards/nrf52/mesh/onoff_level_lighting_vnd_app

@vikrant8051 I just ran the following test:

1. Fetch upstream master, as of today
2. Built samples/bluetooth/mesh and flashed on nrf52840_pca10056
3. Opened up the nRF Mesh iOS application (version 2.0.0, running on iPhone 11)
4. Pressed the top-right "+" button
5. "Zephyr" appears
6. Select it, click on "Provision"
7. Select "No OOB"
8. "Success. Provisioning Complete" appears on the screen

This seems to work fine. Can you try another board? Your board might have an issue.

[cvinayak]

I have tested the samples/bluetooth/mesh sample with nRF mesh app version 2.1.0. And I can provision successfully.

[vikrant8051]

Hi @carlescufi @cvinayak
Could you please test one of the App from samples/boards/nrf52/mesh/ directory on that boards?

Yesterday, i also tried samples/bluetooth/mesh this app. Initially it works but after reprogramming it stops working.

I have already tested things with thingy52 & getting same issue

[carlescufi]

Hi @carlescufi @cvinayak
Could you please test one of the App from samples/boards/nrf52/mesh/ directory on that boards?

Yesterday, i also tried samples/bluetooth/mesh this app. Initially it works but after reprogramming it stops working.

I have already tested things with thingy52 & getting same issue

@vikrant8051

I just tried samples/boards/nrf52/mesh/onoff-app using the exact same procedure and worked fine as well.

NOTE: I am flashing with west flash --erase every time to make sure there are no stale bonds or data in my flash.

[cvinayak]

I tested the samples/boards/nrf52/mesh/onoff-app with nRF mesh app now, and successfully provisioned it, too.

[vikrant8051]

@cvinayak @carlescufi
That means your local repo is not synced with latest master branch !!
Because I've just sync mine & due to some stack level issue not able to build any previously mentioned Apps.
I can only test after resolving this issue.

I had also tried "nrfjprog --eraseall -f nrf52" before west flash

[carlescufi]

@cvinayak @carlescufi
That means your local repo is not synced with latest master branch !!
Because I've just sync mine & due to some stack level issue not able to build any previously mentioned App.

@vikrant8051 I literally just did:

git fetch upstream
git reset --hard upstream/master
west update
west build -b nrf52840_pca10056 samples/boards/nrf52/mesh/onoff-app
west flash --erase

And all works fine

[carlescufi]

The last commit I tested is 740f6868a58d40d5963d592a9d19dce6cee8ea00

[vikrant8051]

@carlescufi after west update able to build the code.

[vikrant8051]

But provisioning issue has not solved

[carlescufi]

But provisioning issue has not solved

I really don't know how to proceed from here @vikrant8051 . Do you have another board you can test with? or another phone? 3 or 4 different people have now tried to reproduce this and we can't.

[vikrant8051]

Now I used another phone with latest Android 9 & now able to provision
samples/boards/nrf52/mesh/onoff-app &
samples/bluetooth/mesh app.

But not same is happening in case of samples/boards/nrf52/mesh/onoff_level_lighting_vnd_app.

[vikrant8051]

[00:00:00.109,771] os: BUS FAULT
[00:00:00.109,771] os: Precise data bus error
[00:00:00.109,771] os: BFAR Address: 0x61000008
[00:00:00.109,802] os: r0/a1: 0x2000427c r1/a2: 0x00000004 r2/a3: 0x00000000
[00:00:00.109,802] os: r3/a4: 0x2000427c r12/ip: 0x00000000 r14/lr: 0x0002818f
[00:00:00.109,832] os: xpsr: 0x61000000
[00:00:00.109,832] os: Faulting instruction address (r15/pc): 0x0002883c
[00:00:00.109,832] os: >>> ZEPHYR FATAL ERROR 0: CPU exception on CPU 0
[00:00:00.109,863] os: Current thread: 0x200012a8 (unknown)
[00:00:00.308,044] os: Halting system

i am getting this debug log after enabling following config in case of samples/boards/nrf52/mesh/onoff_level_lighting_vnd_app.
CONFIG_BT_DEBUG_HCI_CORE=y
CONFIG_BT_DEBUG_HCI_DRIVER=y
CONFIG_BT_DEBUG_LOG=y

[vikrant8051]

Hi @jhedberg,
Now I am able to provision

1. samples/boards/nrf52/mesh/onoff-app &
2. samples/bluetooth/mesh app.

Could you help me to solve the provisioning issue with onoff_level_lighting_vnd_app?

@carlescufi @cvinayak what is your experience in case of this particular App?

It was perfectly working few days back (before release of 2.0)

What is reason behind this BUS FAULT?

[vikrant8051]

waiting for response.

[vikrant8051]

@jhedberg @carlescufi @cvinayak Kindly note that I am still not able to provision samples/boards/nrf52/mesh/onoff_level_lighting_vnd_app. This is regression.

I've already shared debug log. Please guide me what to do next from my end to solve this issue.

[jhedberg]

@vikrant8051 I was able to reproduce this with onoff_level_lighting_vnd_app. Enabling some stack/thread debug Kconfig options immediately showed a stack overflow in the main thread. Increasing the main thread stack size from 512 to 1024 made the issue go away and I was able to provision successfully.

[vikrant8051]

Hi @jhedberg, after setting CONFIG_MAIN_STACK_SIZE=1024, now I
can provision the board (in case of onoff_level_lighting_vnd_app). Thank you for suggestion.

I will send PR shortly for this.

[vikrant8051]

@jhedberg https://github.com/zephyrproject-rtos/zephyr/pull/20668 PR submitted to solve this issue.

[vikrant8051]

Solved !!