During an unsuccessful attempt to pair a Matter device with an OTBR/Matter controller, the following log appears: "SRP update error: timed out waiting on server response"
What could be the cause ?
uart:~$ *** Booting nRF Connect SDK v2.5.2 *** I: Init CHIP stack I: 211 [DL]BLE address: DF:FE:5B:8C:54:6F I: 220 [DL]OpenThread started: OK I: 223 [DL]Setting OpenThread device type to ROUTER I: 229 [SVR]Subscription persistence not supported I: 233 [SVR]Server initializing... I: 237 [TS]Last Known Good Time: 2024-03-04T21:31:08 I: 242 [DMG]AccessControl: initializing I: 246 [DMG]Examples::AccessControlDelegate::Init I: 250 [DMG]AccessControl: setting I: 253 [DMG]DefaultAclStorage: initializing I: 257 [DMG]DefaultAclStorage: 0 entries loaded D: 261 [IN]UDP::Init bind&listen port=5540 E: 265 [IN]SO_REUSEPORT failed: 109 D: 268 [IN]UDP::Init bound to port=5540 D: 272 [IN]BLEBase::Init - setting/overriding transport D: 277 [IN]TransportMgr initialized D: 283 [DL]Using Thread extended MAC for hostname. I: 290 [ZCL]Using ZAP configuration... I: 295 [DMG]AccessControlCluster: initializing D: 299 [DL]Boot reason: 1 I: 302 [ZCL]Initiating Admin Commissioning cluster. I: 307 [ZCL]Endpoint 1 On/off already set to new value I: 312 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254 D: 318 [IN]SecureSession[0x20003230]: Allocated Type:1 LSID:32855 D: 324 [DL]CHIPoBLE advertising set to on I: 328 [DIS]Updating services using commissioning mode 1 E: 333 [DIS]Failed to remove advertised services: 3 D: 338 [DL]Using Thread extended MAC for hostname. I: 342 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 E: 351 [DIS]Failed to advertise commissionable node: 3 E: 356 [DIS]Failed to finalize service update: 3 I: 360 [DIS]Updating services using commissioning mode 1 E: 365 [DIS]Failed to remove advertised services: 3 D: 370 [DL]Using Thread extended MAC for hostname. I: 374 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 E: 383 [DIS]Failed to advertise commissionable node: 3 E: 388 [DIS]Failed to finalize service update: 3 I: 392 [DIS]Delaying proxy of operational discovery: missing delegate I: 399 [IN]CASE Server enabling CASE session setups D: 403 [IN]SecureSession[0x200032e8]: Allocated Type:2 LSID:32856 I: 409 [SVR]Joining Multicast groups I: 413 [SVR]Server Listening... I: 415 [DL]Device Configuration: I: 418 [DL] Serial Number: 11223344556677889900 I: 423 [DL] Vendor Id: 65521 (0xFFF1) I: 426 [DL] Product Id: 32773 (0x8005) I: 430 [DL] Product Name: not-specified I: 433 [DL] Hardware Version: 0 I: 436 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 442 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) I: 448 [DL] Manufacturing Date: 2022-01-01 I: 452 [DL] Device Type: 65535 (0xFFFF) I: 456 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00] I: 460 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 466 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00 I: 475 [SVR]Manual pairing code: [34970112332] I: 480 [DL]CHIP task running I: 484 [DL]CHIPoBLE advertising started I: 488 [ZCL]Cluster OnOff: attribute OnOff set to 0 I: 493 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254 I: 499 [DL]NFC Tag emulation started I: 30488 [DL]CHIPoBLE advertising mode changed to slow I: 30494 [DL]CHIPoBLE advertising started I: 32826 [DL]BLE connection established (ConnId: 0x00) I: 32831 [DL]Current number of connections: 1/1 I: 32835 [DL]CHIPoBLE advertising stopped I: 32839 [DL]NFC Tag emulation stopped D: 33602 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 33609 [BLE]local and remote recv window sizes = 5 I: 33614 [BLE]selected BTP version 4 I: 33618 [BLE]using BTP fragment sizes rx 244 / tx 244. D: 33625 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 33629 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 33636 [IN]BLE EndPoint 0x20012158 Connection Complete I: 33642 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247) D: 33699 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 33790 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 33797 [EM]>>> [E:36699r S:0 M:45547311] (U) Msg RX from 0:6D557E1E8FADEA77 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) I: 33810 [EM]<<< [E:36699r S:0 M:77337346] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) I: 33822 [IN](U) Sending msg 77337346 to IP address 'BLE' D: 33828 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 140) D: 33939 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 33947 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 33955 [EM]>>> [E:36699r S:0 M:45547312] (U) Msg RX from 0:6D557E1E8FADEA77 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) I: 35601 [EM]<<< [E:36699r S:0 M:77337347] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) I: 35612 [IN](U) Sending msg 77337347 to IP address 'BLE' D: 35618 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132) E: 35625 [DL]Long dispatch time: 1678 ms, for event type 16388 D: 35694 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 35703 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 35710 [EM]>>> [E:36699r S:0 M:45547313] (U) Msg RX from 0:6D557E1E8FADEA77 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) I: 35722 [EM]<<< [E:36699r S:0 M:77337348] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) I: 35733 [IN](U) Sending msg 77337348 to IP address 'BLE' D: 35739 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 35747 [SC]SecureSession[0x20003230]: Moving from state 'kEstablishing' --> 'kActive' D: 35755 [IN]SecureSession[0x20003230]: Activated - Type:1 LSID:32855 D: 35761 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:32855 PSID:19682! I: 35770 [SVR]Commissioning completed session establishment step I: 35776 [DIS]Updating services using commissioning mode 0 E: 35781 [DIS]Failed to remove advertised services: 3 E: 35786 [DIS]Failed to finalize service update: 3 D: 35791 [DL]CHIPoBLE advertising set to off I: 35795 [SVR]Device completed Rendezvous process D: 35829 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 35837 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 35845 [EM]>>> [E:36700r S:32855 M:148450504] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 35856 [IM]Received Read request I: 35861 [EM]<<< [E:36700r S:32855 M:160773457] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 35872 [IN](S) Sending msg 160773457 on secure session with LSID: 32855 D: 35879 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 97) D: 35964 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 35972 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 35980 [EM]>>> [E:36701r S:32855 M:148450505] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 35991 [IM]Received Read request I: 35996 [EM]<<< [E:36701r S:32855 M:160773458] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 36007 [IN](S) Sending msg 160773458 on secure session with LSID: 32855 D: 36013 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 36099 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 36107 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 36115 [EM]>>> [E:36702r S:32855 M:148450506] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 36126 [IM]Received Read request I: 36131 [EM]<<< [E:36702r S:32855 M:160773459] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 36142 [IN](S) Sending msg 160773459 on secure session with LSID: 32855 D: 36148 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 36234 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 36242 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 36250 [EM]>>> [E:36703r S:32855 M:148450507] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 36261 [IM]Received Read request I: 36266 [EM]<<< [E:36703r S:32855 M:160773460] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 36277 [IN](S) Sending msg 160773460 on secure session with LSID: 32855 D: 36283 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 36369 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 36377 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 36385 [EM]>>> [E:36704r S:32855 M:148450508] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 36396 [IM]Received Read request I: 36401 [EM]<<< [E:36704r S:32855 M:160773461] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 36412 [IN](S) Sending msg 160773461 on secure session with LSID: 32855 D: 36418 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 36504 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 36512 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 36520 [EM]>>> [E:36705r S:32855 M:148450509] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 36531 [IM]Received Read request I: 36536 [EM]<<< [E:36705r S:32855 M:160773462] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 36547 [IN](S) Sending msg 160773462 on secure session with LSID: 32855 D: 36553 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 36639 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 36647 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 36655 [EM]>>> [E:36706r S:32855 M:148450510] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) I: 36668 [ZCL]OpCreds: Certificate Chain request received for DAC I: 36677 [EM]<<< [E:36706r S:32855 M:160773463] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 36688 [IN](S) Sending msg 160773463 on secure session with LSID: 32855 D: 36695 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 36774 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 36782 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 36864 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 36872 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77) D: 36954 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 36962 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 36970 [EM]>>> [E:36707r S:32855 M:148450511] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 36981 [IM]Received Read request I: 36986 [EM]<<< [E:36707r S:32855 M:160773464] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 36997 [IN](S) Sending msg 160773464 on secure session with LSID: 32855 D: 37004 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 97) D: 37089 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37097 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37105 [EM]>>> [E:36708r S:32855 M:148450512] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 37116 [IM]Received Read request I: 37121 [EM]<<< [E:36708r S:32855 M:160773465] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 37132 [IN](S) Sending msg 160773465 on secure session with LSID: 32855 D: 37138 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 37224 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37232 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37240 [EM]>>> [E:36709r S:32855 M:148450513] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 37251 [IM]Received Read request I: 37256 [EM]<<< [E:36709r S:32855 M:160773466] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 37267 [IN](S) Sending msg 160773466 on secure session with LSID: 32855 D: 37273 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 37359 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37367 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37375 [EM]>>> [E:36710r S:32855 M:148450514] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest) I: 37387 [EM]<<< [E:36710r S:32855 M:160773467] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse) I: 37398 [IN](S) Sending msg 160773467 on secure session with LSID: 32855 D: 37405 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 37494 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37502 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37510 [EM]>>> [E:36710r S:32855 M:148450515] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) I: 37523 [FS]GeneralCommissioning: Received ArmFailSafe (120s) I: 37529 [EM]<<< [E:36710r S:32855 M:160773468] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 37541 [IN](S) Sending msg 160773468 on secure session with LSID: 32855 D: 37547 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 37629 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37637 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37645 [EM]>>> [E:36711r S:32855 M:148450516] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 37656 [IM]Received Read request I: 37661 [EM]<<< [E:36711r S:32855 M:160773469] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 37672 [IN](S) Sending msg 160773469 on secure session with LSID: 32855 D: 37678 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 37764 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37772 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37780 [EM]>>> [E:36712r S:32855 M:148450517] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest) I: 37792 [EM]<<< [E:36712r S:32855 M:160773470] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse) I: 37803 [IN](S) Sending msg 160773470 on secure session with LSID: 32855 D: 37810 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 37899 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37907 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37915 [EM]>>> [E:36712r S:32855 M:148450518] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) I: 37946 [EM]<<< [E:36712r S:32855 M:160773471] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 37958 [IN](S) Sending msg 160773471 on secure session with LSID: 32855 D: 37964 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 38079 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38087 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 38096 [EM]>>> [E:36713r S:32855 M:148450519] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) I: 38108 [ZCL]OpCreds: Certificate Chain request received for PAI I: 38117 [EM]<<< [E:36713r S:32855 M:160773472] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 38128 [IN](S) Sending msg 160773472 on secure session with LSID: 32855 D: 38135 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 38214 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38222 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 38304 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38312 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48) D: 38394 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38403 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 38411 [EM]>>> [E:36714r S:32855 M:148450520] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) I: 38423 [ZCL]OpCreds: Received an AttestationRequest command I: 38462 [ZCL]OpCreds: AttestationRequest successful. I: 38471 [EM]<<< [E:36714r S:32855 M:160773473] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 38483 [IN](S) Sending msg 160773473 on secure session with LSID: 32855 D: 38490 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 38574 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38582 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 38664 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38672 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 237) D: 38754 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38762 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 38771 [EM]>>> [E:36715r S:32855 M:148450521] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) I: 38783 [ZCL]OpCreds: Received a CSRRequest command I: 38955 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded I: 38995 [ZCL]OpCreds: CSRRequest successful. I: 39001 [EM]<<< [E:36715r S:32855 M:160773474] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 39013 [IN](S) Sending msg 160773474 on secure session with LSID: 32855 D: 39019 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) E: 39027 [DL]Long dispatch time: 265 ms, for event type 16388 D: 39114 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39122 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 139) D: 39204 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39657 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 39745 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 39754 [EM]>>> [E:36716r S:32855 M:148450522] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) I: 39766 [ZCL]OpCreds: Received an AddTrustedRootCertificate command I: 39834 [ZCL]OpCreds: AddTrustedRootCertificate successful. I: 39840 [EM]<<< [E:36716r S:32855 M:160773475] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 39852 [IN](S) Sending msg 160773475 on secure session with LSID: 32855 D: 39858 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68) E: 39866 [DL]Long dispatch time: 121 ms, for event type 16388 D: 39924 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39933 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 40016 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 40025 [EM]>>> [E:36717r S:32855 M:148450523] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) I: 40037 [ZCL]OpCreds: Received an AddNOC command I: 40044 [FP]Validating NOC chain I: 40110 [FP]NOC chain validation successful I: 40114 [FP]Added new fabric at index: 0x1 I: 40118 [FP]Assigned compressed fabric ID: 0xDEBFDED298055D34, node ID: 0x7B1FFC5E40FFED90 I: 40127 [TS]Last Known Good Time: 2024-03-04T21:31:08 I: 40132 [TS]New proposed Last Known Good Time: 2024-03-06T00:00:00 I: 40138 [TS]Updating pending Last Known Good Time to 2024-03-06T00:00:00 I: 40169 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00010001 D: 40177 [DL]Using Thread extended MAC for hostname. I: 40182 [DIS]Advertise operational node DEBFDED298055D34-7B1FFC5E40FFED90 I: 40189 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC I: 40196 [EM]<<< [E:36717r S:32855 M:160773476] (S) Msg TX to 1:FFFFFFFB00000000 [5D34] --- Type 0001:09 (IM:InvokeCommandResponse) I: 40208 [IN](S) Sending msg 160773476 on secure session with LSID: 32855 D: 40214 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) E: 40222 [DL]Long dispatch time: 206 ms, for event type 16388 D: 40284 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40293 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 40301 [EM]>>> [E:36718r S:32855 M:148450524] (S) Msg RX from 1:FFFFFFFB00000000 [5D34] --- Type 0001:08 (IM:InvokeCommandRequest) I: 40320 [EM]<<< [E:36718r S:32855 M:160773477] (S) Msg TX to 1:FFFFFFFB00000000 [5D34] --- Type 0001:09 (IM:InvokeCommandResponse) I: 40332 [IN](S) Sending msg 160773477 on secure session with LSID: 32855 D: 40338 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 40419 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40427 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 40435 [EM]>>> [E:36719r S:32855 M:148450525] (S) Msg RX from 1:FFFFFFFB00000000 [5D34] --- Type 0001:02 (IM:ReadRequest) D: 40446 [IM]Received Read request I: 40451 [EM]<<< [E:36719r S:32855 M:160773478] (S) Msg TX to 1:FFFFFFFB00000000 [5D34] --- Type 0001:05 (IM:ReportData) I: 40462 [IN](S) Sending msg 160773478 on secure session with LSID: 32855 D: 40468 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 40554 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40562 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 40570 [EM]>>> [E:36720r S:32855 M:148450526] (S) Msg RX from 1:FFFFFFFB00000000 [5D34] --- Type 0001:08 (IM:InvokeCommandRequest) D: 40593 [DL]OpenThread State Changed (Flags: 0x101fc100) D: 40599 [DL] Network Name: mythread D: 40602 [DL] PAN Id: 0x1234 D: 40605 [DL] Extended PAN Id: 0x1111111122222222 D: 40610 [DL] Channel: 15 D: 40612 [DL] Mesh Prefix: fdaa:1434:dc31:af63::/64 D: 40618 [DL]OpenThread State Changed (Flags: 0x1100101d) D: 40623 [DL] Device Role: DETACHED D: 40627 [DL] Thread Unicast Addresses: D: 40630 [DL] fdaa:1434:dc31:af63:8e0e:6f87:afa3:c57b/64 valid D: 40637 [DL] fe80::3c78:116f:9d64:c5ba/64 valid preferred I: 41714 [DL]SRP Client was started, detected server: fd8b:fda2:c58c:5546:855a:d7b7:31aa:5438 D: 41723 [DL]OpenThread State Changed (Flags: 0x200012a4) D: 41728 [DL] Device Role: CHILD D: 41732 [DL] Partition Id: 0x6F4F727B D: 41736 [DL]OpenThread State Changed (Flags: 0x00000001) D: 41741 [DL] Thread Unicast Addresses: D: 41746 [DL] fd11:22::ba2b:5fce:dd95:e16a/64 valid preferred D: 41752 [DL] fdaa:1434:dc31:af63:0:ff:fe00:5406/64 valid rloc D: 41759 [DL] fdaa:1434:dc31:af63:8e0e:6f87:afa3:c57b/64 valid D: 41765 [DL] fe80::3c78:116f:9d64:c5ba/64 valid preferred I: 41773 [EM]<<< [E:36720r S:32855 M:160773479] (S) Msg TX to 1:FFFFFFFB00000000 [5D34] --- Type 0001:09 (IM:InvokeCommandResponse) I: 41785 [IN](S) Sending msg 160773479 on secure session with LSID: 32855 D: 41791 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70) D: 41799 [DL]Using Thread extended MAC for hostname. I: 41804 [DIS]Advertise operational node DEBFDED298055D34-7B1FFC5E40FFED90 I: 41811 [SVR]Operational advertising enabled D: 41859 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) I: 42894 [DL]BLE GAP connection terminated (reason 0x13) I: 42900 [DL]Current number of connections: 0/1 E: 44233 [DL]SRP update error: timed out waiting on server response E: 47634 [DL]SRP update error: timed out waiting on server response E: 53054 [DL]SRP update error: timed out waiting on server response E: 56800 [BLE]ack recv timeout, closing ep 0x20012158 D: 56804 [IN]Clearing BLE pending packets. I: 56808 [BLE]Releasing end point's BLE connection back to application. I: 56814 [DL]Closing BLE GATT connection (ConnId 00) E: 62200 [DL]SRP update error: timed out waiting on server response E: 77796 [DL]SRP update error: timed out waiting on server response E: 103906 [DL]SRP update error: timed out waiting on server response E: 147450 [DL]SRP update error: timed out waiting on server response I: 157528 [FS]Fail-safe timer expired E: 157532 [SVR]Failsafe timer expired D: 157535 [IN]SecureSession[0x20003230]: MarkForEviction Type:1 LSID:32855 I: 157542 [SC]SecureSession[0x20003230]: Moving from state 'kActive' --> 'kPendingEviction' D: 157550 [IN]SecureSession[0x20003230]: Released - Type:1 LSID:32855 E: 157556 [SVR]Commissioning failed (attempt 1): 32 D: 157561 [IN]SecureSession[0x20003230]: Allocated Type:1 LSID:32857 D: 157567 [DL]CHIPoBLE advertising set to on I: 157571 [DIS]Updating services using commissioning mode 1 E: 157577 [DIS]Failed to remove advertised services: 3 D: 157581 [DL]Using Thread extended MAC for hostname. I: 157586 [DIS]Advertise operational node DEBFDED298055D34-7B1FFC5E40FFED90 E: 157593 [DIS]Failed to advertise operational node: 3 D: 157598 [DL]Using Thread extended MAC for hostname. I: 157603 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 E: 157612 [DIS]Failed to advertise commissionable node: 3 E: 157617 [DIS]Failed to finalize service update: 3 E: 157622 [ZCL]OpCreds: Got FailSafeTimerExpired E: 157626 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry! D: 157633 [IN]Expiring all sessions for fabric 0x1!! E: 157637 [FP]Reverting pending fabric data for fabric 0x1 E: 157643 [FP]Warning: metadata not found during delete of fabric 0x1 I: 157708 [FP]Fabric (0x1) deleted. I: 157711 [ZCL]OpCreds: Fabric index 0x1 was removed I: 157716 [DIS]Updating services using commissioning mode 1 E: 157721 [DIS]Failed to remove advertised services: 3 D: 157726 [DL]Using Thread extended MAC for hostname. I: 157731 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 E: 157740 [DIS]Failed to advertise commissionable node: 3 E: 157745 [DIS]Failed to finalize service update: 3 I: 157856 [TS]Pending Last Known Good Time: 2024-03-06T00:00:00 I: 157863 [TS]Previous Last Known Good Time: 2024-03-04T21:31:08 I: 157868 [TS]Reverted Last Known Good Time to previous value E: 157875 [FP]Warning: metadata not found during delete of fabric 0x1 E: 157883 [ZCL]OpCreds: failed to delete fabric at index 1: d8 I: 157889 [NP]Reverting Thread operational dataset E: 157901 [DL]Long dispatch time: 369 ms, for event type 32782 I: 157907 [FS]Fail-safe cleanly disarmed I: 157912 [DL]CHIPoBLE advertising started D: 157916 [DL]OpenThread State Changed (Flags: 0x11002046) D: 157921 [DL] Device Role: DISABLED D: 157925 [DL] Thread Unicast Addresses: D: 157929 [DL] fd11:22::ba2b:5fce:dd95:e16a/64 valid preferred D: 157935 [DL]OpenThread State Changed (Flags: 0x10000000) I: 157941 [DL]NFC Tag emulation started I: 158711 [TS]Pending Last Known Good Time: 2024-03-04T21:31:08 I: 158718 [TS]Previous Last Known Good Time: 2024-03-04T21:31:08 I: 158723 [TS]Reverted Last Known Good Time to previous value I: 158729 [DL]Performing factory reset
