ZAP tool crash on editing Storage Option

[Tiit]

Hi,

I found out that my Matter device does not commission to Alexa because as part of adding the device Alexa will try to read FeatureMap attributes from all clusters and many of these reads are failing for my device. I do have that attribute enabled in all clusters but for some reason I canät read it at all. When trying chip-tool I can see that the reads fail. It seems that reads fail for attributes that have the Storage Option set to External. What does External mean there?

Also when I try to set the Storage Option to RAM (which would likely work and what I want to do) the ZAP tool crashes. I'm pasting the terminal output here from when this happens.

(v3.0.1) tiit@tiidu-pc:~/ncs/v3.0.1/nrf/samples/matter/window_covering$ west zap-gui
Using ZAP file: /home/tiit/ncs/v3.0.1/nrf/samples/matter/window_covering/src/default_zap/window-app.zap
Using ZCL file: /home/tiit/ncs/v3.0.1/modules/lib/matter/src/app/zap-templates/zcl/zcl.json
Using app templates: /home/tiit/ncs/v3.0.1/modules/lib/matter/src/app/zap-templates/app-templates.json
ZAP installation directory: /home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install
Found ZAP 2024.8.14 (up to date)
🔧 Using temporary state directory: /tmp/zap.N9kkx9
[585898:0930/135849.683511:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.683724:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.683825:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.683933:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684037:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684147:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684257:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684360:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684433:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684505:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684572:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684630:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684688:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684746:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684811:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684888:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.684947:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685006:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685063:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685130:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685266:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685339:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685426:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685647:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685759:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.685920:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686032:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686229:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686388:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686454:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686514:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686583:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686653:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686729:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686791:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686860:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686930:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.686991:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.687055:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)
[585898:0930/135849.687120:ERROR:gbm_wrapper.cc(253)] Failed to export buffer to dma_buf: No such file or directory (2)


🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨

Application is failing the Device Type Specification as follows: 

  - ⚠ Check Device Type Compliance on endpoint: 2, device type: MA-air-quality-sensor, cluster: Identify server needs to be enabled
  - ⚠ Check Device Type Compliance on endpoint: 2, device type: MA-air-quality-sensor, cluster: Identify, attribute: IdentifyTime needs to be enabled
  - ⚠ Check Device Type Compliance on endpoint: 2, device type: MA-air-quality-sensor, cluster: Identify, attribute: IdentifyType needs to be enabled
  - ⚠ Check Device Type Compliance on endpoint: 2, device type: MA-air-quality-sensor, cluster: Identify server, command: Identify incoming needs to be enabled

Application is failing the Cluster Specification as follows: 


🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨🚨


[585898:0930/135858.368429:ERROR:gl_surface_presentation_helper.cc(260)] GetVSyncParametersIfAvailable() failed for 1 times!
[585898:0930/135910.591641:ERROR:gl_surface_presentation_helper.cc(260)] GetVSyncParametersIfAvailable() failed for 2 times!
[585898:0930/135910.603139:ERROR:gl_surface_presentation_helper.cc(260)] GetVSyncParametersIfAvailable() failed for 3 times!
(node:585865) UnhandledPromiseRejectionWarning: TypeError: Cannot convert null to a BigInt
    at BigInt (<anonymous>)
    at extractBigIntegerValue (/home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/validation/validation.js:173:16)
    at getIntegerFromAttribute (/home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/validation/validation.js:215:11)
    at checkAttributeBoundsInteger (/home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/validation/validation.js:258:30)
    at validateSpecificAttribute (/home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/validation/validation.js:92:24)
    at /home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/rest/user-data.js:273:30
(Use `zap --trace-warnings ...` to show where the warning was created)
(node:585865) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2)
Warning: terminator_CreateInstance: Failed to CreateInstance in ICD 3.  Skipping ICD.
Error: ../src/amd/vulkan/radv_physical_device.c:1877: Device '/dev/dri/renderD128' is not using the AMDGPU kernel driver: Invalid argument (VK_ERROR_INCOMPATIBLE_DRIVER)
(node:585865) UnhandledPromiseRejectionWarning: TypeError: Cannot convert null to a BigInt
    at BigInt (<anonymous>)
    at extractBigIntegerValue (/home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/validation/validation.js:173:16)
    at getIntegerFromAttribute (/home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/validation/validation.js:215:11)
    at checkAttributeBoundsInteger (/home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/validation/validation.js:258:30)
    at validateSpecificAttribute (/home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/validation/validation.js:92:24)
    at /home/tiit/ncs/v3.0.1/modules/lib/matter/.zap-install/resources/app.asar/dist/src-electron/rest/user-data.js:273:30
(node:585865) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 4)

This is not my only problem with ZAP tool though so maybe my issue is with some configuration somewhere. I have gotten so far that I can somehow change the clusters for my Matter device but it is extremely clumsy at the moment and if I could I would just manually do all this in the conf files at this point. ZAP tool can only edit the zap file in the samples directory for me - I can not run it in my out of tree project at all. when I save/generate code from the tool I can only do so in the root of the sample project - I can not navigate to a different folder using the file selection window. And for the CO2 measurement cluster ZAP tool just refuses to remember my settings and I have to set all values again (Storage Option for MeasuredValue for example) every time. 

All the other issues aside I really need to fix the read error for the FeatureMap attributes as soon as possible as we are already late for sending the device out to the lab to get certified.

Tiit

[Marte Myrvold]

Hi Tiit,

Which version of the nRF Connect SDK are you using?

Do you fail to read the FeatureMap for all clusters on the device or only specific clusters?

Please share the log from chip-tool.

What does External mean there?

External means that the attribute value is stored in non-volatile memory in the external flash. The value of the FeatureMap attribute should be persistently stored when a device is powered off or reset, so it should be stored in non-volatile memory and not in RAM.

Best regards,
Marte

[Tiit]

Hi Marte,

I'm using SDK v3.0.1.

FeatureMap attributes can't be read on Carbon Dioxide Measurement and Air Quality clusters. On those clusters FeatureMap attributes are set to Storage Option "External". Trying to change the Storage Option to RAM crashes the tool. I tried manually editing the generated source files and I can change them to RAM and that fixes the Alexa commissioning error (it fixes the error on reading these in chip-tool as well).

Are you sure about the description of External here? That does not seem right at all. This tool should not care or know about where different parts of memory are mapped in hardware. The options in that drop-down are RAM, NVM ja External. My gut says that RAM means device memory, NVM means memory that is kept through resets (in whatever way the hardware implements that - could be settings mapped to SOC internal flash). And External seems to mean something else. If I had to guess I would say external should cause a callback to be called in the device that is then responsible for sending the response generated in user code. But I can't find any information to confirm that yet. So I would use External if I wanted to send the response in some device specific way.

ubuntu@ubuntu:~$ ./apps/chip-tool pairing ble-thread 1 hex:0e08000000000001000035060004001fffe00708fd414ce3cb811d320410a8af263edc5f96ed6936634602aabb170c0402a0f7f8000300001901025b3502085b35dead5b35beef030435623335051000112233445566778899aabbccddeeff 20250926 001
[1759488701.489] [57027:57027] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1759488701.489] [57027:57027] [DL] ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1759488701.492] [57027:57027] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1759488701.492] [57027:57027] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1759488701.492] [57027:57027] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1759488701.505] [57027:57027] [DL] Wrote settings to /tmp/chip_counters.ini
[1759488701.505] [57027:57027] [DL] NVS set: chip-counters/reboot-count = 26 (0x1A)
[1759488701.506] [57027:57027] [DL] Got Ethernet interface: eth0
[1759488701.506] [57027:57027] [DL] Found the primary Ethernet interface:eth0
[1759488701.506] [57027:57027] [DL] Got WiFi interface: wlan0
[1759488701.506] [57027:57027] [DL] Failed to reset WiFi statistic counts
[1759488701.506] [57027:57027] [IN] UDP::Init bind&listen port=0
[1759488701.506] [57027:57027] [IN] UDP::Init bound to port=53505
[1759488701.506] [57027:57027] [IN] BLEBase::Init - setting/overriding transport
[1759488701.506] [57027:57027] [IN] TransportMgr initialized
[1759488701.506] [57027:57027] [FP] Initializing FabricTable from persistent storage
[1759488701.506] [57027:57027] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1759488701.507] [57027:57027] [FP] Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xD51E2C5F40271BF8, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1759488701.508] [57027:57027] [ZCL] Using ZAP configuration...
[1759488701.510] [57027:57027] [DL] Avahi client registered
[1759488701.510] [57027:57027] [IM] WARNING ┌────────────────────────────────────────────────────
[1759488701.510] [57027:57027] [IM] WARNING │ Interaction Model Engine running in 'Checked' mode.
[1759488701.510] [57027:57027] [IM] WARNING │ This executes BOTH ember and data-model code paths.
[1759488701.510] [57027:57027] [IM] WARNING │ which is inefficient and consumes more flash space.
[1759488701.510] [57027:57027] [IM] WARNING │ This should be done for testing only.
[1759488701.510] [57027:57027] [IM] WARNING └────────────────────────────────────────────────────
[1759488701.510] [57027:57027] [CTL] System State Initialized...
[1759488701.510] [57027:57027] [CTL] Setting attestation nonce to random value
[1759488701.510] [57027:57027] [CTL] Setting CSR nonce to random value
[1759488701.510] [57027:57027] [IN] UDP::Init bind&listen port=5550
[1759488701.510] [57027:57027] [IN] UDP::Init bound to port=5550
[1759488701.510] [57027:57027] [IN] TransportMgr initialized
[1759488701.510] [57027:57029] [DL] CHIP task running
[1759488701.511] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 32786
[1759488701.511] [57027:57029] [CTL] Setting attestation nonce to random value
[1759488701.511] [57027:57029] [CTL] Setting CSR nonce to random value
[1759488701.511] [57027:57029] [CTL] Generating NOC
[1759488701.512] [57027:57029] [FP] Validating NOC chain
[1759488701.513] [57027:57029] [FP] NOC chain validation successful
[1759488701.513] [57027:57029] [FP] Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1759488701.513] [57027:57029] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1759488701.513] [57027:57029] [TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
[1759488701.513] [57027:57029] [TS] Retaining current Last Known Good Time
[1759488701.519] [57027:57029] [FP] Metadata for Fabric 0x1 persisted to storage.
[1759488701.520] [57027:57029] [TS] Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1759488701.522] [57027:57029] [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: D51E2C5F40271BF8)
[1759488701.522] [57027:57029] [IN] UDP::Init bind&listen port=5550
[1759488701.522] [57027:57029] [IN] UDP::Init bound to port=5550
[1759488701.522] [57027:57029] [IN] TransportMgr initialized
[1759488701.533] [57027:57029] [CTL] Setting thread operational dataset from parameters
[1759488701.533] [57027:57029] [CTL] Setting attestation nonce to random value
[1759488701.533] [57027:57029] [CTL] Setting CSR nonce to random value
[1759488701.533] [57027:57029] [CTL] Commission called for node ID 0x0000000000000001
[1759488701.537] [57027:57028] [BLE] BLE removing known devices
[1759488701.538] [57027:57028] [BLE] BLE initiating scan
[1759488701.540] [57027:57029] [BLE] ChipDeviceScanner has started scanning!
[1759488701.547] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.550] [57027:57028] [BLE] Device 34:60:D5:45:EA:44 does not look like a CHIP device.
[1759488701.552] [57027:57028] [BLE] Device 18:23:E6:43:E0:C3 does not look like a CHIP device.
[1759488701.556] [57027:57028] [BLE] Device DB:98:CA:54:54:D6 does not look like a CHIP device.
[1759488701.563] [57027:57028] [BLE] Device 65:84:2B:04:02:61 does not look like a CHIP device.
[1759488701.569] [57027:57028] [BLE] Device FC:65:1E:FA:26:DE does not look like a CHIP device.
[1759488701.574] [57027:57028] [BLE] Device F8:90:A6:1C:B4:38 does not look like a CHIP device.
[1759488701.584] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.592] [57027:57028] [BLE] Device D7:79:F1:DB:06:AA does not look like a CHIP device.
[1759488701.593] [57027:57028] [BLE] Device E2:46:8D:5B:EF:A1 does not look like a CHIP device.
[1759488701.595] [57027:57028] [BLE] Device 65:84:2B:04:02:61 does not look like a CHIP device.
[1759488701.601] [57027:57028] [BLE] Device F4:46:E5:8D:01:31 does not look like a CHIP device.
[1759488701.604] [57027:57028] [BLE] Device 2C:31:8F:0B:86:9B does not look like a CHIP device.
[1759488701.624] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.638] [57027:57028] [BLE] Device C1:E5:8A:F7:74:A0 does not look like a CHIP device.
[1759488701.648] [57027:57028] [BLE] Device C4:54:CE:20:0F:EC does not look like a CHIP device.
[1759488701.649] [57027:57028] [BLE] Device E3:FE:D1:B1:57:59 does not look like a CHIP device.
[1759488701.654] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.661] [57027:57028] [BLE] Device E5:8D:BA:33:45:57 does not look like a CHIP device.
[1759488701.661] [57027:57028] [BLE] Device 18:23:E6:43:E0:C3 does not look like a CHIP device.
[1759488701.669] [57027:57028] [BLE] Device 65:84:2B:04:02:61 does not look like a CHIP device.
[1759488701.670] [57027:57028] [BLE] Device ED:AA:0C:58:2C:DD does not look like a CHIP device.
[1759488701.673] [57027:57028] [BLE] Device FC:65:1E:FA:26:DE does not look like a CHIP device.
[1759488701.679] [57027:57028] [BLE] Device 75:4A:22:0A:32:36 does not look like a CHIP device.
[1759488701.695] [57027:57028] [BLE] Device F6:19:C9:A8:BF:64 does not look like a CHIP device.
[1759488701.697] [57027:57028] [BLE] Device 42:69:2C:AA:FC:44 does not look like a CHIP device.
[1759488701.701] [57027:57028] [BLE] Device E2:46:8D:5B:EF:A1 does not look like a CHIP device.
[1759488701.702] [57027:57028] [BLE] Device FE:2D:C8:95:1D:58 does not look like a CHIP device.
[1759488701.716] [57027:57028] [BLE] Device C6:00:AB:5D:39:41 does not look like a CHIP device.
[1759488701.720] [57027:57028] [BLE] Device D3:16:E6:A6:21:F7 does not look like a CHIP device.
[1759488701.736] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.736] [57027:57028] [BLE] Device 34:60:D5:45:EA:44 does not look like a CHIP device.
[1759488701.740] [57027:57028] [BLE] Device 65:84:2B:04:02:61 does not look like a CHIP device.
[1759488701.750] [57027:57028] [BLE] Device C4:54:CE:20:0F:EC does not look like a CHIP device.
[1759488701.755] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.756] [57027:57028] [BLE] Device F4:46:E5:8D:01:31 does not look like a CHIP device.
[1759488701.762] [57027:57028] [BLE] Device 18:23:E6:43:E0:C3 does not look like a CHIP device.
[1759488701.768] [57027:57028] [BLE] Device DB:98:CA:54:54:D6 does not look like a CHIP device.
[1759488701.768] [57027:57028] [BLE] Device 65:84:2B:04:02:61 does not look like a CHIP device.
[1759488701.781] [57027:57028] [BLE] Device ED:AA:0C:58:2C:DD does not look like a CHIP device.
[1759488701.785] [57027:57028] [BLE] Device D4:FA:8A:55:6F:38 does not look like a CHIP device.
[1759488701.788] [57027:57028] [BLE] Device E2:70:4F:7F:69:2C does not look like a CHIP device.
[1759488701.789] [57027:57028] [BLE] Device D7:79:F1:DB:06:AA does not look like a CHIP device.
[1759488701.802] [57027:57028] [BLE] Device E2:46:8D:5B:EF:A1 does not look like a CHIP device.
[1759488701.807] [57027:57028] [BLE] Device E3:FE:D1:B1:57:59 does not look like a CHIP device.
[1759488701.810] [57027:57028] [BLE] Device FE:2D:C8:95:1D:58 does not look like a CHIP device.
[1759488701.815] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.816] [57027:57028] [BLE] Device FB:F3:2B:5E:92:C1 does not look like a CHIP device.
[1759488701.821] [57027:57028] [BLE] Device C0:BC:3D:E1:57:EF does not look like a CHIP device.
[1759488701.839] [57027:57028] [BLE] Device DC:AD:D5:F8:1B:0F does not look like a CHIP device.
[1759488701.839] [57027:57028] [BLE] Device C1:E5:8A:F7:74:A0 does not look like a CHIP device.
[1759488701.845] [57027:57028] [BLE] Device 19:B9:32:B7:47:C0 does not look like a CHIP device.
[1759488701.848] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.867] [57027:57028] [BLE] Device 65:84:2B:04:02:61 does not look like a CHIP device.
[1759488701.879] [57027:57028] [BLE] Device 65:84:2B:04:02:61 does not look like a CHIP device.
[1759488701.883] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.894] [57027:57028] [BLE] Device DD:F9:F4:7E:FB:4C does not look like a CHIP device.
[1759488701.910] [57027:57028] [BLE] Device D8:AF:BD:41:75:93 does not look like a CHIP device.
[1759488701.911] [57027:57028] [BLE] Device E2:46:8D:5B:EF:A1 does not look like a CHIP device.
[1759488701.913] [57027:57028] [BLE] Device FA:2D:1D:AF:A4:6B does not look like a CHIP device.
[1759488701.920] [57027:57028] [BLE] Device FE:2D:C8:95:1D:58 does not look like a CHIP device.
[1759488701.939] [57027:57028] [BLE] Device DC:AD:D5:F8:1B:0F does not look like a CHIP device.
[1759488701.945] [57027:57028] [BLE] New device scanned: E5:10:37:A3:C7:80
[1759488701.945] [57027:57028] [BLE] Device discriminator match. Attempting to connect.
[1759488701.946] [57027:57028] [BLE] ChipDeviceScanner has stopped scanning!
[1759488702.351] [57027:57028] [DL] ConnectDevice complete
[1759488702.351] [57027:57028] [BLE] New device connected: E5:10:37:A3:C7:80
[1759488703.542] [57027:57028] [DL] CHIP service found
[1759488703.542] [57027:57028] [DL] Valid C1 characteristic found
[1759488703.543] [57027:57028] [DL] Valid C2 characteristic found
[1759488703.543] [57027:57028] [DL] New BLE connection: conn=0xffffac043900 device=E5:10:37:A3:C7:80 path=/org/bluez/hci0/dev_E5_10_37_A3_C7_80
[1759488703.543] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16387
[1759488703.543] [57027:57029] [DIS] Closing all BLE connections
[1759488703.543] [57027:57029] [IN] BleConnectionComplete: endPoint 0xaaaac372cb88
[1759488703.543] [57027:57029] [IN] SecureSession[0xffffa4000da0]: Allocated Type:1 LSID:50153
[1759488703.543] [57027:57029] [SC] Assigned local session key ID 50153
[1759488703.543] [57027:57029] [EM] <<< [E:29397i S:0 M:151048955] (U) Msg TX from 6757901ADFE51E93 to 0:0000000000000000 [0000] [BLE] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98)
[1759488703.543] [57027:57029] [IN] Message appended to BLE send queue
[1759488703.543] [57027:57029] [SC] Sent PBKDF param request [II:500ms AI:300ms AT:4000ms)
[1759488703.976] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488704.066] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16390
[1759488704.066] [57027:57029] [BLE] subscribe complete, ep = 0xaaaac372cb88
[1759488704.067] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.067] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.067] [57027:57029] [BLE] peripheral chose BTP version 4; central expected between 4 and 4
[1759488704.067] [57027:57029] [BLE] using BTP fragment sizes rx 244 / tx 244.
[1759488704.067] [57027:57029] [BLE] local and remote recv window size = 5
[1759488704.067] [57027:57029] [IN] BLE EndPoint 0xaaaac372cb88 Connection Complete
[1759488704.156] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488704.159] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.159] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.159] [57027:57029] [EM] >>> [E:29397i S:0 M:16472185] (U) Msg RX from 0:0000000000000000 [0000] to 6757901ADFE51E93 --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154)
[1759488704.159] [57027:57029] [EM] Found matching exchange: 29397i, Delegate: 0xffffa400b778
[1759488704.159] [57027:57029] [SC] Received PBKDF param response
[1759488704.159] [57027:57029] [SC] Peer assigned session ID 19558
[1759488704.159] [57027:57029] [SC] Found MRP parameters in the message
[1759488704.162] [57027:57029] [EM] <<< [E:29397i S:0 M:151048956] (U) Msg TX from 6757901ADFE51E93 to 0:0000000000000000 [0000] [BLE] --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92)
[1759488704.162] [57027:57029] [SC] Sent spake2p msg1
[1759488704.246] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488704.383] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.383] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.383] [57027:57029] [EM] >>> [E:29397i S:0 M:16472186] (U) Msg RX from 0:0000000000000000 [0000] to 6757901ADFE51E93 --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127)
[1759488704.383] [57027:57029] [EM] Found matching exchange: 29397i, Delegate: 0xffffa400b778
[1759488704.383] [57027:57029] [SC] Received spake2p msg2
[1759488704.385] [57027:57029] [EM] <<< [E:29397i S:0 M:151048957] (U) Msg TX from 6757901ADFE51E93 to 0:0000000000000000 [0000] [BLE] --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59)
[1759488704.385] [57027:57029] [SC] Sent spake2p msg3
[1759488704.471] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488704.473] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.473] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.473] [57027:57029] [EM] >>> [E:29397i S:0 M:16472187] (U) Msg RX from 0:0000000000000000 [0000] to 6757901ADFE51E93 --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
[1759488704.473] [57027:57029] [EM] Found matching exchange: 29397i, Delegate: 0xffffa400b778
[1759488704.473] [57027:57029] [SC] SecureSession[0xffffa4000da0, LSID:50153]: State change 'kEstablishing' --> 'kActive'
[1759488704.473] [57027:57029] [IN] SecureSession[0xffffa4000da0]: Activated - Type:1 LSID:50153
[1759488704.473] [57027:57029] [IN] New secure session activated for device <FFFFFFFB00000000, 0>, LSID:50153 PSID:19558!
[1759488704.473] [57027:57029] [CTL] Remote device completed SPAKE2+ handshake
[1759488704.473] [57027:57029] [TOO] Pairing Success
[1759488704.473] [57027:57029] [TOO] PASE establishment successful
[1759488704.473] [57027:57029] [CTL] Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1759488704.473] [57027:57029] [CTL] Performing next commissioning step 'ReadCommissioningInfo'
[1759488704.473] [57027:57029] [CTL] Sending read request for commissioning information
[1759488704.473] [57027:57029] [DMG] SendReadRequest ReadClient[0xffffa400a060]: Sending Read Request
[1759488704.473] [57027:57029] [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
[1759488704.473] [57027:57029] [EM] <<< [E:29398i S:50153 M:145504451] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:02 (IM:ReadRequest) (B:131)
[1759488704.473] [57027:57029] [DMG] MoveToState ReadClient[0xffffa400a060]: Moving to [AwaitingIn]
[1759488704.473] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 32792
[1759488704.561] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488704.565] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.565] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.652] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.652] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.652] [57027:57029] [EM] >>> [E:29398i S:50153 M:58084346] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:05 (IM:ReportData) (B:258)
[1759488704.652] [57027:57029] [EM] Found matching exchange: 29398i, Delegate: 0xffffa400a070
[1759488704.652] [57027:57029] [DMG] ReportDataMessage =
[1759488704.652] [57027:57029] [DMG] {
[1759488704.652] [57027:57029] [DMG] 	AttributeReportIBs =
[1759488704.652] [57027:57029] [DMG] 	[
[1759488704.652] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.652] [57027:57029] [DMG] 		{
[1759488704.652] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.652] [57027:57029] [DMG] 			{
[1759488704.652] [57027:57029] [DMG] 				DataVersion = 0x1d297b4f,
[1759488704.652] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.653] [57027:57029] [DMG] 				{
[1759488704.653] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.653] [57027:57029] [DMG] 					Cluster = 0x31,
[1759488704.653] [57027:57029] [DMG] 					Attribute = 0x0000_0003,
[1759488704.653] [57027:57029] [DMG] 				}
[1759488704.653] [57027:57029] [DMG] 					
[1759488704.653] [57027:57029] [DMG] 				Data = 20 (unsigned), 
[1759488704.653] [57027:57029] [DMG] 			},
[1759488704.653] [57027:57029] [DMG] 			
[1759488704.653] [57027:57029] [DMG] 		},
[1759488704.653] [57027:57029] [DMG] 		
[1759488704.653] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.653] [57027:57029] [DMG] 		{
[1759488704.653] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.653] [57027:57029] [DMG] 			{
[1759488704.653] [57027:57029] [DMG] 				DataVersion = 0xfe2b7d63,
[1759488704.653] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.653] [57027:57029] [DMG] 				{
[1759488704.653] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.653] [57027:57029] [DMG] 					Cluster = 0x28,
[1759488704.653] [57027:57029] [DMG] 					Attribute = 0x0000_0004,
[1759488704.653] [57027:57029] [DMG] 				}
[1759488704.653] [57027:57029] [DMG] 					
[1759488704.653] [57027:57029] [DMG] 				Data = 32784 (unsigned), 
[1759488704.653] [57027:57029] [DMG] 			},
[1759488704.653] [57027:57029] [DMG] 			
[1759488704.653] [57027:57029] [DMG] 		},
[1759488704.654] [57027:57029] [DMG] 		
[1759488704.654] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.654] [57027:57029] [DMG] 		{
[1759488704.654] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.654] [57027:57029] [DMG] 			{
[1759488704.654] [57027:57029] [DMG] 				DataVersion = 0xfe2b7d63,
[1759488704.654] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.654] [57027:57029] [DMG] 				{
[1759488704.654] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.654] [57027:57029] [DMG] 					Cluster = 0x28,
[1759488704.654] [57027:57029] [DMG] 					Attribute = 0x0000_0002,
[1759488704.654] [57027:57029] [DMG] 				}
[1759488704.654] [57027:57029] [DMG] 					
[1759488704.654] [57027:57029] [DMG] 				Data = 65521 (unsigned), 
[1759488704.654] [57027:57029] [DMG] 			},
[1759488704.654] [57027:57029] [DMG] 			
[1759488704.654] [57027:57029] [DMG] 		},
[1759488704.654] [57027:57029] [DMG] 		
[1759488704.654] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.654] [57027:57029] [DMG] 		{
[1759488704.654] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.654] [57027:57029] [DMG] 			{
[1759488704.654] [57027:57029] [DMG] 				DataVersion = 0x584a7eaf,
[1759488704.654] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.654] [57027:57029] [DMG] 				{
[1759488704.655] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.655] [57027:57029] [DMG] 					Cluster = 0x30,
[1759488704.655] [57027:57029] [DMG] 					Attribute = 0x0000_0003,
[1759488704.655] [57027:57029] [DMG] 				}
[1759488704.655] [57027:57029] [DMG] 					
[1759488704.655] [57027:57029] [DMG] 				Data = 0 (unsigned), 
[1759488704.655] [57027:57029] [DMG] 			},
[1759488704.655] [57027:57029] [DMG] 			
[1759488704.655] [57027:57029] [DMG] 		},
[1759488704.655] [57027:57029] [DMG] 		
[1759488704.655] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.655] [57027:57029] [DMG] 		{
[1759488704.655] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.655] [57027:57029] [DMG] 			{
[1759488704.655] [57027:57029] [DMG] 				DataVersion = 0x584a7eaf,
[1759488704.655] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.655] [57027:57029] [DMG] 				{
[1759488704.655] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.655] [57027:57029] [DMG] 					Cluster = 0x30,
[1759488704.655] [57027:57029] [DMG] 					Attribute = 0x0000_0002,
[1759488704.655] [57027:57029] [DMG] 				}
[1759488704.655] [57027:57029] [DMG] 					
[1759488704.655] [57027:57029] [DMG] 				Data = 0 (unsigned), 
[1759488704.655] [57027:57029] [DMG] 			},
[1759488704.655] [57027:57029] [DMG] 			
[1759488704.655] [57027:57029] [DMG] 		},
[1759488704.656] [57027:57029] [DMG] 		
[1759488704.656] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.656] [57027:57029] [DMG] 		{
[1759488704.656] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.656] [57027:57029] [DMG] 			{
[1759488704.656] [57027:57029] [DMG] 				DataVersion = 0x584a7eaf,
[1759488704.656] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.656] [57027:57029] [DMG] 				{
[1759488704.656] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.656] [57027:57029] [DMG] 					Cluster = 0x30,
[1759488704.656] [57027:57029] [DMG] 					Attribute = 0x0000_0001,
[1759488704.656] [57027:57029] [DMG] 				}
[1759488704.656] [57027:57029] [DMG] 					
[1759488704.656] [57027:57029] [DMG] 				Data = 
[1759488704.656] [57027:57029] [DMG] 				{
[1759488704.656] [57027:57029] [DMG] 					0x0 = 60 (unsigned), 
[1759488704.656] [57027:57029] [DMG] 					0x1 = 900 (unsigned), 
[1759488704.656] [57027:57029] [DMG] 				},
[1759488704.656] [57027:57029] [DMG] 			},
[1759488704.656] [57027:57029] [DMG] 			
[1759488704.656] [57027:57029] [DMG] 		},
[1759488704.656] [57027:57029] [DMG] 		
[1759488704.656] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.656] [57027:57029] [DMG] 		{
[1759488704.656] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.656] [57027:57029] [DMG] 			{
[1759488704.656] [57027:57029] [DMG] 				DataVersion = 0x584a7eaf,
[1759488704.656] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.657] [57027:57029] [DMG] 				{
[1759488704.657] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.657] [57027:57029] [DMG] 					Cluster = 0x30,
[1759488704.657] [57027:57029] [DMG] 					Attribute = 0x0000_0000,
[1759488704.657] [57027:57029] [DMG] 				}
[1759488704.657] [57027:57029] [DMG] 					
[1759488704.657] [57027:57029] [DMG] 				Data = 0 (unsigned), 
[1759488704.657] [57027:57029] [DMG] 			},
[1759488704.657] [57027:57029] [DMG] 			
[1759488704.657] [57027:57029] [DMG] 		},
[1759488704.657] [57027:57029] [DMG] 		
[1759488704.657] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.657] [57027:57029] [DMG] 		{
[1759488704.657] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.657] [57027:57029] [DMG] 			{
[1759488704.657] [57027:57029] [DMG] 				DataVersion = 0x1d297b4f,
[1759488704.657] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.657] [57027:57029] [DMG] 				{
[1759488704.657] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.657] [57027:57029] [DMG] 					Cluster = 0x31,
[1759488704.657] [57027:57029] [DMG] 					Attribute = 0x0000_FFFC,
[1759488704.657] [57027:57029] [DMG] 				}
[1759488704.657] [57027:57029] [DMG] 					
[1759488704.657] [57027:57029] [DMG] 				Data = 2 (unsigned), 
[1759488704.657] [57027:57029] [DMG] 			},
[1759488704.657] [57027:57029] [DMG] 			
[1759488704.657] [57027:57029] [DMG] 		},
[1759488704.657] [57027:57029] [DMG] 		
[1759488704.657] [57027:57029] [DMG] 	],
[1759488704.658] [57027:57029] [DMG] 	
[1759488704.658] [57027:57029] [DMG] 	SuppressResponse = true, 
[1759488704.658] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488704.658] [57027:57029] [DMG] }
[1759488704.658] [57027:57029] [CTL] Successfully finished commissioning step 'ReadCommissioningInfo'
[1759488704.658] [57027:57029] [CTL] Commissioning stage next step: 'ReadCommissioningInfo' -> 'ReadCommissioningInfo2'
[1759488704.658] [57027:57029] [CTL] Performing next commissioning step 'ReadCommissioningInfo2'
[1759488704.658] [57027:57029] [DMG] SendReadRequest ReadClient[0xffffa400a060]: Sending Read Request
[1759488704.658] [57027:57029] [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
[1759488704.658] [57027:57029] [EM] <<< [E:29399i S:50153 M:145504452] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:02 (IM:ReadRequest) (B:106)
[1759488704.659] [57027:57029] [DMG] MoveToState ReadClient[0xffffa400a060]: Moving to [AwaitingIn]
[1759488704.741] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488704.745] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.745] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.745] [57027:57029] [EM] >>> [E:29399i S:50153 M:58084347] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:05 (IM:ReportData) (B:191)
[1759488704.745] [57027:57029] [EM] Found matching exchange: 29399i, Delegate: 0xffffa400a070
[1759488704.745] [57027:57029] [DMG] ReportDataMessage =
[1759488704.745] [57027:57029] [DMG] {
[1759488704.745] [57027:57029] [DMG] 	AttributeReportIBs =
[1759488704.745] [57027:57029] [DMG] 	[
[1759488704.745] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.745] [57027:57029] [DMG] 		{
[1759488704.745] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.745] [57027:57029] [DMG] 			{
[1759488704.745] [57027:57029] [DMG] 				DataVersion = 0x18418599,
[1759488704.745] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.745] [57027:57029] [DMG] 				{
[1759488704.745] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.745] [57027:57029] [DMG] 					Cluster = 0x46,
[1759488704.745] [57027:57029] [DMG] 					Attribute = 0x0000_0002,
[1759488704.745] [57027:57029] [DMG] 				}
[1759488704.745] [57027:57029] [DMG] 					
[1759488704.745] [57027:57029] [DMG] 				Data = 300 (unsigned), 
[1759488704.745] [57027:57029] [DMG] 			},
[1759488704.746] [57027:57029] [DMG] 			
[1759488704.746] [57027:57029] [DMG] 		},
[1759488704.746] [57027:57029] [DMG] 		
[1759488704.746] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.746] [57027:57029] [DMG] 		{
[1759488704.746] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.746] [57027:57029] [DMG] 			{
[1759488704.746] [57027:57029] [DMG] 				DataVersion = 0x18418599,
[1759488704.746] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.746] [57027:57029] [DMG] 				{
[1759488704.746] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.746] [57027:57029] [DMG] 					Cluster = 0x46,
[1759488704.746] [57027:57029] [DMG] 					Attribute = 0x0000_0001,
[1759488704.746] [57027:57029] [DMG] 				}
[1759488704.746] [57027:57029] [DMG] 					
[1759488704.746] [57027:57029] [DMG] 				Data = 300 (unsigned), 
[1759488704.746] [57027:57029] [DMG] 			},
[1759488704.746] [57027:57029] [DMG] 			
[1759488704.746] [57027:57029] [DMG] 		},
[1759488704.746] [57027:57029] [DMG] 		
[1759488704.746] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.746] [57027:57029] [DMG] 		{
[1759488704.746] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.746] [57027:57029] [DMG] 			{
[1759488704.746] [57027:57029] [DMG] 				DataVersion = 0x18418599,
[1759488704.746] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.746] [57027:57029] [DMG] 				{
[1759488704.746] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.747] [57027:57029] [DMG] 					Cluster = 0x46,
[1759488704.747] [57027:57029] [DMG] 					Attribute = 0x0000_0000,
[1759488704.747] [57027:57029] [DMG] 				}
[1759488704.747] [57027:57029] [DMG] 					
[1759488704.747] [57027:57029] [DMG] 				Data = 120 (unsigned), 
[1759488704.747] [57027:57029] [DMG] 			},
[1759488704.747] [57027:57029] [DMG] 			
[1759488704.747] [57027:57029] [DMG] 		},
[1759488704.747] [57027:57029] [DMG] 		
[1759488704.747] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.747] [57027:57029] [DMG] 		{
[1759488704.747] [57027:57029] [DMG] 			AttributeStatusIB =
[1759488704.747] [57027:57029] [DMG] 			{
[1759488704.747] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.747] [57027:57029] [DMG] 				{
[1759488704.747] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.747] [57027:57029] [DMG] 					Cluster = 0x46,
[1759488704.747] [57027:57029] [DMG] 					Attribute = 0x0000_0007,
[1759488704.747] [57027:57029] [DMG] 				}
[1759488704.747] [57027:57029] [DMG] 					
[1759488704.747] [57027:57029] [DMG] 				StatusIB =
[1759488704.747] [57027:57029] [DMG] 				{
[1759488704.747] [57027:57029] [DMG] 					status = 0x86 (UNSUPPORTED_ATTRIBUTE),
[1759488704.747] [57027:57029] [DMG] 				},
[1759488704.747] [57027:57029] [DMG] 				
[1759488704.747] [57027:57029] [DMG] 			},
[1759488704.747] [57027:57029] [DMG] 			
[1759488704.747] [57027:57029] [DMG] 		},
[1759488704.748] [57027:57029] [DMG] 		
[1759488704.748] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.748] [57027:57029] [DMG] 		{
[1759488704.748] [57027:57029] [DMG] 			AttributeStatusIB =
[1759488704.748] [57027:57029] [DMG] 			{
[1759488704.748] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.748] [57027:57029] [DMG] 				{
[1759488704.748] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.748] [57027:57029] [DMG] 					Cluster = 0x46,
[1759488704.748] [57027:57029] [DMG] 					Attribute = 0x0000_0006,
[1759488704.748] [57027:57029] [DMG] 				}
[1759488704.748] [57027:57029] [DMG] 					
[1759488704.748] [57027:57029] [DMG] 				StatusIB =
[1759488704.748] [57027:57029] [DMG] 				{
[1759488704.748] [57027:57029] [DMG] 					status = 0x86 (UNSUPPORTED_ATTRIBUTE),
[1759488704.748] [57027:57029] [DMG] 				},
[1759488704.748] [57027:57029] [DMG] 				
[1759488704.748] [57027:57029] [DMG] 			},
[1759488704.748] [57027:57029] [DMG] 			
[1759488704.748] [57027:57029] [DMG] 		},
[1759488704.748] [57027:57029] [DMG] 		
[1759488704.748] [57027:57029] [DMG] 		AttributeReportIB =
[1759488704.748] [57027:57029] [DMG] 		{
[1759488704.748] [57027:57029] [DMG] 			AttributeDataIB =
[1759488704.748] [57027:57029] [DMG] 			{
[1759488704.749] [57027:57029] [DMG] 				DataVersion = 0x584a7eaf,
[1759488704.749] [57027:57029] [DMG] 				AttributePathIB =
[1759488704.749] [57027:57029] [DMG] 				{
[1759488704.749] [57027:57029] [DMG] 					Endpoint = 0x0,
[1759488704.749] [57027:57029] [DMG] 					Cluster = 0x30,
[1759488704.749] [57027:57029] [DMG] 					Attribute = 0x0000_0004,
[1759488704.749] [57027:57029] [DMG] 				}
[1759488704.749] [57027:57029] [DMG] 					
[1759488704.749] [57027:57029] [DMG] 				Data = true, 
[1759488704.749] [57027:57029] [DMG] 			},
[1759488704.749] [57027:57029] [DMG] 			
[1759488704.749] [57027:57029] [DMG] 		},
[1759488704.749] [57027:57029] [DMG] 		
[1759488704.749] [57027:57029] [DMG] 	],
[1759488704.749] [57027:57029] [DMG] 	
[1759488704.749] [57027:57029] [DMG] 	SuppressResponse = true, 
[1759488704.749] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488704.749] [57027:57029] [DMG] }
[1759488704.750] [57027:57029] [CTL] ----- NetworkCommissioning Features: has Thread. endpointid = 0
[1759488704.750] [57027:57029] [SVR] OnReadCommissioningInfo - vendorId=0xFFF1 productId=0x8010
[1759488704.750] [57027:57029] [SVR] OnReadCommissioningInfo ICD - IdleModeDuration=0 activeModeDuration=0 activeModeThreshold=0
[1759488704.750] [57027:57029] [CTL] Successfully finished commissioning step 'ReadCommissioningInfo2'
[1759488704.750] [57027:57029] [CTL] Commissioning stage next step: 'ReadCommissioningInfo2' -> 'ArmFailSafe'
[1759488704.750] [57027:57029] [CTL] Performing next commissioning step 'ArmFailSafe'
[1759488704.750] [57027:57029] [CTL] Arming failsafe (60 seconds)
[1759488704.750] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488704.750] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488704.750] [57027:57029] [EM] <<< [E:29400i S:50153 M:145504453] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
[1759488704.750] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488704.831] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488704.833] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.833] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.833] [57027:57029] [EM] >>> [E:29400i S:50153 M:58084348] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1759488704.833] [57027:57029] [EM] Found matching exchange: 29400i, Delegate: 0xffffa40081c8
[1759488704.833] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488704.833] [57027:57029] [DMG] InvokeResponseMessage =
[1759488704.833] [57027:57029] [DMG] {
[1759488704.833] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488704.833] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488704.833] [57027:57029] [DMG] 	[
[1759488704.833] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488704.833] [57027:57029] [DMG] 		{
[1759488704.833] [57027:57029] [DMG] 			CommandDataIB =
[1759488704.833] [57027:57029] [DMG] 			{
[1759488704.833] [57027:57029] [DMG] 				CommandPathIB =
[1759488704.833] [57027:57029] [DMG] 				{
[1759488704.833] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488704.833] [57027:57029] [DMG] 					ClusterId = 0x30,
[1759488704.834] [57027:57029] [DMG] 					CommandId = 0x1,
[1759488704.834] [57027:57029] [DMG] 				},
[1759488704.834] [57027:57029] [DMG] 				
[1759488704.834] [57027:57029] [DMG] 				CommandFields = 
[1759488704.834] [57027:57029] [DMG] 				{
[1759488704.834] [57027:57029] [DMG] 					0x0 = 0 (unsigned), 
[1759488704.834] [57027:57029] [DMG] 					0x1 = "" (0 chars), 
[1759488704.834] [57027:57029] [DMG] 				},
[1759488704.834] [57027:57029] [DMG] 			},
[1759488704.834] [57027:57029] [DMG] 			
[1759488704.834] [57027:57029] [DMG] 		},
[1759488704.834] [57027:57029] [DMG] 		
[1759488704.834] [57027:57029] [DMG] 	],
[1759488704.834] [57027:57029] [DMG] 	
[1759488704.834] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488704.834] [57027:57029] [DMG] },
[1759488704.834] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1759488704.834] [57027:57029] [CTL] Received ArmFailSafe response errorCode=0
[1759488704.834] [57027:57029] [CTL] Successfully finished commissioning step 'ArmFailSafe'
[1759488704.834] [57027:57029] [CTL] Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1759488704.834] [57027:57029] [CTL] Performing next commissioning step 'ConfigRegulatory'
[1759488704.834] [57027:57029] [CTL] Setting Regulatory Config
[1759488704.834] [57027:57029] [CTL] Device does not support configurable regulatory location
[1759488704.834] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488704.834] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488704.834] [57027:57029] [EM] <<< [E:29401i S:50153 M:145504454] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:70)
[1759488704.835] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488704.835] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488704.921] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488704.923] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488704.923] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488704.923] [57027:57029] [EM] >>> [E:29401i S:50153 M:58084349] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1759488704.923] [57027:57029] [EM] Found matching exchange: 29401i, Delegate: 0xffffa4008378
[1759488704.923] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488704.923] [57027:57029] [DMG] InvokeResponseMessage =
[1759488704.923] [57027:57029] [DMG] {
[1759488704.923] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488704.923] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488704.923] [57027:57029] [DMG] 	[
[1759488704.923] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488704.923] [57027:57029] [DMG] 		{
[1759488704.923] [57027:57029] [DMG] 			CommandDataIB =
[1759488704.923] [57027:57029] [DMG] 			{
[1759488704.923] [57027:57029] [DMG] 				CommandPathIB =
[1759488704.923] [57027:57029] [DMG] 				{
[1759488704.923] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488704.923] [57027:57029] [DMG] 					ClusterId = 0x30,
[1759488704.923] [57027:57029] [DMG] 					CommandId = 0x3,
[1759488704.923] [57027:57029] [DMG] 				},
[1759488704.924] [57027:57029] [DMG] 				
[1759488704.924] [57027:57029] [DMG] 				CommandFields = 
[1759488704.924] [57027:57029] [DMG] 				{
[1759488704.924] [57027:57029] [DMG] 					0x0 = 0 (unsigned), 
[1759488704.924] [57027:57029] [DMG] 					0x1 = "" (0 chars), 
[1759488704.924] [57027:57029] [DMG] 				},
[1759488704.924] [57027:57029] [DMG] 			},
[1759488704.924] [57027:57029] [DMG] 			
[1759488704.924] [57027:57029] [DMG] 		},
[1759488704.924] [57027:57029] [DMG] 		
[1759488704.924] [57027:57029] [DMG] 	],
[1759488704.924] [57027:57029] [DMG] 	
[1759488704.924] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488704.924] [57027:57029] [DMG] },
[1759488704.924] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1759488704.924] [57027:57029] [CTL] Received SetRegulatoryConfig response errorCode=0
[1759488704.924] [57027:57029] [CTL] Successfully finished commissioning step 'ConfigRegulatory'
[1759488704.924] [57027:57029] [CTL] Commissioning stage next step: 'ConfigRegulatory' -> 'ConfigureTCAcknowledgments'
[1759488704.924] [57027:57029] [CTL] Performing next commissioning step 'ConfigureTCAcknowledgments'
[1759488704.924] [57027:57029] [CTL] Setting Terms and Conditions
[1759488704.924] [57027:57029] [CTL] Setting Terms and Conditions: Skipped
[1759488704.924] [57027:57029] [CTL] Successfully finished commissioning step 'ConfigureTCAcknowledgments'
[1759488704.924] [57027:57029] [CTL] Commissioning stage next step: 'ConfigureTCAcknowledgments' -> 'SendPAICertificateRequest'
[1759488704.924] [57027:57029] [CTL] Performing next commissioning step 'SendPAICertificateRequest'
[1759488704.924] [57027:57029] [CTL] Sending request for PAI certificate
[1759488704.924] [57027:57029] [CTL] Sending Certificate Chain request to 0xffffa400b720 device
[1759488704.925] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488704.925] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488704.925] [57027:57029] [EM] <<< [E:29402i S:50153 M:145504455] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[1759488704.925] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488704.925] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488705.011] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488705.015] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.015] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.104] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.104] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.192] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.192] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.192] [57027:57029] [EM] >>> [E:29402i S:50153 M:58084350] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:527)
[1759488705.192] [57027:57029] [EM] Found matching exchange: 29402i, Delegate: 0xffffa40081c8
[1759488705.192] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488705.192] [57027:57029] [DMG] InvokeResponseMessage =
[1759488705.192] [57027:57029] [DMG] {
[1759488705.192] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488705.192] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488705.192] [57027:57029] [DMG] 	[
[1759488705.192] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488705.192] [57027:57029] [DMG] 		{
[1759488705.192] [57027:57029] [DMG] 			CommandDataIB =
[1759488705.193] [57027:57029] [DMG] 			{
[1759488705.193] [57027:57029] [DMG] 				CommandPathIB =
[1759488705.193] [57027:57029] [DMG] 				{
[1759488705.193] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488705.193] [57027:57029] [DMG] 					ClusterId = 0x3e,
[1759488705.193] [57027:57029] [DMG] 					CommandId = 0x3,
[1759488705.193] [57027:57029] [DMG] 				},
[1759488705.193] [57027:57029] [DMG] 				
[1759488705.193] [57027:57029] [DMG] 				CommandFields = 
[1759488705.193] [57027:57029] [DMG] 				{
[1759488705.193] [57027:57029] [DMG] 					0x0 = [
[1759488705.193] [57027:57029] [DMG] 							0x30, 0x82, 0x01, 0xcb, 0x30, 0x82, 0x01, 0x71, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x56, 0xad, 0x82, 0x22, 0xad, 0x94, 0x5b, 0x64, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x30, 0x31, 0x18, 0x30, 0x16, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x0f, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x54, 0x65, 0x73, 0x74, 0x20, 0x50, 0x41, 0x41, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x41, 0x9a, 0x93, 0x15, 0xc2, 0x17, 0x3e, 0x0c, 0x8c, 0x87, 0x6d, 0x03, 0xcc, 0xfc, 0x94, 0x48, 0x52, 0x64, 0x7f, 0x7f, 0xec, 0x5e, 0x50, 0x82, 0xf4, 0x05, 0x99, 0x28, 0xec, 0xa8, 0x94, 0xc5, 0x94, 0x15, 0x13, 0x09, 0xac, 0x63, 0x1e, 0x4c, 0xb0, 0x33, 0x92, 0xaf, 0x68, 0x4b, 0x0b, 0xaf, 0xb7, 0xe6, 0x5b, 0x3b, 0x81, 0x62, 0xc2, 0xf5, 0x2b, 0xf9, 0x31, 0xb8, 0xe7, 0x7a, 0xaa, 0x82, 0xa3, 0x66, 0x30, 0x64, 0x30, 0x12, 0x06, 0x03, 0x55, 0x1d, 0x
[1759488705.193] [57027:57029] [DMG] 					] (463 bytes)
[1759488705.193] [57027:57029] [DMG] 				},
[1759488705.193] [57027:57029] [DMG] 			},
[1759488705.193] [57027:57029] [DMG] 			
[1759488705.193] [57027:57029] [DMG] 		},
[1759488705.193] [57027:57029] [DMG] 		
[1759488705.193] [57027:57029] [DMG] 	],
[1759488705.193] [57027:57029] [DMG] 	
[1759488705.193] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488705.193] [57027:57029] [DMG] },
[1759488705.193] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1759488705.193] [57027:57029] [CTL] Received certificate chain from the device
[1759488705.193] [57027:57029] [CTL] Successfully finished commissioning step 'SendPAICertificateRequest'
[1759488705.193] [57027:57029] [CTL] Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1759488705.193] [57027:57029] [CTL] Performing next commissioning step 'SendDACCertificateRequest'
[1759488705.193] [57027:57029] [CTL] Sending request for DAC certificate
[1759488705.193] [57027:57029] [CTL] Sending Certificate Chain request to 0xffffa400b720 device
[1759488705.194] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488705.194] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488705.194] [57027:57029] [EM] <<< [E:29403i S:50153 M:145504456] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[1759488705.194] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488705.194] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488705.326] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488705.330] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.330] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.420] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.420] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.507] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.507] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.507] [57027:57029] [EM] >>> [E:29403i S:50153 M:58084351] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:555)
[1759488705.507] [57027:57029] [EM] Found matching exchange: 29403i, Delegate: 0xffffa4008378
[1759488705.508] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488705.508] [57027:57029] [DMG] InvokeResponseMessage =
[1759488705.508] [57027:57029] [DMG] {
[1759488705.508] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488705.508] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488705.508] [57027:57029] [DMG] 	[
[1759488705.508] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488705.508] [57027:57029] [DMG] 		{
[1759488705.508] [57027:57029] [DMG] 			CommandDataIB =
[1759488705.508] [57027:57029] [DMG] 			{
[1759488705.508] [57027:57029] [DMG] 				CommandPathIB =
[1759488705.508] [57027:57029] [DMG] 				{
[1759488705.508] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488705.508] [57027:57029] [DMG] 					ClusterId = 0x3e,
[1759488705.508] [57027:57029] [DMG] 					CommandId = 0x3,
[1759488705.508] [57027:57029] [DMG] 				},
[1759488705.508] [57027:57029] [DMG] 				
[1759488705.508] [57027:57029] [DMG] 				CommandFields = 
[1759488705.508] [57027:57029] [DMG] 				{
[1759488705.508] [57027:57029] [DMG] 					0x0 = [
[1759488705.508] [57027:57029] [DMG] 							0x30, 0x82, 0x01, 0xe7, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x46, 0x7f, 0x57, 0x62, 0xc8, 0xdc, 0x90, 0xd5, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x33, 0x33, 0x31, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x53, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x44, 0x41, 0x43, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x2f, 0x30, 0x78, 0x38, 0x30, 0x31, 0x30, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x02, 0x0c, 0x04, 0x38, 0x30, 0x31, 0x30, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x39, 0xef, 0x6c, 0x9d, 0x9c, 0x99, 0x7b, 0xa2, 0xc7, 0x31, 0x9a, 0x4c, 0x73, 0xc9, 0xbf, 0x47, 0xdb, 0xcd, 0xbc, 0x42, 0xc5, 0x41, 0x3e, 0xec, 0x14, 0x52, 0x75, 0xb8, 0x8f, 0xc1, 0x1a, 0xb1, 0xad, 0x0b, 0xc3, 0x3e, 0xf1, 0x4c, 0x27, 0x
[1759488705.508] [57027:57029] [DMG] 					] (491 bytes)
[1759488705.508] [57027:57029] [DMG] 				},
[1759488705.508] [57027:57029] [DMG] 			},
[1759488705.508] [57027:57029] [DMG] 			
[1759488705.508] [57027:57029] [DMG] 		},
[1759488705.508] [57027:57029] [DMG] 		
[1759488705.508] [57027:57029] [DMG] 	],
[1759488705.508] [57027:57029] [DMG] 	
[1759488705.508] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488705.508] [57027:57029] [DMG] },
[1759488705.508] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1759488705.509] [57027:57029] [CTL] Received certificate chain from the device
[1759488705.509] [57027:57029] [CTL] Successfully finished commissioning step 'SendDACCertificateRequest'
[1759488705.509] [57027:57029] [CTL] Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1759488705.509] [57027:57029] [CTL] Performing next commissioning step 'SendAttestationRequest'
[1759488705.509] [57027:57029] [CTL] Sending Attestation Request to the device.
[1759488705.509] [57027:57029] [CTL] Sending Attestation request to 0xffffa400b720 device
[1759488705.509] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488705.509] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488705.509] [57027:57029] [EM] <<< [E:29404i S:50153 M:145504457] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
[1759488705.509] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488705.509] [57027:57029] [CTL] Sent Attestation request, waiting for the Attestation Information
[1759488705.509] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488705.596] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488705.644] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.644] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.734] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.734] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.824] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488705.824] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488705.824] [57027:57029] [EM] >>> [E:29404i S:50153 M:58084352] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:716)
[1759488705.824] [57027:57029] [EM] Found matching exchange: 29404i, Delegate: 0xffffa40081c8
[1759488705.825] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488705.825] [57027:57029] [DMG] InvokeResponseMessage =
[1759488705.825] [57027:57029] [DMG] {
[1759488705.825] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488705.825] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488705.825] [57027:57029] [DMG] 	[
[1759488705.825] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488705.825] [57027:57029] [DMG] 		{
[1759488705.825] [57027:57029] [DMG] 			CommandDataIB =
[1759488705.825] [57027:57029] [DMG] 			{
[1759488705.825] [57027:57029] [DMG] 				CommandPathIB =
[1759488705.825] [57027:57029] [DMG] 				{
[1759488705.825] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488705.825] [57027:57029] [DMG] 					ClusterId = 0x3e,
[1759488705.825] [57027:57029] [DMG] 					CommandId = 0x1,
[1759488705.825] [57027:57029] [DMG] 				},
[1759488705.825] [57027:57029] [DMG] 				
[1759488705.825] [57027:57029] [DMG] 				CommandFields = 
[1759488705.825] [57027:57029] [DMG] 				{
[1759488705.825] [57027:57029] [DMG] 					0x0 = [
[1759488705.825] [57027:57029] [DMG] 							0x15, 0x31, 0x01, 0x1d, 0x02, 0x30, 0x82, 0x02, 0x19, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x82, 0x02, 0x0a, 0x30, 0x82, 0x02, 0x06, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x82, 0x01, 0x71, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x82, 0x01, 0x62, 0x04, 0x82, 0x01, 0x5e, 0x15, 0x24, 0x00, 0x01, 0x25, 0x01, 0xf1, 0xff, 0x36, 0x02, 0x05, 0x00, 0x80, 0x05, 0x01, 0x80, 0x05, 0x02, 0x80, 0x05, 0x03, 0x80, 0x05, 0x04, 0x80, 0x05, 0x05, 0x80, 0x05, 0x06, 0x80, 0x05, 0x07, 0x80, 0x05, 0x08, 0x80, 0x05, 0x09, 0x80, 0x05, 0x0a, 0x80, 0x05, 0x0b, 0x80, 0x05, 0x0c, 0x80, 0x05, 0x0d, 0x80, 0x05, 0x0e, 0x80, 0x05, 0x0f, 0x80, 0x05, 0x10, 0x80, 0x05, 0x11, 0x80, 0x05, 0x12, 0x80, 0x05, 0x13, 0x80, 0x05, 0x14, 0x80, 0x05, 0x15, 0x80, 0x05, 0x16, 0x80, 0x05, 0x17, 0x80, 0x05, 0x18, 0x80, 0x05, 0x19, 0x80, 0x05, 0x1a, 0x80, 0x05, 0x1b, 0x80, 0x05, 0x1c, 0x80, 0x05, 0x1d, 0x80, 0x05, 0x1e, 0x80, 0x05, 0x1f, 0x80, 0x05, 0x20, 0x80, 0x05, 0x21, 0x80, 0x05, 0x22, 0x80, 0x05, 0x23, 0x80, 0x05, 0x24, 0x80, 0x05, 0x25, 0x80, 0x05, 0x26, 0x80, 0x05, 0x27, 0x80, 0x05, 0x28, 0x80, 0x05, 0x29, 0x80, 0x05, 0x2a, 0x80, 0x05, 0x2b, 0x80, 0x05, 0x2c, 0x80, 0x05, 0x2d, 0x80, 0x05, 0x2e, 0x80, 0x05, 0x2f, 0x80, 0x05, 0x30, 0x80, 0x05, 0x31, 0x80, 0x05, 0x32, 0x80, 0x05, 0x33, 0x80, 0x05, 0x34, 0x80, 0x05, 0x35, 0x80, 0x05, 0x36, 0x80, 0x05, 0x37, 0x80, 0x05, 0x38, 0x80, 0x05, 0x39, 0x80, 0x05, 0x3a, 0x80, 0x05, 0x3b, 0x80, 0x05, 0x3c, 0x80, 0x05, 0x3d, 0x80, 0x05, 0x3e, 0x80, 0x05, 0x3f, 0x80, 0x05, 0x40, 0x80, 0x05, 0x41, 0x80, 0x05, 0x42, 0x80, 0x05, 0x43, 0x80, 0x
[1759488705.825] [57027:57029] [DMG] 					] (585 bytes)
[1759488705.825] [57027:57029] [DMG] 					0x1 = [
[1759488705.825] [57027:57029] [DMG] 							0xd1, 0x20, 0x17, 0xb9, 0x4c, 0xfb, 0x55, 0xda, 0xc2, 0x8d, 0x97, 0x30, 0xdf, 0x7b, 0x16, 0x69, 0xf7, 0x9c, 0x07, 0x0d, 0xc5, 0xaf, 0xb0, 0xe3, 0xc8, 0xea, 0xaf, 0x22, 0x25, 0xaa, 0x0b, 0x34, 0x5b, 0x42, 0xa6, 0xf2, 0x05, 0xda, 0x56, 0x95, 0xc4, 0x1a, 0x9f, 0x1d, 0x1b, 0x53, 0xd7, 0xc9, 0x87, 0x2d, 0xc5, 0xdd, 0xa5, 0x17, 0x92, 0x67, 0x6e, 0x90, 0xb0, 0xb4, 0x81, 0x47, 0x6e, 0xa1, 
[1759488705.825] [57027:57029] [DMG] 					] (64 bytes)
[1759488705.825] [57027:57029] [DMG] 				},
[1759488705.825] [57027:57029] [DMG] 			},
[1759488705.825] [57027:57029] [DMG] 			
[1759488705.825] [57027:57029] [DMG] 		},
[1759488705.825] [57027:57029] [DMG] 		
[1759488705.825] [57027:57029] [DMG] 	],
[1759488705.825] [57027:57029] [DMG] 	
[1759488705.826] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488705.826] [57027:57029] [DMG] },
[1759488705.826] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1759488705.826] [57027:57029] [CTL] Received Attestation Information from the device
[1759488705.826] [57027:57029] [CTL] Successfully finished commissioning step 'SendAttestationRequest'
[1759488705.826] [57027:57029] [CTL] AutoCommissioner setting attestationElements buffer size 585/585
[1759488705.826] [57027:57029] [CTL] Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1759488705.826] [57027:57029] [CTL] Performing next commissioning step 'AttestationVerification'
[1759488705.826] [57027:57029] [CTL] Verifying attestation
[1759488705.838] [57027:57029] [CTL] Successfully finished commissioning step 'AttestationVerification'
[1759488705.838] [57027:57029] [CTL] Commissioning stage next step: 'AttestationVerification' -> 'AttestationRevocationCheck'
[1759488705.838] [57027:57029] [CTL] Performing next commissioning step 'AttestationRevocationCheck'
[1759488705.838] [57027:57029] [CTL] Verifying device's DAC chain revocation status
[1759488705.838] [57027:57029] [CTL] Successfully validated 'Attestation Information' command received from the device.
[1759488705.838] [57027:57029] [CTL] Successfully finished commissioning step 'AttestationRevocationCheck'
[1759488705.838] [57027:57029] [CTL] Commissioning stage next step: 'AttestationRevocationCheck' -> 'SendOpCertSigningRequest'
[1759488705.838] [57027:57029] [CTL] Performing next commissioning step 'SendOpCertSigningRequest'
[1759488705.838] [57027:57029] [CTL] Sending CSR request to 0xffffa400b720 device
[1759488705.838] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488705.838] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488705.838] [57027:57029] [EM] <<< [E:29405i S:50153 M:145504458] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
[1759488705.838] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488705.838] [57027:57029] [CTL] Sent CSR request, waiting for the CSR
[1759488705.838] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488705.911] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488706.004] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488706.005] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488706.093] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488706.093] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488706.093] [57027:57029] [EM] >>> [E:29405i S:50153 M:58084353] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:392)
[1759488706.093] [57027:57029] [EM] Found matching exchange: 29405i, Delegate: 0xffffa4008378
[1759488706.093] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488706.094] [57027:57029] [DMG] InvokeResponseMessage =
[1759488706.094] [57027:57029] [DMG] {
[1759488706.094] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488706.094] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488706.094] [57027:57029] [DMG] 	[
[1759488706.094] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488706.094] [57027:57029] [DMG] 		{
[1759488706.094] [57027:57029] [DMG] 			CommandDataIB =
[1759488706.094] [57027:57029] [DMG] 			{
[1759488706.094] [57027:57029] [DMG] 				CommandPathIB =
[1759488706.094] [57027:57029] [DMG] 				{
[1759488706.094] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488706.094] [57027:57029] [DMG] 					ClusterId = 0x3e,
[1759488706.094] [57027:57029] [DMG] 					CommandId = 0x5,
[1759488706.094] [57027:57029] [DMG] 				},
[1759488706.094] [57027:57029] [DMG] 				
[1759488706.094] [57027:57029] [DMG] 				CommandFields = 
[1759488706.094] [57027:57029] [DMG] 				{
[1759488706.094] [57027:57029] [DMG] 					0x0 = [
[1759488706.094] [57027:57029] [DMG] 							0x15, 0x30, 0x01, 0xdd, 0x30, 0x81, 0xda, 0x30, 0x81, 0x81, 0x02, 0x01, 0x00, 0x30, 0x0e, 0x31, 0x0c, 0x30, 0x0a, 0x06, 0x03, 0x55, 0x04, 0x0b, 0x0c, 0x03, 0x43, 0x53, 0x41, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x22, 0x7b, 0x30, 0x5b, 0xd9, 0x5a, 0xdb, 0x36, 0x0f, 0x49, 0x7c, 0x88, 0x91, 0x58, 0x43, 0x7c, 0x0e, 0x64, 0x0d, 0x61, 0xa0, 0xc5, 0x48, 0xd2, 0x5f, 0x2f, 0x89, 0x42, 0xdd, 0x96, 0x6f, 0x42, 0x0e, 0x3a, 0x86, 0x44, 0x47, 0x55, 0x3f, 0x4b, 0x4f, 0x6f, 0x5f, 0x9a, 0x4b, 0x89, 0xcb, 0x4d, 0xcc, 0x32, 0x46, 0x2b, 0xe9, 0x10, 0xd0, 0x1d, 0x25, 0xc8, 0xdc, 0x69, 0xe0, 0x08, 0xd2, 0x9a, 0xa0, 0x11, 0x30, 0x0f, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x09, 0x0e, 0x31, 0x02, 0x30, 0x00, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x03, 0x48, 0x00, 0x30, 0x45, 0x02, 0x21, 0x00, 0xaa, 0x6c, 0x3c, 0x41, 0x57, 0x68, 0x79, 0x82, 0xd5, 0x4c, 0x0e, 0x33, 0x1a, 0x8d, 0x28, 0x19, 0xf1, 0xff, 0xc2, 0x0b, 0xfd, 0x4b, 0x4b, 0x3f, 0xa0, 0x35, 0xff, 0x23, 0x78, 0x1a, 0xc4, 0xb4, 0x02, 0x20, 0x75, 0xb9, 0xbe, 0xc6, 0xec, 0x44, 0x9a, 0x85, 0x42, 0x42, 0xcb, 0xfb, 0xb1, 0x9c, 0xf8, 0x4f, 0xed, 0xc6, 0x7f, 0x29, 0x3b, 0x69, 0x99, 0x9e, 0x87, 0x73, 0xb7, 0x70, 0x4c, 0x88, 0x7a, 0x69, 0x30, 0x02, 0x20, 0xc4, 0xf4, 0xa4, 0x19, 0xf1, 0xf8, 0x9e, 0xf2, 0xd6, 0x2a, 0x96, 0xf1, 0x5b, 0xf6, 0x1a, 0xa1, 0xc2, 0xe3, 0x15, 0x31, 0x6b, 0x40, 0x49, 0x5e, 0x86, 0x02, 0x96, 0x60, 0x14, 0xb3, 0x24, 0x26, 0x18, 
[1759488706.094] [57027:57029] [DMG] 					] (261 bytes)
[1759488706.094] [57027:57029] [DMG] 					0x1 = [
[1759488706.094] [57027:57029] [DMG] 							0x31, 0xd3, 0xe9, 0x75, 0x1a, 0x56, 0xb1, 0x77, 0x79, 0x09, 0xb5, 0xbf, 0x85, 0xfc, 0x2d, 0x74, 0x16, 0x81, 0x1a, 0x29, 0x02, 0xef, 0xac, 0xaa, 0xea, 0x2f, 0x37, 0xb6, 0xe5, 0x13, 0xcd, 0xa3, 0x6b, 0x4b, 0xc0, 0x62, 0x5f, 0x43, 0xd1, 0x5a, 0x65, 0xc7, 0x79, 0x15, 0xd5, 0x58, 0x4c, 0xe2, 0x8e, 0x64, 0x90, 0x94, 0xdd, 0xf1, 0xfb, 0x0f, 0x6e, 0x60, 0x0b, 0xbd, 0x40, 0x2a, 0xc8, 0xa8, 
[1759488706.094] [57027:57029] [DMG] 					] (64 bytes)
[1759488706.094] [57027:57029] [DMG] 				},
[1759488706.094] [57027:57029] [DMG] 			},
[1759488706.094] [57027:57029] [DMG] 			
[1759488706.095] [57027:57029] [DMG] 		},
[1759488706.095] [57027:57029] [DMG] 		
[1759488706.095] [57027:57029] [DMG] 	],
[1759488706.095] [57027:57029] [DMG] 	
[1759488706.095] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488706.095] [57027:57029] [DMG] },
[1759488706.095] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1759488706.095] [57027:57029] [CTL] Received certificate signing request from the device
[1759488706.095] [57027:57029] [CTL] Successfully finished commissioning step 'SendOpCertSigningRequest'
[1759488706.095] [57027:57029] [CTL] Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
[1759488706.095] [57027:57029] [CTL] Performing next commissioning step 'ValidateCSR'
[1759488706.097] [57027:57029] [CTL] Successfully finished commissioning step 'ValidateCSR'
[1759488706.097] [57027:57029] [CTL] Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
[1759488706.097] [57027:57029] [CTL] Performing next commissioning step 'GenerateNOCChain'
[1759488706.097] [57027:57029] [CTL] Getting certificate chain for the device from the issuer
[1759488706.099] [57027:57029] [CTL] Verifying Certificate Signing Request
[1759488706.100] [57027:57029] [CTL] Generating NOC
[1759488706.100] [57027:57029] [CTL] Providing certificate chain to the commissioner
[1759488706.100] [57027:57029] [CTL] Received callback from the CA for NOC Chain generation. Status src/controller/ExampleOperationalCredentialsIssuer.cpp:395: Success
[1759488706.100] [57027:57029] [CTL] Successfully finished commissioning step 'GenerateNOCChain'
[1759488706.100] [57027:57029] [CTL] Performing next commissioning step 'SendTrustedRootCert'
[1759488706.100] [57027:57029] [CTL] Sending root certificate to the device
[1759488706.100] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488706.100] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488706.100] [57027:57029] [EM] <<< [E:29406i S:50153 M:145504459] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:293)
[1759488706.100] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488706.100] [57027:57029] [CTL] Sent root certificate to the device
[1759488706.101] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488706.181] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488706.271] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488706.317] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488706.317] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488706.317] [57027:57029] [EM] >>> [E:29406i S:50153 M:58084354] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
[1759488706.317] [57027:57029] [EM] Found matching exchange: 29406i, Delegate: 0xffffa40081c8
[1759488706.318] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488706.318] [57027:57029] [DMG] InvokeResponseMessage =
[1759488706.318] [57027:57029] [DMG] {
[1759488706.318] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488706.318] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488706.318] [57027:57029] [DMG] 	[
[1759488706.318] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488706.318] [57027:57029] [DMG] 		{
[1759488706.318] [57027:57029] [DMG] 			CommandStatusIB =
[1759488706.318] [57027:57029] [DMG] 			{
[1759488706.318] [57027:57029] [DMG] 				CommandPathIB =
[1759488706.318] [57027:57029] [DMG] 				{
[1759488706.318] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488706.318] [57027:57029] [DMG] 					ClusterId = 0x3e,
[1759488706.318] [57027:57029] [DMG] 					CommandId = 0xb,
[1759488706.318] [57027:57029] [DMG] 				},
[1759488706.318] [57027:57029] [DMG] 				
[1759488706.318] [57027:57029] [DMG] 				StatusIB =
[1759488706.318] [57027:57029] [DMG] 				{
[1759488706.318] [57027:57029] [DMG] 					status = 0x00 (SUCCESS),
[1759488706.318] [57027:57029] [DMG] 				},
[1759488706.318] [57027:57029] [DMG] 				
[1759488706.318] [57027:57029] [DMG] 			},
[1759488706.318] [57027:57029] [DMG] 			
[1759488706.318] [57027:57029] [DMG] 		},
[1759488706.318] [57027:57029] [DMG] 		
[1759488706.318] [57027:57029] [DMG] 	],
[1759488706.318] [57027:57029] [DMG] 	
[1759488706.318] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488706.318] [57027:57029] [DMG] },
[1759488706.319] [57027:57029] [DMG] Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1759488706.319] [57027:57029] [CTL] Device confirmed that it has received the root certificate
[1759488706.319] [57027:57029] [CTL] Successfully finished commissioning step 'SendTrustedRootCert'
[1759488706.319] [57027:57029] [CTL] Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1759488706.319] [57027:57029] [CTL] Performing next commissioning step 'SendNOC'
[1759488706.319] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488706.319] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488706.319] [57027:57029] [EM] <<< [E:29407i S:50153 M:145504460] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:566)
[1759488706.319] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488706.319] [57027:57029] [CTL] Sent operational certificate to the device
[1759488706.319] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488706.451] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488706.541] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488706.631] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488706.812] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488706.812] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488706.813] [57027:57029] [EM] >>> [E:29407i S:50153 M:58084355] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1759488706.813] [57027:57029] [EM] Found matching exchange: 29407i, Delegate: 0xffffa4008378
[1759488706.813] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488706.813] [57027:57029] [DMG] InvokeResponseMessage =
[1759488706.813] [57027:57029] [DMG] {
[1759488706.813] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488706.813] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488706.813] [57027:57029] [DMG] 	[
[1759488706.813] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488706.813] [57027:57029] [DMG] 		{
[1759488706.813] [57027:57029] [DMG] 			CommandDataIB =
[1759488706.813] [57027:57029] [DMG] 			{
[1759488706.813] [57027:57029] [DMG] 				CommandPathIB =
[1759488706.813] [57027:57029] [DMG] 				{
[1759488706.813] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488706.813] [57027:57029] [DMG] 					ClusterId = 0x3e,
[1759488706.813] [57027:57029] [DMG] 					CommandId = 0x8,
[1759488706.813] [57027:57029] [DMG] 				},
[1759488706.813] [57027:57029] [DMG] 				
[1759488706.813] [57027:57029] [DMG] 				CommandFields = 
[1759488706.813] [57027:57029] [DMG] 				{
[1759488706.813] [57027:57029] [DMG] 					0x0 = 0 (unsigned), 
[1759488706.813] [57027:57029] [DMG] 					0x1 = 1 (unsigned), 
[1759488706.813] [57027:57029] [DMG] 				},
[1759488706.813] [57027:57029] [DMG] 			},
[1759488706.813] [57027:57029] [DMG] 			
[1759488706.813] [57027:57029] [DMG] 		},
[1759488706.813] [57027:57029] [DMG] 		
[1759488706.813] [57027:57029] [DMG] 	],
[1759488706.813] [57027:57029] [DMG] 	
[1759488706.813] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488706.813] [57027:57029] [DMG] },
[1759488706.813] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1759488706.814] [57027:57029] [CTL] Device returned status 0 on receiving the NOC
[1759488706.814] [57027:57029] [CTL] Operational credentials provisioned on device 0xffffa400b720
[1759488706.814] [57027:57029] [TOO] Secure Pairing Success
[1759488706.814] [57027:57029] [TOO] CASE establishment successful
[1759488706.814] [57027:57029] [CTL] Successfully finished commissioning step 'SendNOC'
[1759488706.814] [57027:57029] [CTL] No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks
[1759488706.814] [57027:57029] [CTL] Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup'
[1759488706.814] [57027:57029] [CTL] Performing next commissioning step 'ThreadNetworkSetup'
[1759488706.814] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488706.814] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488706.814] [57027:57029] [EM] <<< [E:29408i S:50153 M:145504461] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:160)
[1759488706.814] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488706.814] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488706.901] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488706.903] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488706.903] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488706.903] [57027:57029] [EM] >>> [E:29408i S:50153 M:58084356] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1759488706.903] [57027:57029] [EM] Found matching exchange: 29408i, Delegate: 0xffffa40081c8
[1759488706.903] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488706.903] [57027:57029] [DMG] InvokeResponseMessage =
[1759488706.903] [57027:57029] [DMG] {
[1759488706.903] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488706.903] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488706.903] [57027:57029] [DMG] 	[
[1759488706.903] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488706.903] [57027:57029] [DMG] 		{
[1759488706.903] [57027:57029] [DMG] 			CommandDataIB =
[1759488706.903] [57027:57029] [DMG] 			{
[1759488706.903] [57027:57029] [DMG] 				CommandPathIB =
[1759488706.903] [57027:57029] [DMG] 				{
[1759488706.903] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488706.903] [57027:57029] [DMG] 					ClusterId = 0x31,
[1759488706.903] [57027:57029] [DMG] 					CommandId = 0x5,
[1759488706.903] [57027:57029] [DMG] 				},
[1759488706.903] [57027:57029] [DMG] 				
[1759488706.904] [57027:57029] [DMG] 				CommandFields = 
[1759488706.904] [57027:57029] [DMG] 				{
[1759488706.904] [57027:57029] [DMG] 					0x0 = 0 (unsigned), 
[1759488706.904] [57027:57029] [DMG] 					0x2 = 0 (unsigned), 
[1759488706.904] [57027:57029] [DMG] 				},
[1759488706.904] [57027:57029] [DMG] 			},
[1759488706.904] [57027:57029] [DMG] 			
[1759488706.904] [57027:57029] [DMG] 		},
[1759488706.904] [57027:57029] [DMG] 		
[1759488706.904] [57027:57029] [DMG] 	],
[1759488706.904] [57027:57029] [DMG] 	
[1759488706.904] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488706.904] [57027:57029] [DMG] },
[1759488706.904] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1759488706.904] [57027:57029] [CTL] Received NetworkConfig response, networkingStatus=0
[1759488706.904] [57027:57029] [CTL] Successfully finished commissioning step 'ThreadNetworkSetup'
[1759488706.904] [57027:57029] [CTL] Commissioning stage next step: 'ThreadNetworkSetup' -> 'FailsafeBeforeThreadEnable'
[1759488706.904] [57027:57029] [CTL] Performing next commissioning step 'FailsafeBeforeThreadEnable'
[1759488706.904] [57027:57029] [CTL] Arming failsafe (101 seconds)
[1759488706.904] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488706.904] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488706.904] [57027:57029] [EM] <<< [E:29409i S:50153 M:145504462] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
[1759488706.905] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488706.905] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488706.991] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488706.993] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488706.993] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488706.993] [57027:57029] [EM] >>> [E:29409i S:50153 M:58084357] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1759488706.993] [57027:57029] [EM] Found matching exchange: 29409i, Delegate: 0xffffa4008378
[1759488706.993] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488706.993] [57027:57029] [DMG] InvokeResponseMessage =
[1759488706.993] [57027:57029] [DMG] {
[1759488706.993] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488706.993] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488706.993] [57027:57029] [DMG] 	[
[1759488706.993] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488706.993] [57027:57029] [DMG] 		{
[1759488706.993] [57027:57029] [DMG] 			CommandDataIB =
[1759488706.993] [57027:57029] [DMG] 			{
[1759488706.993] [57027:57029] [DMG] 				CommandPathIB =
[1759488706.993] [57027:57029] [DMG] 				{
[1759488706.993] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488706.993] [57027:57029] [DMG] 					ClusterId = 0x30,
[1759488706.993] [57027:57029] [DMG] 					CommandId = 0x1,
[1759488706.993] [57027:57029] [DMG] 				},
[1759488706.994] [57027:57029] [DMG] 				
[1759488706.994] [57027:57029] [DMG] 				CommandFields = 
[1759488706.994] [57027:57029] [DMG] 				{
[1759488706.994] [57027:57029] [DMG] 					0x0 = 0 (unsigned), 
[1759488706.994] [57027:57029] [DMG] 					0x1 = "" (0 chars), 
[1759488706.994] [57027:57029] [DMG] 				},
[1759488706.994] [57027:57029] [DMG] 			},
[1759488706.994] [57027:57029] [DMG] 			
[1759488706.994] [57027:57029] [DMG] 		},
[1759488706.994] [57027:57029] [DMG] 		
[1759488706.994] [57027:57029] [DMG] 	],
[1759488706.994] [57027:57029] [DMG] 	
[1759488706.994] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488706.994] [57027:57029] [DMG] },
[1759488706.994] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1759488706.994] [57027:57029] [CTL] Received ArmFailSafe response errorCode=0
[1759488706.994] [57027:57029] [CTL] Successfully finished commissioning step 'FailsafeBeforeThreadEnable'
[1759488706.994] [57027:57029] [CTL] Commissioning stage next step: 'FailsafeBeforeThreadEnable' -> 'ThreadNetworkEnable'
[1759488706.994] [57027:57029] [CTL] Performing next commissioning step 'ThreadNetworkEnable'
[1759488706.994] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488706.994] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488706.994] [57027:57029] [EM] <<< [E:29410i S:50153 M:145504463] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:73)
[1759488706.995] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488706.995] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488707.081] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488708.478] [57027:57028] [DL] Indication received, conn = 0xffffac043900
[1759488708.478] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16391
[1759488708.478] [57027:57029] [EM] >>> [E:29410i S:50153 M:58084358] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:65)
[1759488708.478] [57027:57029] [EM] Found matching exchange: 29410i, Delegate: 0xffffa40081c8
[1759488708.478] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488708.478] [57027:57029] [DMG] InvokeResponseMessage =
[1759488708.478] [57027:57029] [DMG] {
[1759488708.478] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488708.478] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488708.478] [57027:57029] [DMG] 	[
[1759488708.478] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488708.478] [57027:57029] [DMG] 		{
[1759488708.478] [57027:57029] [DMG] 			CommandDataIB =
[1759488708.478] [57027:57029] [DMG] 			{
[1759488708.478] [57027:57029] [DMG] 				CommandPathIB =
[1759488708.478] [57027:57029] [DMG] 				{
[1759488708.478] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488708.478] [57027:57029] [DMG] 					ClusterId = 0x31,
[1759488708.478] [57027:57029] [DMG] 					CommandId = 0x7,
[1759488708.478] [57027:57029] [DMG] 				},
[1759488708.478] [57027:57029] [DMG] 				
[1759488708.478] [57027:57029] [DMG] 				CommandFields = 
[1759488708.478] [57027:57029] [DMG] 				{
[1759488708.478] [57027:57029] [DMG] 					0x0 = 0 (unsigned), 
[1759488708.479] [57027:57029] [DMG] 					0x2 = NULL
[1759488708.479] [57027:57029] [DMG] 				},
[1759488708.479] [57027:57029] [DMG] 			},
[1759488708.479] [57027:57029] [DMG] 			
[1759488708.479] [57027:57029] [DMG] 		},
[1759488708.479] [57027:57029] [DMG] 		
[1759488708.479] [57027:57029] [DMG] 	],
[1759488708.479] [57027:57029] [DMG] 	
[1759488708.479] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488708.479] [57027:57029] [DMG] },
[1759488708.479] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1759488708.479] [57027:57029] [CTL] Received ConnectNetwork response, networkingStatus=0
[1759488708.479] [57027:57029] [CTL] Successfully finished commissioning step 'ThreadNetworkEnable'
[1759488708.479] [57027:57029] [CTL] Commissioning stage next step: 'ThreadNetworkEnable' -> 'kEvictPreviousCaseSessions'
[1759488708.479] [57027:57029] [CTL] Performing next commissioning step 'kEvictPreviousCaseSessions'
[1759488708.479] [57027:57029] [IN] Expiring all sessions for node <0000000000000001, 1>!!
[1759488708.479] [57027:57029] [CTL] Successfully finished commissioning step 'kEvictPreviousCaseSessions'
[1759488708.479] [57027:57029] [CTL] Commissioning stage next step: 'kEvictPreviousCaseSessions' -> 'kFindOperationalForStayActive'
[1759488708.479] [57027:57029] [CTL] Performing next commissioning step 'kFindOperationalForStayActive'
[1759488708.479] [57027:57029] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1759488708.479] [57027:57029] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1759488708.479] [57027:57029] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1759488708.479] [57027:57029] [DIS] Resolving D51E2C5F40271BF8:0000000000000001 ...
[1759488708.480] [57027:57029] [DIS] Lookup started for D51E2C5F40271BF8-0000000000000001
[1759488708.480] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488708.679] [57027:57029] [DIS] Checking node lookup status for D51E2C5F40271BF8-0000000000000001 after 200 ms
[1759488710.526] [57027:57029] [DL] Avahi resolve found
[1759488710.526] [57027:57029] [DIS] Node ID resolved for D51E2C5F40271BF8-0000000000000001
[1759488710.526] [57027:57029] [DIS] 	Hostname: 3EC80D8801039003
[1759488710.526] [57027:57029] [DIS] 	IP Address #1: fd11:35::5946:3209:d5c:dc69
[1759488710.526] [57027:57029] [DIS] 	Port: 5540
[1759488710.526] [57027:57029] [DIS] 	Mrp Interval idle: 2500 ms
[1759488710.526] [57027:57029] [DIS] 	Mrp Interval active: 2500 ms
[1759488710.526] [57027:57029] [DIS] 	Mrp Active Threshold: 300 ms
[1759488710.526] [57027:57029] [DIS] 	TCP Client Supported: 0
[1759488710.527] [57027:57029] [DIS] 	TCP Server Supported: 0
[1759488710.527] [57027:57029] [DIS] 	ICD: not present
[1759488710.527] [57027:57029] [DIS] Lookup clearing interface for non LL address
[1759488710.527] [57027:57029] [DIS] UDP:[fd11:35::5946:3209:d5c:dc69%eth0]:5540: new best score: 5 (for D51E2C5F40271BF8-0000000000000001)
[1759488710.527] [57027:57029] [DIS] Checking node lookup status for D51E2C5F40271BF8-0000000000000001 after 2048 ms
[1759488710.527] [57027:57029] [DIS] OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd11:35::5946:3209:d5c:dc69]:5540 while in state 2
[1759488710.527] [57027:57029] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
[1759488710.528] [57027:57029] [IN] SecureSession[0xffffa4028ce0]: Allocated Type:2 LSID:50154
[1759488710.528] [57027:57029] [SC] Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
[1759488710.528] [57027:57029] [EM] <<< [E:29411i S:0 M:151048958] (U) Msg TX from 519D8030E5153634 to 0:0000000000000000 [0000] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
[1759488710.528] [57027:57029] [EM] ??1 [E:29411i S:0 M:151048958] (U) Msg Retransmission to 0:0000000000000000 in 3309ms [State:Idle II:2500 AI:2500 AT:300]
[1759488710.528] [57027:57029] [SC] Sent Sigma1 msg to <0000000000000001, 1> [II:500ms AI:300ms AT:4000ms]
[1759488710.528] [57027:57029] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
[1759488710.938] [57027:57029] [EM] >>> [E:29411i S:0 M:16472188 (Ack:151048958)] (U) Msg RX from 0:0000000000000000 [0000] to 519D8030E5153634 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[1759488710.938] [57027:57029] [EM] Found matching exchange: 29411i, Delegate: 0xffffa4010ba8
[1759488710.938] [57027:57029] [EM] Rxd Ack; Removing MessageCounter:151048958 from Retrans Table on exchange 29411i
[1759488711.041] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16389
[1759488711.124] [57027:57029] [EM] >>> [E:29411i S:0 M:16472189 (Ack:151048958)] (U) Msg RX from 0:0000000000000000 [0000] to 519D8030E5153634 --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751)
[1759488711.124] [57027:57029] [EM] Found matching exchange: 29411i, Delegate: 0xffffa4010ba8
[1759488711.124] [57027:57029] [EM] CHIP MessageCounter:151048958 not in RetransTable on exchange 29411i
[1759488711.124] [57027:57029] [SC] Received Sigma2 msg
[1759488711.124] [57027:57029] [SC] Peer assigned session session ID 19559
[1759488711.127] [57027:57029] [SC] Found MRP parameters in the message
[1759488711.127] [57027:57029] [SC] Sending Sigma3
[1759488711.127] [57027:57029] [EM] <<< [E:29411i S:0 M:151048959 (Ack:16472189)] (U) Msg TX from 519D8030E5153634 to 0:0000000000000000 [0000] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598)
[1759488711.127] [57027:57029] [EM] ??1 [E:29411i S:0 M:151048959] (U) Msg Retransmission to 0:0000000000000000 in 3137ms [State:Active II:2500 AI:2500 AT:300]
[1759488711.127] [57027:57029] [SC] Sent Sigma3 msg
[1759488711.611] [57027:57029] [EM] >>> [E:29411i S:0 M:16472190 (Ack:151048959)] (U) Msg RX from 0:0000000000000000 [0000] to 519D8030E5153634 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[1759488711.611] [57027:57029] [EM] Found matching exchange: 29411i, Delegate: 0xffffa4010ba8
[1759488711.611] [57027:57029] [EM] Rxd Ack; Removing MessageCounter:151048959 from Retrans Table on exchange 29411i
[1759488711.825] [57027:57029] [EM] >>> [E:29411i S:0 M:16472191 (Ack:151048959)] (U) Msg RX from 0:0000000000000000 [0000] to 519D8030E5153634 --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
[1759488711.825] [57027:57029] [EM] Found matching exchange: 29411i, Delegate: 0xffffa4010ba8
[1759488711.825] [57027:57029] [EM] CHIP MessageCounter:151048959 not in RetransTable on exchange 29411i
[1759488711.825] [57027:57029] [SC] Success status report received. Session was established
[1759488711.832] [57027:57029] [SC] SecureSession[0xffffa4028ce0, LSID:50154]: State change 'kEstablishing' --> 'kActive'
[1759488711.832] [57027:57029] [IN] SecureSession[0xffffa4028ce0]: Activated - Type:2 LSID:50154
[1759488711.832] [57027:57029] [IN] New secure session activated for device <0000000000000001, 1>, LSID:50154 PSID:19559!
[1759488711.832] [57027:57029] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5
[1759488711.832] [57027:57029] [CTL] Successfully finished commissioning step 'kFindOperationalForStayActive'
[1759488711.832] [57027:57029] [CTL] Commissioning stage next step: 'kFindOperationalForStayActive' -> 'ICDSendStayActive'
[1759488711.832] [57027:57029] [CTL] Performing next commissioning step 'ICDSendStayActive'
[1759488711.832] [57027:57029] [CTL] Skipping kICDSendStayActive
[1759488711.832] [57027:57029] [CTL] Successfully finished commissioning step 'ICDSendStayActive'
[1759488711.832] [57027:57029] [CTL] Commissioning stage next step: 'ICDSendStayActive' -> 'kFindOperationalForCommissioningComplete'
[1759488711.832] [57027:57029] [CTL] Performing next commissioning step 'kFindOperationalForCommissioningComplete'
[1759488711.832] [57027:57029] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1759488711.833] [57027:57029] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1759488711.833] [57027:57029] [DIS] Found an existing secure session to [1:0000000000000001]!
[1759488711.833] [57027:57029] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1759488711.833] [57027:57029] [CTL] Successfully finished commissioning step 'kFindOperationalForCommissioningComplete'
[1759488711.833] [57027:57029] [CTL] Commissioning stage next step: 'kFindOperationalForCommissioningComplete' -> 'SendComplete'
[1759488711.833] [57027:57029] [CTL] Performing next commissioning step 'SendComplete'
[1759488711.833] [57027:57029] [DMG] ICR moving to [AddingComm]
[1759488711.833] [57027:57029] [DMG] ICR moving to [AddedComma]
[1759488711.833] [57027:57029] [EM] <<< [E:29412i S:50154 M:100165583] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [1BF8] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:59)
[1759488711.833] [57027:57029] [EM] ??1 [E:29412i S:50154 M:100165583] (S) Msg Retransmission to 1:0000000000000001 in 3051ms [State:Active II:2500 AI:2500 AT:300]
[1759488711.833] [57027:57029] [DMG] ICR moving to [AwaitingRe]
[1759488711.833] [57027:57029] [EM] <<< [E:29411i S:0 M:151048960 (Ack:16472191)] (U) Msg TX from 519D8030E5153634 to 0:0000000000000000 [0000] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[1759488711.833] [57027:57029] [EM] Flushed pending ack for MessageCounter:16472191 on exchange 29411i
[1759488711.833] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 32792
[1759488711.974] [57027:57029] [EM] >>> [E:29412i S:50154 M:211630120 (Ack:100165583)] (S) Msg RX from 1:0000000000000001 [1BF8] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
[1759488711.974] [57027:57029] [EM] Found matching exchange: 29412i, Delegate: 0xffffa40081c8
[1759488711.974] [57027:57029] [EM] Rxd Ack; Removing MessageCounter:100165583 from Retrans Table on exchange 29412i
[1759488711.974] [57027:57029] [DMG] ICR moving to [ResponseRe]
[1759488711.974] [57027:57029] [DMG] InvokeResponseMessage =
[1759488711.974] [57027:57029] [DMG] {
[1759488711.974] [57027:57029] [DMG] 	suppressResponse = false, 
[1759488711.974] [57027:57029] [DMG] 	InvokeResponseIBs =
[1759488711.974] [57027:57029] [DMG] 	[
[1759488711.974] [57027:57029] [DMG] 		InvokeResponseIB =
[1759488711.974] [57027:57029] [DMG] 		{
[1759488711.974] [57027:57029] [DMG] 			CommandDataIB =
[1759488711.974] [57027:57029] [DMG] 			{
[1759488711.974] [57027:57029] [DMG] 				CommandPathIB =
[1759488711.974] [57027:57029] [DMG] 				{
[1759488711.974] [57027:57029] [DMG] 					EndpointId = 0x0,
[1759488711.974] [57027:57029] [DMG] 					ClusterId = 0x30,
[1759488711.974] [57027:57029] [DMG] 					CommandId = 0x5,
[1759488711.974] [57027:57029] [DMG] 				},
[1759488711.974] [57027:57029] [DMG] 				
[1759488711.974] [57027:57029] [DMG] 				CommandFields = 
[1759488711.974] [57027:57029] [DMG] 				{
[1759488711.974] [57027:57029] [DMG] 					0x0 = 0 (unsigned), 
[1759488711.974] [57027:57029] [DMG] 					0x1 = "" (0 chars), 
[1759488711.974] [57027:57029] [DMG] 				},
[1759488711.974] [57027:57029] [DMG] 			},
[1759488711.974] [57027:57029] [DMG] 			
[1759488711.974] [57027:57029] [DMG] 		},
[1759488711.974] [57027:57029] [DMG] 		
[1759488711.974] [57027:57029] [DMG] 	],
[1759488711.974] [57027:57029] [DMG] 	
[1759488711.974] [57027:57029] [DMG] 	InteractionModelRevision = 12
[1759488711.975] [57027:57029] [DMG] },
[1759488711.975] [57027:57029] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
[1759488711.975] [57027:57029] [CTL] Received CommissioningComplete response, errorCode=0
[1759488711.975] [57027:57029] [CTL] Successfully finished commissioning step 'SendComplete'
[1759488711.975] [57027:57029] [CTL] Commissioning stage next step: 'SendComplete' -> 'Cleanup'
[1759488711.975] [57027:57029] [CTL] Performing next commissioning step 'Cleanup'
[1759488711.975] [57027:57029] [CTL] Successfully finished commissioning step 'Cleanup'
[1759488711.975] [57027:57029] [DIS] Closing all BLE connections
[1759488711.975] [57027:57029] [IN] Clearing BLE pending packets.
[1759488711.975] [57027:57029] [BLE] Auto-closing end point's BLE connection.
[1759488711.975] [57027:57029] [DL] Closing BLE GATT connection (con 0xffffac043900)
[1759488711.975] [57027:57028] [DL] Close BLE connection: peer=E5:10:37:A3:C7:80
[1759488712.302] [57027:57029] [IN] SecureSession[0xffffa4000da0]: MarkForEviction Type:1 LSID:50153
[1759488712.302] [57027:57029] [SC] SecureSession[0xffffa4000da0, LSID:50153]: State change 'kActive' --> 'kPendingEviction'
[1759488712.302] [57027:57029] [IN] SecureSession[0xffffa4000da0]: Released - Type:1 LSID:50153
[1759488712.303] [57027:57029] [CTL] Commissioning complete for node ID 0x0000000000000001: success
[1759488712.303] [57027:57029] [TOO] Device commissioning completed with success
[1759488712.303] [57027:57028] [DL] BLE connection closed: conn=0xffffac043900
[1759488712.303] [57027:57029] [DMG] ICR moving to [AwaitingDe]
[1759488712.303] [57027:57029] [EM] <<< [E:29412i S:50154 M:100165584 (Ack:211630120)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [1BF8] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1759488712.303] [57027:57029] [EM] Flushed pending ack for MessageCounter:211630120 on exchange 29412i
[1759488712.303] [57027:57029] [DL] HandlePlatformSpecificBLEEvent 16390
[1759488712.303] [57027:57029] [BLE] No endpoint for unsubscribe complete
[1759488712.303] [57027:57029] [BLE] No endpoint for connection error
[1759488712.303] [57027:57027] [CTL] Shutting down the commissioner
[1759488712.303] [57027:57027] [CTL] Shutting down the controller
[1759488712.303] [57027:57027] [IN] Expiring all sessions for fabric 0x1!!
[1759488712.303] [57027:57027] [IN] SecureSession[0xffffa4028ce0]: MarkForEviction Type:2 LSID:50154
[1759488712.303] [57027:57027] [SC] SecureSession[0xffffa4028ce0, LSID:50154]: State change 'kActive' --> 'kPendingEviction'
[1759488712.303] [57027:57027] [IN] SecureSession[0xffffa4028ce0]: Released - Type:2 LSID:50154
[1759488712.303] [57027:57027] [FP] Forgetting fabric 0x1
[1759488712.303] [57027:57027] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1759488712.303] [57027:57027] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1759488712.303] [57027:57027] [TS] Reverted Last Known Good Time to previous value
[1759488712.303] [57027:57027] [CTL] Shutting down the commissioner
[1759488712.303] [57027:57027] [CTL] Shutting down the controller
[1759488712.303] [57027:57027] [CTL] Shutting down the System State, this will teardown the CHIP Stack
[1759488712.303] [57027:57027] [DMG] All ReadHandler-s are clean, clear GlobalDirtySet
[1759488712.303] [57027:57027] [FP] Shutting down FabricTable
[1759488712.303] [57027:57027] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1759488712.304] [57027:57027] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1759488712.304] [57027:57027] [TS] Reverted Last Known Good Time to previous value
[1759488712.317] [57027:57027] [DL] Wrote settings to /tmp/chip_counters.ini
[1759488712.317] [57027:57027] [DL] NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1759488712.317] [57027:57027] [DL] Inet Layer shutdown
[1759488712.317] [57027:57027] [DL] BLE Layer shutdown
[1759488712.318] [57027:57027] [DL] System Layer shutdown
ubuntu@ubuntu:~$ ./apps/chip-tool carbondioxideconcentrationmeasurement read feature-map 1 2
[1759488731.617] [57037:57037] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1759488731.617] [57037:57037] [DL] ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1759488731.620] [57037:57037] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1759488731.620] [57037:57037] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1759488731.620] [57037:57037] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1759488731.636] [57037:57037] [DL] Wrote settings to /tmp/chip_counters.ini
[1759488731.636] [57037:57037] [DL] NVS set: chip-counters/reboot-count = 27 (0x1B)
[1759488731.636] [57037:57037] [DL] Got Ethernet interface: eth0
[1759488731.637] [57037:57037] [DL] Found the primary Ethernet interface:eth0
[1759488731.637] [57037:57037] [DL] Got WiFi interface: wlan0
[1759488731.637] [57037:57037] [DL] Failed to reset WiFi statistic counts
[1759488731.637] [57037:57037] [IN] UDP::Init bind&listen port=0
[1759488731.637] [57037:57037] [IN] UDP::Init bound to port=49706
[1759488731.637] [57037:57037] [IN] BLEBase::Init - setting/overriding transport
[1759488731.637] [57037:57037] [IN] TransportMgr initialized
[1759488731.637] [57037:57037] [FP] Initializing FabricTable from persistent storage
[1759488731.637] [57037:57037] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1759488731.638] [57037:57037] [FP] Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xD51E2C5F40271BF8, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1759488731.644] [57037:57037] [ZCL] Using ZAP configuration...
[1759488731.646] [57037:57037] [DL] Avahi client registered
[1759488731.646] [57037:57037] [IM] WARNING ┌────────────────────────────────────────────────────
[1759488731.646] [57037:57037] [IM] WARNING │ Interaction Model Engine running in 'Checked' mode.
[1759488731.646] [57037:57037] [IM] WARNING │ This executes BOTH ember and data-model code paths.
[1759488731.646] [57037:57037] [IM] WARNING │ which is inefficient and consumes more flash space.
[1759488731.646] [57037:57037] [IM] WARNING │ This should be done for testing only.
[1759488731.646] [57037:57037] [IM] WARNING └────────────────────────────────────────────────────
[1759488731.646] [57037:57037] [CTL] System State Initialized...
[1759488731.646] [57037:57037] [CTL] Setting attestation nonce to random value
[1759488731.646] [57037:57037] [CTL] Setting CSR nonce to random value
[1759488731.646] [57037:57037] [IN] UDP::Init bind&listen port=5550
[1759488731.646] [57037:57037] [IN] UDP::Init bound to port=5550
[1759488731.646] [57037:57037] [IN] TransportMgr initialized
[1759488731.646] [57037:57039] [DL] CHIP task running
[1759488731.647] [57037:57039] [DL] HandlePlatformSpecificBLEEvent 32786
[1759488731.647] [57037:57039] [CTL] Setting attestation nonce to random value
[1759488731.647] [57037:57039] [CTL] Setting CSR nonce to random value
[1759488731.647] [57037:57039] [CTL] Generating NOC
[1759488731.648] [57037:57039] [FP] Validating NOC chain
[1759488731.649] [57037:57039] [FP] NOC chain validation successful
[1759488731.649] [57037:57039] [FP] Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1759488731.649] [57037:57039] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1759488731.649] [57037:57039] [TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
[1759488731.649] [57037:57039] [TS] Retaining current Last Known Good Time
[1759488731.653] [57037:57039] [FP] Metadata for Fabric 0x1 persisted to storage.
[1759488731.654] [57037:57039] [TS] Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1759488731.656] [57037:57039] [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: D51E2C5F40271BF8)
[1759488731.656] [57037:57039] [IN] UDP::Init bind&listen port=5550
[1759488731.656] [57037:57039] [IN] UDP::Init bound to port=5550
[1759488731.656] [57037:57039] [IN] TransportMgr initialized
[1759488731.668] [57037:57039] [TOO] Sending command to node 0x1
[1759488731.668] [57037:57039] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1759488731.668] [57037:57039] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1759488731.669] [57037:57039] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1759488731.669] [57037:57039] [DIS] Resolving D51E2C5F40271BF8:0000000000000001 ...
[1759488731.669] [57037:57039] [DIS] Lookup started for D51E2C5F40271BF8-0000000000000001
[1759488731.669] [57037:57039] [DL] Avahi resolve found
[1759488731.669] [57037:57039] [DIS] Node ID resolved for D51E2C5F40271BF8-0000000000000001
[1759488731.669] [57037:57039] [DIS] 	Hostname: 3EC80D8801039003
[1759488731.669] [57037:57039] [DIS] 	IP Address #1: fd11:35::5946:3209:d5c:dc69
[1759488731.669] [57037:57039] [DIS] 	Port: 5540
[1759488731.669] [57037:57039] [DIS] 	Mrp Interval idle: 2500 ms
[1759488731.669] [57037:57039] [DIS] 	Mrp Interval active: 2500 ms
[1759488731.669] [57037:57039] [DIS] 	Mrp Active Threshold: 300 ms
[1759488731.669] [57037:57039] [DIS] 	TCP Client Supported: 0
[1759488731.669] [57037:57039] [DIS] 	TCP Server Supported: 0
[1759488731.669] [57037:57039] [DIS] 	ICD: not present
[1759488731.670] [57037:57039] [DIS] Lookup clearing interface for non LL address
[1759488731.670] [57037:57039] [DIS] UDP:[fd11:35::5946:3209:d5c:dc69%veth3d7c5e7]:5540: new best score: 5 (for D51E2C5F40271BF8-0000000000000001)
[1759488731.670] [57037:57039] [DIS] Checking node lookup status for D51E2C5F40271BF8-0000000000000001 after 2 ms
[1759488731.670] [57037:57039] [DIS] Keeping DNSSD lookup active
[1759488731.868] [57037:57039] [DIS] Checking node lookup status for D51E2C5F40271BF8-0000000000000001 after 200 ms
[1759488731.869] [57037:57039] [DIS] OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd11:35::5946:3209:d5c:dc69]:5540 while in state 2
[1759488731.869] [57037:57039] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
[1759488731.869] [57037:57039] [IN] SecureSession[0xffffa000bc50]: Allocated Type:2 LSID:52273
[1759488731.869] [57037:57039] [SC] Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
[1759488731.869] [57037:57039] [EM] <<< [E:42061i S:0 M:112816515] (U) Msg TX from A78BC73DC7FFFACA to 0:0000000000000000 [0000] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
[1759488731.869] [57037:57039] [EM] ??1 [E:42061i S:0 M:112816515] (U) Msg Retransmission to 0:0000000000000000 in 3277ms [State:Idle II:2500 AI:2500 AT:300]
[1759488731.869] [57037:57039] [SC] Sent Sigma1 msg to <0000000000000001, 1> [II:500ms AI:300ms AT:4000ms]
[1759488731.869] [57037:57039] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
[1759488732.435] [57037:57039] [EM] >>> [E:42061i S:0 M:16472192 (Ack:112816515)] (U) Msg RX from 0:0000000000000000 [0000] to A78BC73DC7FFFACA --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[1759488732.436] [57037:57039] [EM] Found matching exchange: 42061i, Delegate: 0xffffa000b968
[1759488732.436] [57037:57039] [EM] Rxd Ack; Removing MessageCounter:112816515 from Retrans Table on exchange 42061i
[1759488732.614] [57037:57039] [EM] >>> [E:42061i S:0 M:16472193 (Ack:112816515)] (U) Msg RX from 0:0000000000000000 [0000] to A78BC73DC7FFFACA --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751)
[1759488732.614] [57037:57039] [EM] Found matching exchange: 42061i, Delegate: 0xffffa000b968
[1759488732.614] [57037:57039] [EM] CHIP MessageCounter:112816515 not in RetransTable on exchange 42061i
[1759488732.614] [57037:57039] [SC] Received Sigma2 msg
[1759488732.614] [57037:57039] [SC] Peer assigned session session ID 19560
[1759488732.617] [57037:57039] [SC] Found MRP parameters in the message
[1759488732.617] [57037:57039] [SC] Sending Sigma3
[1759488732.617] [57037:57039] [EM] <<< [E:42061i S:0 M:112816516 (Ack:16472193)] (U) Msg TX from A78BC73DC7FFFACA to 0:0000000000000000 [0000] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598)
[1759488732.617] [57037:57039] [EM] ??1 [E:42061i S:0 M:112816516] (U) Msg Retransmission to 0:0000000000000000 in 2777ms [State:Active II:2500 AI:2500 AT:300]
[1759488732.617] [57037:57039] [SC] Sent Sigma3 msg
[1759488733.358] [57037:57039] [EM] >>> [E:42061i S:0 M:16472194 (Ack:112816516)] (U) Msg RX from 0:0000000000000000 [0000] to A78BC73DC7FFFACA --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[1759488733.358] [57037:57039] [EM] Found matching exchange: 42061i, Delegate: 0xffffa000b968
[1759488733.358] [57037:57039] [EM] Rxd Ack; Removing MessageCounter:112816516 from Retrans Table on exchange 42061i
[1759488733.558] [57037:57039] [EM] >>> [E:42061i S:0 M:16472195 (Ack:112816516)] (U) Msg RX from 0:0000000000000000 [0000] to A78BC73DC7FFFACA --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
[1759488733.558] [57037:57039] [EM] Found matching exchange: 42061i, Delegate: 0xffffa000b968
[1759488733.558] [57037:57039] [EM] CHIP MessageCounter:112816516 not in RetransTable on exchange 42061i
[1759488733.558] [57037:57039] [SC] Success status report received. Session was established
[1759488733.565] [57037:57039] [SC] SecureSession[0xffffa000bc50, LSID:52273]: State change 'kEstablishing' --> 'kActive'
[1759488733.565] [57037:57039] [IN] SecureSession[0xffffa000bc50]: Activated - Type:2 LSID:52273
[1759488733.565] [57037:57039] [IN] New secure session activated for device <0000000000000001, 1>, LSID:52273 PSID:19560!
[1759488733.565] [57037:57039] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5
[1759488733.565] [57037:57039] [TOO] Sending ReadAttribute to:
[1759488733.566] [57037:57039] [TOO] 	cluster 0x0000_040D, attribute: 0x0000_FFFC, endpoint 2
[1759488733.566] [57037:57039] [DMG] SendReadRequest ReadClient[0xffffa000a060]: Sending Read Request
[1759488733.566] [57037:57039] [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
[1759488733.566] [57037:57039] [EM] <<< [E:42062i S:52273 M:78757880] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [1BF8] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0001:02 (IM:ReadRequest) (B:53)
[1759488733.566] [57037:57039] [EM] ??1 [E:42062i S:52273 M:78757880] (S) Msg Retransmission to 1:0000000000000001 in 2804ms [State:Active II:2500 AI:2500 AT:300]
[1759488733.566] [57037:57039] [DMG] MoveToState ReadClient[0xffffa000a060]: Moving to [AwaitingIn]
[1759488733.566] [57037:57039] [EM] <<< [E:42061i S:0 M:112816517 (Ack:16472195)] (U) Msg TX from A78BC73DC7FFFACA to 0:0000000000000000 [0000] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[1759488733.566] [57037:57039] [EM] Flushed pending ack for MessageCounter:16472195 on exchange 42061i
[1759488733.566] [57037:57039] [DL] HandlePlatformSpecificBLEEvent 32792
[1759488733.913] [57037:57039] [EM] >>> [E:42062i S:52273 M:23047878 (Ack:78757880)] (S) Msg RX from 1:0000000000000001 [1BF8] to 000000000001B669 --- Type 0001:05 (IM:ReportData) (B:69)
[1759488733.913] [57037:57039] [EM] Found matching exchange: 42062i, Delegate: 0xffffa000a070
[1759488733.913] [57037:57039] [EM] Rxd Ack; Removing MessageCounter:78757880 from Retrans Table on exchange 42062i
[1759488733.913] [57037:57039] [DMG] ReportDataMessage =
[1759488733.913] [57037:57039] [DMG] {
[1759488733.913] [57037:57039] [DMG] 	AttributeReportIBs =
[1759488733.913] [57037:57039] [DMG] 	[
[1759488733.913] [57037:57039] [DMG] 		AttributeReportIB =
[1759488733.913] [57037:57039] [DMG] 		{
[1759488733.913] [57037:57039] [DMG] 			AttributeStatusIB =
[1759488733.913] [57037:57039] [DMG] 			{
[1759488733.913] [57037:57039] [DMG] 				AttributePathIB =
[1759488733.913] [57037:57039] [DMG] 				{
[1759488733.913] [57037:57039] [DMG] 					Endpoint = 0x2,
[1759488733.913] [57037:57039] [DMG] 					Cluster = 0x40d,
[1759488733.913] [57037:57039] [DMG] 					Attribute = 0x0000_FFFC,
[1759488733.913] [57037:57039] [DMG] 				}
[1759488733.913] [57037:57039] [DMG] 					
[1759488733.913] [57037:57039] [DMG] 				StatusIB =
[1759488733.913] [57037:57039] [DMG] 				{
[1759488733.913] [57037:57039] [DMG] 					status = 0x01 (FAILURE),
[1759488733.913] [57037:57039] [DMG] 				},
[1759488733.913] [57037:57039] [DMG] 				
[1759488733.913] [57037:57039] [DMG] 			},
[1759488733.913] [57037:57039] [DMG] 			
[1759488733.913] [57037:57039] [DMG] 		},
[1759488733.913] [57037:57039] [DMG] 		
[1759488733.913] [57037:57039] [DMG] 	],
[1759488733.914] [57037:57039] [DMG] 	
[1759488733.914] [57037:57039] [DMG] 	SuppressResponse = true, 
[1759488733.914] [57037:57039] [DMG] 	InteractionModelRevision = 12
[1759488733.914] [57037:57039] [DMG] }
[1759488733.914] [57037:57039] [TOO] Response Failure: IM Error 0x00000501: General error: 0x01 (FAILURE)
[1759488733.914] [57037:57039] [EM] <<< [E:42062i S:52273 M:78757881 (Ack:23047878)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [1BF8] [UDP:[fd11:35::5946:3209:d5c:dc69]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1759488733.914] [57037:57039] [EM] Flushed pending ack for MessageCounter:23047878 on exchange 42062i
[1759488733.914] [57037:57037] [CTL] Shutting down the commissioner
[1759488733.914] [57037:57037] [CTL] Shutting down the controller
[1759488733.914] [57037:57037] [IN] Expiring all sessions for fabric 0x1!!
[1759488733.914] [57037:57037] [IN] SecureSession[0xffffa000bc50]: MarkForEviction Type:2 LSID:52273
[1759488733.914] [57037:57037] [SC] SecureSession[0xffffa000bc50, LSID:52273]: State change 'kActive' --> 'kPendingEviction'
[1759488733.914] [57037:57037] [IN] SecureSession[0xffffa000bc50]: Released - Type:2 LSID:52273
[1759488733.914] [57037:57037] [FP] Forgetting fabric 0x1
[1759488733.914] [57037:57037] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1759488733.914] [57037:57037] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1759488733.914] [57037:57037] [TS] Reverted Last Known Good Time to previous value
[1759488733.914] [57037:57037] [CTL] Shutting down the commissioner
[1759488733.914] [57037:57037] [CTL] Shutting down the controller
[1759488733.914] [57037:57037] [CTL] Shutting down the System State, this will teardown the CHIP Stack
[1759488733.915] [57037:57037] [DMG] All ReadHandler-s are clean, clear GlobalDirtySet
[1759488733.915] [57037:57037] [FP] Shutting down FabricTable
[1759488733.915] [57037:57037] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1759488733.915] [57037:57037] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1759488733.915] [57037:57037] [TS] Reverted Last Known Good Time to previous value
[1759488733.925] [57037:57037] [DL] Wrote settings to /tmp/chip_counters.ini
[1759488733.925] [57037:57037] [DL] NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1759488733.925] [57037:57037] [DL] Inet Layer shutdown
[1759488733.925] [57037:57037] [DL] BLE Layer shutdown
[1759488733.925] [57037:57037] [DL] System Layer shutdown
[1759488733.925] [57037:57037] [TOO] Run command failure: IM Error 0x00000501: General error: 0x01 (FAILURE)
ubuntu@ubuntu:~$ 

Here is the log from chip-tool. I run chip-tool that is included with the TH to be sure the versions all match. The log includes the commissioning part just in case. The status is always 0x01 (FAILURE) when the attribute is set to External and when I set it to RAM (through direct manipulation of the generated sources) it works as expected.

Tiit

[Marte Myrvold]

Hi Tiit,

You are correct that my description of External was incorrect.. External means that it is application-managed, that is, that you are expected to provide the implementation for handling the attribute in the application.

I checked internally, and apparently, there was a bug in ZAP tool versions older than 2025.5.14. It appears that the storage option can be changed, but for certain attributes, it should be locked to "External." This has been fixed in the 2025.5.14 ZAP tool release.

So, if an attribute is External, it should stay as External, and you should set the value at initialization using Set(). For example, in emberAfCarbonDioxideConcentrationMeasurementClusterInitCallback(), you can add something like this:

void emberAfCarbonDioxideConcentrationMeasurementClusterInitCallback(chip::EndpointId endpoint)
{
	const auto logOnFailure = [](Protocols::InteractionModel::Status status, const char *attributeName) {
		if (status != Protocols::InteractionModel::Status::Success) {
			ChipLogError(Zcl, "Failed to set CarbonDioxideConcentrationMeasurement %s: %x", attributeName, to_underlying(status));
		}
	};

	Protocols::InteractionModel::Status status;

	uint32_t featureMap;
    
    status = CarbonDioxideConcentrationMeasurement::Attributes::FeatureMap::Get(endpoint, &featureMap);
	if (Protocols::InteractionModel::Status::Success == status) {
		logOnFailure(CarbonDioxideConcentrationMeasurement::Attributes::FeatureMap::Set(endpoint, 1),
			     "feature map");
	}

}

Best regards,
Marte

[Tiit]

Hi Marte,

Being in the hurry I am I actually somehow got this to compile and pass the TH tests I have tried inhouse for now. ZAP tool is still incredibly unstable and can't do that but I can manually edit the files and that seems to at least satisfy the tests.

The code example you sent is actually something I did try. And just o be sure I'm not missing anything I just tried it again. What I always run into is this:

namespace "chip::app::Clusters::CarbonDioxideConcentrationMeasurement::Attributes::FeatureMap" has no member "Get"C/C++(135)

CarbonDioxideConcentrationMeasurement::Attributes::FeatureMap (and MeasuredValue, maybe more attributes) only have Id and TypeInfo. No other members. And this is also an issue that I want to solve at some point as currently we have no way of updating the CO2 sensor value in Matter. Temperature and Humidity Clusters seem similar in layout and they do have members to get and set values.

Tiit

[Marte Myrvold]

Hi Tiit,

Good to hear that you got it to compile and pass the TH tests.

I tested again, and you are correct that the Get() and Set() functions do not work.

I believe the problem is that the FeatureMap attribute in CarbonDioxideConcentrationMeasurement does not have Set() and Get() functions, as you can see here:
https://github.com/nrfconnect/sdk-connectedhomeip/blob/v3.1.1/zzz_generated/app-common/app-common/zap-generated/attributes/Accessors.h#L4841-L4851.

The same is true for the MeasuredValue attribute in the same cluster.

However, an API was added for the cluster some time ago: https://github.com/project-chip/connectedhomeip/pull/28576/commits. As part of this, the all-clusters-app was updated to show how to use the API, so I suggest taking a look at this: 
https://github.com/nrfconnect/sdk-connectedhomeip/blob/v3.1.1/examples/all-clusters-app/all-clusters-common/src/concentration-measurement-instances.cpp

Best regards,
Marte

[Tiit]

Hi Marte,

Thank you for leading me to the correct solution for the CarbonDioxideConcentrationMeasurement cluster. It seems that if I just ignore the ZAP tool crash and leave these attributes as external I can move forward. If they are external AND I also have this CarbonDioxideConcentrationMeasurement instance AND I have run Init() for it chip-tool can successfully read the FeatureMap and all other required attributes. And I have tested the MeasuredValue stting code as well and it seems to work. This also lead me to the correct way to use the AQI cluster which I also got to work now.

Thank you again and as far as I'm concerned the issue can be closed.

Tiit