espressif / esp-matter

Espressif's SDK for Matter
Apache License 2.0
647 stars 150 forks source link

unable to pair the device matter with "esp matter controller" (CON-1310) #1059

Open JoseAntonioMG opened 3 weeks ago

JoseAntonioMG commented 3 weeks ago

Describe the bug I have a matter esp32c6 device with the compiled firmware of light_switch example. I have commissioned this firmware with chip-tool on linux and it works perfectly. Then I have uncommissioned it from chip-tool. I have compiled the "esp matter controller" example using the border router options and the "ESP Thread Border Router Board" hardware. I followed the instructions for the OTBR:

->matter esp ot_cli dataset init new ->matter esp ot_cli dataset commit active I get the TLV: ->matter esp ot_cli dataset active -x I start the border router: ->matter esp ot_cli ifconfig up ->matter esp ot_cli thread start

To provision the device I entered the command: ->matter esp controller pairing ble-thread 1234 20202021 3840

where I put the TLV obtained previously. Environment

Logs for Esp32C6:

I (1498) chip[DL]: CHIPoBLE advertising started
I (1508) app_main: Commissioning window opened
Writing to serial is timing out. Please make sure that your application supports an interactive console and that you have picked the correct console for serial communication.
I (1998) main_task: Returned from app_main()
I (31378) chip[DL]: bleAdv Timeout : Start slow advertisement
I (31378) chip[DL]: Configuring CHIPoBLE advertising (interval 500 ms, connectable)
I (31388) chip[DL]: Device already advertising, stop active advertisement and restart
I (31388) NimBLE: GAP procedure initiated: stop advertising.

I (31398) NimBLE: GAP procedure initiated: advertise; 
I (31398) NimBLE: disc_mode=2
I (31408) NimBLE:  adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=800 adv_itvl_max=800
I (31418) NimBLE: 

I (104218) chip[DL]: BLE GAP connection established (con 1)
I (104218) chip[DL]: CHIPoBLE advertising stopped
I (105388) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 16
I (105388) chip[BLE]: local and remote recv window sizes = 5
I (105398) chip[BLE]: selected BTP version 4
I (105398) chip[BLE]: using BTP fragment sizes rx 244 / tx 244.
I (105438) chip[DL]: BLE GAP connection terminated (con 1 reason 0x213)
E (105438) chip[IN]: Failed to establish BLE connection: 40b
I (105448) chip[BLE]: Releasing end point's BLE connection back to application.
I (105448) chip[DL]: Closing BLE GATT connection (con 1)
E (105458) chip[DL]: ble_gap_terminate() failed: Error CHIP:0x00000048
I (105458) esp_matter_core: BLE Disconnected

Logs for "ESP Thread Border Router Board":

matter esp controller pairing ble-thread 432 0e080000000000010000000300000d35060004001fffe0020808c9b5459bc9e06b0708fd92e031c59e6b590510f31e5a7f35f571f91debbc3bd1993fc3030f4f70656e5468726561642d30326665010202fe041012923ef26dd2476747b9dfa4c1cf0e910c0402a0f7f8 20202021 3840

I (73155) chip[CTL]: Setting thread operational dataset from parameters[0m
I (73155) chip[CTL]: Setting attestation nonce to random value
I (73155) chip[CTL]: Setting CSR nonce to random value
I (73155) chip[CTL]: Commission called for node ID 0x00000000000001B0
Done
I (73155) NimBLE: GAP procedure initiated: discovery; 
I (73155) NimBLE: own_addr_type=1 filter_policy=0 passive=1 limited=0 filter_duplicates=1 
I (73155) NimBLE: duration=60000ms
I (73155) NimBLE: 

I (73315) chip[BLE]: Device Discriminator match. Attempting to connect
I (73325) chip[BLE]: Scan complete notification without an active scan
I (73325) NimBLE: GAP procedure initiated: connect; 
I (73325) NimBLE: peer_addr_type=1 peer_addr=
I (73325) NimBLE: dc:e2:df:26:b3:7b
I (73325) NimBLE:  scan_itvl=16 scan_window=16 itvl_min=24 itvl_max=40 latency=0 supervision_timeout=256 min_ce_len=0 max_ce_len=0 own_addr_type=1
I (73325) NimBLE: 

I (73825) NimBLE: GATT procedure initiated: exchange mtu

I (73825) chip[DL]: BLE GAP connection established (con 1)
I (73825) NimBLE: GATT procedure initiated: discover all services

I (73885) NimBLE: GATT procedure initiated: discover all characteristics; 
I (73885) NimBLE: start_handle=1 end_handle=5

I (74085) NimBLE: GATT procedure initiated: discover all characteristics; 
I (74085) NimBLE: start_handle=6 end_handle=13

I (74285) NimBLE: GATT procedure initiated: discover all characteristics; 
I (74285) NimBLE: start_handle=14 end_handle=65535

I (74485) NimBLE: GATT procedure initiated: discover all descriptors; 
I (74485) NimBLE: chr_val_handle=8 end_handle=9

I (74585) NimBLE: GATT procedure initiated: discover all descriptors; 
I (74585) NimBLE: chr_val_handle=18 end_handle=65535

I (74935) chip[BLE]: GATT discovery complete status:0 conn_handle:1
I (74935) chip[DL]: HandlePlatformSpecificBLEEvent 16385
I (74945) chip[DIS]: Closing all BLE connections
I (74945) NimBLE: GATT procedure initiated: write; 
I (74945) NimBLE: att_handle=16 len=9

E (74945) chip[CSL]: PacketBuffer: pool EMPTY.
I (74945) chip[DIS]: Closing all BLE connections
I (74945) chip[BLE]: Auto-closing end point's BLE connection.
I (74945) chip[DL]: Closing BLE GATT connection (con 1)
I (74945) NimBLE: GAP procedure initiated: terminate connection; conn_handle=1 hci_reason=19

E (74945) chip[-]: Error CHIP:0x0000000B at src/controller/CHIPDeviceController.cpp:771
I (74985) chip[DL]: I (74985) chip[DL]: BLE GAP connection terminated (con 1 reason 0x216)HandlePlatformSpecificBLEEvent 16387

E (74985) chip[BLE]: no endpoint for BLE sent data ack
wqx6 commented 3 weeks ago

The log from the Border Router border shows that the ESP32-S3 uses up the memory. Do you disable the SRAM of ESP32-S3? you can run this command matter esp diagnostics mem-dump to see the memory usage.

JoseAntonioMG commented 3 weeks ago

matter esp diagnostics mem-dump

Description Internal SPIRAM Current Free Memory 23760 0 Largest Free Block 7680 0 Min. Ever Free Size 14724 0 Done

JoseAntonioMG commented 3 weeks ago

Esp32s3 device has 16Mb SRAM

JoseAntonioMG commented 3 weeks ago

Logs for Esp32S3 at boot:

I (26) boot: ESP-IDF v5.2.2-dirty 2nd stage bootloader
I (27) boot: compile time Aug 20 2024 14:15:09
I (27) boot: Multicore bootloader
I (30) boot: chip revision: v0.1
I (34) boot.esp32s3: Boot SPI Speed : 80MHz
I (39) boot.esp32s3: SPI Mode       : DIO
I (44) boot.esp32s3: SPI Flash Size : 16MB
I (48) boot: Enabling RNG early entropy source...
I (54) boot: Partition Table:
I (57) boot: ## Label            Usage          Type ST Offset   Length
I (65) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (72) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (80) boot:  2 factory          factory app      00 00 00010000 002ee000
I (87) boot: End of partition table
I (91) esp_image: segment 0: paddr=00010020 vaddr=3c1b0020 size=57108h (356616) map
I (164) esp_image: segment 1: paddr=00067130 vaddr=3fc9c100 size=05264h ( 21092) load
I (168) esp_image: segment 2: paddr=0006c39c vaddr=40374000 size=03c7ch ( 15484) load
I (173) esp_image: segment 3: paddr=00070020 vaddr=42000020 size=1a1d6ch (1711468) map
I (485) esp_image: segment 4: paddr=00211d94 vaddr=40377c7c size=14468h ( 83048) load
I (513) boot: Loaded app from partition at offset 0x10000
I (514) boot: Disabling RNG early entropy source...
I (515) cpu_start: Multicore app
I (527) cpu_start: Pro cpu start user code
I (528) cpu_start: cpu freq: 160000000 Hz
I (528) cpu_start: Application information:
I (528) cpu_start: Project name:     controller
I (528) cpu_start: App version:      d57af86-dirty
I (528) cpu_start: Compile time:     Aug 20 2024 14:15:03
I (529) cpu_start: ELF file SHA256:  e23498a34...
I (529) cpu_start: ESP-IDF:          v5.2.2-dirty
I (529) cpu_start: Min chip rev:     v0.0
I (529) cpu_start: Max chip rev:     v0.99 
I (529) cpu_start: Chip rev:         v0.1
I (529) heap_init: Initializing. RAM available for dynamic allocation:
I (530) heap_init: At 3FCC1040 len 000286D0 (161 KiB): RAM
I (530) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (530) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (530) heap_init: At 600FE010 len 00001FD8 (7 KiB): RTCRAM
I (532) spi_flash: detected chip: gd
I (532) spi_flash: flash io: dio
I (533) sleep: Configure to isolate all GPIO pins in sleep state
I (533) sleep: Enable automatic switching of GPIO sleep configuration
I (534) coexist: coex firmware version: d96c1e51f
I (534) coexist: coexist rom version e7ae62f
I (535) main_task: Started on CPU0
I (545) main_task: Calling app_main()
I (635) pp: pp rom version: e7ae62f
I (635) net80211: net80211 rom version: e7ae62f
wqx6 commented 2 weeks ago

matter esp diagnostics mem-dump

Description Internal SPIRAM Current Free Memory 23760 0 Largest Free Block 7680 0 Min. Ever Free Size 14724 0 Done

Looks like there SPIRAM is not enabled in your device so that there will be error of no-memory.

wqx6 commented 2 weeks ago

Esp32s3 device has 16Mb SRAM

But from you log I didn't see the 16MB SRAM only 16MB flash.

JoseAntonioMG commented 2 weeks ago

correct, it's 16MB flash memory. The esp32s3, as I understand it, has 512KB SRAM, isn't that enough for this type of applications?

JoseAntonioMG commented 2 weeks ago

How can I expand the SRAM without having to buy a new esp32s3 device?

wqx6 commented 2 weeks ago

isn't that enough for this type of applications?

Yes, we would suggest that you should use PSRAM for controller+thread-br example.

How can I expand the SRAM without having to buy a new esp32s3 device?

If you are using a Thread Border Router board, I remember that there is a 2MB SRAM on ESP32-S3 of that board, and you need to follow the instruction to configure the SRAM https://docs.espressif.com/projects/esp-idf/en/latest/esp32s3/api-guides/external-ram.html#configuring-external-ram