Re: [Zephyr-devel] not able to complete #BluetoothMesh provisioning & configuration process using #meshctl (5.49)

Home Messages Hashtags Subgroups

#738

Re: [Zephyr-devel] not able to complete #BluetoothMesh provisioning & configuration process using #meshctl (5.49)
#bluetoothmesh #meshctl

Kai Ren <kren@...> #738 Hi Vikrant, I just did two tests today, the detail is: 1^st test. I built “onoff-app” example basing on latest Zephyr project, the commit is 9968cda453ac7a91d513b6a50817c926c3fe5cc6 of today, you can see that my log is the same like yours, after close the connection, need to initial a new connection, but it’s failed. [meshctl]# provision 135334dd01cf00000000000000000000 Trying to connect Device CF:01:DD:34:53:13 Zephyr Adapter property changed [CHG] Controller 00:1B:DC:08:01:4A Discovering: no Connection successful Service added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service0006 Service added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a Char added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b: Char added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d: Services resolved yes Found matching char: path /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b, uuid 00002adb-0000-1000-8000-00805f9b34fb Found matching char: path /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d, uuid 00002adc-0000-1000-8000-00805f9b34fb Start notification on /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d Characteristic property changed /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d AcquireNotify success: fd 7 MTU 69 Notify for Mesh Provisioning Out Data started Open-Node: 0x176ae78 Open-Prov: 0x176e470 Open-Prov: proxy 0x176aec8 Initiated provisioning Characteristic property changed /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b AcquireWrite success: fd 8 MTU 69 GATT-TX: 03 00 10 GATT-RX: 03 01 04 00 01 00 00 06 00 18 00 00 00 Got provisioning data (12 bytes) 01 04 00 01 00 00 06 00 18 00 00 00 GATT-TX: 03 02 00 00 02 04 06 GATT-TX: 03 03 46 29 4e 55 9b ff 27 e0 b9 58 5a c2 ee 56 GATT-TX: 93 aa 38 35 2e 4e de 6b 78 af b8 c7 6c 42 0e be GATT-TX: 75 78 94 af 19 c1 24 e8 78 0f 1d 57 25 ea 03 5c GATT-TX: 3e a6 81 48 37 f8 9b 94 e1 35 bd 34 c1 97 dc d9 GATT-TX: e9 60 GATT-RX: 03 03 44 3e 0c 3c b7 4a 37 f0 68 3c 73 b3 59 44 GATT-RX: 68 cf 67 e0 b7 7d f1 f0 cf aa 97 74 e4 04 49 c4 GATT-RX: 01 32 fb 92 82 bc 15 32 de 52 e1 b2 9a 4a 01 43 GATT-RX: 49 a9 24 ab 1a a6 27 d3 a7 08 72 33 25 0b 36 f3 GATT-RX: 4c bf Got provisioning data (65 bytes) 03 44 3e 0c 3c b7 4a 37 f0 68 3c 73 b3 59 44 68 cf 67 e0 b7 7d f1 f0 cf aa 97 74 e4 04 49 c4 01 32 fb 92 82 bc 15 32 de 52 e1 b2 9a 4a 01 43 49 a9 24 ab 1a a6 27 d3 a7 08 72 33 25 0b 36 f3 4c bf Request ASCII key (max characters 6) [mesh] Enter key (ascii string): 7GG0LQ GATT-TX: 03 05 2b 9f 92 6f ca de 51 48 f8 26 2f f1 b0 b3 GATT-TX: 83 c4 GATT-RX: 03 05 c7 f4 8a cf de 22 92 b3 30 66 9f e5 64 3d GATT-RX: 90 76 Got provisioning data (17 bytes) 05 c7 f4 8a cf de 22 92 b3 30 66 9f e5 64 3d 90 76 GATT-TX: 03 06 0b 86 f5 06 69 65 6f 51 3d 75 d2 6e 3b 18 GATT-TX: d8 91 GATT-RX: 03 06 0a 31 b0 f9 0d a7 a2 42 32 c4 cd 0f 62 62 GATT-RX: b1 ea Got provisioning data (17 bytes) 06 0a 31 b0 f9 0d a7 a2 42 32 c4 cd 0f 62 62 b1 ea Confirmation Validated S-Key 37 6f 39 7f f4 aa b3 a2 b8 3b b3 25 52 e1 fe 14 S-Nonce d2 d2 f8 72 f0 74 38 2e 77 11 3a 51 eb DevKey bd 5b db c6 fb 68 5d 9b f3 d0 d4 0a 7a 2b b9 1f 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 13 DataEncrypted + mic 31 0c 91 f7 33 89 40 40 8d 10 53 0e 5c cb 6c 00 DataEncrypted + mic 69 a7 4c ba e1 af 28 6b 2b a0 b2 da ba 2d 0f ca DataEncrypted + mic 5b GATT-TX: 03 07 31 0c 91 f7 33 89 40 40 8d 10 53 0e 5c cb GATT-TX: 6c 00 69 a7 4c ba e1 af 28 6b 2b a0 b2 da ba 2d GATT-TX: 0f ca 5b GATT-RX: 03 08 Got provisioning data (1 bytes) 08 Provision success. Assigned Primary Unicast 0113 Attempting to disconnect from CF:01:DD:34:53:13 Characteristic property changed /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d Write closed Service added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a Char added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b: Char added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d: Services resolved no SetDiscoveryFilter success Discovery started Adapter property changed [CHG] Controller 00:1B:DC:08:01:4A Discovering: yes [meshctl]# 2^nd test, I “make clean” and “make”, this time, “onoff-app” is basing on the commit, c33087d3366f395168d477feb631aae1785a008e on March 29^th, it works well, you can see below screenshot that BlueZ could get Composition Data. [meshctl]# provision 135334dd01cf00000000000000000000 Trying to connect Device CF:01:DD:34:53:13 Zephyr Adapter property changed [CHG] Controller 00:1B:DC:08:01:4A Discovering: no Connection successful Service added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a Char added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b: Char added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d: Services resolved yes Found matching char: path /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b, uuid 00002adb-0000-1000-8000-00805f9b34fb Found matching char: path /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d, uuid 00002adc-0000-1000-8000-00805f9b34fb Start notification on /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d Characteristic property changed /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d AcquireNotify success: fd 7 MTU 69 Notify for Mesh Provisioning Out Data started Open-Node: 0x1915e08 Open-Prov: 0x19149d0 Open-Prov: proxy 0x19124d8 Initiated provisioning Characteristic property changed /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b AcquireWrite success: fd 8 MTU 69 GATT-TX: 03 00 10 GATT-RX: 03 01 04 00 01 00 00 06 00 18 00 00 00 Got provisioning data (12 bytes) 01 04 00 01 00 00 06 00 18 00 00 00 GATT-TX: 03 02 00 00 02 04 06 GATT-TX: 03 03 e5 28 0b b0 20 40 5e f4 e4 92 f1 ff 1b a4 GATT-TX: 51 96 0a 9a 85 e4 e1 2b 13 50 8f 5d 27 19 d3 b4 GATT-TX: 0c 99 bc 73 dd 1d b9 3e 11 3f c7 03 45 3d d4 b7 GATT-TX: fb 1e 28 e5 1e b2 d4 dc 88 31 82 49 0c 78 82 3f GATT-TX: e1 0f GATT-RX: 03 03 8a 48 c5 d5 c9 13 9f fd c6 5b 59 b3 87 9e GATT-RX: 4e 1d a7 0b 6c 1a e6 65 ea f4 f4 07 a0 5f 10 18 GATT-RX: 1c 5d 00 eb a2 31 33 ca 73 95 a3 ff aa f7 72 c2 GATT-RX: e3 32 4a 13 93 21 bf 8c 01 1e 32 74 25 ad 9e e6 GATT-RX: 7c 49 Got provisioning data (65 bytes) 03 8a 48 c5 d5 c9 13 9f fd c6 5b 59 b3 87 9e 4e 1d a7 0b 6c 1a e6 65 ea f4 f4 07 a0 5f 10 18 1c 5d 00 eb a2 31 33 ca 73 95 a3 ff aa f7 72 c2 e3 32 4a 13 93 21 bf 8c 01 1e 32 74 25 ad 9e e6 7c 49 Request ASCII key (max characters 6) [mesh] Enter key (ascii string): RZTCNG GATT-TX: 03 05 00 99 fd 99 5e c7 d9 49 41 f5 27 8a 45 dd GATT-TX: fa f7 GATT-RX: 03 05 5a ca d3 3f bb ef cb e5 31 e5 27 d6 91 17 GATT-RX: 3c a3 Got provisioning data (17 bytes) 05 5a ca d3 3f bb ef cb e5 31 e5 27 d6 91 17 3c a3 GATT-TX: 03 06 d4 9f a5 2d d3 f5 c8 b3 6b 21 36 81 64 27 GATT-TX: dd dc GATT-RX: 03 06 76 86 6c ef 49 43 18 21 51 f2 0a cb 13 64 GATT-RX: b7 9f Got provisioning data (17 bytes) 06 76 86 6c ef 49 43 18 21 51 f2 0a cb 13 64 b7 9f Confirmation Validated S-Key 2f 1d 94 8c cd 5b 4a 23 e2 63 38 45 4b 95 f2 ec S-Nonce 69 4e 98 62 2f 09 45 2f 10 8a 8b 12 03 DevKey 85 a0 58 ab 9c 9a cc 84 4c 94 ba a6 f1 f9 fa 70 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 1b DataEncrypted + mic e6 d2 b9 87 fd e0 fd a2 96 80 ea 3a 16 ff 3a 4d DataEncrypted + mic a4 6e 81 0b ca 33 b8 27 09 1d f2 e6 12 f7 3c 71 DataEncrypted + mic 2b GATT-TX: 03 07 e6 d2 b9 87 fd e0 fd a2 96 80 ea 3a 16 ff GATT-TX: 3a 4d a4 6e 81 0b ca 33 b8 27 09 1d f2 e6 12 f7 GATT-TX: 3c 71 2b GATT-RX: 03 08 Got provisioning data (1 bytes) 08 Provision success. Assigned Primary Unicast 011b Attempting to disconnect from CF:01:DD:34:53:13 Characteristic property changed /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d Write closed Service added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a Char added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b: Char added /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d: Services resolved no SetDiscoveryFilter success Discovery started Adapter property changed [CHG] Controller 00:1B:DC:08:01:4A Discovering: yes Mesh Proxy Service (00001828-0000-1000-8000-00805f9b34fb) Identity for node 011b Trying to connect to mesh Adapter property changed [CHG] Controller 00:1B:DC:08:01:4A Discovering: no Connection successful Services resolved yes Found matching char: path /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000b, uuid 00002add-0000-1000-8000-00805f9b34fb Found matching char: path /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d, uuid 00002ade-0000-1000-8000-00805f9b34fb Start notification on /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d Characteristic property changed /org/bluez/hci0/dev_CF_01_DD_34_53_13/service000a/char000d 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/hci0/dev_CF_01_DD_34_53_13/service000a/char000b AcquireWrite success: fd 8 MTU 69 GATT-TX: 02 f4 e2 f9 cb d9 47 7b c5 4d 23 04 3b 32 74 02 GATT-TX: a7 77 d9 51 GATT-TX: 00 f4 27 cd 77 9a de f7 06 74 c4 1f e9 e5 e7 07 GATT-TX: 57 67 06 0c 51 02 GATT-RX: 02 f4 44 af 19 fa 89 51 83 cb db b1 08 10 97 f0 GATT-RX: 78 86 79 a1 ea fd Proxy Whitelist filter length: 0 GATT-RX: 00 f4 0d 8b ee 59 96 9c da b5 73 39 4f 13 da 2e GATT-RX: 4d 30 47 06 7b d5 b0 15 71 fc ab b1 87 2d GATT-RX: 00 f4 8e 31 9b dd 67 26 c6 08 60 f6 2a 3e a0 eb GATT-RX: 2e 1b c6 d2 49 8c 14 11 53 54 e9 47 a2 a9 GATT-RX: 00 f4 28 4e de 68 59 e5 37 f0 50 12 6b bc 5a 39 GATT-RX: 97 70 64 01 9b 77 2b 51 90 e3 04 11 91 71 GATT-RX: 00 f4 b1 dd 9d 38 17 1b 10 60 32 90 b1 f9 dd cc GATT-RX: 7e 71 ad a6 6e 08 3f df 7b 0a 9e 12 6b 30 GATT-RX: 00 f4 d9 1e 75 e2 77 1f 9f e7 c7 73 4e fa 86 92 GATT-RX: ea eb dc 22 e8 61 3e d5 02 5b 3c 12 Composition data for node 011b { "cid":"05f1", "pid":"0000", "vid":"0000", "crpl":"000a", "features":{ "relay":true, "proxy":true, "friend":false, "lpn":false }, "elements":[ { "elementIndex":0, "location":"0000", "models":[ "0000", "0001", "0002", "1000", "1001" ] }, { "elementIndex":1, "location":"0000", "models":[ "1000", "1001" ] }, { "elementIndex":2, "location":"0000", "models":[ "1000", "1001" ] }, { "elementIndex":3, "location":"0000", "models":[ "1000", "1001" ] } ] } GATT-TX: 00 f4 64 37 a5 e0 5f c0 3b 3c 90 42 cc f9 55 65 GATT-TX: 0b f9 13 7b fb 95 19 e4 a5 [Zephyr-Node-011b]# I guess there may be a bug in Bluetooth or Bluetooth mesh subsys, just guessing… Regards, Kai From: Vikrant More <vikrant8051@...> Date: Thursday, April 26, 2018 at 12:38 PM To: Kai Ren <kren@...>, "devel@..." <devel@...>, "users@..." <users@...> Subject: Re: [Zephyr-devel] not able to complete #BluetoothMesh provisioning & configuration process using #meshctl (5.49) HI Kai, Today I tried to provision #BlueNRG Mesh (It is based on ST Mesh library to which we could provision using Silicon Labs Mesh App ) DEVICE using #meshctl, in this case too provisioning process did not complete. This is complete log, ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- provision f81d4fae7dec4b53a1540cb44f9726db Trying to connect Device DB:26:97:4F:B4:0C DB-26-97-4F-B4-0C Adapter property changed [CHG] Controller 28:F0:76:2F:42:BB Discovering: no Connection successful Service added /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service0001 Service added /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c Char added /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000d: Char added /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000f: Services resolved yes Found matching char: path /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000d, uuid 00002adb-0000-1000-8000-00805f9b34fb Found matching char: path /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000f, uuid 00002adc-0000-1000-8000-00805f9b34fb Start notification on /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000f Characteristic property changed /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000f AcquireNotify success: fd 7 MTU 23 Notify for Mesh Provisioning Out Data started Open-Node: 0xfeeb10 Open-Prov: 0x1001c20 Open-Prov: proxy 0xffd7f0 Initiated provisioning Characteristic property changed /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000d AcquireWrite success: fd 8 MTU 23 GATT-TX: 03 00 10 GATT-RX: 03 01 01 00 01 00 00 00 00 00 00 00 00 Got provisioning data (12 bytes) 01 01 00 01 00 00 00 00 00 00 00 00 GATT-TX: 03 02 00 00 00 00 00 GATT-TX: 03 03 1b 79 c0 dd 6e f0 60 4d bf 01 92 de ed b7 GATT-TX: 2d 48 e0 bb 42 ec 36 cf d0 76 cc 60 aa 2a fa 9f GATT-TX: 4d 1f ba 3d b5 43 a8 a7 0d 80 b5 e3 08 34 2d d5 GATT-TX: 31 6c 02 0d 1b 36 b4 1d 44 36 84 91 a2 26 da c8 GATT-TX: 52 ea GATT-RX: 43 03 f0 ef 67 07 66 32 7b c8 df 2c 6a 4f c2 6c GATT-RX: 10 28 b4 89 GATT-RX: 83 b2 17 cb f8 ff 9f cc 32 e4 2f 16 40 64 14 fe GATT-RX: 87 b9 2b a3 GATT-RX: 83 63 22 b8 4e bb 58 ac 71 c8 a2 5e b7 bf ab 25 GATT-RX: b7 1a f5 1d GATT-RX: c3 a9 19 52 a8 61 85 d9 27 Got provisioning data (65 bytes) 03 f0 ef 67 07 66 32 7b c8 df 2c 6a 4f c2 6c 10 28 b4 89 b2 17 cb f8 ff 9f cc 32 e4 2f 16 40 64 14 fe 87 b9 2b a3 63 22 b8 4e bb 58 ac 71 c8 a2 5e b7 bf ab 25 b7 1a f5 1d a9 19 52 a8 61 85 d9 27 GATT-TX: 03 05 2a 0b bf ec e6 45 80 06 89 67 b6 c2 e4 30 GATT-TX: 82 90 GATT-RX: 03 05 d7 93 53 dc 12 36 90 ea 85 b5 fe 1a 79 9d GATT-RX: 59 d0 Got provisioning data (17 bytes) 05 d7 93 53 dc 12 36 90 ea 85 b5 fe 1a 79 9d 59 d0 GATT-TX: 03 06 16 6f b0 65 5a c6 da 55 15 6a 83 22 45 c3 GATT-TX: a2 b6 GATT-RX: 03 06 70 86 ff 82 75 05 3a b9 cb f5 32 2d 1b a1 GATT-RX: f1 88 Got provisioning data (17 bytes) 06 70 86 ff 82 75 05 3a b9 cb f5 32 2d 1b a1 f1 88 Confirmation Validated S-Key bf c7 ea 9f dd 95 76 cd 5d fe d0 ba 56 23 a7 25 S-Nonce 1a 5c 5d 8b 57 85 fb ef d9 d4 b8 42 8e DevKey 24 c9 87 84 71 3a 4a 5b c0 30 ed 3e de 4a e5 44 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 6f 6e 24 26 aa 65 f5 b1 de 16 1d 16 03 cd 37 19 DataEncrypted + mic 44 6d f7 3c f8 27 dd da d0 0f 1c d7 33 67 50 01 DataEncrypted + mic 67 GATT-TX: 03 07 6f 6e 24 26 aa 65 f5 b1 de 16 1d 16 03 cd GATT-TX: 37 19 44 6d f7 3c f8 27 dd da d0 0f 1c d7 33 67 GATT-TX: 50 01 67 GATT-RX: 03 08 Got provisioning data (1 bytes) 08 Provision success. Assigned Primary Unicast 0100 Attempting to disconnect from DB:26:97:4F:B4:0C Characteristic property changed /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000f Write closed Services resolved no Characteristic property changed /org/bluez/hci0/dev_DB_26_97_4F_B4_0C/service000c/char000d SetDiscoveryFilter success Discovery started Adapter property changed [CHG] Controller 28:F0:76:2F:42:BB Discovering: yes toggle quoted messageShow quoted text On Wed, Apr 25, 2018 at 9:10 PM, Vikrant More <vikrant8051@...> wrote: Hi Kai, Yes, you are right. Thanks for sharing it. Regards, vikrant On Wed, Apr 25, 2018, 8:43 AM Kai Ren <kren@...> wrote: Hi Vikrant8051, I had tried this one month ago, my testing environment is: BlueZ v5.49; nRF52832-DK; I can provision the DK which run "onoff-app" firmware and make model configuration, use meshctl "menu onoff" to control LED on and off. By the way, I also use BlueZ 5.49 to provision SiLabs kit in last week, it was successful, so BlueZ works well, the issue may be from Zephyr. Kai
More

View All 8 Messages In Topic

#738

Join users@lists.zephyrproject.org to automatically receive all group messages.

Home Hashtags Subgroups Terms