Description
Reproduction steps
we use siliconlabs 4187C board to test.
firstly, ./scripts/examples/gn_efr32_example.sh ./examples/lock-app/silabs/efr32/ ./out/lock_app BRD4187C, all works normal
second, ./scripts/examples/gn_efr32_example.sh ./examples/lock-app/silabs/efr32/ ./out/lock_app BRD4187C is_debug=false, 4187C will commission fail with SRP update error: timed out waiting on server response, chip tool stop at step 'ThreadNetworkEnable' -> 'FindOperational'
Bug prevalence
everytime
GitHub hash of the SDK that was being used
Platform
efr32
Platform Version(s)
No response
Anything else?
here is the 4187C log.
[00:00:30.009][detail][DL] bleAdv Timeout : Start slow advertissment
[00:00:41.331][info ][DL] Connect Event for handle : 1
[00:00:42.165][info ][DL] Char Write Req, char : 23
[00:00:42.165][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 9)
[00:00:42.166][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:42.166][info ][BLE] local and remote recv window sizes = 5
[00:00:42.166][info ][BLE] selected BTP version 4
[00:00:42.166][info ][BLE] using BTP fragment sizes rx 244 / tx 244.
[00:00:42.262][info ][DL] HandleTXcharCCCDWrite - Config Flags value : 2
[00:00:42.262][info ][DL] CHIPoBLE subscribe received
[00:00:42.263][info ][DL] _OnPlatformEvent kCHIPoBLESubscribe
[00:00:42.263][detail][IN] BLE EndPoint 0x20024200 Connection Complete
[00:00:42.263][info ][DL] _OnPlatformEvent default: event->Type = 32775
[00:00:42.360][info ][DL] Tx Confirmation received
[00:00:42.360][info ][DL] stop soft timer
[00:00:42.360][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:42.362][info ][DL] Char Write Req, char : 23
[00:00:42.362][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 73)
[00:00:42.363][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:42.363][info ][EM] >>> [E:60828r S:0 M:64679249] (U) Msg RX from 0:4CF7DD8C1E1ED14C [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[00:00:42.363][detail][EM] Handling via exchange: 60828r, Delegate: 0x20028560
[00:00:42.363][detail][SC] Received PBKDF param request
[00:00:42.364][detail][SC] Peer assigned session ID 10348
[00:00:42.364][detail][SC] Including MRP parameters in PBKDF param response
[00:00:42.365][info ][EM] <<< [E:60828r S:0 M:76547114] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
[00:00:42.365][info ][IN] (U) Sending msg 76547114 to IP address 'BLE'
[00:00:42.366][detail][SC] Sent PBKDF param response
[00:00:42.555][info ][DL] Tx Confirmation received
[00:00:42.555][info ][DL] stop soft timer
[00:00:42.555][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:42.604][info ][DL] Char Write Req, char : 23
[00:00:42.604][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 97)
[00:00:42.604][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:42.605][info ][EM] >>> [E:60828r S:0 M:64679250] (U) Msg RX from 0:4CF7DD8C1E1ED14C [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
[00:00:42.605][detail][EM] Found matching exchange: 60828r, Delegate: 0x20028560
[00:00:42.605][detail][SC] Received spake2p msg1
[00:00:42.663][info ][EM] <<< [E:60828r S:0 M:76547115] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
[00:00:42.663][info ][IN] (U) Sending msg 76547115 to IP address 'BLE'
[00:00:42.664][detail][SC] Sent spake2p msg2
[00:00:42.896][info ][DL] Tx Confirmation received
[00:00:42.896][info ][DL] stop soft timer
[00:00:42.897][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:42.898][info ][DL] Char Write Req, char : 23
[00:00:42.898][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 64)
[00:00:42.899][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:42.899][info ][EM] >>> [E:60828r S:0 M:64679251] (U) Msg RX from 0:4CF7DD8C1E1ED14C [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
[00:00:42.899][detail][EM] Found matching exchange: 60828r, Delegate: 0x20028560
[00:00:42.899][detail][SC] Received spake2p msg3
[00:00:42.900][detail][SC] Sending status report. Protocol code 0, exchange 60828
[00:00:42.900][info ][EM] <<< [E:60828r S:0 M:76547116] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[00:00:42.900][info ][IN] (U) Sending msg 76547116 to IP address 'BLE'
[00:00:42.904][info ][SC] SecureSession[0x20025df8]: Moving from state 'kEstablishing' --> 'kActive'
[00:00:42.904][detail][IN] SecureSession[0x20025df8]: Activated - Type:1 LSID:7505
[00:00:42.904][detail][IN] New secure session activated for device <FFFFFFFB00000000, 0>, LSID:7505 PSID:10348!
[00:00:42.904][info ][SVR] Commissioning completed session establishment step
[00:00:42.905][info ][DIS] Updating services using commissioning mode 0
[00:00:42.905][error ][DIS] Failed to remove advertised services: 3
[00:00:42.905][error ][DIS] Failed to finalize service update: 3
[00:00:42.905][info ][SVR] Device completed Rendezvous process
[00:00:43.042][info ][DL] Tx Confirmation received
[00:00:43.042][info ][DL] stop soft timer
[00:00:43.042][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:43.141][info ][DL] Char Write Req, char : 23
[00:00:43.141][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 128)
[00:00:43.141][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:43.142][info ][EM] >>> [E:60829r S:7505 M:148457245] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
[00:00:43.142][detail][EM] Handling via exchange: 60829r, Delegate: 0x20021bc4
[00:00:43.142][detail][IM] Received Read request
[00:00:43.145][detail][DMG] IM RH moving to [GeneratingReports]
[00:00:43.145][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu
[00:00:43.145][detail][DMG] RE:Run Cluster 31, Attribute 3 is dirty
[00:00:43.145][detail][DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1)
[00:00:43.145][detail][DMG] RE:Run Cluster 28, Attribute 4 is dirty
[00:00:43.145][detail][DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0)
[00:00:43.146][detail][DMG] RE:Run Cluster 28, Attribute 2 is dirty
[00:00:43.146][detail][DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0)
[00:00:43.146][detail][DMG] RE:Run Cluster 30, Attribute 3 is dirty
[00:00:43.146][detail][DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0)
[00:00:43.146][detail][DMG] RE:Run Cluster 30, Attribute 2 is dirty
[00:00:43.147][detail][DM[00:00:43.334][info ][DL] Tx Confirmation received
[00:00:43.334][info ][DL] stop soft timer
[00:00:43.335][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:43.432][info ][DL] Tx Confirmation received
[00:00:43.432][info ][DL] stop soft timer
[00:00:43.433][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:43.434][info ][DL] Char Write Req, char : 23
[00:00:43.434][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 70)
[00:00:43.435][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:43.436][info ][EM] >>> [E:60830r S:7505 M:148457246] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:43.436][detail][EM] Handling via exchange: 60830r, Delegate: 0x20021bc4
[00:00:43.436][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
[00:00:43.437][info ][FS] GeneralCommissioning: Received ArmFailSafe (60s)
[00:00:43.437][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 92426f5a
[00:00:43.437][info ][ZCL] Cluster callback: 0x0000_0030
[00:00:43.437][detail][DMG] Command handler moving to [ Preparing]
[00:00:43.437][detail][DMG] Command handler moving to [AddingComm]
[00:00:43.437][detail][DMG] Command handler moving to [AddedComma]
[00:00:43.438][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:43.438][info ][EM] <<< [E:60830r S:7505 M:21450997] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:43.439][info ][IN] (S) Sen[00:00:43.579][info ][DL] Tx Confirmation received
[00:00:43.579][info ][DL] stop soft timer
[00:00:43.579][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:43.627][info ][DL] Char Write Req, char : 23
[00:00:43.627][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 75)
[00:00:43.627][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:43.628][info ][EM] >>> [E:60831r S:7505 M:148457247] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:43.628][detail][EM] Handling via exchange: 60831r, Delegate: 0x20021bc4
[00:00:43.629][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002
[00:00:43.629][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 92426f5b
[00:00:43.630][info ][ZCL] Cluster callback: 0x0000_0030
[00:00:43.630][detail][DMG] Command handler moving to [ Preparing]
[00:00:43.630][detail][DMG] Command handler moving to [AddingComm]
[00:00:43.630][detail][DMG] Command handler moving to [AddedComma]
[00:00:43.630][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:43.631][info ][EM] <<< [E:60831r S:7505 M:21450998] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:43.631][info ][IN] (S) Sending msg 21450998 on secure session with LSID: 7505
[00:00:43.632][detail][DMG] Command handler moving to [CommandSen]
[00:00:43.632][detail][DMG] Command handler moving to [AwaitingDe]
[00:00:43.725][info ][DL] Tx Confirmation received
[00:00:43.725][info ][DL] stop soft timer
[00:00:43.725][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:43.727][info ][DL] Char Write Req, char : 23
[00:00:43.727][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 67)
[00:00:43.727][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:43.728][info ][EM] >>> [E:60832r S:7505 M:148457248] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:43.728][detail][EM] Handling via exchange: 60832r, Delegate: 0x20021bc4
[00:00:43.729][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
[00:00:43.729][info ][ZCL] OpCreds: Certificate Chain request received for PAI
[00:00:43.729][detail][DMG] Command handler moving to [ Preparing]
[00:00:43.729][detail][DMG] Command handler moving to [AddingComm]
[00:00:43.730][detail][DMG] Command handler moving to [AddedComma]
[00:00:43.730][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:43.731][info ][EM] <<< [E:60832r S:7505 M:21450999] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:43.731][info ][IN] (S) Sending msg 21450999 on secure session with LSID: 7505
[00:00:43.731][detail][DMG] Command handler moving to [CommandSen]
[00:00:43.732][detail][00:00:43.968][info ][DL] Tx Confirmation received
[00:00:43.968][info ][DL] stop soft timer
[00:00:43.969][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:44.261][info ][DL] Tx Confirmation received
[00:00:44.261][info ][DL] stop soft timer
[00:00:44.261][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:44.359][info ][DL] Tx Confirmation received
[00:00:44.359][info ][DL] stop soft timer
[00:00:44.359][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:44.361][info ][DL] Char Write Req, char : 23
[00:00:44.361][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 67)
[00:00:44.361][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:44.362][info ][EM] >>> [E:60833r S:7505 M:148457249] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:44.362][detail][EM] Handling via exchange: 60833r, Delegate: 0x20021bc4
[00:00:44.363][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
[00:00:44.363][info ][ZCL] OpCreds: Certificate Chain request received for DAC
[00:00:44.363][detail][DMG] Command handler moving to [ Preparing]
[00:00:44.363][detail][DMG] Command handler moving to [AddingComm]
[00:00:44.363][detail][DMG] Command handler moving to [AddedComma]
[00:00:44.364][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:44.365][info ][EM] <<< [E:60833r S:7505 M:21451000] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:44.365][info ][IN] (S) Sending msg 21451000 on secure session with LSID: 7505
[00:00:44.365][detail][DMG] Command handler moving to [CommandSen]
[00:00:44.365][detail][00:00:44.700][info ][DL] Tx Confirmation received
[00:00:44.700][info ][DL] stop soft timer
[00:00:44.701][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:44.944][info ][DL] Tx Confirmation received
[00:00:44.944][info ][DL] stop soft timer
[00:00:44.944][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:45.089][info ][DL] Tx Confirmation received
[00:00:45.089][info ][DL] stop soft timer
[00:00:45.090][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:45.187][info ][DL] Char Write Req, char : 23
[00:00:45.188][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 99)
[00:00:45.188][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:45.189][info ][EM] >>> [E:60834r S:7505 M:148457250] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:45.189][detail][EM] Handling via exchange: 60834r, Delegate: 0x20021bc4
[00:00:45.190][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000
[00:00:45.190][info ][ZCL] OpCreds: Received an AttestationRequest command
[00:00:45.196][info ][ZCL] OpCreds: AttestationRequest successful.
[00:00:45.196][detail][DMG] Command handler moving to [ Preparing]
[00:00:45.196][detail][DMG] Command handler moving to [AddingComm]
[00:00:45.196][detail][DMG] Command handler moving to [AddedComma]
[00:00:45.197][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:45.197][info ][EM] <<< [E:60834r S:7505 M:21451001] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:45.198][info ][IN] (S) Sending msg 21451001 on secure session with LSID: 7505
[00:00:45.198][detail][DMG] Command handler moving to [CommandSen]
[00:00:45.198][detail][DMG] Command handler moving to [AwaitingDe]
[00:00:45.431][info ][DL] Tx Confirmation received
[00:00:45.431][info ][DL] stop soft timer
[00:00:45.431][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:45.625][info ][DL] Tx Confirmation received
[00:00:45.626][info ][DL] stop soft timer
[00:00:45.626][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:45.821][info ][DL] Tx Confirmation received
[00:00:45.821][info ][DL] stop soft timer
[00:00:45.822][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:45.918][info ][DL] Char Write Req, char : 23
[00:00:45.918][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 99)
[00:00:45.919][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:45.919][info ][EM] >>> [E:60835r S:7505 M:148457251] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:45.920][detail][EM] Handling via exchange: 60835r, Delegate: 0x20021bc4
[00:00:45.920][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004
[00:00:45.920][info ][ZCL] OpCreds: Received a CSRRequest command
[00:00:45.921][detail][ZCL] OpCreds: Finding fabric with fabricIndex 0x0
[00:00:45.921][error ][CR] WARNING: PSA key recycled: 0 / 17408
[00:00:45.935][info ][ZCL] OpCreds: AllocatePendingOperationalKey succeeded
[00:00:45.941][info ][ZCL] OpCreds: CSRRequest successful.
[00:00:45.942][detail][DMG] Command handler moving to [ Preparing]
[00:00:45.942][detail][DMG] Command handler moving to [AddingComm]
[00:00:45.942][detail][DMG] Command handler moving to [AddedComma]
[00:00:45.942][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:45.943][info ][EM] <<< [E:60835r S:7505 M:21451002] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:45.943][info ][IN] (S) Sending msg 21451002 on secure session with LSID: 7505
[00:00:45.944][detail][DMG] Command handler moving to [CommandSen]
[00:00:45.944][detail][DMG] Command handler moving to [AwaitingDe]
[00:00:46.114][info ][DL] Tx Confirmation received
[00:00:46.114][info ][DL] stop soft timer
[00:00:46.114][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:46.259][info ][DL] Tx Confirmation received
[00:00:46.259][info ][DL] stop soft timer
[00:00:46.260][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:46.359][info ][DL] Char Write Req, char : 23
[00:00:46.360][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 244)
[00:00:46.360][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:46.457][info ][DL] Char Write Req, char : 23
[00:00:46.457][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 56)
[00:00:46.457][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:46.458][info ][EM] >>> [E:60836r S:7505 M:148457252] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:46.458][detail][EM] Handling via exchange: 60836r, Delegate: 0x20021bc4
[00:00:46.458][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B
[00:00:46.458][info ][ZCL] OpCreds: Received an AddTrustedRootCertificate command
[00:00:46.465][info ][ZCL] OpCreds: AddTrustedRootCertificate successful.
[00:00:46.465][detail][DMG] Command handler moving to [ Preparing]
[00:00:46.466][detail][DMG] Command handler moving to [AddingComm]
[00:00:46.466][detail][DMG] Command handler moving to [AddedComma]
[00:00:46.466][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:46.467][info ][EM] <<< [E:60836r S:7505 M:21451003] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:46.467][info ][IN] (S) Sending msg 21451003 on secure session with LSID: 7505
[00:00:46.467][detail][DMG] Command handler moving to [CommandSen]
[00:00:46.468][detail][DMG] Command handler moving to [AwaitingDe]
[00:00:46.552][info ][DL] Tx Confirmation received
[00:00:46.552][info ][DL] stop soft timer
[00:00:46.552][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:46.699][info ][DL] Char Write Req, char : 23
[00:00:46.700][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 244)
[00:00:46.700][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:46.894][info ][DL] Char Write Req, char : 23
[00:00:46.894][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 244)
[00:00:46.895][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:46.993][info ][DL] Char Write Req, char : 23
[00:00:46.993][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 87)
[00:00:46.994][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:46.995][info ][EM] >>> [E:60837r S:7505 M:148457253] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:46.995][detail][EM] Handling via exchange: 60837r, Delegate: 0x20021bc4
[00:00:46.996][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006
[00:00:46.996][info ][ZCL] OpCreds: Received an AddNOC command
[00:00:46.997][info ][FP] Validating NOC chain
[00:00:47.013][info ][FP] NOC chain validation successful
[00:00:47.013][info ][FP] Added new fabric at index: 0x1
[00:00:47.013][info ][FP] Assigned compressed fabric ID: 0x098C58BDA04B3592, node ID: 0x0000000000000002
[00:00:47.014][info ][TS] Last Known Good Time: 2023-08-04T14:19:53
[00:00:47.014][info ][TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
[00:00:47.014][info ][TS] Retaining current Last Known Good Time
[00:00:47.014][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 4ddda552
[00:00:47.014][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 4ddda553
[00:00:47.025][detail][EVL] LogEvent event number: 0x0000000000000003 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000000B7B0
[00:00:47.025][info ][ZCL] OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669
[00:00:47.025][detail][DL] Using Thread extended MAC for hostname.
[00:00:47.025][info ][DIS] Advertise operational node 098C58BDA04B3592-0000000000000002
[00:00:47.025][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 4ddda554
[00:00:47.026][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 4ddda555
[00:00:47.026][detail][DMG] Command handler moving to [ Preparing]
[00:00:47.026][detail][DMG] Command handler moving to [AddingComm]
[00:00:47.026][detail][DMG] Command handler moving to [AddedComma]
[00:00:47.026][info ][ZCL] OpCreds: successfully created fabric index 0x1 via AddNOC
[00:00:47.026][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:47.027][info ][EM] <<< [E:60837r S:7505 M:21451004] (S) Msg TX to 1:FFFFFFFB00000000 [3592] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:47.027][info ][IN] (S) Sending msg 21451004 on secure session with LSID: 7505
[00:00:47.028][detail][DMG] Command handler moving to [CommandSen]
[00:00:47.[00:00:47.137][info ][DL] Tx Confirmation received
[00:00:47.137][info ][DL] stop soft timer
[00:00:47.137][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:47.237][info ][DL] Char Write Req, char : 23
[00:00:47.237][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 175)
[00:00:47.238][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:47.238][info ][EM] >>> [E:60838r S:7505 M:148457254] (S) Msg RX from 1:FFFFFFFB00000000 [3592] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:47.239][detail][EM] Handling via exchange: 60838r, Delegate: 0x20021bc4
[00:00:47.239][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003
[00:00:47.240][detail][DMG] Command handler moving to [ Preparing]
[00:00:47.240][detail][DMG] Command handler moving to [AddingComm]
[00:00:47.241][detail][DMG] Command handler moving to [AddedComma]
[00:00:47.241][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 92426f5c
[00:00:47.241][info ][ZCL] Cluster callback: 0x0000_0030
[00:00:47.241][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:47.242][info ][EM] <<< [E:60838r S:7505 M:21451005] (S) Msg TX to 1:FFFFFFFB00000000 [3592] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:47.242][info ][IN] (S) Sending msg 21451005 on secure session with LSID: 7505
[00:00:47.243][detail][DMG] Command handler moving to [CommandSen]
[00:00:47.243][detail][DMG] Command handler moving to [AwaitingDe]
[00:00:47.332][info ][DL] Tx Confirmation received
[00:00:47.333][info ][DL] stop soft timer
[00:00:47.333][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:47.381][info ][DL] Char Write Req, char : 23
[00:00:47.382][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 70)
[00:00:47.382][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:47.383][info ][EM] >>> [E:60839r S:7505 M:148457255] (S) Msg RX from 1:FFFFFFFB00000000 [3592] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:47.383][detail][EM] Handling via exchange: 60839r, Delegate: 0x20021bc4
[00:00:47.383][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
[00:00:47.384][info ][FS] GeneralCommissioning: Received ArmFailSafe (73s)
[00:00:47.384][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 92426f5d
[00:00:47.384][info ][ZCL] Cluster callback: 0x0000_0030
[00:00:47.384][detail][DMG] Command handler moving to [ Preparing]
[00:00:47.384][detail][DMG] Command handler moving to [AddingComm]
[00:00:47.384][detail][DMG] Command handler moving to [AddedComma]
[00:00:47.385][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:47.385][info ][EM] <<< [E:60839r S:7505 M:21451006] (S) Msg TX to 1:FFFFFFFB00000000 [3592] --- Type 00[00:00:47.386][detail][DMG] Command handler moving to [CommandSen]
[00:00:47.386][detail][DMG] Command handler moving to [AwaitingDe]
[00:00:47.478][info ][DL] Tx Confirmation received
[00:00:47.478][info ][DL] stop soft timer
[00:00:47.479][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:47.527][info ][DL] Char Write Req, char : 23
[00:00:47.527][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 78)
[00:00:47.528][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:47.529][info ][EM] >>> [E:60840r S:7505 M:148457256] (S) Msg RX from 1:FFFFFFFB00000000 [3592] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:00:47.529][detail][EM] Handling via exchange: 60840r, Delegate: 0x20021bc4
[00:00:47.529][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006
[00:00:47.538][detail][DMG] Decreasing reference count for CommandHandler, remaining 1
[00:00:47.538][info ][DL] _OnPlatformEvent default: event->Type = 32772
[00:00:47.539][info ][DL] _OnPlatformEvent default: event->Type = 32777
[00:00:47.539][detail][DL] OpenThread State Changed (Flags: 0x111fd01d)
[00:00:47.539][detail][DL] Device Role: DETACHED
[00:00:47.539][detail][DL] Network Name: OpenThreadDemo
[00:00:47.539][detail][DL] PAN Id: 0x1234
[00:00:47.539][detail][DL] Extended PAN Id: 0x1111111122222222
[00:00:47.539][detail][DL] Channel: 15
[00:00:47.540][detail][DL] Mesh Prefix: fdab:9082:1e50:22b6:0:0:0:0/64
[00:00:47.540][detail][DL] Thread Unicast Addresses:
[00:00:47.540][detail][DL] fdab:9082:1e50:22b6:1114:caa0:23f2:5502/64 valid
[00:00:47.540][detail][DL] fe80:0:0:0:9c57:dd4d:2af8:96ec/64 valid preferred
[00:00:48.804][info ][DL] SRP Client was started, detected server: fdab:9082:1e50:22b6:9d3e:7642:dcb2:f696
[00:00:48.804][info ][DL] _OnPlatformEvent default: event->Type = 32777
[00:00:48.804][detail][DL] OpenThread State Changed (Flags: 0x200012a4)
[00:00:48.804][detail][DL] Device Role: CHILD
[00:00:48.804][detail][DL] Partition Id: 0x1CBDA707
[00:00:48.805][info ][DL] _OnPlatformEvent default: event->Type = 32777
[00:00:48.805][detail][DL] Thread Attached updating Multicast address
[00:00:48.805][info ][SVR] Joining Multicast groups
[00:00:48.806][detail][DL] OpenThread State Changed (Flags: 0x00000001)
[00:00:48.806][detail][DL] Thread Unicast Addresses:
[00:00:48.806][detail][DL] fd11:22:0:0:e146:d6a2:4b55:7dc3/64 valid preferred
[00:00:48.806][detail][DL] fdab:9082:1e50:22b6:0:ff:fe00:b001/64 valid rloc
[00:00:48.807][detail][DL] fdab:9082:1e50:22b6:1114:caa0:23f2:5502/64 valid
[00:00:48.807][detail][DL] fe80:0:0:0:9c57:dd4d:2af8:96ec/64 valid preferred
[00:00:48.808][info ][DL] _OnPlatformEvent default: event->Type = 32769
[00:00:48.808][silabs[00:00:48.809][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:00:48.809][info ][EM] <<< [E:60840r S:7505 M:21451007] (S) Msg TX to 1:FFFFFFFB00000000 [3592] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:00:48.810][info ][IN] (S) Sending msg 21451007 on secure session with LSID: 7505
[00:00:48.810][detail][DMG] Command handler moving to [CommandSen]
[00:00:48.810][detail][DMG] Command handler moving to [AwaitingDe][00:00:48.892][info ][DL] Tx Confirmation received
[00:00:48.892][info ][DL] stop soft timer
[00:00:48.893][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:50.802][error ][DL] SRP update error: timed out waiting on server response
[00:00:51.476][info ][DL] Char Write Req, char : 23
[00:00:51.476][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:00:51.476][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:51.809][info ][SWU] Stopping the watchdog timer
[00:00:51.809][info ][SWU] Starting the periodic query timer, timeout: 86400 seconds
[00:00:51.809][detail][DMG] Endpoint 0, Cluster 0x0000_002A update version to c171489a
[00:00:51.810][info ][ZCL] Cluster callback: 0x0000_002A
[00:00:51.810][detail][DMG] Endpoint 0, Cluster 0x0000_002A update version to c171489b
[00:00:51.810][info ][ZCL] Cluster callback: 0x0000_002A
[00:00:54.206][info ][DL] Tx Confirmation received
[00:00:54.206][info ][DL] stop soft timer
[00:00:54.207][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:54.467][error ][DL] SRP update error: timed out waiting on server response
[00:00:56.692][info ][DL] Char Write Req, char : 23
[00:00:56.692][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:00:56.692][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:00:59.324][info ][DL] Tx Confirmation received
[00:00:59.324][info ][DL] stop soft timer
[00:00:59.325][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:00:59.697][error ][DL] SRP update error: timed out waiting on server response
[00:01:01.957][info ][DL] Char Write Req, char : 23
[00:01:01.957][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:01.957][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:04.588][info ][DL] Tx Confirmation received
[00:01:04.588][info ][DL] stop soft timer
[00:01:04.589][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:07.221][info ][DL] Char Write Req, char : 23
[00:01:07.221][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:07.221][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:08.859][error ][DL] SRP update error: timed out waiting on server response
[00:01:09.853][info ][DL] Tx Confirmation received
[00:01:09.853][info ][DL] stop soft timer
[00:01:09.854][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:12.437][info ][DL] Char Write Req, char : 23
[00:01:12.438][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:12.438][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:15.069][info ][DL] Tx Confirmation received
[00:01:15.070][info ][DL] stop soft timer
[00:01:15.070][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:17.702][info ][DL] Char Write Req, char : 23
[00:01:17.702][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:17.703][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:20.334][info ][DL] Tx Confirmation received
[00:01:20.334][info ][DL] stop soft timer
[00:01:20.334][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:23.016][info ][DL] Char Write Req, char : 23
[00:01:23.016][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:23.016][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:24.582][error ][DL] SRP update error: timed out waiting on server response
[00:01:25.648][info ][DL] Tx Confirmation received
[00:01:25.648][info ][DL] stop soft timer
[00:01:25.648][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:28.329][info ][DL] Char Write Req, char : 23
[00:01:28.329][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:28.330][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:30.961][info ][DL] Tx Confirmation received
[00:01:30.961][info ][DL] stop soft timer
[00:01:30.961][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:33.593][info ][DL] Char Write Req, char : 23
[00:01:33.593][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:33.594][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:33.887][info ][DL] Char Write Req, char : 23
[00:01:33.887][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 69)
[00:01:33.888][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:33.888][info ][EM] >>> [E:60841r S:7505 M:148457257] (S) Msg RX from 1:FFFFFFFB00000000 [3592] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:01:33.889][detail][EM] Handling via exchange: 60841r, Delegate: 0x20021bc4
[00:01:33.889][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
[00:01:33.889][info ][FS] GeneralCommissioning: Received ArmFailSafe (120s)
[00:01:33.889][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 92426f5f
[00:01:33.890][info ][ZCL] Cluster callback: 0x0000_0030
[00:01:33.890][detail][DMG] Command handler moving to [ Preparing]
[00:01:33.890][detail][DMG] Command handler moving to [AddingComm]
[00:01:33.890][detail][DMG] Command handler moving to [AddedComma]
[00:01:33.890][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:01:33.891][info ][EM] <<< [E:60841r S:7505 M:21451008] (S) Msg TX to 1:FFFFFFFB00000000 [3592] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:01:33.891][info ][IN] (S) Sending msg 21451008 on secure session with LSID: 7505
[00:01:33.892][detail][DMG] Command handler moving to [CommandSen]
[00:01:33.892][detail][DMG] Command handler moving to [AwaitingDe]
[00:01:33.983][info ][DL] Tx Confirmation received
[00:01:33.983][info ][DL] stop soft timer
[00:01:33.984][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:36.567][info ][DL] Char Write Req, char : 23
[00:01:36.567][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:36.567][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:39.199][info ][DL] Tx Confirmation received
[00:01:39.199][info ][DL] stop soft timer
[00:01:39.200][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:41.832][info ][DL] Char Write Req, char : 23
[00:01:41.832][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:41.832][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:44.463][info ][DL] Tx Confirmation received
[00:01:44.463][info ][DL] stop soft timer
[00:01:44.464][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:47.145][info ][DL] Char Write Req, char : 23
[00:01:47.145][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:47.145][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:49.777][info ][DL] Tx Confirmation received
[00:01:49.777][info ][DL] stop soft timer
[00:01:49.777][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:50.211][error ][DL] SRP update error: timed out waiting on server response
[00:01:52.312][info ][DL] Char Write Req, char : 23
[00:01:52.312][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:52.312][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:01:54.944][info ][DL] Tx Confirmation received
[00:01:54.944][info ][DL] stop soft timer
[00:01:54.945][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:01:57.479][info ][DL] Char Write Req, char : 23
[00:01:57.479][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:01:57.479][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:00.111][info ][DL] Tx Confirmation received
[00:02:00.111][info ][DL] stop soft timer
[00:02:00.112][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:02.743][info ][DL] Char Write Req, char : 23
[00:02:02.744][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:02:02.744][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:05.375][info ][DL] Tx Confirmation received
[00:02:05.375][info ][DL] stop soft timer
[00:02:05.375][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:08.105][info ][DL] Char Write Req, char : 23
[00:02:08.105][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:02:08.106][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:10.738][info ][DL] Tx Confirmation received
[00:02:10.738][info ][DL] stop soft timer
[00:02:10.738][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:13.418][info ][DL] Char Write Req, char : 23
[00:02:13.418][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:02:13.419][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:16.050][info ][DL] Tx Confirmation received
[00:02:16.050][info ][DL] stop soft timer
[00:02:16.051][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:18.683][info ][DL] Char Write Req, char : 23
[00:02:18.683][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:02:18.683][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:18.879][info ][DL] Char Write Req, char : 23
[00:02:18.879][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 69)
[00:02:18.880][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:18.880][info ][EM] >>> [E:60842r S:7505 M:148457258] (S) Msg RX from 1:FFFFFFFB00000000 [3592] --- Type 0001:08 (IM:InvokeCommandRequest)
[00:02:18.881][detail][EM] Handling via exchange: 60842r, Delegate: 0x20021bc4
[00:02:18.881][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
[00:02:18.881][info ][FS] GeneralCommissioning: Received ArmFailSafe (120s)
[00:02:18.882][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 92426f60
[00:02:18.882][info ][ZCL] Cluster callback: 0x0000_0030
[00:02:18.882][detail][DMG] Command handler moving to [ Preparing]
[00:02:18.882][detail][DMG] Command handler moving to [AddingComm]
[00:02:18.882][detail][DMG] Command handler moving to [AddedComma]
[00:02:18.882][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
[00:02:18.883][info ][EM] <<< [E:60842r S:7505 M:21451009] (S) Msg TX to 1:FFFFFFFB00000000 [3592] --- Type 0001:09 (IM:InvokeCommandResponse)
[00:02:18.883][info ][IN] (S) Se[00:02:18.975][info ][DL] Tx Confirmation received
[00:02:18.975][info ][DL] stop soft timer
[00:02:18.976][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:21.559][info ][DL] Char Write Req, char : 23
[00:02:21.559][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:02:21.560][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:24.191][info ][DL] Tx Confirmation received
[00:02:24.192][info ][DL] stop soft timer
[00:02:24.192][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:26.824][info ][DL] Char Write Req, char : 23
[00:02:26.824][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:02:26.825][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:29.456][info ][DL] Tx Confirmation received
[00:02:29.456][info ][DL] stop soft timer
[00:02:29.457][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:32.137][info ][DL] Char Write Req, char : 23
[00:02:32.138][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:02:32.138][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:33.768][error ][DL] SRP update error: timed out waiting on server response
[00:02:34.770][info ][DL] Tx Confirmation received
[00:02:34.770][info ][DL] stop soft timer
[00:02:34.770][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:37.451][info ][DL] Char Write Req, char : 23
[00:02:37.451][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
[00:02:37.451][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
[00:02:40.083][info ][DL] Tx Confirmation received
[00:02:40.083][info ][DL] stop soft timer
[00:02:40.083][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
[00:02:40.571][info ][DL] HandleTXcharCCCDWrite - Config Flags value : 0
[00:02:40.571][info ][DL] CHIPoBLE unsubscribe received
[00:02:40.571][info ][DL] _OnPlatformEvent kCHIPoBLEUnsubscribe
[00:02:40.571][detail][IN] Clearing BLE pending packets.
[00:02:40.571][info ][BLE] Releasing end point's BLE connection back to application.
[00:02:42.813][info ][DL] Disconnect Event for handle : 1
[00:02:42.813][info ][DL] BLE GATT connection closed (con 1, reason 4115)
[00:02:42.813][info ][DL] _OnPlatformEvent kCHIPoBLEConnectionError
[00:03:47.658][error ][DL] SRP update error: timed out waiting on server response
[00:04:18.881][info ][FS] Fail-safe timer expired
[00:04:18.881][info ][DL] _OnPlatformEvent default: event->Type = 32782
[00:04:18.881][error ][SVR] Failsafe timer expired
[00:04:18.881][detail][IN] SecureSession[0x20025df8]: MarkForEviction Type:1 LSID:7505
[00:04:18.881][info ][SC] SecureSession[0x20025df8]: Moving from state 'kActive' --> 'kPendingEviction'
[00:04:18.881][detail][IN] SecureSession[0x20025df8]: Released - Type:1 LSID:7505
[00:04:18.881][error ][SVR] Commissioning failed (attempt 1): 32
[00:04:18.882][detail][IN] SecureSession[0x20025df8]: Allocated Type:1 LSID:7507
[00:04:18.882][detail][SC] Assigned local session key ID 7507
[00:04:18.882][detail][SC] Waiting for PBKDF param request
[00:04:18.882][info ][DIS] Updating services using commissioning mode 1
[00:04:18.883][error ][DIS] Failed to remove advertised services: 3
[00:04:18.883][detail][DL] Using Thread extended MAC for hostname.
[00:04:18.883][info ][DIS] Advertise operational node 098C58BDA04B3592-0000000000000002
[00:04:18.883][error ][DIS] Failed to advertise[00:04:18.885][error ][FP] Warning: metadata not found during delete of fabric 0x1
[00:04:18.888][info ][FP] Fabric (0x1) deleted.
[00:04:18.888][info ][ZCL] UserLabel: Last Fabric index 0x1 was removed
[00:04:18.889][info ][ZCL] OpCreds: Fabric index 0x1 was removed
[00:04:18.889][info ][DIS] Updating services using commissioning mode 1
[00:04:18.889][error ][DIS] Failed to remove advertised services: 3
[00:04:18.889][detail][DL] Using Thread extended MAC for hostname.
[00:04:18.889][info ][DIS] Advertise commission parameter vendorID=65521 productID=32774 discriminator=3840/15 cm=1
[00:04:18.890][error ][DIS] Failed to advertise commissionable node: 3
[00:04:18.890][error ][DIS] Failed to finalize service update: 3
[00:04:18.890][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 4ddda556
[00:04:18.891][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 4ddda557
[00:04:18.891][info ][ZCL] [OnFabricRemoved] Handling a fabric removal from the door lock server [endpointId=1,fabricIndex=1]
[00:04:18.891][info ][ZCL] Door Lock App: LockManager::GetUs[00:04:18.892][detail][ZCL] Found unoccupied user [endpoint=1]
[00:04:18.892][info ][ZCL] Door Lock App: LockManager::GetUser [endpoint=1,userIndex=6]
[00:04:18.892][detail][ZCL] Found unoccupied user [endpoint=1]
[00:04:18.893][info ][ZCL] Door Lock App: LockManager::GetUser [endpoint=1,userIndex=7]
[00:04:18.893][detail][ZCL] Found unoccupied user [endpoint=1]
[00:04:18.893][info ][ZCL] Do[00:04:18.897][detail][ZCL] Found unoccupied credential
[00:04:18.897][info ][ZCL] Lock App: LockManager::GetCredential [credentialType=1], credentialIndex=1
[00:04:18.897][detail][ZCL] CredentialStatus: 0, CredentialIndex: 1
[00:04:18.897][detail][ZCL] Found unoccupied credential
[00:04:18.898][info ][ZCL] Lock App: LockManager::GetCredential [credentialType=1], credentialIndex=2
[00:04:18.898][detail][ZCL] CredentialStatus: 0, CredentialIndex: 2
[00:04:18.898][detail][ZCL] Found unoccupied credential
[00:04:18.898][info ][ZCL] Lock App: LockManager::GetCredential [credentialType=1], credentialIndex=3
[00:04:18.898][detail][ZCL] CredentialStatus: 0, CredentialIndex: 3
[00:04:18.898][detail][ZCL] Found unoccupied credential
[00:04:18.898][info [00:04:18.920][info ][TS] Pending Last Known Good Time: 2023-08-04T14:19:53
[00:04:18.921][info ][TS] Previous Last Known Good Time: 2023-08-04T14:19:53
[00:04:18.921][info ][TS] Reverted Last Known Good Time to previous value
[00:04:18.921][detail][EVL] LogEvent event number: 0x0000000000000005 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x000000000003F369
[00:04:18.921][detail][DMG] All ReadHandler-s are clean, clear GlobalDirtySet
[00:04:18.922][error ][FP] Warning: metadata not found during delete of fabric 0x1
[00:04:18.923][error ][ZCL] OpCreds: failed to delete fabric at index 1: d8
[00:04:18.923][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 92426f61
[00:04:18.923][info ][ZCL] Cluster callback: 0x0000_0030
[00:04:18.923][detail][ZCL] Failsafe timeout, tell platform driver to revert network credentials.
[00:04:18.924][info ][NP] Reverting Thread operational dataset
[00:04:18.926][info ][FS] Fail-safe cleanly disarmed
[00:04:18.926][detail][DL] Start BLE advertissement
[00:04:18.928][info ][DL] _OnPlatformEvent default: event->Type = 32772
[00:04:18.928][info ][DL] _OnPlatformEvent default: event->Type = 32777
[00:04:18.928][detail][DL] OpenThread State Changed (Flags: 0x11002046)
[00:04:18.928][detail][DL] Device Role: DISABLED
[00:04:18.929][detail][DL] Thread Unicast Addresses:
[00:04:18.929][detail][DL] fd11:22:0:0:e146:d6a2:4b55:7dc3/64 valid preferred
[00:04:18.929][info ][DL] _OnPlatformEvent default: event->Type = 32769
[00:04:48.928][detail][DL] bleAdv Timeout : Start slow advertissment
[00:15:00.000][info ][SVR] Closing pairing window
[00:15:00.000][detail][IN] SecureSession[0x20025df8]: Released - Type:1 LSID:7507
[00:15:00.000][info ][DIS] Updating services using commissioning mode 0
[00:15:00.000][error ][DIS] Failed to remove advertised services: 3
[00:15:00.000][error ][DIS] Failed to finalize service update: 3