Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Failed to Provision device in rainmaker for matter controller (MEGH-6053) #337

Closed
3 tasks done
aadhimellow opened this issue Oct 15, 2024 · 4 comments
Closed
3 tasks done

Comments

@aadhimellow
Copy link

Answers checklist.

  • I have read the Rainmaker documentation and the issue is not addressed there.
  • I have updated my IDF branch (release/vX.Y) to the latest version and checked that the issue is present there. This is not applicable if you are using Rainmaker with Arduino.
  • I have searched the Rainmaker forum and issue tracker for a similar issue and not found a similar issue.

IDF / ESP32-Arduino version.

ESP-IDF v5.3.1

Operating System used.

Linux

How did you build your project?

Command line with idf.py

Development Kit.

ESP Wi-Fi based Thread Border Router

What is the expected behavior?

Tried to create a rainmaker matter controller with OTBR feature on Espressif thread border router which should show the qr code and details for provisioning with rainmaker account and start thread network after that.

What is the actual behavior?

After executing the command it shows an error failed to get device certificate. The qr code or provisioning details are not showing up which should be scanned on the rainmaker app.

Steps to reproduce.

  1. Cloned the repository git clone --recursive https://github.com/espressif/esp-rainmaker.git
  2. Installed the prerequisites given in https://github.com/espressif/esp-rainmaker/tree/master/examples/matter
  3. Created the environments
  4. Followed the steps for claiming the certification
  5. Generated the factory nvs binary
  6. flashed it using esptool.py
  7. Opened the example /examples/matter/matter_controller
  8. Executed the steps mentioned and ran flash monitor
  9. Got error failed to fetch device certificate along with other errors
    Screenshot 2024-10-15 at 6 46 35 PM

Debug Logs.

I (26) boot: ESP-IDF v5.3.1 2nd stage bootloader
I (27) boot: compile time Oct 15 2024 16:59:34
I (27) boot: Multicore bootloader
I (27) boot: chip revision: v0.2
I (27) boot.esp32s3: Boot SPI Speed : 80MHz
I (27) boot.esp32s3: SPI Mode       : DIO
I (28) boot.esp32s3: SPI Flash Size : 4MB
I (28) boot: Enabling RNG early entropy source...
I (28) boot: Partition Table:
I (28) boot: ## Label            Usage          Type ST Offset   Length
I (29) boot:  0 esp_secure_cert  unknown          3f 06 0000d000 00002000
I (29) boot:  1 nvs              WiFi data        01 02 00010000 0000c000
I (30) boot:  2 otadata          OTA data         01 00 0001c000 00002000
I (30) boot:  3 phy_init         RF data          01 01 0001e000 00001000
I (30) boot:  4 ota_0            OTA app          00 10 00020000 002ee000
I (31) boot:  5 fctry            WiFi data        01 02 00320000 00006000
I (31) boot: End of partition table
I (31) esp_image: segment 0: paddr=00020020 vaddr=3c1f0020 size=86264h (549476) map
I (130) esp_image: segment 1: paddr=000a628c vaddr=3fc9e700 size=05b78h ( 23416) load
I (136) esp_image: segment 2: paddr=000abe0c vaddr=40374000 size=0420ch ( 16908) load
I (140) esp_image: segment 3: paddr=000b0020 vaddr=42000020 size=1e8b48h (2001736) map
I (499) esp_image: segment 4: paddr=00298b70 vaddr=4037820c size=164a0h ( 91296) load
I (519) esp_image: segment 5: paddr=002af018 vaddr=600fe100 size=00004h (     4) load
I (531) boot: Loaded app from partition at offset 0x20000
I (531) boot: Disabling RNG early entropy source...
I (532) esp_psram: Found 2MB PSRAM device
I (532) esp_psram: Speed: 80MHz
I (532) cpu_start: Multicore app
I (762) esp_psram: SPI SRAM memory test OK
I (778) cpu_start: Pro cpu start user code
I (778) cpu_start: cpu freq: 160000000 Hz
I (778) app_init: Application information:
I (778) app_init: Project name:     matter_controller
I (778) app_init: App version:      86f0c19-dirty
I (779) app_init: Compile time:     Oct 15 2024 18:24:40
I (779) app_init: ELF file SHA256:  ccb67864d...
I (779) app_init: ESP-IDF:          v5.3.1
I (779) efuse_init: Min chip rev:     v0.0
I (779) efuse_init: Max chip rev:     v0.99 
I (780) efuse_init: Chip rev:         v0.2
I (780) heap_init: Initializing. RAM available for dynamic allocation:
I (780) heap_init: At 3FCA6EB0 len 00042860 (266 KiB): RAM
I (780) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (781) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (781) heap_init: At 600FE104 len 00001EE4 (7 KiB): RTCRAM
I (782) esp_psram: Adding pool of 1936K of PSRAM memory to heap allocator
I (783) spi_flash: detected chip: gd
I (783) spi_flash: flash io: dio
W (783) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (787) sleep: Configure to isolate all GPIO pins in sleep state
I (787) sleep: Enable automatic switching of GPIO sleep configuration
I (788) coexist: coex firmware version: 4482466
I (788) coexist: coexist rom version e7ae62f
I (789) main_task: Started on CPU0
I (799) esp_psram: Reserving pool of 8K of internal memory for DMA/internal allocations
I (799) main_task: Calling app_main()
I (839) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (859) pp: pp rom version: e7ae62f
I (859) net80211: net80211 rom version: e7ae62f
I (869) wifi:wifi driver task: 3fcb617c, prio:23, stack:6656, core=0
I (889) wifi:wifi firmware version: ccaebfa
I (889) wifi:wifi certification version: v7.0
I (889) wifi:config NVS flash: enabled
I (889) wifi:config nano formating: disabled
I (889) wifi:Init data frame dynamic rx buffer num: 32
I (889) wifi:Init static rx mgmt buffer num: 5
I (889) wifi:Init management short buffer num: 32
I (889) wifi:Init static tx buffer num: 16
I (889) wifi:Init tx cache buffer num: 32
I (889) wifi:Init static tx FG buffer num: 2
I (889) wifi:Init static rx buffer size: 1600
I (889) wifi:Init static rx buffer num: 16
I (889) wifi:Init dynamic rx buffer num: 32
I (889) wifi_init: rx ba win: 16
I (889) wifi_init: accept mbox: 6
I (889) wifi_init: tcpip mbox: 32
I (889) wifi_init: udp mbox: 6
I (889) wifi_init: tcp mbox: 6
I (889) wifi_init: tcp tx win: 5760
I (889) wifi_init: tcp rx win: 5760
I (889) wifi_init: tcp mss: 1440
I (889) wifi_init: WiFi/LWIP prefer SPIRAM
I (889) wifi_init: WiFi IRAM OP enabled
I (889) wifi_init: WiFi RX IRAM OP enabled
I (919) chip[DL]: NVS set: chip-counters/reboot-count = 8 (0x8)
I (919) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC)
I (929) BLE_INIT: BT controller compile version [aa16a46]
I (929) BLE_INIT: Bluetooth MAC: e8:06:90:d3:fb:86
I (929) phy_init: phy_version 680,a6008b2,Jun  4 2024,16:41:10
I (979) NimBLE: GAP procedure initiated: stop advertising.

I (979) NimBLE: Failed to restore IRKs from store; status=8

I (979) CHIP[DL]: BLE host-controller synced
I (1479) chip[DL]: Starting ESP WiFi layer
I (1479) wifi:mode : sta (e8:06:90:d3:fb:84)
I (1479) wifi:enable tsf
W (1479) wifi:Haven't to connect to a suitable AP now!
I (1479) chip[DL]: Done driving station state, nothing else to do...
W (1479) wifi:Haven't to connect to a suitable AP now!
I (1479) chip[DL]: I (1479) chip[DL]: Done driving station state, nothing else to do...Posting ESPSystemEvent: Wifi Event with eventId : 43

I (1479) chip[SVR]: Initializing subscription resumption storage...
I (1479) chip[DL]: Posting ESPSystemEvent: Wifi Event with eventId : 2
I (1479) chip[SVR]: Server initializing...
I (1489) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48
I (1489) chip[DMG]: AccessControl: initializing
I (1489) chip[DMG]: Examples::AccessControlDelegate::Init
I (1489) chip[DMG]: AccessControl: setting
I (1489) chip[DMG]: DefaultAclStorage: initializing
I (1489) chip[DMG]: DefaultAclStorage: 0 entries loaded
I (1489) chip[SVR]: WARNING: mTestEventTriggerDelegate is null
I (1529) chip[ZCL]: Using ZAP configuration...
I (1529) esp_matter_cluster: Cluster plugin init common callback
I (1539) chip[DMG]: AccessControlCluster: initializing
I (1539) chip[ZCL]: 0x3c1f7f66 ep 0 clus 0x0000_0030 attr 0x0000_0000 not supported
I (1539) chip[ZCL]: Initiating Admin Commissioning cluster.
I (1539) chip[DIS]: Updating services using commissioning mode 0
E (1539) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments
E (1539) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments
E (1539) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments
E (1539) chip[DIS]: Setup discriminator read error (201)! Critical error, will not be commissionable.
E (1539) chip[DIS]: Failed to advertise extended commissionable node: 201
E (1539) chip[SVR]: ERROR setting up transport: 201
I (1539) esp_matter_core: Dynamic endpoint 0 added
I (1539) esp_matter_core: Dynamic endpoint 1 added
I (1549) chip[DL]: WIFI_EVENT_STA_START
W (1549) wifi:Haven't to connect to a suitable AP now!
I (1549) chip[DL]: Done driving station state, nothing else to do...
I (1549) chip[DIS]: Updating services using commissioning mode 0
E (1549) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments
E (1549) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments
E (1549) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments
E (1549) chip[DIS]: Setup discriminator read error (201)! Critical error, will not be commissionable.
E (1549) chip[DIS]: Failed to advertise extended commissionable node: 201
E (1549) esp_rmaker_core: Failed to get device certificate.
I (1549) esp_rmaker_work_queue: Work Queue created.
I (1559) esp_claim: Initialising Assisted Claiming. This may take time.
I (1569) esp_claim: Private key already exists. No need to re-initialise it.
I (1579) esp_rmaker_node: Node ID ----- E80690D3FB84
I (1579) esp_rmaker_ota_using_topics: OTA enabled with Topics
I (1579) esp_rmaker_ota: OTA state = 2
I (1579) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
I (1579) esp_rmaker_time_service: Time service enabled
I (1579) esp_rmaker_time: SNTP already initialized.
I (1579) app_insights: Enable CONFIG_ESP_INSIGHTS_ENABLED to get Insights.
I (1579) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x131BFC00's Attribute 0x00000001 is E80690D3FB84 **********
I (1579) app_matter: RainMaker init not done. Not processing attribute update
I (1589) esp_rmaker_core: Starting RainMaker Work Queue task
I (1589) esp_rmaker_work_queue: RainMaker Work Queue task started.
W (1589) wifi:Haven't to connect to a suitable AP now!
I (1589) esp_claim: Waiting for assisted claim to finish.
I (1629) main_task: Returned from app_main()
>

More Information.

While building the example a warning was shown but didn't cause any failure
[1710/1714] Generating ld/sections.ld warning: default on the choice symbol SEC_CERT_DAC_PROVIDER (defined at /Users/a1248986/matterProject/esp-matter/connectedhomeip/connectedhomeip/config/esp32/components/chip/Kconfig:966, /Users/a1248986/matterProject/esp-matter/components/esp_matter/Kconfig:48) will have no effect, as defaults do not affect choice symbols warning: the choice symbol SEC_CERT_DAC_PROVIDER (defined at /Users/a1248986/matterProject/esp-matter/connectedhomeip/connectedhomeip/config/esp32/components/chip/Kconfig:966, /Users/a1248986/matterProject/esp-matter/components/esp_matter/Kconfig:48) is defined with a prompt outside the choice [1712/1714] Generating binary image from built executable

@aadhimellow aadhimellow changed the title Failed to Provision device in rainmaker Failed to Provision device in rainmaker for matter controller Oct 15, 2024
@github-actions github-actions bot changed the title Failed to Provision device in rainmaker for matter controller Failed to Provision device in rainmaker for matter controller (MEGH-6053) Oct 15, 2024
@shahpiyushv
Copy link
Collaborator

All Matter examples need to follow the instructions here to get the RainMaker MQTT Credentials/Matter DAC and other matter specific configuration. Have you done all of that?

One misleading instruction I see for TBR here is that it also asks to erase flash, which will also clear the certificates. Instead, the instruction should have been just idf.py -p <PORT> flash monitor.

@aadhimellow
Copy link
Author

aadhimellow commented Oct 15, 2024

I have followed the instructions given in the link.
I have tried without giving erase-flash just like you suggested but result in an error
For secure cert manager i have followed the step 2 of the link here

E (1453) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments E (1453) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments E (1453) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments E (1453) chip[DIS]: Setup discriminator read error (201)! Critical error, will not be commissionable. E (1453) chip[DIS]: Failed to advertise extended commissionable node: 201 E (1453) chip[SVR]: ERROR setting up transport: 201 I (1453) esp_matter_core: Dynamic endpoint 0 added I (1453) esp_matter_core: Dynamic endpoint 1 added I (1453) chip[DL]: WIFI_EVENT_STA_START W (1453) wifi:Haven't to connect to a suitable AP now! I (1453) chip[DL]: Done driving station state, nothing else to do... I (1463) chip[DIS]: Updating services using commissioning mode 0 E (1463) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments E (1463) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments E (1463) mdns: mdns_service_remove_for_host(6377): Invalid state or arguments E (1463) chip[DIS]: Setup discriminator read error (201)! Critical error, will not be commissionable. E (1463) chip[DIS]: Failed to advertise extended commissionable node: 201 E (1463) esp_rmaker_core: Failed to initialise Node Id. Please perform "claiming" using RainMaker CLI. E (1463) app_main: Could not initialise node.

@sayondeep
Copy link
Contributor

@aadhimellow please try by flashing the the generated factory partition at 0x320000 and reclaiming.

I would suggest to erase-flash then, flash the firmware , then flash the factory partition and then claim. This is to avoid problems that can occur if you flashed the factory partition at incorrect address earlier.

@aadhimellow
Copy link
Author

@sayondeep I tried this approach and was able to create the controller successfully. Thank you for the support.
I were able to add two matter devices to the rainmaker app.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants