Matter over Thread commission error with CHIP-Tools: CHIP Error 0x00000032: Timeout

[susepc]

Hello DevZone,

I'm building a Matter development environment with OTBR and CHIP-Tool:

• NB: Ubuntu 22.04 with WIFI and BT, get CHIP tool from official pre-built (V2.5.1 corresponding version: chip-tool-linux_x64.zip)
• DK: nRF52840DK with Light Bulb examples(build from V2.5.1)
• Raspberry Pi4 with OTBR configured
• DK: nRF52840DK with coprocessor examples(build from V2.5.1)

But when I want to commission the bulb, it popup errors(as below attachments):

Then I check this issue in DevZone(CHIP error 0x32), it's solution is the credentials is not correct, but I have checked my credentials before commission that they are all correct.

So I am confusing why commission fail with CHIP-Tools: CHIP Error 0x00000032: Timeout?

Looking forward to your response! thx

CHIP tool log:

[1732796087.845465][6682:6684] CHIP:EM: <<< [E:50772i S:59916 M:206939600] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1732796087.845531][6682:6684] CHIP:IN: (S) Sending msg 206939600 on secure session with LSID: 59916
[1732796087.845908][6682:6684] CHIP:DMG: ICR moving to [CommandSen]
[1732796087.928892][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1732796087.975564][6682:6683] CHIP:DL: Indication received, conn = 0x7fb2b8049220
[1732796087.975800][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1732796087.975985][6682:6684] CHIP:EM: >>> [E:50772i S:59916 M:91052311] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1732796087.976033][6682:6684] CHIP:EM: Found matching exchange: 50772i, Delegate: 0x7fb2b0022108
[1732796087.976068][6682:6684] CHIP:DMG: ICR moving to [ResponseRe]
[1732796087.976130][6682:6684] CHIP:DMG: InvokeResponseMessage =
[1732796087.976167][6682:6684] CHIP:DMG: {
[1732796087.976196][6682:6684] CHIP:DMG: suppressResponse = false,
[1732796087.976224][6682:6684] CHIP:DMG: InvokeResponseIBs =
[1732796087.976274][6682:6684] CHIP:DMG: [
[1732796087.976308][6682:6684] CHIP:DMG: InvokeResponseIB =
[1732796087.976355][6682:6684] CHIP:DMG: {
[1732796087.976386][6682:6684] CHIP:DMG: CommandDataIB =
[1732796087.976426][6682:6684] CHIP:DMG: {
[1732796087.976461][6682:6684] CHIP:DMG: CommandPathIB =
[1732796087.976495][6682:6684] CHIP:DMG: {
[1732796087.976529][6682:6684] CHIP:DMG: EndpointId = 0x0,
[1732796087.976569][6682:6684] CHIP:DMG: ClusterId = 0x30,
[1732796087.976608][6682:6684] CHIP:DMG: CommandId = 0x1,
[1732796087.976638][6682:6684] CHIP:DMG: },
[1732796087.976674][6682:6684] CHIP:DMG:
[1732796087.976712][6682:6684] CHIP:DMG: CommandFields =
[1732796087.976748][6682:6684] CHIP:DMG: {
[1732796087.976793][6682:6684] CHIP:DMG: 0x0 = 0,
[1732796087.976838][6682:6684] CHIP:DMG: 0x1 = "" (0 chars),
[1732796087.976883][6682:6684] CHIP:DMG: },
[1732796087.976919][6682:6684] CHIP:DMG: },
[1732796087.976970][6682:6684] CHIP:DMG:
[1732796087.977003][6682:6684] CHIP:DMG: },
[1732796087.977051][6682:6684] CHIP:DMG:
[1732796087.977083][6682:6684] CHIP:DMG: ],
[1732796087.977135][6682:6684] CHIP:DMG:
[1732796087.977167][6682:6684] CHIP:DMG: InteractionModelRevision = 1
[1732796087.977196][6682:6684] CHIP:DMG: },
[1732796087.977316][6682:6684] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1732796087.977366][6682:6684] CHIP:CTL: Status of extending fail-safe for CASE retry: 0
[1732796087.977437][6682:6684] CHIP:DMG: ICR moving to [AwaitingDe]
[1732796088.043671][6682:6684] CHIP:DIS: Checking node lookup status after 200 ms
[1732796090.673956][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1732796092.848031][6682:6684] CHIP:DL: Re-trying resolve
[1732796093.234041][6682:6683] CHIP:DL: Indication received, conn = 0x7fb2b8049220
[1732796093.234198][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1732796095.938689][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1732796097.852483][6682:6684] CHIP:DL: Re-trying resolve
[1732796098.498303][6682:6683] CHIP:DL: Indication received, conn = 0x7fb2b8049220
[1732796098.498623][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1732796101.204178][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1732796102.856444][6682:6684] CHIP:DL: Re-trying resolve
[1732796103.761917][6682:6683] CHIP:DL: Indication received, conn = 0x7fb2b8049220
[1732796103.762122][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1732796106.514139][6682:6684] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1732796107.861795][6682:6684] CHIP:DL: Avahi resolve failed
[1732796108.291628][6682:6682] CHIP:CTL: Shutting down the commissioner
[1732796108.291691][6682:6682] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1732796108.291731][6682:6682] CHIP:DIS: Closing all BLE connections
[1732796108.291770][6682:6682] CHIP:IN: Clearing BLE pending packets.
[1732796108.292258][6682:6682] CHIP:BLE: Auto-closing end point's BLE connection.
[1732796108.292309][6682:6682] CHIP:DL: Closing BLE GATT connection (con 0x7fb2b8049220)
[1732796108.292438][6682:6683] CHIP:DL: BluezDisconnect peer=F4:AB:1E:3F:C9:43
[1732796108.450873][6682:6682] CHIP:IN: SecureSession[0x7fb2b0020200]: MarkForEviction Type:1 LSID:59916
[1732796108.450927][6682:6682] CHIP:SC: SecureSession[0x7fb2b0020200]: Moving from state 'kActive' --> 'kPendingEviction'
[1732796108.450988][6682:6682] CHIP:IN: SecureSession[0x7fb2b0020200]: Released - Type:1 LSID:59916
[1732796108.451066][6682:6682] CHIP:CTL: Shutting down the controller
[1732796108.451098][6682:6682] CHIP:DIS: OperationalSessionSetup[1:000000000000000C]: Cancelling incomplete address resolution as device is being deleted.
[1732796108.451171][6682:6682] CHIP:CTL: Device connection failed. Error src/app/OperationalSessionSetup.cpp:438: CHIP Error 0x00000074: The operation has been cancelled
[1732796108.451209][6682:6682] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1732796108.451235][6682:6682] CHIP:FP: Forgetting fabric 0x1
[1732796108.451275][6682:6682] CHIP:TS: Pending Last Known Good Time: 2023-10-26T12:12:01
[1732796108.451458][6682:6682] CHIP:TS: Previous Last Known Good Time: 2023-10-26T12:12:01
[1732796108.451486][6682:6682] CHIP:TS: Reverted Last Known Good Time to previous value
[1732796108.451530][6682:6682] CHIP:CTL: Shutting down the commissioner
[1732796108.451554][6682:6682] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1732796108.451588][6682:6682] CHIP:CTL: Shutting down the controller
[1732796108.451624][6682:6682] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1732796108.452117][6682:6683] CHIP:DL: Bluez disconnected
[1732796108.452133][6682:6683] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1732796108.452242][6682:6682] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1732796108.452280][6682:6682] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1732796108.452302][6682:6682] CHIP:FP: Shutting down FabricTable
[1732796108.452316][6682:6682] CHIP:TS: Pending Last Known Good Time: 2023-10-26T12:12:01
[1732796108.452373][6682:6682] CHIP:TS: Previous Last Known Good Time: 2023-10-26T12:12:01
[1732796108.452383][6682:6682] CHIP:TS: Reverted Last Known Good Time to previous value
[1732796108.452523][6682:6682] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-FFMNZu)
[1732796108.452770][6682:6682] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1732796108.452794][6682:6682] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1732796108.452803][6682:6682] CHIP:DL: Inet Layer shutdown
[1732796108.452811][6682:6682] CHIP:DL: BLE shutdown
[1732796108.453326][6682:6682] CHIP:DL: System Layer shutdown
[1732796108.453446][6682:6682] CHIP:TOO: Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:537: CHIP Error 0x00000032: Timeout
ss1@nb18020136:~/Downloads/chip-tool-linux_x64$


Bulb log:

I: 114077 [EM]>>> [E:50772r S:54053 M:206939600] (S) Msg RX from 1:FFFFFFFB00000000 [1540] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 114089 [FS]GeneralCommissioning: Received ArmFailSafe (120s)
I: 114096 [EM]<<< [E:50772r S:54053 M:91052311] (S) Msg TX to 1:FFFFFFFB00000000 [1540] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 114107 [IN](S) Sending msg 91052311 on secure session with LSID: 54053
D: 114114 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 114202 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 116812 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 119320 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 119422 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 122077 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 124585 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 124687 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 127342 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 129849 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 129952 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
E: 130550 [DL]SRP update error: timed out waiting on server response
D: 131332 [DL]OpenThread State Changed (Flags: 0x00002044)
D: 131337 [DL] Device Role: DETACHED
D: 132607 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 134497 [DL]ConnId: 0x00, New CCCD value: 0x0000
D: 134501 [IN]Clearing BLE pending packets.
I: 134505 [BLE]Releasing end point's BLE connection back to application.
I: 134512 [DL]Closing BLE GATT connection (ConnId 00)
I: 134631 [DL]BLE GAP connection terminated (reason 0x16)
I: 134637 [DL]Current number of connections: 0/1
I: 234094 [FS]Fail-safe timer expired
E: 234098 [SVR]Failsafe timer expired
D: 234101 [IN]SecureSession[0x200031b0]: MarkForEviction Type:1 LSID:54053
I: 234108 [SC]SecureSession[0x200031b0]: Moving from state 'kActive' --> 'kPendingEviction'
D: 234116 [IN]SecureSession[0x200031b0]: Released - Type:1 LSID:54053
E: 234122 [SVR]Commissioning failed (attempt 1): 32
D: 234127 [IN]SecureSession[0x200031b0]: Allocated Type:1 LSID:54055
D: 234133 [DL]CHIPoBLE advertising set to on
I: 234137 [DIS]Updating services using commissioning mode 1
D: 234143 [DL]Using Thread extended MAC for hostname.
I: 234148 [DIS]Advertise operational node FCEA78D788151540-000000000000000C
D: 234155 [DL]Using Thread extended MAC for hostname.
I: 234160 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
I: 234169 [DL]advertising srp service: 96D7216D347D602A._matterc._udp
E: 234175 [ZCL]OpCreds: Got FailSafeTimerExpired
E: 234180 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!
D: 234186 [IN]Expiring all sessions for fabric 0x1!!
E: 234191 [FP]Reverting pending fabric data for fabric 0x1
E: 234197 [FP]Warning: metadata not found during delete of fabric 0x1
I: 234257 [FP]Fabric (0x1) deleted.
I: 234261 [ZCL]OpCreds: Fabric index 0x1 was removed
I: 234265 [DIS]Updating services using commissioning mode 1
D: 234271 [DL]Using Thread extended MAC for hostname.
I: 234276 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
I: 234285 [DL]advertising srp service: 96D7216D347D602A._matterc._udp
I: 234292 [DL]removing srp service: FCEA78D788151540-000000000000000C._matter._tcp
I: 234406 [TS]Pending Last Known Good Time: 2024-10-24T15:40:36
I: 234412 [TS]Previous Last Known Good Time: 2024-10-24T15:40:36
I: 234418 [TS]Reverted Last Known Good Time to previous value
E: 234424 [FP]Warning: metadata not found during delete of fabric 0x1
E: 234433 [ZCL]OpCreds: failed to delete fabric at index 1: d8
I: 234439 [NP]Reverting Thread operational dataset
E: 234451 [DL]Long dispatch time: 353 ms, for event type 32782
I: 234457 [FS]Fail-safe cleanly disarmed
I: 234462 [DL]CHIPoBLE advertising started
D: 234466 [DL]OpenThread State Changed (Flags: 0x11002006)
D: 234471 [DL] Device Role: DISABLED
D: 234475 [DL] Thread Unicast Addresses:
D: 234479 [DL] fd85:5aa5:57b8:1:3780:d3e4:1c1a:9f86/64 valid preferred
D: 234486 [DL]OpenThread State Changed (Flags: 0x10000000)
I: 234492 [DL]NFC Tag emulation started
I: 235261 [TS]Pending Last Known Good Time: 2024-10-24T15:40:36
I: 235268 [TS]Previous Last Known Good Time: 2024-10-24T15:40:36
I: 235273 [TS]Reverted Last Known Good Time to previous value
I: 235279 [DL]Performing factory reset

[Charlie]

Did you test on office network environment?

One more thing I remeber of is that same features are disabled by office network for security reason, you may test with your home router or just a mobilephone hotspot to verify.

Best regards,

Charlie

[susepc]

Got it. I'll have a try next week, thanks for your tips!

[susepc]

 Charlie 

I have downloaded NCS 2.8.0 pass, and build FW to test:

• NB: Ubuntu 22.04 with WIFI and BT, get CHIP tool from official pre-built (V2.8.0 corresponding version: chip-tool-linux_x64.zip)
• DK: nRF52840DK with Light Bulb examples(build from NCS 2.8.0)
• Raspberry Pi4 with OTBR configured
• DK: nRF52840DK with coprocessor examples(build from NCS 2.8.0)

Unfortunately, I failed to connect to the network whether I used WIFI or mobile hotspot.

Could you view my logs and guide me how to fix this issue?

BR

Chuan

This is my credentials:

pi@raspberrypi:~ $ sudo ot-ctl dataset active -x
0e0800000000000100004a0300000e35060004001fffe00208096bd483014e202e0708fda37a11e76e0de9030f4f70656e5468726561642d3530353101025051041020a0307c03e7703f2c9992c1be24f3a70c0402a0f7f8000300000b051000112233445566778899aabbccddeeff
Done

This is my commission command:

ss1@nb18020136:~/2.8.0/chip-tool-linux_x64$ ./chip-tool-debug pairing ble-thread 1212 hex:0e0800000000000100004a0300000e35060004001fffe00208096bd483014e202e0708fda37a11e76e0de9030f4f70656e5468726561642d3530353101025051041020a0307c03e7703f2c9992c1be24f3a70c0402a0f7f8000300000b051000112233445566778899aabbccddeeff 20202021 3840
[1733132401.347767][4669:4669] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1733132401.348395][4669:4669] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1733132401.348405][4669:4669] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1733132401.348534][4669:4669] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1733132401.348598][4669:4669] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1733132401.348658][4669:4669] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1733132401.348806][4669:4669] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-4UB8ig)
[1733132401.349066][4669:4669] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)

[susepc]

CHIP tool log:

[1733132454.541537][4669:4671] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1733132454.541583][4669:4671] CHIP:CTL: Status of extending fail-safe for CASE retry: 0
[1733132454.541661][4669:4671] CHIP:DMG: ICR moving to [AwaitingDe]
[1733132454.609917][4669:4671] CHIP:DIS: Checking node lookup status after 200 ms
[1733132457.237690][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132459.414036][4669:4671] CHIP:DL: Re-trying resolve
[1733132459.795549][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132459.795730][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132462.502742][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132464.420409][4669:4671] CHIP:DL: Re-trying resolve
[1733132465.063255][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132465.063444][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132467.767874][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132469.425721][4669:4671] CHIP:DL: Re-trying resolve
[1733132470.327078][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132470.327165][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132473.032902][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132474.431388][4669:4671] CHIP:DL: Avahi resolve failed
[1733132475.590969][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132475.591149][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132478.342928][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132480.903112][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132480.903277][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132483.608076][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132486.167059][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132486.167272][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132488.873138][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132491.431482][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132491.431702][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132494.002580][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132496.563248][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132496.563430][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132499.268173][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132499.410773][4669:4671] CHIP:DIS: Checking node lookup status after 45001 ms
[1733132499.410843][4669:4671] CHIP:DIS: OperationalSessionSetup[1:00000000000004BC]: operational discovery failed: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:119: CHIP Error 0x00000032: Timeout
[1733132499.410867][4669:4671] CHIP:DIS: Retrying operational DNS-SD discovery. Attempts remaining: 1
[1733132499.410893][4669:4671] CHIP:DIS: Resolving F8711E6743B48C01:00000000000004BC ...
[1733132499.412305][4669:4671] CHIP:CTL: Session establishment failed for <00000000000004BC, 1>, error: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:119: CHIP Error 0x00000032: Timeout. Next retry expected to get a response to Sigma1 or fail within 60 seconds
[1733132499.412357][4669:4671] CHIP:CTL: Arming failsafe (120 seconds)
[1733132499.412419][4669:4671] CHIP:DMG: ICR moving to [AddingComm]
[1733132499.412459][4669:4671] CHIP:DMG: ICR moving to [AddedComma]
[1733132499.412589][4669:4671] CHIP:EM: <<< [E:56843i S:25152 M:109802343] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1733132499.413062][4669:4671] CHIP:DMG: ICR moving to [AwaitingRe]
[1733132499.493049][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132499.540354][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132499.540515][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132499.540655][4669:4671] CHIP:EM: >>> [E:56843i S:25152 M:116199231] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1733132499.540695][4669:4671] CHIP:EM: Found matching exchange: 56843i, Delegate: 0x7fdaf8006488
[1733132499.540745][4669:4671] CHIP:DMG: ICR moving to [ResponseRe]
[1733132499.540803][4669:4671] CHIP:DMG: InvokeResponseMessage =
[1733132499.540829][4669:4671] CHIP:DMG: {
[1733132499.540862][4669:4671] CHIP:DMG: suppressResponse = false,
[1733132499.540891][4669:4671] CHIP:DMG: InvokeResponseIBs =
[1733132499.540940][4669:4671] CHIP:DMG: [
[1733132499.540966][4669:4671] CHIP:DMG: InvokeResponseIB =
[1733132499.541016][4669:4671] CHIP:DMG: {
[1733132499.541049][4669:4671] CHIP:DMG: CommandDataIB =
[1733132499.541100][4669:4671] CHIP:DMG: {
[1733132499.541139][4669:4671] CHIP:DMG: CommandPathIB =
[1733132499.541177][4669:4671] CHIP:DMG: {
[1733132499.541215][4669:4671] CHIP:DMG: EndpointId = 0x0,
[1733132499.541251][4669:4671] CHIP:DMG: ClusterId = 0x30,
[1733132499.541286][4669:4671] CHIP:DMG: CommandId = 0x1,
[1733132499.541318][4669:4671] CHIP:DMG: },
[1733132499.541357][4669:4671] CHIP:DMG:
[1733132499.541388][4669:4671] CHIP:DMG: CommandFields =
[1733132499.541425][4669:4671] CHIP:DMG: {
[1733132499.541463][4669:4671] CHIP:DMG: 0x0 = 0 (unsigned),
[1733132499.541501][4669:4671] CHIP:DMG: 0x1 = "" (0 chars),
[1733132499.541536][4669:4671] CHIP:DMG: },
[1733132499.541565][4669:4671] CHIP:DMG: },
[1733132499.541610][4669:4671] CHIP:DMG:
[1733132499.541637][4669:4671] CHIP:DMG: },
[1733132499.541705][4669:4671] CHIP:DMG:
[1733132499.541736][4669:4671] CHIP:DMG: ],
[1733132499.541781][4669:4671] CHIP:DMG:
[1733132499.541810][4669:4671] CHIP:DMG: InteractionModelRevision = 11
[1733132499.541838][4669:4671] CHIP:DMG: },
[1733132499.541949][4669:4671] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1733132499.541995][4669:4671] CHIP:CTL: Status of extending fail-safe for CASE retry: 0
[1733132499.542074][4669:4671] CHIP:DMG: ICR moving to [AwaitingDe]
[1733132499.611555][4669:4671] CHIP:DIS: Checking node lookup status after 201 ms
[1733132502.103242][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132504.415079][4669:4671] CHIP:DL: Re-trying resolve
[1733132504.663550][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132504.663710][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132507.368307][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132509.421421][4669:4671] CHIP:DL: Re-trying resolve
[1733132509.927220][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132509.927402][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132512.633320][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132514.426648][4669:4671] CHIP:DL: Re-trying resolve
[1733132515.190744][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132515.190893][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132517.898343][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1733132519.431740][4669:4671] CHIP:DL: Avahi resolve failed
[1733132520.459636][4669:4670] CHIP:DL: Indication received, conn = 0x7fdb0004b6c0
[1733132520.459786][4669:4671] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1733132521.355685][4669:4669] CHIP:CTL: Shutting down the commissioner
[1733132521.355737][4669:4669] CHIP:CTL: Cancelling CASE setup for step 'kFindOperationalForStayActive'
[1733132521.355760][4669:4669] CHIP:DIS: Closing all BLE connections
[1733132521.355788][4669:4669] CHIP:IN: Clearing BLE pending packets.
[1733132521.356179][4669:4669] CHIP:BLE: Auto-closing end point's BLE connection.
[1733132521.356217][4669:4669] CHIP:DL: Closing BLE GATT connection (con 0x7fdb0004b6c0)
[1733132521.356415][4669:4670] CHIP:DL: BluezDisconnect peer=E9:8A:93:2A:4F:3F
[1733132521.500155][4669:4669] CHIP:IN: SecureSession[0x7fdaf800b2d0]: MarkForEviction Type:1 LSID:25152
[1733132521.500210][4669:4669] CHIP:SC: SecureSession[0x7fdaf800b2d0, LSID:25152]: State change 'kActive' --> 'kPendingEviction'
[1733132521.500302][4669:4669] CHIP:IN: SecureSession[0x7fdaf800b2d0]: Released - Type:1 LSID:25152
[1733132521.500354][4669:4669] CHIP:CTL: Shutting down the controller
[1733132521.500387][4669:4669] CHIP:DIS: OperationalSessionSetup[1:00000000000004BC]: Cancelling incomplete address resolution as device is being deleted.
[1733132521.500458][4669:4669] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1733132521.500492][4669:4669] CHIP:FP: Forgetting fabric 0x1
[1733132521.500525][4669:4669] CHIP:TS: Pending Last Known Good Time: 2023-10-26T12:12:01
[1733132521.500698][4669:4669] CHIP:TS: Previous Last Known Good Time: 2023-10-26T12:12:01
[1733132521.500725][4669:4669] CHIP:TS: Reverted Last Known Good Time to previous value
[1733132521.500769][4669:4669] CHIP:CTL: Shutting down the commissioner
[1733132521.500797][4669:4669] CHIP:CTL: Shutting down the controller
[1733132521.500823][4669:4669] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1733132521.501006][4669:4669] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1733132521.501138][4669:4669] CHIP:FP: Shutting down FabricTable
[1733132521.501175][4669:4669] CHIP:TS: Pending Last Known Good Time: 2023-10-26T12:12:01
[1733132521.501315][4669:4669] CHIP:TS: Previous Last Known Good Time: 2023-10-26T12:12:01
[1733132521.501341][4669:4669] CHIP:TS: Reverted Last Known Good Time to previous value
[1733132521.501624][4669:4669] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-mZVvIe)
[1733132521.502178][4669:4669] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1733132521.502240][4669:4669] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1733132521.502271][4669:4669] CHIP:DL: Inet Layer shutdown
[1733132521.502294][4669:4669] CHIP:DL: BLE shutdown
[1733132521.502916][4669:4670] CHIP:DL: Bluez disconnected
[1733132521.502955][4669:4670] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1733132521.503733][4669:4669] CHIP:DL: System Layer shutdown
[1733132521.503906][4669:4669] CHIP:TOO: Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:617: CHIP Error 0x00000032: Timeout
ss1@nb18020136:~/2.8.0/chip-tool-linux_x64$

[susepc]

Bulb syslog:

D: 12563 [DL]OpenThread State Changed (Flags: 0x101fc110)
D: 12568 [DL] Network Name: OpenThread-5051
D: 12572 [DL] PAN Id: 0x5051
D: 12575 [DL] Extended PAN Id: 0x096BD483014E202E
D: 12580 [DL] Channel: 11
D: 12582 [DL] Mesh Prefix: fda3:7a11:e76e:de9::/64
D: 12589 [DL]OpenThread State Changed (Flags: 0x1100100d)
D: 12594 [DL] Device Role: DETACHED
D: 12597 [DL] Thread Unicast Addresses:
D: 12601 [DL] fda3:7a11:e76e:de9:87a3:1b0a:fef6:cf69/64 valid preferred
D: 12608 [DL] fe80::84ff:dd56:cdcc:f963/64 valid preferred
I: 13705 [DL]SRP Client was started, detected server: fda3:7a11:e76e:0de9:595c:5bf4:b4ad:064f
I: 13714 [ZCL]ThreadDiagnosticsDelegate: OnConnectionStatusChanged
D: 13720 [DL]OpenThread State Changed (Flags: 0x200012a4)
D: 13725 [DL] Device Role: CHILD
D: 13728 [DL] Partition Id: 0x44C3ABC5
D: 13733 [DL]OpenThread State Changed (Flags: 0x00000001)
D: 13738 [DL] Thread Unicast Addresses:
D: 13742 [DL] fd85:5aa5:57b8:1:9157:6632:e212:6813/64 valid preferred
D: 13749 [DL] fda3:7a11:e76e:de9:0:ff:fe00:4c01/64 valid preferred rloc
D: 13756 [DL] fda3:7a11:e76e:de9:87a3:1b0a:fef6:cf69/64 valid preferred
D: 13763 [DL] fe80::84ff:dd56:cdcc:f963/64 valid preferred
I: 13771 [EM]<<< [E:56841r S:28517 M:116199229] (S) Msg TX to 1:FFFFFFFB00000000 [8C01] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
D: 13784 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70)
D: 13791 [DL]Using Thread extended MAC for hostname.
I: 13797 [DIS]Advertise operational node F8711E6743B48C01-00000000000004BC
I: 13803 [SVR]Operational advertising enabled
D: 13838 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
E: 15767 [DL]SRP update error: timed out waiting on server response
D: 16448 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
E: 18938 [DL]SRP update error: timed out waiting on server response
D: 18956 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 19058 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 21713 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 24220 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 24323 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
E: 24696 [DL]SRP update error: timed out waiting on server response
D: 26978 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 29485 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 29588 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 32288 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
E: 33668 [DL]SRP update error: timed out waiting on server response
D: 34795 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 34898 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 37598 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 40105 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 40207 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 42863 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 45370 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 45472 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 48128 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
E: 48808 [DL]SRP update error: timed out waiting on server response
D: 50635 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 50737 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 53393 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 55900 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 56002 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 58657 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 58839 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 58847 [EM]>>> [E:56842r S:28517 M:109802342] (S) Msg RX from 1:FFFFFFFB00000000 [8C01] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 58859 [FS]GeneralCommissioning: Received ArmFailSafe (120s)
I: 58866 [EM]<<< [E:56842r S:28517 M:116199230] (S) Msg TX to 1:FFFFFFFB00000000 [8C01] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
D: 58878 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 58972 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61582 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 64089 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 64192 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 66847 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 69354 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 69457 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 72112 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
E: 74497 [DL]SRP update error: timed out waiting on server response
D: 74619 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 74722 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 77377 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 79885 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 79987 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 82687 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 85195 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 85297 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 87952 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 90460 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 90562 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 93217 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 95725 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 95827 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 98347 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 100854 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 100957 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 103612 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 103838 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 103846 [EM]>>> [E:56843r S:28517 M:109802343] (S) Msg RX from 1:FFFFFFFB00000000 [8C01] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 103859 [FS]GeneralCommissioning: Received ArmFailSafe (120s)
I: 103866 [EM]<<< [E:56843r S:28517 M:116199231] (S) Msg TX to 1:FFFFFFFB00000000 [8C01] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
D: 103878 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 104017 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 106447 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 108954 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 109057 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
I: 111422 [ZCL]ThreadDiagnosticsDelegate: OnConnectionStatusChanged
I: 111428 [ZCL]ThreadDiagnosticsDelegate: OnNetworkFaultChanged
D: 111434 [DL]OpenThread State Changed (Flags: 0x00002044)
D: 111439 [DL] Device Role: DETACHED
D: 111712 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 114219 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 114321 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 116977 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 118270 [DL]SRP Client was stopped, because current server is no longer detected.
I: 118279 [ZCL]ThreadDiagnosticsDelegate: OnConnectionStatusChanged
D: 118286 [DL]OpenThread State Changed (Flags: 0x100012a5)
D: 118291 [DL] Device Role: LEADER
D: 118295 [DL] Partition Id: 0xDDF1893
D: 118298 [DL] Thread Unicast Addresses:
D: 118302 [DL] fda3:7a11:e76e:de9:0:ff:fe00:fc00/64 valid preferred
D: 118309 [DL] fda3:7a11:e76e:de9:0:ff:fe00:800/64 valid preferred rloc
D: 118316 [DL] fd85:5aa5:57b8:1:9157:6632:e212:6813/64 valid
D: 118322 [DL] fda3:7a11:e76e:de9:87a3:1b0a:fef6:cf69/64 valid preferred
D: 118329 [DL] fe80::84ff:dd56:cdcc:f963/64 valid preferred
D: 118337 [DL]OpenThread State Changed (Flags: 0x00000003)
D: 118342 [DL] Thread Unicast Addresses:
D: 118346 [DL] fda3:7a11:e76e:de9:0:ff:fe00:fc00/64 valid preferred
D: 118353 [DL] fda3:7a11:e76e:de9:0:ff:fe00:800/64 valid preferred rloc
D: 118360 [DL] fd85:5aa5:57b8:1:9157:6632:e212:6813/64 valid
D: 118366 [DL] fda3:7a11:e76e:de9:87a3:1b0a:fef6:cf69/64 valid preferred
D: 118373 [DL] fe80::84ff:dd56:cdcc:f963/64 valid preferred
D: 119485 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 119586 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 122242 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 124750 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 124851 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 125752 [DL]ConnId: 0x00, New CCCD value: 0x0000
D: 125756 [IN]Clearing BLE pending packets.
I: 125760 [BLE]Releasing end point's BLE connection back to application.
I: 125766 [DL]Closing BLE GATT connection (ConnId 00)
I: 125886 [DL]Current number of connections: 0/1
I: 125891 [DL]BLE GAP connection terminated (reason 0x16)
I: 223865 [FS]Fail-safe timer expired
E: 223869 [SVR]Failsafe timer expired
D: 223872 [IN]SecureSession[0x200036a0]: MarkForEviction Type:1 LSID:28517
I: 223879 [SC]SecureSession[0x200036a0, LSID:28517]: State change 'kActive' --> 'kPendingEviction'
D: 223888 [IN]SecureSession[0x200036a0]: Released - Type:1 LSID:28517
E: 223894 [SVR]Commissioning failed (attempt 1): 32
D: 223899 [IN]SecureSession[0x200036a0]: Allocated Type:1 LSID:28519
D: 223905 [DL]CHIPoBLE advertising set to on
I: 223909 [DIS]Updating services using commissioning mode 1
E: 223915 [DIS]Failed to remove advertised services: 3
D: 223919 [DL]Using Thread extended MAC for hostname.
I: 223924 [DIS]Advertise operational node F8711E6743B48C01-00000000000004BC
E: 223931 [DIS]Failed to advertise operational node: 3
D: 223936 [DL]Using Thread extended MAC for hostname.
I: 223941 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 cp=0
E: 223950 [DIS]Failed to advertise commissionable node: 3
E: 223955 [DIS]Failed to finalize service update: 3
E: 223960 [ZCL]OpCreds: Got FailSafeTimerExpired
E: 223964 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!
D: 223971 [IN]Expiring all sessions for fabric 0x1!!
E: 223976 [FP]Reverting pending fabric data for fabric 0x1
E: 223982 [FP]Warning: metadata not found during delete of fabric 0x1
I: 224045 [FP]Fabric (0x1) deleted.
I: 224048 [ZCL]OpCreds: Fabric index 0x1 was removed
I: 224053 [DIS]Updating services using commissioning mode 1
E: 224058 [DIS]Failed to remove advertised services: 3
D: 224063 [DL]Using Thread extended MAC for hostname.
I: 224068 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 cp=0
E: 224078 [DIS]Failed to advertise commissionable node: 3
E: 224083 [DIS]Failed to finalize service update: 3
I: 224198 [TS]Pending Last Known Good Time: 2023-10-14T01:16:48
I: 224204 [TS]Previous Last Known Good Time: 2023-10-14T01:16:48
I: 224210 [TS]Reverted Last Known Good Time to previous value
E: 224216 [FP]Warning: metadata not found during delete of fabric 0x1
E: 224226 [ZCL]OpCreds: failed to delete fabric at index 1: d8
I: 224232 [NP]Reverting Thread operational dataset
E: 224250 [DL]Long dispatch time: 381 ms, for event type 32784
I: 224256 [FS]Fail-safe cleanly disarmed
I: 224261 [DL]CHIPoBLE advertising started
I: 224265 [ZCL]ThreadDiagnosticsDelegate: OnConnectionStatusChanged
I: 224271 [ZCL]ThreadDiagnosticsDelegate: OnNetworkFaultChanged
D: 224277 [DL]OpenThread State Changed (Flags: 0x11002046)
D: 224282 [DL] Device Role: DISABLED
D: 224286 [DL] Thread Unicast Addresses:
D: 224290 [DL] fd85:5aa5:57b8:1:9157:6632:e212:6813/64 valid
D: 224297 [DL]OpenThread State Changed (Flags: 0x10000000)
I: 224303 [DL]NFC Tag emulation started
I: 225049 [TS]Pending Last Known Good Time: 2023-10-14T01:16:48
I: 225055 [TS]Previous Last Known Good Time: 2023-10-14T01:16:48
I: 225061 [TS]Reverted Last Known Good Time to previous value
I: 225067 [DL]Performing factory reset
I: 227096 [DL]Erasing Thread persistent info...