Board: nrf7002
Project: matter_light_blub
OS: Kubuntu 22
Toolchains: v2.6.1
SDK: v2.6.1
I am developing with the nrf7002, and my current setup involves using a Samsung A54 as the network gateway. I connect to Google Nest Mini via Google Home, and use a second phone as a controller to connect the device.
Initially, the device connects successfully, and the light bulb icon appears on Google Home. However, I cannot control the Matter device through my phone. It seems like a connection timeout, but I'm not sure which part is failing. I have verified that my phone’s network supports IPv6 through this URL: https://test-ipv6.com/index.html.en_US.
Here is the error message:
I: 152 [DL]BLE address: DB:36:89:99:96:07 D: 183 [DL]WiFiManager has been initialized I: 188 [DL]CHIP task running I: Init CHIP stack D: 192 [DL]Connecting to WiFi network: Galaxy A54 5G E59B D: 201 [DL]WiFi scanning started... I: 204 [SVR]Subscription persistence not supported I: 209 [SVR]Server initializing... I: 214 [TS]Last Known Good Time: 2024-08-14T15:00:54 I: 222 [FP]Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x7BABAAB43C4053C0, FabricId 0x410B7D3944284516, NodeId 0x0000000019E9F7B2, VendorId 0x6006 I: 238 [DMG]AccessControl: initializing I: 241 [DMG]Examples::AccessControlDelegate::Init I: 246 [DMG]AccessControl: setting I: 249 [DMG]DefaultAclStorage: initializing I: 254 [DMG]DefaultAclStorage: 1 entries loaded D: 258 [IN]UDP::Init bind&listen port=5540 D: 262 [IN]UDP::Init bound to port=5540 D: 265 [IN]BLEBase::Init - setting/overriding transport D: 270 [IN]TransportMgr initialized I: 278 [ZCL]Using ZAP configuration... I: 285 [DMG]AccessControlCluster: initializing D: 289 [DL]Boot reason: 1 I: 292 [ZCL]Initiating Admin Commissioning cluster. I: Turn On Action has been initiated I: Turn On Action has been completed I: 303 [ZCL]Endpoint 1 On/off already set to new value I: 308 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254 I: 314 [SVR]Fabric already commissioned. Disabling BLE advertisement D: 320 [DL]CHIPoBLE advertising set to off I: 324 [DIS]Updating services using commissioning mode 0 I: 331 [DIS]CHIP minimal mDNS started advertising. D: 335 [DL]Using wifi MAC for hostname I: 339 [DIS]Advertise operational node 7BABAAB43C4053C0-0000000019E9F7B2 D: 345 [DIS]Responding with _matter._tcp.local D: 350 [DIS]Responding with 7BABAAB43C4053C0-0000000019E9F7B2._matter._tcp.local D: 357 [DIS]Responding with 7BABAAB43C4053C0-0000000019E9F7B2._matter._tcp.local D: 364 [DIS]Responding with F4CE360024AE.local D: 368 [DIS]Responding with F4CE360024AE.local D: 372 [DIS]Responding with _I7BABAAB43C4053C0._sub._matter._tcp.local I: 378 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 7BABAAB43C4053C0-0000000019E9F7B2. I: 389 [DIS]mDNS service published: _matter._tcp I: 393 [IN]CASE Server enabling CASE session setups D: 398 [IN]SecureSession[0x20004530]: Allocated Type:2 LSID:32755 I: 404 [SVR]Joining Multicast groups I: 408 [SVR]Server Listening... I: 411 [DL]Device Configuration: I: 414 [DL] Serial Number: 11223344556677889900 I: 419 [DL] Vendor Id: 65521 (0xFFF1) I: 422 [DL] Product Id: 32773 (0x8005) I: 426 [DL] Product Name: not-specified I: 429 [DL] Hardware Version: 0 I: 432 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 438 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) I: 444 [DL] Manufacturing Date: 2022-01-01 I: 448 [DL] Device Type: 65535 (0xFFFF) I: 452 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00] I: 457 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 464 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00 I: 475 [SVR]Manual pairing code: [34970112332] E: 481 [DL]Long dispatch time: 291 ms, for event type 2 I: 487 [ZCL]Cluster OnOff: attribute OnOff set to 1 I: 492 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254 I: 4819 [DL]Wi-Fi scan done (0) I: 6362 [DL]Connection to Galaxy A54 5G E59B requested [RSSI=-81] E: 6367 [DL]Long dispatch time: 1548 ms, for event type 3 I: 11122 [DL]Connected to WiFi network I: 11133 [SWU]Stopping the watchdog timer I: 11137 [SWU]Starting the periodic query timer, timeout: 86400 seconds I: 11143 [SVR]Server initialization complete I: 11147 [DIS]Updating services using commissioning mode 0 I: 11154 [DIS]CHIP minimal mDNS started advertising. D: 11165 [DL]Using wifi MAC for hostname I: 11169 [DIS]Advertise operational node 7BABAAB43C4053C0-0000000019E9F7B2 D: 11176 [DIS]Responding with _matter._tcp.local D: 11180 [DIS]Responding with 7BABAAB43C4053C0-0000000019E9F7B2._matter._tcp.local D: 11191 [DIS]Responding with 7BABAAB43C4053C0-0000000019E9F7B2._matter._tcp.local D: 11198 [DIS]Responding with F4CE360024AE.local D: 11202 [DIS]Responding with F4CE360024AE.local D: 11207 [DIS]Responding with _I7BABAAB43C4053C0._sub._matter._tcp.local I: 11213 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 7BABAAB43C4053C0-0000000019E9F7B2. I: 11227 [DIS]mDNS service published: _matter._tcp I: 11232 [DIS]Updating services using commissioning mode 0 I: 11238 [DIS]CHIP minimal mDNS started advertising. D: 11249 [DL]Using wifi MAC for hostname I: 11254 [DIS]Advertise operational node 7BABAAB43C4053C0-0000000019E9F7B2 D: 11261 [DIS]Responding with _matter._tcp.local D: 11265 [DIS]Responding with 7BABAAB43C4053C0-0000000019E9F7B2._matter._tcp.local D: 11272 [DIS]Responding with 7BABAAB43C4053C0-0000000019E9F7B2._matter._tcp.local D: 11279 [DIS]Responding with F4CE360024AE.local D: 11284 [DIS]Responding with F4CE360024AE.local D: 11289 [DIS]Responding with _I7BABAAB43C4053C0._sub._matter._tcp.local I: 11296 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 7BABAAB43C4053C0-0000000019E9F7B2. I: 11309 [DIS]mDNS service published: _matter._tcp I: 11960 [DIS]Updating services using commissioning mode 0 I: 11966 [DIS]CHIP minimal mDNS started advertising. D: 11978 [DL]Using wifi MAC for hostname I: 11983 [DIS]Advertise operational node 7BABAAB43C4053C0-0000000019E9F7B2 D: 11989 [DIS]Responding with _matter._tcp.local D: 11994 [DIS]Responding with 7BABAAB43C4053C0-0000000019E9F7B2._matter._tcp.local D: 12001 [DIS]Responding with 7BABAAB43C4053C0-0000000019E9F7B2._matter._tcp.local D: 12009 [DIS]Responding with F4CE360024AE.local D: 12014 [DIS]Responding with F4CE360024AE.local D: 12018 [DIS]Responding with _I7BABAAB43C4053C0._sub._matter._tcp.local I: 12025 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 7BABAAB43C4053C0-0000000019E9F7B2. I: 12038 [DIS]mDNS service published: _matter._tcp E: 27785 [IN]Data received on an unknown session (LSID=38411). Dropping it! E: 29147 [IN]Data received on an unknown session (LSID=38411). Dropping it! E: 30256 [IN]Data received on an unknown session (LSID=38411). Dropping it! E: 32426 [IN]Data received on an unknown session (LSID=38411). Dropping it! I: 35673 [EM]>>> [E:63190r S:0 M:54146442] (U) Msg RX from 0:5052798BBE69948A [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) I: 35684 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x20005e50 I: 35692 [EM]<<< [E:63190r S:0 M:51696349 (Ack:54146442)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::ae67:84ff:fe35:31f8]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 35709 [SC]Received Sigma1 msg I: 35717 [EM]<<< [E:63190r S:0 M:51696350 (Ack:54146442)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::ae67:84ff:fe35:31f8]:5540] --- Type 0000:33 (SecureChannel:CASE_Sigma2Resume) I: 35746 [EM]>>> [E:63190r S:0 M:54146443 (Ack:51696350)] (U) Msg RX from 0:5052798BBE69948A [0000] --- Type 0000:40 (SecureChannel:StatusReport) I: 35759 [SC]Success status report received. Session was established I: 35770 [SC]SecureSession[0x20004530, LSID:32755]: State change 'kEstablishing' --> 'kActive' D: 35778 [IN]SecureSession[0x20004530]: Activated - Type:2 LSID:32755 D: 35784 [IN]New secure session activated for device <000000004E8206DB, 1>, LSID:32755 PSID:27606! I: 35793 [IN]CASE Session established to peer: <000000004E8206DB, 1> D: 35800 [IN]SecureSession[0x200045f0]: Allocated Type:2 LSID:32756 I: 35806 [EM]<<< [E:63190r S:0 M:51696351 (Ack:54146443)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::ae67:84ff:fe35:31f8]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 35824 [EM]>>> [E:63191r S:32755 M:180485541] (S) Msg RX from 1:000000004E8206DB [53C0] --- Type 0001:03 (IM:SubscribeRequest) D: 35838 [IM]Received Subscribe request I: 35842 [DMG]Final negotiated min/max parameters: Min = 0s, Max = 30s E: 35854 [DMG]Error retrieving data from clusterId: 0x0000_0028, err = b I: 35868 [EM]<<< [E:63191r S:32755 M:237850087 (Ack:180485541)] (S) Msg TX to 1:000000004E8206DB [53C0] [UDP:[fe80::ae67:84ff:fe35:31f8]:5540] --- Type 0001:05 (IM:ReportData) I: 35995 [EM]>>> [E:63191r S:32755 M:180485542 (Ack:237850087)] (S) Msg RX from 1:000000004E8206DB [53C0] --- Type 0001:01 (IM:StatusResponse) I: 36008 [IM]Received status response, status is 0x00 E: 36021 [DMG]Error retrieving data from clusterId: 0x0000_0031, err = b I: 36033 [EM]<<< [E:63191r S:32755 M:237850088 (Ack:180485542)] (S) Msg TX to 1:000000004E8206DB [53C0] [UDP:[fe80::ae67:84ff:fe35:31f8]:5540] --- Type 0001:05 (IM:ReportData) I: 36441 [EM]Retransmitting MessageCounter:237850088 on exchange 63191r Send Cnt 1 I: 36859 [EM]Retransmitting MessageCounter:237850088 on exchange 63191r Send Cnt 2 I: 37503 [EM]Retransmitting MessageCounter:237850088 on exchange 63191r Send Cnt 3 I: 38494 [EM]Retransmitting MessageCounter:237850088 on exchange 63191r Send Cnt 4 E: 40121 [EM]Failed to Send CHIP MessageCounter:237850088 on exchange 63191r sendCount: 4 max retries: 4 D: 42251 [IN]SecureSession[0x20004530]: MarkAsDefunct Type:2 LSID:32755 I: 42258 [SC]SecureSession[0x20004530, LSID:32755]: State change 'kActive' --> 'kDefunct' E: 42266 [DMG]Time out! failed to receive status response from Exchange: 63191r