What I'm trying to do is set a matter device as a sleepy end device, my device as in I'm using a nrf52840dk as my matter device.
Also, I am using nrf connect sdk v2.1.1, visual studio IDE
I choose the template sample and followed the steps in the documentation to make the device work as a temperature sensor which send random data. I edited the prj file to set my device as a sleepy end device "CONFIG_OPENTHREAD_MTD_SED=y".
I was able to see that my device was configured as a sleepy end device from the device log upon boot up.
But I was not able to commission the device. I changed the device type to minimal end device type and was able to commission the device. And again to sleepy end device, I couldn't commission it.
I am using a google nest hub as border router and am using the google home app to commission my device.
The log of the device after I tried commissioning is shown below;
I: nRF5 802154 radio initialized I: 4 Sectors of 4096 bytes I: alloc wra: 0, 8c8 I: data wra: 0, 744 ooting Zephyr OS build v3.1.99-ncs1 *** I: Init CHIP stack 32muart:~$ : 220 [DL]BLE address: F3:4D:76:26:56:FD mI: SoftDevice Controller build revision: I: f2 e7 5f 6f 23 a2 f3 e8 |.._o#... I: 10 2f c3 35 9e d7 1d fe |./.5.... I: 8f 80 42 f9 |..B. I: 245 [DL]OpenThread started: OK I: 248 [DL]Setting OpenThread device type to SLEEPY END DEVICE I: 254 [SVR]Server initializing... D: 257 [FP]Initializing FabricTable from persistent storage I: 263 [TS]Last Known Good Time: 2023-03-02T16:41:46 I: 268 [DMG]AccessControl: initializing I: 272 [DMG]Examples::AccessControlDelegate::Init I: 276 [DMG]AccessControl: setting I: 279 [DMG]DefaultAclStorage: initializing I: 283 [DMG]DefaultAclStorage: 0 entries loaded D: 288 [IN]UDP::Init bind&listen port=5540 E: 292 [IN]SO_REUSEPORT failed: 109 D: 295 [IN]UDP::Init bound to port=5540 D: 298 [IN]BLEBase::Init - setting/overriding transport D: 303 [IN]TransportMgr initialized D: 310 [DL]Using Thread extended MAC for hostname. I: 317 [ZCL]Using ZAP configuration... D: 321 [DMG]Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0 I: 328 [DMG]AccessControlCluster: initializing D: 332 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 60435297 D: 339 [DL]Boot reason: 1 D: 341 [ZCL]GeneralDiagnostics: OnDeviceReboot D: 345 [DMG]Endpoint 0, Cluster 0x0000_0033 update version to 3972ca76 D: 352 [EVL]LogEvent event number: 0x0000000000010000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x0000000000000160 I: 366 [ZCL]Initiating Admin Commissioning cluster. D: 372 [IN]SecureSession[0x20003540]: Allocated Type:1 LSID:58721 D: 378 [SC]Assigned local session key ID 58721 D: 382 [SC]Waiting for PBKDF param request D: 386 [DL]CHIPoBLE advertising set to on I: 390 [DIS]Updating services using commissioning mode 1 D: 395 [DL]Using Thread extended MAC for hostname. D: 400 [DL]Using Thread extended MAC for hostname. I: 405 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 E: 414 [DIS]Failed to advertise commissionable node: 3 E: 419 [DIS]Failed to finalize service update: 1c I: 423 [DIS]Updating services using commissioning mode 1 D: 428 [DL]Using Thread extended MAC for hostname. D: 433 [DL]Using Thread extended MAC for hostname. I: 438 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 E: 447 [DIS]Failed to advertise commissionable node: 3 E: 452 [DIS]Failed to finalize service update: 1c I: 456 [DIS]Delaying proxy of operational discovery: missing delegate I: 462 [IN]CASE Server enabling CASE session setups D: 467 [IN]SecureSession[0x200035f8]: Allocated Type:2 LSID:58722 D: 473 [SC]Allocated SecureSession (0x200035f8) - waiting for Sigma1 msg I: 480 [SVR]Joining Multicast groups D: 483 [ZCL]Emitting StartUp event D: 486 [EVL]LogEvent event number: 0x0000000000010001 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x00000000000001E6 I: 500 [SVR]Server Listening... I: 503 [DL]Device Configuration: I: 506 [DL] Serial Number: 11223344556677889900 I: 511 [DL] Vendor Id: 65521 (0xFFF1) I: 514 [DL] Product Id: 32768 (0x8000) I: 518 [DL] Hardware Version: 0 I: 521 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 527 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) I: 534 [DL] Manufacturing Date: (not set) I: 538 [DL] Device Type: 65535 (0xFFFF) I: 542 [SVR]SetupQRCode: [MT:Y.K9042C00KA0648G00] I: 547 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 553 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3AY.K9042C00KA0648G00 I: 562 [SVR]Manual pairing code: [34970112332] I: 567 [DL]CHIP task running I: 571 [DL]CHIPoBLE advertising started I: 26958 [DL]BLE connection established (ConnId: 0x00) I: 26963 [DL]Current number of connections: 1/1 I: 26967 [DL]CHIPoBLE advertising stopped D: 27857 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 27864 [BLE]local and remote recv window sizes = 5 I: 27869 [BLE]selected BTP version 4 I: 27873 [BLE]using BTP fragment sizes rx 128 / tx 128. D: 27878 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 27883 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 27890 [IN]BLE EndPoint 0x2000f3c0 Connection Complete I: 27895 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 131) D: 28051 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 28187 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 28194 [EM]>>> [E:46752r M:266243308] (U) Msg RX from 0:31B467478F82CCC3 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) D: 28206 [EM]Handling via exchange: 46752r, Delegate: 0x20005724 D: 28212 [SC]Received PBKDF param request D: 28216 [SC]Peer assigned session ID 35242 D: 28220 [SC]Found MRP parameters in the message D: 28224 [SC]Including MRP parameters in PBKDF param response I: 28230 [EM]<<< [E:46752r M:232972338] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) I: 28242 [IN](U) Sending msg 232972338 to IP address 'BLE' D: 28247 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 28255 [SC]Sent PBKDF param response D: 28322 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 28329 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 14) D: 28546 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 28555 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 28562 [EM]>>> [E:46752r M:266243309] (U) Msg RX from 0:31B467478F82CCC3 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) D: 28574 [EM]Found matching exchange: 46752r, Delegate: 0x20005724 D: 28579 [SC]Received spake2p msg1 I: 30442 [EM]<<< [E:46752r M:232972339] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) I: 30453 [IN](U) Sending msg 232972339 to IP address 'BLE' D: 30459 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 30466 [SC]Sent spake2p msg2 E: 30469 [DL]Long dispatch time: 1914 ms, for event type 16388 D: 30572 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 30579 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 30707 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 30715 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 30722 [EM]>>> [E:46752r M:266243310] (U) Msg RX from 0:31B467478F82CCC3 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) D: 30733 [EM]Found matching exchange: 46752r, Delegate: 0x20005724 D: 30739 [SC]Received spake2p msg3 D: 30743 [SC]Sending status report. Protocol code 0, exchange 46752 I: 30749 [EM]<<< [E:46752r M:232972340] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) I: 30760 [IN](U) Sending msg 232972340 to IP address 'BLE' D: 30766 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 30774 [SC]SecureSession[0x20003540]: Moving from state 'kEstablishing' --> 'kActive' D: 30782 [IN]SecureSession[0x20003540]: Activated - Type:1 LSID:58721 D: 30788 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:58721 PSID:35242! I: 30797 [SVR]Commissioning completed session establishment step I: 30803 [DIS]Updating services using commissioning mode 0 D: 30809 [DL]Using Thread extended MAC for hostname. D: 30814 [DL]Using Thread extended MAC for hostname. I: 30819 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=0 E: 30828 [DIS]Failed to advertise extended commissionable node: 3 D: 30834 [DIS]Scheduling extended discovery timeout in 900s E: 30839 [DIS]Failed to finalize service update: 1c D: 30845 [DL]CHIPoBLE advertising set to off I: 30849 [SVR]Device completed Rendezvous process E: 30853 [DL]Long dispatch time: 138 ms, for event type 16388 D: 30859 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 30867 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 30874 [EM]>>> [E:46753r M:110274610] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 30885 [EM]Handling via exchange: 46753r, Delegate: 0x2000cd8c D: 30891 [IM]Received Read request D: 30895 [DMG]IM RH moving to [GeneratingReports] D: 30899 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 30908 [DMG]<RE:Run> Cluster 28, Attribute 2 is dirty D: 30913 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 30922 [DMG]<RE> Sending report (payload has 37 bytes)... I: 30928 [EM]<<< [E:46753r M:60519150] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 30938 [IN](S) Sending msg 60519150 on secure session with LSID: 58721 D: 30945 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 30952 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 30957 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 30964 [DMG]IM RH moving to [AwaitingDestruction] D: 30969 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 31067 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 31075 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 31083 [EM]>>> [E:46754r M:110274611] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 31093 [EM]Handling via exchange: 46754r, Delegate: 0x2000cd8c D: 31099 [IM]Received Read request D: 31103 [DMG]IM RH moving to [GeneratingReports] D: 31107 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 31116 [DMG]<RE:Run> Cluster 28, Attribute 4 is dirty D: 31121 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) D: 31130 [DMG]<RE> Sending report (payload has 37 bytes)... I: 31136 [EM]<<< [E:46754r M:60519151] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 31146 [IN](S) Sending msg 60519151 on secure session with LSID: 58721 D: 31152 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 31160 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 31165 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 31172 [DMG]IM RH moving to [AwaitingDestruction] D: 31177 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 31247 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 31292 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 31300 [EM]>>> [E:46755r M:110274612] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 31310 [EM]Handling via exchange: 46755r, Delegate: 0x2000cd8c D: 31316 [IM]Received Read request D: 31320 [DMG]IM RH moving to [GeneratingReports] D: 31324 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 31333 [DMG]<RE:Run> Cluster 3e, Attribute 2 is dirty D: 31338 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 31347 [DMG]<RE> Sending report (payload has 36 bytes)... I: 31353 [EM]<<< [E:46755r M:60519152] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 31363 [IN](S) Sending msg 60519152 on secure session with LSID: 58721 D: 31369 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 31377 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 31382 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 31389 [DMG]IM RH moving to [AwaitingDestruction] D: 31394 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 31427 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 31472 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 31480 [EM]>>> [E:46756r M:110274613] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 31490 [EM]Handling via exchange: 46756r, Delegate: 0x2000cd8c D: 31496 [IM]Received Read request D: 31500 [DMG]IM RH moving to [GeneratingReports] D: 31505 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 31513 [DMG]<RE:Run> Cluster 3e, Attribute 3 is dirty D: 31518 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 31527 [DMG]<RE> Sending report (payload has 36 bytes)... I: 31534 [EM]<<< [E:46756r M:60519153] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 31543 [IN](S) Sending msg 60519153 on secure session with LSID: 58721 D: 31550 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 31557 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 31562 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 31570 [DMG]IM RH moving to [AwaitingDestruction] D: 31574 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 31607 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 31615 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 31623 [EM]>>> [E:46757r M:110274614] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 31633 [EM]Handling via exchange: 46757r, Delegate: 0x2000cd8c D: 31639 [IM]Received Read request D: 31643 [DMG]IM RH moving to [GeneratingReports] D: 31647 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 31656 [DMG]<RE:Run> Cluster 3e, Attribute 1 is dirty D: 31661 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 31670 [DMG]<RE> Sending report (payload has 36 bytes)... I: 31676 [EM]<<< [E:46757r M:60519154] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 31686 [IN](S) Sending msg 60519154 on secure session with LSID: 58721 D: 31692 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 31700 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 31705 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 31712 [DMG]IM RH moving to [AwaitingDestruction] D: 31717 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 31786 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 31832 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 31840 [EM]>>> [E:46758r M:110274615] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 31850 [EM]Handling via exchange: 46758r, Delegate: 0x2000cd8c D: 31856 [IM]Received Read request D: 31860 [DMG]IM RH moving to [GeneratingReports] D: 31864 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 31873 [DMG]<RE:Run> Cluster 1d, Attribute 1 is dirty D: 31878 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 31887 [DMG]<RE> Sending report (payload has 400 bytes)... I: 31895 [EM]<<< [E:46758r M:60519155] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 31905 [IN](S) Sending msg 60519155 on secure session with LSID: 58721 D: 31912 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 31919 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 31924 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 31932 [DMG]IM RH moving to [AwaitingDestruction] D: 31936 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 32012 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 32019 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 32101 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 32109 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 32281 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 32289 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 57) D: 32372 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 32380 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 32462 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 32470 [EM]>>> [E:46759r M:110274616] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 32480 [EM]Handling via exchange: 46759r, Delegate: 0x2000cd8c D: 32486 [IM]Received Read request D: 32490 [DMG]IM RH moving to [GeneratingReports] D: 32494 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 32503 [DMG]<RE:Run> Cluster 31, Attribute fffc is dirty D: 32508 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) D: 32517 [DMG]<RE> Sending report (payload has 37 bytes)... I: 32523 [EM]<<< [E:46759r M:60519156] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 32533 [IN](S) Sending msg 60519156 on secure session with LSID: 58721 D: 32540 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 32547 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 32552 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 32560 [DMG]IM RH moving to [AwaitingDestruction] D: 32564 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 32596 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 35071 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 37579 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 37681 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40201 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 42708 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 42766 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 43621 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 43629 [EM]>>> [E:46760r M:110274617] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest) D: 43640 [EM]Handling via exchange: 46760r, Delegate: 0x2000cd8c D: 43646 [DMG]Got Timed Request with timeout 10000: handler 0x2000d188 exchange 46760r I: 43654 [EM]<<< [E:46760r M:60519157] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse) I: 43664 [IN](S) Sending msg 60519157 on secure session with LSID: 58721 D: 43671 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 43678 [DMG]Timed Request time limit 0x000000000000D1AE: handler 0x2000d188 exchange 46760r D: 43757 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 43764 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 43772 [EM]>>> [E:46760r M:110274618] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 43783 [EM]Found matching exchange: 46760r, Delegate: 0x2000d188 D: 43789 [DMG]Timed following action arrived at 0x000000000000AB0D: handler 0x2000d188 exchange 46760r D: 43799 [DMG]Handing timed invoke to IM engine: handler 0x2000d188 exchange 46760r D: 43807 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 I: 43814 [FS]GeneralCommissioning: Received ArmFailSafe (120s) D: 43820 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 60435298 D: 43826 [DMG]Command handler moving to [ Preparing] D: 43831 [DMG]Command handler moving to [AddingComm] D: 43836 [DMG]Command handler moving to [AddedComma] D: 43841 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 43849 [EM]<<< [E:46760r M:60519158] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 43859 [IN](S) Sending msg 60519158 on secure session with LSID: 58721 D: 43866 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 43873 [DMG]Command handler moving to [CommandSen] D: 43878 [DMG]Command handler moving to [AwaitingDe] E: 43883 [DL]Long dispatch time: 119 ms, for event type 16388 D: 43937 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 43944 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 43952 [EM]>>> [E:46761r M:110274619] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 43963 [EM]Handling via exchange: 46761r, Delegate: 0x2000cd8c D: 43968 [IM]Received Read request D: 43972 [DMG]IM RH moving to [GeneratingReports] D: 43977 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 43985 [DMG]<RE:Run> Cluster 30, Attribute 3 is dirty D: 43991 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 44000 [DMG]<RE> Sending report (payload has 36 bytes)... I: 44006 [EM]<<< [E:46761r M:60519159] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 44015 [IN](S) Sending msg 60519159 on secure session with LSID: 58721 D: 44022 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 44030 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 44034 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 44042 [DMG]IM RH moving to [AwaitingDestruction] D: 44046 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 44117 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 44124 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 44132 [EM]>>> [E:46762r M:110274620] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest) D: 44143 [EM]Handling via exchange: 46762r, Delegate: 0x2000cd8c D: 44149 [DMG]Got Timed Request with timeout 10000: handler 0x2000d188 exchange 46762r I: 44157 [EM]<<< [E:46762r M:60519160] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse) I: 44167 [IN](S) Sending msg 60519160 on secure session with LSID: 58721 D: 44174 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 44181 [DMG]Timed Request time limit 0x000000000000D3A5: handler 0x2000d188 exchange 46762r D: 44251 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 44259 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 44267 [EM]>>> [E:46762r M:110274621] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 44278 [EM]Found matching exchange: 46762r, Delegate: 0x2000d188 D: 44284 [DMG]Timed following action arrived at 0x000000000000ACFC: handler 0x2000d188 exchange 46762r D: 44294 [DMG]Handing timed invoke to IM engine: handler 0x2000d188 exchange 46762r D: 44302 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 D: 44317 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 60435299 D: 44323 [DMG]Command handler moving to [ Preparing] D: 44328 [DMG]Command handler moving to [AddingComm] D: 44332 [DMG]Command handler moving to [AddedComma] D: 44337 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 44345 [EM]<<< [E:46762r M:60519161] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 44356 [IN](S) Sending msg 60519161 on secure session with LSID: 58721 D: 44362 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 44370 [DMG]Command handler moving to [CommandSen] D: 44375 [DMG]Command handler moving to [AwaitingDe] E: 44379 [DL]Long dispatch time: 120 ms, for event type 16388 D: 44432 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 44439 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 44448 [EM]>>> [E:46763r M:110274622] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 44459 [EM]Handling via exchange: 46763r, Delegate: 0x2000cd8c D: 44465 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 44472 [ZCL]OpCreds: Certificate Chain request received for DAC D: 44479 [DMG]Command handler moving to [ Preparing] D: 44483 [DMG]Command handler moving to [AddingComm] D: 44488 [DMG]Command handler moving to [AddedComma] D: 44493 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 44502 [EM]<<< [E:46763r M:60519162] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 44513 [IN](S) Sending msg 60519162 on secure session with LSID: 58721 D: 44520 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 44528 [DMG]Command handler moving to [CommandSen] D: 44532 [DMG]Command handler moving to [AwaitingDe] D: 44656 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 44664 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 44746 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 44754 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 44836 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 44844 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 44927 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 44934 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 44942 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 58) D: 45017 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45024 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 45032 [EM]>>> [E:46764r M:110274623] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 45043 [EM]Handling via exchange: 46764r, Delegate: 0x2000cd8c D: 45050 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 45057 [ZCL]OpCreds: Certificate Chain request received for PAI D: 45064 [DMG]Command handler moving to [ Preparing] D: 45068 [DMG]Command handler moving to [AddingComm] D: 45073 [DMG]Command handler moving to [AddedComma] D: 45078 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 45087 [EM]<<< [E:46764r M:60519163] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 45098 [IN](S) Sending msg 60519163 on secure session with LSID: 58721 D: 45104 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 45112 [DMG]Command handler moving to [CommandSen] D: 45117 [DMG]Command handler moving to [AwaitingDe] D: 45196 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45204 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 45286 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45294 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 45376 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45384 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 45467 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45474 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 45482 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 28) D: 45556 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45564 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 45572 [EM]>>> [E:46765r M:110274624] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 45584 [EM]Handling via exchange: 46765r, Delegate: 0x2000cd8c D: 45590 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 I: 45597 [ZCL]OpCreds: Received an AttestationRequest command I: 45634 [ZCL]OpCreds: AttestationRequest successful. D: 45638 [DMG]Command handler moving to [ Preparing] D: 45643 [DMG]Command handler moving to [AddingComm] D: 45648 [DMG]Command handler moving to [AddedComma] D: 45653 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 45663 [EM]<<< [E:46765r M:60519164] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 45674 [IN](S) Sending msg 60519164 on secure session with LSID: 58721 D: 45681 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 45688 [DMG]Command handler moving to [CommandSen] D: 45693 [DMG]Command handler moving to [AwaitingDe] E: 45698 [DL]Long dispatch time: 134 ms, for event type 16388 D: 45736 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45744 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 45871 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45879 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 45961 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 45969 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 46096 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 46141 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 46148 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 46276 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 46284 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 91) D: 46366 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 46374 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 46382 [EM]>>> [E:46766r M:110274625] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 46394 [EM]Handling via exchange: 46766r, Delegate: 0x2000cd8c D: 46400 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 I: 46407 [ZCL]OpCreds: Received a CSRRequest command D: 46412 [ZCL]OpCreds: Finding fabric with fabricIndex 0x0 I: 46603 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded I: 46639 [ZCL]OpCreds: CSRRequest successful. D: 46643 [DMG]Command handler moving to [ Preparing] D: 46648 [DMG]Command handler moving to [AddingComm] D: 46653 [DMG]Command handler moving to [AddedComma] D: 46658 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 46666 [EM]<<< [E:46766r M:60519165] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 46677 [IN](S) Sending msg 60519165 on secure session with LSID: 58721 D: 46684 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 46691 [DMG]Command handler moving to [CommandSen] D: 46696 [DMG]Command handler moving to [AwaitingDe] E: 46701 [DL]Long dispatch time: 327 ms, for event type 16388 D: 46816 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 46824 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 128) D: 46906 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 46914 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 127) D: 46996 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 49067 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 49157 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 49247 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 49256 [EM]>>> [E:46767r M:110274626] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 49267 [EM]Handling via exchange: 46767r, Delegate: 0x2000cd8c D: 49273 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B I: 49281 [ZCL]OpCreds: Received an AddTrustedRootCertificate command I: 49344 [ZCL]OpCreds: AddTrustedRootCertificate successful. D: 49350 [DMG]Command handler moving to [ Preparing] D: 49354 [DMG]Command handler moving to [AddingComm] D: 49359 [DMG]Command handler moving to [AddedComma] D: 49364 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 49371 [EM]<<< [E:46767r M:60519166] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 49382 [IN](S) Sending msg 60519166 on secure session with LSID: 58721 D: 49389 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68) D: 49396 [DMG]Command handler moving to [CommandSen] D: 49401 [DMG]Command handler moving to [AwaitingDe] E: 49406 [DL]Long dispatch time: 159 ms, for event type 16388 D: 49516 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 49562 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 49652 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 49742 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 49877 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 49884 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 50011 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 50019 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 50102 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 50113 [EM]>>> [E:46768r M:110274627] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 50124 [EM]Handling via exchange: 46768r, Delegate: 0x2000cd8c D: 50130 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 I: 50138 [ZCL]OpCreds: Received an AddNOC command I: 50145 [FP]Validating NOC chain I: 50263 [FP]NOC chain validation successful I: 50267 [FP]Added new fabric at index: 0x1 I: 50271 [FP]Assigned compressed fabric ID: 0xF42E5BF5B2BAD9F3, node ID: 0x0000000081DACAF1 I: 50279 [TS]Last Known Good Time: 2023-03-02T16:41:46 I: 50284 [TS]New proposed Last Known Good Time: 2023-03-02T12:05:17 I: 50290 [TS]Retaining current Last Known Good Time D: 50295 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e3f476cc D: 50301 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e3f476cd D: 50461 [EVL]LogEvent event number: 0x0000000000010002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000000C51D I: 50475 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00010001 D: 50484 [DL]Using Thread extended MAC for hostname. I: 50489 [DIS]Advertise operational node F42E5BF5B2BAD9F3-0000000081DACAF1 D: 50495 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e3f476ce D: 50502 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e3f476cf D: 50509 [DMG]Command handler moving to [ Preparing] D: 50513 [DMG]Command handler moving to [AddingComm] D: 50518 [DMG]Command handler moving to [AddedComma] I: 50523 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC D: 50529 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 50536 [EM]<<< [E:46768r M:60519167] (S) Msg TX to 1:FFFFFFFB00000000 [D9F3] --- Type 0001:09 (IM:InvokeCommandResponse) I: 50547 [IN](S) Sending msg 60519167 on secure session with LSID: 58721 D: 50554 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 50562 [DMG]Command handler moving to [CommandSen] D: 50566 [DMG]Command handler moving to [AwaitingDe] E: 50571 [DL]Long dispatch time: 469 ms, for event type 16388 D: 50641 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 50649 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 50731 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 50740 [EM]>>> [E:46769r M:110274628] (S) Msg RX from 1:FFFFFFFB00000000 [D9F3] --- Type 0001:08 (IM:InvokeCommandRequest) D: 50751 [EM]Handling via exchange: 46769r, Delegate: 0x2000cd8c D: 50757 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 D: 50778 [DMG]Command handler moving to [ Preparing] D: 50783 [DMG]Command handler moving to [AddingComm] D: 50788 [DMG]Command handler moving to [AddedComma] D: 50792 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 6043529a D: 50799 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 50806 [EM]<<< [E:46769r M:60519168] (S) Msg TX to 1:FFFFFFFB00000000 [D9F3] --- Type 0001:09 (IM:InvokeCommandResponse) I: 50817 [IN](S) Sending msg 60519168 on secure session with LSID: 58721 D: 50824 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 50832 [DMG]Command handler moving to [CommandSen] D: 50836 [DMG]Command handler moving to [AwaitingDe] E: 50841 [DL]Long dispatch time: 110 ms, for event type 16388 D: 51227 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51234 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 51242 [EM]>>> [E:46770r M:110274629] (S) Msg RX from 1:FFFFFFFB00000000 [D9F3] --- Type 0001:02 (IM:ReadRequest) D: 51252 [EM]Handling via exchange: 46770r, Delegate: 0x2000cd8c D: 51258 [IM]Received Read request D: 51262 [DMG]IM RH moving to [GeneratingReports] D: 51267 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 51275 [DMG]<RE:Run> Cluster 31, Attribute 3 is dirty D: 51280 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 51289 [DMG]<RE> Sending report (payload has 36 bytes)... I: 51295 [EM]<<< [E:46770r M:60519169] (S) Msg TX to 1:FFFFFFFB00000000 [D9F3] --- Type 0001:05 (IM:ReportData) I: 51305 [IN](S) Sending msg 60519169 on secure session with LSID: 58721 D: 51312 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 51319 [DMG]<RE> OnReportConfirm: NumReports = 0 D: 51324 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 51331 [DMG]IM RH moving to [AwaitingDestruction] D: 51336 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 51406 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 51414 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 51422 [EM]>>> [E:46771r M:110274630] (S) Msg RX from 1:FFFFFFFB00000000 [D9F3] --- Type 0001:08 (IM:InvokeCommandRequest) D: 51433 [EM]Handling via exchange: 46771r, Delegate: 0x2000cd8c D: 51439 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 D: 51459 [DMG]Decreasing reference count for CommandHandler, remaining 1 D: 51467 [DL]OpenThread State Changed (Flags: 0x1017c100) D: 51472 [DL] Network Name: NEST-PAN-331E D: 51477 [DL] PAN Id: 0x331E D: 51479 [DL] Extended PAN Id: 0xF9083BCBD8D461F8 D: 51484 [DL] Channel: 24 D: 51487 [DL] Mesh Prefix: fd74:e1cd:c95::/64 D: 51492 [DL]OpenThread State Changed (Flags: 0x1100101d) D: 51497 [DL] Device Role: DETACHED D: 51501 [DL] Thread Unicast Addresses: D: 51504 [DL] fd74:e1cd:c95:0:b598:4cfe:f744:6619/64 valid D: 51510 [DL] fe80::1872:e596:9faf:d725/64 valid preferred D: 53921 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 54016 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 56581 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 59088 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 59146 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 61666 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 64173 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 64276 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 66796 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 69303 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 69361 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 71880 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 74388 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 74490 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 76965 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 79472 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 79530 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) I: 82455 [DL]BLE GAP connection terminated (reason 0x13) I: 82461 [DL]Current number of connections: 0/1 E: 94479 [BLE]ack recv timeout, closing ep 0x2000f3c0 D: 94484 [IN]Clearing BLE pending packets. I: 94488 [BLE]Releasing end point's BLE connection back to application. I: 94494 [DL]Closing BLE GATT connection (ConnId 00) I: 163820 [FS]Fail-safe timer expired E: 163824 [SVR]Failsafe timer expired D: 163827 [IN]SecureSession[0x20003540]: MarkForEviction Type:1 LSID:58721 I: 163834 [SC]SecureSession[0x20003540]: Moving from state 'kActive' --> 'kPendingEviction' D: 163842 [IN]SecureSession[0x20003540]: Released - Type:1 LSID:58721 E: 163848 [SVR]Commissioning failed (attempt 1): 32 D: 163854 [IN]SecureSession[0x20003540]: Allocated Type:1 LSID:58723 D: 163860 [SC]Assigned local session key ID 58723 D: 163865 [SC]Waiting for PBKDF param request D: 163869 [DL]CHIPoBLE advertising set to on I: 163873 [DIS]Updating services using commissioning mode 1 D: 163878 [DL]Using Thread extended MAC for hostname. D: 163883 [DL]Using Thread extended MAC for hostname. I: 163888 [DIS]Advertise operational node F42E5BF5B2BAD9F3-0000000081DACAF1 E: 163895 [DIS]Failed to advertise operational node: 3 D: 163900 [DL]Using Thread extended MAC for hostname. I: 163905 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 E: 163914 [DIS]Failed to advertise commissionable node: 3 E: 163920 [DIS]Failed to finalize service update: 1c E: 163924 [ZCL]OpCreds: Got FailSafeTimerExpired E: 163929 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry! D: 163935 [IN]Expiring all sessions for fabric 0x1!! E: 163940 [FP]Reverting pending fabric data for fabric 0x1 D: 163945 [EVL]LogEvent event number: 0x0000000000010003 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x0000000000028069 D: 163959 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet E: 163966 [FP]Warning: metadata not found during delete of fabric 0x1 I: 163980 [FP]Fabric (0x1) deleted. I: 163983 [ZCL]OpCreds: Fabric index 0x1 was removed D: 163989 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e3f476d0 D: 163995 [DMG]Endpoint 0, Cluster 0x0000_003E update version to e3f476d1 I: 164017 [TS]Pending Last Known Good Time: 2023-03-02T16:41:46 I: 164023 [TS]Previous Last Known Good Time: 2023-03-02T16:41:46 I: 164029 [TS]Reverted Last Known Good Time to previous value D: 164035 [EVL]LogEvent event number: 0x0000000000010004 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x00000000000280C2 D: 164049 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet E: 164055 [FP]Warning: metadata not found during delete of fabric 0x1 E: 164063 [ZCL]OpCreds: failed to delete fabric at index 1: d8 D: 164069 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 6043529b D: 164075 [ZCL]Failsafe timeout, tell platform driver to revert network credentials. I: 164083 [NP]Reverting Thread operational dataset D: 164093 [DMG]Decreasing reference count for CommandHandler, remaining 0 E: 164100 [DMG]Failed to send command response: 3 D: 164104 [DMG]Command handler moving to [AwaitingDe] E: 164109 [DL]Long dispatch time: 285 ms, for event type 32782 I: 164115 [FS]Fail-safe cleanly disarmed I: 164120 [DL]CHIPoBLE advertising started D: 164124 [DL]OpenThread State Changed (Flags: 0x11002006) D: 164129 [DL] Device Role: DISABLED D: 164133 [DL] Thread Unicast Addresses: D: 164137 [DL]OpenThread State Changed (Flags: 0x10000000) I: 194125 [DL]CHIPoBLE advertising mode changed to slow
My configuration looks like:
- Android version: 11
- Home App version: 2.63.1.12 (using in public preview mode)
- BR: google nest hub(v47.9.4.447810048)
- Chromecast version: v1.56.324896
- There are no other things in the network currently.
EDIT 1: I would also like to add i tried to commission the light switch sample in which it is configured as sleepy end device and couldn't do so. Is there anything else to do other than set the device type as sleepy end device?
EDIT 2: I tried to commission the device using the python chip controller, i was not able to commission my device
