generic_switch border router - Thread credentials (CON-1085)

[FHFS]

Hi there,

I've got the generic_switch project running on an ESP Thread Border Router board. I've added Border Router functionality, and I can use the matter cli to configure OpenThread on the esp32h2. Commissioning works thanks to @wqx6.

Now I would like to get Border Router to also get the OpenThread Credentials during commissioning. How do I achieve that?

Does anyone know why the commissioning process only provisions wifi credentials and not thread credentials?

[FHFS]

When I enable "CONFIG_ENABLE_MATTER_OVER_THREAD" commissioning fails, see log below.

When I look at esp-matter/connectedhomeip/connectedhomeip/src/app/clusters/network-commissioning/network-commissioning.cpp it looks like CHIP_DEVICE_CONFIG_ENABLE_THREAD is required for passing SupportedThreadFeatures during the commissioning process.

However setting CHIP_DEVICE_CONFIG_ENABLE_THREAD through CONFIG_ENABLE_MATTER_OVER_THREAD will cause err = esp_matter::start(app_event_cb); to try and initialize OpenThread. But for the Border Router we need to initialize OpenThread with esp_matter::thread_br_init(&config);. We cannot initialize esp_matter::thread_br_init(&config); because that will try to attach to a netif, and we do not have network access yet.

Is it just not possible yet to get the Thread credentials for the Border Router?

I (163) esp_image: segment 1: paddr=00066124 vaddr=3fc9a8I (516) main_task: Calling app_main()
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40384ac1
0x40384ac1: spimem_flash_ll_cmd_is_done at /home/fhfs/Repos/MatterESP/esp-idf/components/hal/esp32s3/include/hal/spimem_flash_ll.h:60 (discriminator 1)
 (inlined by) spi_flash_hal_poll_cmd_done at /home/fhfs/Repos/MatterESP/esp-idf/components/hal/spi_flash_hal_common.inc:38 (discriminator 1)

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3818,len:0x1758
load:0x403c9700,len:0x4
load:0x403c9704,len:0xbe4
load:0x403cc700,len:0x2d18
entry 0x403c9908
I (26) boot: ESP-IDF v5.1.2-dirty 2nd stage bootloader
I (27) boot: compile time Mar 14 2024 14:11:38
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 : 4MB
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 (79) 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=3c180020 size=560fch (352508) map
I (163) esp_image: segment 1: paddr=00066124 vaddr=3fc9a800 size=051f0h ( 20976) load
I (168) esp_image: segment 2: paddr=0006b31c vaddr=40374000 size=04cfch ( 19708) load
I (173) esp_image: segment 3: paddr=00070020 vaddr=42000020 size=171a9ch (1514140) map
I (449) esp_image: segment 4: paddr=001e1ac4 vaddr=40378cfc size=11a88h ( 72328) load
I (465) esp_image: segment 5: paddr=001f3554 vaddr=600fe010 size=00004h (     4) load
I (475) boot: Loaded app from partition at offset 0x10000
I (475) boot: Disabling RNG early entropy source...
I (476) cpu_start: Multicore app
I (480) cpu_start: Pro cpu up.
I (483) cpu_start: Starting app cpu, entry point is 0x40375644
0x40375644: call_start_cpu1 at /home/fhfs/Repos/MatterESP/esp-idf/components/esp_system/port/cpu_start.c:157

I (0) cpu_start: App cpu up.
I (499) cpu_start: Pro cpu start user code
I (499) cpu_start: cpu freq: 160000000 Hz
I (499) cpu_start: Application information:
I (499) cpu_start: Project name:     generic_switch
I (499) cpu_start: App version:      1.0
I (499) cpu_start: Compile time:     Mar 14 2024 14:11:27
I (500) cpu_start: ELF file SHA256:  03df04ec581b1b2a...
I (500) cpu_start: ESP-IDF:          v5.1.2-dirty
I (500) cpu_start: Min chip rev:     v0.0
I (500) cpu_start: Max chip rev:     v0.99 
I (501) cpu_start: Chip rev:         v0.1
I (501) heap_init: Initializing. RAM available for dynamic allocation:
I (501) heap_init: At 3FCBC378 len 0002D398 (180 KiB): DRAM
I (501) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (502) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (502) heap_init: At 600FE014 len 00001FD4 (7 KiB): RTCRAM
I (503) spi_flash: detected chip: generic
I (503) spi_flash: flash io: dio
I (505) sleep: Configure to isolate all GPIO pins in sleep state
I (506) sleep: Enable automatic switching of GPIO sleep configuration
I (506) coexist: coex firmware version: b6d5e8c
I (507) coexist: coexist rom version e7ae62f
I (507) app_start: Starting scheduler on CPU0
I (507) app_start: Starting scheduler on CPU1
I (507) main_task: Started on CPU0
I (517) main_task: Calling app_main()
I (537) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (537) app_main: Generic Switch created with endpoint_id 1
I (547) pp: pp rom version: e7ae62f
I (547) net80211: net80211 rom version: e7ae62f
I (557) wifi:wifi driver task: 3fccb010, prio:23, stack:6656, core=0
I (567) wifi:wifi firmware version: 91b9630
I (567) wifi:wifi certification version: v7.0
I (567) wifi:config NVS flash: enabled
I (567) wifi:config nano formating: disabled
I (567) wifi:Init data frame dynamic rx buffer num: 32
I (567) wifi:Init static rx mgmt buffer num: 5
I (567) wifi:Init management short buffer num: 32
I (567) wifi:Init dynamic tx buffer num: 32
I (567) wifi:Init static tx FG buffer num: 2
I (567) wifi:Init static rx buffer size: 1600
I (567) wifi:Init static rx buffer num: 10
I (567) wifi:Init dynamic rx buffer num: 32
I (567) wifi_init: rx ba win: 6
I (567) wifi_init: tcpip mbox: 32
I (567) wifi_init: udp mbox: 6
I (567) wifi_init: tcp mbox: 6
I (567) wifi_init: tcp tx win: 5744
I (567) wifi_init: tcp rx win: 5744
I (567) wifi_init: tcp mss: 1440
I (567) wifi_init: WiFi IRAM OP enabled
I (567) wifi_init: WiFi RX IRAM OP enabled
I (577) chip[DL]: NVS set: chip-counters/reboot-count = 1 (0x1)
I (577) chip[DL]: NVS set: chip-counters/total-hours = 0 (0x0)
I (577) chip[DL]: NVS set: chip-config/unique-id = "738B760B46445628"
I (587) chip[DL]: Changing ESP WiFi mode: AP -> STA
I (597) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC)
I (597) OPENTHREAD: Host connection mode none
I (597) BLE_INIT: BT controller compile version [59725b5]
I (597) BLE_INIT: Bluetooth MAC: 34:85:18:7e:7e:8e

I (597) OPENTHREAD: spinel UART interface initialization completed
I (597) phy_init: phy_version 620,ec7ec30,Sep  5 2023,13:49:13
E (597) OPENTHREAD: esp_openthread_radio_init(39): Spinel interface init falied
W (597) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
E (597) OPENTHREAD: esp_openthread_platform_init(148): esp_openthread_radio_init failed
E (597) OPENTHREAD: esp_openthread_init(69): Failed to initialize OpenThread platform driver
> I (597) OPENTHREAD: OpenThread attached to netif
E (597) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (597) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (607) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (607) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (607) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (607) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (607) chip[DL]: OpenThread started: OK
I (607) chip[DL]: Setting OpenThread device type to ROUTER
E (607) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
I(607) OPENTHREAD:[N] Mle-----------: Mode 0x00 -> 0x0e [rx-on:yes ftd:yes full-net:no]
E (607) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (607) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (607) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (607) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (637) NimBLE: GAP procedure initiated: stop advertising.

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

I (647) CHIP[DL]: BLE host-controller synced
I (1147) chip[DL]: Starting ESP WiFi layer
I (1147) wifi:mode : sta (34:85:18:7e:7e:8c)
I (1147) wifi:enable tsf
W (1147) wifi:Haven't to connect to a suitable AP now!
I (1147) chip[DL]: Done driving station state, nothing else to do...
W (1147) wifi:Haven't to connect to a suitable AP now!
I (1147) chip[DL]: Done driving station state, nothing else to do...
I (1147) chip[SVR]: Initializing subscription resumption storage...
I (1147) chip[SVR]: Server initializing...
I (1147) chip[TS]: Last Known Good Time: [unknown]
I (1147) chip[TS]: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48
I (1157) chip[DMG]: AccessControl: initializing
I (1157) chip[DMG]: Examples::AccessControlDelegate::Init
I (1157) chip[DMG]: AccessControl: setting
I (1157) chip[DMG]: DefaultAclStorage: initializing
I (1157) chip[DMG]: DefaultAclStorage: 0 entries loaded
E (1157) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (1157) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (1167) chip[ZCL]: Using ZAP configuration...
I (1167) esp_matter_cluster: Cluster plugin init common callback
I (1167) chip[DMG]: AccessControlCluster: initializing
I (1167) chip[ZCL]: 0x3c1895dd ep 0 clus 0x0000_0030 attr 0x0000_0000 not supported
I (1167) chip[ZCL]: Initiating Admin Commissioning cluster.
I (1167) chip[DIS]: Updating services using commissioning mode 1
E (1167) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (1167) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (1167) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (1167) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0
E (1177) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (1177) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (1177) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (1177) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (1177) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (1177) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (1177) chip[IN]: CASE Server enabling CASE session setups
I (1177) chip[SVR]: Joining Multicast groups
I (1177) chip[SVR]: Server initialization complete
I (1177) chip[SVR]: Server Listening...
E (1177) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (1177) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (1177) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (1177) esp_matter_core: Dynamic endpoint 0 added
I (1177) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000003's Attribute 0x00000001 is 0 **********
I (1177) esp_matter_core: Dynamic endpoint 1 added
E (1177) chip[IM]: Duplicate command handler registration failed
I (1187) chip[DL]: WIFI_EVENT_STA_START
W (1187) wifi:Haven't to connect to a suitable AP now!
I (1187) chip[DL]: Done driving station state, nothing else to do...
I (1187) chip[DIS]: Updating services using commissioning mode 1
E (1187) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (1187) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (1187) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (1187) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0
I (1187) esp_matter_core: Cannot find minimum unused endpoint_id, try to find in the previous namespace
I (1187) esp_matter_core: Failed to open node namespace
E (1197) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (1197) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (1197) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (1197) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (1197) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (1197) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (1197) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)
I (1197) NimBLE: GAP procedure initiated: advertise; 
I (1197) NimBLE: disc_mode=2
I (1197) NimBLE:  adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40
I (1197) NimBLE: 

I (1197) chip[DL]: CHIPoBLE advertising started
I (1197) app_main: Commissioning window opened
I (1197) chip[IM]: No subscriptions to resume
I (1207) chip[SVR]: SetupQRCode: [MT:Y.K90GSY00KA0648G00]
I (1207) chip[SVR]: Copy/paste the below URL in a browser to see the QR Code:
I (1207) chip[SVR]: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3AY.K90GSY00KA0648G00
I (1207) chip[SVR]: Manual pairing code: [34970112332]
I (1207) KibbaAzure: KibbaAzureTask
I (1207) KibbaAzure: Waiting for IP(s)
I (1307) main_task: Returned from app_main()
> E (10617) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (10617) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (10617) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (10617) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (20627) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (20627) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (20627) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (20627) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (30637) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (30637) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (30637) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (30637) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (31167) chip[DL]: Configuring CHIPoBLE advertising (interval 500 ms, connectable)
I (31167) chip[DL]: Device already advertising, stop active advertisement and restart
I (31167) NimBLE: GAP procedure initiated: stop advertising.

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

E (40647) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (40647) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (40647) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (40647) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (50657) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (50657) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (50657) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (50657) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (60667) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (60667) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (60667) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (60667) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (70677) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (70677) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (70677) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (70677) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (80687) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (80687) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (80687) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (80687) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (90237) chip[DL]: BLE GAP connection established (con 1)
I (90237) chip[DL]: CHIPoBLE advertising stopped
E (90697) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (90697) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (90697) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (90697) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (91017) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (91017) chip[BLE]: local and remote recv window sizes = 5
I (91017) chip[BLE]: selected BTP version 4
I (91017) chip[BLE]: using BTP fragment sizes rx 128 / tx 128.
I (91027) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 1
I (91027) chip[DL]: CHIPoBLE subscribe received
I (91027) NimBLE: GATT procedure initiated: indicate; 
I (91027) NimBLE: att_handle=14

I (91047) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (91047) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (91047) chip[EM]: >>> [E:11117r S:0 M:34058536] (U) Msg RX from 0:50A230D128D006D2 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
I (91047) chip[EM]: <<< [E:11117r S:0 M:68729534] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
I (91057) NimBLE: GATT procedure initiated: indicate; 
I (91057) NimBLE: att_handle=14

I (91057) chip[SVR]: Commissioning session establishment step started
I (91117) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (91117) NimBLE: GATT procedure initiated: indicate; 
I (91117) NimBLE: att_handle=14

I (91217) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (91217) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (91217) chip[EM]: >>> [E:11117r S:0 M:34058537] (U) Msg RX from 0:50A230D128D006D2 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
I (91937) chip[EM]: <<< [E:11117r S:0 M:68729535] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2)
I (91937) NimBLE: GATT procedure initiated: indicate; 
I (91937) NimBLE: att_handle=14

E (91937) chip[DL]: Long dispatch time: 720 ms, for event type 7
I (91997) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (91997) NimBLE: GATT procedure initiated: indicate; 
I (91997) NimBLE: att_handle=14

I (92097) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92097) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (92097) chip[EM]: >>> [E:11117r S:0 M:34058538] (U) Msg RX from 0:50A230D128D006D2 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
I (92097) chip[EM]: <<< [E:11117r S:0 M:68729536] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport)
I (92097) NimBLE: GATT procedure initiated: indicate; 
I (92097) NimBLE: att_handle=14

I (92107) chip[SC]: SecureSession[0x3fca2790, LSID:19180]: State change 'kEstablishing' --> 'kActive'
I (92107) chip[SVR]: Commissioning completed session establishment step
I (92107) chip[DIS]: Updating services using commissioning mode 0
E (92107) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (92107) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (92107) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (92107) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=0 cp=0
E (92117) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (92117) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (92117) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (92117) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (92117) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (92117) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (92117) chip[SVR]: Device completed Rendezvous process
I (92117) app_main: Commissioning session started
I (92117) app_main: Commissioning window closed
I (92187) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92187) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (92197) chip[EM]: >>> [E:11118r S:19180 M:29458988] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (92197) chip[EM]: <<< [E:11118r S:19180 M:50056445] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (92197) NimBLE: GATT procedure initiated: indicate; 
I (92197) NimBLE: att_handle=14

I (92287) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92287) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (92287) chip[EM]: >>> [E:11119r S:19180 M:29458989] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (92297) chip[EM]: <<< [E:11119r S:19180 M:50056446] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (92297) NimBLE: GATT procedure initiated: indicate; 
I (92297) NimBLE: att_handle=14

I (92387) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92387) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (92387) chip[EM]: >>> [E:11120r S:19180 M:29458990] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (92397) chip[EM]: <<< [E:11120r S:19180 M:50056447] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (92397) NimBLE: GATT procedure initiated: indicate; 
I (92397) NimBLE: att_handle=14

I (92487) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92487) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (92487) chip[EM]: >>> [E:11121r S:19180 M:29458991] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (92487) chip[EM]: <<< [E:11121r S:19180 M:50056448] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (92497) NimBLE: GATT procedure initiated: indicate; 
I (92497) NimBLE: att_handle=14

I (92627) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92627) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (92637) chip[EM]: >>> [E:11122r S:19180 M:29458992] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (92637) chip[EM]: <<< [E:11122r S:19180 M:50056449] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (92637) NimBLE: GATT procedure initiated: indicate; 
I (92637) NimBLE: att_handle=14

I (92727) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92727) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (92727) chip[EM]: >>> [E:11123r S:19180 M:29458993] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (92737) chip[EM]: <<< [E:11123r S:19180 M:50056450] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (92737) NimBLE: GATT procedure initiated: indicate; 
I (92737) NimBLE: att_handle=14

I (92827) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92827) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (92827) chip[EM]: >>> [E:11124r S:19180 M:29458994] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I (92827) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x0000003E
I (92827) chip[ZCL]: OpCreds: Certificate Chain request received for DAC
I (92837) chip[EM]: <<< [E:11124r S:19180 M:50056451] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (92837) NimBLE: GATT procedure initiated: indicate; 
I (92837) NimBLE: att_handle=14

I (92917) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (92927) NimBLE: GATT procedure initiated: indicate; 
I (92927) NimBLE: att_handle=14

I (93017) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (93017) NimBLE: GATT procedure initiated: indicate; 
I (93017) NimBLE: att_handle=14

I (93117) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (93117) NimBLE: GATT procedure initiated: indicate; 
I (93117) NimBLE: att_handle=14

I (93217) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (93217) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (93217) NimBLE: GATT procedure initiated: indicate; 
I (93217) NimBLE: att_handle=14

I (93307) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (93317) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (93317) chip[EM]: >>> [E:11125r S:19180 M:29458995] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (93317) chip[EM]: <<< [E:11125r S:19180 M:50056452] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (93317) NimBLE: GATT procedure initiated: indicate; 
I (93317) NimBLE: att_handle=14

I (93407) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (93407) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (93417) chip[EM]: >>> [E:11126r S:19180 M:29458996] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (93417) chip[EM]: <<< [E:11126r S:19180 M:50056453] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (93417) NimBLE: GATT procedure initiated: indicate; 
I (93417) NimBLE: att_handle=14

I (93507) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (93507) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (93507) chip[EM]: >>> [E:11127r S:19180 M:29458997] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (93517) chip[EM]: <<< [E:11127r S:19180 M:50056454] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (93517) NimBLE: GATT procedure initiated: indicate; 
I (93517) NimBLE: att_handle=14

I (93607) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (96087) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (98587) NimBLE: GATT procedure initiated: indicate; 
I (98587) NimBLE: att_handle=14

I (98677) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
E (100707) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (100707) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (100707) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (100707) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (101157) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (103497) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (103507) chip[EM]: >>> [E:11128r S:19180 M:29458998] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest)
I (103507) chip[EM]: <<< [E:11128r S:19180 M:50056455] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:01 (IM:StatusResponse)
I (103507) NimBLE: GATT procedure initiated: indicate; 
I (103507) NimBLE: att_handle=14

I (103597) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (103597) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (103597) chip[EM]: >>> [E:11128r S:19180 M:29458999] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I (103607) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x00000030
I (103607) chip[FS]: GeneralCommissioning: Received ArmFailSafe (120s)
I (103607) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **********
I (103607) chip[EM]: <<< [E:11128r S:19180 M:50056456] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (103607) NimBLE: GATT procedure initiated: indicate; 
I (103607) NimBLE: att_handle=14

I (103697) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (103697) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (103697) chip[EM]: >>> [E:11129r S:19180 M:29459000] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
I (103707) chip[EM]: <<< [E:11129r S:19180 M:50056457] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
I (103707) NimBLE: GATT procedure initiated: indicate; 
I (103707) NimBLE: att_handle=14

I (103797) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (103797) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (103797) chip[EM]: >>> [E:11130r S:19180 M:29459001] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest)
I (103797) chip[EM]: <<< [E:11130r S:19180 M:50056458] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:01 (IM:StatusResponse)
I (103797) NimBLE: GATT procedure initiated: indicate; 
I (103797) NimBLE: att_handle=14

I (103887) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (103937) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (103947) chip[EM]: >>> [E:11130r S:19180 M:29459002] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I (103947) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x00000030
I (103947) chip[DL]: NVS set: chip-config/reg-location = 0 (0x0)
I (103947) chip[DL]: NVS set: chip-config/country-code = "US"
I (103947) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **********
I (103947) chip[EM]: <<< [E:11130r S:19180 M:50056459] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (103957) NimBLE: GATT procedure initiated: indicate; 
I (103957) NimBLE: att_handle=14

I (104037) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104037) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (104037) chip[EM]: >>> [E:11131r S:19180 M:29459003] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I (104047) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x0000003E
I (104047) chip[ZCL]: OpCreds: Certificate Chain request received for PAI
I (104047) chip[EM]: <<< [E:11131r S:19180 M:50056460] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (104047) NimBLE: GATT procedure initiated: indicate; 
I (104047) NimBLE: att_handle=14

I (104137) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104137) NimBLE: GATT procedure initiated: indicate; 
I (104137) NimBLE: att_handle=14

I (104227) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104237) NimBLE: GATT procedure initiated: indicate; 
I (104237) NimBLE: att_handle=14

I (104327) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104327) NimBLE: GATT procedure initiated: indicate; 
I (104327) NimBLE: att_handle=14

I (104427) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104427) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (104427) NimBLE: GATT procedure initiated: indicate; 
I (104427) NimBLE: att_handle=14

I (104527) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104527) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (104527) chip[EM]: >>> [E:11132r S:19180 M:29459004] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I (104527) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x0000003E
I (104527) chip[ZCL]: OpCreds: Received an AttestationRequest command
I (104597) chip[ZCL]: OpCreds: AttestationRequest successful.
I (104607) chip[EM]: <<< [E:11132r S:19180 M:50056461] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (104607) NimBLE: GATT procedure initiated: indicate; 
I (104607) NimBLE: att_handle=14

I (104667) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104667) NimBLE: GATT procedure initiated: indicate; 
I (104667) NimBLE: att_handle=14

I (104767) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104767) NimBLE: GATT procedure initiated: indicate; 
I (104767) NimBLE: att_handle=14

I (104867) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104867) NimBLE: GATT procedure initiated: indicate; 
I (104867) NimBLE: att_handle=14

I (104967) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (104967) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (104967) NimBLE: GATT procedure initiated: indicate; 
I (104967) NimBLE: att_handle=14

I (105107) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (105107) NimBLE: GATT procedure initiated: indicate; 
I (105107) NimBLE: att_handle=14

I (105207) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (105207) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (105207) chip[EM]: >>> [E:11133r S:19180 M:29459005] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I (105217) esp_matter_command: Received command 0x00000004 for endpoint 0x0000's cluster 0x0000003E
I (105217) chip[ZCL]: OpCreds: Received a CSRRequest command
I (105337) chip[ZCL]: OpCreds: AllocatePendingOperationalKey succeeded
I (105407) chip[ZCL]: OpCreds: CSRRequest successful.
I (105407) chip[EM]: <<< [E:11133r S:19180 M:50056462] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (105417) NimBLE: GATT procedure initiated: indicate; 
I (105417) NimBLE: att_handle=14

I (105547) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (105547) NimBLE: GATT procedure initiated: indicate; 
I (105547) NimBLE: att_handle=14

I (105647) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (105647) NimBLE: GATT procedure initiated: indicate; 
I (105647) NimBLE: att_handle=14

I (105747) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (107987) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (108867) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (108957) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (109057) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (109057) NimBLE: GATT procedure initiated: indicate; 
I (109057) NimBLE: att_handle=14

I (109067) chip[EM]: >>> [E:11134r S:19180 M:29459006] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I (109067) esp_matter_command: Received command 0x0000000B for endpoint 0x0000's cluster 0x0000003E
I (109067) chip[ZCL]: OpCreds: Received an AddTrustedRootCertificate command
I (109157) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (109297) chip[ZCL]: OpCreds: AddTrustedRootCertificate successful.
I (109297) chip[EM]: <<< [E:11134r S:19180 M:50056463] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (109307) NimBLE: GATT procedure initiated: indicate; 
I (109307) NimBLE: att_handle=14

I (109397) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (109397) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (109497) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (109647) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (109737) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (109747) NimBLE: GATT procedure initiated: indicate; 
I (109747) NimBLE: att_handle=14

I (109837) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (109837) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (109937) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (109937) chip[EM]: >>> [E:11135r S:19180 M:29459007] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I (109947) esp_matter_command: Received command 0x00000006 for endpoint 0x0000's cluster 0x0000003E
I (109947) chip[ZCL]: OpCreds: Received an AddNOC command
I (109947) chip[FP]: Validating NOC chain
I (110407) chip[FP]: NOC chain validation successful
I (110407) chip[FP]: Added new fabric at index: 0x1
I (110407) chip[FP]: Assigned compressed fabric ID: 0xE8A947DEC51E4DC0, node ID: 0x0000000083E7B41B
I (110407) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48
I (110407) chip[TS]: New proposed Last Known Good Time: 2024-03-14T13:23:34
I (110407) chip[TS]: Updating pending Last Known Good Time to 2024-03-14T13:23:34
I (110417) chip[ZCL]: OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00010001
I (110417) chip[DIS]: Advertise operational node E8A947DEC51E4DC0-0000000083E7B41B
E (110427) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (110427) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (110427) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (110427) chip[ZCL]: OpCreds: successfully created fabric index 0x1 via AddNOC
I (110427) chip[EM]: <<< [E:11135r S:19180 M:50056464] (S) Msg TX to 1:FFFFFFFB00000000 [4DC0] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (110427) NimBLE: GATT procedure initiated: indicate; 
I (110427) NimBLE: att_handle=14

I (110517) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (110517) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (110617) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (110617) chip[EM]: >>> [E:11136r S:19180 M:29459008] (S) Msg RX from 1:FFFFFFFB00000000 [4DC0] --- Type 0001:08 (IM:InvokeCommandRequest)
I (110627) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **********
I (110627) chip[EM]: <<< [E:11136r S:19180 M:50056465] (S) Msg TX to 1:FFFFFFFB00000000 [4DC0] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (110627) NimBLE: GATT procedure initiated: indicate; 
I (110627) NimBLE: att_handle=14

E (110717) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (110717) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (110717) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
I (110717) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
E (110717) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (110717) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (110717) chip[EM]: >>> [E:11137r S:19180 M:29459009] (S) Msg RX from 1:FFFFFFFB00000000 [4DC0] --- Type 0001:02 (IM:ReadRequest)
I (110727) chip[EM]: <<< [E:11137r S:19180 M:50056466] (S) Msg TX to 1:FFFFFFFB00000000 [4DC0] [BLE] --- Type 0001:05 (IM:ReportData)
I (110727) NimBLE: GATT procedure initiated: indicate; 
I (110727) NimBLE: att_handle=14

I (110817) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (110817) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (110817) chip[EM]: >>> [E:11138r S:19180 M:29459010] (S) Msg RX from 1:FFFFFFFB00000000 [4DC0] --- Type 0001:08 (IM:InvokeCommandRequest)
E (110827) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (110827) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (110827) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (110827) OPENTHREAD: otPlatSettingsSet(166): OT NVS handle is invalid.
W(110827) OPENTHREAD:[W] Settings------: Error NotFound saving ActiveDataset
E (110827) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (110827) chip[EM]: <<< [E:11138r S:19180 M:50056467] (S) Msg TX to 1:FFFFFFFB00000000 [4DC0] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (110827) NimBLE: GATT procedure initiated: indicate; 
I (110827) NimBLE: att_handle=14

I (110957) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (110957) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (110967) chip[EM]: >>> [E:11139r S:19180 M:29459011] (S) Msg RX from 1:FFFFFFFB00000000 [4DC0] --- Type 0001:0a (IM:TimedRequest)
I (110967) chip[EM]: <<< [E:11139r S:19180 M:50056468] (S) Msg TX to 1:FFFFFFFB00000000 [4DC0] [BLE] --- Type 0001:01 (IM:StatusResponse)
I (110967) NimBLE: GATT procedure initiated: indicate; 
I (110967) NimBLE: att_handle=14

I (111057) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (111057) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12
I (111057) chip[EM]: >>> [E:11139r S:19180 M:29459012] (S) Msg RX from 1:FFFFFFFB00000000 [4DC0] --- Type 0001:08 (IM:InvokeCommandRequest)
I (111067) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x00000030
I (111067) chip[FS]: GeneralCommissioning: Received ArmFailSafe (1s)
I (111067) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **********
I (111067) chip[EM]: <<< [E:11139r S:19180 M:50056469] (S) Msg TX to 1:FFFFFFFB00000000 [4DC0] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
I (111067) NimBLE: GATT procedure initiated: indicate; 
I (111067) NimBLE: att_handle=14

I (111157) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 
I (112067) chip[FS]: Fail-safe timer expired
E (112067) chip[SVR]: Failsafe timer expired
I (112067) chip[SC]: SecureSession[0x3fca2790, LSID:19180]: State change 'kActive' --> 'kPendingEviction'
E (112067) chip[SVR]: Commissioning failed (attempt 1): 32
I (112067) chip[BLE]: Releasing end point's BLE connection back to application.
I (112067) chip[DIS]: Updating services using commissioning mode 1
E (112067) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112067) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (112067) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (112067) chip[DIS]: Advertise operational node E8A947DEC51E4DC0-0000000083E7B41B
E (112077) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112077) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (112077) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (112077) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0
E (112087) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112087) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (112087) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (112087) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112087) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (112087) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (112087) chip[ZCL]: OpCreds: Got FailSafeTimerExpired
E (112087) chip[ZCL]: OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!
E (112087) chip[FP]: Reverting pending fabric data for fabric 0x1
E (112097) chip[FP]: Warning: metadata not found during delete of fabric 0x1
I (112127) chip[FP]: Fabric (0x1) deleted.
I (112127) chip[ZCL]: UserLabel: Last Fabric index 0x1 was removed
I (112127) chip[ZCL]: OpCreds: Fabric index 0x1 was removed
I (112127) chip[DIS]: Updating services using commissioning mode 1
E (112127) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112127) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (112127) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (112127) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0
I (112127) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 0
I (112127) chip[DL]: CHIPoBLE unsubscribe received
I (112127) chip[DL]: BLE GAP connection terminated (con 1 reason 0x213)
E (112147) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112147) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (112147) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (112147) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112147) OPENTHREAD: otPlatSettingsGet(149): OT NVS handle is invalid.
E (112147) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (112197) chip[TS]: Pending Last Known Good Time: 2024-03-14T13:23:34
I (112197) chip[TS]: Previous Last Known Good Time: 2023-10-14T01:16:48
I (112207) chip[TS]: Reverted Last Known Good Time to previous value
E (112207) chip[FP]: Warning: metadata not found during delete of fabric 0x1
E (112217) chip[ZCL]: OpCreds: failed to delete fabric at index 1: d8
I (112217) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 **********
I (112217) chip[NP]: Reverting Thread operational dataset
E (112217) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112217) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (112217) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (112217) OPENTHREAD: otPlatSettingsSet(166): OT NVS handle is invalid.
W(112217) OPENTHREAD:[W] Settings------: Error NotFound saving ActiveDataset
E (112217) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (112237) app_main: Commissioning failed, fail safe timer expired
I (112237) chip[FS]: Fail-safe cleanly disarmed
I (112237) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)
I (112237) NimBLE: GAP procedure initiated: advertise; 
I (112237) NimBLE: disc_mode=2
I (112237) NimBLE:  adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40
I (112237) NimBLE: 

I (112237) chip[DL]: CHIPoBLE advertising started
I (112237) app_main: Commissioning window opened
E (112237) chip[BLE]: no endpoint for unsub recvd
I (112237) esp_matter_core: BLE Disconnected
E (120727) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (120727) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (120727) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (120727) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (130737) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (130737) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (130737) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (130737) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (140747) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (140747) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (140747) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (140747) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
I (142067) chip[DL]: Configuring CHIPoBLE advertising (interval 500 ms, connectable)
I (142067) chip[DL]: Device already advertising, stop active advertisement and restart
I (142067) NimBLE: GAP procedure initiated: stop advertising.

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

E (150757) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (150757) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready
E (150757) OPENTHREAD: esp_openthread_lock_acquire(21): Failed to acquire the lock because the mutex is not ready
E (150757) OPENTHREAD: esp_openthread_lock_release(30): Failed to release the lock because the mutex is not ready

[jonsmirl]

I'm not a thread user, but I believe this is being addressed in Matter 1.3.

[FHFS]

@jonsmirl Thanks for your response! Do you by any chance know if there is a upstream issue about the problem I am having? Or why do you know it is being addressed in 1.3?

[jonsmirl]

My understanding is that thread initially got built as three islands. For things commissioned on Google, you had to use a Google bridge, things on Apple an Apple bridge, etc. Thread was not shared between the ecosystems. 1,3 fixes it to work as a single system.

[FHFS]

@jonsmirl you are probably right. ~~but I am not trying to mix Google and Apple. I am trying to commission a generic_switch, which also has border router capabilities.~~

Does anyone know what happens with the esp32c6 that has wifi and thread capabilities? Can the esp32c6 get the wifi and thread credentials during commissioning?

[jonsmirl]

This is what is coming in Matter 1.3 https://www.threadgroup.org/news-events/blog/ID/428/Threads-2024-Enhancements-and-What-Theyll-Mean-to-You https://www.theverge.com/2024/1/8/24028203/thread-group-fix-credential-sharing-thread-border-router

[wqx6]

Hi, @FHFS Matter Working Group is working on a new device type named Home Router and Access Point (HRAP) and you can use related clusters to configure the Thread Dataset of the Thread Border Router. The device type might be planed to be published in the end of year.

For now, the Thread Border can be commissioned as a Matter-Over-Wi-Fi device and the Thread credential can be configured after commissioning with some custom cluster. Just like what we do in the rainmaker cluster. https://github.com/espressif/esp-matter/blob/main/components/esp_matter_rainmaker/esp_matter_rainmaker.cpp#L362

[FHFS]

@wqx6 Thanks again! HRAP sounds exactly like what I am looking for.

For now, the Thread Border can be commissioned as a Matter-Over-Wi-Fi device and the Thread credential can be configured after commissioning with some custom cluster. Just like what we do in the rainmaker cluster. https://github.com/espressif/esp-matter/blob/main/components/esp_matter_rainmaker/esp_matter_rainmaker.cpp#L362

What you are suggesting here is, I should configure Thread after Commissioning over Wifi, using a custom cluster. But how do I get the Thread Credentials in this case? In rainmaker it is probably done using the android/iOS app?

[wqx6]

Current iOS has provided APIs to manage thread credentials https://developer.apple.com/documentation/threadnetwork/managing-thread-network-credentials , after the BR is added to your fabric you can get the credentials with these APIs and set them with custom cluster client on your phone app. We have already tested these APIs in our test iOS app.

For Android, I think there should be similar APIs.

[FHFS]

Yes I did see the ThreadCredentials being requested in both the iOS and Android Rainmaker sources.

Thank you both for your help and input! I look forward to seeing the HRAP in the next Matter version.