I (657) cpu_start: App cpu up. I (687) cpu_start: Pro cpu start user code I (687) cpu_start: cpu freq: 160000000 I (687) cpu_start: Application information: I (691) cpu_start: Project name: chip-all-clusters-app I (697) cpu_start: App version: test_event_4_2021_07_06-2755-g2 I (704) cpu_start: Compile time: Feb 8 2022 07:31:32 I (710) cpu_start: ELF file SHA256: 96446139f8d8e8c5... I (716) cpu_start: ESP-IDF: v4.4-beta1-177-ge104dd7f27 I (723) heap_init: Initializing. RAM available for dynamic allocation: I (730) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM I (736) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM I (742) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM I (749) heap_init: At 3FFD83C8 len 00007C38 (31 KiB): DRAM I (755) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (761) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM I (768) heap_init: At 4009E330 len 00001CD0 (7 KiB): IRAM I (775) spi_flash: detected chip: generic I (778) spi_flash: flash io: dio W (782) spi_flash: Detected size(16384k) larger than the size in the binary image header(4096k). Using the size in the binary image header. I (799) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. I (806) all-clusters-app: All Clusters Demo! I (816) all-clusters-app: This is ESP32 chip with 2 CPU cores, WiFi/BT/BLE, I (816) all-clusters-app: silicon revision 3, I (826) all-clusters-app: 4MB external flash I (1036) wifi:wifi driver task: 3ffde820, prio:23, stack:6656, core=0 I (1036) system_api: Base MAC address is not set I (1036) system_api: read default base MAC address from EFUSE I (1066) wifi:wifi firmware version: 7e67c79 I (1076) wifi:wifi certification version: v7.0 I (1076) wifi:config NVS flash: enabled I (1076) wifi:config nano formating: disabled > I (1086) wifi:Init data frame dynamic rx buffer num: 32 I (1086) wifi:Init management frame dynamic rx buffer num: 32 I (1096) wifi:Init management short buffer num: 32 I (1096) wifi:Init dynamic tx buffer num: 32 I (1096) wifi:Init static rx buffer size: 1600 I (1106) wifi:Init static rx buffer num: 10 I (1116) wifi:Init dynamic rx buffer num: 32 I (1116) wifi_init: rx ba win: 6 I (1116) wifi_init: tcpip mbox: 32 I (1126) wifi_init: udp mbox: 6 I (1126) wifi_init: tcp mbox: 6 I (1126) wifi_init: tcp tx win: 5744 I (1126) wifi_init: tcp rx win: 5744 I (1136) wifi_init: tcp mss: 1440 I (1136) wifi_init: WiFi IRAM OP enabled I (1156) wifi_init: WiFi RX IRAM OP enabled I (1166) chip[DL]: NVS set: chip-counters/reboot-count = 5 (0x5) I (1166) chip[DL]: Changing ESP WiFi mode: AP -> STA+AP I (1166) chip[DL]: Changing ESP WiFi mode: STA+AP -> STA I (1196) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC) I (1196) chip[SVR]: SetupQRCode: [MT:YNJV7P1814-C1648G00] I (1196) chip[SVR]: Copy/paste the below URL in a browser to see the QR Code: https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3AYNJV7P1814-C1648G00 I (1216) chip[SVR]: Manual pairing code: [34970412336] I (1226) chip[SVR]: Long manual pairing code: [749704123309050652790] I (1196) BTDM_INIT: BT controller compile version [6a07b06] I (1236) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07 I (1616) CHIP[DL]: BLE host-controller synced I (2146) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable, device name MATTER-3844) I (2146) NimBLE: GAP procedure initiated: advertise; I (2156) NimBLE: disc_mode=2 I (2156) NimBLE: adv_channel_map=0 own_addr_type=2 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (2166) NimBLE: I (2206) chip[DL]: CHIPoBLE advertising started E (2206) chip[DL]: Long dispatch time: 1014 ms, for event type 2 I (2226) chip[DL]: Starting ESP WiFi layer I (2226) wifi:mode : sta (8c:aa:b5:80:4b:4c) I (2226) wifi:enable tsf W (2226) wifi:Haven't to connect to a suitable AP now! I (2226) chip[DL]: Done driving station state, nothing else to do... W (2246) wifi:Haven't to connect to a suitable AP now! I (2246) chip[DL]: Done driving station state, nothing else to do... I (2246) chip[ZCL]: Using ZAP configuration... I (2276) chip[ZCL]: Initiating Admin Commissioning cluster. I (2276) chip[ZCL]: Door Lock server initialized I (2276) chip[ZCL]: OpCreds: Initiating OpCreds cluster by writing fabrics list from fabric table. I (2296) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0003', EndPoint ID: '0x00', Attribute ID: '0x0001' I (2306) app-devicecallbacks: Current free heap: 70416 I (2306) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x00', Attribute ID: '0x0000' I (2326) app-devicecallbacks: Unhandled cluster ID: 4 I (2336) app-devicecallbacks: Current free heap: 70416 E (2336) chip[ZCL]: Trying to write invalid Calendar Type E (2346) chip[ZCL]: Failed to write calendar type with error: 0x87 I (2346) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0003', EndPoint ID: '0x01', Attribute ID: '0x0001' I (2356) app-devicecallbacks: Current free heap: 72336 I (2366) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x01', Attribute ID: '0x0000' I (2376) app-devicecallbacks: Unhandled cluster ID: 4 I (2386) app-devicecallbacks: Current free heap: 72336 I (2386) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0005', EndPoint ID: '0x01', Attribute ID: '0x0000' I (2396) app-devicecallbacks: Unhandled cluster ID: 5 I (2416) app-devicecallbacks: Current free heap: 72336 I (2416) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0008', EndPoint ID: '0x01', Attribute ID: '0x0000' I (2426) app-devicecallbacks: Current free heap: 72336 I (2426) chip[ZCL]: Window Covering Cluster init I (2446) chip[ZCL]: Initialize PCC Server Cluster [EP:1] I (2446) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x0007' I (2456) app-devicecallbacks: Unhandled cluster ID: 768 I (2456) app-devicecallbacks: Current free heap: 72336 I (2466) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x0008' I (2486) app-devicecallbacks: Unhandled cluster ID: 768 I (2486) app-devicecallbacks: Current free heap: 72336 I (2496) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0300', EndPoint ID: '0x01', Attribute ID: '0x4001' I (2496) app-devicecallbacks: Unhandled cluster ID: 768 I (2506) app-devicecallbacks: Current free heap: 72336 I (2516) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0001' I (2526) app-devicecallbacks: Unhandled cluster ID: 1030 I (2536) app-devicecallbacks: Current free heap: 72336 I (2536) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0002' I (2546) app-devicecallbacks: Unhandled cluster ID: 1030 I (2556) app-devicecallbacks: Current free heap: 72336 I (2566) chip[ZCL]: WARNING: ATTRIBUTES ARE NOT BEING STORED IN FLASH! I (2576) chip[ZCL]: DEVICE WILL NOT FUNCTION PROPERLY AFTER REBOOTING!! I (2576) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0500', EndPoint ID: '0x01', Attribute ID: '0x0001' I (2586) app-devicecallbacks: Unhandled cluster ID: 1280 I (2596) app-devicecallbacks: Current free heap: 72336 I (2606) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0500', EndPoint ID: '0x01', Attribute ID: '0x0002' I (2616) app-devicecallbacks: Unhandled cluster ID: 1280 I (2616) app-devicecallbacks: Current free heap: 72336 I (2626) chip[ZCL]: Failed to send IAS Zone update. Err 0x70 I (2626) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0004', EndPoint ID: '0x02', Attribute ID: '0x0000' I (2636) app-devicecallbacks: Unhandled cluster ID: 4 I (2656) app-devicecallbacks: Current free heap: 72336 I (2656) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x02', Attribute ID: '0x0001' I (2666) app-devicecallbacks: Unhandled cluster ID: 1030 I (2676) app-devicecallbacks: Current free heap: 72336 I (2676) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x02', Attribute ID: '0x0002' I (2696) app-devicecallbacks: Unhandled cluster ID: 1030 I (2696) app-devicecallbacks: Current free heap: 72336 I (2336) all-clusters-app: Display initialized (height 240, width 320) I (2716) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (2726) chip[DL]: NVS set: chip-counters/GlobalMCTR = 5000 (0x1388) I (2726) chip[DL]: NVS set: chip-counters/global-eidc = 327680 (0x50000) I (2896) chip[DIS]: CHIP minimal mDNS started advertising. I (2896) chip[DIS]: Failed to find a valid admin pairing. Node ID unknown I (2906) chip[DIS]: Start dns-sd server - no current nodeId I (2916) chip[DIS]: Advertise commission parameter vendorID=9050 productID=65279 discriminator=3844/15 I (2926) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'. I (2926) chip[IN]: CASE Server enabling CASE session setups I (2946) chip[SVR]: Adding Multicast groups I (2946) chip[SVR]: Server Listening... I (2946) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (2956) app-devicecallbacks: Unhandled cluster ID: 1026 I (2966) app-devicecallbacks: Current free heap: 67468 I (2976) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0101', EndPoint ID: '0x01', Attribute ID: '0x0000' I (2986) app-devicecallbacks: Unhandled cluster ID: 257 I (2986) app-devicecallbacks: Current free heap: 67348 I (3006) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0406', EndPoint ID: '0x01', Attribute ID: '0x0000' I (3006) app-devicecallbacks: Unhandled cluster ID: 1030 I (3016) app-devicecallbacks: Current free heap: 67264 I (3016) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0045', EndPoint ID: '0x01', Attribute ID: '0x0000' I (3026) app-devicecallbacks: Unhandled cluster ID: 69 I (3046) app-devicecallbacks: Current free heap: 68140 I (3046) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (3056) app-devicecallbacks: Unhandled cluster ID: 1026 I (3056) app-devicecallbacks: Current free heap: 67780 I (3066) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0201', EndPoint ID: '0x01', Attribute ID: '0x0000' I (3086) app-devicecallbacks: Unhandled cluster ID: 513 I (3086) app-devicecallbacks: Current free heap: 67780 I (3096) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0201', EndPoint ID: '0x01', Attribute ID: '0x001c' I (3106) app-devicecallbacks: Unhandled cluster ID: 513 I (3106) app-devicecallbacks: Current free heap: 67732 I (3116) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0201', EndPoint ID: '0x01', Attribute ID: '0x0011' I (3126) app-devicecallbacks: Unhandled cluster ID: 513 I (3136) app-devicecallbacks: Current free heap: 67660 I (3136) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0201', EndPoint ID: '0x01', Attribute ID: '0x0012' I (3146) app-devicecallbacks: Unhandled cluster ID: 513 I (3156) app-devicecallbacks: Current free heap: 67536 I (3166) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0405', EndPoint ID: '0x01', Attribute ID: '0x0000' I (3176) app-devicecallbacks: Unhandled cluster ID: 1029 I (3176) app-devicecallbacks: Current free heap: 67416 E (3186) chip[DL]: Long dispatch time: 943 ms, for event type 2 I (3186) app-devicecallbacks: Current free heap: 67416 I (3206) chip[DL]: WIFI_EVENT_STA_START W (3206) wifi:Haven't to connect to a suitable AP now! I (3206) chip[DL]: Done driving station state, nothing else to do... I (3216) app-devicecallbacks: Current free heap: 67416 I (3046) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (3216) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable, device name MATTER-3844) I (3246) chip[DL]: Device already advertising, stop active advertisement and restart I (3246) NimBLE: GAP procedure initiated: stop advertising. I (3256) NimBLE: GAP procedure initiated: advertise; I (3256) NimBLE: disc_mode=2 I (3266) NimBLE: adv_channel_map=0 own_addr_type=2 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (3276) NimBLE: I (5286) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (5476) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (5626) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (5816) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (6116) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (6116) all-clusters-app: Opening QR code screen I (6126) all-clusters-app: QR CODE Text: 'MT:YNJV7P1814-C1648G00' I (6126) all-clusters-app: Setup discriminator: 3844 (0xf04) I (6136) all-clusters-app: Setup PIN code: 20202024 (0x1344228) I (6416) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (18306) chip[DL]: BLE GAP connection established (con 0) I (18306) chip[DL]: CHIPoBLE advertising stopped I (18306) app-devicecallbacks: Current free heap: 67232 I (18946) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (18956) chip[BLE]: local and remote recv window sizes = 5 I (18956) chip[BLE]: selected BTP version 4 I (18966) chip[BLE]: using BTP fragment sizes rx 244 / tx 244. I (19126) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 0 ) indicate = 0 notify = 1 I (19136) chip[DL]: CHIPoBLE subscribe received I (19136) NimBLE: GATT procedure initiated: notify; I (19146) NimBLE: att_handle=14 I (19146) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (19166) app-devicecallbacks: CHIPoBLE connection established I (19166) app-devicecallbacks: Current free heap: 67232 I (19196) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (19196) chip[EM]: Received message of type 0x20 with protocolId (0, 0) and MessageCounter:905217574 on exchange 46714r I (19736) chip[IN]: Prepared unauthenticated message 0x3ffe8964 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 46714r with MessageCounter:3821842840. I (19746) chip[IN]: Sending unauthenticated msg 0x3ffe8964 with MessageCounter:3821842840 to 0x0000000000000000 at monotonic time: 18973 msec I (19756) NimBLE: GATT procedure initiated: notify; I (19766) NimBLE: att_handle=14 I (19766) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 E (19776) chip[DL]: Long dispatch time: 585 ms, for event type 7 I (19846) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (19856) chip[EM]: Received message of type 0x22 with protocolId (0, 0) and MessageCounter:905217575 on exchange 46714r I (22326) chip[IN]: Prepared unauthenticated message 0x3ffe88e4 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 46714r with MessageCounter:3821842841. I (22336) chip[IN]: Sending unauthenticated msg 0x3ffe88e4 with MessageCounter:3821842841 to 0x0000000000000000 at monotonic time: 21563 msec I (22346) NimBLE: GATT procedure initiated: notify; I (22356) NimBLE: att_handle=14 I (22356) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 E (22366) chip[DL]: Long dispatch time: 2516 ms, for event type 7 I (22466) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (22466) chip[EM]: Received message of type 0x24 with protocolId (0, 0) and MessageCounter:905217576 on exchange 46714r I (22476) chip[IN]: Prepared unauthenticated message 0x3ffe8964 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 46714r with MessageCounter:3821842842. I (22496) chip[IN]: Sending unauthenticated msg 0x3ffe8964 with MessageCounter:3821842842 to 0x0000000000000000 at monotonic time: 21720 msec I (22506) NimBLE: GATT procedure initiated: notify; I (22506) NimBLE: att_handle=14 I (22526) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (22526) chip[SVR]: Commissioning completed session establishment step I (22536) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (22546) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (22556) chip[SVR]: Device completed Rendezvous process I (25156) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (27666) NimBLE: GATT procedure initiated: notify; I (27666) NimBLE: att_handle=14 I (27666) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (30196) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (32706) NimBLE: GATT procedure initiated: notify; I (32706) NimBLE: att_handle=14 I (32706) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (35236) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (37746) NimBLE: GATT procedure initiated: notify; I (37746) NimBLE: att_handle=14 I (37746) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41116) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (41126) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:10720873 on exchange 46715r I (41146) chip[IN]: Prepared secure message 0x3ffe8be4 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 46715r with MessageCounter:12945284. I (41156) chip[IN]: Sending encrypted msg 0x3ffe8be4 with MessageCounter:12945284 to 0xFFFFFFFB00000000 (0) at monotonic time: 40384 msec I (41176) NimBLE: GATT procedure initiated: notify; I (41176) NimBLE: att_handle=14 I (41176) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41216) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (41216) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:10720874 on exchange 46716r I (41236) chip[IN]: Prepared secure message 0x3ffe8be4 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 46716r with MessageCounter:12945285. I (41246) chip[IN]: Sending encrypted msg 0x3ffe8be4 with MessageCounter:12945285 to 0xFFFFFFFB00000000 (0) at monotonic time: 40474 msec I (41266) NimBLE: GATT procedure initiated: notify; I (41266) NimBLE: att_handle=14 I (41266) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41306) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (41306) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:10720875 on exchange 46717r I (41326) chip[IN]: Prepared secure message 0x3ffe8be4 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 46717r with MessageCounter:12945286. I (41336) chip[IN]: Sending encrypted msg 0x3ffe8be4 with MessageCounter:12945286 to 0xFFFFFFFB00000000 (0) at monotonic time: 40565 msec I (41356) NimBLE: GATT procedure initiated: notify; I (41356) NimBLE: att_handle=14 I (41356) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41396) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (41396) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:10720876 on exchange 46718r I (41416) chip[IN]: Prepared secure message 0x3ffe8be4 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 46718r with MessageCounter:12945287. I (41426) chip[IN]: Sending encrypted msg 0x3ffe8be4 with MessageCounter:12945287 to 0xFFFFFFFB00000000 (0) at monotonic time: 40656 msec I (41446) NimBLE: GATT procedure initiated: notify; I (41446) NimBLE: att_handle=14 I (41446) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41486) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (41486) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720877 on exchange 46719r I (41506) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 46719r with MessageCounter:12945288. I (41516) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945288 to 0xFFFFFFFB00000000 (0) at monotonic time: 40744 msec I (41536) NimBLE: GATT procedure initiated: notify; I (41536) NimBLE: att_handle=14 I (41536) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41576) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (41576) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720878 on exchange 46720r E (41596) chip[DL]: SetRegulatoryConfig failed with error: Error ESP32:0x05001109 I (41596) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 46720r with MessageCounter:12945289. I (41616) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945289 to 0xFFFFFFFB00000000 (0) at monotonic time: 40838 msec I (41626) NimBLE: GATT procedure initiated: notify; I (41626) NimBLE: att_handle=14 I (41636) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41696) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (41696) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720879 on exchange 46721r I (41716) chip[ZCL]: OpCreds: Certificate Chain request received for PAI I (41716) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 46721r with MessageCounter:12945290. I (41736) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945290 to 0xFFFFFFFB00000000 (0) at monotonic time: 40957 msec I (41746) NimBLE: GATT procedure initiated: notify; I (41746) NimBLE: att_handle=14 I (41746) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41766) NimBLE: GATT procedure initiated: notify; I (41766) NimBLE: att_handle=14 I (41776) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41776) NimBLE: GATT procedure initiated: notify; I (41786) NimBLE: att_handle=14 I (41796) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41866) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (41876) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720880 on exchange 46722r I (41896) chip[ZCL]: OpCreds: Certificate Chain request received for DAC I (41896) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 46722r with MessageCounter:12945291. I (41906) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945291 to 0xFFFFFFFB00000000 (0) at monotonic time: 41136 msec I (41926) NimBLE: GATT procedure initiated: notify; I (41926) NimBLE: att_handle=14 I (41926) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41946) NimBLE: GATT procedure initiated: notify; I (41946) NimBLE: att_handle=14 I (41956) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (41956) NimBLE: GATT procedure initiated: notify; I (41966) NimBLE: att_handle=14 I (41976) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (42056) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (42056) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720881 on exchange 46723r I (42076) chip[ZCL]: OpCreds: received an AttestationRequest I (42586) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 46723r with MessageCounter:12945292. I (42606) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945292 to 0xFFFFFFFB00000000 (0) at monotonic time: 41827 msec I (42616) NimBLE: GATT procedure initiated: notify; I (42616) NimBLE: att_handle=14 I (42616) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 E (42636) chip[DL]: Long dispatch time: 577 ms, for event type 7 I (42636) NimBLE: GATT procedure initiated: notify; I (42646) NimBLE: att_handle=14 I (42646) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (42776) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (42776) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720882 on exchange 46724r I (42796) chip[ZCL]: OpCreds: commissioner has requested a CSR I (44286) chip[ZCL]: OpCreds: NewCertificateSigningRequest returned 0 I (44796) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 46724r with MessageCounter:12945293. I (44806) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945293 to 0xFFFFFFFB00000000 (0) at monotonic time: 44032 msec I (44816) NimBLE: GATT procedure initiated: notify; I (44816) NimBLE: att_handle=14 I (44826) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 E (44836) chip[DL]: Long dispatch time: 2064 ms, for event type 7 I (44836) NimBLE: GATT procedure initiated: notify; I (44856) NimBLE: att_handle=14 I (44856) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (44966) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (45016) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (45026) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720883 on exchange 46725r I (45046) chip[ZCL]: OpCreds: commissioner has added a trusted root Cert I (45046) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 46725r with MessageCounter:12945294. I (45056) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945294 to 0xFFFFFFFB00000000 (0) at monotonic time: 44286 msec I (45076) NimBLE: GATT procedure initiated: notify; I (45076) NimBLE: att_handle=14 I (45086) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (45146) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (45206) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (45206) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720884 on exchange 46726r I (45226) chip[ZCL]: OpCreds: commissioner has added a NOC I (45226) chip[DIS]: Verifying the received credentials I (46236) chip[DIS]: Added new fabric at index: 1, Initialized: 1 I (46236) chip[DIS]: Assigned compressed fabric ID: 0x07C6659C28CE3501, node ID: 0x0000000000000001 I (46246) chip[DIS]: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage I (46256) chip[DIS]: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage I (46266) chip[ZCL]: OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000001, VendorId 0x0000 I (46276) chip[ZCL]: OpCreds: Call to fabricListChanged I (46296) chip[DIS]: Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage I (46296) chip[ZCL]: OpCreds: Fabric 1 was persisted to storage. FabricId 0000000000000000, NodeId 0000000000000001, VendorId 0x0000 I (46306) chip[ZCL]: OpCreds: Call to fabricListChanged I (46326) chip[DIS]: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage I (46326) chip[DIS]: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage I (46336) chip[ZCL]: OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000001, VendorId 0x0000 I (46346) chip[ZCL]: OpCreds: Call to fabricListChanged I (46356) chip[DIS]: Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage I (46356) chip[ZCL]: OpCreds: Fabric 1 was persisted to storage. FabricId 0000000000000000, NodeId 0000000000000001, VendorId 0x0000 I (46376) chip[ZCL]: OpCreds: Call to fabricListChanged I (46726) chip[ZCL]: OpCreds: ACL entry created for Fabric 1 CASE Admin NodeId 0xFEBB776F12FC11DA I (46726) chip[DIS]: Advertise operational node 07C6659C28CE3501-0000000000000001 I (46736) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (46746) chip[ZCL]: OpCreds: successfully added a NOC I (46756) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 46726r with MessageCounter:12945295. I (46766) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945295 to 0xFFFFFFFB00000000 (1) at monotonic time: 45995 msec I (46786) NimBLE: GATT procedure initiated: notify; I (46786) NimBLE: att_handle=14 I (46786) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 E (46796) chip[DL]: Long dispatch time: 1595 ms, for event type 7 I (46826) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (46826) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720885 on exchange 46727r I (46846) chip[IN]: Prepared secure message 0x3ffe89c4 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 46727r with MessageCounter:12945296. I (46856) chip[IN]: Sending encrypted msg 0x3ffe89c4 with MessageCounter:12945296 to 0xFFFFFFFB00000000 (1) at monotonic time: 46085 msec I (46876) NimBLE: GATT procedure initiated: notify; I (46876) NimBLE: att_handle=14 I (46876) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (46916) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (46916) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:10720886 on exchange 46728r I (46936) chip[NP]: ESP NetworkCommissioningDelegate: SSID: Casa Lim$$?020!$$?$ I (46936) chip[DL]: WiFi station mode change: Enabled -> Disabled I (46986) chip[DL]: Changing ESP WiFi mode: STA -> STA+AP I (46986) wifi:mode : sta (8c:aa:b5:80:4b:4c) + softAP (0a:9f:dc:7d:0d:dd) I (46986) wifi:Total power save buffer number: 16 I (47006) wifi:Init max length of beacon: 752/752 I (47006) wifi:Init max length of beacon: 752/752 I (47016) chip[DL]: WiFi station mode change: Disabled -> Enabled E (47016) chip[DL]: Long dispatch time: 102 ms, for event type 7 W (47016) wifi:Haven't to connect to a suitable AP now! I (47026) chip[DL]: Attempting to connect WiFi station interface I (47036) chip[DL]: WiFi station state change: NotConnected -> Connecting I (47036) chip[DL]: Done driving station state, nothing else to do... I (47036) wifi:new:<1,1>, old:<1,1>, ap:<1,1>, sta:<1,0>, prof:1 I (48216) wifi:state: init -> auth (b0) I (48216) chip[DL]: Done driving station state, nothing else to do... E (48226) chip[DL]: Long dispatch time: 1173 ms, for event type 3 I (48226) chip[DL]: Done driving station state, nothing else to do... I (48236) chip[DL]: WIFI_EVENT_AP_START I (48236) chip[DL]: WiFi AP state change: NotActive -> Active I (48246) chip[DL]: Changing ESP WiFi mode: STA+AP -> STA I (48226) wifi:state: auth -> assoc (0) I (48256) wifi:mode : sta (8c:aa:b5:80:4b:4c) I (48266) chip[DL]: WiFi AP state change: Active -> Deactivating I (48266) app-devicecallbacks: Current free heap: 60932 I (48276) chip[DL]: WIFI_EVENT_AP_STOP I (48276) chip[DL]: WiFi AP state change: Deactivating -> NotActive I (48286) app-devicecallbacks: Current free heap: 61260 I (48266) wifi:state: assoc -> run (10) I (48296) wifi:connected with Casa Lim, aid = 3, channel 1, BW20, bssid = 4c:01:43:da:16:c6 I (48306) wifi:security: WPA2-PSK, phy: bgn, rssi: -47 I (48426) wifi:pm start, type: 1 I (48426) wifi:AP's beacon interval = 102400 us, DTIM period = 2 I (48436) chip[DL]: WIFI_EVENT_STA_CONNECTED I (48436) chip[DL]: WiFi station state change: Connecting -> Connecting_Succeeded W (48436) wifi:idx:0 (ifx:0, 4c:01:43:da:16:c6), tid:0, ssn:0, winSize:64 I (48456) chip[DL]: WiFi station state change: Connecting_Succeeded -> Connected I (48456) chip[DL]: WiFi station interface connected I (48466) chip[DIS]: Advertise operational node 07C6659C28CE3501-0000000000000001 I (48476) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. E (48486) chip[SVR]: Operational advertising enabled I (48486) app-devicecallbacks: Current free heap: 60824 I (48486) chip[IN]: Prepared secure message 0x3ffe8bb4 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 46728r with MessageCounter:12945297. I (48506) chip[IN]: Sending encrypted msg 0x3ffe8bb4 with MessageCounter:12945297 to 0xFFFFFFFB00000000 (1) at monotonic time: 47729 msec I (48516) NimBLE: GATT procedure initiated: notify; I (48526) NimBLE: att_handle=14 I (48526) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 0 I (48546) chip[DL]: Done driving station state, nothing else to do... I (48546) app-devicecallbacks: Current free heap: 60824 E (48556) chip[DL]: Long dispatch time: 124 ms, for event type 49152 I (48556) chip[DL]: Updating advertising data I (48566) app-devicecallbacks: Current free heap: 62344 I (50026) chip[DL]: IP_EVENT_GOT_IP6 I (50026) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fe80:0000:0000:0000:8eaa:b5ff:fe80:4b4c I (50026) chip[DL]: IPv4 Internet connectivity ESTABLISHED I (50046) app-devicecallbacks: Current free heap: 61704 I (50046) app-devicecallbacks: Server ready at: 192.168.7.145:5540 I (50056) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (50026) esp_netif_handlers: sta ip: 192.168.7.145, mask: 255.255.252.0, gw: 192.168.4.1 I (50066) chip[DIS]: CHIP minimal mDNS started advertising. I (50086) chip[DIS]: Advertise operational node 07C6659C28CE3501-0000000000000001 I (50096) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (50116) chip[DIS]: Have operational credentials I (50116) app-devicecallbacks: Current free heap: 61824 I (50116) chip[DIS]: CHIP minimal mDNS started advertising. I (50126) chip[DIS]: Advertise operational node 07C6659C28CE3501-0000000000000001 I (50126) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (50146) chip[DIS]: Have operational credentials I (50156) app-devicecallbacks: Current free heap: 61968 I (50156) chip[DL]: IP_EVENT_STA_GOT_IP I (50166) chip[DL]: IPv4 address changed on WiFi station interface: 192.168.7.145/255.255.252.0 gateway 192.168.4.1 I (50166) app-devicecallbacks: Current free heap: 62212 I (50176) ROUTE_HOOK: Received RIO I (50186) ROUTE_HOOK: prefix FD01:3E3:30D0:: lifetime 1800 I (50186) chip[EM]: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:905217577 on exchange 46729r I (50196) chip[IN]: CASE Server received Sigma1 message. Starting handshake. EC 0x3ffca188 I (50206) chip[DIS]: CASE handshake initiated, closing all BLE Connections I (50226) chip[BLE]: Releasing end point's BLE connection back to application. I (50226) chip[IN]: CASE Server disabling CASE session setups I (50236) chip[DIS]: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage I (50236) chip[DIS]: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage I (50246) chip[ZCL]: OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000001, VendorId 0x0000 I (50266) chip[ZCL]: OpCreds: Call to fabricListChanged I (50266) chip[DIS]: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage I (50286) chip[DIS]: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage I (50286) chip[ZCL]: OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000001, VendorId 0x0000 I (50296) chip[ZCL]: OpCreds: Call to fabricListChanged I (51776) chip[IN]: Prepared unauthenticated message 0x3ffca0a4 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 46729r with MessageCounter:3821842843. I (51786) chip[IN]: Sending unauthenticated msg 0x3ffca0a4 with MessageCounter:3821842843 to 0x0000000000000000 at monotonic time: 51015 msec E (51806) chip[DL]: Long dispatch time: 1624 ms, for event type 3 I (51806) chip[DIS]: CHIP minimal mDNS started advertising. I (51816) chip[DIS]: Advertise operational node 07C6659C28CE3501-0000000000000001 I (51816) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (51836) chip[DIS]: Have operational credentials I (51836) app-devicecallbacks: Current free heap: 48208 I (51776) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 12 I (51856) chip[BLE]: Releasing end point's BLE connection back to application. E (51856) chip[BLE]: HandleChipConnectionReceived failed, err = d E (51876) chip[BLE]: failed handle new chip BLE connection, status = d I (52026) chip[DL]: IP_EVENT_GOT_IP6 I (52026) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fdec:ac1c:f3c1:483b:8eaa:b5ff:fe80:4b4c I (52026) app-devicecallbacks: Current free heap: 59128 I (52046) chip[DIS]: CHIP minimal mDNS started advertising. I (52056) chip[DIS]: Advertise operational node 07C6659C28CE3501-0000000000000001 I (52056) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (52076) chip[DIS]: Have operational credentials I (52076) ROUTE_HOOK: Hook already installed on netif, skip... I (52086) app-devicecallbacks: Current free heap: 57028 I (52096) chip[EM]: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:905217578 on exchange 46729r I (54066) chip[IN]: Prepared unauthenticated message 0x3ffca0a4 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 46729r with MessageCounter:3821842844. I (54086) chip[IN]: Sending unauthenticated msg 0x3ffca0a4 with MessageCounter:3821842844 to 0x0000000000000000 at monotonic time: 53307 msec I (54096) chip[IN]: CASE Session established. Setting up the secure channel. I (54096) chip[IN]: CASE secure channel is available now. I (54106) chip[IN]: CASE Server enabling CASE session setups E (54116) chip[DL]: Long dispatch time: 2021 ms, for event type 3 I (54076) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 0 ) indicate = 0 notify = 0 I (54126) chip[DL]: CHIPoBLE unsubscribe received I (54136) chip[DL]: BLE GAP connection terminated (con 0 reason 0x08) E (54126) chip[BLE]: no endpoint for unsub recvd I (54156) app-devicecallbacks: CHIPoBLE disconnected I (54156) app-devicecallbacks: Current free heap: 59156 I (54286) ROUTE_HOOK: Received RIO I (54286) ROUTE_HOOK: prefix FD01:3E3:30D0:: lifetime 1800 I (54286) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5070068 on exchange 46730r I (54306) chip[IN]: Prepared secure message 0x3ffca0bc to 0xFEBB776F12FC11DA (1) of type 0x9 and protocolId (0, 1) on exchange 46730r with MessageCounter:4339777. I (54326) chip[IN]: Sending encrypted msg 0x3ffca0bc with MessageCounter:4339777 to 0xFEBB776F12FC11DA (1) at monotonic time: 53547 msec I (54336) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:905217579 on exchange 46729r I (54336) chip[SVR]: Commissioning completed successfully I (54356) chip[DIS]: CHIP minimal mDNS started advertising. I (54366) chip[DIS]: Advertise operational node 07C6659C28CE3501-0000000000000001 I (54366) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'. I (54386) chip[DIS]: Have operational credentials I (54396) app-devicecallbacks: Commissioning complete I (54396) app-devicecallbacks: Current free heap: 59144 I (54486) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:5070069 on exchange 46730r I (54586) ROUTE_HOOK: Received RIO I (54586) ROUTE_HOOK: prefix FDD6:BA28:E8A5:: lifetime 1800 I (55096) ROUTE_HOOK: Received RIO I (55096) ROUTE_HOOK: prefix FD01:3E3:30D0:: lifetime 1800 I (56126) chip[EM]: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:5070070 on exchange 46731r I (56136) chip[ZCL]: On/Off set value: 1 1 I (56136) chip[ZCL]: Toggle on/off from 0 to 1 I (56146) chip[ZCL]: On Command - OffWaitTime : 0 I (56146) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0006', EndPoint ID: '0x01', Attribute ID: '0x4002' I (56156) app-devicecallbacks: Unhandled Attribute ID: '0x4002 I (56166) app-devicecallbacks: Current free heap: 59128 I (56176) chip[ZCL]: On/Toggle Command - Stop Timer I (56176) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0006', EndPoint ID: '0x01', Attribute ID: '0x4000' I (56186) app-devicecallbacks: Unhandled Attribute ID: '0x4000 I (56196) app-devicecallbacks: Current free heap: 59128 I (56196) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0006', EndPoint ID: '0x01', Attribute ID: '0x0000' I (56216) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (56226) app-devicecallbacks: Current free heap: 59128 I (56236) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0008', EndPoint ID: '0x01', Attribute ID: '0x0000' I (56236) app-devicecallbacks: Current free heap: 59128 I (56246) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0005', EndPoint ID: '0x01', Attribute ID: '0x0003' I (56266) app-devicecallbacks: Unhandled cluster ID: 5 I (56266) app-devicecallbacks: Current free heap: 59128 I (56276) chip[IN]: Prepared secure message 0x3ffca0a4 to 0xFEBB776F12FC11DA (1) of type 0x9 and protocolId (0, 1) on exchange 46731r with MessageCounter:4339778. I (56296) chip[IN]: Sending encrypted msg 0x3ffca0a4 with MessageCounter:4339778 to 0xFEBB776F12FC11DA (1) at monotonic time: 55517 msec E (56306) chip[DL]: Long dispatch time: 182 ms, for event type 3 I (56306) chip[ZCL]: Event: move from 1 I (56306) chip[ZCL]: to 254 I (56326) chip[ZCL]: (diff +1) I (56336) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0008', EndPoint ID: '0x01', Attribute ID: '0x0000' I (56336) app-devicecallbacks: Current free heap: 58996 I (56346) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0005', EndPoint ID: '0x01', Attribute ID: '0x0003' I (56366) app-devicecallbacks: Unhandled cluster ID: 5 I (56366) app-devicecallbacks: Current free heap: 58996 I (56376) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0008', EndPoint ID: '0x01', Attribute ID: '0x0001' I (56386) app-devicecallbacks: Unhandled Attribute ID: '0x0001 I (56386) app-devicecallbacks: Current free heap: 58708 I (56406) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:5070071 on exchange 46731r I (58276) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:5070072 on exchange 46732r I (58286) chip[IN]: Prepared secure message 0x3ffca0a4 to 0xFEBB776F12FC11DA (1) of type 0x5 and protocolId (0, 1) on exchange 46732r with MessageCounter:4339779. I (58296) chip[IN]: Sending encrypted msg 0x3ffca0a4 with MessageCounter:4339779 to 0xFEBB776F12FC11DA (1) at monotonic time: 57525 msec I (58406) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:5070073 on exchange 46732r I (58886) ROUTE_HOOK: Received RIO I (58896) ROUTE_HOOK: prefix FD01:3E3:30D0:: lifetime 1800 I (58986) ROUTE_HOOK: Received RIO I (58986) ROUTE_HOOK: prefix FDD6:BA28:E8A5:: lifetime 1800 I (60326) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (60526) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (60926) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (61126) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (62076) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (62276) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (62426) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (62626) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (63326) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (63496) ROUTE_HOOK: Received RIO I (63496) ROUTE_HOOK: prefix FDD6:BA28:E8A5:: lifetime 1800 I (63526) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (63776) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (63776) all-clusters-app: Opening device list I (63806) ROUTE_HOOK: Received RIO I (63806) ROUTE_HOOK: prefix FD01:3E3:30D0:: lifetime 1800 I (63986) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (65036) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (65236) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (65386) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (65586) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (65786) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (65786) all-clusters-app: Opening device 2 I (65986) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (66536) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (66536) all-clusters-app: Opening endpoint 0 I (66736) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (67086) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (67086) all-clusters-app: Opening cluster 0 I (67286) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (67686) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (67686) all-clusters-app: Opening attribute 0 I (68036) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (68536) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (68536) all-clusters-app: editing attribute as integer: 21 (+) I (68546) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (68546) app-devicecallbacks: Unhandled cluster ID: 1026 I (68556) app-devicecallbacks: Current free heap: 60512 I (69106) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (69206) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (69206) all-clusters-app: editing attribute as integer: 22 (+) I (69216) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (69216) app-devicecallbacks: Unhandled cluster ID: 1026 I (69236) app-devicecallbacks: Current free heap: 60512 I (69476) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (69576) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (69576) all-clusters-app: editing attribute as integer: 23 (+) I (69586) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (69586) app-devicecallbacks: Unhandled cluster ID: 1026 I (69596) app-devicecallbacks: Current free heap: 60512 I (69846) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (69946) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (69946) all-clusters-app: editing attribute as integer: 24 (+) I (69956) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (69956) app-devicecallbacks: Unhandled cluster ID: 1026 I (69966) app-devicecallbacks: Current free heap: 60512 I (70316) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (71696) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:5070074 on exchange 46733r I (71896) chip[IN]: Prepared secure message 0x3ffe8cd4 to 0xFEBB776F12FC11DA (1) of type 0x10 and protocolId (0, 0) on exchange 46733r with MessageCounter:4339780. I (71906) chip[IN]: Sending encrypted msg 0x3ffe8cd4 with MessageCounter:4339780 to 0xFEBB776F12FC11DA (1) at monotonic time: 71135 msec I (74046) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:5070075 on exchange 46734r I (74246) chip[IN]: Prepared secure message 0x3ffe8cd4 to 0xFEBB776F12FC11DA (1) of type 0x10 and protocolId (0, 0) on exchange 46734r with MessageCounter:4339781. I (74266) chip[IN]: Sending encrypted msg 0x3ffe8cd4 with MessageCounter:4339781 to 0xFEBB776F12FC11DA (1) at monotonic time: 73490 msec I (77216) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:5070076 on exchange 46735r I (77426) chip[IN]: Prepared secure message 0x3ffe8cd4 to 0xFEBB776F12FC11DA (1) of type 0x10 and protocolId (0, 0) on exchange 46735r with MessageCounter:4339782. I (77436) chip[IN]: Sending encrypted msg 0x3ffe8cd4 with MessageCounter:4339782 to 0xFEBB776F12FC11DA (1) at monotonic time: 76664 msec I (79666) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (79856) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (80306) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (80306) all-clusters-app: editing attribute as integer: 25 (-) I (80316) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (80316) app-devicecallbacks: Unhandled cluster ID: 1026 I (80326) app-devicecallbacks: Current free heap: 60512 I (80526) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (80626) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (80626) all-clusters-app: editing attribute as integer: 24 (-) I (80636) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (80636) app-devicecallbacks: Unhandled cluster ID: 1026 I (80646) app-devicecallbacks: Current free heap: 60512 I (80846) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (80946) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (80946) all-clusters-app: editing attribute as integer: 23 (-) I (80956) app-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x0402', EndPoint ID: '0x01', Attribute ID: '0x0000' I (80956) app-devicecallbacks: Unhandled cluster ID: 1026 I (80966) app-devicecallbacks: Current free heap: 60512 I (81166) all-clusters-app: Display awake but will switch off automatically in 30 seconds I (81826) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:5070077 on exchange 46736r I (82036) chip[IN]: Prepared secure message 0x3ffe8cd4 to 0xFEBB776F12FC11DA (1) of type 0x10 and protocolId (0, 0) on exchange 46736r with MessageCounter:4339783. I (82046) chip[IN]: Sending encrypted msg 0x3ffe8cd4 with MessageCounter:4339783 to 0xFEBB776F12FC11DA (1) at monotonic time: 81273 msec I (99446) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:5070078 on exchange 46737r I (99446) chip[IM]: no resource for Read interaction I (99456) chip[IN]: Prepared secure message 0x3ffca0a4 to 0xFEBB776F12FC11DA (1) of type 0x1 and protocolId (0, 1) on exchange 46737r with MessageCounter:4339784. I (99466) chip[IN]: Sending encrypted msg 0x3ffca0a4 with MessageCounter:4339784 to 0xFEBB776F12FC11DA (1) at monotonic time: 98696 msec I (99636) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:5070079 on exchange 46737r I (100366) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:5070080 on exchange 46738r I (100366) chip[IM]: no resource for Read interaction I (100376) chip[IN]: Prepared secure message 0x3ffca0a4 to 0xFEBB776F12FC11DA (1) of type 0x1 and protocolId (0, 1) on exchange 46738r with MessageCounter:4339785. I (100396) chip[IN]: Sending encrypted msg 0x3ffca0a4 with MessageCounter:4339785 to 0xFEBB776F12FC11DA (1) at monotonic time: 99618 msec I (100566) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:5070081 on exchange 46738r I (102716) chip[EM]: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:5070082 on exchange 46739r I (102726) chip[IM]: no resource for Read interaction I (102736) chip[IN]: Prepared secure message 0x3ffca0a4 to 0xFEBB776F12FC11DA (1) of type 0x1 and protocolId (0, 1) on exchange 46739r with MessageCounter:4339786. I (102746) chip[IN]: Sending encrypted msg 0x3ffca0a4 with MessageCounter:4339786 to 0xFEBB776F12FC11DA (1) at monotonic time: 101973 msec I (102816) chip[EM]: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:5070083 on exchange 46739r I (111166) all-clusters-app: Display going to sleep... I (130876) ROUTE_HOOK: Received RIO I (130876) ROUTE_HOOK: prefix FDD6:BA28:E8A5:: lifetime 1800