ESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd6100,len:0x16b4 load:0x403ce000,len:0x930 load:0x403d0000,len:0x2d28 entry 0x403ce000 I (30) boot: ESP-IDF v4.4.1 2nd stage bootloader I (30) boot: compile time 08:45:10 I (30) boot: chip revision: 3 I (32) boot.esp32c3: SPI Speed : 80MHz I (37) boot.esp32c3: SPI Mode : DIO I (41) boot.esp32c3: SPI Flash Size : 4MB I (46) boot: Enabling RNG early entropy source... I (52) boot: Partition Table: I (55) boot: ## Label Usage Type ST Offset Length I (62) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (70) boot: 1 otadata OTA data 01 00 0000f000 00002000 I (77) boot: 2 phy_init RF data 01 01 00011000 00001000 I (85) boot: 3 ota_0 OTA app 00 10 00020000 00177000 I (92) boot: 4 ota_1 OTA app 00 11 001a0000 00177000 I (100) boot: 5 ot_storage Unknown data 01 3a 00317000 00002000 I (107) boot: End of partition table I (112) esp_image: segment 0: paddr=00020020 vaddr=3c110020 size=375e0h (226784) map I (155) esp_image: segment 1: paddr=00057608 vaddr=3fc8fa00 size=03918h ( 14616) load I (158) esp_image: segment 2: paddr=0005af28 vaddr=40380000 size=050f0h ( 20720) load I (165) esp_image: segment 3: paddr=00060020 vaddr=42000020 size=103034h (1060916) map I (336) esp_image: segment 4: paddr=0016305c vaddr=403850f0 size=0a890h ( 43152) load I (344) esp_image: segment 5: paddr=0016d8f4 vaddr=50000010 size=00010h ( 16) load I (349) boot: Loaded app from partition at offset 0x20000 I (349) boot: Disabling RNG early entropy source... I (365) cpu_start: Pro cpu up. I (373) cpu_start: Pro cpu start user code I (373) cpu_start: cpu freq: 160000000 I (373) cpu_start: Application information: I (376) cpu_start: Project name: chip-all-clusters-app I (382) cpu_start: App version: TE9-1148-g51e41f9df I (388) cpu_start: Compile time: Jul 15 2022 08:44:45 I (394) cpu_start: ELF file SHA256: 8d99985f3daedcc7... I (400) cpu_start: ESP-IDF: v4.4.1 I (405) heap_init: Initializing. RAM available for dynamic allocation: I (412) heap_init: At 3FCA5020 len 0001AFE0 (107 KiB): DRAM I (418) heap_init: At 3FCC0000 len 0001F060 (124 KiB): STACK/DRAM I (425) heap_init: At 50000020 len 00001FE0 (7 KiB): RTCRAM I (432) spi_flash: detected chip: generic I (436) spi_flash: flash io: dio I (441) sleep: Configure to isolate all GPIO pins in sleep state I (447) sleep: Enable automatic switching of GPIO sleep configuration I (454) coexist: coexist rom version 9387209 I (459) cpu_start: Starting scheduler. I (471) all-clusters-app: ================================================== I (471) all-clusters-app: chip-esp32-all-cluster-demo starting I (481) all-clusters-app: ================================================== I (661) pp: pp rom version: 9387209 I (661) net80211: net80211 rom version: 9387209 I (671) wifi:wifi driver task: 3fcb0154, prio:23, stack:6656, core=0 I (671) system_api: Base MAC address is not set I (681) system_api: read default base MAC address from EFUSE I (681) wifi:wifi firmware version: 63017e0 I (681) wifi:wifi certification version: v7.0 I (691) wifi:config NVS flash: enabled I (691) wifi:config nano formating: disabled I (691) wifi:Init data frame dynamic rx buffer num: 32 I (701) wifi:Init management frame dynamic rx buffer num: 32 I (701) wifi:Init management short buffer num: 32 I (701) wifi:Init dynamic tx buffer num: 32 I (711) wifi:Init static tx FG buffer num: 2 I (721) wifi:Init static rx buffer size: 1600 I (721) wifi:Init static rx buffer num: 10 I (731) wifi:Init dynamic rx buffer num: 32 I (741) wifi_init: rx ba win: 6 I (741) wifi_init: tcpip mbox: 32 I (741) wifi_init: udp mbox: 6 I (741) wifi_init: tcp mbox: 6 I (751) wifi_init: tcp tx win: 5744 I (751) wifi_init: tcp rx win: 5744 I (751) wifi_init: tcp mss: 1440 I (761) wifi_init: WiFi IRAM OP enabled I (761) wifi_init: WiFi RX IRAM OP enabled I (791) chip[DL]: NVS set: chip-counters/reboot-count = 2 (0x2) I (791) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC) I (801) all-clusters-app: ------------------------Starting App Task--------------------------- W (801) BTDM_INIT: esp_bt_controller_mem_release not implemented, return OK I (811) BTDM_INIT: BT controller compile version [d913766] I (811) phy_init: phy_version 909,156dee4,Apr 7 2022,20:27:09 I (801) app-task: This is ESP32 chip with 1 CPU cores, WiFi/BLE, > I (831) app-task: silicon revision 3, I (851) app-task: 4MB external flash I (851) chip[SVR]: SetupQRCode: [MT:-24J042C00KA0648G00] I (851) chip[SVR]: Copy/paste the below URL in a browser to see the QR Code: I (871) chip[SVR]: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J042C00KA0648G00 I (901) chip[SVR]: Manual pairing code: [34970112332] I (901) app-task: App Task started I (951) BTDM_INIT: Bluetooth MAC: 84:f7:03:60:fb:e6 I (951) NimBLE: GAP procedure initiated: stop advertising. I (961) CHIP[DL]: BLE host-controller synced I (1461) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable, device name MATTER-3840) I (1461) NimBLE: GAP procedure initiated: advertise; I (1471) NimBLE: disc_mode=2 I (1471) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (1481) NimBLE: I (1481) chip[DL]: CHIPoBLE advertising started E (1491) chip[DL]: Long dispatch time: 692 ms, for event type 2 I (1491) chip[DL]: Starting ESP WiFi layer I (1501) wifi:mode : sta (84:f7:03:60:fb:e4) I (1511) wifi:enable tsf W (1511) wifi:Haven't to connect to a suitable AP now! I (1511) chip[DL]: Done driving station state, nothing else to do... I (1521) phy: chan:1,max_power:80 I (1521) phy: chan:2,max_power:80 I (1531) phy: chan:3,max_power:80 I (1531) phy: chan:4,max_power:80 I (1531) phy: chan:5,max_power:80 I (1541) phy: chan:6,max_power:80 I (1541) phy: chan:7,max_power:80 I (1541) phy: chan:8,max_power:80 I (1551) phy: chan:9,max_power:80 I (1551) phy: chan:10,max_power:80 I (1551) phy: chan:11,max_power:80 I (1571) phy: chan:12,max_power:80 I (1571) phy: chan:13,max_power:80 I (1571) phy: chan:14,max_power:80 W (1581) wifi:Haven't to connect to a suitable AP now! I (1581) chip[DL]: Done driving station state, nothing else to do... I (1591) phy: chan:1,max_power:80 I (1591) phy: chan:2,max_power:80 I (1591) phy: chan:3,max_power:80 I (1601) phy: chan:4,max_power:80 I (1601) phy: chan:5,max_power:80 I (1601) phy: chan:6,max_power:80 I (1611) phy: chan:7,max_power:80 I (1611) phy: chan:8,max_power:80 I (1611) phy: chan:9,max_power:80 I (1621) phy: chan:10,max_power:80 I (1621) phy: chan:11,max_power:80 I (1621) phy: chan:12,max_power:80 I (1641) phy: chan:13,max_power:80 I (1641) phy: chan:14,max_power:80 I (1651) chip[SVR]: Server initializing... I (1651) chip[TS]: Last Known Good Time: 2022-07-15T09:07:11 I (1651) chip[DMG]: AccessControl: initializing I (1661) chip[DMG]: Examples::AccessControlDelegate::Init I (1661) chip[DMG]: AccessControl: setting I (1671) chip[DMG]: DefaultAclStorage: initializing I (1671) chip[DMG]: DefaultAclStorage: 0 entries loaded I (1701) chip[ZCL]: Using ZAP configuration... I (1711) chip[DMG]: AccessControlCluster: initializing I (1711) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (1731) app-devicecallbacks: Unhandled cluster ID: 48 I (1731) app-devicecallbacks: Current free heap: 112644 I (1741) chip[ZCL]: Initiating Admin Commissioning cluster. I (1741) chip[ZCL]: Door Lock server initialized I (1751) chip[ZCL]: Initialize PCC Plugin Server Cluster. I (1751) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0003', EndPoint ID: '0x00', Attribute ID: '0x0001' I (1761) app-devicecallbacks: Current free heap: 112616 I (1781) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x00', Attribute ID: '0x0000' I (1791) app-devicecallbacks: Unhandled cluster ID: 4 I (1791) app-devicecallbacks: Current free heap: 112616 I (1801) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x00', Attribute ID: '0xfffc' I (1811) app-devicecallbacks: Unhandled cluster ID: 4 I (1811) app-devicecallbacks: Current free heap: 112616 I (1821) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x002b', EndPoint ID: '0x00', Attribute ID: '0x0000' I (1841) app-devicecallbacks: Unhandled cluster ID: 43 I (1841) app-devicecallbacks: Current free heap: 112616 I (1851) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0003', EndPoint ID: '0x01', Attribute ID: '0x0001' I (1861) app-devicecallbacks: Current free heap: 112616 I (1861) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x01', Attribute ID: '0x0000' I (1871) app-devicecallbacks: Unhandled cluster ID: 4 I (1881) app-devicecallbacks: Current free heap: 112616 I (1881) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x01', Attribute ID: '0xfffc' I (1901) app-devicecallbacks: Unhandled cluster ID: 4 I (1911) app-devicecallbacks: Current free heap: 112616 I (1911) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0005', EndPoint ID: '0x01', Attribute ID: '0x0000' I (1921) app-devicecallbacks: Unhandled cluster ID: 5 I (1931) app-devicecallbacks: Current free heap: 112616 I (1931) chip[ZCL]: On/Off set value: 1 0 I (1941) chip[ZCL]: On/off already set to new value I (1941) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0008', EndPoint ID: '0x01', Attribute ID: '0x0000' I (1961) app-devicecallbacks: Current free heap: 112616 I (1971) chip[ZCL]: Window Covering Cluster init I (1971) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0102', EndPoint ID: '0x01', Attribute ID: '0x0007' I (1981) app-devicecallbacks: Unhandled cluster ID: 258 I (1981) app-devicecallbacks: Current free heap: 112616 I (1991) chip[ZCL]: WC POST ATTRIBUTE=7 I (1991) chip[ZCL]: ConfigStatus 0x1B Operational=1 OnlineReserved=1 I (2001) chip[ZCL]: Lift(PA=1 Encoder=0 Reversed=0) Tilt(PA=1 Encoder=0) I (2021) chip[ZCL]: Initialize PCC Server Cluster [EP:1] I (2021) chip[ZCL]: Constant Pressure Supported I (2021) chip[ZCL]: PCC Server: Constant Proportional Pressure Supported I (2031) chip[ZCL]: PCC Server: Constant Flow Supported I (2041) chip[ZCL]: PCC Server: Constant Temperature Supported I (2041) chip[ZCL]: PCC Server: Constant Speed Supported I (2051) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x0007' I (2061) app-devicecallbacks: Unhandled AttributeId ID: '0x0007 I (2061) app-devicecallbacks: Current free heap: 112616 I (2081) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x0008' I (2091) app-devicecallbacks: Unhandled AttributeId ID: '0x0008 I (2091) app-devicecallbacks: Current free heap: 112616 I (2101) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x4001' I (2111) app-devicecallbacks: Unhandled AttributeId ID: '0x4001 I (2111) app-devicecallbacks: Current free heap: 112616 I (2121) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0001' I (2131) app-devicecallbacks: Unhandled cluster ID: 1030 I (2141) app-devicecallbacks: Current free heap: 112616 I (2151) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0002' I (2161) app-devicecallbacks: Unhandled cluster ID: 1030 I (2161) app-devicecallbacks: Current free heap: 112616 I (2171) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x02', Attribute ID: '0x0000' I (2181) app-devicecallbacks: Unhandled cluster ID: 4 I (2181) app-devicecallbacks: Current free heap: 112616 I (2191) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x02', Attribute ID: '0xfffc' I (2211) app-devicecallbacks: Unhandled cluster ID: 4 I (2211) app-devicecallbacks: Current free heap: 112616 I (2221) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x02', Attribute ID: '0x0001' I (2231) app-devicecallbacks: Unhandled cluster ID: 1030 I (2231) app-devicecallbacks: Current free heap: 112616 I (2241) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x02', Attribute ID: '0x0002' I (2251) app-devicecallbacks: Unhandled cluster ID: 1030 I (2261) app-devicecallbacks: Current free heap: 112616 I (2271) chip[DIS]: Updating services using commissioning mode 1 I (2271) chip[DIS]: CHIP minimal mDNS started advertising. I (2281) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15 I (2291) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'. I (2291) chip[DIS]: mDNS service published: _matterc._udp I (2301) chip[IN]: CASE Server enabling CASE session setups I (2311) chip[SVR]: Joining Multicast groups I (2321) chip[SVR]: Server Listening... E (2321) chip[DL]: Long dispatch time: 673 ms, for event type 2 I (2321) app-devicecallbacks: Current free heap: 111900 I (2331) chip[DL]: WIFI_EVENT_STA_START I (2331) phy: chan:1,max_power:80 I (2341) phy: chan:2,max_power:80 I (2341) phy: chan:3,max_power:80 I (2341) phy: chan:4,max_power:80 I (2361) phy: chan:5,max_power:80 I (2361) phy: chan:6,max_power:80 I (2361) phy: chan:7,max_power:80 I (2371) phy: chan:8,max_power:80 I (2371) phy: chan:9,max_power:80 I (2371) phy: chan:10,max_power:80 I (2381) phy: chan:11,max_power:80 I (2381) phy: chan:12,max_power:80 I (2381) phy: chan:13,max_power:80 I (2391) phy: chan:14,max_power:80 W (2391) wifi:Haven't to connect to a suitable AP now! I (2391) chip[DL]: Done driving station state, nothing else to do... I (2401) app-devicecallbacks: Current free heap: 111900 I (2411) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable, device name MATTER-3840) I (2421) chip[DL]: Device already advertising, stop active advertisement and restart I (2431) NimBLE: GAP procedure initiated: stop advertising. I (2441) NimBLE: GAP procedure initiated: advertise; I (2441) NimBLE: disc_mode=2 I (2441) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (2451) NimBLE: I (2451) chip[SVR]: Cannot load binding table: a0 I (32271) chip[DL]: Configuring CHIPoBLE advertising (interval 500 ms, connectable, device name MATTER-3840) I (32271) chip[DL]: Device already advertising, stop active advertisement and restart I (32281) NimBLE: GAP procedure initiated: stop advertising. I (32291) NimBLE: GAP procedure initiated: advertise; I (32291) NimBLE: disc_mode=2 I (32291) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=800 adv_itvl_max=800 I (32301) NimBLE: I (44941) chip[DL]: BLE GAP connection established (con 1) I (44941) chip[DL]: CHIPoBLE advertising stopped I (44941) app-devicecallbacks: Current free heap: 111904 I (46281) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (46291) chip[BLE]: local and remote recv window sizes = 5 I (46301) chip[BLE]: selected BTP version 4 I (46301) chip[BLE]: using BTP fragment sizes rx 244 / tx 244. I (46381) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 1 notify = 1 I (46391) chip[DL]: CHIPoBLE subscribe received I (46391) NimBLE: GATT procedure initiated: notify; I (46401) NimBLE: att_handle=14 I (46411) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (46411) app-devicecallbacks: CHIPoBLE connection established I (46421) app-devicecallbacks: Current free heap: 111872 I (46491) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (46491) chip[EM]: Received message of type 0x20 with protocolId (0, 0) and MessageCounter:78130418 on exchange 60002r I (46501) chip[IN]: Prepared unauthenticated message 0x3fcb7798 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 60002r with MessageCounter:1584448. I (46511) chip[IN]: Sending unauthenticated msg 0x3fcb7798 with MessageCounter:1584448 to 0x0000000000000000 at monotonic time: 000000000000B5B1 msec I (46531) NimBLE: GATT procedure initiated: notify; I (46541) NimBLE: att_handle=14 I (46541) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (46641) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (46641) chip[EM]: Received message of type 0x22 with protocolId (0, 0) and MessageCounter:78130419 on exchange 60002r I (47501) chip[IN]: Prepared unauthenticated message 0x3fcb7718 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 60002r with MessageCounter:1584449. I (47511) chip[IN]: Sending unauthenticated msg 0x3fcb7718 with MessageCounter:1584449 to 0x0000000000000000 at monotonic time: 000000000000B996 msec I (47521) NimBLE: GATT procedure initiated: notify; I (47521) NimBLE: att_handle=14 I (47541) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (47551) chip[DL]: Long dispatch time: 911 ms, for event type 7 I (47631) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (47641) chip[EM]: Received message of type 0x24 with protocolId (0, 0) and MessageCounter:78130420 on exchange 60002r I (47651) chip[IN]: Prepared unauthenticated message 0x3fcb77a8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 60002r with MessageCounter:1584450. I (47661) chip[IN]: Sending unauthenticated msg 0x3fcb77a8 with MessageCounter:1584450 to 0x0000000000000000 at monotonic time: 000000000000BA2E msec I (47681) NimBLE: GATT procedure initiated: notify; I (47691) NimBLE: att_handle=14 I (47691) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (47701) chip[SC]: SecureSession[0x3fc945c8]: Moving from state 'kEstablishing' --> 'kActive' I (47711) chip[SVR]: Commissioning completed session establishment step I (47711) chip[DIS]: Updating services using commissioning mode 0 I (47721) chip[DIS]: CHIP minimal mDNS started advertising. I (47731) chip[SVR]: Device completed Rendezvous process I (47791) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (47791) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:86939816 on exchange 60003r I (47811) chip[IN]: Prepared secure message 0x3fcb79d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 60003r with MessageCounter:202066451. I (47821) chip[IN]: Sending encrypted msg 0x3fcb79d8 with MessageCounter:202066451 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BACE msec I (47841) NimBLE: GATT procedure initiated: notify; I (47841) NimBLE: att_handle=14 I (47851) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (47851) NimBLE: GATT procedure initiated: notify; I (47861) NimBLE: att_handle=14 I (47861) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (47981) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (47991) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:86939817 on exchange 60004r I (48001) chip[FS]: GeneralCommissioning: Received ArmFailSafe (60s) I (48001) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (48021) app-devicecallbacks: Unhandled cluster ID: 48 I (48031) app-devicecallbacks: Current free heap: 110964 I (48031) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 60004r with MessageCounter:202066452. I (48041) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:202066452 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BBA8 msec I (48061) NimBLE: GATT procedure initiated: notify; I (48071) NimBLE: att_handle=14 I (48071) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (48141) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (48141) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:86939818 on exchange 60005r I (48151) chip[DL]: NVS set: chip-config/reg-location = 0 (0x0) I (48161) chip[DL]: NVS set: chip-config/country-code = "XX" I (48171) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (48181) app-devicecallbacks: Unhandled cluster ID: 48 I (48181) app-devicecallbacks: Current free heap: 110964 I (48191) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 60005r with MessageCounter:202066453. I (48201) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:202066453 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BC4B msec I (48221) NimBLE: GATT procedure initiated: notify; I (48221) NimBLE: att_handle=14 I (48231) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (48241) chip[DL]: Long dispatch time: 104 ms, for event type 7 I (48281) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (48291) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:86939819 on exchange 60006r I (48301) chip[ZCL]: OpCreds: Certificate Chain request received for PAI I (48311) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 60006r with MessageCounter:202066454. I (48321) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:202066454 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BCBD msec I (48331) NimBLE: GATT procedure initiated: notify; I (48341) NimBLE: att_handle=14 I (48341) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (48361) NimBLE: GATT procedure initiated: notify; I (48361) NimBLE: att_handle=14 I (48371) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (48371) NimBLE: GATT procedure initiated: notify; I (48381) NimBLE: att_handle=14 I (48381) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (48531) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (48541) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:86939820 on exchange 60007r I (48551) chip[ZCL]: OpCreds: Certificate Chain request received for DAC I (48561) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 60007r with MessageCounter:202066455. I (48571) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:202066455 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BDB8 msec I (48581) NimBLE: GATT procedure initiated: notify; I (48591) NimBLE: att_handle=14 I (48591) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (48611) NimBLE: GATT procedure initiated: notify; I (48611) NimBLE: att_handle=14 I (48621) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (48621) NimBLE: GATT procedure initiated: notify; I (48631) NimBLE: att_handle=14 I (48631) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (48791) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (48791) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:86939821 on exchange 60008r I (48801) chip[ZCL]: OpCreds: Received an AttestationRequest command I (48981) chip[ZCL]: OpCreds: AttestationRequest successful. I (48981) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 60008r with MessageCounter:202066456. I (48991) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:202066456 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000BF60 msec I (49011) NimBLE: GATT procedure initiated: notify; I (49021) NimBLE: att_handle=14 I (49021) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (49031) chip[DL]: Long dispatch time: 243 ms, for event type 7 I (49031) NimBLE: GATT procedure initiated: notify; I (49041) NimBLE: att_handle=14 I (49041) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (49061) NimBLE: GATT procedure initiated: notify; I (49061) NimBLE: att_handle=14 I (49061) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (49231) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (49241) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:86939822 on exchange 60009r I (49251) chip[ZCL]: OpCreds: Received a CSRRequest command I (49591) chip[ZCL]: OpCreds: AllocatePendingOperationalKey succeeded I (49761) chip[ZCL]: OpCreds: CSRRequest successful. I (49771) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 60009r with MessageCounter:202066457. I (49781) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:202066457 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000C273 msec I (49791) NimBLE: GATT procedure initiated: notify; I (49801) NimBLE: att_handle=14 I (49801) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (49821) chip[DL]: Long dispatch time: 581 ms, for event type 7 I (49821) NimBLE: GATT procedure initiated: notify; I (49831) NimBLE: att_handle=14 I (49831) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (52631) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (55141) NimBLE: GATT procedure initiated: notify; I (55141) NimBLE: att_handle=14 I (55141) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (67641) chip[BLE]: ack recv timeout, closing ep 0x3fc9ed28 I (67641) chip[BLE]: Releasing end point's BLE connection back to application. I (70341) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 0 notify = 0 I (70341) chip[DL]: CHIPoBLE unsubscribe received I (70351) chip[DL]: BLE GAP connection terminated (con 1 reason 0x213) E (70341) chip[BLE]: no endpoint for unsub recvd I (70371) app-devicecallbacks: CHIPoBLE disconnected I (70371) app-devicecallbacks: Current free heap: 110844