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.
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.
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,
this is the pcapng file,
and when i try to run BLE-WIFI command then 1-2 times i get invalid argument and then i get time-out error.
if in case this file don't work:
Hi Gautam,
I'm sorry for the late response. It's holiday in Norway last week.
Your new trace still doesn't capture the communication between the two devices.
My suggestion is to follow our course on capturing sniffer trace here: https://academy.nordicsemi.com/lessons/lesson-6-bluetooth-le-sniffer/
What you need to look for when capturing the trace is to see the connection established and the communication before it's terminated.
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).
actually i am flashing this code which give me an error.
actually i am flashing this code which give me an error.
this file i generate from this link https://openthread.io/codelabs/openthread-hardware#3
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 ?
yes i tried and i make OTBR sucessesfully but once again i get that timeout error which i get in BLE-WIFI, so don't know that what is an issue.
Hi Gautam,
Could you please try follow the sniffer course and try capture the sniffer trace ? We need to see how the disconnect happen. To see if it's a BLE issue or it's related to Matter.
Hello,
Sorry for late reply,
I have try recently and this time i don't get any error, but i want to check the connection is there any way to check that my matter device is properly connected to OTBR.
