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 17:45:09 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=37658h (226904) map I (155) esp_image: segment 1: paddr=00057680 vaddr=3fc8fa00 size=03918h ( 14616) load I (158) esp_image: segment 2: paddr=0005afa0 vaddr=40380000 size=05078h ( 20600) load I (165) esp_image: segment 3: paddr=00060020 vaddr=42000020 size=1035b8h (1062328) map I (336) esp_image: segment 4: paddr=001635e0 vaddr=40385078 size=0a908h ( 43272) load I (344) esp_image: segment 5: paddr=0016def0 vaddr=50000010 size=00010h ( 16) load I (349) boot: Loaded app from partition at offset 0x20000 I (350) 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-1213-gaa9457e6b I (388) cpu_start: Compile time: Jul 18 2022 17:44:47 I (394) cpu_start: ELF file SHA256: dba0b06fdf7378f4... 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 (442) 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 (651) pp: pp rom version: 9387209 I (651) net80211: net80211 rom version: 9387209 I (661) wifi:wifi driver task: 3fcb0154, prio:23, stack:6656, core=0 I (661) system_api: Base MAC address is not set I (671) system_api: read default base MAC address from EFUSE I (671) wifi:wifi firmware version: 63017e0 I (671) wifi:wifi certification version: v7.0 I (681) wifi:config NVS flash: enabled I (681) wifi:config nano formating: disabled I (681) wifi:Init data frame dynamic rx buffer num: 32 I (691) wifi:Init management frame dynamic rx buffer num: 32 I (691) wifi:Init management short buffer num: 32 I (691) wifi:Init dynamic tx buffer num: 32 I (701) wifi:Init static tx FG buffer num: 2 I (711) wifi:Init static rx buffer size: 1600 I (711) wifi:Init static rx buffer num: 10 I (721) wifi:Init dynamic rx buffer num: 32 I (731) wifi_init: rx ba win: 6 I (731) wifi_init: tcpip mbox: 32 I (731) wifi_init: udp mbox: 6 I (731) wifi_init: tcp mbox: 6 I (741) wifi_init: tcp tx win: 5744 I (741) wifi_init: tcp rx win: 5744 I (741) wifi_init: tcp mss: 1440 I (751) wifi_init: WiFi IRAM OP enabled I (751) wifi_init: WiFi RX IRAM OP enabled I (781) chip[DL]: NVS set: chip-counters/reboot-count = 3 (0x3) I (781) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC) I (791) all-clusters-app: ------------------------Starting App Task--------------------------- W (791) BTDM_INIT: esp_bt_controller_mem_release not implemented, return OK I (801) BTDM_INIT: BT controller compile version [d913766] I (801) phy_init: phy_version 909,156dee4,Apr 7 2022,20:27:09 I (791) app-task: This is ESP32 chip with 1 CPU cores, WiFi/BLE, I (821) app-task: silicon revision 3, > I (841) app-task: 4MB external flash I (841) chip[SVR]: SetupQRCode: [MT:-24J042C00KA0648G00] I (841) chip[SVR]: Copy/paste the below URL in a browser to see the QR Code: I (861) chip[SVR]: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J042C00KA0648G00 I (871) chip[SVR]: Manual pairing code: [34970112332] I (891) 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 (951) CHIP[DL]: BLE host-controller synced I (1451) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable, device name MATTER-3840) I (1451) NimBLE: GAP procedure initiated: advertise; I (1461) NimBLE: disc_mode=2 I (1461) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (1471) NimBLE: I (1471) chip[DL]: CHIPoBLE advertising started E (1481) chip[DL]: Long dispatch time: 692 ms, for event type 2 I (1481) chip[DL]: Starting ESP WiFi layer I (1491) wifi:mode : sta (84:f7:03:60:fb:e4) I (1501) wifi:enable tsf W (1501) wifi:Haven't to connect to a suitable AP now! I (1501) chip[DL]: Done driving station state, nothing else to do... I (1511) phy: chan:1,max_power:80 I (1511) phy: chan:2,max_power:80 I (1521) phy: chan:3,max_power:80 I (1521) phy: chan:4,max_power:80 I (1521) phy: chan:5,max_power:80 I (1531) phy: chan:6,max_power:80 I (1531) phy: chan:7,max_power:80 I (1531) phy: chan:8,max_power:80 I (1541) phy: chan:9,max_power:80 I (1541) phy: chan:10,max_power:80 I (1541) phy: chan:11,max_power:80 I (1561) phy: chan:12,max_power:80 I (1561) phy: chan:13,max_power:80 I (1561) phy: chan:14,max_power:80 W (1571) wifi:Haven't to connect to a suitable AP now! I (1571) chip[DL]: Done driving station state, nothing else to do... I (1581) phy: chan:1,max_power:80 I (1581) phy: chan:2,max_power:80 I (1581) phy: chan:3,max_power:80 I (1591) phy: chan:4,max_power:80 I (1591) phy: chan:5,max_power:80 I (1591) phy: chan:6,max_power:80 I (1601) phy: chan:7,max_power:80 I (1601) phy: chan:8,max_power:80 I (1601) phy: chan:9,max_power:80 I (1611) phy: chan:10,max_power:80 I (1611) phy: chan:11,max_power:80 I (1621) phy: chan:12,max_power:80 I (1631) phy: chan:13,max_power:80 I (1631) phy: chan:14,max_power:80 I (1631) chip[SVR]: Server initializing... I (1641) chip[TS]: Last Known Good Time: 2022-07-18T18:06:23 I (1641) chip[DMG]: AccessControl: initializing I (1651) chip[DMG]: Examples::AccessControlDelegate::Init I (1651) chip[DMG]: AccessControl: setting I (1661) chip[DMG]: DefaultAclStorage: initializing I (1661) chip[DMG]: DefaultAclStorage: 0 entries loaded I (1691) chip[ZCL]: Using ZAP configuration... I (1701) chip[DMG]: AccessControlCluster: initializing I (1701) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (1721) app-devicecallbacks: Unhandled cluster ID: 48 I (1721) app-devicecallbacks: Current free heap: 112644 I (1731) chip[ZCL]: Initiating Admin Commissioning cluster. I (1731) chip[ZCL]: Door Lock server initialized I (1741) chip[ZCL]: Initialize PCC Plugin Server Cluster. I (1741) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0003', EndPoint ID: '0x00', Attribute ID: '0x0001' I (1751) app-devicecallbacks: Current free heap: 112616 I (1771) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x00', Attribute ID: '0x0000' I (1781) app-devicecallbacks: Unhandled cluster ID: 4 I (1781) app-devicecallbacks: Current free heap: 112616 I (1791) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x00', Attribute ID: '0xfffc' I (1801) app-devicecallbacks: Unhandled cluster ID: 4 I (1801) app-devicecallbacks: Current free heap: 112616 I (1811) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x002b', EndPoint ID: '0x00', Attribute ID: '0x0000' I (1831) app-devicecallbacks: Unhandled cluster ID: 43 I (1831) app-devicecallbacks: Current free heap: 112616 I (1841) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0003', EndPoint ID: '0x01', Attribute ID: '0x0001' I (1851) app-devicecallbacks: Current free heap: 112616 I (1851) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x01', Attribute ID: '0x0000' I (1861) app-devicecallbacks: Unhandled cluster ID: 4 I (1871) app-devicecallbacks: Current free heap: 112616 I (1871) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x01', Attribute ID: '0xfffc' I (1891) app-devicecallbacks: Unhandled cluster ID: 4 I (1901) app-devicecallbacks: Current free heap: 112616 I (1901) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0005', EndPoint ID: '0x01', Attribute ID: '0x0000' I (1911) app-devicecallbacks: Unhandled cluster ID: 5 I (1921) app-devicecallbacks: Current free heap: 112616 I (1921) chip[ZCL]: On/Off set value: 1 0 I (1931) chip[ZCL]: On/off already set to new value I (1931) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0008', EndPoint ID: '0x01', Attribute ID: '0x0000' I (1951) app-devicecallbacks: Current free heap: 112616 I (1961) chip[ZCL]: Window Covering Cluster init I (1961) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0102', EndPoint ID: '0x01', Attribute ID: '0x0007' I (1971) app-devicecallbacks: Unhandled cluster ID: 258 I (1971) app-devicecallbacks: Current free heap: 112616 I (1981) chip[ZCL]: WC POST ATTRIBUTE=7 I (1981) chip[ZCL]: ConfigStatus 0x1B Operational=1 OnlineReserved=1 I (1991) chip[ZCL]: Lift(PA=1 Encoder=0 Reversed=0) Tilt(PA=1 Encoder=0) I (2001) chip[ZCL]: Initialize PCC Server Cluster [EP:1] I (2011) chip[ZCL]: Constant Pressure Supported I (2011) chip[ZCL]: PCC Server: Constant Proportional Pressure Supported I (2021) chip[ZCL]: PCC Server: Constant Flow Supported I (2031) chip[ZCL]: PCC Server: Constant Temperature Supported I (2031) chip[ZCL]: PCC Server: Constant Speed Supported I (2041) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x0007' I (2051) app-devicecallbacks: Unhandled AttributeId ID: '0x0007 I (2051) app-devicecallbacks: Current free heap: 112616 I (2071) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x0008' I (2081) app-devicecallbacks: Unhandled AttributeId ID: '0x0008 I (2081) app-devicecallbacks: Current free heap: 112616 I (2091) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x4001' I (2101) app-devicecallbacks: Unhandled AttributeId ID: '0x4001 I (2101) app-devicecallbacks: Current free heap: 112616 I (2111) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0001' I (2121) app-devicecallbacks: Unhandled cluster ID: 1030 I (2121) app-devicecallbacks: Current free heap: 112616 I (2141) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0002' I (2151) app-devicecallbacks: Unhandled cluster ID: 1030 I (2151) app-devicecallbacks: Current free heap: 112616 I (2161) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x02', Attribute ID: '0x0000' I (2171) app-devicecallbacks: Unhandled cluster ID: 4 I (2171) app-devicecallbacks: Current free heap: 112616 I (2181) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x02', Attribute ID: '0xfffc' I (2201) app-devicecallbacks: Unhandled cluster ID: 4 I (2201) app-devicecallbacks: Current free heap: 112616 I (2211) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x02', Attribute ID: '0x0001' I (2221) app-devicecallbacks: Unhandled cluster ID: 1030 I (2231) app-devicecallbacks: Current free heap: 112616 I (2231) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x02', Attribute ID: '0x0002' I (2241) app-devicecallbacks: Unhandled cluster ID: 1030 I (2251) app-devicecallbacks: Current free heap: 112616 I (2261) chip[DIS]: Updating services using commissioning mode 1 I (2261) chip[DIS]: CHIP minimal mDNS started advertising. I (2271) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15 I (2281) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'. I (2281) chip[DIS]: mDNS service published: _matterc._udp I (2291) chip[IN]: CASE Server enabling CASE session setups I (2301) chip[SVR]: Joining Multicast groups I (2311) chip[SVR]: Server Listening... E (2311) chip[DL]: Long dispatch time: 682 ms, for event type 2 I (2311) app-devicecallbacks: Current free heap: 111900 I (2321) chip[DL]: WIFI_EVENT_STA_START I (2321) phy: chan:1,max_power:80 I (2331) phy: chan:2,max_power:80 I (2331) phy: chan:3,max_power:80 I (2331) phy: chan:4,max_power:80 I (2351) phy: chan:5,max_power:80 I (2351) phy: chan:6,max_power:80 I (2351) phy: chan:7,max_power:80 I (2361) phy: chan:8,max_power:80 I (2361) phy: chan:9,max_power:80 I (2361) phy: chan:10,max_power:80 I (2371) phy: chan:11,max_power:80 I (2371) phy: chan:12,max_power:80 I (2371) phy: chan:13,max_power:80 I (2381) phy: chan:14,max_power:80 W (2381) wifi:Haven't to connect to a suitable AP now! I (2381) chip[DL]: Done driving station state, nothing else to do... I (2391) app-devicecallbacks: Current free heap: 111900 I (2401) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable, device name MATTER-3840) I (2411) chip[DL]: Device already advertising, stop active advertisement and restart I (2421) NimBLE: GAP procedure initiated: stop advertising. I (2431) NimBLE: GAP procedure initiated: advertise; I (2431) NimBLE: disc_mode=2 I (2431) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (2441) NimBLE: I (2441) chip[SVR]: Cannot load binding table: a0 I (9141) chip[DL]: BLE GAP connection established (con 1) I (9141) chip[DL]: CHIPoBLE advertising stopped I (9141) app-devicecallbacks: Current free heap: 111904 I (10801) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (10811) chip[BLE]: local and remote recv window sizes = 5 I (10821) chip[BLE]: selected BTP version 4 I (10821) chip[BLE]: using BTP fragment sizes rx 244 / tx 244. I (10901) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 1 notify = 1 I (10911) chip[DL]: CHIPoBLE subscribe received I (10911) NimBLE: GATT procedure initiated: notify; I (10921) NimBLE: att_handle=14 I (10931) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (10931) app-devicecallbacks: CHIPoBLE connection established I (10941) app-devicecallbacks: Current free heap: 111872 I (11011) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (11011) chip[EM]: Received message of type 0x20 with protocolId (0, 0) and MessageCounter:170621867 on exchange 59968r I (11021) chip[IN]: Prepared unauthenticated message 0x3fcb7798 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 59968r with MessageCounter:216505420. I (11041) chip[IN]: Sending unauthenticated msg 0x3fcb7798 with MessageCounter:216505420 to 0x0000000000000000 at monotonic time: 0000000000002B1A msec I (11051) NimBLE: GATT procedure initiated: notify; I (11061) NimBLE: att_handle=14 I (11061) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (11161) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (11161) chip[EM]: Received message of type 0x22 with protocolId (0, 0) and MessageCounter:170621868 on exchange 59968r I (12021) chip[IN]: Prepared unauthenticated message 0x3fcb7718 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 59968r with MessageCounter:216505421. I (12031) chip[IN]: Sending unauthenticated msg 0x3fcb7718 with MessageCounter:216505421 to 0x0000000000000000 at monotonic time: 0000000000002EFA msec I (12041) NimBLE: GATT procedure initiated: notify; I (12051) NimBLE: att_handle=14 I (12051) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (12061) chip[DL]: Long dispatch time: 907 ms, for event type 7 I (12111) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (12111) chip[EM]: Received message of type 0x24 with protocolId (0, 0) and MessageCounter:170621869 on exchange 59968r I (12121) chip[IN]: Prepared unauthenticated message 0x3fcb77a8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 59968r with MessageCounter:216505422. I (12131) chip[IN]: Sending unauthenticated msg 0x3fcb77a8 with MessageCounter:216505422 to 0x0000000000000000 at monotonic time: 0000000000002F64 msec I (12151) NimBLE: GATT procedure initiated: notify; I (12161) NimBLE: att_handle=14 I (12161) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12171) chip[SC]: SecureSession[0x3fc945c8]: Moving from state 'kEstablishing' --> 'kActive' I (12181) chip[SVR]: Commissioning completed session establishment step I (12181) chip[DIS]: Updating services using commissioning mode 0 I (12201) chip[DIS]: CHIP minimal mDNS started advertising. I (12201) chip[SVR]: Device completed Rendezvous process E (12211) chip[DL]: Long dispatch time: 101 ms, for event type 7 I (12261) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (12261) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:191110802 on exchange 59969r I (12281) chip[IN]: Prepared secure message 0x3fcb79d8 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 59969r with MessageCounter:180942529. I (12291) chip[IN]: Sending encrypted msg 0x3fcb79d8 with MessageCounter:180942529 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000003004 msec I (12311) NimBLE: GATT procedure initiated: notify; I (12311) NimBLE: att_handle=14 I (12321) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12321) NimBLE: GATT procedure initiated: notify; I (12331) NimBLE: att_handle=14 I (12331) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12411) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (12411) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110803 on exchange 59970r I (12421) chip[FS]: GeneralCommissioning: Received ArmFailSafe (60s) I (12421) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (12441) app-devicecallbacks: Unhandled cluster ID: 48 I (12451) app-devicecallbacks: Current free heap: 110964 I (12451) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 59970r with MessageCounter:180942530. I (12461) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942530 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000030AD msec I (12481) NimBLE: GATT procedure initiated: notify; I (12491) NimBLE: att_handle=14 I (12491) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12561) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (12561) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110804 on exchange 59971r I (12571) chip[DL]: NVS set: chip-config/reg-location = 0 (0x0) I (12581) chip[DL]: NVS set: chip-config/country-code = "XX" I (12591) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (12601) app-devicecallbacks: Unhandled cluster ID: 48 I (12601) app-devicecallbacks: Current free heap: 110964 I (12611) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 59971r with MessageCounter:180942531. I (12621) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942531 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000314F msec I (12641) NimBLE: GATT procedure initiated: notify; I (12641) NimBLE: att_handle=14 I (12651) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (12661) chip[DL]: Long dispatch time: 103 ms, for event type 7 I (12711) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (12711) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110805 on exchange 59972r I (12721) chip[ZCL]: OpCreds: Certificate Chain request received for PAI I (12731) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 59972r with MessageCounter:180942532. I (12741) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942532 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000000031C2 msec I (12751) NimBLE: GATT procedure initiated: notify; I (12761) NimBLE: att_handle=14 I (12761) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12781) NimBLE: GATT procedure initiated: notify; I (12781) NimBLE: att_handle=14 I (12791) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12791) NimBLE: GATT procedure initiated: notify; I (12801) NimBLE: att_handle=14 I (12801) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12861) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (12861) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110806 on exchange 59973r I (12871) chip[ZCL]: OpCreds: Certificate Chain request received for DAC I (12881) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 59973r with MessageCounter:180942533. I (12891) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942533 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000003258 msec I (12901) NimBLE: GATT procedure initiated: notify; I (12911) NimBLE: att_handle=14 I (12911) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12931) NimBLE: GATT procedure initiated: notify; I (12931) NimBLE: att_handle=14 I (12941) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (12941) NimBLE: GATT procedure initiated: notify; I (12951) NimBLE: att_handle=14 I (12951) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (13011) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (13011) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110807 on exchange 59974r I (13021) chip[ZCL]: OpCreds: Received an AttestationRequest command I (13201) chip[ZCL]: OpCreds: AttestationRequest successful. I (13201) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 59974r with MessageCounter:180942534. I (13211) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942534 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000000339D msec I (13231) NimBLE: GATT procedure initiated: notify; I (13231) NimBLE: att_handle=14 I (13241) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (13251) chip[DL]: Long dispatch time: 244 ms, for event type 7 I (13251) NimBLE: GATT procedure initiated: notify; I (13261) NimBLE: att_handle=14 I (13261) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (13281) NimBLE: GATT procedure initiated: notify; I (13281) NimBLE: att_handle=14 I (13281) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (13361) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (13361) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110808 on exchange 59975r I (13371) chip[ZCL]: OpCreds: Received a CSRRequest command I (13711) chip[ZCL]: OpCreds: AllocatePendingOperationalKey succeeded I (13881) chip[ZCL]: OpCreds: CSRRequest successful. I (13891) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 59975r with MessageCounter:180942535. I (13901) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942535 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000003649 msec I (13911) NimBLE: GATT procedure initiated: notify; I (13921) NimBLE: att_handle=14 I (13921) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (13941) chip[DL]: Long dispatch time: 578 ms, for event type 7 I (13941) NimBLE: GATT procedure initiated: notify; I (13951) NimBLE: att_handle=14 I (13951) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (14011) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (14101) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (14111) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110809 on exchange 59976r I (14121) chip[ZCL]: OpCreds: Received an AddTrustedRootCertificate command I (14471) chip[ZCL]: OpCreds: AddTrustedRootCertificate successful. I (14481) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 59976r with MessageCounter:180942536. I (14491) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942536 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000003897 msec I (14501) NimBLE: GATT procedure initiated: notify; I (14511) NimBLE: att_handle=14 I (14511) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (14521) chip[DL]: Long dispatch time: 418 ms, for event type 7 I (14611) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (14711) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (14811) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (14811) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110810 on exchange 59977r I (14831) chip[ZCL]: OpCreds: Received an AddNOC command I (14831) chip[FP]: Validating NOC chain I (15521) chip[FP]: NOC chain validation successful I (15521) chip[FP]: Added new fabric at index: 0x1 I (15521) chip[FP]: Assigned compressed fabric ID: 0x260FC187F506344B, node ID: 0x0000000000BC5C01 I (15531) chip[TS]: Last Known Good Time: 2022-07-18T18:06:23 I (15551) chip[TS]: New proposed Last Known Good Time: 2021-01-01T00:00:00 I (15551) chip[TS]: Retaining current Last Known Good Time I (15561) chip[ZCL]: OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669 I (15571) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (15581) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (15591) chip[DIS]: mDNS service published: _matter._tcp I (15591) chip[ZCL]: OpCreds: successfully created fabric index 0x1 via AddNOC I (15601) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 59977r with MessageCounter:180942537. I (15621) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942537 to 0xFFFFFFFB00000000 (1) at monotonic time: 0000000000003CFF msec I (15631) NimBLE: GATT procedure initiated: notify; I (15631) NimBLE: att_handle=14 I (15641) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 E (15651) chip[DL]: Long dispatch time: 846 ms, for event type 7 I (15711) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (15711) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110811 on exchange 59978r I (15721) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (15741) app-devicecallbacks: Unhandled cluster ID: 48 I (15741) app-devicecallbacks: Current free heap: 106072 I (15751) chip[IN]: Prepared secure message 0x3fcb77f8 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 59978r with MessageCounter:180942538. I (15761) chip[IN]: Sending encrypted msg 0x3fcb77f8 with MessageCounter:180942538 to 0xFFFFFFFB00000000 (1) at monotonic time: 0000000000003D91 msec I (15771) NimBLE: GATT procedure initiated: notify; I (15781) NimBLE: att_handle=14 I (15791) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (15861) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (15861) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:191110812 on exchange 59979r I (15871) chip[NP]: ESP NetworkCommissioningDelegate: SSID: pr600k-eaf2cc-2 I (15871) chip[DL]: WiFi station mode change: Enabled -> Disabled I (15891) chip[DL]: Changing ESP WiFi mode: STA -> STA+AP I (15891) wifi:mode : sta (84:f7:03:60:fb:e4) + softAP (84:f7:03:60:fb:e5) I (15901) wifi:Total power save buffer number: 16 I (15911) wifi:Init max length of beacon: 752/752 I (15911) phy: chan:1,max_power:80 I (15911) phy: chan:2,max_power:80 I (15921) phy: chan:3,max_power:80 I (15921) phy: chan:4,max_power:80 I (15921) phy: chan:5,max_power:80 I (15931) phy: chan:6,max_power:80 I (15931) phy: chan:7,max_power:80 I (15941) phy: chan:8,max_power:80 I (15941) phy: chan:9,max_power:80 I (15941) phy: chan:10,max_power:80 I (15951) phy: chan:11,max_power:80 I (15951) phy: chan:12,max_power:80 I (15961) phy: chan:13,max_power:80 I (15971) phy: chan:14,max_power:80 I (15971) wifi:Init max length of beacon: 752/752 I (15981) chip[DL]: WiFi station mode change: Disabled -> Enabled E (15981) chip[DL]: Long dispatch time: 121 ms, for event type 7 I (15991) phy: chan:1,max_power:80 I (15991) phy: chan:2,max_power:80 I (15991) phy: chan:3,max_power:80 I (16001) phy: chan:4,max_power:80 I (16001) phy: chan:5,max_power:80 I (16001) phy: chan:6,max_power:80 I (16011) phy: chan:7,max_power:80 I (16011) phy: chan:8,max_power:80 I (16011) phy: chan:9,max_power:80 I (16031) phy: chan:10,max_power:80 I (16031) phy: chan:11,max_power:80 I (16031) phy: chan:12,max_power:80 I (16041) phy: chan:13,max_power:80 I (16041) phy: chan:14,max_power:80 W (16041) wifi:Haven't to connect to a suitable AP now! I (16051) chip[DL]: Attempting to connect WiFi station interface I (16051) chip[DL]: WiFi station state change: NotConnected -> Connecting I (16061) chip[DL]: Done driving station state, nothing else to do... I (16061) phy: chan:1,max_power:80 I (16071) phy: chan:2,max_power:80 I (16071) phy: chan:3,max_power:80 I (16091) phy: chan:4,max_power:80 I (16091) phy: chan:5,max_power:80 I (16091) phy: chan:6,max_power:80 I (16101) phy: chan:7,max_power:80 I (16101) phy: chan:8,max_power:80 I (16101) phy: chan:9,max_power:80 I (16111) phy: chan:10,max_power:80 I (16111) phy: chan:11,max_power:80 I (16111) phy: chan:12,max_power:80 I (16121) phy: chan:13,max_power:80 I (16121) phy: chan:14,max_power:80 I (16061) wifi:new:<1,1>, old:<1,1>, ap:<1,1>, sta:<1,0>, prof:1 I (16701) wifi:state: init -> auth (b0) I (16701) chip[DL]: Done driving station state, nothing else to do... E (16701) chip[DL]: Long dispatch time: 637 ms, for event type 3 I (16711) chip[DL]: WIFI_EVENT_AP_START I (16711) chip[DL]: WiFi AP state change: NotActive -> Active I (16721) phy: chan:1,max_power:80 I (16721) phy: chan:2,max_power:80 I (16721) phy: chan:3,max_power:80 I (16741) phy: chan:4,max_power:80 I (16741) phy: chan:5,max_power:80 I (16741) phy: chan:6,max_power:80 I (16751) phy: chan:7,max_power:80 I (16751) phy: chan:8,max_power:80 I (16751) phy: chan:9,max_power:80 I (16761) phy: chan:10,max_power:80 I (16761) phy: chan:11,max_power:80 I (16761) phy: chan:12,max_power:80 I (16771) phy: chan:13,max_power:80 I (16771) phy: chan:14,max_power:80 I (16781) chip[DL]: Changing ESP WiFi mode: STA+AP -> STA I (16711) wifi:state: auth -> assoc (0) I (16781) wifi:mode : sta (84:f7:03:60:fb:e4) I (16811) chip[DL]: WiFi AP state change: Active -> Deactivating I (16811) app-devicecallbacks: Current free heap: 106896 E (16821) chip[DL]: Long dispatch time: 106 ms, for event type 49152 I (16821) phy: chan:1,max_power:80 I (16821) phy: chan:2,max_power:80 I (16831) phy: chan:3,max_power:80 I (16831) phy: chan:4,max_power:80 I (16831) phy: chan:5,max_power:80 I (16841) phy: chan:6,max_power:80 I (16841) phy: chan:7,max_power:80 I (16851) phy: chan:8,max_power:80 I (16851) phy: chan:9,max_power:80 I (16851) phy: chan:10,max_power:80 I (16811) wifi:state: assoc -> run (10) I (16871) phy: chan:11,max_power:80 I (16871) phy: chan:12,max_power:80 I (16871) phy: chan:13,max_power:80 I (16881) phy: chan:14,max_power:80 I (16881) chip[DL]: Done driving station state, nothing else to do... I (16891) wifi:connected with pr600k-eaf2cc-2, aid = 1, channel 1, BW20, bssid = 16:66:82:fa:9e:c5 I (16891) wifi:security: WPA2-PSK, phy: bgn, rssi: -53 I (16911) wifi:pm start, type: 1 I (16911) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 14, mt_pti: 25000, mt_time: 10000 I (16911) wifi:BcnInt:102400, DTIM:1 I (16911) chip[DL]: WIFI_EVENT_AP_STOP I (16921) chip[DL]: WiFi AP state change: Deactivating -> NotActive I (16931) phy: chan:1,max_power:80 I (16931) phy: chan:2,max_power:80 I (16941) phy: chan:3,max_power:80 I (16951) phy: chan:4,max_power:80 I (16951) phy: chan:5,max_power:80 I (16951) phy: chan:6,max_power:80 I (16961) phy: chan:7,max_power:80 I (16961) phy: chan:8,max_power:80 I (16961) phy: chan:9,max_power:80 I (16971) phy: chan:10,max_power:80 I (16971) phy: chan:11,max_power:80 I (16971) phy: chan:12,max_power:80 I (16981) phy: chan:13,max_power:80 I (16981) phy: chan:14,max_power:80 I (16981) app-devicecallbacks: Current free heap: 106684 I (16991) chip[DL]: WIFI_EVENT_STA_CONNECTED I (16991) chip[DL]: WiFi station state change: Connecting -> Connecting_Succeeded I (17011) phy: chan:1,max_power:80 I (17011) phy: chan:2,max_power:80 I (17021) phy: chan:3,max_power:80 I (17021) phy: chan:4,max_power:80 I (17021) phy: chan:5,max_power:80 I (17031) phy: chan:6,max_power:80 I (17031) phy: chan:7,max_power:80 I (17031) phy: chan:8,max_power:80 I (17041) phy: chan:9,max_power:80 I (17041) phy: chan:10,max_power:80 I (17041) phy: chan:11,max_power:80 I (17051) phy: chan:12,max_power:80 I (17051) phy: chan:13,max_power:80 I (17051) phy: chan:14,max_power:80 I (17061) chip[DL]: WiFi station state change: Connecting_Succeeded -> Connected I (17081) chip[DL]: WiFi station interface connected I (17081) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (17091) app-devicecallbacks: Unhandled cluster ID: 48 I (17091) app-devicecallbacks: Current free heap: 105164 I (17101) chip[IN]: Prepared secure message 0x3fcb7a38 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 59979r with MessageCounter:180942539. I (17121) chip[IN]: Sending encrypted msg 0x3fcb7a38 with MessageCounter:180942539 to 0xFFFFFFFB00000000 (1) at monotonic time: 00000000000042DA msec I (17131) NimBLE: GATT procedure initiated: notify; I (17141) NimBLE: att_handle=14 I (17141) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 0 I (17151) chip[ZCL]: WiFiDiagnosticsDelegate: OnConnectionStatusChanged I (17151) chip[DL]: Done driving station state, nothing else to do... I (17171) app-devicecallbacks: Current free heap: 105084 E (17171) chip[DL]: Long dispatch time: 172 ms, for event type 49152 I (17181) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (17191) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (17191) chip[DIS]: mDNS service published: _matter._tcp I (17201) chip[SVR]: Operational advertising enabled I (17201) app-devicecallbacks: Current free heap: 105100 I (17211) chip[DL]: Updating advertising data I (17221) app-devicecallbacks: Current free heap: 106700 W (18071) wifi:idx:0 (ifx:0, 16:66:82:fa:9e:c5), tid:6, ssn:3, winSize:64 I (18651) chip[DL]: IP_EVENT_GOT_IP6 I (18651) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fe80:0000:0000:0000:86f7:03ff:fe60:fbe4 I (18661) app-devicecallbacks: Current free heap: 106064 I (18661) chip[DIS]: Updating services using commissioning mode 0 I (18671) chip[DIS]: CHIP minimal mDNS started advertising. I (18681) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (18691) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (18691) chip[DIS]: mDNS service published: _matter._tcp I (18701) app-devicecallbacks: Current free heap: 103332 W (18701) wifi:idx:1 (ifx:0, 16:66:82:fa:9e:c5), tid:0, ssn:0, winSize:64 I (18691) esp_netif_handlers: sta ip: 192.168.1.26, mask: 255.255.255.0, gw: 192.168.1.1 I (18711) chip[EM]: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:170621870 on exchange 59980r I (18731) chip[IN]: CASE Server received Sigma1 message. Starting handshake. EC 0x3fc95e38 I (18741) chip[IN]: CASE Server disabling CASE session setups I (18751) chip[IN]: Prepared unauthenticated message 0x3fcb7838 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 59980r with MessageCounter:216505423. I (18761) chip[IN]: Sending unauthenticated msg 0x3fcb7838 with MessageCounter:216505423 to 0x0000000000000000 at monotonic time: 0000000000004945 msec I (18781) chip[SC]: Received Sigma1 msg I (18791) chip[SC]: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000BC5C01 I (19291) chip[IN]: Prepared unauthenticated message 0x3fc960ec to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 59980r with MessageCounter:216505424. I (19301) chip[IN]: Sending unauthenticated msg 0x3fc960ec with MessageCounter:216505424 to 0x0000000000000000 at monotonic time: 0000000000004B64 msec I (19311) chip[SC]: Sent Sigma2 msg E (19321) chip[DL]: Long dispatch time: 606 ms, for event type 3 I (19331) chip[DL]: IP_EVENT_STA_GOT_IP I (19331) chip[DL]: IPv4 address changed on WiFi station interface: 192.168.1.26/255.255.255.0 gateway 192.168.1.1 I (19341) chip[DL]: IPv4 Internet connectivity ESTABLISHED I (19351) app-devicecallbacks: Current free heap: 101988 I (19351) app-devicecallbacks: IPv4 Server ready... I (19361) chip[DIS]: Updating services using commissioning mode 0 I (19361) chip[DIS]: CHIP minimal mDNS started advertising. I (19381) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (19381) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (19401) chip[DIS]: mDNS service published: _matter._tcp I (19401) app-devicecallbacks: Current free heap: 100260 I (19401) chip[DIS]: Updating services using commissioning mode 0 I (19411) chip[DIS]: CHIP minimal mDNS started advertising. I (19421) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (19431) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (19441) chip[DIS]: mDNS service published: _matter._tcp I (19441) app-devicecallbacks: Current free heap: 99204 I (19451) chip[EM]: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:170621871 on exchange 59980r I (19461) chip[IN]: Prepared unauthenticated message 0x3fcb7808 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 59980r with MessageCounter:216505425. I (19471) chip[IN]: Sending unauthenticated msg 0x3fcb7808 with MessageCounter:216505425 to 0x0000000000000000 at monotonic time: 0000000000004C11 msec I (19491) chip[SC]: Received Sigma3 msg E (19491) chip[SC]: The device does not support GetClock_RealTimeMS() API: 6c. Falling back to Last Known Good UTC Time I (20541) chip[IN]: Prepared unauthenticated message 0x3fc960ec to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 59980r with MessageCounter:216505426. I (20561) chip[IN]: Sending unauthenticated msg 0x3fc960ec with MessageCounter:216505426 to 0x0000000000000000 at monotonic time: 000000000000504A msec I (20571) chip[SC]: SecureSession[0x3fc94680]: Moving from state 'kEstablishing' --> 'kActive' I (20581) chip[IN]: CASE Session established to peer: <000000000001B669, 1> I (20581) chip[IN]: CASE Server enabling CASE session setups E (20591) chip[DL]: Long dispatch time: 1146 ms, for event type 3 I (20601) chip[DL]: IP_EVENT_GOT_IP6 I (20611) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: 2400:4050:27e2:8b00:86f7:03ff:fe60:fbe4 I (20611) chip[DL]: IPv6 Internet connectivity ESTABLISHED I (20621) app-devicecallbacks: Current free heap: 104572 I (20621) app-devicecallbacks: IPv6 Server ready... I (20631) chip[DIS]: Updating services using commissioning mode 0 I (20641) chip[DIS]: CHIP minimal mDNS started advertising. I (20651) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (20651) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (20671) chip[DIS]: mDNS service published: _matter._tcp I (20671) app-devicecallbacks: Current free heap: 100860 I (20671) chip[DIS]: Updating services using commissioning mode 0 I (20691) chip[DIS]: CHIP minimal mDNS started advertising. I (20691) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (20701) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (20721) chip[DIS]: mDNS service published: _matter._tcp I (20721) ROUTE_HOOK: Hook already installed on netif, skip... I (20721) app-devicecallbacks: Current free heap: 95036 I (20731) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:232492533 on exchange 59981r I (20741) chip[FS]: GeneralCommissioning: Received CommissioningComplete I (20751) chip[FP]: Metadata for Fabric 0x1 persisted to storage. I (20771) chip[TS]: Committing Last Known Good Time to storage: 2022-07-18T18:06:23 I (20771) chip[ZCL]: OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x260FC187F506344B, FabricId 0000000000000001, NodeId 0000000000BC5C01, VendorId 0xFFF1 I (20541) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12 I (20791) chip[FS]: GeneralCommissioning: Successfully commited pending fabric data I (20811) chip[FS]: Fail-safe cleanly disarmed I (20811) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0030', EndPoint ID: '0x00', Attribute ID: '0x0000' I (20821) app-devicecallbacks: Unhandled cluster ID: 48 I (20831) app-devicecallbacks: Current free heap: 102056 I (20831) chip[IN]: Prepared secure message 0x3fc96104 to 0x000000000001B669 (1) of type 0x9 and protocolId (0, 1) on exchange 59981r with MessageCounter:230777039. I (20841) chip[IN]: Sending encrypted msg 0x3fc96104 with MessageCounter:230777039 to 0x000000000001B669 (1) at monotonic time: 000000000000516B msec E (20861) chip[DL]: Long dispatch time: 130 ms, for event type 3 I (20871) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:170621872 on exchange 59980r I (20881) chip[SVR]: Commissioning completed successfully I (20881) chip[DIS]: Updating services using commissioning mode 0 I (20901) chip[DIS]: CHIP minimal mDNS started advertising. I (20901) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (20911) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (20931) chip[DIS]: mDNS service published: _matter._tcp I (20931) chip[SC]: SecureSession[0x3fc945c8]: Moving from state 'kActive' --> 'kPendingEviction' I (20941) chip[BLE]: Releasing end point's BLE connection back to application. I (20941) app-devicecallbacks: Commissioning complete I (20951) NimBLE: GAP procedure initiated: stop advertising. I (20951) NimBLE: GAP procedure initiated: terminate connection; conn_handle=1 hci_reason=19 I (20971) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 0 notify = 0 I (20981) chip[DL]: CHIPoBLE unsubscribe received I (21051) chip[DL]: BLE GAP connection terminated (con 1 reason 0x216) W (21061) Timer: Timer not stopped W (21061) Timer: Timer not stopped W (21071) BTDM_INIT: esp_bt_mem_release not implemented, return OK I (21071) app-devicecallbacks: BLE deinit successful and memory reclaimed I (21081) app-devicecallbacks: Current free heap: 156396 E (21081) chip[DL]: Long dispatch time: 199 ms, for event type 32781 I (21091) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:232492534 on exchange 59981r E (21121) chip[BLE]: no endpoint for unsub recvd I (21121) app-devicecallbacks: CHIPoBLE disconnected I (21141) app-devicecallbacks: Current free heap: 159680 I (26491) wifi:bcn_timout,ap_probe_send_start I (26501) app-devicecallbacks: Current free heap: 159372 I (29001) wifi:ap_probe_send over, resett wifi status to disassoc I (29001) wifi:state: run -> init (c800) I (29001) wifi:pm stop, total sleep time: 1350507 us / 12089733 us W (29011) wifi:idx W (29011) wifi:idx I (29011) wifi:new:<1,0>, old:<1,1>, ap:<255,255>, sta:<1,0>, prof:1 I (29021) chip[DL]: WIFI_EVENT_STA_DISCONNECTED I (29021) phy: chan:1,max_power:80 I (29031) phy: chan:2,max_power:80 I (29041) phy: chan:3,max_power:80 I (29041) phy: chan:4,max_power:80 I (29041) phy: chan:5,max_power:80 I (29051) phy: chan:6,max_power:80 I (29051) phy: chan:7,max_power:80 I (29051) phy: chan:8,max_power:80 I (29061) phy: chan:9,max_power:80 I (29061) phy: chan:10,max_power:80 I (29061) phy: chan:11,max_power:80 I (29071) phy: chan:12,max_power:80 I (29071) phy: chan:13,max_power:80 I (29071) phy: chan:14,max_power:80 W (29081) wifi:Haven't to connect to a suitable AP now! I (29081) chip[DL]: WiFi station state change: Connected -> NotConnected I (29101) chip[DL]: WiFi station interface disconnected I (29101) chip[ZCL]: WiFiDiagnosticsDelegate: OnDisconnectionDetected I (29111) chip[ZCL]: WiFiDiagnosticsDelegate: OnConnectionStatusChanged I (29111) chip[DL]: IPv4 Internet connectivity LOST I (29121) chip[DL]: IPv6 Internet connectivity LOST I (29121) chip[DL]: Attempting to connect WiFi station interface I (29131) chip[DL]: WiFi station state change: NotConnected -> Connecting I (29131) chip[DL]: Done driving station state, nothing else to do... I (29151) app-devicecallbacks: Current free heap: 160312 E (29151) chip[DL]: Long dispatch time: 123 ms, for event type 49152 W (29161) wifi:Haven't to connect to a suitable AP now! E (29161) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F I (29171) chip[DL]: Updating advertising data I (29181) app-devicecallbacks: Current free heap: 160312 E (29181) app-devicecallbacks: Lost IPv4 connectivity... E (29191) app-devicecallbacks: Lost IPv6 connectivity... I (29191) app-devicecallbacks: Current free heap: 160312 W (29201) wifi:Haven't to connect to a suitable AP now! E (29211) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F I (31191) chip[DL]: WIFI_EVENT_STA_DISCONNECTED I (31191) chip[DL]: WiFi station state change: Connecting -> Connecting_Failed I (31201) phy: chan:1,max_power:80 I (31201) phy: chan:2,max_power:80 I (31201) phy: chan:3,max_power:80 I (31221) phy: chan:4,max_power:80 I (31221) phy: chan:5,max_power:80 I (31221) phy: chan:6,max_power:80 I (31231) phy: chan:7,max_power:80 I (31231) phy: chan:8,max_power:80 I (31231) phy: chan:9,max_power:80 I (31241) phy: chan:10,max_power:80 I (31241) phy: chan:11,max_power:80 I (31241) phy: chan:12,max_power:80 I (31251) phy: chan:13,max_power:80 I (31251) phy: chan:14,max_power:80 W (31251) wifi:Haven't to connect to a suitable AP now! I (31261) chip[DL]: WiFi station state change: Connecting_Failed -> NotConnected I (31271) chip[DL]: Next WiFi station reconnect in 5000 ms I (31271) chip[DL]: Done driving station state, nothing else to do... I (31291) app-devicecallbacks: Current free heap: 160344 W (31291) wifi:Haven't to connect to a suitable AP now! E (31301) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F W (31301) wifi:Haven't to connect to a suitable AP now! E (31311) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F I (36271) phy: chan:1,max_power:80 I (36271) phy: chan:2,max_power:80 I (36281) phy: chan:3,max_power:80 I (36281) phy: chan:4,max_power:80 I (36291) phy: chan:5,max_power:80 I (36291) phy: chan:6,max_power:80 I (36301) phy: chan:7,max_power:80 I (36301) phy: chan:8,max_power:80 I (36301) phy: chan:9,max_power:80 I (36311) phy: chan:10,max_power:80 I (36311) phy: chan:11,max_power:80 I (36311) phy: chan:12,max_power:80 I (36321) phy: chan:13,max_power:80 I (36321) phy: chan:14,max_power:80 W (36321) wifi:Haven't to connect to a suitable AP now! I (36331) chip[DL]: Attempting to connect WiFi station interface I (36331) chip[DL]: WiFi station state change: NotConnected -> Connecting I (36351) chip[DL]: Done driving station state, nothing else to do... I (36341) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1 I (36361) wifi:state: init -> auth (b0) I (36361) wifi:state: auth -> assoc (0) E (36371) wifi:Association refused temporarily, comeback time 0 mSec I (36371) wifi:state: assoc -> assoc (0) E (36381) wifi:Association refused temporarily, comeback time 0 mSec I (36381) wifi:state: assoc -> assoc (0) E (36391) wifi:Association refused temporarily, comeback time 0 mSec I (36391) wifi:state: assoc -> assoc (0) E (36401) wifi:Association refused temporarily, comeback time 0 mSec I (36401) wifi:state: assoc -> assoc (0) E (36411) wifi:Association refused temporarily, comeback time 0 mSec I (36411) wifi:state: assoc -> assoc (0) E (36421) wifi:Association refused temporarily, comeback time 0 mSec I (36421) wifi:state: assoc -> assoc (0) E (36441) wifi:Association refused temporarily, comeback time 0 mSec I (36441) wifi:state: assoc -> assoc (0) E (36451) wifi:Association refused temporarily, comeback time 0 mSec I (36451) wifi:state: assoc -> assoc (0) E (36451) wifi:Association refused temporarily, comeback time 0 mSec I (36451) wifi:state: assoc -> assoc (0) E (36471) wifi:Association refused temporarily, comeback time 0 mSec I (36471) wifi:state: assoc -> assoc (0) E (36481) wifi:Association refused temporarily, comeback time 0 mSec I (36481) wifi:state: assoc -> assoc (0) E (36491) wifi:Association refused temporarily, comeback time 0 mSec I (36491) wifi:state: assoc -> assoc (0) E (36501) wifi:Association refused temporarily, comeback time 0 mSec I (36501) wifi:state: assoc -> assoc (0) E (36521) wifi:Association refused temporarily, comeback time 0 mSec I (36521) wifi:state: assoc -> assoc (0) E (36531) wifi:Association refused temporarily, comeback time 0 mSec I (36531) wifi:state: assoc -> assoc (0) E (36541) wifi:Association refused temporarily, comeback time 0 mSec I (36551) wifi:state: assoc -> assoc (0) E (36551) wifi:Association refused temporarily, comeback time 0 mSec I (36551) wifi:state: assoc -> assoc (0) E (36571) wifi:Association refused temporarily, comeback time 0 mSec I (36571) wifi:state: assoc -> assoc (0) E (36581) wifi:Association refused temporarily, comeback time 0 mSec I (36581) wifi:state: assoc -> assoc (0) E (36581) wifi:Association refused temporarily, comeback time 0 mSec I (36591) wifi:state: assoc -> assoc (0) E (36591) wifi:Association refused temporarily, comeback time 0 mSec I (36591) wifi:state: assoc -> assoc (0) E (36641) wifi:Association refused temporarily, comeback time 0 mSec I (36641) wifi:state: assoc -> assoc (0) E (36661) wifi:Association refused temporarily, comeback time 0 mSec I (36671) wifi:state: assoc -> assoc (0) E (36711) wifi:Association refused temporarily, comeback time 0 mSec I (36711) wifi:state: assoc -> assoc (0) E (36721) wifi:Association refused temporarily, comeback time 0 mSec I (36721) wifi:state: assoc -> assoc (0) E (36731) wifi:Association refused temporarily, comeback time 0 mSec I (36731) wifi:state: assoc -> assoc (0) E (36741) wifi:Association refused temporarily, comeback time 0 mSec I (36741) wifi:state: assoc -> assoc (0) E (36741) wifi:Association refused temporarily, comeback time 0 mSec I (36741) wifi:state: assoc -> assoc (0) E (36761) wifi:Association refused temporarily, comeback time 0 mSec I (36761) wifi:state: assoc -> assoc (0) E (36771) wifi:Association refused temporarily, comeback time 0 mSec I (36771) wifi:state: assoc -> assoc (0) E (36781) wifi:Association refused temporarily, comeback time 0 mSec I (36781) wifi:state: assoc -> assoc (0) E (36791) wifi:Association refused temporarily, comeback time 0 mSec I (36791) wifi:state: assoc -> assoc (0) E (36811) wifi:Association refused temporarily, comeback time 0 mSec I (36811) wifi:state: assoc -> assoc (0) E (36811) wifi:Association refused temporarily, comeback time 0 mSec I (36811) wifi:state: assoc -> assoc (0) E (36831) wifi:Association refused temporarily, comeback time 0 mSec I (36831) wifi:state: assoc -> assoc (0) E (36841) wifi:Association refused temporarily, comeback time 0 mSec I (36841) wifi:state: assoc -> assoc (0) E (36851) wifi:Association refused temporarily, comeback time 0 mSec I (36861) wifi:state: assoc -> assoc (0) E (36861) wifi:Association refused temporarily, comeback time 0 mSec I (36861) wifi:state: assoc -> assoc (0) E (36881) wifi:Association refused temporarily, comeback time 0 mSec I (36881) wifi:state: assoc -> assoc (0) E (36881) wifi:Association refused temporarily, comeback time 0 mSec I (36881) wifi:state: assoc -> assoc (0) E (36891) wifi:Association refused temporarily, comeback time 0 mSec I (36891) wifi:state: assoc -> assoc (0) E (36911) wifi:Association refused temporarily, comeback time 0 mSec I (36911) wifi:state: assoc -> assoc (0) E (36921) wifi:Association refused temporarily, comeback time 0 mSec I (36921) wifi:state: assoc -> assoc (0) E (36931) wifi:Association refused temporarily, comeback time 0 mSec I (36931) wifi:state: assoc -> assoc (0) E (36931) wifi:Association refused temporarily, comeback time 0 mSec I (36931) wifi:state: assoc -> assoc (0) E (36951) wifi:Association refused temporarily, comeback time 0 mSec I (36951) wifi:state: assoc -> assoc (0) E (36961) wifi:Association refused temporarily, comeback time 0 mSec I (36961) wifi:state: assoc -> assoc (0) E (36981) wifi:Association refused temporarily, comeback time 0 mSec I (36981) wifi:state: assoc -> assoc (0) E (36991) wifi:Association refused temporarily, comeback time 0 mSec I (36991) wifi:state: assoc -> assoc (0) E (36991) wifi:Association refused temporarily, comeback time 0 mSec I (36991) wifi:state: assoc -> assoc (0) E (37041) wifi:Association refused temporarily, comeback time 0 mSec I (37041) wifi:state: assoc -> assoc (0) E (37041) wifi:Association refused temporarily, comeback time 0 mSec I (37041) wifi:state: assoc -> assoc (0) E (37081) wifi:Association refused temporarily, comeback time 0 mSec I (37081) wifi:state: assoc -> assoc (0) E (37121) wifi:Association refused temporarily, comeback time 0 mSec I (37121) wifi:state: assoc -> assoc (0) E (37121) wifi:Association refused temporarily, comeback time 0 mSec I (37131) wifi:state: assoc -> assoc (0) E (37131) wifi:Association refused temporarily, comeback time 0 mSec I (37131) wifi:state: assoc -> assoc (0) E (37151) wifi:Association refused temporarily, comeback time 0 mSec I (37161) wifi:state: assoc -> assoc (0) E (37181) wifi:Association refused temporarily, comeback time 0 mSec I (37181) wifi:state: assoc -> assoc (0) E (37191) wifi:Association refused temporarily, comeback time 0 mSec I (37191) wifi:state: assoc -> assoc (0) E (37231) wifi:Association refused temporarily, comeback time 0 mSec I (37231) wifi:state: assoc -> assoc (0) E (37241) wifi:Association refused temporarily, comeback time 0 mSec I (37241) wifi:state: assoc -> assoc (0) E (37241) wifi:Association refused temporarily, comeback time 0 mSec I (37251) wifi:state: assoc -> assoc (0) E (37261) wifi:Association refused temporarily, comeback time 0 mSec I (37261) wifi:state: assoc -> assoc (0) E (37271) wifi:Association refused temporarily, comeback time 0 mSec I (37271) wifi:state: assoc -> assoc (0) E (37281) wifi:Association refused temporarily, comeback time 0 mSec I (37291) wifi:state: assoc -> assoc (0) E (37291) wifi:Association refused temporarily, comeback time 0 mSec I (37291) wifi:state: assoc -> assoc (0) E (37301) wifi:Association refused temporarily, comeback time 0 mSec I (37301) wifi:state: assoc -> assoc (0) E (37321) wifi:Association refused temporarily, comeback time 0 mSec I (37321) wifi:state: assoc -> assoc (0) E (37321) wifi:Association refused temporarily, comeback time 0 mSec I (37331) wifi:state: assoc -> assoc (0) E (37331) wifi:Association refused temporarily, comeback time 0 mSec I (37341) wifi:state: assoc -> assoc (0) E (37341) wifi:Association refused temporarily, comeback time 0 mSec I (37341) wifi:state: assoc -> assoc (0) E (37361) wifi:Association refused temporarily, comeback time 0 mSec I (37361) wifi:state: assoc -> assoc (0) E (37371) wifi:Association refused temporarily, comeback time 0 mSec I (37371) wifi:state: assoc -> assoc (0) E (37381) wifi:Association refused temporarily, comeback time 0 mSec I (37381) wifi:state: assoc -> assoc (0) E (37391) wifi:Association refused temporarily, comeback time 0 mSec I (37391) wifi:state: assoc -> assoc (0) I (38391) wifi:state: assoc -> init (200) I (38391) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1 I (38391) chip[DL]: WIFI_EVENT_STA_DISCONNECTED I (38401) chip[DL]: WiFi station state change: Connecting -> Connecting_Failed I (38401) phy: chan:1,max_power:80 I (38421) phy: chan:2,max_power:80 I (38421) phy: chan:3,max_power:80 I (38421) phy: chan:4,max_power:80 I (38431) phy: chan:5,max_power:80 I (38431) phy: chan:6,max_power:80 I (38431) phy: chan:7,max_power:80 I (38441) phy: chan:8,max_power:80 I (38441) phy: chan:9,max_power:80 I (38441) phy: chan:10,max_power:80 I (38451) phy: chan:11,max_power:80 I (38451) phy: chan:12,max_power:80 I (38451) phy: chan:13,max_power:80 I (38461) phy: chan:14,max_power:80 W (38461) wifi:Haven't to connect to a suitable AP now! I (38471) chip[DL]: WiFi station state change: Connecting_Failed -> NotConnected I (38481) chip[DL]: Next WiFi station reconnect in 5000 ms I (38491) chip[DL]: Done driving station state, nothing else to do... I (38491) app-devicecallbacks: Current free heap: 160332 E (38501) chip[DL]: Long dispatch time: 106 ms, for event type 49152 W (38511) wifi:Haven't to connect to a suitable AP now! E (38511) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F W (38521) wifi:Haven't to connect to a suitable AP now! E (38521) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F I (43491) phy: chan:1,max_power:80 I (43491) phy: chan:2,max_power:80 I (43491) phy: chan:3,max_power:80 I (43491) phy: chan:4,max_power:80 I (43501) phy: chan:5,max_power:80 I (43501) phy: chan:6,max_power:80 I (43511) phy: chan:7,max_power:80 I (43511) phy: chan:8,max_power:80 I (43511) phy: chan:9,max_power:80 I (43521) phy: chan:10,max_power:80 I (43521) phy: chan:11,max_power:80 I (43521) phy: chan:12,max_power:80 I (43531) phy: chan:13,max_power:80 I (43531) phy: chan:14,max_power:80 W (43531) wifi:Haven't to connect to a suitable AP now! I (43551) chip[DL]: Attempting to connect WiFi station interface I (43551) chip[DL]: WiFi station state change: NotConnected -> Connecting I (43561) chip[DL]: Done driving station state, nothing else to do... W (43561) wifi:Haven't to connect to a suitable AP now! E (43571) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F I (45591) chip[DL]: WIFI_EVENT_STA_DISCONNECTED I (45601) chip[DL]: WiFi station state change: Connecting -> Connecting_Failed I (45611) phy: chan:1,max_power:80 I (45611) phy: chan:2,max_power:80 I (45611) phy: chan:3,max_power:80 I (45621) phy: chan:4,max_power:80 I (45621) phy: chan:5,max_power:80 I (45621) phy: chan:6,max_power:80 I (45631) phy: chan:7,max_power:80 I (45631) phy: chan:8,max_power:80 I (45631) phy: chan:9,max_power:80 I (45641) phy: chan:10,max_power:80 I (45641) phy: chan:11,max_power:80 I (45641) phy: chan:12,max_power:80 I (45651) phy: chan:13,max_power:80 I (45651) phy: chan:14,max_power:80 W (45661) wifi:Haven't to connect to a suitable AP now! I (45671) chip[DL]: WiFi station state change: Connecting_Failed -> NotConnected I (45681) chip[DL]: Next WiFi station reconnect in 5000 ms I (45681) chip[DL]: Done driving station state, nothing else to do... I (45691) app-devicecallbacks: Current free heap: 160344 W (45691) wifi:Haven't to connect to a suitable AP now! E (45701) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F W (45701) wifi:Haven't to connect to a suitable AP now! E (45711) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F I (50681) phy: chan:1,max_power:80 I (50681) phy: chan:2,max_power:80 I (50681) phy: chan:3,max_power:80 I (50681) phy: chan:4,max_power:80 I (50691) phy: chan:5,max_power:80 I (50691) phy: chan:6,max_power:80 I (50701) phy: chan:7,max_power:80 I (50701) phy: chan:8,max_power:80 I (50701) phy: chan:9,max_power:80 I (50711) phy: chan:10,max_power:80 I (50711) phy: chan:11,max_power:80 I (50711) phy: chan:12,max_power:80 I (50731) phy: chan:13,max_power:80 I (50731) phy: chan:14,max_power:80 W (50731) wifi:Haven't to connect to a suitable AP now! I (50741) chip[DL]: Attempting to connect WiFi station interface I (50741) chip[DL]: WiFi station state change: NotConnected -> Connecting I (50751) chip[DL]: Done driving station state, nothing else to do... I (50751) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1 I (50761) wifi:state: init -> auth (b0) I (50771) wifi:state: auth -> assoc (0) I (50771) wifi:state: assoc -> run (10) I (50801) wifi:connected with pr600k-eaf2cc-2, aid = 1, channel 1, BW20, bssid = 16:66:82:fa:9e:c5 I (50811) wifi:security: WPA2-PSK, phy: bgn, rssi: -59 I (50821) wifi:pm start, type: 1 I (50821) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 14, mt_pti: 25000, mt_time: 10000 I (50821) chip[DL]: WIFI_EVENT_STA_CONNECTED I (50831) chip[DL]: WiFi station state change: Connecting -> Connecting_Succeeded I (50831) phy: chan:1,max_power:80 I (50841) phy: chan:2,max_power:80 I (50841) phy: chan:3,max_power:80 I (50851) phy: chan:4,max_power:80 I (50861) phy: chan:5,max_power:80 I (50861) phy: chan:6,max_power:80 I (50861) phy: chan:7,max_power:80 I (50871) phy: chan:8,max_power:80 I (50871) phy: chan:9,max_power:80 I (50881) phy: chan:10,max_power:80 I (50881) phy: chan:11,max_power:80 I (50881) phy: chan:12,max_power:80 I (50891) phy: chan:13,max_power:80 I (50891) phy: chan:14,max_power:80 I (50891) chip[DL]: WiFi station state change: Connecting_Succeeded -> Connected I (50901) chip[DL]: WiFi station interface connected I (50901) chip[ZCL]: WiFiDiagnosticsDelegate: OnConnectionStatusChanged I (50921) chip[DL]: Done driving station state, nothing else to do... I (50921) app-devicecallbacks: Current free heap: 157724 E (50931) chip[DL]: Long dispatch time: 108 ms, for event type 49152 I (50911) wifi:BcnInt:102400, DTIM:1 I (50941) chip[DL]: Updating advertising data I (50941) app-devicecallbacks: Current free heap: 159400 W (52051) wifi:idx:0 (ifx:0, 16:66:82:fa:9e:c5), tid:6, ssn:2, winSize:64 I (52651) chip[DL]: IP_EVENT_GOT_IP6 I (52651) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fe80:0000:0000:0000:86f7:03ff:fe60:fbe4 I (52661) app-devicecallbacks: Current free heap: 159608 I (52661) chip[DIS]: Updating services using commissioning mode 0 I (52671) chip[DIS]: CHIP minimal mDNS started advertising. I (52671) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (52691) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (52691) chip[DIS]: mDNS service published: _matter._tcp I (52691) ROUTE_HOOK: Hook already installed on netif, skip... I (52701) app-devicecallbacks: Current free heap: 159780 I (53051) esp_netif_handlers: sta ip: 192.168.1.26, mask: 255.255.255.0, gw: 192.168.1.1 I (53051) chip[DL]: IP_EVENT_STA_GOT_IP I (53051) chip[DL]: IPv4 address ready on WiFi station interface: 192.168.1.26/255.255.255.0 gateway 192.168.1.1 I (53061) chip[DL]: IPv4 Internet connectivity ESTABLISHED I (53071) app-devicecallbacks: Current free heap: 159788 I (53071) app-devicecallbacks: IPv4 Server ready... I (53081) chip[DIS]: Updating services using commissioning mode 0 I (53081) chip[DIS]: CHIP minimal mDNS started advertising. I (53101) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (53101) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (53121) chip[DIS]: mDNS service published: _matter._tcp I (53121) app-devicecallbacks: Current free heap: 158868 I (53121) chip[DIS]: Updating services using commissioning mode 0 I (53131) chip[DIS]: CHIP minimal mDNS started advertising. I (53141) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (53151) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (53161) chip[DIS]: mDNS service published: _matter._tcp I (53161) app-devicecallbacks: Current free heap: 159364 I (55651) chip[DL]: IP_EVENT_GOT_IP6 I (55651) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: 2400:4050:27e2:8b00:86f7:03ff:fe60:fbe4 I (55661) chip[DL]: IPv6 Internet connectivity ESTABLISHED I (55661) app-devicecallbacks: Current free heap: 159804 I (55671) app-devicecallbacks: IPv6 Server ready... I (55671) chip[DIS]: Updating services using commissioning mode 0 I (55681) chip[DIS]: CHIP minimal mDNS started advertising. I (55691) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (55691) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (55711) chip[DIS]: mDNS service published: _matter._tcp I (55711) app-devicecallbacks: Current free heap: 158300 I (55711) chip[DIS]: Updating services using commissioning mode 0 I (55731) chip[DIS]: CHIP minimal mDNS started advertising. I (55731) chip[DIS]: Advertise operational node 260FC187F506344B-0000000000BC5C01 I (55741) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (55751) chip[DIS]: mDNS service published: _matter._tcp I (55751) ROUTE_HOOK: Hook already installed on netif, skip... I (55761) app-devicecallbacks: Current free heap: 158312