When the OTBR is rebooted after the Matter enddevice is paired with the OTBR, the chip tool command is not transmitted.

[classic037]

Hi

I am currently working on a Matter project.

I configured OTBR with Raspberry Pi, completed pairing with nRF52840 board (Light bulb), and confirmed that Light on/off works (use to chiptool command).

However, after rebooting the OTBR, the Chip tool light on/off command is not delivered to the Enddevice.

I checked the topology of Otbr web and found it was still connecting.

When Otbr is rebooted, the n52840 board log is also output as shown below.

D: 4171091 [DL]OpenThread State Changed (Flags: 0x00000200) I: 4171101 [DL]SRP Client was stopped, because current server is no longer detected. D: 4171109 [DL]OpenThread State Changed (Flags: 0x00000200) D: 4171116 [DL]OpenThread State Changed (Flags: 0x00000002) D: 4171121 [DL]   Thread Unicast Addresses: D: 4171125 [DL]        fd15:f73b:9669:466a:0:ff:fe00:0/64 valid rloc D: 4171131 [DL]        fd15:f73b:9669:466a:5d79:1733:146f:bf/64 valid D: 4171138 [DL]        fe80::90b7:f629:a2c8:a8a9/64 valid preferred D: 4171733 [DL]OpenThread State Changed (Flags: 0x00000200) D: 4171740 [DL]OpenThread State Changed (Flags: 0x00000001) D: 4171745 [DL]   Thread Unicast Addresses: D: 4171749 [DL]        fdfa:abe6:eb46:1:bbd8:7c9:d4cd:5521/64 valid preferred D: 4171756 [DL]        fd15:f73b:9669:466a:0:ff:fe00:0/64 valid rloc D: 4171763 [DL]        fd15:f73b:9669:466a:5d79:1733:146f:bf/64 valid D: 4171769 [DL]        fe80::90b7:f629:a2c8:a8a9/64 valid preferred D: 4172039 [DL]OpenThread State Changed (Flags: 0x00000200) I: 4172062 [DL]SRP Client was started, detected server: fd15:f73b:9669:466a:34a3:c700:bb6a:851f D: 4172071 [DL]OpenThread State Changed (Flags: 0x00000200) D: 4172383 [DL]OpenThread State Changed (Flags: 0x00000200) D: 4173224 [DL]OnSrpClientNotification: Last requested operation completed successfully D: 4174363 [DL]OpenThread State Changed (Flags: 0x00000200)

OTBT Chip tool command error log

coway@raspberrypi:~/Matter-aws-iot-device-sdk-python-v2/samples $ ./chip-tool-release onoff on 303 1 [1661331506.060391][826:826] CHIP:DL: writing settings to file (/tmp/chip_kvs-d8q5SE) [1661331506.061100][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1661331506.062555][826:826] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-L5eWAG) [1661331506.062972][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1661331506.063473][826:826] CHIP:DL: writing settings to file (/tmp/chip_config.ini-r8I1FC) [1661331506.063824][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1661331506.064257][826:826] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-sWonJC) [1661331506.064720][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1661331506.065443][826:826] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-ZB9L9F) [1661331506.066898][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1661331506.067057][826:826] CHIP:DL: NVS set: chip-factory/unique-id = "4DCFB3E2508D3059" [1661331506.067436][826:826] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-TIFWUC) [1661331506.069748][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1661331506.069907][826:826] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1661331506.070303][826:826] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-bVMcVC) [1661331506.076736][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1661331506.076896][826:826] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1661331506.077319][826:826] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Lcql9C) [1661331506.078694][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1661331506.078841][826:826] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1661331506.079222][826:826] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-1sWe9E) [1661331506.080811][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1661331506.080997][826:826] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1661331506.081600][826:826] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-eaTgJE) [1661331506.083198][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1661331506.083437][826:826] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1661331506.083822][826:826] CHIP:DL: writing settings to file (/tmp/chip_config.ini-uShRTC) [1661331506.085155][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1661331506.085305][826:826] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1661331506.085710][826:826] CHIP:DL: writing settings to file (/tmp/chip_config.ini-LMMjJG) [1661331506.087302][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1661331506.087487][826:826] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1661331506.384761][826:826] CHIP:DL: Got Ethernet interface: eth0 [1661331506.386038][826:826] CHIP:DL: Found the primary Ethernet interface:eth0 [1661331506.387166][826:826] CHIP:DL: Got WiFi interface: wlan0 [1661331506.394028][826:826] CHIP:DL: Found the primary WiFi interface:wlan0 [1661331506.406148][826:826] CHIP:ZCL: Using ZAP configuration... [1661331506.419038][826:826] CHIP:DL: Avahi client registered [1661331506.429245][826:826] CHIP:CTL: Setting attestation nonce to random value [1661331506.429468][826:826] CHIP:CTL: Setting CSR nonce to random value [1661331506.431702][826:826] CHIP:CTL: Setting attestation nonce to random value [1661331506.431889][826:826] CHIP:CTL: Setting CSR nonce to random value [1661331506.433076][826:826] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: ../../examples/chip-tool/co                                                            nfig/PersistentStorage.cpp:108: CHIP Error 0x000000A0: Value not found in the persisted storage [1661331506.444114][826:826] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: ../../examples/chip-tool/c                                                            onfig/PersistentStorage.cpp:108: CHIP Error 0x000000A0: Value not found in the persisted storage [1661331506.451870][826:826] CHIP:CTL: Generating RCAC [1661331506.518041][826:826] CHIP:CTL: Generating ICAC [1661331506.521138][826:826] CHIP:CTL: Generating NOC [1661331506.525146][826:826] CHIP:DIS: Verifying the received credentials [1661331506.533023][826:826] CHIP:DIS: Added new fabric at index: 0x1, Initialized: 1 [1661331506.533156][826:826] CHIP:DIS: Assigned compressed fabric ID: 0x0BB67AF65BEC5973, node ID: 0x000000000001                                                            B669 [1661331506.553574][826:826] CHIP:DIS: Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage [1661331506.556021][826:826] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x0BB67AF65BEC5973 [1661331506.556344][826:826] CHIP:CTL: Setting attestation nonce to random value [1661331506.556660][826:826] CHIP:CTL: Setting CSR nonce to random value [1661331506.561272][826:826] CHIP:CTL: Generating NOC [1661331506.564180][826:826] CHIP:DIS: Verifying the received credentials [1661331506.571487][826:826] CHIP:DIS: Added new fabric at index: 0x2, Initialized: 1 [1661331506.571611][826:826] CHIP:DIS: Assigned compressed fabric ID: 0x09FDD1D7A4163087, node ID: 0x000000000001                                                            B669 [1661331506.586235][826:826] CHIP:DIS: Fabric (2) persisted to storage. Calling OnFabricPersistedToStorage [1661331506.600002][826:826] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x09FDD1D7A4163087 [1661331506.600364][826:826] CHIP:CTL: Setting attestation nonce to random value [1661331506.600978][826:826] CHIP:CTL: Setting CSR nonce to random value [1661331506.605343][826:826] CHIP:CTL: Generating NOC [1661331506.609513][826:826] CHIP:DIS: Verifying the received credentials [1661331506.617269][826:826] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1 [1661331506.617523][826:826] CHIP:DIS: Assigned compressed fabric ID: 0xE2E7646293B8FDDD, node ID: 0x000000000001                                                            B669 [1661331506.632867][826:826] CHIP:DIS: Fabric (3) persisted to storage. Calling OnFabricPersistedToStorage [1661331506.635891][826:826] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xE2E7646293B8FDDD [1661331508.993454][826:831] CHIP:TOO: Sending command to node 0x12f [1661331508.993700][826:831] CHIP:DIS: Resolving 0BB67AF65BEC5973:000000000000012F ... [1661331509.194093][826:831] CHIP:DIS: Checking node lookup status after 200 ms [1661331513.997950][826:831] CHIP:DL: Re-trying resolve [1661331518.993731][826:826] CHIP:DIS: Cancelling incomplete address resolution as device is being deleted. [1661331518.993900][826:826] CHIP:DIS: Discovery does not require any more timeouts [1661331518.996741][826:826] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1661331518.997508][826:826] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-pSjY4C) [1661331519.000148][826:826] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1661331519.000335][826:826] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1661331519.000415][826:826] CHIP:DL: Inet Layer shutdown [1661331519.000477][826:826] CHIP:DL: BLE shutdown [1661331519.000609][826:826] CHIP:DL: System Layer shutdown [1661331519.000919][826:826] CHIP:TOO: Run command failure: ../../examples/chip-tool/commands/common/CHIPCommand.cpp:397: CHIP Error 0x00000032: Timeout

After enddevice and Otbr are paired, if Otbr is rebooted, do I have to unconditionally pair again?

When tested using the Chip tool Android app, it was confirmed that the on/off command was delivered to the enddevice without re-pairing even if otbr was rebooted.

After pairing enddevcie and Otbr, even if Otbr reboots, please guide how to transfer to enddevice with chip tool command without re-pairing process.

Plesae guide

Thank you

Thank you

[classic037]

1. Successful commissioning of endevice and otbr for the first time (node id is 300)
./chip-tool-release onoff on 300 1 When sending command, node id 300 Fabric id 0x1A1EF49FC643541D

[1661490979.941199][1352:1352] CHIP:DIS: Verifying the received credentials
[1661490979.948676][1352:1352] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1
[1661490979.948805][1352:1352] CHIP:DIS: Assigned compressed fabric ID: 0x783E482064712CE1, node ID: 0x000000000001B669
[1661490979.972146][1352:1352] CHIP:DIS: Fabric (3) persisted to storage. Calling OnFabricPersistedToStorage
[1661490979.972271][1352:1352] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x783E482064712CE1
[1661490980.130537][1352:1357] CHIP:TOO: Sending command to node 0x12c
[1661490980.131397][1352:1357] CHIP:DIS: Resolving 1A1EF49FC643541D:000000000000012C ...
[1661490980.137856][1352:1357] CHIP:DL: Avahi resolve found
[1661490980.138696][1352:1357] CHIP:DIS: Node ID resolved for 1A1EF49FC643541D:000000000000012C
[1661490980.140833][1352:1357] CHIP:DIS: UDP:[fd99:bf05:bbe9:1:1ed7:af3:6efd:a15c%wlan0]:5540: new best score: 6
[1661490980.140986][1352:1357] CHIP:DIS: Checking node lookup status after 10 ms
[1661490980.141612][1352:1357] CHIP:DIS: Keeping DNSSD lookup active
[1661490980.331406][1352:1357] CHIP:DIS: Checking node lookup status after 200 ms
[1661490980.332571][1352:1357] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x000000000000012C
[1661490980.335867][1352:1357] CHIP:IN: Prepared unauthenticated message 0x5585e74768 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 4525i with MessageCounter:2314344470.
[1661490980.336651][1352:1357] CHIP:IN: Sending unauthenticated msg 0x5585e74768 with MessageCounter:2314344470 to 0x0000000000000000 at monotonic time: 00000000003D4264 msec
[1661490980.337620][1352:1357] CHIP:SC: Sent Sigma1 msg

2. Retransmit the following command after OTBT reboot
./chip-tool-release onoff on 300 1

Fabric id is different from fabric id before otbr reboot.

[1661491207.821921][789:789] CHIP:DIS: Added new fabric at index: 0x2, Initialized: 1
[1661491207.822056][789:789] CHIP:DIS: Assigned compressed fabric ID: 0x46C385D8286F4C18, node ID: 0x000000000001B669
[1661491207.845347][789:789] CHIP:DIS: Fabric (2) persisted to storage. Calling OnFabricPersistedToStorage
[1661491207.847646][789:789] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x46C385D8286F4C18
[1661491207.848014][789:789] CHIP:CTL: Setting attestation nonce to random value
[1661491207.848207][789:789] CHIP:CTL: Setting CSR nonce to random value
[1661491207.852583][789:789] CHIP:CTL: Generating NOC
[1661491207.855649][789:789] CHIP:DIS: Verifying the received credentials
[1661491207.863075][789:789] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1
[1661491207.863209][789:789] CHIP:DIS: Assigned compressed fabric ID: 0x55F242389EDE75B3, node ID: 0x000000000001B669
[1661491207.874940][789:789] CHIP:DIS: Fabric (3) persisted to storage. Calling OnFabricPersistedToStorage
[1661491207.877534][789:789] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x55F242389EDE75B3
[1661491208.155696][789:794] CHIP:TOO: Sending command to node 0x12c
[1661491208.155948][789:794] CHIP:DIS: Resolving D6D4D6EF92695544:000000000000012C ...
[1661491208.356344][789:794] CHIP:DIS: Checking node lookup status after 200 ms
[1661491213.160018][789:794] CHIP:DL: Re-trying resolve
[1661491218.156018][789:789] CHIP:DIS: Cancelling incomplete address resolution as device is being deleted.
[1661491218.156171][789:789] CHIP:DIS: Discovery does not require any more timeouts
[1661491218.158868][789:789] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.

However, as a result of checking whether the Fabric ID exists before otbr boot, it exists.
./chip-tool-release discover resolve 300 0x1A1EF49FC643541D

coway@raspberrypi:~/Matter-aws-iot-device-sdk-python-v2/samples $ ./chip-tool-release discover resolve 300 0x1A1EF49FC643541D
[1661491291.639196][800:800] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-tTJHpF)
[1661491291.641279][800:800] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1661491291.641601][800:800] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
[1661491295.155690][800:800] CHIP:DL: Got Ethernet interface: eth0
[1661491295.156464][800:800] CHIP:DL: Found the primary Ethernet interface:eth0
[1661491295.157121][800:800] CHIP:DL: Got WiFi interface: wlan0
[1661491295.162824][800:800] CHIP:DL: Found the primary WiFi interface:wlan0
[1661491295.163624][800:800] CHIP:IN: Loading from storage for fabric index 0x1
[1661491295.168682][800:800] CHIP:IN: Loading from storage for fabric index 0x2
[1661491295.170002][800:800] CHIP:IN: Loading from storage for fabric index 0x3
[1661491295.176423][800:800] CHIP:ZCL: Using ZAP configuration...
[1661491295.182938][800:800] CHIP:DL: Avahi client registered
[1661491295.184990][800:800] CHIP:CTL: Setting attestation nonce to random value
[1661491295.185101][800:800] CHIP:CTL: Setting CSR nonce to random value
[1661491295.185264][800:800] CHIP:CTL: Setting attestation nonce to random value
[1661491295.185368][800:800] CHIP:CTL: Setting CSR nonce to random value
[1661491295.187229][800:800] CHIP:CTL: Generating NOC
[1661491295.188771][800:800] CHIP:DIS: Verifying the received credentials
[1661491295.192756][800:800] CHIP:DIS: Added new fabric at index: 0x1, Initialized: 1
[1661491295.192863][800:800] CHIP:DIS: Assigned compressed fabric ID: 0xD6D4D6EF92695544, node ID: 0x000000000001B669
[1661491295.203104][800:800] CHIP:DIS: Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage
[1661491295.203187][800:800] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xD6D4D6EF92695544
[1661491295.203372][800:800] CHIP:CTL: Setting attestation nonce to random value
[1661491295.203527][800:800] CHIP:CTL: Setting CSR nonce to random value
[1661491295.205319][800:800] CHIP:CTL: Generating NOC
[1661491295.206827][800:800] CHIP:DIS: Verifying the received credentials
[1661491295.210647][800:800] CHIP:DIS: Added new fabric at index: 0x2, Initialized: 1
[1661491295.210730][800:800] CHIP:DIS: Assigned compressed fabric ID: 0x46C385D8286F4C18, node ID: 0x000000000001B669
[1661491295.228607][800:800] CHIP:DIS: Fabric (2) persisted to storage. Calling OnFabricPersistedToStorage
[1661491295.228688][800:800] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x46C385D8286F4C18
[1661491295.228877][800:800] CHIP:CTL: Setting attestation nonce to random value
[1661491295.228986][800:800] CHIP:CTL: Setting CSR nonce to random value
[1661491295.230832][800:800] CHIP:CTL: Generating NOC
[1661491295.232539][800:800] CHIP:DIS: Verifying the received credentials
[1661491295.237266][800:800] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1
[1661491295.237401][800:800] CHIP:DIS: Assigned compressed fabric ID: 0x55F242389EDE75B3, node ID: 0x000000000001B669
[1661491295.259592][800:800] CHIP:DIS: Fabric (3) persisted to storage. Calling OnFabricPersistedToStorage
[1661491295.259727][800:800] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x55F242389EDE75B3
[1661491295.447558][800:805] CHIP:DIS: Resolving 1A1EF49FC643541D:000000000000012C ...
[1661491295.556267][800:805] CHIP:DL: Avahi resolve found
[1661491295.556467][800:805] CHIP:DIS: Node ID resolved for 1A1EF49FC643541D:000000000000012C
[1661491295.558047][800:805] CHIP:DIS: UDP:[fd99:bf05:bbe9:1:1ed7:af3:6efd:a15c%wlan0]:5540: new best score: 6
[1661491295.558151][800:805] CHIP:DIS: Checking node lookup status after 110 ms
[1661491295.558220][800:805] CHIP:DIS: Keeping DNSSD lookup active
[1661491295.648033][800:805] CHIP:DIS: Checking node lookup status after 200 ms
[1661491295.648186][800:805] CHIP:TOO: NodeId Resolution: 300 at UDP:[fd99:bf05:bbe9:1:1ed7:af3:6efd:a15c]:5540
[1661491295.648255][800:805] CHIP:TOO: MRP retry interval (idle): 5000ms
[1661491295.648320][800:805] CHIP:TOO: MRP retry interval (active): 300ms
[1661491295.648382][800:805] CHIP:TOO: Supports TCP: no
[1661491295.648600][800:805] CHIP:DIS: Discovery does not require any more timeouts
[1661491295.653085][800:800] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1661491295.653735][800:800] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-suUJsH)
[1661491295.656470][800:800] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1661491295.656650][800:800] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1661491295.656772][800:800] CHIP:DL: Inet Layer shutdown
[1661491295.656840][800:800] CHIP:DL: BLE shutdown
[1661491295.656920][800:800] CHIP:DL: System Layer shutdown

I think Enddevice and otbr can send and receive cluster commands successfully even if Otbr is rebooted if Fabric ID does not change after Otbr reboots

Please guide.

Thank you

[Jørgen Holmefjord]

Hi,

This might be caused by the CHIP-tool config files being stored in /tmp. Some platform like Ubuntu 20.04 on Raspberry Pi removes content in /tmp on reboot.

A quick solution could to modify the setting of /tmp:

sudo vim /usr/lib/tmpfiles.d/tmp.conf
Change the line "D /tmp 1777 root root -" to "d /tmp 1777 root root -"
Then the content of /tmp will not be removed on every reboot.

A better solution is making chip-tool not store information in /tmp, but that will require a re-compilation.

Can you check if this resolves your issue?

Best regards,
Jørgen

[classic037]

Thank you very much!

Changing the tmp settings according to your guide solved the problem.

I agree with you. I think it's right to modify the chip-tool not to save the settings to tmp.

Can you guide me to save to a different path in chip-tool?

Thank you!

[Jørgen Holmefjord]

As far as I can see, the lines linked in my previous reply is the only place where the configs are stored in /tmp. Did you try to change these lines and rebuild chip-tool from the modified sources?

[classic037]

hi  Jørgen Holmefjord

I try edit the chip tool source and test it. I will share the results soon

[classic037]

hi  Jørgen Holmefjord

Do you know how to build in aarch64 format when building CHIP TOOL?

[Jørgen Holmefjord]

Did you try the instructions in the documentation? It mentions aarch64, so I would assume it would build for this architecture if you build it on the Raspberry Pi.