BLE - WIFI commissioning

i am using ubuntu 20.04 as a matter contoller and nrf52840 as matter devce and i am doing BLE - WIFi commssionig and i get BLE timeout error how to solve it.

Parents
  • Hi Gautam, 

    Do you have BLE timeout error on the Ubuntu's side ( I assume it's the central ? ) or on the nRF52840 ? 
    Do you have any log on the nRF52840 ? 
    Which sample  you are running on the nRF52840 ? On the Ubuntu I assume you are running the chip-tool application ? 


    I would suggest to capture a sniffer trace to see what happens over the air. 

  • yes i get error in ubuntu's side and i am using matter-bulb from nrf-connect-sdk 2.3.0 and yes i am using chip-tool.

    this are the logs on nrf52840 when i run this command in chip-tool  "sudo ./chip-tool pairing ble-wifi 1 FD 123  20202021 3840":

    I: Factory Reset Triggered. Release button within 3000ms to cancel.
    I: Factory Reset has been Canceled
    I: Factory Reset Triggered. Release button within 3000ms to cancel.
    I: 28352 [TS]Pending Last Known Good Time: 2023-05-10T17:45:17
    I: 28358 [TS]Previous Last Known Good Time: 2023-05-10T17:45:17
    I: 28364 [TS]Reverted Last Known Good Time to previous value
    I: 28369 [DL]Performing factory reset
    I: 28414 [DL]Erasing Thread persistent info...
    I: nRF5 802154 radio initialized
    E: JEDEC id [00 00 00] expect [c2 28 17]
    I: 4 Sectors of 4096 bytes
    I: alloc wra: 0, 6b0
    I: data wra: 0, 544
    
    
    uart:~$ *** Booting Zephyr OS build v3.2.99-ncs2 ***
    I: Init CHIP stack
    I: 235 [DL]BLE address: D3:91:4F:49:9B:36
    I: 245 [DL]OpenThread started: OK
    I: 248 [DL]Setting OpenThread device type to ROUTER
    I: 253 [SVR]Server initializing...
    I: 256 [TS]Last Known Good Time: [unknown]
    I: 260 [TS]Setting Last Known Good Time to firmware build time 2023-05-10T17:45:17
    I: 272 [DMG]AccessControl: initializing
    I: 275 [DMG]Examples::AccessControlDelegate::Init
    I: 280 [DMG]AccessControl: setting
    I: 283 [DMG]DefaultAclStorage: initializing
    I: 287 [DMG]DefaultAclStorage: 0 entries loaded
    D: 291 [IN]UDP::Init bind&listen port=5540
    E: 295 [IN]SO_REUSEPORT failed: 109
    D: 298 [IN]UDP::Init bound to port=5540
    D: 302 [IN]BLEBase::Init - setting/overriding transport
    D: 307 [IN]TransportMgr initialized
    I: 323 [ZCL]Using ZAP configuration...
    I: 329 [DMG]AccessControlCluster: initializing
    I: 333 [ZCL]Initiating Admin Commissioning cluster.
    I: 338 [ZCL]On/Off set value: 1 0
    I: 341 [ZCL]On/off already set to new value
    I: 349 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
    D: 357 [IN]SecureSession[0x20003568]: Allocated Type:1 LSID:35776
    I: 363 [DIS]Updating services using commissioning mode 1
    I: 368 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
    E: 378 [DIS]Failed to advertise commissionable node: 3
    E: 382 [DIS]Failed to finalize service update: 1c
    I: 387 [DIS]Updating services using commissioning mode 1
    I: 393 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
    E: 402 [DIS]Failed to advertise commissionable node: 3
    E: 407 [DIS]Failed to finalize service update: 1c
    I: 411 [DIS]Delaying proxy of operational discovery: missing delegate
    I: 417 [IN]CASE Server enabling CASE session setups
    D: 422 [IN]SecureSession[0x20003620]: Allocated Type:2 LSID:35777
    I: 428 [SVR]Joining Multicast groups
    I: 432 [SVR]Server Listening...
    I: 435 [DL]Device Configuration:
    I: 438 [DL]  Serial Number: 11223344556677889900
    I: 442 [DL]  Vendor Id: 65521 (0xFFF1)
    I: 446 [DL]  Product Id: 32773 (0x8005)
    I: 450 [DL]  Hardware Version: 0
    I: 453 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
    I: 458 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
    I: 465 [DL]  Manufacturing Date: (not set)
    I: 469 [DL]  Device Type: 65535 (0xFFFF)
    I: 473 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00]
    I: 478 [SVR]Copy/paste the below URL in a browser to see the QR Code:
    I: 484 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00
    I: 493 [SVR]Manual pairing code: [34970112332]
    I: 498 [DL]CHIP task running
    I: 503 [DL]CHIPoBLE advertising started
    I: 654 [ZCL]Cluster OnOff: attribute OnOff set to 0
    I: 658 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254
    E: 665 [DL]Long dispatch time: 159 ms, for event type 3
    I: 670 [DL]NFC Tag emulation started
    I: 30506 [DL]CHIPoBLE advertising mode changed to slow
    I: 30513 [DL]CHIPoBLE advertising started
    I: 31291 [DL]BLE connection established (ConnId: 0x00)
    I: 31296 [DL]Current number of connections: 1/1
    I: 31300 [DL]CHIPoBLE advertising stopped
    I: 31304 [DL]NFC Tag emulation stopped
    I: 41456 [DL]BLE GAP connection terminated (reason 0x28)
    I: 41461 [DL]Current number of connections: 0/1
    I: 41467 [DL]CHIPoBLE advertising started
    I: 41471 [DL]NFC Tag emulation started

    this are my chip-tool logs:

    [1684152654.742530][105627:105627] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
    [1684152654.742639][105627:105627] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
    [1684152654.742672][105627:105627] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
    [1684152654.742699][105627:105627] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
    [1684152654.742757][105627:105627] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-TgY6Xb)
    [1684152654.742847][105627:105627] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
    [1684152654.742854][105627:105627] CHIP:DL: NVS set: chip-counters/reboot-count = 35 (0x23)
    [1684152654.743391][105627:105627] CHIP:DL: Got Ethernet interface: enp1s0
    [1684152654.743831][105627:105627] CHIP:DL: Found the primary Ethernet interface:enp1s0
    [1684152654.744295][105627:105627] CHIP:DL: Got WiFi interface: wlp3s0
    [1684152654.745856][105627:105627] CHIP:DL: Found the primary WiFi interface:wlp3s0
    [1684152654.745873][105627:105627] CHIP:IN: UDP::Init bind&listen port=0
    [1684152654.745885][105627:105627] CHIP:IN: UDP::Init bound to port=60598
    [1684152654.745888][105627:105627] CHIP:IN: UDP::Init bind&listen port=0
    [1684152654.745894][105627:105627] CHIP:IN: UDP::Init bound to port=45850
    [1684152654.745896][105627:105627] CHIP:IN: BLEBase::Init - setting/overriding transport
    [1684152654.745898][105627:105627] CHIP:IN: TransportMgr initialized
    [1684152654.745904][105627:105627] CHIP:FP: Initializing FabricTable from persistent storage
    [1684152654.745931][105627:105627] CHIP:TS: Last Known Good Time: 2023-05-15T15:02:24
    [1684152654.746043][105627:105627] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x2CA210E66CF540C3, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
    [1684152654.746385][105627:105627] CHIP:ZCL: Using ZAP configuration...
    [1684152654.750481][105627:105627] CHIP:CTL: System State Initialized...
    [1684152654.750491][105627:105627] CHIP:CTL: Stopping commissioning discovery over DNS-SD
    [1684152654.750497][105627:105627] CHIP:CTL: Setting attestation nonce to random value
    [1684152654.750502][105627:105627] CHIP:CTL: Setting CSR nonce to random value
    [1684152654.750509][105627:105627] CHIP:IN: UDP::Init bind&listen port=5550
    [1684152654.750515][105627:105627] CHIP:IN: UDP::Init bound to port=5550
    [1684152654.750518][105627:105627] CHIP:IN: UDP::Init bind&listen port=5550
    [1684152654.750523][105627:105627] CHIP:IN: UDP::Init bound to port=5550
    [1684152654.750524][105627:105627] CHIP:IN: TransportMgr initialized
    [1684152654.750589][105627:105629] CHIP:DL: CHIP task running
    [1684152654.750616][105627:105629] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
    [1684152654.750670][105627:105629] CHIP:CTL: Stopping commissioning discovery over DNS-SD
    [1684152654.750676][105627:105629] CHIP:CTL: Setting attestation nonce to random value
    [1684152654.750685][105627:105629] CHIP:CTL: Setting CSR nonce to random value
    [1684152654.751425][105627:105629] CHIP:CTL: Generating NOC
    [1684152654.751627][105627:105629] CHIP:FP: Validating NOC chain
    [1684152654.751962][105627:105629] CHIP:FP: NOC chain validation successful
    [1684152654.751996][105627:105629] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
    [1684152654.752000][105627:105629] CHIP:TS: Last Known Good Time: 2023-05-15T15:02:24
    [1684152654.752002][105627:105629] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
    [1684152654.752004][105627:105629] CHIP:TS: Retaining current Last Known Good Time
    [1684152654.752261][105627:105629] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
    [1684152654.752476][105627:105629] CHIP:TS: Committing Last Known Good Time to storage: 2023-05-15T15:02:24
    [1684152654.752673][105627:105629] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 2CA210E66CF540C3)
    [1684152654.752679][105627:105629] CHIP:IN: UDP::Init bind&listen port=5550
    [1684152654.752689][105627:105629] CHIP:IN: UDP::Init bound to port=5550
    [1684152654.752691][105627:105629] CHIP:IN: UDP::Init bind&listen port=5550
    [1684152654.752698][105627:105629] CHIP:IN: UDP::Init bound to port=5550
    [1684152654.752700][105627:105629] CHIP:IN: TransportMgr initialized
    [1684152654.754690][105627:105629] CHIP:CTL: Setting wifi credentials from parameters
    [1684152654.754696][105627:105629] CHIP:CTL: Setting attestation nonce to random value
    [1684152654.754703][105627:105629] CHIP:CTL: Setting CSR nonce to random value
    [1684152654.754707][105627:105629] CHIP:CTL: Commission called for node ID 0x0000000000000001
    [1684152654.755610][105627:105628] CHIP:DL: TRACE: Bus acquired for name C-9c9b
    [1684152654.757324][105627:105629] CHIP:DL: PlatformBlueZInit init success
    [1684152654.758434][105627:105628] CHIP:BLE: BLE removing known devices.
    [1684152654.758716][105627:105628] CHIP:BLE: BLE initiating scan.
    [1684152654.876034][105627:105629] CHIP:DL: Long dispatch time: 121 ms, for event type 2
    [1684152654.887517][105627:105628] CHIP:BLE: Device E7:70:80:C3:AD:91 does not look like a CHIP device.
    [1684152654.888296][105627:105628] CHIP:BLE: Device 26:56:4A:D8:6E:9E does not look like a CHIP device.
    [1684152654.892176][105627:105628] CHIP:BLE: Device 06:8B:B2:DA:12:10 does not look like a CHIP device.
    [1684152654.904661][105627:105628] CHIP:BLE: Device 38:F5:CD:61:4A:37 does not look like a CHIP device.
    [1684152654.910672][105627:105628] CHIP:BLE: Device 19:88:3A:31:D6:1F does not look like a CHIP device.
    [1684152654.912033][105627:105628] CHIP:BLE: Device 29:88:96:2A:D7:32 does not look like a CHIP device.
    [1684152654.919299][105627:105628] CHIP:BLE: Device 05:E6:6C:A7:20:DA does not look like a CHIP device.
    [1684152654.929630][105627:105628] CHIP:BLE: New device scanned: D3:91:4F:49:9B:36
    [1684152654.929654][105627:105628] CHIP:BLE: Device discriminator match. Attempting to connect.
    [1684152655.448250][105627:105628] CHIP:DL: ConnectDevice complete
    [1684152664.877072][105627:105629] CHIP:DIS: Closing all BLE connections
    [1684152664.877114][105627:105629] CHIP:TOO: Pairing Failure: src/platform/Linux/bluez/ChipDeviceScanner.cpp:178: CHIP Error 0x00000032: Timeout
    [1684152664.877132][105627:105629] CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:178: CHIP Error 0x00000032: Timeout
    [1684152664.877399][105627:105627] CHIP:CTL: Shutting down the commissioner
    [1684152664.877420][105627:105627] CHIP:CTL: Stopping commissioning discovery over DNS-SD
    [1684152664.877465][105627:105627] CHIP:CTL: Shutting down the controller
    [1684152664.877479][105627:105627] CHIP:IN: Expiring all sessions for fabric 0x1!!
    [1684152664.877488][105627:105627] CHIP:FP: Forgetting fabric 0x1
    [1684152664.877506][105627:105627] CHIP:TS: Pending Last Known Good Time: 2023-05-15T15:02:24
    [1684152664.877621][105627:105627] CHIP:TS: Previous Last Known Good Time: 2023-05-15T15:02:24
    [1684152664.877632][105627:105627] CHIP:TS: Reverted Last Known Good Time to previous value
    [1684152664.877657][105627:105627] CHIP:CTL: Shutting down the commissioner
    [1684152664.877665][105627:105627] CHIP:CTL: Stopping commissioning discovery over DNS-SD
    [1684152664.877698][105627:105627] CHIP:CTL: Shutting down the controller
    [1684152664.877708][105627:105627] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
    [1684152664.877775][105627:105627] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
    [1684152664.877805][105627:105627] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
    [1684152664.877822][105627:105627] CHIP:FP: Shutting down FabricTable
    [1684152664.877835][105627:105627] CHIP:TS: Pending Last Known Good Time: 2023-05-15T15:02:24
    [1684152664.877902][105627:105627] CHIP:TS: Previous Last Known Good Time: 2023-05-15T15:02:24
    [1684152664.877911][105627:105627] CHIP:TS: Reverted Last Known Good Time to previous value
    [1684152664.878051][105627:105627] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-1rytof)
    [1684152664.878304][105627:105627] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
    [1684152664.878334][105627:105627] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
    [1684152664.878349][105627:105627] CHIP:DL: Inet Layer shutdown
    [1684152664.878359][105627:105627] CHIP:DL: BLE shutdown
    [1684152664.878768][105627:105627] CHIP:DL: System Layer shutdown
    [1684152664.878938][105627:105627] CHIP:TOO: Run command failure: src/platform/Linux/bluez/ChipDeviceScanner.cpp:178: CHIP Error 0x00000032: Timeout

  • hello,

    sorry for late reply,

    actually we have switch to BLE-thread so we are not longer work on BLE-wifi,in BLE-thread i got an error when make OTBR.

    this error i got when i try to upload hex code in nrf52840 dongle and i am using 3.0.8 version and i have akso try this on latest version.

  • Hi Gautam, 
    Could you tell me which exact firmware you are flashing ot the nRF52840 dongle ? 
    As far as I know it's normal that after DFU update the programmer can not communicate with the dongle (until you put the dongle into DFU mode again). 

  • 7652.ot-rcp.hex

    actually i am flashing this code which give me an error.

  • Hi Gautam, 
    I'm not so sure the firmware is made for the dongle. It's the nRF52840 Dev Kit you should flash it on , not the dongle. 
    On the dongle there is a bootloader and that require the application location to be adjusted. (Unless you have soldered the SWD port to erase the bootloader and flash directly)
    Could you please try testing on a Dev Kit instead ? 

Reply Children
Related