Error on commissioning step 'FindOperational' while pairing matter sample over ble-thread

Hi,

I'm following this tutorial https://developer.nordicsemi.com/nRF_Connect_SDK/doc/2.0.0/nrf/ug_matter.html - I use the nrf52840 dongle as a co-processor connected to a raspberry pi running OTBR, nrf52840 DK flashed with matter door lock sample and I downloaded chip tool (release version 2.0.0) on my laptop with Linux. I want to connect the door lock sample to OTBR as described here. Unfortunately, step 6 causes the problem. When I execute this command:

./chip-tool-release pairing ble-thread 1000 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fd05128ef262a22b051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8 20202021 3840

I get the following error:

 

CHIP:DIS: Operational discovery failed for 0x00000000000003E8: ../../src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:174: CHIP Error 0x00000032: Timeout

and I have no idea what should be wrong. (Does it mean there is something wrong with OTBR? But if I execute `service otbr-agent status` on raspberry pi I get otbr-agent is running and for command  `ot-ctl state` the response is Leader.  

Can anybody help me figure it out? Thank you.

If you want to see full output from the command, you can find it here.

Parents
  • Hi Filipmrazek,

    Here are some suggestions for your debugging:
    1) Ensure that the chip-tool cache is cleaned after each unsuccessful command:
    rm -rf /tmp/chip_*
    2) Ensure that the RPi OS is 64 bit (we use Ubuntu 20.04 LTS 64 bit on daily basis, this distro is also used for Matter certification)
    3) It might be that the docker setup blocks the router advertisements on the RPi. Following lines may help is such a case (run on RPi host, replace the wlan0 with proper WiFi iface name if needed):
    sudo sysctl net.ipv6.conf.wlan0.accept_ra=2
    sudo sysctl net.ipv6.conf.wlan0.accept_ra_rt_info_max_plen=128
    4) Also I advice to run the otbr container in the following fashion on the RPi:
    sudo docker run --rm -it --privileged -d --network host --name otbr --volume /dev/ttyACM0:/dev/ttyACM0 nrfconnect/otbr:1813352 --radio-url spinel+hdlc+uart:///dev/ttyACM0 -B wlan0
    Best regards,
    Charlie
Reply
  • Hi Filipmrazek,

    Here are some suggestions for your debugging:
    1) Ensure that the chip-tool cache is cleaned after each unsuccessful command:
    rm -rf /tmp/chip_*
    2) Ensure that the RPi OS is 64 bit (we use Ubuntu 20.04 LTS 64 bit on daily basis, this distro is also used for Matter certification)
    3) It might be that the docker setup blocks the router advertisements on the RPi. Following lines may help is such a case (run on RPi host, replace the wlan0 with proper WiFi iface name if needed):
    sudo sysctl net.ipv6.conf.wlan0.accept_ra=2
    sudo sysctl net.ipv6.conf.wlan0.accept_ra_rt_info_max_plen=128
    4) Also I advice to run the otbr container in the following fashion on the RPi:
    sudo docker run --rm -it --privileged -d --network host --name otbr --volume /dev/ttyACM0:/dev/ttyACM0 nrfconnect/otbr:1813352 --radio-url spinel+hdlc+uart:///dev/ttyACM0 -B wlan0
    Best regards,
    Charlie
Children
  • Hi Charlie,

    I followed your suggestions and it works!

    I tried several things which didn't help:

    • tried to clean the chip-tool cache
    • already had 64-bit Ubuntu 20.04 on my RPi, so I tried to install OTBR also on Intel NUC with Ubuntu 20.04, but it gave me the same error.
    • tried to add suggested sysctls to docker-compose config
    • tried docker run command  in the tutorial here

    Then I tried your command for running the docker container and it worked! To find out which part is causing the problem I tried many variations of your command and it seems to me it's a combination of host network (custom network is used in the tutorial) and using -B nps1s0 in the command.

    Thank you for your help!
    Anyway, I've got one more question.  After successful pairing, I can control my device using for example

    sudo ./chip-tool-release doorlock unlock-door 7 1 --timedInteractionTimeoutMs 100

    but after I reset my laptop with chip-tool, I get the following error when trying to interact with the paired device:

    [1663513504.010477][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_kvs-QnevCm)
    [1663513504.010548][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs)
    [1663513504.010703][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-9iGebm)
    [1663513504.010753][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
    [1663513504.010806][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_config.ini-6eYnyn)
    [1663513504.010853][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
    [1663513504.010901][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-d97uin)
    [1663513504.010948][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
    [1663513504.011017][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-rmsSSn)
    [1663513504.011142][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
    [1663513504.011158][5676:5676] CHIP:DL: NVS set: chip-factory/unique-id = "F7A36C44BF44AC4B"
    [1663513504.011199][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-MI7Dmm)
    [1663513504.011314][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
    [1663513504.011329][5676:5676] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1)
    [1663513504.011365][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-QqrM3m)
    [1663513504.011471][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
    [1663513504.011487][5676:5676] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001)
    [1663513504.011523][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-dcFbVn)
    [1663513504.011610][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
    [1663513504.011625][5676:5676] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1)
    [1663513504.011661][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-7bKXPo)
    [1663513504.011757][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
    [1663513504.011772][5676:5676] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
    [1663513504.011813][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Z68VPo)
    [1663513504.011910][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
    [1663513504.011928][5676:5676] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0)
    [1663513504.011961][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_config.ini-Gxh2Ep)
    [1663513504.012048][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
    [1663513504.012065][5676:5676] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0)
    [1663513504.012102][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_config.ini-4nBt2o)
    [1663513504.012253][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
    [1663513504.012279][5676:5676] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2)
    [1663513504.012829][5676:5676] CHIP:DL: Got Ethernet interface: enp9s0
    [1663513504.013315][5676:5676] CHIP:DL: Found the primary Ethernet interface:enp9s0
    [1663513504.013795][5676:5676] CHIP:DL: Got WiFi interface: wlp8s0
    [1663513504.014840][5676:5676] CHIP:DL: Found the primary WiFi interface:wlp8s0
    [1663513504.015313][5676:5676] CHIP:ZCL: Using ZAP configuration...
    [1663513504.017375][5676:5676] CHIP:DL: Avahi client registered
    [1663513504.018830][5676:5676] CHIP:CTL: Setting attestation nonce to random value
    [1663513504.018858][5676:5676] CHIP:CTL: Setting CSR nonce to random value
    [1663513504.018920][5676:5676] CHIP:CTL: Setting attestation nonce to random value
    [1663513504.018931][5676:5676] CHIP:CTL: Setting CSR nonce to random value
    [1663513504.019111][5676:5676] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: ../../examples/chip-tool/config/PersistentStorage.cpp:108: CHIP Error 0x000000A0: Value not found in the persisted storage
    [1663513504.022092][5676:5676] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: ../../examples/chip-tool/config/PersistentStorage.cpp:108: CHIP Error 0x000000A0: Value not found in the persisted storage
    [1663513504.022505][5676:5676] CHIP:CTL: Generating RCAC
    [1663513504.022788][5676:5676] CHIP:CTL: Generating ICAC
    [1663513504.023049][5676:5676] CHIP:CTL: Generating NOC
    [1663513504.023727][5676:5676] CHIP:DIS: Verifying the received credentials
    [1663513504.024229][5676:5676] CHIP:DIS: Added new fabric at index: 0x1, Initialized: 1
    [1663513504.024238][5676:5676] CHIP:DIS: Assigned compressed fabric ID: 0xD0430A4B4679D9C7, node ID: 0x000000000001B669
    [1663513504.025366][5676:5676] CHIP:DIS: Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage
    [1663513504.025542][5676:5676] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xD0430A4B4679D9C7
    [1663513504.025578][5676:5676] CHIP:CTL: Setting attestation nonce to random value
    [1663513504.025605][5676:5676] CHIP:CTL: Setting CSR nonce to random value
    [1663513504.026002][5676:5676] CHIP:CTL: Generating NOC
    [1663513504.026289][5676:5676] CHIP:DIS: Verifying the received credentials
    [1663513504.026818][5676:5676] CHIP:DIS: Added new fabric at index: 0x2, Initialized: 1
    [1663513504.026831][5676:5676] CHIP:DIS: Assigned compressed fabric ID: 0x7F29D9201A48EA8B, node ID: 0x000000000001B669
    [1663513504.028127][5676:5676] CHIP:DIS: Fabric (2) persisted to storage. Calling OnFabricPersistedToStorage
    [1663513504.028341][5676:5676] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x7F29D9201A48EA8B
    [1663513504.028379][5676:5676] CHIP:CTL: Setting attestation nonce to random value
    [1663513504.028396][5676:5676] CHIP:CTL: Setting CSR nonce to random value
    [1663513504.028754][5676:5676] CHIP:CTL: Generating NOC
    [1663513504.029019][5676:5676] CHIP:DIS: Verifying the received credentials
    [1663513504.029609][5676:5676] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1
    [1663513504.029620][5676:5676] CHIP:DIS: Assigned compressed fabric ID: 0x692D05399609C116, node ID: 0x000000000001B669
    [1663513504.030652][5676:5676] CHIP:DIS: Fabric (3) persisted to storage. Calling OnFabricPersistedToStorage
    [1663513504.030866][5676:5676] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x692D05399609C116
    [1663513504.053079][5676:5686] CHIP:TOO: Sending command to node 0x9
    [1663513504.053107][5676:5686] CHIP:DIS: Resolving D0430A4B4679D9C7:0000000000000009 ...
    [1663513504.253958][5676:5686] CHIP:DIS: Checking node lookup status after 201 ms
    [1663513509.056111][5676:5686] CHIP:DL: Re-trying resolve
    [1663513514.053429][5676:5676] CHIP:DIS: Cancelling incomplete address resolution as device is being deleted.
    [1663513514.053496][5676:5676] CHIP:DIS: Discovery does not require any more timeouts
    [1663513514.054750][5676:5676] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
    [1663513514.055019][5676:5676] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ZzlNVn)
    [1663513514.055547][5676:5676] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
    [1663513514.055855][5676:5676] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
    [1663513514.056093][5676:5676] CHIP:DL: Inet Layer shutdown
    [1663513514.056117][5676:5676] CHIP:DL: BLE shutdown
    [1663513514.056136][5676:5676] CHIP:DL: System Layer shutdown
    [1663513514.056395][5676:5676] CHIP:TOO: Run command failure: ../../examples/chip-tool/commands/common/CHIPCommand.cpp:397: CHIP Error 0x00000032: Timeout

    What should I do to control the device after resetting the laptop with chip-tool?

    Thank you.

  • Hey how you got operational dataset by running the following command

    sudo docker run --rm -it --privileged -d --network host --name otbr --volume /dev/ttyACM0:/dev/ttyACM0 nrfconnect/otbr:1813352 --radio-url spinel+hdlc+uart:///dev/ttyACM0 -B wlan0

Related