UniqueID attribute of the Basic Information Cluster is empty

[chiba]

Hi,

In some cases, the UniqueID attribute of the Basic Information Cluster is empty (no value is set).
CONFIG_CHIP_LAST_FABRIC_REMOVED_ERASE_ONLY is enabled.

Environment:
- Board: nRF5340 DK
- SDK: NCS v2.9.2
- Sample: Door Lock
- prj.conf: CONFIG_CHIP_LAST_FABRIC_REMOVED_ERASE_ONLY=y

Steps to Reproduce:
1. Perform commissioning.
2. Perform decommissioning (remove the fabric).
3. Perform re-commissioning.
4. Read the UniqueID attribute from the Basic Information Cluster.

$ chip-tool basicinformation read unique-id 2 0

[1790241304.713] [467304:467304] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1790241304.715] [467304:467304] [DL] ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs, IGNORING.
[1790241304.720] [467304:467304] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1790241304.720] [467304:467304] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1790241304.720] [467304:467304] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1790241304.726] [467304:467304] [DL] Wrote settings to /tmp/chip_counters.ini
[1790241304.726] [467304:467304] [DL] NVS set: chip-counters/reboot-count = 3 (0x3)
[1790241304.727] [467304:467304] [DL] Got Ethernet interface: eth0
[1790241304.727] [467304:467304] [DL] Found the primary Ethernet interface:eth0
[1790241304.728] [467304:467304] [DL] Got WiFi interface: wlan0
[1790241304.731] [467304:467304] [DL] Found the primary WiFi interface:wlan0
[1790241304.731] [467304:467304] [PAF] WiFiPAF: WiFiPAFLayer::Init()
[1790241304.731] [467304:467304] [IN] UDP::Init bind&listen port=0
[1790241304.731] [467304:467304] [IN] UDP::Init bound to port=51880
[1790241304.731] [467304:467304] [IN] BLEBase::Init - setting/overriding transport
[1790241304.731] [467304:467304] [IN] WiFiPAFBase::Init - setting/overriding transport
[1790241304.731] [467304:467304] [IN] TransportMgr initialized
[1790241304.731] [467304:467304] [FP] Initializing FabricTable from persistent storage
[1790241304.732] [467304:467304] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1790241304.734] [467304:467304] [FP] Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x4FC239DB662DA104, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1790241304.737] [467304:467304] [DMG] Ember attribute persistence requires setting up
[1790241304.737] [467304:467304] [ZCL] Using ZAP configuration...
[1790241304.743] [467304:467304] [DL] Avahi client registered
[1790241304.743] [467304:467304] [CTL] System State Initialized...
[1790241304.743] [467304:467304] [CTL] Setting attestation nonce to random value
[1790241304.743] [467304:467304] [CTL] Setting CSR nonce to random value
[1790241304.743] [467304:467304] [IN] UDP::Init bind&listen port=5550
[1790241304.743] [467304:467304] [IN] UDP::Init bound to port=5550
[1790241304.743] [467304:467304] [IN] TransportMgr initialized
[1790241304.744] [467304:467306] [DL] CHIP task running
[1790241304.744] [467304:467306] [DL] HandlePlatformSpecificBLEEvent 32786
[1790241304.745] [467304:467306] [CTL] Setting attestation nonce to random value
[1790241304.745] [467304:467306] [CTL] Setting CSR nonce to random value
[1790241304.746] [467304:467306] [CTL] Generating NOC
[1790241304.747] [467304:467306] [FP] Validating NOC chain
[1790241304.749] [467304:467306] [FP] NOC chain validation successful
[1790241304.750] [467304:467306] [FP] Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1790241304.750] [467304:467306] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1790241304.750] [467304:467306] [TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
[1790241304.750] [467304:467306] [TS] Retaining current Last Known Good Time
[1790241304.758] [467304:467306] [FP] Metadata for Fabric 0x1 persisted to storage.
[1790241304.762] [467304:467306] [TS] Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1790241304.764] [467304:467306] [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 4FC239DB662DA104)
[1790241304.764] [467304:467306] [IN] UDP::Init bind&listen port=5551
[1790241304.764] [467304:467306] [IN] UDP::Init bound to port=5551
[1790241304.764] [467304:467306] [IN] TransportMgr initialized
[1790241304.780] [467304:467306] [TOO] Sending command to node 0x2
[1790241304.781] [467304:467306] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000002]
[1790241304.781] [467304:467306] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1790241304.781] [467304:467306] [DIS] OperationalSessionSetup[1:0000000000000002]: State change 1 --> 2
[1790241304.781] [467304:467306] [DIS] Resolving 4FC239DB662DA104:0000000000000002 ...
[1790241304.782] [467304:467306] [DIS] Lookup started for 4FC239DB662DA104-0000000000000002
[1790241304.783] [467304:467306] [DL] Avahi resolve found
[1790241304.783] [467304:467306] [DIS] Node ID resolved for 4FC239DB662DA104-0000000000000002
[1790241304.783] [467304:467306] [DIS] 	Hostname: F691A7A78058A837
[1790241304.783] [467304:467306] [DIS] 	IP Address #1: fd11:25::fcbb:fd84:b83f:2815
[1790241304.783] [467304:467306] [DIS] 	Port: 5540
[1790241304.784] [467304:467306] [DIS] 	Mrp Interval idle: 3000 ms
[1790241304.784] [467304:467306] [DIS] 	Mrp Interval active: 2200 ms
[1790241304.784] [467304:467306] [DIS] 	Mrp Active Threshold: 300 ms
[1790241304.784] [467304:467306] [DIS] 	TCP Client Supported: 0
[1790241304.784] [467304:467306] [DIS] 	TCP Server Supported: 0
[1790241304.784] [467304:467306] [DIS] 	ICD: not present
[1790241304.784] [467304:467306] [DIS] Lookup clearing interface for non LL address
[1790241304.785] [467304:467306] [DIS] UDP:[fd11:25::fcbb:fd84:b83f:2815%veth5875779]:5540: new best score: 5 (for 4FC239DB662DA104-0000000000000002)
[1790241304.785] [467304:467306] [DIS] Checking node lookup status for 4FC239DB662DA104-0000000000000002 after 3 ms
[1790241304.785] [467304:467306] [DIS] Keeping DNSSD lookup active
[1790241304.982] [467304:467306] [DIS] Checking node lookup status for 4FC239DB662DA104-0000000000000002 after 201 ms
[1790241304.982] [467304:467306] [DIS] OperationalSessionSetup[1:0000000000000002]: Updating device address to UDP:[fd11:25::fcbb:fd84:b83f:2815]:5540 while in state 2
[1790241304.983] [467304:467306] [DIS] OperationalSessionSetup[1:0000000000000002]: State change 2 --> 3
[1790241304.983] [467304:467306] [IN] SecureSession[0xffff8c00bb30]: Allocated Type:2 LSID:33639
[1790241304.983] [467304:467306] [SC] Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000002
[1790241304.985] [467304:467306] [EM] <<< [E:8739i S:0 M:92132059] (U) Msg TX from 1179AA5E57D2C7F0 to 0:0000000000000000 [0000] [UDP:[fd11:25::fcbb:fd84:b83f:2815]:5540] --- Type 0000:30 (SecureChannel:CASE_
[1790241304.986] [467304:467306] [EM] ??1 [E:8739i S:0 M:92132059] (U) Msg Retransmission to 0:0000000000000000 scheduled for 3359ms from now [State:Idle II:3000 AI:2200 AT:300]
[1790241304.986] [467304:467306] [SC] Sent Sigma1 msg to <0000000000000002, 1> [II:500ms AI:300ms AT:4000ms]
[1790241304.986] [467304:467306] [DIS] OperationalSessionSetup[1:0000000000000002]: State change 3 --> 4
[1790241305.536] [467304:467306] [EM] >>> [E:8739i S:0 M:47193904 (Ack:92132059)] (U) Msg RX from 0:0000000000000000 [0000] to 1179AA5E57D2C7F0 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[1790241305.536] [467304:467306] [EM] Found matching exchange: 8739i, Delegate: 0xffff8c00b848
[1790241305.536] [467304:467306] [EM] Rxd Ack; Removing MessageCounter:92132059 from Retrans Table on exchange 8739i
[1790241305.758] [467304:467306] [EM] >>> [E:8739i S:0 M:47193905 (Ack:92132059)] (U) Msg RX from 0:0000000000000000 [0000] to 1179AA5E57D2C7F0 --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751)
[1790241305.758] [467304:467306] [EM] Found matching exchange: 8739i, Delegate: 0xffff8c00b848
[1790241305.758] [467304:467306] [EM] CHIP MessageCounter:92132059 not in RetransTable on exchange 8739i
[1790241305.758] [467304:467306] [SC] Received Sigma2 msg
[1790241305.758] [467304:467306] [SC] Found MRP parameters in the message
[1790241305.769] [467304:467306] [SC] Peer <0000000000000002, 1> assigned session ID 6213
[1790241305.769] [467304:467306] [SC] Sending Sigma3
[1790241305.770] [467304:467306] [EM] <<< [E:8739i S:0 M:92132060 (Ack:47193905)] (U) Msg TX from 1179AA5E57D2C7F0 to 0:0000000000000000 [0000] [UDP:[fd11:25::fcbb:fd84:b83f:2815]:5540] --- Type 0000:32 (Secu
[1790241305.770] [467304:467306] [EM] ??1 [E:8739i S:0 M:92132060] (U) Msg Retransmission to 0:0000000000000000 scheduled for 2614ms from now [State:Active II:3000 AI:2200 AT:300]
[1790241305.770] [467304:467306] [SC] Sent Sigma3 msg
[1790241306.236] [467304:467306] [EM] >>> [E:8739i S:0 M:47193906 (Ack:92132060)] (U) Msg RX from 0:0000000000000000 [0000] to 1179AA5E57D2C7F0 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[1790241306.237] [467304:467306] [EM] Found matching exchange: 8739i, Delegate: 0xffff8c00b848
[1790241306.237] [467304:467306] [EM] Rxd Ack; Removing MessageCounter:92132060 from Retrans Table on exchange 8739i
[1790241306.448] [467304:467306] [EM] >>> [E:8739i S:0 M:47193907 (Ack:92132060)] (U) Msg RX from 0:0000000000000000 [0000] to 1179AA5E57D2C7F0 --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
[1790241306.448] [467304:467306] [EM] Found matching exchange: 8739i, Delegate: 0xffff8c00b848
[1790241306.449] [467304:467306] [EM] CHIP MessageCounter:92132060 not in RetransTable on exchange 8739i
[1790241306.449] [467304:467306] [SC] Success status report received. Session was established
[1790241306.456] [467304:467306] [SC] SecureSession[0xffff8c00bb30, LSID:33639]: State change 'kEstablishing' --> 'kActive'
[1790241306.456] [467304:467306] [IN] SecureSession[0xffff8c00bb30]: Activated - Type:2 LSID:33639
[1790241306.456] [467304:467306] [IN] New secure session activated for device <0000000000000002, 1>, LSID:33639 PSID:6213!
[1790241306.457] [467304:467306] [DIS] OperationalSessionSetup[1:0000000000000002]: State change 4 --> 5
[1790241306.457] [467304:467306] [TOO] Sending ReadAttribute to:
[1790241306.457] [467304:467306] [TOO] 	cluster 0x0000_0028, attribute: 0x0000_0012, endpoint 0
[1790241306.457] [467304:467306] [DMG] SendReadRequest ReadClient[0xffff8c00eaf0]: Sending Read Request
[1790241306.457] [467304:467306] [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
[1790241306.457] [467304:467306] [EM] <<< [E:8740i S:33639 M:106557212] (S) Msg TX from 000000000001B669 to 1:0000000000000002 [A104] [UDP:[fd11:25::fcbb:fd84:b83f:2815]:5540] --- Type 0001:02 (IM:ReadRequest
[1790241306.458] [467304:467306] [EM] ??1 [E:8740i S:33639 M:106557212] (S) Msg Retransmission to 1:0000000000000002 scheduled for 2645ms from now [State:Active II:3000 AI:2200 AT:300]
[1790241306.458] [467304:467306] [DMG] MoveToState ReadClient[0xffff8c00eaf0]: Moving to [AwaitingIn]
[1790241306.458] [467304:467306] [EM] <<< [E:8739i S:0 M:92132061 (Ack:47193907)] (U) Msg TX from 1179AA5E57D2C7F0 to 0:0000000000000000 [0000] [UDP:[fd11:25::fcbb:fd84:b83f:2815]:5540] --- Type 0000:10 (Secu
[1790241306.458] [467304:467306] [EM] Flushed pending ack for MessageCounter:47193907 on exchange 8739i
[1790241306.458] [467304:467306] [DL] HandlePlatformSpecificBLEEvent 32792
[1790241306.752] [467304:467306] [EM] >>> [E:8740i S:33639 M:191114545 (Ack:106557212)] (S) Msg RX from 1:0000000000000002 [A104] to 000000000001B669 --- Type 0001:05 (IM:ReportData) (B:70)
[1790241306.752] [467304:467306] [EM] Found matching exchange: 8740i, Delegate: 0xffff8c00eb00
[1790241306.752] [467304:467306] [EM] Rxd Ack; Removing MessageCounter:106557212 from Retrans Table on exchange 8740i
[1790241306.753] [467304:467306] [DMG] ReportDataMessage =
[1790241306.753] [467304:467306] [DMG] {
[1790241306.753] [467304:467306] [DMG] 	AttributeReportIBs =
[1790241306.753] [467304:467306] [DMG] 	[
[1790241306.753] [467304:467306] [DMG] 		AttributeReportIB =
[1790241306.753] [467304:467306] [DMG] 		{
[1790241306.753] [467304:467306] [DMG] 			AttributeDataIB =
[1790241306.753] [467304:467306] [DMG] 			{
[1790241306.753] [467304:467306] [DMG] 				DataVersion = 0x29433f05,
[1790241306.753] [467304:467306] [DMG] 				AttributePathIB =
[1790241306.753] [467304:467306] [DMG] 				{
[1790241306.753] [467304:467306] [DMG] 					Endpoint = 0x0,
[1790241306.753] [467304:467306] [DMG] 					Cluster = 0x28,
[1790241306.754] [467304:467306] [DMG] 					Attribute = 0x0000_0012,
[1790241306.754] [467304:467306] [DMG] 				}
[1790241306.754] [467304:467306] [DMG] 					
[1790241306.754] [467304:467306] [DMG] 				Data = "" (0 chars),      <---------------------------------------------------- empty
[1790241306.754] [467304:467306] [DMG] 			},
[1790241306.754] [467304:467306] [DMG] 			
[1790241306.754] [467304:467306] [DMG] 		},
[1790241306.754] [467304:467306] [DMG] 		
[1790241306.754] [467304:467306] [DMG] 	],
[1790241306.754] [467304:467306] [DMG] 	
[1790241306.754] [467304:467306] [DMG] 	SuppressResponse = true, 
[1790241306.754] [467304:467306] [DMG] 	InteractionModelRevision = 11
[1790241306.754] [467304:467306] [DMG] }
[1790241306.755] [467304:467306] [TOO] Endpoint: 0 Cluster: 0x0000_0028 Attribute 0x0000_0012 DataVersion: 692272901
[1790241306.755] [467304:467306] [TOO]   UniqueID: 
[1790241306.755] [467304:467306] [EM] <<< [E:8740i S:33639 M:106557213 (Ack:191114545)] (S) Msg TX from 000000000001B669 to 1:0000000000000002 [A104] [UDP:[fd11:25::fcbb:fd84:b83f:2815]:5540] --- Type 0000:10
[1790241306.755] [467304:467306] [EM] Flushed pending ack for MessageCounter:191114545 on exchange 8740i
[1790241306.756] [467304:467304] [CTL] Shutting down the commissioner
[1790241306.756] [467304:467304] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1790241306.756] [467304:467304] [CTL] Shutting down the controller
[1790241306.756] [467304:467304] [IN] Expiring all sessions for fabric 0x1!!
[1790241306.756] [467304:467304] [IN] SecureSession[0xffff8c00bb30]: MarkForEviction Type:2 LSID:33639
[1790241306.756] [467304:467304] [SC] SecureSession[0xffff8c00bb30, LSID:33639]: State change 'kActive' --> 'kPendingEviction'
[1790241306.756] [467304:467304] [IN] SecureSession[0xffff8c00bb30]: Released - Type:2 LSID:33639
[1790241306.756] [467304:467304] [FP] Forgetting fabric 0x1
[1790241306.756] [467304:467304] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1790241306.757] [467304:467304] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1790241306.757] [467304:467304] [TS] Reverted Last Known Good Time to previous value
[1790241306.757] [467304:467304] [CTL] Shutting down the commissioner
[1790241306.757] [467304:467304] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1790241306.757] [467304:467304] [CTL] Shutting down the controller
[1790241306.757] [467304:467304] [CTL] Shutting down the System State, this will teardown the CHIP Stack
[1790241306.758] [467304:467304] [DMG] All ReadHandler-s are clean, clear GlobalDirtySet
[1790241306.758] [467304:467304] [FP] Shutting down FabricTable
[1790241306.758] [467304:467304] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1790241306.758] [467304:467304] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1790241306.758] [467304:467304] [TS] Reverted Last Known Good Time to previous value
[1790241306.765] [467304:467304] [DL] Wrote settings to /tmp/chip_counters.ini
[1790241306.766] [467304:467304] [DL] NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1790241306.766] [467304:467304] [DL] Inet Layer shutdown
[1790241306.766] [467304:467304] [DL] BLE Layer shutdown
[1790241306.766] [467304:467304] [DL] WiFi-PAF Layer shutdown
[1790241306.766] [467304:467304] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1790241306.766] [467304:467304] [DL] System Layer shutdown

[Amanda Hsieh]

Hi, 

Could you share the device logs for fabric removal and whether a reboot between decommissioning and recommissioning changes the UniqueID?

Regards,
Amanda H.

[chiba]

HI,
Thanks for your reply.
This is the nRF5340DK log.

Commissioning complete, nRF5340DK booting up.



[2026-09-25 09:08:31.396] 
[2026-09-25 09:08:31.396] uart:~$ *** Booting My Application v2.9.2-18b4f40ea698 ***
[2026-09-25 09:08:31.429] *** Using nRF Connect SDK v2.9.2-4ab7b98fc76f ***
[2026-09-25 09:08:31.429] *** Using Zephyr OS v3.7.99-aa34a5632971 ***
[2026-09-25 09:08:31.438] I: 58 [DL]BLE address: EC:DF:6D:EA:EF:D6
[2026-09-25 09:08:31.457] I: No users indexes stored
[2026-09-25 09:08:31.467] I: No stored indexes for credential of type: 1
[2026-09-25 09:08:31.472] I: 91 [DL]CHIP task running
[2026-09-25 09:08:31.474] I: Init CHIP stack
[2026-09-25 09:08:31.488] I: 108 [DL]OpenThread ifconfig up and thread start
[2026-09-25 09:08:31.494] I: 113 [DL]OpenThread started: OK
[2026-09-25 09:08:31.501] I: 119 [DL]Setting OpenThread device type to SLEEPY END DEVICE
[2026-09-25 09:08:31.507] I: 125 [SVR]Subscription persistence not supported
[2026-09-25 09:08:31.510] I: 130 [SVR]Server initializing...
[2026-09-25 09:08:31.515] I: 133 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2026-09-25 09:08:31.523] I: 141 [FP]Fabric index 0x2 was retrieved from storage. Compressed FabricId 0x4FC239DB662DA104, FabricId 0x0000000000000001, NodeId 0x0000000000000002, VendorId 0xFFF1
[2026-09-25 09:08:31.534] I: 157 [DMG]AccessControl: initializing
[2026-09-25 09:08:31.541] I: 160 [DMG]Examples::AccessControlDelegate::Init
[2026-09-25 09:08:31.545] I: 165 [DMG]AccessControl: setting
[2026-09-25 09:08:31.545] I: 168 [DMG]DefaultAclStorage: initializing
[2026-09-25 09:08:31.545] I: 173 [DMG]DefaultAclStorage: 1 entries loaded
[2026-09-25 09:08:31.560] E: 178 [IN]IPV6_PKTINFO failed: 109
[2026-09-25 09:08:31.561] I: 183 [ZCL]Using ZAP configuration...
[2026-09-25 09:08:31.568] I: 188 [DMG]AccessControlCluster: initializing
[2026-09-25 09:08:31.574] I: 193 [ZCL]Initiating Admin Commissioning cluster.
[2026-09-25 09:08:31.574] I: 197 [ZCL]Door Lock server initialized
[2026-09-25 09:08:31.583] I: 201 [ZCL]Door Lock cluster initialized at endpoint #1
[2026-09-25 09:08:31.587] I: 206 [ZCL]0xaf166 ep 1 clus 0x0000_0101 attr 0x0000_0013 not supported
[2026-09-25 09:08:31.591] E: 214 [ZCL]Failed to set DoorLock number of RFID users: 86
[2026-09-25 09:08:31.696] I: 315 [SVR]Fabric already commissioned. Disabling BLE advertisement
[2026-09-25 09:08:31.704] I: 322 [DIS]Updating services using commissioning mode 0
[2026-09-25 09:08:31.710] E: 329 [DIS]Failed to remove advertised services: 3
[2026-09-25 09:08:31.718] I: 337 [DIS]Advertise operational node 4FC239DB662DA104-0000000000000002
[2026-09-25 09:08:31.724] E:I: 351 [DL]SRP Client was started, detected server: fdd6:208a:44e0:8102:05c4:a54e:7070:8122
[2026-09-25 09:08:31.741]  344 [DIS]Failed to advertise operational node: 3
[2026-09-25 09:08:31.744] E: 363 [DIS]Failed to finalize service update: 3
[2026-09-25 09:08:31.746] I: 368 [IN]CASE Server enabling CASE session setups
[2026-09-25 09:08:31.746] I: 373 [SVR]Joining Multicast groups
[2026-09-25 09:08:31.757] I: 377 [SVR]Server Listening...
[2026-09-25 09:08:31.760] I: 380 [DL]Device Configuration:
[2026-09-25 09:08:31.760] I: 383 [DL]  Serial Number: 11223344556677889900
[2026-09-25 09:08:31.769] I: 387 [DL]  Vendor Id: 65521 (0xFFF1)
[2026-09-25 09:08:31.769] I: 391 [DL]  Product Id: 32774 (0x8006)
[2026-09-25 09:08:31.774] I: 394 [DL]  Product Name: not-specified
[2026-09-25 09:08:31.774] I: 398 [DL]  Hardware Version: 0
[2026-09-25 09:08:31.784] I: 401 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
[2026-09-25 09:08:31.784] I: 406 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
[2026-09-25 09:08:31.791] I: 413 [DL]  Manufacturing Date: 2022-01-01
[2026-09-25 09:08:31.791] I: 417 [DL]  Device Type: 65535 (0xFFFF)
[2026-09-25 09:08:31.791] I: 420 [SVR]SetupQRCode: [MT:8IXS142C00KA0648G00]
[2026-09-25 09:08:31.803] I: 425 [SVR]Copy/paste the below URL in a browser to see the QR Code:
[2026-09-25 09:08:31.807] I: 431 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A8IXS142C00KA0648G00
[2026-09-25 09:08:31.821] I: 441 [SVR]Manual pairing code: [34970112332]
[2026-09-25 09:08:31.824] E: 446 [DL]Long dispatch time: 353 ms, for event type 2
[2026-09-25 09:08:31.846] I: 466 [ZCL]ThreadDiagnosticsDelegate: OnConnectionStatusChanged
[2026-09-25 09:08:32.581] I: 1185 [SVR]Server initialization complete
[2026-09-25 09:08:32.581] I: 1189 [DIS]Updating services using commissioning mode 0
[2026-09-25 09:08:32.581] I: 1194 [DIS]Advertise operational node 4FC239DB662DA104-0000000000000002
[2026-09-25 09:08:32.581] I: 1201 [DL]advertising srp service: 4FC239DB662DA104-0000000000000002._matter._tcp
[2026-09-25 09:08:32.591] I: 1212 [SWU]Stopping the watchdog timer
[2026-09-25 09:08:32.596] I: 1216 [SWU]Starting the periodic query timer, timeout: 86400 seconds



nRF5340DK boot complete.
Starting decommissioning.



[2026-09-25 09:09:59.885] I: 88490 [EM]>>> [E:33878r S:0 M:116540948] (U) Msg RX from 0:842EA98982738386 [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
[2026-09-25 09:09:59.887] I: 88504 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x20007148
[2026-09-25 09:09:59.892] I: 88512 [EM]<<< [E:33878r S:0 M:257592796 (Ack:116540948)] (U) Msg TX from 0000000000000000 to 0:842EA98982738386 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:56765] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:09:59.907] I: 88532 [SC]Received Sigma1 msg
[2026-09-25 09:09:59.917] I: 88542 [SC]CASE matched destination ID: fabricIndex 2, NodeID 0x0000000000000002
[2026-09-25 09:10:00.028] I: 88635 [EM]<<< [E:33878r S:0 M:257592797 (Ack:116540948)] (U) Msg TX from 0000000000000000 to 0:842EA98982738386 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:56765] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751)
[2026-09-25 09:10:00.035] I: 88656 [EM]??1 [E:33878r S:0 M:257592797] (U) Msg Retransmission to 0:0000000000000000 in 2060ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:10:00.044] I: 88670 [SC]Sent Sigma2 msg
[2026-09-25 09:10:00.472] I: 89088 [EM]>>> [E:33878r S:0 M:116540949 (Ack:257592797)] (U) Msg RX from 0:842EA98982738386 [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598)
[2026-09-25 09:10:00.480] I: 89104 [EM]<<< [E:33878r S:0 M:257592798 (Ack:116540949)] (U) Msg TX from 0000000000000000 to 0:842EA98982738386 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:56765] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:10:00.503] I: 89125 [SC]Received Sigma3 msg
[2026-09-25 09:10:00.512] E: 89134 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
[2026-09-25 09:10:00.694] E: 89307 [DL]Long dispatch time: 163 ms, for event type 2
[2026-09-25 09:10:00.694] I: 89318 [EM]<<< [E:33878r S:0 M:257592799 (Ack:116540949)] (U) Msg TX from 0000000000000000 to 0:842EA98982738386 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:56765] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
[2026-09-25 09:10:00.710] I: 89339 [EM]??1 [E:33878r S:0 M:257592799] (U) Msg Retransmission to 0:0000000000000000 in 2108ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:10:00.732] I: 89353 [SC]SecureSession[0x20005370, LSID:1980]: State change 'kEstablishing' --> 'kActive'
[2026-09-25 09:10:00.743] I: 89362 [IN]CASE Session established to peer: <000000000001B669, 2>
[2026-09-25 09:10:00.885] I: 89491 [EM]>>> [E:33879r S:1980 M:108089556] (S) Msg RX from 2:000000000001B669 [A104] to 0000000000000002 --- Type 0001:02 (IM:ReadRequest) (B:51)
[2026-09-25 09:10:00.890] I: 89510 [EM]<<< [E:33879r S:1980 M:15899676 (Ack:108089556)] (S) Msg TX from 0000000000000002 to 2:000000000001B669 [A104] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:56765] --- Type 0001:05 (IM:ReportData) (B:70)
[2026-09-25 09:10:00.908] I: 89530 [EM]??1 [E:33879r S:1980 M:15899676] (S) Msg Retransmission to 2:000000000001B669 in 2090ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:10:00.917] I: 89543 [EM]>>> [E:33878r S:0 M:116540950 (Ack:257592799)] (U) Msg RX from 0:842EA98982738386 [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:10:01.202] I: 89813 [EM]>>> [E:33880r S:1980 M:108089557] (S) Msg RX from 2:000000000001B669 [A104] to 0000000000000002 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[2026-09-25 09:10:01.207] I: 89831 [ZCL]OpCreds: Received a RemoveFabric Command for FabricIndex 0x2
[2026-09-25 09:10:01.217] I: 89839 [EM]<<< [E:33880r S:1980 M:15899677 (Ack:108089557)] (S) Msg TX from 0000000000000002 to 2:000000000001B669 [A104] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:56765] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[2026-09-25 09:10:01.246] I: 89867 [FP]Fabric (0x2) deleted.
[2026-09-25 09:10:01.250] I: 89870 [ZCL][OnFabricRemoved] Handling a fabric removal from the door lock server [endpointId=1,fabricIndex=2]
[2026-09-25 09:10:01.257] E: 89880 [ZCL][clearFabricFromCredentials] Unable to clear fabric from credential - couldn't read credential from database [endpointId=1,credentialType=0,credentialIndex=0,fabricIdToRemove=2]
[2026-09-25 09:10:01.274] I: 89897 [ZCL]OpCreds: Fabric index 0x2 was removed
[2026-09-25 09:10:01.281] I: 89902 [DIS]Updating services using commissioning mode 0
[2026-09-25 09:10:01.281] I: 89907 [DL]removing srp service: 4FC239DB662DA104-0000000000000002._matter._tcp
[2026-09-25 09:10:01.311] I: 89938 [ZCL]OpCreds: RemoveFabric successful
[2026-09-25 09:10:01.311] I: 89942 [SC]SecureSession[0x20005370, LSID:1980]: State change 'kActive' --> 'kPendingEviction'
[2026-09-25 09:10:01.327] I: 89952 [EM]<<< [E:33880r S:1980 M:15899678 (Ack:108089557)] (S) Msg TX from 0000000000000002 to 2:000000000001B669 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:56765] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
[2026-09-25 09:10:01.350] I: 89972 [EM]??1 [E:33880r S:1980 M:15899678] (S) Msg Retransmission to 2:000000000001B669 in 2085ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:10:01.363] I: 89986 [EM]>>> [E:33879r S:1980 M:108089558 (Ack:15899676)] (S) Msg RX from 2:000000000001B669 [0000] to 0000000000000002 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[2026-09-25 09:10:01.381] I: 90002 [EM]Dropping message on inactive session that does not match an existing exchange
[2026-09-25 09:10:01.391] I: 90023 [EM]>>> [E:33880r S:1980 M:108089559 (Ack:15899678)] (S) Msg RX from 2:000000000001B669 [0000] to 0000000000000002 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[2026-09-25 09:10:02.624] I: 91234 [DL]Erasing Thread persistent info...
[2026-09-25 09:10:02.627] E: 91256 [DL]Long dispatch time: 386 ms, for event type 2
[2026-09-25 09:10:02.641] I: 91261 [DIS]Updating services using commissioning mode 0
[2026-09-25 09:10:02.641] I: 91266 [ZCL]ThreadDiagnosticsDelegate: OnConnectionStatusChanged
[2026-09-25 09:10:02.641] I: 91272 [ZCL]ThreadDiagnosticsDelegate: OnNetworkFaultChanged



Decommissioning complete.
Starting re-commissioning.



[2026-09-25 09:10:27.476] I: 116080 [DIS]Updating services using commissioning mode 1
[2026-09-25 09:10:27.476] I: 116086 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3840/15 cm=1 cp=0
[2026-09-25 09:10:27.476] I: 116096 [DL]advertising srp service: E065260FF669AFA2._matterc._udp
[2026-09-25 09:10:27.485] I: 116106 [DL]CHIPoBLE advertising started
[2026-09-25 09:10:27.485] I: 116110 [DL]NFC Tag emulation started
[2026-09-25 09:10:49.029] I: 137634 [DL]Current number of connections: 1/1
[2026-09-25 09:10:49.029] I: 137639 [DL]BLE connection established (ConnId: 0x00)
[2026-09-25 09:10:49.029] I: 137645 [DL]CHIPoBLE advertising stopped
[2026-09-25 09:10:49.029] I: 137649 [DL]NFC Tag emulation stopped
[2026-09-25 09:10:50.535] I: 139143 [BLE]local and remote recv window sizes = 5
[2026-09-25 09:10:50.535] I: 139147 [BLE]selected BTP version 4
[2026-09-25 09:10:50.535] I: 139151 [BLE]using BTP fragment sizes rx 244 / tx 244.
[2026-09-25 09:10:50.615] I: 139233 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
[2026-09-25 09:10:50.710] I: 139324 [EM]>>> [E:41914r S:0 M:103905166] (U) Msg RX from 0:1089A17B49F46F87 [0000] to 0000000000000000 --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98)
[2026-09-25 09:10:50.710] I: 139340 [EM]<<< [E:41914r S:0 M:257592800] (U) Msg TX from 0000000000000000 to 0:1089A17B49F46F87 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154)
[2026-09-25 09:10:50.737] I: 139356 [SVR]Commissioning session establishment step started
[2026-09-25 09:10:50.805] I: 139414 [EM]>>> [E:41914r S:0 M:103905167] (U) Msg RX from 0:1089A17B49F46F87 [0000] to 0000000000000000 --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92)
[2026-09-25 09:10:50.931] I: 139550 [EM]<<< [E:41914r S:0 M:257592801] (U) Msg TX from 0000000000000000 to 0:1089A17B49F46F87 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127)
[2026-09-25 09:10:50.946] E: 139565 [DL]Long dispatch time: 151 ms, for event type 16388
[2026-09-25 09:10:51.074] I: 139684 [EM]>>> [E:41914r S:0 M:103905168] (U) Msg RX from 0:1089A17B49F46F87 [0000] to 0000000000000000 --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59)
[2026-09-25 09:10:51.074] I: 139699 [EM]<<< [E:41914r S:0 M:257592802] (U) Msg TX from 0000000000000000 to 0:1089A17B49F46F87 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
[2026-09-25 09:10:51.097] I: 139716 [SC]SecureSession[0x20005370, LSID:1982]: State change 'kEstablishing' --> 'kActive'
[2026-09-25 09:10:51.103] I: 139724 [SVR]Commissioning completed session establishment step
[2026-09-25 09:10:51.109] I: 139730 [DIS]Updating services using commissioning mode 0
[2026-09-25 09:10:51.109] I: 139736 [DL]removing srp service: E065260FF669AFA2._matterc._udp
[2026-09-25 09:10:51.121] I: 139742 [SVR]Device completed Rendezvous process
[2026-09-25 09:10:51.200] I: 139820 [EM]>>> [E:41915r S:1982 M:29260020] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:134)
[2026-09-25 09:10:51.219] I: 139840 [EM]<<< [E:41915r S:1982 M:162258637] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:257)
[2026-09-25 09:10:51.438] I: 140045 [EM]>>> [E:41916r S:1982 M:29260021] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:103)
[2026-09-25 09:10:51.440] E: 140061 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0007err = 586
[2026-09-25 09:10:51.448] E: 140072 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0006err = 586
[2026-09-25 09:10:51.457] I: 140085 [EM]<<< [E:41916r S:1982 M:162258638] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:192)
[2026-09-25 09:10:51.564] I: 140180 [EM]>>> [E:41917r S:1982 M:29260022] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
[2026-09-25 09:10:51.574] I: 140194 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
[2026-09-25 09:10:51.580] I: 140201 [EM]<<< [E:41917r S:1982 M:162258639] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[2026-09-25 09:10:51.707] I: 140315 [EM]>>> [E:41918r S:1982 M:29260023] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:70)
[2026-09-25 09:10:51.710] I: 140331 [EM]<<< [E:41918r S:1982 M:162258640] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[2026-09-25 09:10:51.786] I: 140404 [EM]>>> [E:41919r S:1982 M:29260024] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[2026-09-25 09:10:51.799] I: 140419 [ZCL]OpCreds: Certificate Chain request received for PAI
[2026-09-25 09:10:51.807] I: 140429 [EM]<<< [E:41919r S:1982 M:162258641] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:527)
[2026-09-25 09:10:52.054] I: 140674 [EM]>>> [E:41920r S:1982 M:29260025] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[2026-09-25 09:10:52.074] I: 140689 [ZCL]OpCreds: Certificate Chain request received for DAC
[2026-09-25 09:10:52.076] I: 140699 [EM]<<< [E:41920r S:1982 M:162258642] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:555)
[2026-09-25 09:10:52.419] I: 141034 [EM]>>> [E:41921r S:1982 M:29260026] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
[2026-09-25 09:10:52.424] I: 141049 [ZCL]OpCreds: Received an AttestationRequest command
[2026-09-25 09:10:52.466] I: 141085 [ZCL]OpCreds: AttestationRequest successful.
[2026-09-25 09:10:52.472] I: 141094 [EM]<<< [E:41921r S:1982 M:162258643] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:716)
[2026-09-25 09:10:52.782] I: 141394 [EM]>>> [E:41922r S:1982 M:29260027] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
[2026-09-25 09:10:52.788] I: 141409 [ZCL]OpCreds: Received a CSRRequest command
[2026-09-25 09:10:52.861] I: 141469 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
[2026-09-25 09:10:52.877] I: 141504 [ZCL]OpCreds: CSRRequest successful.
[2026-09-25 09:10:52.889] I: 141511 [EM]<<< [E:41922r S:1982 M:162258644] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:393)
[2026-09-25 09:10:52.905] E: 141526 [DL]Long dispatch time: 133 ms, for event type 16388
[2026-09-25 09:10:53.225] I: 141845 [EM]>>> [E:41923r S:1982 M:29260028] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:293)
[2026-09-25 09:10:53.240] I: 141860 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
[2026-09-25 09:10:53.304] I: 141920 [ZCL]OpCreds: AddTrustedRootCertificate successful.
[2026-09-25 09:10:53.307] I: 141926 [EM]<<< [E:41923r S:1982 M:162258645] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
[2026-09-25 09:10:53.588] I: 142207 [EM]>>> [E:41924r S:1982 M:29260029] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:566)
[2026-09-25 09:10:53.600] I: 142222 [ZCL]OpCreds: Received an AddNOC command
[2026-09-25 09:10:53.610] I: 142227 [FP]Validating NOC chain
[2026-09-25 09:10:53.730] I: 142340 [FP]NOC chain validation successful
[2026-09-25 09:10:53.730] I: 142344 [FP]Added new fabric at index: 0x3
[2026-09-25 09:10:53.730] I: 142348 [FP]Assigned compressed fabric ID: 0xD6F5CEE6A9E420C0, node ID: 0x0000000000000002
[2026-09-25 09:10:53.736] I: 142356 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2026-09-25 09:10:53.736] I: 142361 [TS]New proposed Last Known Good Time: 2021-01-01T00:00:00
[2026-09-25 09:10:53.746] I: 142367 [TS]Retaining current Last Known Good Time
[2026-09-25 09:10:53.759] I: 142382 [ZCL]OpCreds: ACL entry created for Fabric index 0x3 CASE Admin Subject 0x000000000001B669
[2026-09-25 09:10:53.761] I: 142391 [DIS]Advertise operational node D6F5CEE6A9E420C0-0000000000000002
[2026-09-25 09:10:53.774] I: 142398 [DL]advertising srp service: D6F5CEE6A9E420C0-0000000000000002._matter._tcp
[2026-09-25 09:10:53.777] I: 142406 [ZCL]OpCreds: successfully created fabric index 0x3 via AddNOC
[2026-09-25 09:10:53.790] I: 142413 [EM]<<< [E:41924r S:1982 M:162258646] (S) Msg TX from 0000000000000000 to 3:FFFFFFFB00000000 [20C0] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[2026-09-25 09:10:53.808] E: 142428 [DL]Long dispatch time: 225 ms, for event type 16388
[2026-09-25 09:10:53.903] I: 142521 [EM]>>> [E:41925r S:1982 M:29260030] (S) Msg RX from 3:FFFFFFFB00000000 [20C0] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:160)
[2026-09-25 09:10:53.916] I: 142538 [EM]<<< [E:41925r S:1982 M:162258647] (S) Msg TX from 0000000000000000 to 3:FFFFFFFB00000000 [20C0] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[2026-09-25 09:10:53.998] I: 142610 [EM]>>> [E:41926r S:1982 M:29260031] (S) Msg RX from 3:FFFFFFFB00000000 [20C0] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
[2026-09-25 09:10:54.001] I: 142624 [FS]GeneralCommissioning: Received ArmFailSafe (108s)
[2026-09-25 09:10:54.011] I: 142631 [EM]<<< [E:41926r S:1982 M:162258648] (S) Msg TX from 0000000000000000 to 3:FFFFFFFB00000000 [20C0] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[2026-09-25 09:10:54.093] I: 142700 [EM]>>> [E:41927r S:1982 M:29260032] (S) Msg RX from 3:FFFFFFFB00000000 [20C0] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:73)
[2026-09-25 09:10:55.282] I: 143890 [ZCL]ThreadDiagnosticsDelegate: OnConnectionStatusChanged
[2026-09-25 09:10:55.282] I: 143899 [EM]<<< [E:41927r S:1982 M:162258649] (S) Msg TX from 0000000000000000 to 3:FFFFFFFB00000000 [20C0] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:65)
[2026-09-25 09:10:55.291] I: 143914 [DIS]Advertise operational node D6F5CEE6A9E420C0-0000000000000002
[2026-09-25 09:10:55.297] I: 143921 [SVR]Operational advertising enabled
[2026-09-25 09:10:56.750] I: 145367 [EM]>>> [E:41928r S:0 M:103905169] (U) Msg RX from 0:F7AF320FD2091F76 [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
[2026-09-25 09:10:56.759] I: 145381 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x20007148
[2026-09-25 09:10:56.766] I: 145389 [EM]<<< [E:41928r S:0 M:257592803 (Ack:103905169)] (U) Msg TX from 0000000000000000 to 0:F7AF320FD2091F76 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:45020] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:10:56.782] I: 145409 [SC]Received Sigma1 msg
[2026-09-25 09:10:56.797] I: 145419 [SC]CASE matched destination ID: fabricIndex 3, NodeID 0x0000000000000002
[2026-09-25 09:10:56.892] I: 145509 [EM]<<< [E:41928r S:0 M:257592804 (Ack:103905169)] (U) Msg TX from 0000000000000000 to 0:F7AF320FD2091F76 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:45020] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751)
[2026-09-25 09:10:56.907] I: 145530 [EM]??1 [E:41928r S:0 M:257592804] (U) Msg Retransmission to 0:0000000000000000 in 2087ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:10:56.907] I: 145543 [SC]Sent Sigma2 msg
[2026-09-25 09:10:57.588] I: 146194 [EM]>>> [E:41928r S:0 M:103905170 (Ack:257592804)] (U) Msg RX from 0:F7AF320FD2091F76 [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598)
[2026-09-25 09:10:57.591] I: 146210 [EM]<<< [E:41928r S:0 M:257592805 (Ack:103905170)] (U) Msg TX from 0000000000000000 to 0:F7AF320FD2091F76 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:45020] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:10:57.607] I: 146231 [SC]Received Sigma3 msg
[2026-09-25 09:10:57.607] E: 146240 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
[2026-09-25 09:10:57.794] E: 146413 [DL]Long dispatch time: 163 ms, for event type 2
[2026-09-25 09:10:57.794] I: 146424 [EM]<<< [E:41928r S:0 M:257592806 (Ack:103905170)] (U) Msg TX from 0000000000000000 to 0:F7AF320FD2091F76 [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:45020] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
[2026-09-25 09:10:57.824] I: 146445 [EM]??1 [E:41928r S:0 M:257592806] (U) Msg Retransmission to 0:0000000000000000 in 2091ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:10:57.835] I: 146460 [SC]SecureSession[0x20005448, LSID:1981]: State change 'kEstablishing' --> 'kActive'
[2026-09-25 09:10:57.848] I: 146468 [IN]CASE Session established to peer: <000000000001B669, 3>
[2026-09-25 09:10:57.985] I: 146597 [EM]>>> [E:41929r S:1981 M:12638737] (S) Msg RX from 3:000000000001B669 [20C0] to 0000000000000002 --- Type 0001:08 (IM:InvokeCommandRequest) (B:59)
[2026-09-25 09:10:57.992] I: 146616 [FS]GeneralCommissioning: Received CommissioningComplete
[2026-09-25 09:10:58.001] I: 146623 [FP]Metadata for Fabric 0x3 persisted to storage.
[2026-09-25 09:10:58.018] I: 146640 [TS]Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[2026-09-25 09:10:58.027] I: 146649 [ZCL]OpCreds: Fabric index 0x3 was committed to storage. Compressed Fabric Id 0xD6F5CEE6A9E420C0, FabricId 0000000000000001, NodeId 0000000000000002, VendorId 0xFFF1
[2026-09-25 09:10:58.049] I: 146665 [FS]GeneralCommissioning: Successfully commited pending fabric data
[2026-09-25 09:10:58.049] I: 146672 [FS]Fail-safe cleanly disarmed
[2026-09-25 09:10:58.057] I: 146677 [EM]<<< [E:41929r S:1981 M:4515810 (Ack:12638737)] (S) Msg TX from 0000000000000002 to 3:000000000001B669 [20C0] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:45020] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70)
[2026-09-25 09:10:58.074] I: 146697 [EM]??1 [E:41929r S:1981 M:4515810] (S) Msg Retransmission to 3:000000000001B669 in 2053ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:10:58.090] I: 146710 [SVR]Commissioning completed successfully
[2026-09-25 09:10:58.092] I: 146716 [DIS]Updating services using commissioning mode 0
[2026-09-25 09:10:58.096] I: 146721 [DIS]Advertise operational node D6F5CEE6A9E420C0-0000000000000002
[2026-09-25 09:10:58.107] I: 146729 [SC]SecureSession[0x20005370, LSID:1982]: State change 'kActive' --> 'kPendingEviction'
[2026-09-25 09:10:58.112] I: 146737 [BLE]Releasing end point's BLE connection back to application.
[2026-09-25 09:10:58.112] I: 146744 [DL]Closing BLE GATT connection (ConnId 00)
[2026-09-25 09:10:58.128] I: 146750 [SWU]Device commissioned, schedule a default provider query
[2026-09-25 09:10:58.136] I: 146757 [EM]>>> [E:41928r S:0 M:103905171 (Ack:257592806)] (U) Msg RX from 0:F7AF320FD2091F76 [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:10:58.270] I: 146882 [DL]Current number of connections: 0/1
[2026-09-25 09:10:58.270] I: 146886 [DL]BLE GAP connection terminated (reason 0x16)
[2026-09-25 09:10:58.603] I: 147209 [EM]>>> [E:41929r S:1981 M:12638738 (Ack:4515810)] (S) Msg RX from 3:000000000001B669 [20C0] to 0000000000000002 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)



Re-commissioning complete.
Reading Unique ID.



[2026-09-25 09:11:28.146] E: 176756 [SWU]No suitable OTA Provider candidate found
[2026-09-25 09:11:28.147] I: 176761 [SWU]No provider available
[2026-09-25 09:11:48.631] I: 197238 [EM]>>> [E:56606r S:0 M:264294567] (U) Msg RX from 0:C309693323D6A15C [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196)
[2026-09-25 09:11:48.632] I: 197252 [IN]CASE Server received Sigma1 message . Starting handshake. EC 0x20007148
[2026-09-25 09:11:48.637] I: 197260 [EM]<<< [E:56606r S:0 M:257592807 (Ack:264294567)] (U) Msg TX from 0000000000000000 to 0:C309693323D6A15C [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:55979] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:11:48.658] I: 197281 [SC]Received Sigma1 msg
[2026-09-25 09:11:48.669] I: 197291 [SC]CASE matched destination ID: fabricIndex 3, NodeID 0x0000000000000002
[2026-09-25 09:11:48.771] I: 197381 [EM]<<< [E:56606r S:0 M:257592808 (Ack:264294567)] (U) Msg TX from 0000000000000000 to 0:C309693323D6A15C [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:55979] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751)
[2026-09-25 09:11:48.780] I: 197402 [EM]??1 [E:56606r S:0 M:257592808] (U) Msg Retransmission to 0:0000000000000000 in 2035ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:11:48.792] I: 197415 [SC]Sent Sigma2 msg
[2026-09-25 09:11:49.432] I: 198045 [EM]>>> [E:56606r S:0 M:264294568 (Ack:257592808)] (U) Msg RX from 0:C309693323D6A15C [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598)
[2026-09-25 09:11:49.438] I: 198061 [EM]<<< [E:56606r S:0 M:257592809 (Ack:264294568)] (U) Msg TX from 0000000000000000 to 0:C309693323D6A15C [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:55979] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:11:49.459] I: 198081 [SC]Received Sigma3 msg
[2026-09-25 09:11:49.468] E: 198091 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
[2026-09-25 09:11:49.646] E: 198265 [DL]Long dispatch time: 163 ms, for event type 2
[2026-09-25 09:11:49.653] I: 198275 [EM]<<< [E:56606r S:0 M:257592810 (Ack:264294568)] (U) Msg TX from 0000000000000000 to 0:C309693323D6A15C [0000] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:55979] --- Type 0000:40 (SecureChannel:StatusReport) (B:34)
[2026-09-25 09:11:49.674] I: 198296 [EM]??1 [E:56606r S:0 M:257592810] (U) Msg Retransmission to 0:0000000000000000 in 2069ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:11:49.688] I: 198311 [SC]SecureSession[0x20005520, LSID:1983]: State change 'kEstablishing' --> 'kActive'
[2026-09-25 09:11:49.696] I: 198319 [IN]CASE Session established to peer: <000000000001B669, 3>
[2026-09-25 09:11:49.836] I: 198446 [EM]>>> [E:56607r S:1983 M:129508836] (S) Msg RX from 3:000000000001B669 [20C0] to 0000000000000002 --- Type 0001:02 (IM:ReadRequest) (B:51)
[2026-09-25 09:11:49.846] I: 198466 [EM]<<< [E:56607r S:1983 M:8401818 (Ack:129508836)] (S) Msg TX from 0000000000000002 to 3:000000000001B669 [20C0] [UDP:[fd11:25::eb56:5766:7a4e:d58f]:55979] --- Type 0001:05 (IM:ReportData) (B:70)
[2026-09-25 09:11:49.863] I: 198485 [EM]??1 [E:56607r S:1983 M:8401818] (S) Msg Retransmission to 3:000000000001B669 in 2112ms [State:Active II:500 AI:300 AT:4000]
[2026-09-25 09:11:49.878] I: 198499 [EM]>>> [E:56606r S:0 M:264294569 (Ack:257592810)] (U) Msg RX from 0:C309693323D6A15C [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26)
[2026-09-25 09:11:50.041] I: 198657 [EM]>>> [E:56607r S:1983 M:129508837 (Ack:8401818)] (S) Msg RX from 3:000000000001B669 [20C0] to 0000000000000002 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)

> whether a reboot between decommissioning and recommissioning changes the UniqueID?
yes, Adding a reboot allows the Unique ID to be read correctly.