WiFi connection fails using Matter lightbulb sample

[Dilawar Ali]

I am running matter light bulb sample. I have compiled it for nRF7002DK. I want to run matter over WiFi. But during the device setup I am observing a failure. nRF Device is unable to connect with WiFi access point. 

Here is the details of setup I have and flow of test I am running.

Following the directions provided here https://devzone.nordicsemi.com/nordic/nordic-blog/b/blog/posts/matter-testing-nrf-connect-sdk-platform-with-apple-google-and-samsung-ecosystems-218911247#mcetoc_1gkq24ojdf I have added th vendor id, device id and other configurations in my google dev console. As shown in image below. I also have a google nest mini connected with same google account and wifi network.

When I try to add the device in google home app, everything went well untill WiFi connection. from the logs I can see the device was able to find the SSID in scan list. But the connection request was failed.

D: 29762 [DL]Connecting to WiFi network: Kaka_Pubg_uper
D: 29769 [DL]WiFi scanning started...
D: 32249 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 32343 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
I: 34381 [DL]Wi-Fi scan done (0)
OK
OK
OK
OK
OK
OK
E: 34395 [DL]Connection request failed
I: 34399 [EM]<<< [E:44227r S:22227 M:9246547] (S) Msg TX to 1:FFFFFFFB00000000 [DCD8] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 34410 [IN](S) Sending msg 9246547 on secure session with LSID: 22227

Fullscreen 1256.log.txt Download

uart:~$ *** Booting nRF Connect SDK v2.5.2 ***
I: Init CHIP stack
I: 152 [DL]BLE address: E6:97:92:1E:2F:89
OK
D: 182 [DL]WiFiManager has been initialized
I: 187 [SVR]Subscription persistence not supported
I: 191 [SVR]Server initializing...
I: 194 [TS]Last Known Good Time: [unknown]
I: 198 [TS]Setting Last Known Good Time to firmware build time 2024-03-13T15:15:55
I: 206 [DMG]AccessControl: initializing
I: 210 [DMG]Examples::AccessControlDelegate::Init
I: 214 [DMG]AccessControl: setting
I: 218 [DMG]DefaultAclStorage: initializing
I: 221 [DMG]DefaultAclStorage: 0 entries loaded
D: 226 [IN]UDP::Init bind&listen port=5540
E: 230 [IN]SO_REUSEPORT failed: 109
D: 233 [IN]UDP::Init bound to port=5540
D: 236 [IN]BLEBase::Init - setting/overriding transport
D: 241 [IN]TransportMgr initialized
I: 248 [ZCL]Using ZAP configuration...
I: 253 [DMG]AccessControlCluster: initializing
D: 257 [DL]Boot reason: 1
I: 260 [ZCL]Initiating Admin Commissioning cluster.
I: 265 [ZCL]Endpoint 1 On/off already set to new value
I: 270 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
D: 277 [IN]SecureSession[0x20004308]: Allocated Type:1 LSID:22227
D: 283 [DL]CHIPoBLE advertising set to on
I: 286 [DIS]Updating services using commissioning mode 1
I: 292 [DIS]CHIP minimal mDNS started advertising.
D: 296 [DL]Using wifi MAC for hostname
I: 300 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 309 [DIS]Responding with _matterc._udp.local
D: 313 [DIS]Responding with F458F7CAC80F6FE8._matterc._udp.local
D: 319 [DIS]Responding with F4CE360021E2.local
D: 323 [DIS]Responding with F4CE360021E2.local
D: 327 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 333 [DIS]Responding with _S15._sub._matterc._udp.local
D: 338 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 343 [DIS]Responding with _CM._sub._matterc._udp.local
D: 348 [DIS]Responding with F458F7CAC80F6FE8._matterc._udp.local
I: 354 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: F458F7CAC80F6FE8.
I: 364 [DIS]mDNS service published: _matterc._udp
I: 368 [DIS]Updating services using commissioning mode 1
I: 373 [DIS]CHIP minimal mDNS started advertising.
D: 378 [DL]Using wifi MAC for hostname
I: 382 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 391 [DIS]Responding with _matterc._udp.local
D: 395 [DIS]Responding with F458F7CAC80F6FE8._matterc._udp.local
D: 401 [DIS]Responding with F4CE360021E2.local
D: 405 [DIS]Responding with F4CE360021E2.local
D: 409 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 414 [DIS]Responding with _S15._sub._matterc._udp.local
D: 419 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 425 [DIS]Responding with _CM._sub._matterc._udp.local
D: 430 [DIS]Responding with F458F7CAC80F6FE8._matterc._udp.local
I: 436 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: F458F7CAC80F6FE8.
I: 445 [DIS]mDNS service published: _matterc._udp
I: 449 [IN]CASE Server enabling CASE session setups
D: 454 [IN]SecureSession[0x200043c0]: Allocated Type:2 LSID:22228
I: 460 [SVR]Joining Multicast groups
I: 464 [SVR]Server Listening...
I: 467 [DL]Device Configuration:
I: 469 [DL]  Serial Number: 11223344556677889900
I: 474 [DL]  Vendor Id: 65521 (0xFFF1)
I: 477 [DL]  Product Id: 32773 (0x8005)
I: 481 [DL]  Product Name: not-specified
I: 484 [DL]  Hardware Version: 0
I: 487 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
I: 493 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
I: 499 [DL]  Manufacturing Date: 2022-01-01
I: 503 [DL]  Device Type: 65535 (0xFFFF)
I: 507 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00]
I: 511 [SVR]Copy/paste the below URL in a browser to see the QR Code:
I: 517 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00
I: 526 [SVR]Manual pairing code: [34970112332]
I: 531 [DL]CHIP task running
I: 537 [DL]CHIPoBLE advertising started
I: 541 [ZCL]Cluster OnOff: attribute OnOff set to 0
I: 546 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254
I: 552 [DL]NFC Tag emulation started
I: 17563 [DL]BLE connection established (ConnId: 0x00)
I: 17568 [DL]Current number of connections: 1/1
I: 17573 [DL]CHIPoBLE advertising stopped
I: 17576 [DL]NFC Tag emulation stopped
D: 18226 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 18233 [BLE]local and remote recv window sizes = 5
I: 18238 [BLE]selected BTP version 4
I: 18241 [BLE]using BTP fragment sizes rx 128 / tx 128.
D: 18248 [DL]ConnId: 0x00, New CCCD value: 0x0002
D: 18253 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
D: 18260 [IN]BLE EndPoint 0x2000afb8 Connection Complete
I: 18265 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 131)
D: 18348 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 18469 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 18476 [EM]>>> [E:44206r S:0 M:261696040] (U) Msg RX from 0:AE33B8ADA12F467C [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
I: 18489 [EM]<<< [E:44206r S:0 M:196681821] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
I: 18501 [IN](U) Sending msg 196681821 to IP address 'BLE'
D: 18506 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 18558 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 18566 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 14)
D: 18678 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 18686 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 18694 [EM]>>> [E:44206r S:0 M:261696041] (U) Msg RX from 0:AE33B8ADA12F467C [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
I: 20071 [EM]<<< [E:44206r S:0 M:196681822] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
I: 20082 [IN](U) Sending msg 196681822 to IP address 'BLE'
D: 20088 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
E: 20095 [DL]Long dispatch time: 1409 ms, for event type 16388
D: 20148 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 20156 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
D: 20238 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 20246 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 20254 [EM]>>> [E:44206r S:0 M:261696042] (U) Msg RX from 0:AE33B8ADA12F467C [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
I: 20266 [EM]<<< [E:44206r S:0 M:196681823] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 20277 [IN](U) Sending msg 196681823 to IP address 'BLE'
D: 20282 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35)
I: 20291 [SC]SecureSession[0x20004308]: Moving from state 'kEstablishing' --> 'kActive'
D: 20299 [IN]SecureSession[0x20004308]: Activated - Type:1 LSID:22227
D: 20305 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:22227 PSID:47346!
I: 20313 [SVR]Commissioning completed session establishment step
I: 20320 [DIS]Updating services using commissioning mode 0
I: 20325 [DIS]CHIP minimal mDNS started advertising.
D: 20330 [DL]CHIPoBLE advertising set to off
I: 20334 [SVR]Device completed Rendezvous process
D: 20373 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 20419 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 20427 [EM]>>> [E:44207r S:22227 M:257938087] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 20438 [IM]Received Read request
I: 20443 [EM]<<< [E:44207r S:22227 M:9246525] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 20453 [IN](S) Sending msg 9246525 on secure session with LSID: 22227
D: 20459 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 97)
D: 20553 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 20561 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 20569 [EM]>>> [E:44208r S:22227 M:257938088] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 20580 [IM]Received Read request
I: 20585 [EM]<<< [E:44208r S:22227 M:9246526] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 20595 [IN](S) Sending msg 9246526 on secure session with LSID: 22227
D: 20602 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
D: 20688 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 20696 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 20704 [EM]>>> [E:44209r S:22227 M:257938089] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 20715 [IM]Received Read request
I: 20720 [EM]<<< [E:44209r S:22227 M:9246527] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 20730 [IN](S) Sending msg 9246527 on secure session with LSID: 22227
D: 20737 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
D: 20823 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 20831 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 20839 [EM]>>> [E:44210r S:22227 M:257938090] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 20850 [IM]Received Read request
I: 20855 [EM]<<< [E:44210r S:22227 M:9246528] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 20865 [IN](S) Sending msg 9246528 on secure session with LSID: 22227
D: 20872 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
D: 20958 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 20966 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 20974 [EM]>>> [E:44211r S:22227 M:257938091] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 20985 [IM]Received Read request
I: 20990 [EM]<<< [E:44211r S:22227 M:9246529] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 21000 [IN](S) Sending msg 9246529 on secure session with LSID: 22227
D: 21007 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 21093 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21101 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 21109 [EM]>>> [E:44212r S:22227 M:257938092] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 21120 [IM]Received Read request
I: 21125 [EM]<<< [E:44212r S:22227 M:9246530] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 21135 [IN](S) Sending msg 9246530 on secure session with LSID: 22227
D: 21142 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 21228 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21236 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 21244 [EM]>>> [E:44213r S:22227 M:257938093] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 21256 [ZCL]OpCreds: Certificate Chain request received for DAC
I: 21266 [EM]<<< [E:44213r S:22227 M:9246531] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 21277 [IN](S) Sending msg 9246531 on secure session with LSID: 22227
D: 21283 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 21363 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21371 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 21453 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21461 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 21544 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21551 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 21634 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21641 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 21649 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 57)
D: 21723 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21731 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 21739 [EM]>>> [E:44214r S:22227 M:257938094] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 21750 [IM]Received Read request
I: 21755 [EM]<<< [E:44214r S:22227 M:9246532] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 21765 [IN](S) Sending msg 9246532 on secure session with LSID: 22227
D: 21772 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 97)
D: 21858 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21866 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 21874 [EM]>>> [E:44215r S:22227 M:257938095] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 21885 [IM]Received Read request
I: 21890 [EM]<<< [E:44215r S:22227 M:9246533] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 21900 [IN](S) Sending msg 9246533 on secure session with LSID: 22227
D: 21907 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
D: 22038 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 22046 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 22054 [EM]>>> [E:44216r S:22227 M:257938096] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 22065 [IM]Received Read request
I: 22070 [EM]<<< [E:44216r S:22227 M:9246534] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 22080 [IN](S) Sending msg 9246534 on secure session with LSID: 22227
D: 22087 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 22173 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 22669 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 22677 [EM]>>> [E:44217r S:22227 M:257938097] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest)
I: 22688 [EM]<<< [E:44217r S:22227 M:9246535] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse)
I: 22699 [IN](S) Sending msg 9246535 on secure session with LSID: 22227
D: 22705 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43)
D: 22803 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 22811 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 22820 [EM]>>> [E:44217r S:22227 M:257938098] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 22832 [FS]GeneralCommissioning: Received ArmFailSafe (120s)
I: 22838 [EM]<<< [E:44217r S:22227 M:9246536] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 22849 [IN](S) Sending msg 9246536 on secure session with LSID: 22227
D: 22856 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 22938 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 22946 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 22954 [EM]>>> [E:44218r S:22227 M:257938099] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 22965 [IM]Received Read request
I: 22970 [EM]<<< [E:44218r S:22227 M:9246537] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 22980 [IN](S) Sending msg 9246537 on secure session with LSID: 22227
D: 22987 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 23073 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 23081 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 23089 [EM]>>> [E:44219r S:22227 M:257938100] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest)
I: 23101 [EM]<<< [E:44219r S:22227 M:9246538] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse)
I: 23112 [IN](S) Sending msg 9246538 on secure session with LSID: 22227
D: 23118 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43)
D: 23208 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 23216 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 23224 [EM]>>> [E:44219r S:22227 M:257938101] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 23239 [EM]<<< [E:44219r S:22227 M:9246539] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 23251 [IN](S) Sending msg 9246539 on secure session with LSID: 22227
D: 23257 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 23343 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 23351 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 23359 [EM]>>> [E:44220r S:22227 M:257938102] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 23371 [ZCL]OpCreds: Certificate Chain request received for PAI
I: 23380 [EM]<<< [E:44220r S:22227 M:9246540] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 23392 [IN](S) Sending msg 9246540 on secure session with LSID: 22227
D: 23398 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 23478 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 23486 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 23568 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 23576 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 23658 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 23666 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 23749 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 23756 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 23764 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 28)
D: 23838 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 23846 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 23855 [EM]>>> [E:44221r S:22227 M:257938103] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 23867 [ZCL]OpCreds: Received an AttestationRequest command
I: 23902 [ZCL]OpCreds: AttestationRequest successful.
I: 23910 [EM]<<< [E:44221r S:22227 M:9246541] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 23922 [IN](S) Sending msg 9246541 on secure session with LSID: 22227
D: 23928 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 24019 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 24026 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 24108 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 24116 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 24243 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 24251 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 24334 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 24342 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 24349 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 24424 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 24431 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 92)
D: 24513 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 24521 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 24530 [EM]>>> [E:44222r S:22227 M:257938104] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 24542 [ZCL]OpCreds: Received a CSRRequest command
I: 24687 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
I: 24721 [ZCL]OpCreds: CSRRequest successful.
I: 24728 [EM]<<< [E:44222r S:22227 M:9246542] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 24739 [IN](S) Sending msg 9246542 on secure session with LSID: 22227
D: 24746 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
E: 24753 [DL]Long dispatch time: 232 ms, for event type 16388
D: 24828 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 24836 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128)
D: 24918 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 24926 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 127)
D: 25008 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 27348 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 28249 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 28340 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 28430 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 28437 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
I: 28446 [EM]>>> [E:44223r S:22227 M:257938105] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 28459 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
I: 28519 [ZCL]OpCreds: AddTrustedRootCertificate successful.
I: 28525 [EM]<<< [E:44223r S:22227 M:9246543] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 28536 [IN](S) Sending msg 9246543 on secure session with LSID: 22227
E: 28543 [DL]Long dispatch time: 113 ms, for event type 16388
D: 28548 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 28556 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 67)
D: 28653 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 28661 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 28745 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 28835 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 28925 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 28932 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 29013 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 29021 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 29104 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 29115 [EM]>>> [E:44224r S:22227 M:257938106] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 29128 [ZCL]OpCreds: Received an AddNOC command
I: 29134 [FP]Validating NOC chain
I: 29245 [FP]NOC chain validation successful
I: 29249 [FP]Added new fabric at index: 0x1
I: 29253 [FP]Assigned compressed fabric ID: 0x7BFCF0B5B325DCD8, node ID: 0x0000000096449828
I: 29261 [TS]Last Known Good Time: 2024-03-13T15:15:55
I: 29266 [TS]New proposed Last Known Good Time: 2024-03-13T10:36:46
I: 29272 [TS]Retaining current Last Known Good Time
I: 29284 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00010001
D: 29293 [DL]Using wifi MAC for hostname
I: 29296 [DIS]Advertise operational node 7BFCF0B5B325DCD8-0000000096449828
D: 29303 [DIS]Responding with _matter._tcp.local
D: 29308 [DIS]Responding with 7BFCF0B5B325DCD8-0000000096449828._matter._tcp.local
D: 29315 [DIS]Responding with 7BFCF0B5B325DCD8-0000000096449828._matter._tcp.local
D: 29322 [DIS]Responding with F4CE360021E2.local
D: 29327 [DIS]Responding with F4CE360021E2.local
D: 29331 [DIS]Responding with _I7BFCF0B5B325DCD8._sub._matter._tcp.local
I: 29337 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 7BFCF0B5B325DCD8-0000000096449828.
I: 29348 [DIS]mDNS service published: _matter._tcp
I: 29352 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC
I: 29360 [EM]<<< [E:44224r S:22227 M:9246544] (S) Msg TX to 1:FFFFFFFB00000000 [DCD8] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 29371 [IN](S) Sending msg 9246544 on secure session with LSID: 22227
D: 29377 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
E: 29385 [DL]Long dispatch time: 281 ms, for event type 16388
D: 29463 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 29471 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 29480 [EM]>>> [E:44225r S:22227 M:257938107] (S) Msg RX from 1:FFFFFFFB00000000 [DCD8] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 29493 [EM]<<< [E:44225r S:22227 M:9246545] (S) Msg TX to 1:FFFFFFFB00000000 [DCD8] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 29504 [IN](S) Sending msg 9246545 on secure session with LSID: 22227
D: 29511 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 29598 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 29606 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 29614 [EM]>>> [E:44226r S:22227 M:257938108] (S) Msg RX from 1:FFFFFFFB00000000 [DCD8] --- Type 0001:02 (IM:ReadRequest)
D: 29625 [IM]Received Read request
I: 29630 [EM]<<< [E:44226r S:22227 M:9246546] (S) Msg TX to 1:FFFFFFFB00000000 [DCD8] --- Type 0001:05 (IM:ReportData)
I: 29640 [IN](S) Sending msg 9246546 on secure session with LSID: 22227
D: 29647 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 29733 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 29741 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 29750 [EM]>>> [E:44227r S:22227 M:257938109] (S) Msg RX from 1:FFFFFFFB00000000 [DCD8] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 29762 [DL]Connecting to WiFi network: Kaka_Pubg_uper
D: 29769 [DL]WiFi scanning started...
D: 32249 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 32343 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
I: 34381 [DL]Wi-Fi scan done (0)
OK
OK
OK
OK
OK
OK
E: 34395 [DL]Connection request failed
I: 34399 [EM]<<< [E:44227r S:22227 M:9246547] (S) Msg TX to 1:FFFFFFFB00000000 [DCD8] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 34410 [IN](S) Sending msg 9246547 on secure session with LSID: 22227
D: 34417 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70)
D: 34503 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 34511 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 34519 [EM]>>> [E:44228r S:22227 M:257938110] (S) Msg RX from 1:FFFFFFFB00000000 [DCD8] --- Type 0001:0a (IM:TimedRequest)
I: 34531 [EM]<<< [E:44228r S:22227 M:9246548] (S) Msg TX to 1:FFFFFFFB00000000 [DCD8] --- Type 0001:01 (IM:StatusResponse)
I: 34542 [IN](S) Sending msg 9246548 on secure session with LSID: 22227
D: 34548 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43)
D: 34638 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 34646 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 34654 [EM]>>> [E:44228r S:22227 M:257938111] (S) Msg RX from 1:FFFFFFFB00000000 [DCD8] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 34666 [FS]GeneralCommissioning: Received ArmFailSafe (1s)
I: 34673 [EM]<<< [E:44228r S:22227 M:9246549] (S) Msg TX to 1:FFFFFFFB00000000 [DCD8] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 34684 [IN](S) Sending msg 9246549 on secure session with LSID: 22227
D: 34691 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 34773 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
I: 35672 [FS]Fail-safe timer expired
E: 35676 [SVR]Failsafe timer expired
D: 35679 [IN]SecureSession[0x20004308]: MarkForEviction Type:1 LSID:22227
I: 35685 [SC]SecureSession[0x20004308]: Moving from state 'kActive' --> 'kPendingEviction'
D: 35693 [IN]SecureSession[0x20004308]: Released - Type:1 LSID:22227
E: 35700 [SVR]Commissioning failed (attempt 1): 32
D: 35704 [IN]Clearing BLE pending packets.
I: 35708 [BLE]Releasing end point's BLE connection back to application.
I: 35714 [DL]Closing BLE GATT connection (ConnId 00)
D: 35720 [IN]SecureSession[0x20004308]: Allocated Type:1 LSID:22229
D: 35726 [DL]CHIPoBLE advertising set to on
I: 35730 [DIS]Updating services using commissioning mode 1
I: 35735 [DIS]CHIP minimal mDNS started advertising.
D: 35740 [DL]Using wifi MAC for hostname
I: 35744 [DIS]Advertise operational node 7BFCF0B5B325DCD8-0000000096449828
D: 35751 [DIS]Responding with _matter._tcp.local
D: 35755 [DIS]Responding with 7BFCF0B5B325DCD8-0000000096449828._matter._tcp.local
D: 35762 [DIS]Responding with 7BFCF0B5B325DCD8-0000000096449828._matter._tcp.local
D: 35770 [DIS]Responding with F4CE360021E2.local
D: 35774 [DIS]Responding with F4CE360021E2.local
D: 35779 [DIS]Responding with _I7BFCF0B5B325DCD8._sub._matter._tcp.local
I: 35785 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 7BFCF0B5B325DCD8-0000000096449828.
I: 35795 [DIS]mDNS service published: _matter._tcp
D: 35800 [DL]Using wifi MAC for hostname
I: 35804 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 35813 [DIS]Responding with _matterc._udp.local
D: 35817 [DIS]Responding with F458F7CAC80F6FE8._matterc._udp.local
D: 35823 [DIS]Responding with F4CE360021E2.local
D: 35827 [DIS]Responding with F4CE360021E2.local
D: 35832 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 35837 [DIS]Responding with _S15._sub._matterc._udp.local
D: 35843 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 35848 [DIS]Responding with _CM._sub._matterc._udp.local
D: 35854 [DIS]Responding with F458F7CAC80F6FE8._matterc._udp.local
I: 35859 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: F458F7CAC80F6FE8.
I: 35869 [DIS]mDNS service published: _matterc._udp
E: 35874 [ZCL]OpCreds: Got FailSafeTimerExpired
E: 35878 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!
D: 35884 [IN]Expiring all sessions for fabric 0x1!!
E: 35889 [FP]Reverting pending fabric data for fabric 0x1
E: 35894 [FP]Warning: metadata not found during delete of fabric 0x1
I: 35904 [FP]Fabric (0x1) deleted.
I: 35907 [ZCL]OpCreds: Fabric index 0x1 was removed
I: 35912 [DIS]Updating services using commissioning mode 1
I: 35917 [DIS]CHIP minimal mDNS started advertising.
D: 35922 [DL]Using wifi MAC for hostname
I: 35926 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 35935 [DIS]Responding with _matterc._udp.local
D: 35940 [DIS]Responding with F458F7CAC80F6FE8._matterc._udp.local
D: 35945 [DIS]Responding with F4CE360021E2.local
D: 35950 [DIS]Responding with F4CE360021E2.local
D: 35954 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 35960 [DIS]Responding with _S15._sub._matterc._udp.local
D: 35965 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 35971 [DIS]Responding with _CM._sub._matterc._udp.local
D: 35976 [DIS]Responding with F458F7CAC80F6FE8._matterc._udp.local
I: 35982 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: F458F7CAC80F6FE8.
I: 35991 [DIS]mDNS service published: _matterc._udp
I: 36005 [TS]Pending Last Known Good Time: 2024-03-13T15:15:55
I: 36011 [TS]Previous Last Known Good Time: 2024-03-13T15:15:55
I: 36017 [TS]Reverted Last Known Good Time to previous value
E: 36023 [FP]Warning: metadata not found during delete of fabric 0x1
E: 36030 [ZCL]OpCreds: failed to delete fabric at index 1: d8
E: 36036 [DL]Long dispatch time: 360 ms, for event type 32782
I: 36041 [FS]Fail-safe cleanly disarmed
I: 36045 [DL]BLE GAP connection terminated (reason 0x13)
I: 36050 [DL]Current number of connections: 0/1
I: 36057 [DL]CHIPoBLE advertising started
I: 36061 [DL]NFC Tag emulation started
I: 36907 [TS]Pending Last Known Good Time: 2024-03-13T15:15:55
I: 36913 [TS]Previous Last Known Good Time: 2024-03-13T15:15:55
I: 36919 [TS]Reverted Last Known Good Time to previous value
I: 36924 [DL]Performing factory reset


uart:~$ *** Booting nRF Connect SDK v2.5.2 ***
I: Init CHIP stack
I: 152 [DL]BLE address: E7:F1:02:01:06:D9
OK
D: 182 [DL]WiFiManager has been initialized
I: 187 [SVR]Subscription persistence not supported
I: 191 [SVR]Server initializing...
I: 194 [TS]Last Known Good Time: [unknown]
I: 198 [TS]Setting Last Known Good Time to firmware build time 2024-03-13T15:15:55
I: 206 [DMG]AccessControl: initializing
I: 210 [DMG]Examples::AccessControlDelegate::Init
I: 214 [DMG]AccessControl: setting
I: 217 [DMG]DefaultAclStorage: initializing
I: 221 [DMG]DefaultAclStorage: 0 entries loaded
D: 226 [IN]UDP::Init bind&listen port=5540
E: 229 [IN]SO_REUSEPORT failed: 109
D: 233 [IN]UDP::Init bound to port=5540
D: 236 [IN]BLEBase::Init - setting/overriding transport
D: 241 [IN]TransportMgr initialized
I: 248 [ZCL]Using ZAP configuration...
I: 253 [DMG]AccessControlCluster: initializing
D: 257 [DL]Boot reason: 6
I: 260 [ZCL]Initiating Admin Commissioning cluster.
I: 265 [ZCL]Endpoint 1 On/off already set to new value
I: 270 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
D: 277 [IN]SecureSession[0x20004308]: Allocated Type:1 LSID:33001
D: 283 [DL]CHIPoBLE advertising set to on
I: 286 [DIS]Updating services using commissioning mode 1
I: 292 [DIS]CHIP minimal mDNS started advertising.
D: 296 [DL]Using wifi MAC for hostname
I: 300 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 309 [DIS]Responding with _matterc._udp.local
D: 313 [DIS]Responding with C1D69910ED85624A._matterc._udp.local
D: 319 [DIS]Responding with F4CE360021E2.local
D: 323 [DIS]Responding with F4CE360021E2.local
D: 327 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 333 [DIS]Responding with _S15._sub._matterc._udp.local
D: 338 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 343 [DIS]Responding with _CM._sub._matterc._udp.local
D: 348 [DIS]Responding with C1D69910ED85624A._matterc._udp.local
I: 354 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: C1D69910ED85624A.
I: 364 [DIS]mDNS service published: _matterc._udp
I: 368 [DIS]Updating services using commissioning mode 1
I: 373 [DIS]CHIP minimal mDNS started advertising.
D: 378 [DL]Using wifi MAC for hostname
I: 381 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 390 [DIS]Responding with _matterc._udp.local
D: 395 [DIS]Responding with C1D69910ED85624A._matterc._udp.local
D: 400 [DIS]Responding with F4CE360021E2.local
D: 405 [DIS]Responding with F4CE360021E2.local
D: 409 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 414 [DIS]Responding with _S15._sub._matterc._udp.local
D: 419 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 425 [DIS]Responding with _CM._sub._matterc._udp.local
D: 430 [DIS]Responding with C1D69910ED85624A._matterc._udp.local
I: 436 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: C1D69910ED85624A.
I: 445 [DIS]mDNS service published: _matterc._udp
I: 449 [IN]CASE Server enabling CASE session setups
D: 454 [IN]SecureSession[0x200043c0]: Allocated Type:2 LSID:33002
I: 460 [SVR]Joining Multicast groups
I: 464 [SVR]Server Listening...
I: 466 [DL]Device Configuration:
I: 469 [DL]  Serial Number: 11223344556677889900
I: 474 [DL]  Vendor Id: 65521 (0xFFF1)
I: 477 [DL]  Product Id: 32773 (0x8005)
I: 481 [DL]  Product Name: not-specified
I: 484 [DL]  Hardware Version: 0
I: 487 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
I: 493 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
I: 499 [DL]  Manufacturing Date: 2022-01-01
I: 503 [DL]  Device Type: 65535 (0xFFFF)
I: 507 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00]
I: 511 [SVR]Copy/paste the below URL in a browser to see the QR Code:
I: 517 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00
I: 526 [SVR]Manual pairing code: [34970112332]
I: 531 [DL]CHIP task running
I: 537 [DL]CHIPoBLE advertising started
I: 541 [ZCL]Cluster OnOff: attribute OnOff set to 0
I: 546 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254
I: 552 [DL]NFC Tag emulation started
I: 30540 [DL]CHIPoBLE advertising mode changed to slow
I: 30548 [DL]CHIPoBLE advertising started

When I run wifi-sta sample enabling ipv6, the device connection is succesful and ipv6 ip is also assigned. Access point is able to assign ipv6 address..

[00:00:07.048,797] <inf> sta: ==================
[00:00:07.048,828] <inf> sta: State: SCANNING
[00:00:07.348,937] <inf> sta: ==================
[00:00:07.348,968] <inf> sta: State: AUTHENTICATING
[00:00:07.516,876] <inf> sta: Connected
[00:00:07.577,117] <inf> net_config: IPv6 address: fe80::f6ce:36ff:fe00:21e2
[00:00:08.585,113] <inf> net_config: IPv6 address: fd98:1a35:7d43:ec00:f6ce:36ff:fe00:21e2
[00:00:09.728,240] <inf> net_dhcpv4: Received: 192.168.100.15
[00:00:09.728,363] <inf> net_config: IPv4 address: 192.168.100.15
[00:00:09.728,393] <inf> net_config: Lease time: 86400 seconds
[00:00:09.728,424] <inf> net_config: Subnet: 255.255.255.0
[00:00:09.728,454] <inf> net_config: Router: 192.168.100.1
[00:00:09.728,576] <inf> sta: DHCP IP address: 192.168.100.15

Why the connection is request is failing, and how can I enable the logs to view why WiFi connections fails? Can you please help me out here.

[AHaug]

Hi,

Could you verify the following:

1. Did you perform the steps from the guide with IPV6? From https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/nrf/protocols/matter/getting_started/testing/wifi_pc.html (and the Matter spec) you can see that IPv6 is a requirement for Matter networking
2. You must also make sure that the IPv6 router advertisement guard is disabled (as per requirements in the link above)
3. If the issue persists after making sure that you're testing the Matter over Wifi samples in the commercial ecosystems with IPv6, could you provide us with a chip-tool log as well?

Kind regards,
Andreas

[Dilawar Ali]

Thanks for the response.

I changed the accesspoint. Added a dedicated AP for this testing. I was able to connect the nRF7002DK with WiFi network. But afterwards unable to resolve some configurations.

[1710347823.820689][937988:937991] CHIP:CTL: Successfully finished commissioning step 'WiFiNetworkEnable'
[1710347823.820693][937988:937991] CHIP:CTL: Commissioning stage next step: 'WiFiNetworkEnable' -> 'FindOperational'
[1710347823.820696][937988:937991] CHIP:CTL: Performing next commissioning step 'FindOperational'
[1710347823.820699][937988:937991] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001]
[1710347823.820702][937988:937991] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1710347823.820708][937988:937991] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1710347823.820713][937988:937991] CHIP:DIS: Resolving 9E43B8E2CAAE1023:0000000000000001 ...
[1710347823.821218][937988:937991] CHIP:DMG: ICR moving to [AwaitingDe]
[1710347824.021106][937988:937991] CHIP:DIS: Checking node lookup status after 200 ms
[1710347824.044166][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1710347824.467362][937988:937990] CHIP:DL: Got IP address on interface: wlp164s0 IP: 192.168.2.101
[1710347824.467420][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 32770
[1710347826.692695][937988:937990] CHIP:DL: Indication received, conn = 0x7f64dc044fc0
[1710347826.692830][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1710347827.642351][937988:937990] CHIP:DL: Got IP address on interface: wlp164s0 IP: 192.168.2.101
[1710347827.642473][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 32770
[1710347828.821890][937988:937991] CHIP:DL: Re-trying resolve
[1710347829.399447][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1710347830.817285][937988:937990] CHIP:DL: Got IP address on interface: wlp164s0 IP: 192.168.2.101
[1710347830.817342][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 32770
[1710347831.956509][937988:937990] CHIP:DL: Indication received, conn = 0x7f64dc044fc0
[1710347831.956566][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1710347833.826343][937988:937991] CHIP:DL: Re-trying resolve
[1710347834.093424][937988:937990] CHIP:DL: Got IP address on interface: wlp164s0 IP: 192.168.2.101
[1710347834.093481][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 32770
[1710347834.664494][937988:937991] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1710347837.220141][937988:937990] CHIP:DL: Indication received, conn = 0x7f64dc044fc0

Complete chip tool logs are here.

chiptool_logs.txt

These are complete nRF7002DK logs.

Fullscreen nRF7002_log.txt Download

uart:~$ *** Booting nRF Connect SDK v2.5.2 ***
I: Init CHIP stack
I: 153 [DL]BLE address: F3:57:E7:78:CA:61
OK
D: 184 [DL]WiFiManager has been initialized
I: 188 [SVR]Subscription persistence not supported
I: 193 [SVR]Server initializing...
I: 196 [TS]Last Known Good Time: [unknown]
I: 200 [TS]Setting Last Known Good Time to firmware build time 2024-03-13T20:05:54
I: 208 [DMG]AccessControl: initializing
I: 212 [DMG]Examples::AccessControlDelegate::Init
I: 216 [DMG]AccessControl: setting
I: 219 [DMG]DefaultAclStorage: initializing
I: 223 [DMG]DefaultAclStorage: 0 entries loaded
D: 227 [IN]UDP::Init bind&listen port=5540
E: 231 [IN]SO_REUSEPORT failed: 109
D: 235 [IN]UDP::Init bound to port=5540
D: 238 [IN]BLEBase::Init - setting/overriding transport
D: 243 [IN]TransportMgr initialized
I: 249 [ZCL]Using ZAP configuration...
I: 255 [DMG]AccessControlCluster: initializing
D: 259 [DL]Boot reason: 6
I: 262 [ZCL]Initiating Admin Commissioning cluster.
I: 266 [ZCL]Endpoint 1 On/off already set to new value
I: 272 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
D: 279 [IN]SecureSession[0x200041e0]: Allocated Type:1 LSID:9648
D: 284 [DL]CHIPoBLE advertising set to on
I: 288 [DIS]Updating services using commissioning mode 1
I: 294 [DIS]CHIP minimal mDNS started advertising.
D: 298 [DL]Using wifi MAC for hostname
I: 302 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 311 [DIS]Responding with _matterc._udp.local
D: 315 [DIS]Responding with 869EECED9BCC5D93._matterc._udp.local
D: 321 [DIS]Responding with F4CE360021E2.local
D: 325 [DIS]Responding with F4CE360021E2.local
D: 329 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 334 [DIS]Responding with _S15._sub._matterc._udp.local
D: 340 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 345 [DIS]Responding with _CM._sub._matterc._udp.local
D: 350 [DIS]Responding with 869EECED9BCC5D93._matterc._udp.local
I: 356 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 869EECED9BCC5D93.
I: 365 [DIS]mDNS service published: _matterc._udp
I: 370 [DIS]Updating services using commissioning mode 1
I: 375 [DIS]CHIP minimal mDNS started advertising.
D: 380 [DL]Using wifi MAC for hostname
I: 383 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 392 [DIS]Responding with _matterc._udp.local
D: 396 [DIS]Responding with 869EECED9BCC5D93._matterc._udp.local
D: 402 [DIS]Responding with F4CE360021E2.local
D: 406 [DIS]Responding with F4CE360021E2.local
D: 411 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 416 [DIS]Responding with _S15._sub._matterc._udp.local
D: 421 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 426 [DIS]Responding with _CM._sub._matterc._udp.local
D: 432 [DIS]Responding with 869EECED9BCC5D93._matterc._udp.local
I: 437 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 869EECED9BCC5D93.
I: 447 [DIS]mDNS service published: _matterc._udp
I: 451 [IN]CASE Server enabling CASE session setups
D: 456 [IN]SecureSession[0x20004298]: Allocated Type:2 LSID:9649
I: 462 [SVR]Joining Multicast groups
I: 465 [SVR]Server Listening...
I: 468 [DL]Device Configuration:
I: 471 [DL]  Serial Number: 11223344556677889900
I: 475 [DL]  Vendor Id: 65521 (0xFFF1)
I: 479 [DL]  Product Id: 32773 (0x8005)
I: 482 [DL]  Product Name: not-specified
I: 486 [DL]  Hardware Version: 0
I: 489 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
I: 494 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
I: 501 [DL]  Manufacturing Date: 2022-01-01
I: 505 [DL]  Device Type: 65535 (0xFFFF)
I: 508 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00]
I: 513 [SVR]Copy/paste the below URL in a browser to see the QR Code:
I: 519 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00
I: 528 [SVR]Manual pairing code: [34970112332]
I: 533 [DL]CHIP task running
I: 539 [DL]CHIPoBLE advertising started
I: 543 [ZCL]Cluster OnOff: attribute OnOff set to 0
I: 548 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254
I: 554 [DL]NFC Tag emulation started
I: 4527 [DL]BLE connection established (ConnId: 0x00)
I: 4532 [DL]Current number of connections: 1/1
I: 4536 [DL]CHIPoBLE advertising stopped
I: 4540 [DL]NFC Tag emulation stopped
D: 5935 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 5942 [BLE]local and remote recv window sizes = 5
I: 5946 [BLE]selected BTP version 4
I: 5950 [BLE]using BTP fragment sizes rx 244 / tx 244.
D: 6025 [DL]ConnId: 0x00, New CCCD value: 0x0002
D: 6029 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
D: 6036 [IN]BLE EndPoint 0x2000ae00 Connection Complete
I: 6041 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
D: 6114 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 6122 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 6130 [EM]>>> [E:62086r S:0 M:45129755] (U) Msg RX from 0:E3E778B501B4A944 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
I: 6143 [EM]<<< [E:62086r S:0 M:54310545] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
I: 6154 [IN](U) Sending msg 54310545 to IP address 'BLE'
D: 6159 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 140)
D: 6249 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 6257 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 6265 [EM]>>> [E:62086r S:0 M:45129756] (U) Msg RX from 0:E3E778B501B4A944 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
I: 7630 [EM]<<< [E:62086r S:0 M:54310546] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
I: 7641 [IN](U) Sending msg 54310546 to IP address 'BLE'
D: 7646 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132)
E: 7654 [DL]Long dispatch time: 1397 ms, for event type 16388
D: 7734 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 7742 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 7750 [EM]>>> [E:62086r S:0 M:45129757] (U) Msg RX from 0:E3E778B501B4A944 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
I: 7762 [EM]<<< [E:62086r S:0 M:54310547] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 7773 [IN](U) Sending msg 54310547 to IP address 'BLE'
D: 7778 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35)
I: 7786 [SC]SecureSession[0x200041e0]: Moving from state 'kEstablishing' --> 'kActive'
D: 7794 [IN]SecureSession[0x200041e0]: Activated - Type:1 LSID:9648
D: 7800 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:9648 PSID:12628!
I: 7808 [SVR]Commissioning completed session establishment step
I: 7814 [DIS]Updating services using commissioning mode 0
I: 7819 [DIS]CHIP minimal mDNS started advertising.
D: 7825 [DL]CHIPoBLE advertising set to off
I: 7829 [SVR]Device completed Rendezvous process
D: 7869 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 7877 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 7886 [EM]>>> [E:62087r S:9648 M:45844896] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 7896 [IM]Received Read request
I: 7905 [EM]<<< [E:62087r S:9648 M:138068617] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 7916 [IN](S) Sending msg 138068617 on secure session with LSID: 9648
D: 7922 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 8005 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8012 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 21)
D: 8094 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8102 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 8110 [EM]>>> [E:62088r S:9648 M:45844897] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 8122 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
I: 8128 [EM]<<< [E:62088r S:9648 M:138068618] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 8140 [IN](S) Sending msg 138068618 on secure session with LSID: 9648
D: 8146 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 8229 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8237 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 8245 [EM]>>> [E:62089r S:9648 M:45844898] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 8259 [EM]<<< [E:62089r S:9648 M:138068619] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 8270 [IN](S) Sending msg 138068619 on secure session with LSID: 9648
D: 8277 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 8364 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8372 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 8380 [EM]>>> [E:62090r S:9648 M:45844899] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 8392 [ZCL]OpCreds: Certificate Chain request received for PAI
I: 8401 [EM]<<< [E:62090r S:9648 M:138068620] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 8412 [IN](S) Sending msg 138068620 on secure session with LSID: 9648
D: 8419 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 8500 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8507 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 8589 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8597 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48)
D: 8679 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8687 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 8695 [EM]>>> [E:62091r S:9648 M:45844900] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 8707 [ZCL]OpCreds: Certificate Chain request received for DAC
I: 8716 [EM]<<< [E:62091r S:9648 M:138068621] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 8728 [IN](S) Sending msg 138068621 on secure session with LSID: 9648
D: 8734 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 8815 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8822 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 8950 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 8957 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77)
D: 9039 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 9047 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 9055 [EM]>>> [E:62092r S:9648 M:45844901] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 9067 [ZCL]OpCreds: Received an AttestationRequest command
I: 9102 [ZCL]OpCreds: AttestationRequest successful.
I: 9111 [EM]<<< [E:62092r S:9648 M:138068622] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 9122 [IN](S) Sending msg 138068622 on secure session with LSID: 9648
D: 9129 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 9220 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 9227 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 9309 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 9317 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 237)
D: 9399 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 9407 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 9415 [EM]>>> [E:62093r S:9648 M:45844902] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 9427 [ZCL]OpCreds: Received a CSRRequest command
I: 9572 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
I: 9607 [ZCL]OpCreds: CSRRequest successful.
I: 9614 [EM]<<< [E:62093r S:9648 M:138068623] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 9625 [IN](S) Sending msg 138068623 on secure session with LSID: 9648
D: 9631 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
E: 9639 [DL]Long dispatch time: 232 ms, for event type 16388
D: 9715 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 9722 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 138)
D: 9804 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 9812 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 9895 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 9904 [EM]>>> [E:62094r S:9648 M:45844903] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 9916 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
I: 9975 [ZCL]OpCreds: AddTrustedRootCertificate successful.
I: 9981 [EM]<<< [E:62094r S:9648 M:138068624] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 9993 [IN](S) Sending msg 138068624 on secure session with LSID: 9648
D: 9999 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
E: 10007 [DL]Long dispatch time: 112 ms, for event type 16388
D: 10074 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 10083 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 10167 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 10255 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 10266 [EM]>>> [E:62095r S:9648 M:45844904] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 10278 [ZCL]OpCreds: Received an AddNOC command
I: 10284 [FP]Validating NOC chain
I: 10394 [FP]NOC chain validation successful
I: 10398 [FP]Added new fabric at index: 0x1
I: 10402 [FP]Assigned compressed fabric ID: 0x9E43B8E2CAAE1023, node ID: 0x0000000000000001
I: 10410 [TS]Last Known Good Time: 2024-03-13T20:05:54
I: 10415 [TS]New proposed Last Known Good Time: 2021-01-01T00:00:00
I: 10421 [TS]Retaining current Last Known Good Time
I: 10433 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669
D: 10442 [DL]Using wifi MAC for hostname
I: 10446 [DIS]Advertise operational node 9E43B8E2CAAE1023-0000000000000001
D: 10453 [DIS]Responding with _matter._tcp.local
D: 10457 [DIS]Responding with 9E43B8E2CAAE1023-0000000000000001._matter._tcp.local
D: 10464 [DIS]Responding with 9E43B8E2CAAE1023-0000000000000001._matter._tcp.local
D: 10472 [DIS]Responding with F4CE360021E2.local
D: 10476 [DIS]Responding with F4CE360021E2.local
D: 10480 [DIS]Responding with _I9E43B8E2CAAE1023._sub._matter._tcp.local
I: 10487 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 9E43B8E2CAAE1023-0000000000000001.
I: 10497 [DIS]mDNS service published: _matter._tcp
I: 10502 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC
I: 10509 [EM]<<< [E:62095r S:9648 M:138068625] (S) Msg TX to 1:FFFFFFFB00000000 [1023] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 10521 [IN](S) Sending msg 138068625 on secure session with LSID: 9648
D: 10527 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
E: 10535 [DL]Long dispatch time: 280 ms, for event type 16388
D: 10614 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 10623 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 10631 [EM]>>> [E:62096r S:9648 M:45844905] (S) Msg RX from 1:FFFFFFFB00000000 [1023] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 10644 [EM]<<< [E:62096r S:9648 M:138068626] (S) Msg TX to 1:FFFFFFFB00000000 [1023] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 10655 [IN](S) Sending msg 138068626 on secure session with LSID: 9648
D: 10661 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 10749 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 10757 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 10765 [EM]>>> [E:62097r S:9648 M:45844906] (S) Msg RX from 1:FFFFFFFB00000000 [1023] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 10777 [FS]GeneralCommissioning: Received ArmFailSafe (76s)
I: 10784 [EM]<<< [E:62097r S:9648 M:138068627] (S) Msg TX to 1:FFFFFFFB00000000 [1023] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 10795 [IN](S) Sending msg 138068627 on secure session with LSID: 9648
D: 10802 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 10884 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 10893 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 10901 [EM]>>> [E:62098r S:9648 M:45844907] (S) Msg RX from 1:FFFFFFFB00000000 [1023] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 10913 [DL]Connecting to WiFi network: Test_Network
D: 10920 [DL]WiFi scanning started...
D: 13400 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 13539 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
I: 15533 [DL]Wi-Fi scan done (0)
OK
OK
OK
OK
OK
OK
OK
OK
OK
OK
I: 17089 [DL]Connection to Test_Network requested [RSSI=-24]
E: 17095 [DL]Long dispatch time: 1561 ms, for event type 3
D: 17101 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 19610 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 19749 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
I: 21938 [DL]Connected to WiFi network
I: 21943 [EM]<<< [E:62098r S:9648 M:138068628] (S) Msg TX to 1:FFFFFFFB00000000 [1023] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 21955 [IN](S) Sending msg 138068628 on secure session with LSID: 9648
D: 21962 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 69)
D: 21971 [DL]Using wifi MAC for hostname
I: 21974 [DIS]Advertise operational node 9E43B8E2CAAE1023-0000000000000001
D: 21981 [DIS]Responding with _matter._tcp.local
D: 21986 [DIS]Responding with 9E43B8E2CAAE1023-0000000000000001._matter._tcp.local
D: 21993 [DIS]Responding with 9E43B8E2CAAE1023-0000000000000001._matter._tcp.local
D: 22000 [DIS]Responding with F4CE360021E2.local
D: 22005 [DIS]Responding with F4CE360021E2.local
D: 22009 [DIS]Responding with _I9E43B8E2CAAE1023._sub._matter._tcp.local
I: 22016 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 9E43B8E2CAAE1023-0000000000000001.
I: 22026 [DIS]mDNS service published: _matter._tcp
I: 22030 [SVR]Operational advertising enabled
I: 22036 [SWU]Stopping the watchdog timer
I: 22040 [SWU]Starting the periodic query timer, timeout: 86400 seconds
E: 22047 [SVR]Server initialization complete
I: 22051 [DIS]Updating services using commissioning mode 0
E: 22056 [IN]SO_REUSEPORT failed: 109
I: 22061 [DIS]CHIP minimal mDNS started advertising.
D: 22077 [DL]Using wifi MAC for hostname
I: 22081 [DIS]Advertise operational node 9E43B8E2CAAE1023-0000000000000001
D: 22088 [DIS]Responding with _matter._tcp.local
D: 22092 [DIS]Responding with 9E43B8E2CAAE1023-0000000000000001._matter._tcp.local
D: 22100 [DIS]Responding with 9E43B8E2CAAE1023-0000000000000001._matter._tcp.local
D: 22107 [DIS]Responding with F4CE360021E2.local
D: 22111 [DIS]Responding with F4CE360021E2.local
D: 22116 [DIS]Responding with _I9E43B8E2CAAE1023._sub._matter._tcp.local
I: 22122 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 9E43B8E2CAAE1023-0000000000000001.
I: 22137 [DIS]mDNS service published: _matter._tcp
D: 22142 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
I: 22150 [DIS]Updating services using commissioning mode 0
E: 22155 [IN]SO_REUSEPORT failed: 109
I: 22159 [DIS]CHIP minimal mDNS started advertising.
D: 22176 [DL]Using wifi MAC for hostname
I: 22180 [DIS]Advertise operational node 9E43B8E2CAAE1023-0000000000000001
D: 22187 [DIS]Responding with _matter._tcp.local
D: 22191 [DIS]Responding with 9E43B8E2CAAE1023-0000000000000001._matter._tcp.local
D: 22198 [DIS]Responding with 9E43B8E2CAAE1023-0000000000000001._matter._tcp.local
D: 22206 [DIS]Responding with F4CE360021E2.local
D: 22210 [DIS]Responding with F4CE360021E2.local
D: 22214 [DIS]Responding with _I9E43B8E2CAAE1023._sub._matter._tcp.local
I: 22221 [DIS]CHIP minimal mDNS configured as 'Operational device'; instance name: 9E43B8E2CAAE1023-0000000000000001.
I: 22236 [DIS]mDNS service published: _matter._tcp
D: 22270 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 24778 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 24879 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 27535 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 30042 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 30145 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 32800 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 35307 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 35410 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 38065 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 40572 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 40675 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 43330 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 45837 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 45940 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 48595 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 51102 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 51205 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 53860 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 56367 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 56470 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 59125 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 61633 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 61735 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 64390 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 66898 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 67000 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 67046 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 67054 [EM]>>> [E:62099r S:9648 M:45844908] (S) Msg RX from 1:FFFFFFFB00000000 [1023] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 67066 [FS]GeneralCommissioning: Received ArmFailSafe (120s)
I: 67072 [EM]<<< [E:62099r S:9648 M:138068629] (S) Msg TX to 1:FFFFFFFB00000000 [1023] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 67084 [IN](S) Sending msg 138068629 on secure session with LSID: 9648
D: 67090 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 67180 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 69790 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 72298 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 72400 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 75055 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 77563 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 77665 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 80320 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 82828 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 82930 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 85585 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 88093 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 88195 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 90850 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 93357 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 93460 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 96115 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 98622 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 98725 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 101380 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 103888 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 103990 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 106645 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 109153 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 109255 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 111911 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 112046 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 112054 [EM]>>> [E:62100r S:9648 M:45844909] (S) Msg RX from 1:FFFFFFFB00000000 [1023] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 112066 [FS]GeneralCommissioning: Received ArmFailSafe (120s)
I: 112073 [EM]<<< [E:62100r S:9648 M:138068630] (S) Msg TX to 1:FFFFFFFB00000000 [1023] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 112086 [IN](S) Sending msg 138068630 on secure session with LSID: 9648
D: 112092 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 112181 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 114791 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 117298 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 117400 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 120056 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 122563 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 122665 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 124331 [DL]ConnId: 0x00, New CCCD value: 0x0000
D: 124335 [IN]Clearing BLE pending packets.
I: 124339 [BLE]Releasing end point's BLE connection back to application.
I: 124345 [DL]Closing BLE GATT connection (ConnId 00)
I: 124465 [DL]BLE GAP connection terminated (reason 0x16)
I: 124471 [DL]Current number of connections: 0/1
I: Factory Reset Triggered. Release button within 3000ms to cancel.
E: 184295 [FP]Reverting pending fabric data for fabric 0x1
E: 184300 [FP]Warning: metadata not found during delete of fabric 0x1
I: 184310 [FP]Fabric (0x1) deleted.
I: 184313 [ZCL]OpCreds: Fabric index 0x1 was removed
I: 184318 [DIS]Updating services using commissioning mode 0
E: 184324 [IN]SO_REUSEPORT failed: 109
I: 184327 [DIS]CHIP minimal mDNS started advertising.
I: 184352 [TS]Pending Last Known Good Time: 2024-03-13T20:05:54
I: 184359 [TS]Previous Last Known Good Time: 2024-03-13T20:05:54
I: 184364 [TS]Reverted Last Known Good Time to previous value
I: 184370 [DL]Performing factory reset

[AHaug]

Hi,

Based on the log you have and from the flowchart in operational discovery under Matter commissioning documentation it looks like that Chip-tool is trying to find the IP address of the device on the network but it can't find it and thus it times out. This could be caused by for instance that the device running chip-tool and the Matter device you're trying to commission is not connected to the same network, it could be that you have RA guard enabled on the AP or other. Could you try to check either of these two things and verify if either are causing the issue or not?

Kind regards,
Andreas