Bluez brokes Mesh connection

[Konstantsin Balabanov]

Hi there,
I am working on controlling the nRF Mesh device (nRF52840-DK) via the bluez version of 5.52 (meshctl).
I try to connect to Nordic nRF52840-DK (example <nrf5_SDK_for_Mesh_3.2.0>/examples/light_switch/server)
Devices successfully provisioned after entering key.
Unfortunately, connection brokes down after a few seconds.
Commands which I use for the connection:

Also please see files:
nordic.log - output of Segger Embedded Studio console
meshctl.log - output of meshctl
local_node.json and prov_db.json - config files for meshctl (standart files from bluez/tools/mesh-gatt directory)

As I can see nRF52840-DK can be controlled from nRF Mesh utility from Android device without any problems.
Thanks in advance

[Konstantsin Balabanov]

Fullscreen 7002.meshctl.log Download

[meshctl]# discover-unprovisioned on
SetDiscoveryFilter success
Discovery started
Adapter property changed 
[CHG] Controller 14:4F:8A:76:1D:57 Discovering: yes
                Mesh Provisioning Service (00001827-0000-1000-8000-00805f9b34fb)
                        Device UUID: a9bdcbb822a7274b9213a424183ad83e
                        OOB: 0000
[meshctl]# security 0
Provision Security Level set to 0 (low)
[meshctl]# provision a9bdcbb822a7274b9213a424183ad83e
Trying to connect Device FA:18:24:A4:13:D2 nRF5x Mesh Light
Adapter property changed 
[CHG] Controller 14:4F:8A:76:1D:57 Discovering: no
Connection successful
Services resolved yes
Found matching char: path /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char000f, uuid 00002adb-0000-1000-8000-00805f9b34fb
Found matching char: path /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011, uuid 00002adc-0000-1000-8000-00805f9b34fb
Start notification on /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011
Characteristic property changed /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011
AcquireNotify success: fd 7 MTU 69
Notify for Mesh Provisioning Out Data started
Open-Node: 0x87df90
Open-Prov: 0x87bfa0
Open-Prov: proxy 0x880ea0
Initiated provisioning
Characteristic property changed /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char000f
AcquireWrite success: fd 8 MTU 69
GATT-TX:         03 00 10 
GATT-RX:         03 01 01 00 01 00 01 00 00 00 00 00 00 
Got provisioning data (12 bytes)
         01 01 00 01 00 01 00 00 00 00 00 00 
GATT-TX:         03 02 00 00 01 00 00 
GATT-TX:         03 03 ff 67 cc 35 b6 40 ca dc 9e 56 62 99 d8 e9 
GATT-TX:         ff 66 17 7e 4d 67 99 00 47 de 69 4a c4 b8 fc 17 
GATT-TX:         4a 7b 4f 25 6e 99 9d bb bc 55 d5 ac 7a d0 13 f2 
GATT-TX:         13 2c 95 2e 10 12 b1 3b df 1b 03 d6 6b d6 11 1d 
GATT-TX:         30 36 
GATT-RX:         03 03 cd a2 26 df 7e 7a 9a 05 03 36 af 68 fb bd 
GATT-RX:         e4 e4 c8 67 ca 73 74 f8 3f 90 9c 0a 38 89 34 4c 
GATT-RX:         a1 22 36 44 1e 21 dc 97 44 1d 78 e1 be 9d 1e 68 
GATT-RX:         2b f2 c0 c9 c5 91 5c e4 7d 7a 83 bb 0d 87 16 1c 
GATT-RX:         cd 7b 
Got provisioning data (65 bytes)
         03 cd a2 26 df 7e 7a 9a 05 03 36 af 68 fb bd e4 
         e4 c8 67 ca 73 74 f8 3f 90 9c 0a 38 89 34 4c a1 
         22 36 44 1e 21 dc 97 44 1d 78 e1 be 9d 1e 68 2b 
         f2 c0 c9 c5 91 5c e4 7d 7a 83 bb 0d 87 16 1c cd 
         7b 
Request hexadecimal key (hex 16 octets)
[[mesh-agent]# ] Enter key (hex number): 6E6F726469635F6578616D706C655F31
GATT-TX:         03 05 70 e5 6a c4 c9 08 df d5 94 9e 98 39 f0 7d 
GATT-TX:         97 12 
GATT-RX:         03 05 9c 5c 7e b4 5c 60 8c 2b 03 d1 bf bd 09 9c 
GATT-RX:         72 e2 
Got provisioning data (17 bytes)
         05 9c 5c 7e b4 5c 60 8c 2b 03 d1 bf bd 09 9c 72 
         e2 
GATT-TX:         03 06 1f 84 49 ab 4d 8e ba 03 bb e0 c9 51 f9 8c 
GATT-TX:         ea 65 
GATT-RX:         03 06 e1 65 28 2d 3e 79 6a e4 91 6c 7a cd 18 5a 
GATT-RX:         5b 1b 
Got provisioning data (17 bytes)
         06 e1 65 28 2d 3e 79 6a e4 91 6c 7a cd 18 5a 5b 
         1b 
Confirmation Validated
S-Key    37 6a 7a ab f9 00 5f b7 b4 db 05 ac d2 35 b3 5d 
S-Nonce  7d 77 7f a1 4d 98 f6 9f e7 ce fd 5a 52 
DevKey   0a e4 a2 cd 86 a9 6a 90 e0 e3 b3 b2 1b c3 42 55 
Data     18 ee d9 c2 a5 6a dd 85 04 9f fc 3c 59 ad 0e 12 
Data     00 00 00 00 00 00 05 01 00 
DataEncrypted + mic      4b 9b 6f 79 29 b8 8b 70 82 11 54 52 dc 4c d3 c3 
DataEncrypted + mic      10 6f 44 1c e3 0c 00 2e 40 ab 10 6f 45 aa 9b 2d 
DataEncrypted + mic      bf 
GATT-TX:         03 07 4b 9b 6f 79 29 b8 8b 70 82 11 54 52 dc 4c 
GATT-TX:         d3 c3 10 6f 44 1c e3 0c 00 2e 40 ab 10 6f 45 aa 
GATT-TX:         9b 2d bf 
GATT-RX:         03 08 
Got provisioning data (1 bytes)
         08 
Provision success. Assigned Primary Unicast 0100
Attempting to disconnect from FA:18:24:A4:13:D2
Characteristic property changed /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011
Write closed
Services resolved no
Characteristic property changed /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char000f
SetDiscoveryFilter success
Discovery started
Adapter property changed 
[CHG] Controller 14:4F:8A:76:1D:57 Discovering: yes

                Mesh Proxy Service (00001828-0000-1000-8000-00805f9b34fb)
                Identity for node 0100
Trying to connect to mesh
Adapter property changed 
[CHG] Controller 14:4F:8A:76:1D:57 Discovering: no
Connection successful
Service added /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e
Char added /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char000f:
Char added /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011:
Services resolved yes
Found matching char: path /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char000f, uuid 00002add-0000-1000-8000-00805f9b34fb
Found matching char: path /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011, uuid 00002ade-0000-1000-8000-00805f9b34fb
Start notification on /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011
Characteristic property changed /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011
AcquireNotify success: fd 7 MTU 69
Notify for Mesh Proxy Out Data started
Trying to open mesh session
GATT-RX:         01 01 00 d4 76 79 43 3f db 10 4a 00 00 00 05 f4 
GATT-RX:         0a 41 fa b0 af 32 0b 
iv_upd_state = IV_UPD_NORMAL
Mesh session is open
Characteristic property changed /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char000f
AcquireWrite success: fd 8 MTU 69
GATT-TX:         02 f4 9e 64 99 fe 13 cd c8 9b 0e 1c e5 61 82 cc 
GATT-TX:         ab f5 83 70 
GATT-TX:         00 f4 da 19 91 34 51 5d cd 7a 74 23 c1 4f 03 09 
GATT-TX:         ff 11 c6 91 55 c2 
GATT-RX:         02 f4 e7 02 fe d4 84 81 a3 32 e7 6e 4b 1b 74 4a 
GATT-RX:         13 95 f5 61 7f eb 
Proxy Whitelist filter length: 0
GATT-RX:         00 f4 25 51 de b7 9a d1 ad c7 3d 4e 8a 8c 84 ab 
GATT-RX:         eb 77 25 74 4f 05 b6 94 12 ae 3d ef e6 1c 
GATT-RX:         00 f4 73 fe 99 35 3f e9 53 23 84 9f e9 6d 69 87 
GATT-RX:         51 8b fa b4 43 35 29 c8 75 90 bf 51 b1 c7 
GATT-RX:         00 f4 78 36 d8 c3 94 76 68 58 b5 38 76 87 cb a2 
GATT-RX:         ad 66 0a 4a 
        Composition data for node 0100 {
  "cid":"0059",
  "pid":"0000",
  "vid":"0000",
  "crpl":"0028",
  "features":{
    "relay":true,
    "proxy":true,
    "friend":false,
    "lpn":false
  },
  "elements":[
    {
      "elementIndex":0,
      "location":"0000",
      "models":[
        "0000",
        "0002",
        "1000"
      ]
    }
  ]
}
GATT-TX:         00 f4 2b d6 e6 46 66 5b 65 31 1d 78 08 28 5d 16 
GATT-TX:         aa e2 97 b6 18 84 1f 29 7f 
Notify closed
Write closed
Services resolved no
Characteristic property changed /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char0011
Characteristic property changed /org/bluez/hci1/dev_FA_18_24_A4_13_D2/service000e/char000f

Fullscreen 1638.nordic.log Download

<t:          0>, main.c,  238, ----- BLE Mesh Light Switch Server Demo -----
<t:      13555>, main.c,  218, Initializing and adding models
<t:      13558>, main.c,  113, App OnOff Model Handle: 2
<t:      18297>, prov_bearer_adv.c,  400, PB-ADV: context at 0x20002F6C added to bearer
<t:      18308>, mesh_app_utils.c,   65, Device UUID (raw): A9BDCBB822A7274B9213A424183AD83E
<t:      18311>, mesh_app_utils.c,   70, Device UUID : B8CBBDA9-A722-4B27-9213-A424183AD83E
<t:     886749>, prov_provisionee.c,  402, Provisionee: invite received!
<t:     886755>, prov_provisionee.c,  117, Provisionee: sending capabilities
<t:     891668>, prov_provisionee.c,  424, Provisionee: provisioning start message received!
<t:     891728>, prov_provisionee.c,  451, Provisionee: public key message received!
<t:     899666>, prov_provisionee.c,  333, Provisionee: requested static OOB data from application
<t:     947372>, prov_provisionee.c,  479, Provisioning: provisioning confirmation received!
<t:     950655>, prov_provisionee.c,  507, Provisionee: provisioner's random number received!
<t:     953945>, prov_provisionee.c,  531, Provisionee: received provisioning data!
<t:    1032166>, main.c,  198, Successfully provisioned
<t:    1032171>, main.c,  209, Node Address: 0x0100 

[Mttrinh]

Hi,

Does the connection break everytime? Can you try debug the code on the nRF side and see if any errors is returned when the disconnection happens? 

Also is there anye modifications done to the example?