CC2652R7: TI-Matter pump-app not BLE provisioning to the Thread&Matter network(s).

Hi Steve,

Steve Kranz said:

Example of MacBook command to Provision pump-app to Thread&Matter.
Note: single click of btn-2 of the LP-cc2652R7 (presumably to activate BLE), and then the following at MacBook…

Does this mean that you are attempting to use the MacBook as the Matter controller? (I.e. to on-board the CC2652R7 to the Thread network)?

Or, is the MacBook SSH'ing into a RasPi, and the RasPi is the Matter controller?

Thanks,
Toby

Hi Toby,

I don't have a RasPi. I have a MacBook and within the ./matter/connectedhomeip repository I've built the cc2652 pump-app image that runs on the LP-cc2652R7 and in that same repository I've built the chip-tool Matter controller that I run in a MacBook shell. This is what the transcript looks like. See below:

$ hostname
MacBook-Pro.local

$  ./chip-tool pairing ble-thread 0x777 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fdcf00635fae4ed1051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0fff8 20202021 3840
[1674173407278] [91223:8621614] [DL] KVS will be written to: file:///tmp/chip_kvs
[1674173407297] [91223:8621614] [DL] _Init
[1674173407297] [91223:8621614] [IN] UDP::Init bind&listen port=0
[1674173407297] [91223:8621614] [IN] UDP::Init bound to port=54109
[1674173407297] [91223:8621614] [IN] UDP::Init bind&listen port=0
[1674173407297] [91223:8621614] [IN] UDP::Init bound to port=59651
[1674173407297] [91223:8621614] [IN] BLEBase::Init - setting/overriding transport
[1674173407297] [91223:8621614] [IN] TransportMgr initialized
[1674173407297] [91223:8621614] [FP] Initializing FabricTable from persistent storage
[1674173407297] [91223:8621614] [TS] Last Known Good Time: [unknown]
[1674173407297] [91223:8621614] [TS] Setting Last Known Good Time to firmware build time 2023-01-11T20:15:35
[1674173407299] [91223:8621614] [ZCL] Using ZAP configuration...
[1674173407299] [91223:8621614] [CTL] System State Initialized...
[1674173407299] [91223:8621614] [CTL] Stopping commissioning discovery over DNS-SD
[1674173407299] [91223:8621614] [CTL] Setting attestation nonce to random value
[1674173407299] [91223:8621614] [CTL] Setting CSR nonce to random value
[1674173407299] [91223:8621617] [DL] _OnPlatformEvent
[1674173407300] [91223:8621617] [CTL] Stopping commissioning discovery over DNS-SD
[1674173407300] [91223:8621617] [CTL] Setting attestation nonce to random value
[1674173407300] [91223:8621617] [CTL] Setting CSR nonce to random value
[1674173407300] [91223:8621617] [CTL] Couldn't get ExampleOpCredsCAKey from storage: ../../src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1674173407300] [91223:8621617] [CTL] Couldn't get ExampleOpCredsICAKey from storage: ../../src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1674173407300] [91223:8621617] [CTL] Generating RCAC
[1674173407301] [91223:8621617] [CTL] Generating ICAC
[1674173407301] [91223:8621617] [CTL] Generating NOC
[1674173407301] [91223:8621617] [FP] Validating NOC chain
[1674173407302] [91223:8621617] [FP] NOC chain validation successful
[1674173407302] [91223:8621617] [FP] Added new fabric at index: 0x1
[1674173407302] [91223:8621617] [FP] Assigned compressed fabric ID: 0x8EC00C8020DF4999, node ID: 0x000000000001B669
[1674173407302] [91223:8621617] [TS] Last Known Good Time: 2023-01-11T20:15:35
[1674173407302] [91223:8621617] [TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
[1674173407302] [91223:8621617] [TS] Retaining current Last Known Good Time
[1674173407302] [91223:8621617] [FP] Metadata for Fabric 0x1 persisted to storage.
[1674173407303] [91223:8621617] [TS] Committing Last Known Good Time to storage: 2023-01-11T20:15:35
[1674173407303] [91223:8621617] [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 8EC00C8020DF4999)
[1674173407308] [91223:8621617] [BLE] NewConnection
[1674173407308] [91223:8621617] [BLE] CancelConnection
[1674173407310] [91223:8621617] [CTL] Setting thread operational dataset from parameters
[1674173407310] [91223:8621617] [CTL] Setting attempt thread scan from parameters
[1674173407310] [91223:8621617] [CTL] Setting attestation nonce to random value
[1674173407310] [91223:8621617] [CTL] Setting CSR nonce to random value
[1674173407310] [91223:8621617] [CTL] Setting PASE-only commissioning from parameters
[1674173407310] [91223:8621617] [CTL] Commission called for node ID 0x0000000000000777
[1674173411755] [91223:8621618] [BLE] CBManagerState: ON
[1674173471660] [91223:8621618] [DIS] Closing all BLE connections
[1674173527306] [91223:8621614] [CTL] Shutting down the commissioner
[1674173527306] [91223:8621614] [CTL] Stopping commissioning discovery over DNS-SD
[1674173527306] [91223:8621614] [CTL] Shutting down the controller
[1674173527307] [91223:8621614] [IN] Expiring all sessions for fabric 0x1!!
[1674173527307] [91223:8621614] [FP] Forgetting fabric 0x1
[1674173527307] [91223:8621614] [TS] Pending Last Known Good Time: 2023-01-11T20:15:35
[1674173527307] [91223:8621614] [TS] Previous Last Known Good Time: 2023-01-11T20:15:35
[1674173527307] [91223:8621614] [TS] Reverted Last Known Good Time to previous value
[1674173527307] [91223:8621614] [CTL] Shutting down the commissioner
[1674173527307] [91223:8621614] [CTL] Stopping commissioning discovery over DNS-SD
[1674173527307] [91223:8621614] [CTL] Shutting down the controller
[1674173527307] [91223:8621614] [CTL] Shutting down the System State, this will teardown the CHIP Stack
[1674173527308] [91223:8621614] [DMG] IM WH moving to [Uninitialized]
[1674173527308] [91223:8621614] [DMG] IM WH moving to [Uninitialized]
[1674173527308] [91223:8621614] [DMG] IM WH moving to [Uninitialized]
[1674173527308] [91223:8621614] [DMG] IM WH moving to [Uninitialized]
[1674173527308] [91223:8621614] [DMG] All ReadHandler-s are clean, clear GlobalDirtySet
[1674173527308] [91223:8621614] [BLE] CancelConnection
[1674173527308] [91223:8621614] [FP] Shutting down FabricTable
[1674173527308] [91223:8621614] [TS] Pending Last Known Good Time: 2023-01-11T20:15:35
[1674173527308] [91223:8621614] [TS] Previous Last Known Good Time: 2023-01-11T20:15:35
[1674173527308] [91223:8621614] [TS] Reverted Last Known Good Time to previous value
[1674173527308] [91223:8621614] [DL] Inet Layer shutdown
[1674173527308] [91223:8621614] [DL] BLE shutdown
[1674173527308] [91223:8621614] [DL] System Layer shutdown
[1674173527309] [91223:8621614] [TOO] Run command failure: ../../examples/chip-tool/commands/common/CHIPCommand.cpp:512: CHIP Error 0x00000032: Timeout
Kranz@MacBook-Pro host %

Thanks,

Steve K.

Thanks for confirming that the chip-tool is running on the MacBook.

The chip-tool argument looks correct.

Do you have BLE advertising enabled on the pump-app? (If not, BLE advertising can be enabled/disable by a short press/release of BTN-1).

Can you share the output on the CC2652R7?

Hi Toby,

Yes, I first started the BLE advertising at the LaunchPad-Pump-app (before starting chip-tool), and I used a short press of the LP's btn-2. That is what the pump-app README.md says. Is that correct? You mentioned btn-1 but suspect you meant btn-2.

The LaunchPad-Pump-app terminal output is the following, any ideas?:

OpenThread started: OK
Setting OpenThread device type to ROUTER
Initialize LEDs
Initialize buttons
Initialize Pump
Setting extended discovery timeout to 20s
Server initializing...
Initializing FabricTable from persistent storage
Last Known Good Time: 2023-01-17T15:28:16
AccessControl: initializing
Examples::AccessControlDelegate::Init
AccessControl: setting
DefaultAclStorage: initializing
DefaultAclStorage: 0 entries loaded
UDP::Init bind&listen port=5540
UDP::Init bound to port=5540
BLEBase::Init - setting/overriding transport
TransportMgr initialized
Using Thread extended MAC for hostname.
Using ZAP configuration...
Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0
AccessControlCluster: initializing
Initiating Admin Commissioning cluster.
Endpoint 0, Cluster 0x0000_0030 update version to aa93f845
GeneralDiagnostics: OnDeviceReboot
Endpoint 0, Cluster 0x0000_0033 update version to a7805bff
LogEvent event number: 0x00000000000A0000 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x00000000000001D9
Initialize PCC Plugin Server Cluster.
Init On/Off clusterstate
Endpoint 1, Cluster 0x0000_0006 update version to a324dd9d
Initialize PCC Server Cluster [EP:1]
Constant Pressure Not Supported
PCC Server: Constant Proportional Pressure Not Supported
PCC Server: Constant Flow Not Supported
PCC Server: Constant Temperature Not Supported
PCC Server: Constant Speed Not Supported
Updating services using commissioning mode 0
Using Thread extended MAC for hostname.
Using Thread extended MAC for hostname.
Advertise commission parameter vendorID=65521 productID=32778 discriminator=3840/15 cm=0
Failed to advertise extended commissionable node: 3
Scheduling extended discovery timeout in 20s
Failed to finalize service update: 1c
Delaying proxy of operational discovery: missing delegate
CASE Server enabling CASE session setups
SecureSession[0x20011bb0]: Allocated Type:2 LSID:28410
Allocated SecureSession (0x20011bb0) - waiting for Sigma1 msg
Joining Multicast groups
Emitting StartUp event
LogEvent event number: 0x00000000000A0001 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x0000000000000246
Server Listening...
Device Configuration:
  Serial Number: TEST_SN
  Vendor Id: 65521 (0xFFF1)
  Product Id: 32778 (0x800A)
  Hardware Version: 0
  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
  Manufacturing Date: (not set)
  Device Type: 65535 (0xFFFF)
Stopping the watchdog timer
Starting the periodic query timer, timeout: 86400 seconds
SetupQRCode: [MT:GU3T242C00KA0648G00]
Copy/paste the below URL in a browser to see the QR Code:
project-chip.github.io/.../qrcode.html
Manual pairing code: [34970112332]
CHIP task running
OpenThread State Changed (Flags: 0x00038200)
   Network Name: OpenThread
   PAN Id: 0xFFFF
   Extended PAN Id: 0xDEAD00BEEF00CAFE
   Channel: 11
   Mesh Prefix: FDDE:AD00:BEEF::/64
## Thread stack state change (38200)
PreAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0002'
Unhandled cluster ID: 42
Endpoint 0, Cluster 0x0000_002A update version to 643faec2
PostAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0002'
Unhandled cluster ID: 42
PreAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0003'
Unhandled cluster ID: 42
Endpoint 0, Cluster 0x0000_002A update version to 643faec3
PostAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0003'
Unhandled cluster ID: 42
Extended discovery timed out
Updating services using commissioning mode 0
Using Thread extended MAC for hostname.
Failed to finalize service update: 1c
Pump start initiated
Pump start completed
Update Cluster State
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0010'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x10]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf61c
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0010'
PCC Server Cluster Attribute changed [EP:1, ID:0x10]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0021'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x21]
ERR: Constant Flow error  87
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0021'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x21]
ERR: Constant Pressure error  87
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0021'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x21]
ERR: Constant Speed error  87
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0021'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x21]
ERR: Constant Temperature error  87
PreAttributeChangeCallback - Cluster ID: '0x0006', EndPoint ID: '0x01', Attribute ID: '0x0000'
Endpoint 1, Cluster 0x0000_0006 update version to a324dd9e
PostAttributeChangeCallback - Cluster ID: '0x0006', EndPoint ID: '0x01', Attribute ID: '0x0000'
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0000'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x0]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf61d
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0000'
PCC Server Cluster Attribute changed [EP:1, ID:0x0]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0001'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x1]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf61e
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0001'
PCC Server Cluster Attribute changed [EP:1, ID:0x1]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0002'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x2]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf61f
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0002'
PCC Server Cluster Attribute changed [EP:1, ID:0x2]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0003'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x3]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf620
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0003'
PCC Server Cluster Attribute changed [EP:1, ID:0x3]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0004'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x4]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf621
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0004'
PCC Server Cluster Attribute changed [EP:1, ID:0x4]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0005'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x5]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf622
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0005'
PCC Server Cluster Attribute changed [EP:1, ID:0x5]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0006'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x6]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf623
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0006'
PCC Server Cluster Attribute changed [EP:1, ID:0x6]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0007'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x7]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf624
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0007'
PCC Server Cluster Attribute changed [EP:1, ID:0x7]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0008'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x8]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf625
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0008'
PCC Server Cluster Attribute changed [EP:1, ID:0x8]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0009'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0x9]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf626
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x0009'
PCC Server Cluster Attribute changed [EP:1, ID:0x9]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x000a'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0xa]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf627
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x000a'
PCC Server Cluster Attribute changed [EP:1, ID:0xa]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x000b'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0xb]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf628
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x000b'
PCC Server Cluster Attribute changed [EP:1, ID:0xb]
PCC Server: unhandled attribute ID
PreAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x000c'
PCC Server Cluster Attribute Pre-changed [EP:1, ID:0xc]
Endpoint 1, Cluster 0x0000_0200 update version to 322bf629
PostAttributeChangeCallback - Cluster ID: '0x0200', EndPoint ID: '0x01', Attribute ID: '0x000c'
PCC Server Cluster Attribute changed [EP:1, ID:0xc]
PCC Server: unhandled attribute ID
Long dispatch time: 593 ms, for event type 2

Thanks in advance!

Steve.

Hi Toby,

And one other comment I’d like to add to my prior post…

While browsing the Matter repository I just noticed something a little strange and wanted to run it by you:

There are several TI Matter example apps (pump-app, pump-controller-app, lock-app), and I imagine that when building any of these that the following common file is used for all of them:

./connectedhomeip/config/cc13x2_26x2/toolchain/BUILD.gn

But the strange thing is that in that [common?] file is a hardcoded reference to the “lock-app”:

$ grep -i args.gni ./connectedhomeip/config/cc13x2_26x2/toolchain/BUILD.gn
    import("${chip_root}/examples/lock-app/cc13x2x7_26x2x7/args.gni")
      import("${chip_root}/examples/all-clusters-app/cc13x2x7_26x2x7/args.gni")

And the lock-app args.gni is not the same as the pump-app args.gni. So it seems this might influence the builds of some of the TI Matter examples. This `diff` for example:

$ diff ./connectedhomeip/examples/lock-app/cc13x2x7_26x2x7/args.gni ./connectedhomeip/examples/pump-app/cc13x2x7_26x2x7/args.gni
34,35c34,35
< chip_detail_logging = false
< chip_automation_logging = false
---
> #chip_detail_logging = false
> #chip_automation_logging = false
44,45d43
< chip_openthread_ftd = false
<
47c45
< matter_device_pid = "0x8006"
---
> matter_device_pid = "0x800A"

Anyhow, this seemed a bit suspicious to me and I wanted to bring it to your attention. Possibly it will nudge some idea for why I am unable to [BLE] commission my LaunchPad-pump-app to the Matter/Thread network. That is still an ongoing issue for me that I hope you can help with.

Thanks in advance,
Steve.

Hi Toby,

It looks like the pump-app README.md doesn’t match the pump-app source code. I did a fresh experiment this time using the other LaunchPad button (E.g using Btn-1 instead of Btn-2), I get different transcript results now (below) but I still get a provisioning failure (possibly related to the matter_device_pid comment of my prior post????). 

####################################################
This is the terminal output of the cli-mtd that is already joined to the thread network. Demonstrates that I have an operational OTBR (BeagleBone).

> ifconfig up
Done
> thread start
Done
> state
child
Done
> ipaddr
fdd6:3481:6985:ebdb:79b3:b1fd:1f82:fd9
fdcf:63:5fae:4ed1:0:ff:fe00:b804
fdcf:63:5fae:4ed1:534f:8f6:fc23:616
fe80:0:0:0:4ce7:c27a:2188:c275
Done
> networkname
OpenThreadDemo
Done
> channel
15
Done
> panid
0x1234
Done
> extpanid
1111111122222222
Done
>

####################################################
Note: this is the dataset as acquired from the OTBR.
    $ ssh -l debian beaglebone.local
    $ sudo ot-ctl dataset active -x
0e080000000000010000000300000f35060004001fffe0020811111111222222220708fdcf00635fae4ed1051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0fff8

####################################################
Note: I issued the chip-tool provisioning command immediately after pressing the Left-Btn (Btn-1) of the LaunchPad2652R7 loaded with TI/Matter pump-app system. See below for each transcript.

####################################################
chip-tool transcript (as run from MacBook terminal).
Kranz@MacBook-Pro chip-tool % hostname
MacBook-Pro.local
Kranz@MacBook-Pro chip-tool % echo $SHELL
/bin/zsh
Kranz@MacBook-Pro chip-tool % ./out/debug/chip-tool pairing ble-thread 1 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fdcf00635fae4ed1051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0fff8 20202021 3840
[1674664265511] [35784:10254373] [DL] KVS will be written to: file:///tmp/chip_kvs
[1674664265525] [35784:10254373] [DL] _Init
[1674664265525] [35784:10254373] [IN] UDP::Init bind&listen port=0
[1674664265525] [35784:10254373] [IN] UDP::Init bound to port=58257
[1674664265525] [35784:10254373] [IN] UDP::Init bind&listen port=0
[1674664265525] [35784:10254373] [IN] UDP::Init bound to port=55089
[1674664265525] [35784:10254373] [IN] BLEBase::Init - setting/overriding transport
[1674664265525] [35784:10254373] [IN] TransportMgr initialized
[1674664265525] [35784:10254373] [FP] Initializing FabricTable from persistent storage
[1674664265525] [35784:10254373] [TS] Last Known Good Time: 2023-01-15T14:56:42
[1674664265525] [35784:10254373] [TS] Setting Last Known Good Time to firmware build time 2023-01-24T16:00:01
[1674664265526] [35784:10254373] [FP] Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x8EC00C8020DF4999, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1674664265527] [35784:10254373] [ZCL] Using ZAP configuration...
[1674664265527] [35784:10254373] [CTL] System State Initialized...
[1674664265527] [35784:10254373] [CTL] Stopping commissioning discovery over DNS-SD
[1674664265527] [35784:10254373] [CTL] Setting attestation nonce to random value
[1674664265527] [35784:10254373] [CTL] Setting CSR nonce to random value
[1674664265527] [35784:10254373] [IN] UDP::Init bind&listen port=5550
[1674664265527] [35784:10254373] [IN] UDP::Init bound to port=5550
[1674664265527] [35784:10254373] [IN] UDP::Init bind&listen port=5550
[1674664265527] [35784:10254373] [IN] UDP::Init bound to port=5550
[1674664265527] [35784:10254373] [IN] TransportMgr initialized
[1674664265527] [35784:10254389] [DL] _OnPlatformEvent
[1674664265527] [35784:10254389] [CTL] Stopping commissioning discovery over DNS-SD
[1674664265527] [35784:10254389] [CTL] Setting attestation nonce to random value
[1674664265527] [35784:10254389] [CTL] Setting CSR nonce to random value
[1674664265528] [35784:10254389] [CTL] Generating NOC
[1674664265528] [35784:10254389] [FP] Validating NOC chain
[1674664265528] [35784:10254389] [FP] NOC chain validation successful
[1674664265528] [35784:10254389] [FP] Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1674664265528] [35784:10254389] [TS] Last Known Good Time: 2023-01-24T16:00:01
[1674664265528] [35784:10254389] [TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
[1674664265528] [35784:10254389] [TS] Retaining current Last Known Good Time
[1674664265529] [35784:10254389] [FP] Metadata for Fabric 0x1 persisted to storage.
[1674664265529] [35784:10254389] [TS] Committing Last Known Good Time to storage: 2023-01-24T16:00:01
[1674664265530] [35784:10254389] [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 8EC00C8020DF4999)
[1674664265530] [35784:10254389] [IN] UDP::Init bind&listen port=5550
[1674664265530] [35784:10254389] [IN] UDP::Init bound to port=5550
[1674664265530] [35784:10254389] [IN] UDP::Init bind&listen port=5550
[1674664265530] [35784:10254389] [IN] UDP::Init bound to port=5550
[1674664265530] [35784:10254389] [IN] TransportMgr initialized
[1674664265532] [35784:10254389] [BLE] NewConnection
[1674664265532] [35784:10254389] [BLE] CancelConnection
[1674664265533] [35784:10254389] [CTL] Setting thread operational dataset from parameters
[1674664265533] [35784:10254389] [CTL] Setting attempt thread scan from parameters
[1674664265533] [35784:10254389] [CTL] Setting attestation nonce to random value
[1674664265533] [35784:10254389] [CTL] Setting CSR nonce to random value
[1674664265533] [35784:10254389] [CTL] Setting PASE-only commissioning from parameters
[1674664265533] [35784:10254389] [CTL] Commission called for node ID 0x0000000000000001
[1674664265555] [35784:10254389] [BLE] CBManagerState: ON
[1674664266499] [35784:10254390] [BLE] Connecting to device 0x60000153dba0 with discriminator: 3840
[1674664267079] [35784:10254390] [DIS] Closing all BLE connections
[1674664267080] [35784:10254390] [IN] BleConnectionComplete: endPoint 0x102ee6608
[1674664267080] [35784:10254390] [BLE] ATT MTU = 251
[1674664267081] [35784:10254390] [IN] SecureSession[0x60000113c000]: Allocated Type:1 LSID:56526
[1674664267081] [35784:10254390] [SC] Assigned local session key ID 56526
[1674664267081] [35784:10254389] [BLE] BLE:Error writing Characteristics in Chip service on the device: [The specified UUID is not allowed for this operation.]
[1674664267081] [35784:10254390] [EM] <<< [E:5473i M:245921535] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[1674664267081] [35784:10254390] [IN] (U) Sending msg 245921535 to IP address 'BLE'
[1674664267081] [35784:10254390] [IN] Message appended to BLE send queue
[1674664267081] [35784:10254390] [SC] Sent PBKDF param request
[1674664267081] [35784:10254390] [IN] Failed to establish BLE connection: ../../third_party/connectedhomeip/src/platform/Darwin/BleConnectionDelegateImpl.mm:335: Ble Error 0x00000407: GATT write characteristic operation failed
[1674664267081] [35784:10254390] [IN] Clearing BLE pending packets.
[1674664267081] [35784:10254390] [BLE] Auto-closing end point's BLE connection.
[1674664284083] [35784:10254394] [SC] PASESession timed out while waiting for a response from the peer. Expected message type was 33
[1674664284083] [35784:10254394] [IN] SecureSession[0x60000113c000]: Released - Type:1 LSID:56526
[1674664284083] [35784:10254394] [TOO] Secure Pairing Failed
[1674664284083] [35784:10254394] [DIS] Closing all BLE connections
[1674664284083] [35784:10254394] [TOO] Pairing Failure: ../../third_party/connectedhomeip/src/protocols/secure_channel/PASESession.cpp:254: CHIP Error 0x00000032: Timeout
[1674664284084] [35784:10254373] [CTL] Shutting down the commissioner
[1674664284084] [35784:10254373] [CTL] Stopping commissioning discovery over DNS-SD
[1674664284084] [35784:10254373] [CTL] Shutting down the controller
[1674664284084] [35784:10254373] [IN] Expiring all sessions for fabric 0x1!!
[1674664284084] [35784:10254373] [FP] Forgetting fabric 0x1
[1674664284084] [35784:10254373] [TS] Pending Last Known Good Time: 2023-01-24T16:00:01
[1674664284084] [35784:10254373] [TS] Previous Last Known Good Time: 2023-01-24T16:00:01
[1674664284084] [35784:10254373] [TS] Reverted Last Known Good Time to previous value
[1674664284084] [35784:10254373] [CTL] Shutting down the commissioner
[1674664284084] [35784:10254373] [CTL] Stopping commissioning discovery over DNS-SD
[1674664284084] [35784:10254373] [CTL] Shutting down the controller
[1674664284084] [35784:10254373] [CTL] Shutting down the System State, this will teardown the CHIP Stack
[1674664284084] [35784:10254373] [DMG] IM WH moving to [Uninitialized]
[1674664284084] [35784:10254373] [DMG] IM WH moving to [Uninitialized]
[1674664284084] [35784:10254373] [DMG] IM WH moving to [Uninitialized]
[1674664284084] [35784:10254373] [DMG] IM WH moving to [Uninitialized]
[1674664284084] [35784:10254373] [DMG] All ReadHandler-s are clean, clear GlobalDirtySet
[1674664284085] [35784:10254373] [BLE] CancelConnection
[1674664284085] [35784:10254373] [FP] Shutting down FabricTable
[1674664284085] [35784:10254373] [TS] Pending Last Known Good Time: 2023-01-24T16:00:01
[1674664284085] [35784:10254373] [TS] Previous Last Known Good Time: 2023-01-24T16:00:01
[1674664284085] [35784:10254373] [TS] Reverted Last Known Good Time to previous value
[1674664284085] [35784:10254373] [DL] Inet Layer shutdown
[1674664284085] [35784:10254373] [DL] BLE shutdown
[1674664284085] [35784:10254373] [DL] System Layer shutdown
[1674664284085] [35784:10254373] [TOO] Run command failure: ../../third_party/connectedhomeip/src/protocols/secure_channel/PASESession.cpp:254: CHIP Error 0x00000032: Timeout

####################################################
LaunchPad_pump-app terminal transcript.
OpenThread started: OK
Setting OpenThread device type to ROUTER
Initialize LEDs
Initialize buttons
Initialize Pump
Setting extended discovery timeout to 20s
Server initializing...
Initializing FabricTable from persistent storage
Last Known Good Time: 2023-01-17T15:28:16
AccessControl: initializing
Examples::AccessControlDelegate::Init
AccessControl: setting
DefaultAclStorage: initializing
DefaultAclStorage: 0 entries loaded
UDP::Init bind&listen port=5540
UDP::Init bound to port=5540
BLEBase::Init - setting/overriding transport
TransportMgr initialized
Using Thread extended MAC for hostname.
Using ZAP configuration...
Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0
AccessControlCluster: initializing
Initiating Admin Commissioning cluster.
Endpoint 0, Cluster 0x0000_0030 update version to 1daba659
GeneralDiagnostics: OnDeviceReboot
Endpoint 0, Cluster 0x0000_0033 update version to 557a3a5b
LogEvent event number: 0x0000000000170000 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x00000000000001FF
Initialize PCC Plugin Server Cluster.
Init On/Off clusterstate
Endpoint 1, Cluster 0x0000_0006 update version to c69b77c5
Initialize PCC Server Cluster [EP:1]
Constant Pressure Not Supported
PCC Server: Constant Proportional Pressure Not Supported
PCC Server: Constant Flow Not Supported
PCC Server: Constant Temperature Not Supported
PCC Server: Constant Speed Not Supported
Updating services using commissioning mode 0
Using Thread extended MAC for hostname.
Using Thread extended MAC for hostname.
Advertise commission parameter vendorID=65521 productID=32778 discriminator=3840/15 cm=0
Failed to advertise extended commissionable node: 3
Scheduling extended discovery timeout in 20s
Failed to finalize service update: 1c
Delaying proxy of operational discovery: missing delegate
CASE Server enabling CASE session setups
SecureSession[0x20011bb0]: Allocated Type:2 LSID:63616
Allocated SecureSession (0x20011bb0) - waiting for Sigma1 msg
Joining Multicast groups
Emitting StartUp event
LogEvent event number: 0x0000000000170001 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x000000000000026D
Server Listening...
Device Configuration:
  Serial Number: TEST_SN
  Vendor Id: 65521 (0xFFF1)
  Product Id: 32778 (0x800A)
  Hardware Version: 0
  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
  Manufacturing Date: (not set)
  Device Type: 65535 (0xFFFF)
Stopping the watchdog timer
Starting the periodic query timer, timeout: 86400 seconds
SetupQRCode: [MT:GU3T242C00KA0648G00]
Copy/paste the below URL in a browser to see the QR Code:
project-chip.github.io/.../qrcode.html
Manual pairing code: [34970112332]
CHIP task running
OpenThread State Changed (Flags: 0x00038200)
   Network Name: OpenThread
   PAN Id: 0xFFFF
   Extended PAN Id: 0xDEAD00BEEF00CAFE
   Channel: 11
   Mesh Prefix: FDDE:AD00:BEEF::/64
## Thread stack state change (38200)
PreAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0002'
Unhandled cluster ID: 42
Endpoint 0, Cluster 0x0000_002A update version to 9e086941
PostAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0002'
Unhandled cluster ID: 42
PreAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0003'
Unhandled cluster ID: 42
Endpoint 0, Cluster 0x0000_002A update version to 9e086942
PostAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0003'
Unhandled cluster ID: 42
SecureSession[0x20011c68]: Alloca00170002 priority: 1, eAssigned local session key ID 63617
Waiting for PBKDF param request
Updating services using commissioning mode 1
Using Thread extended MAC for hostname.
Using Thread extended MAC for hostname.
Advertise commission parameter vendorID=65521 productID=32778 discriminator=3840/15 cm=1
Failed to advertise commissionable node: 3
Failed to finalize service update: 1c
Enabled BLE Advertisements

Hi Steve,

Yes, it looks like the README needs some updating. I'll notify the team.

Steve Kranz said:

Enabled BLE Advertisements

Ok, so it looks like BLE is advertised now. (Good)

Steve Kranz said:

I issued the chip-tool provisioning command immediately after pressing the Left-Btn (Btn-1) of the LaunchPad2652R7 loaded with TI/Matter pump-app system.

And it looks like the device should be advertising before you run the command on the MacBook. (Good).

Can you check if you can see the CC2652R7 advertisements?
A third-party app such as LightBlue can confirm this (a BLE scan with this app should show a "MATTER" device advertising).

If you are able to see this, then we need to check why the MacBook is unable to perform the BLE sequence successfully. We usually test with embedded chip-tool (e.g. RasPi), but it should be possible with any device which has a Bluetooth 5+.

Steve Kranz said:

I have a MacBook and within the ./matter/connectedhomeip repository I've built the cc2652 pump-app image that runs on the LP-cc2652R7 and in that same repository I've built the chip-tool Matter controller that I run in a MacBook shell.

I have not checked with MacBook before, but will try to get access to one. (It will likely be an Intel-based MacBook).

Thanks,
Toby

Hi Toby, yes, I think if you can confirm that a MacBook-Chiptool is compatible with the TI/Matter examples that would be good. Even if the MacBook you use is a non-M1 variety. I don't think I'll have any immediate ability to acquire and ramp up on a BLE sniffer and so your datapoint might be our best short term approach. I appreciate the help, Thank you,

Thanks, Steve K.

Hi Steve,

Note that you do not need a BLE sniffer, just an application you can install from the App Store or Google Play. The one I recommended is here: 

• https://apps.apple.com/us/app/lightblue/id557428110
• https://play.google.com/store/apps/details?id=com.punchthrough.lightblueexplorer&hl=en_US&gl=US

On startup, the app will automatically list all Bluetooth devices it can detect.

As an update, I am still working to get such a MacBook setup, looking like mid next week.

Thanks,
Toby

Hi Toby,

Thanks for the links. As per your recommendation I now have LightBlue installed and when I run it I can't seem to get past its "searching for peripherals..." state. No BLE device is itemized despite have pressed the Btn-1 of the LP2652R7_pump-app. In the terminal output of the pump-app (in response to the click of Btn-1) I see the following lines of transcript emitted:

Failed to advertise commissionable node: 3
Failed to finalize service update: 1c
Enabled BLE Advertisements

I am still hopeful that you can confirm that the MacBook-Chip-tool and the TI/Matter pump-app are functional, and possibly you can offer some slight change in the recipe I've been attempting. Also, as a reminder, please don't forget about the args.gni comment I made back on Jan 24th (final post of the collection that day). I still wonder if that is potentially creating an issue.

Thanks,

Steve.

Hi Steve,

I have limited hardware with me due to winter weather in Dallas, but I do have  CC2652R7.

When I run the pump-app and enable BLE advertising, I do see a device called "MATTER-3840". It seems to me that the device is running ok and advertising as expected.

Once the weather clears up (Fri or early next week), I will need to setup the other HW (such as Thread Border router).

Thanks,
Toby

Hi Toby,

How are your attempts going? I've switched to focusing on the lock-app (previously was attempting the pump-app) and I continue to struggle (using either a non-M1 or M1 MacBook). The readme directs the user to flash the *.out but I don't believe that is the system intended (based on the terminal output emitted on boot) and I've instead been flashing the *-bim.hex file; some weeks back I noticed you referenced that file as the one that you were using. It is the system that will emit (to the terminal) important items such as Setup Discriminator, and Setup Pin Code that I subsequently use (with the dataset as acquired from the OTBR) in my MacBook command line issued `chip-tool` command (below):

$ ./chip-tool pairing ble-thread 1 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fdcf00635fae4ed1051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0fff8 20202021 3840

... and prior to issuing that `chip-tool` command, when I use the button to put the device in BLE advertise mode I still do not see any device showing up in the LightBlue list of devices. I'm running LightBlue on my non-M1 MacBook. I do get a few suspicious lines of terminal output from my LaunchPadCC2652R7 device when I enter BLE advertise mode:

Failed to advertise commissionable node: 3
Failed to finalize service update: 1c
Enabled BLE Advertisements

Thanks in Advance,

Steve K.

Hi Steve,

I tried a MacBook Pro 2016 (Intel based) to run chip-tool, and it is working ok.
That is, I can successfully commission the pump-app into the Thread network of my otbr (BBB), and I can also send commands to remotely turn it "on" or "off".

When I ran the BLE commissioning command, I did get a prompt on the MacBook from the chip-tool. It requested permission to access the BLE interface on the MacBook -- I granted permission, and afterwards the rest of the process follows.

Note that this was with no updates to the args.gni file -- for pump-app, this is defined in its own args.gni (https://github.com/TexasInstruments/matter/blob/v1.0-ti-branch/examples/pump-app/cc13x2x7_26x2x7/args.gni) and CHIPProjectConfig.h (https://github.com/TexasInstruments/matter/blob/v1.0-ti-branch/examples/pump-app/cc13x2x7_26x2x7/main/include/CHIPProjectConfig.h).

Could it be related to any admin rights on the MacBook you're using for chip-tool?

Please try this new recommended repository/branch: https://github.com/TexasInstruments/matter/tree/v1.0-ti-branch

In my evaluation, chip-tool and CC2652R7 firmware are both built from this repo.

Moving forward, this will be the recommended location to evaluate TI-based Matter.

I used the same commit-id for the otbr as prescribed in the Getting Started Guide.

1832.chip-LP_CC2652R7-pump-example-bim.hex

For convenience, I have attached the pump-app firmware.

After flashing, press/release BTN-1 to enable BLE Advertising.

Then on chip-tool, proceed as you did before (e.g. ./chip-tool pairing ble-thread ....)

To send command to control the pump-app's LED:

./chip-tool onoff on 1 1

Thanks,
Toby

Hi Toby,

Some good news and some not.

I was able to successfully run one session using your *-bim.hex flashed to my LaunchPad2652R7.
I used the chip-tool that I’d previously built within the connectedhomeip repository (not the TI repo). And for a time I was able to use the `./chip-tool onoff toggle 1 1` command to change the state on the LaunchPad. Everything was good until I pressed the reset button of the LaunchPad and from that point on I was unable to get a working system, so I tried to start over with the BLE commissioning step, same as the first time except this time it didn’t work. I decided to shift gears and switch over to the TI matter repo as you suggested; my intent was to build everything fresh and see if that would work.

I was able to successfully install the repo with:
$ git clone --recurse-submodules github.com/.../matter.git
and I installed the sysconfig-1.14.0_2667 and was able to build the chip-tool and the *-bim.hex for the pump-app. I flashed it.

But again, no luck. I get part way through the BLE commissioning and I can see from the transcripts that there is BLE communication taking place between chip-tool and the LaunchPad but the commissioning ultimately fails. It seem that something is lingering on the LaunchPad that I need to clear out. Maybe, so I looked in the pump-app source code and could see that Btn-1 long press is supposed to issue a factory reset. I tried it. No luck. It didn’t fix anything. But do you suspect the factory reset actually might not have happened? This is what is reported by the device when I request it.

Factory Reset (5 second long Press of Btn-1 left button).
FactoryResetConfig() failed: Error CHIP:0x0000009F
Initialize LEDs
Initialize buttons
Initialize Pump
Failed to advertise extended commissionable node: 3
Failed to finalize service update: 1c
PreAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0002'
Unhandled cluster ID: 42
PostAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0002'
Unhandled cluster ID: 42
PreAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0003'
Unhandled cluster ID: 42
PostAttributeChangeCallback - Cluster ID: '0x002a', EndPoint ID: '0x00', Attribute ID: '0x0003'
Unhandled cluster ID: 42
## Thread stack state change (38200)

The first line shows a FactoryResetConfig() failure. Any ideas? Again, I had one good session toggling the LEDs via chip-tool and after resetting the LaunchPad I’ve never been back to a working system.

Thanks in advance,
Steve K.

Hi Steve,

Glad to hear the present issue is resolved!

Yes, feel free to post here again for your next issue or question.

Thanks,
Toby