irenesiu@Irenes-MacBook-Pro connectedhomeip % out/apps/ota-requestor/chip-ota-requestor-app --discriminator 30 --secured-device-port 5560 --KVS /tmp/chip_kvs_requestor [1650992623300] [32396:1415217] CHIP: [DL] KVS will be written to: file:///tmp/chip_kvs_requestor [1650992623315] [32396:1415217] CHIP: [SPT] *** WARNING: Using temporary passcode 20202021 due to no neither --passcode or --spake2p-verifier-base64 given on command line. This is temporary and will disappear. Please update your scripts to explicitly conf [1650992623315] [32396:1415217] CHIP: [SPT] PASE PBKDF iterations set to 1000 [1650992623315] [32396:1415217] CHIP: [SPT] LinuxCommissionableDataProvider didn't get a PASE salt, generating one. [1650992623318] [32396:1415217] CHIP: [DL] Device Configuration: [1650992623319] [32396:1415217] CHIP: [DL] Serial Number: TEST_SN [1650992623319] [32396:1415217] CHIP: [DL] Vendor Id: 65521 (0xFFF1) [1650992623319] [32396:1415217] CHIP: [DL] Product Id: 32769 (0x8001) [1650992623319] [32396:1415217] CHIP: [DL] Hardware Version: 0 [1650992623319] [32396:1415217] CHIP: [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1650992623319] [32396:1415217] CHIP: [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 30 (0x1E) [1650992623319] [32396:1415217] CHIP: [DL] Manufacturing Date: (not set) [1650992623319] [32396:1415217] CHIP: [DL] Device Type: 65535 (0xFFFF) [1650992623319] [32396:1415217] CHIP: [SVR] SetupQRCode: [MT:-24J0KCZ16.Z.548G00] [1650992623319] [32396:1415217] CHIP: [SVR] Copy/paste the below URL in a browser to see the QR Code: [1650992623319] [32396:1415217] CHIP: [SVR] https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J0KCZ16.Z.548G00 [1650992623319] [32396:1415217] CHIP: [SVR] Manual pairing code: [00054912336] [1650992623320] [32396:1415217] CHIP: [SVR] SetupQRCode: [MT:-24J0C6026.Z.548G00] [1650992623320] [32396:1415217] CHIP: [SVR] Copy/paste the below URL in a browser to see the QR Code: [1650992623320] [32396:1415217] CHIP: [SVR] https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J0C6026.Z.548G00 [1650992623320] [32396:1415217] CHIP: [SVR] Manual pairing code: [400549123365521327697] [1650992623320] [32396:1415217] CHIP: [ZCL] Using ZAP configuration... [1650992623320] [32396:1415217] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: ../../../examples/ota-requestor-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Val [1650992623320] [32396:1415217] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_0028, 0x0000_0010: ../../../examples/ota-requestor-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Val [1650992623320] [32396:1415217] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_002C, 0x0000_0000: ../../../examples/ota-requestor-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Val [1650992623320] [32396:1415217] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_002C, 0x0000_0001: ../../../examples/ota-requestor-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Val [1650992623320] [32396:1415217] CHIP: [DMG] AccessControlCluster: initializing [1650992623320] [32396:1415217] CHIP: [DIS] Add fabric pairing table delegate [1650992623320] [32396:1415217] CHIP: [ZCL] Initiating Admin Commissioning cluster. [1650992623321] [32396:1415217] CHIP: [ZCL] OpCreds: Initiating OpCreds cluster by writing fabrics list from fabric table. [1650992623321] [32396:1415217] CHIP: [DIS] Add fabric pairing table delegate [1650992623321] [32396:1415217] CHIP: [DMG] Endpoint 0, Cluster 0x0000_002B update version to 307975de [1650992623321] [32396:1415217] CHIP: [DIS] Init fabric pairing table with server storage [1650992623321] [32396:1415217] CHIP: [IN] Loading from storage for fabric index 0x1 [1650992623323] [32396:1415217] CHIP: [DIS] Fabric (1) loaded from storage [1650992623323] [32396:1415217] CHIP: [ZCL] OpCreds: Fabric index 0x1 was retrieved from storage. FabricId 0x0000000000000001, NodeId 0x0000001234567890, VendorId 0xFFF1 [1650992623323] [32396:1415217] CHIP: [ZCL] OpCreds: Call to fabricListChanged [1650992623323] [32396:1415217] CHIP: [DMG] Endpoint 0, Cluster 0x0000_003E update version to 77320d27 [1650992623323] [32396:1415217] CHIP: [DMG] Endpoint 0, Cluster 0x0000_003E update version to 77320d28 [1650992623323] [32396:1415217] CHIP: [DIS] Fabric (1) loaded from storage [1650992623323] [32396:1415217] CHIP: [DMG] AccessControl: initializing [1650992623323] [32396:1415217] CHIP: [DMG] Examples::AccessControlDelegate::Init [1650992623330] [32396:1415217] CHIP: [DMG] AccessControl: setting [1650992623330] [32396:1415217] CHIP: [IN] UDP::Init bind&listen port=5560 [1650992623330] [32396:1415217] CHIP: [IN] UDP::Init bound to port=5560 [1650992623330] [32396:1415217] CHIP: [IN] UDP::Init bind&listen port=5560 [1650992623330] [32396:1415217] CHIP: [IN] UDP::Init bound to port=5560 [1650992623330] [32396:1415217] CHIP: [IN] TransportMgr initialized [1650992623331] [32396:1415217] CHIP: [DIS] Add fabric pairing table delegate [1650992623331] [32396:1415217] CHIP: [SVR] Fabric already commissioned. Disabling BLE advertisement [1650992623331] [32396:1415217] CHIP: [DIS] Updating services using commissioning mode 0 [1650992623331] [32396:1415217] CHIP: [DL] Using wifi MAC for hostname [1650992623331] [32396:1415217] CHIP: [DIS] Advertise operational node 91EF925C6264024F-0000001234567890 [1650992623331] [32396:1415217] CHIP: [DL] Publishing service 91EF925C6264024F-0000001234567890 on port 5560 with type: _matter._tcp,_I91EF925C6264024F on interface id: 0 [1650992623332] [32396:1415217] CHIP: [IN] CASE Server enabling CASE session setups [1650992623332] [32396:1415217] CHIP: [SVR] Joining Multicast groups [1650992623332] [32396:1415217] CHIP: [ZCL] Emitting StartUp event [1650992623332] [32396:1415217] CHIP: [EVL] LogEvent event number: 0x0000000000030000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x00000000147C4742 [1650992623332] [32396:1415217] CHIP: [SVR] Server Listening... [1650992623332] [32396:1415217] CHIP: [DL] Device Configuration: [1650992623332] [32396:1415217] CHIP: [DL] Serial Number: TEST_SN [1650992623332] [32396:1415217] CHIP: [DL] Vendor Id: 65521 (0xFFF1) [1650992623332] [32396:1415217] CHIP: [DL] Product Id: 32769 (0x8001) [1650992623332] [32396:1415217] CHIP: [DL] Hardware Version: 0 [1650992623332] [32396:1415217] CHIP: [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1650992623332] [32396:1415217] CHIP: [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 30 (0x1E) [1650992623332] [32396:1415217] CHIP: [DL] Manufacturing Date: (not set) [1650992623333] [32396:1415217] CHIP: [DL] Device Type: 65535 (0xFFFF) [1650992623333] [32396:1415217] CHIP: [SVR] SetupQRCode: [MT:-24J0C6026.Z.548G00] [1650992623333] [32396:1415217] CHIP: [SVR] Copy/paste the below URL in a browser to see the QR Code: [1650992623333] [32396:1415217] CHIP: [SVR] https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J0C6026.Z.548G00 [1650992623333] [32396:1415217] CHIP: [SVR] Manual pairing code: [400549123365521327697] [1650992623333] [32396:1415217] CHIP: [SWU] Stopping the watchdog timer [1650992623333] [32396:1415217] CHIP: [SWU] Starting the periodic query timer, timeout: 86400 seconds [1650992623333] [32396:1415218] CHIP: [DIS] Updating services using commissioning mode 0 [1650992623333] [32396:1415218] CHIP: [DL] Using wifi MAC for hostname [1650992623333] [32396:1415218] CHIP: [DIS] Advertise operational node 91EF925C6264024F-0000001234567890 [1650992623333] [32396:1415218] CHIP: [DL] Publishing service 91EF925C6264024F-0000001234567890 on port 5560 with type: _matter._tcp,_I91EF925C6264024F on interface id: 0 [1650992623333] [32396:1415218] CHIP: [DMG] Endpoint 0, Cluster 0x0000_002A update version to c3e6d3be [1650992623333] [32396:1415218] CHIP: [DMG] Endpoint 0, Cluster 0x0000_002A update version to c3e6d3bf [1650992623333] [32396:1415218] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1650992623981] [32396:1415218] CHIP: [DL] Mdns: OnRegister name: 91EF925C6264024F-0000001234567890, type: _matter._tcp., domain: local., flags: 2 [1650992623981] [32396:1415218] CHIP: [DIS] mDNS service published: _matter. [1650992659710] [32396:1415399] CHIP: [EM] Received message of type 0x30 with protocolId (0, 0) and MessageCounter:4280285437 on exchange 42546r [1650992659710] [32396:1415399] CHIP: [EM] Handling via exchange: 42546r, Delegate: 0x10bd74f80 [1650992659710] [32396:1415399] CHIP: [IN] CASE Server received Sigma1 message. Starting handshake. EC 0x10bd76868 [1650992659710] [32396:1415399] CHIP: [SC] Waiting for Sigma1 msg [1650992659710] [32396:1415399] CHIP: [IN] CASE Server disabling CASE session setups [1650992659710] [32396:1415399] CHIP: [SC] Received Sigma1 msg [1650992659710] [32396:1415399] CHIP: [SC] Found MRP parameters in the message [1650992659710] [32396:1415399] CHIP: [SC] Peer assigned session key ID 37021 [1650992659711] [32396:1415399] CHIP: [SC] CASE matched destination ID: fabricIndex 1, NodeID 0x0000001234567890 [1650992659712] [32396:1415399] CHIP: [SC] Including MRP parameters [1650992659712] [32396:1415399] CHIP: [EM] Piggybacking Ack for MessageCounter:4280285437 on exchange: 42546r [1650992659712] [32396:1415399] CHIP: [IN] Prepared unauthenticated message 0x10bd75560 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 42546r with MessageCounter:1825606034. [1650992659712] [32396:1415399] CHIP: [IN] Sending unauthenticated msg 0x10bd75560 with MessageCounter:1825606034 to 0x0000000000000000 at monotonic time: 00000000147CD55E msec [1650992659712] [32396:1415399] CHIP: [SC] Sent Sigma2 msg [1650992659714] [32396:1415399] CHIP: [EM] Received message of type 0x32 with protocolId (0, 0) and MessageCounter:4280285438 on exchange 42546r [1650992659714] [32396:1415399] CHIP: [EM] Found matching exchange: 42546r, Delegate: 0x10bd74fa0 [1650992659714] [32396:1415399] CHIP: [EM] Rxd Ack; Removing MessageCounter:1825606034 from Retrans Table on exchange 42546r [1650992659714] [32396:1415399] CHIP: [EM] Removed CHIP MessageCounter:1825606034 from RetransTable on exchange 42546r [1650992659714] [32396:1415399] CHIP: [SC] Received Sigma3 msg [1650992659717] [32396:1415399] CHIP: [SC] Sending status report. Protocol code 0, exchange 42546 [1650992659717] [32396:1415399] CHIP: [EM] Piggybacking Ack for MessageCounter:4280285438 on exchange: 42546r [1650992659717] [32396:1415399] CHIP: [IN] Prepared unauthenticated message 0x10bd75560 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 42546r with MessageCounter:1825606035. [1650992659717] [32396:1415399] CHIP: [IN] Sending unauthenticated msg 0x10bd75560 with MessageCounter:1825606035 to 0x0000000000000000 at monotonic time: 00000000147CD564 msec [1650992659717] [32396:1415399] CHIP: [IN] New secure session created for device <000000000001B669, 1>, LSID:48039 PSID:37021! [1650992659717] [32396:1415399] CHIP: [IN] CASE Session established to peer: <000000000001B669, 1> [1650992659717] [32396:1415399] CHIP: [IN] CASE Server enabling CASE session setups [1650992659718] [32396:1415399] CHIP: [EM] Received message of type 0x3 with protocolId (0, 1) and MessageCounter:9190899 on exchange 42547r [1650992659718] [32396:1415399] CHIP: [EM] Handling via exchange: 42547r, Delegate: 0x10bd7d1d8 [1650992659718] [32396:1415399] CHIP: [IM] Received Subscribe request [1650992659718] [32396:1415399] CHIP: [DMG] SubscribeRequestMessage = [1650992659718] [32396:1415399] CHIP: [DMG] { [1650992659718] [32396:1415399] CHIP: [DMG] KeepSubscriptions = false, [1650992659718] [32396:1415399] CHIP: [DMG] MinIntervalFloorSeconds = 0x5, [1650992659718] [32396:1415399] CHIP: [DMG] MaxIntervalCeilingSeconds = 0xa, [1650992659718] [32396:1415399] CHIP: [DMG] EventPathIBs = [1650992659718] [32396:1415399] CHIP: [DMG] [ [1650992659718] [32396:1415399] CHIP: [DMG] EventPath = [1650992659718] [32396:1415399] CHIP: [DMG] { [1650992659718] [32396:1415399] CHIP: [DMG] Endpoint = 0x0, [1650992659718] [32396:1415399] CHIP: [DMG] Cluster = 0x2a, [1650992659718] [32396:1415399] CHIP: [DMG] Event = 0x0, [1650992659718] [32396:1415399] CHIP: [DMG] }, [1650992659718] [32396:1415399] CHIP: [DMG] [1650992659718] [32396:1415399] CHIP: [DMG] ], [1650992659718] [32396:1415399] CHIP: [DMG] [1650992659718] [32396:1415399] CHIP: [DMG] isFabricFiltered = true, [1650992659718] [32396:1415399] CHIP: [DMG] InteractionModelRevision = 1 [1650992659718] [32396:1415399] CHIP: [DMG] }, [1650992659718] [32396:1415399] CHIP: [DMG] Final negotiated min/max parameters: Min = 5s, Max = 10s [1650992659718] [32396:1415399] CHIP: [DMG] IM RH moving to [GeneratingReports] [1650992659718] [32396:1415399] CHIP: [DMG] Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1650992659719] [32396:1415399] CHIP: [DMG] Fetched 0 events [1650992659719] [32396:1415399] CHIP: [DMG] Sending report (payload has 15 bytes)... [1650992659719] [32396:1415399] CHIP: [DMG] IM RH moving to [AwaitingReportResponse] [1650992659719] [32396:1415399] CHIP: [EM] Piggybacking Ack for MessageCounter:9190899 on exchange: 42547r [1650992659719] [32396:1415399] CHIP: [IN] Prepared secure message 0x10bd75580 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 42547r with MessageCounter:4938994. [1650992659719] [32396:1415399] CHIP: [IN] Sending encrypted msg 0x10bd75580 with MessageCounter:4938994 to 0x000000000001B669 (1) at monotonic time: 00000000147CD565 msec [1650992659719] [32396:1415399] CHIP: [DMG] ReportsInFlight = 1 with readHandler 0, RE has no more messages [1650992659719] [32396:1415399] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1650992659719] [32396:1415399] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:4280285439 on exchange 42546r [1650992659719] [32396:1415399] CHIP: [EM] Found matching exchange: 42546r, Delegate: 0x0 [1650992659719] [32396:1415399] CHIP: [EM] Rxd Ack; Removing MessageCounter:1825606035 from Retrans Table on exchange 42546r [1650992659719] [32396:1415399] CHIP: [EM] Removed CHIP MessageCounter:1825606035 from RetransTable on exchange 42546r [1650992659719] [32396:1415399] CHIP: [EM] Received message of type 0x1 with protocolId (0, 1) and MessageCounter:9190900 on exchange 42547r [1650992659719] [32396:1415399] CHIP: [EM] Found matching exchange: 42547r, Delegate: 0x7f9fdd2099a0 [1650992659719] [32396:1415399] CHIP: [EM] Rxd Ack; Removing MessageCounter:4938994 from Retrans Table on exchange 42547r [1650992659719] [32396:1415399] CHIP: [EM] Removed CHIP MessageCounter:4938994 from RetransTable on exchange 42547r [1650992659719] [32396:1415399] CHIP: [DMG] StatusResponseMessage = [1650992659719] [32396:1415399] CHIP: [DMG] { [1650992659719] [32396:1415399] CHIP: [DMG] Status = 0x0, [1650992659719] [32396:1415399] CHIP: [DMG] InteractionModelRevision = 1 [1650992659719] [32396:1415399] CHIP: [DMG] } [1650992659719] [32396:1415399] CHIP: [IM] Received status response, status is 0x00 (SUCCESS) [1650992659719] [32396:1415399] CHIP: [DMG] Refresh Subscribe Sync Timer with max 10 seconds [1650992659719] [32396:1415399] CHIP: [DMG] OnReportConfirm: NumReports = 0 [1650992659719] [32396:1415399] CHIP: [DMG] IM RH moving to [GeneratingReports] [1650992659719] [32396:1415399] CHIP: [EM] Piggybacking Ack for MessageCounter:9190900 on exchange: 42547r [1650992659719] [32396:1415399] CHIP: [IN] Prepared secure message 0x10bd75560 to 0x000000000001B669 (1) of type 0x4 and protocolId (0, 1) on exchange 42547r with MessageCounter:4938995. [1650992659719] [32396:1415399] CHIP: [IN] Sending encrypted msg 0x10bd75560 with MessageCounter:4938995 to 0x000000000001B669 (1) at monotonic time: 00000000147CD566 msec [1650992659720] [32396:1415455] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:9190901 on exchange 42547r [1650992659720] [32396:1415455] CHIP: [EM] Found matching exchange: 42547r, Delegate: 0x0 [1650992659720] [32396:1415455] CHIP: [EM] Rxd Ack; Removing MessageCounter:4938995 from Retrans Table on exchange 42547r [1650992659720] [32396:1415455] CHIP: [EM] Removed CHIP MessageCounter:4938995 from RetransTable on exchange 42547r [1650992664720] [32396:1415399] CHIP: [DMG] Unblock report hold after min 5 seconds [1650992669720] [32396:1415399] CHIP: [DMG] Refresh subscribe timer sync after 5 seconds [1650992669720] [32396:1415399] CHIP: [DMG] Building Reports for ReadHandler with LastReportGeneration = 6 DirtyGeneration = 0 [1650992669720] [32396:1415399] CHIP: [DMG] Fetched 0 events [1650992669720] [32396:1415399] CHIP: [DMG] Sending report (payload has 15 bytes)... [1650992669720] [32396:1415399] CHIP: [DMG] IM RH moving to [AwaitingReportResponse] [1650992669720] [32396:1415399] CHIP: [IN] Prepared secure message 0x10bd75560 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 62627i with MessageCounter:4938996. [1650992669720] [32396:1415399] CHIP: [IN] Sending encrypted msg 0x10bd75560 with MessageCounter:4938996 to 0x000000000001B669 (1) at monotonic time: 00000000147CFC77 msec [1650992669721] [32396:1415399] CHIP: [DMG] Refresh Subscribe Sync Timer with max 10 seconds [1650992669721] [32396:1415399] CHIP: [DMG] ReportsInFlight = 1 with readHandler 0, RE has no more messages [1650992669721] [32396:1415399] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1650992669722] [32396:1415609] CHIP: [EM] Received message of type 0x1 with protocolId (0, 1) and MessageCounter:9190902 on exchange 62627i [1650992669722] [32396:1415609] CHIP: [EM] Found matching exchange: 62627i, Delegate: 0x7f9fdd2099a0 [1650992669722] [32396:1415609] CHIP: [EM] Rxd Ack; Removing MessageCounter:4938996 from Retrans Table on exchange 62627i [1650992669722] [32396:1415609] CHIP: [EM] Removed CHIP MessageCounter:4938996 from RetransTable on exchange 62627i [1650992669722] [32396:1415609] CHIP: [DMG] StatusResponseMessage = [1650992669722] [32396:1415609] CHIP: [DMG] { [1650992669722] [32396:1415609] CHIP: [DMG] Status = 0x0, [1650992669722] [32396:1415609] CHIP: [DMG] InteractionModelRevision = 1 [1650992669722] [32396:1415609] CHIP: [DMG] } [1650992669722] [32396:1415609] CHIP: [IM] Received status response, status is 0x00 (SUCCESS) [1650992669722] [32396:1415609] CHIP: [DMG] OnReportConfirm: NumReports = 0 [1650992669722] [32396:1415609] CHIP: [DMG] IM RH moving to [GeneratingReports] [1650992669722] [32396:1415609] CHIP: [EM] Sending Standalone Ack for MessageCounter:9190902 on exchange 62627i [1650992669722] [32396:1415609] CHIP: [IN] Prepared secure message 0x700003f404d0 to 0x000000000001B669 (1) of type 0x10 and protocolId (0, 0) on exchange 62627i with MessageCounter:4938997. [1650992669722] [32396:1415609] CHIP: [IN] Sending encrypted msg 0x700003f404d0 with MessageCounter:4938997 to 0x000000000001B669 (1) at monotonic time: 00000000147CFC78 msec [1650992669722] [32396:1415609] CHIP: [EM] Flushed pending ack for MessageCounter:9190902 on exchange 62627i [1650992674721] [32396:1415609] CHIP: [DMG] Unblock report hold after min 5 seconds [1650992679721] [32396:1415609] CHIP: [DMG] Refresh subscribe timer sync after 5 seconds [1650992679721] [32396:1415609] CHIP: [DMG] Building Reports for ReadHandler with LastReportGeneration = 6 DirtyGeneration = 0 [1650992679721] [32396:1415609] CHIP: [DMG] Fetched 0 events [1650992679721] [32396:1415609] CHIP: [DMG] Sending report (payload has 15 bytes)... [1650992679721] [32396:1415609] CHIP: [DMG] IM RH moving to [AwaitingReportResponse] [1650992679722] [32396:1415609] CHIP: [IN] Prepared secure message 0x10bd75560 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 62628i with MessageCounter:4938998. [1650992679722] [32396:1415609] CHIP: [IN] Sending encrypted msg 0x10bd75560 with MessageCounter:4938998 to 0x000000000001B669 (1) at monotonic time: 00000000147D2388 msec [1650992679722] [32396:1415609] CHIP: [DMG] Refresh Subscribe Sync Timer with max 10 seconds [1650992679722] [32396:1415609] CHIP: [DMG] ReportsInFlight = 1 with readHandler 0, RE has no more messages [1650992679722] [32396:1415609] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1650992679723] [32396:1415609] CHIP: [EM] Received message of type 0x1 with protocolId (0, 1) and MessageCounter:9190903 on exchange 62628i [1650992679723] [32396:1415609] CHIP: [EM] Found matching exchange: 62628i, Delegate: 0x7f9fdd2099a0 [1650992679723] [32396:1415609] CHIP: [EM] Rxd Ack; Removing MessageCounter:4938998 from Retrans Table on exchange 62628i [1650992679723] [32396:1415609] CHIP: [EM] Removed CHIP MessageCounter:4938998 from RetransTable on exchange 62628i [1650992679723] [32396:1415609] CHIP: [DMG] StatusResponseMessage = [1650992679723] [32396:1415609] CHIP: [DMG] { [1650992679723] [32396:1415609] CHIP: [DMG] Status = 0x0, [1650992679723] [32396:1415609] CHIP: [DMG] InteractionModelRevision = 1 [1650992679723] [32396:1415609] CHIP: [DMG] } [1650992679723] [32396:1415609] CHIP: [IM] Received status response, status is 0x00 (SUCCESS) [1650992679723] [32396:1415609] CHIP: [DMG] OnReportConfirm: NumReports = 0 [1650992679723] [32396:1415609] CHIP: [DMG] IM RH moving to [GeneratingReports] [1650992679723] [32396:1415609] CHIP: [EM] Sending Standalone Ack for MessageCounter:9190903 on exchange 62628i [1650992679723] [32396:1415609] CHIP: [IN] Prepared secure message 0x700003f404d0 to 0x000000000001B669 (1) of type 0x10 and protocolId (0, 0) on exchange 62628i with MessageCounter:4938999. [1650992679723] [32396:1415609] CHIP: [IN] Sending encrypted msg 0x700003f404d0 with MessageCounter:4938999 to 0x000000000001B669 (1) at monotonic time: 00000000147D2389 msec [1650992679723] [32396:1415609] CHIP: [EM] Flushed pending ack for MessageCounter:9190903 on exchange 62628i [1650992684724] [32396:1415399] CHIP: [DMG] Unblock report hold after min 5 seconds [1650992689724] [32396:1415609] CHIP: [DMG] Refresh subscribe timer sync after 5 seconds [1650992689724] [32396:1415609] CHIP: [DMG] Building Reports for ReadHandler with LastReportGeneration = 6 DirtyGeneration = 0 [1650992689724] [32396:1415609] CHIP: [DMG] Fetched 0 events [1650992689724] [32396:1415609] CHIP: [DMG] Sending report (payload has 15 bytes)... [1650992689724] [32396:1415609] CHIP: [DMG] IM RH moving to [AwaitingReportResponse] [1650992689724] [32396:1415609] CHIP: [IN] Prepared secure message 0x10bd75560 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 62629i with MessageCounter:4939000. [1650992689724] [32396:1415609] CHIP: [IN] Sending encrypted msg 0x10bd75560 with MessageCounter:4939000 to 0x000000000001B669 (1) at monotonic time: 00000000147D4A9B msec [1650992689725] [32396:1415609] CHIP: [DMG] Refresh Subscribe Sync Timer with max 10 seconds [1650992689725] [32396:1415609] CHIP: [DMG] ReportsInFlight = 1 with readHandler 0, RE has no more messages [1650992689725] [32396:1415609] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1650992694727] [32396:1415399] CHIP: [DMG] Unblock report hold after min 5 seconds [1650992694769] [32396:1415609] CHIP: [EM] Retransmitting MessageCounter:4939000 on exchange 62629i Send Cnt 0 [1650992694769] [32396:1415609] CHIP: [IN] Sending encrypted msg 0x10bd75560 with MessageCounter:4939000 to 0x000000000001B669 (1) at monotonic time: 00000000147D5E4F msec [1650992699727] [32396:1415399] CHIP: [DMG] Refresh subscribe timer sync after 5 seconds [1650992699727] [32396:1415399] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1650992700237] [32396:1415399] CHIP: [EM] Retransmitting MessageCounter:4939000 on exchange 62629i Send Cnt 1 [1650992700237] [32396:1415399] CHIP: [IN] Sending encrypted msg 0x10bd75560 with MessageCounter:4939000 to 0x000000000001B669 (1) at monotonic time: 00000000147D73AC msec [1650992701727] [32396:1415609] CHIP: [DMG] Time out! failed to receive status response from Exchange: 62629i [1650992701727] [32396:1415609] CHIP: [DMG] OnReportConfirm: NumReports = 0 [1650992701727] [32396:1415609] CHIP: [DMG] IM RH moving to [AwaitingDestruction] [1650992706043] [32396:1415399] CHIP: [EM] Retransmitting MessageCounter:4939000 on exchange 62629i Send Cnt 2 [1650992706043] [32396:1415399] CHIP: [IN] Sending encrypted msg 0x10bd75560 with MessageCounter:4939000 to 0x000000000001B669 (1) at monotonic time: 00000000147D8A59 msec [1650992714122] [32396:1415609] CHIP: [EM] Failed to Send CHIP MessageCounter:4939000 on exchange 62629i sendCount: 3 max retries: 3