[2025-07-29 14:40:51.409] 
[2025-07-29 14:40:51.409] uart:~$ *** Booting My Application v23.55.1-2f9996e8c87c ***
[2025-07-29 14:40:51.469] *** Using nRF Connect SDK v2.8.0-a2386bfc8401 ***
[2025-07-29 14:40:51.469] *** Using Zephyr OS v3.7.99-0bc3393fb112 ***
[2025-07-29 14:40:51.469] I: KWIKSET HALO 3 PLUS VERSION: 17.37.01.03
[2025-07-29 14:40:51.469] I: 51 [DL]BLE address: C4:6F:07:DB:A9:AA
[2025-07-29 14:40:51.579] I: No users indexes stored
[2025-07-29 14:40:51.579] I: No stored indexes for credential of type: 1
[2025-07-29 14:40:51.579] I: No stored indexes for credential of type: 2
[2025-07-29 14:40:51.579] I: ========== User Index: 0x01 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.579] I: ========== User Index: 0x02 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.579] I: ========== User Index: 0x03 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.579] I: ========== User Index: 0x04 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.579] I: ========== User Index: 0x05 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.579] I: ========== User Index: 0x06 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.579] I: ========== User Index: 0x07 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.579] I: ========== User Index: 0x08 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.579] I: ========== User Index: 0x09 User ID: 0xffffffff ==========
[2025-07-29 14:40:51.589] I: ========== User Index: 0x0a User ID: 0xffffffff ==========
[2025-07-29 14:40:51.589] I: ========== User Index: 0x0b User ID: 0xffffffff ==========
[2025-07-29 14:40:51.589] I: Board config kwiksetmdb_nrf5340_cpuapp
[2025-07-29 14:40:51.589] I: IMAGE_VERSION 17370103
[2025-07-29 14:40:51.589] I: build time: Jul 29 2025 12:02:01
[2025-07-29 14:40:51.589] I: 158 [DL]CHIP task running
[2025-07-29 14:40:51.589] I: Init CHIP stack
[2025-07-29 14:40:51.589] I: 164 [DL]OpenThread started: OK
[2025-07-29 14:40:51.589] I: 167 [DL]Setting OpenThread device type to SLEEPY END DEVICE
[2025-07-29 14:40:51.589] I: 173 [SWU]DFU_BLEAdvertising_Init
[2025-07-29 14:40:51.999] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-29 14:40:51.999] I: NFC Boot Event PN7642 FW VERSION 17.01.00.02
[2025-07-29 14:40:51.999] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-29 14:40:51.999] I: 
[2025-07-29 14:40:51.999] Boot Event Received
[2025-07-29 14:40:51.999] 
[2025-07-29 14:40:51.999] I: Booted NFC IC in Normal Operation Mode.
[2025-07-29 14:40:51.999] 
[2025-07-29 14:40:51.999] I: 257 [SVR]Subscription persistence not supported
[2025-07-29 14:40:51.999] I: 261 [SVR]Server initializing...
[2025-07-29 14:40:51.999] I: 265 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2025-07-29 14:40:51.999] I: 270 [DMG]AccessControl: initializing
[2025-07-29 14:40:51.999] I: 273 [DMG]Examples::AccessControlDelegate::Init
[2025-07-29 14:40:51.999] I: 278 [DMG]AccessControl: setting
[2025-07-29 14:40:51.999] I: 281 [DMG]DefaultAclStorage: initializing
[2025-07-29 14:40:51.999] I: 285 [DMG]DefaultAclStorage: 0 entries loaded
[2025-07-29 14:40:52.019] E: 289 [IN]IPV6_PKTINFO failed: 109
[2025-07-29 14:40:52.019] I: 295 [ZCL]Using ZAP configuration...
[2025-07-29 14:40:52.019] I: 300 [DMG]AccessControlCluster: initializing
[2025-07-29 14:40:52.019] Unhandled cluster ID: 0x  30
[2025-07-29 14:40:52.019] 
[2025-07-29 14:40:52.019] ===== Attribute Received are: Cluster=30 Attribute=0 Value=0 =====
[2025-07-29 14:40:52.019] I: 314 [ZCL]Emit DSTTableEmpty event [ep=0]
[2025-07-29 14:40:52.019] I: 318 [ZCL]Initiating Admin Commissioning cluster.
[2025-07-29 14:40:52.019] I: 323 [ZCL]Door Lock server initialized
[2025-07-29 14:40:52.019] E: 326 [ZCL]DeviceInfoProvider is not registered
[2025-07-29 14:40:52.019] E: 330 [ZCL]Failed to read calendar type with error: 0x86
[2025-07-29 14:40:52.019] Unhandled cluster ID: 0x   3
[2025-07-29 14:40:52.019] 
[2025-07-29 14:40:52.019] ===== Attribute Received are: Cluster=3 Attribute=1 Value=3 =====
[2025-07-29 14:40:52.029] I: 344 [ZCL]Door Lock cluster initialized at endpoint #1
[2025-07-29 14:40:52.029] ===== Attribute Received are: Cluster=101 Attribute=0 Value=255 =====
[2025-07-29 14:40:52.029] ===== Attribute Received are: Cluster=101 Attribute=2 Value=1 =====
[2025-07-29 14:40:52.029] ===== Attribute Received are: Cluster=101 Attribute=1 Value=0 =====
[2025-07-29 14:40:52.029] ===== Attribute Received are: Cluster=101 Attribute=11 Value=11 =====
[2025-07-29 14:40:52.029] ===== Attribute Received are: Cluster=101 Attribute=12 Value=35 =====
[2025-07-29 14:40:52.029] ===== Attribute Received are: Cluster=101 Attribute=13 Value=35 =====
[2025-07-29 14:40:52.029] ===== Attribute Received are: Cluster=101 Attribute=1c Value=35 =====
[2025-07-29 14:40:52.029] ===== Attribute Received are: Cluster=101 Attribute=19 Value=80 =====
[2025-07-29 14:40:52.029] I: 398 [DIS]Updating services using commissioning mode 0
[2025-07-29 14:40:52.029] E: 403 [DIS]Failed to remove advertised services: 3
[2025-07-29 14:40:52.056] E: 407 [DIS]Failed to finalize service update: 3
[2025-07-29 14:40:52.056] I: 412 [IN]CASE Server enabling CASE session setups
[2025-07-29 14:40:52.056] I: 417 [SVR]Joining Multicast groups
[2025-07-29 14:40:52.056] I: 420 [SVR]Server Listening...
[2025-07-29 14:40:52.056] I: 423 [DL]Device Configuration:
[2025-07-29 14:40:52.056] I: 426 [DL]  Serial Number: 1789AE57B32427844F
[2025-07-29 14:40:52.056] I: 430 [DL]  Vendor Id: 5153 (0x1421)
[2025-07-29 14:40:52.056] I: 433 [DL]  Product Id: 66 (0x42)
[2025-07-29 14:40:52.056] I: Get product name B, len 0
[2025-07-29 14:40:52.056] I: 439 [DL]  Product Name: B
[2025-07-29 14:40:52.056] I: 442 [DL]  Hardware Version: 1
[2025-07-29 14:40:52.056] I: 445 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 75655451
[2025-07-29 14:40:52.056] I: 450 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 776 (0x308)
[2025-07-29 14:40:52.056] I: 456 [DL]  Manufacturing Date: 2025-07-24
[2025-07-29 14:40:52.064] I: 460 [DL]  Device Type: 10 (0xA)
[2025-07-29 14:40:52.064] I: 463 [SVR]SetupQRCode: [MT:-QWJ08DB00.I2N6SM10]
[2025-07-29 14:40:52.064] I: 468 [SVR]Copy/paste the below URL in a browser to see the QR Code:
[2025-07-29 14:40:52.064] I: 474 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-QWJ08DB00.I2N6SM10
[2025-07-29 14:40:52.064] I: 483 [SVR]Manual pairing code: [05967546175]
[2025-07-29 14:40:52.064] I: STM32 device number: 
[2025-07-29 14:40:52.064] I: 31 37 38 39 41 45 35 37 |1789AE57
[2025-07-29 14:40:52.064] I: 42 33 32 34 32 37 38 34 |B3242784
[2025-07-29 14:40:52.064] I: 34 46                   |4F      
[2025-07-29 14:40:52.064] I: SKU number: 
[2025-07-29 14:40:52.069] I: 4b 31 37 2d 30 31       |K17-01  
[2025-07-29 14:40:52.069] I: WO number: 
[2025-07-29 14:40:52.069] I: 30 30 30 30 30 30 30 30 |00000000
[2025-07-29 14:40:52.069] I: 30                      |0       
[2025-07-29 14:40:52.089] I: Manuf Date: 
[2025-07-29 14:40:52.089] I: 32 30 32 35 2d 30 37 2d |2025-07-
[2025-07-29 14:40:52.089] I: 32 34 00 00 00 00       |24....  
[2025-07-29 14:40:52.089] I: Prod config length 6
[2025-07-29 14:40:52.089] I: Product Config: 
[2025-07-29 14:40:52.089] I: 30 78 30 30 30 31       |0x0001  
[2025-07-29 14:40:52.089] I: Prod Config Read 1
[2025-07-29 14:40:52.089] I: User intend flow enabled, set commissioning flow to kUserActionRequired
[2025-07-29 14:40:52.089] I: Factory Data Version length 2
[2025-07-29 14:40:52.089] I: Factory Data Ver: 
[2025-07-29 14:40:52.089] I: 30 31                   |01      
[2025-07-29 14:40:52.089] I: Payload value in string format: MT:-QWJ04TC00.I2N60Q4P0ILT70VYYR1JFSK14YDB0-0LJ1-0LJ1-0LJ1IHLC0AUZL1XIKJ17AZL1UV700CXYR1K6Y12NNZR1YC-L1-2ZR1OADO1KB40
[2025-07-29 14:40:52.089] I: Pairing Code value in string format: 459675461705153000660
[2025-07-29 14:40:52.089] I: ============== Updating product finish and color to 15, 2, product Name Halo Select Plus ==============
[2025-07-29 14:40:52.109] E: 574 [DL]Long dispatch time: 413 ms, for event type 2
[2025-07-29 14:40:52.109] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-29 14:40:52.139] I: Lock State Event
[2025-07-29 14:40:52.139] I: Received response of command id 10
[2025-07-29 14:40:52.139] I: Received Lock State event, lock st: 12
[2025-07-29 14:40:52.139] I: Found matching nordic source of operation 0
[2025-07-29 14:40:52.139] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 14:40:52.139] I: Unlock action completed
[2025-07-29 14:40:52.139] I: Updating LockState attribute
[2025-07-29 14:40:52.139] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 14:40:53.549] I: Syncing up on message 9a
[2025-07-29 14:40:53.549] I: STM32 counter to 1
[2025-07-29 14:40:53.609] I: BLE Device ID: 2784
[2025-07-29 14:40:53.609] I: Device is provisioned
[2025-07-29 14:40:53.609] I: network state 0
[2025-07-29 14:40:53.609] E: Sending UART cmd(3) st 0
[2025-07-29 14:40:53.609] I: BLE Name set: HU:2784 errCode: 0
[2025-07-29 14:40:53.609] I: Received response of command id 9a
[2025-07-29 14:40:53.609] I: Command 0x9A Received
[2025-07-29 14:40:53.609] I: Received DC Eco Config REQ
[2025-07-29 14:40:53.609] I: DC Eco Config Resp
[2025-07-29 14:40:53.609] I: Received DC eco config req
[2025-07-29 14:40:53.609] I: 80 72 03 00 10 00 50 e0 |.r....P.
[2025-07-29 14:40:53.609] I: c5 ba                   |..      
[2025-07-29 14:40:53.619] E: Sending UART cmd(72) st 0
[2025-07-29 14:40:53.759] I: General Lock Setting event
[2025-07-29 14:40:53.809] I: Received response of command id 20
[2025-07-29 14:40:53.809] I: Received Lock General Setting event
[2025-07-29 14:40:53.809] I: Sound Volume Attribute Update, sound volume 1
[2025-07-29 14:40:53.809] SoundVolume attribute change
[2025-07-29 14:40:53.809] 
[2025-07-29 14:40:53.809] I: == Sound Volume Attribute Update Callback, sound volume 2 ==
[2025-07-29 14:40:53.809] I: No change in sound volume, return
[2025-07-29 14:40:53.809] ===== Attribute Received are: Cluster=101 Attribute=24 Value=2 =====
[2025-07-29 14:40:53.809] I: Matter Not Enabled do not set
[2025-07-29 14:40:53.896] I: Firmware Attribute event
[2025-07-29 14:40:53.896] I: Received response of command id 30
[2025-07-29 14:40:53.949] I: Hardware Attribute event
[2025-07-29 14:40:53.949] I: Received response of command id 31
[2025-07-29 14:40:53.999] I: Operating mode event
[2025-07-29 14:40:53.999] I: Received response of command id 5
[2025-07-29 14:40:54.029] I: Received Lock Op Mode Event, mode 10, App state 10
[2025-07-29 14:40:54.029] I: Lock Current Mode : 10, Lock Current State = 10
[2025-07-29 14:40:54.029] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:40:54.029] I: Set Kwikset Lock App State 16
[2025-07-29 14:40:54.029] I: Matter enabled state 0
[2025-07-29 14:40:54.029] I: Matter is disabled
[2025-07-29 14:40:54.159] I: Battery Info event
[2025-07-29 14:40:54.159] I: Received response of command id 51
[2025-07-29 14:40:54.159] I: Received Battery info event
[2025-07-29 14:40:54.159] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 14:40:54.159] Unhandled cluster ID: 0x  2f
[2025-07-29 14:40:54.159] 
[2025-07-29 14:40:54.159] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 14:40:54.159] Unhandled cluster ID: 0x  2f
[2025-07-29 14:40:54.159] 
[2025-07-29 14:40:54.159] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 14:40:54.239] I: System info event
[2025-07-29 14:40:54.239] I: Received System Info Event
[2025-07-29 14:40:54.259] W: Time invalid, set time
[2025-07-29 14:40:54.259] I: Get system time
[2025-07-29 14:40:54.259] I: System Real time in seconds 373663017
[2025-07-29 14:40:54.259] I: Time sync status flag 0
[2025-07-29 14:40:54.259] E: Time not sync, keep default value
[2025-07-29 14:40:54.289] I: System init event
[2025-07-29 14:40:54.339] I: Received response of command id 3
[2025-07-29 14:40:54.339] I: Update sync timer
[2025-07-29 14:40:54.339] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-29 14:40:54.339] I: Lock Current Mode : 10, Lock Current State = 10
[2025-07-29 14:40:54.339] I: Received Data: 
[2025-07-29 14:40:54.339] E: PAN PACKET(TLV16) CRC VALIDATION FAILED 11 b
[2025-07-29 14:40:54.339] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-29 14:40:54.339] I: STM Pending =0, Redpine Pending = 0
[2025-07-29 14:40:54.449] I: Count = 0
[2025-07-29 14:40:54.449] I: BLE-OTA: No pending image transfers
[2025-07-29 14:40:54.449] I: OTA STAGE = ff
[2025-07-29 14:40:54.449] I: OTA Stage Change from (ff)->(10)
[2025-07-29 14:40:54.814] I: All message synced.
[2025-07-29 14:41:00.299] I: System info event
[2025-07-29 14:41:00.299] I: Received System Info Event
[2025-07-29 14:41:00.299] I: Time is set in STM
[2025-07-29 14:41:38.489] I: Updated ota meta data
[2025-07-29 14:41:38.489] I: Operating Mode Command: Mode:10, State:34
[2025-07-29 14:41:38.489] E: Sending UART cmd(5) st 0
[2025-07-29 14:41:38.539] I: Operating mode event
[2025-07-29 14:41:38.539] I: Received response of command id 5
[2025-07-29 14:41:38.539] I: Received Lock Op Mode Event, mode 10, App state 34
[2025-07-29 14:41:38.539] I: Lock Current Mode : 10, Lock Current State = 34
[2025-07-29 14:41:38.539] I: STM32 HALO APP STATE IS BLE OTAU TRANSFER
[2025-07-29 14:41:38.539] E: Sending UART cmd(9e) st 0
[2025-07-29 14:41:38.539] I: BLE Name set: HU:2784 errCode: 0
[2025-07-29 14:41:38.539] I: 47119 [SWU]SMP BLE advertising started
[2025-07-29 14:41:38.539] I: 47122 [DL]DFU over SMP started
[2025-07-29 14:41:38.539] I: OTA Stage Change from (10)->(11)
[2025-07-29 14:41:38.539] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:41:38.539] I: Set Kwikset Lock App State 52
[2025-07-29 14:41:38.539] I: Matter is disabled
[2025-07-29 14:41:54.869] I: 63476 [DL]Current number of connections: 1/1
[2025-07-29 14:41:54.889] I: BLE Connected
[2025-07-29 14:41:55.119] I: 63705 [DL]Current number of connections: 0/1
[2025-07-29 14:41:55.119] I: BLE Disconnected: 13
[2025-07-29 14:41:58.959] I: 67559 [DL]Current number of connections: 1/1
[2025-07-29 14:41:58.959] I: BLE Connected
[2025-07-29 14:41:59.179] I: 67786 [DL]DFU Image upload started
[2025-07-29 14:42:00.019] I: Connection parameters updated.
[2025-07-29 14:42:00.019]  interval: 9, latency: 0, timeout: 42
[2025-07-29 14:42:09.189] I: OTA Stage Change from (11)->(12)
[2025-07-29 14:42:09.189] I: 77774 [DL]Image 0 download completed successfully
[2025-07-29 14:42:09.220] I: 77801 [DL]Current number of connections: 0/1
[2025-07-29 14:42:09.220] I: 77805 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:42:09.220] I: BLE Disconnected: 13
[2025-07-29 14:42:20.979] I: 89568 [DL]Current number of connections: 1/1
[2025-07-29 14:42:20.979] I: BLE Connected
[2025-07-29 14:42:21.209] I: 89811 [DL]DFU Image upload started
[2025-07-29 14:42:22.049] I: Connection parameters updated.
[2025-07-29 14:42:22.049]  interval: 9, latency: 0, timeout: 42
[2025-07-29 14:42:22.049] E: No available ACL buffers!
[2025-07-29 14:42:22.049] E: Unexpected first L2CAP frame
[2025-07-29 14:43:54.839] I: OTA Stage Change from (12)->(13)
[2025-07-29 14:43:54.839] I: 183429 [DL]Image 1 download completed successfully
[2025-07-29 14:43:54.839] I: 183446 [DL]Current number of connections: 0/1
[2025-07-29 14:43:54.859] I: 183451 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:43:54.859] I: BLE Disconnected: 13
[2025-07-29 14:44:01.999] I: 190599 [DL]Current number of connections: 1/1
[2025-07-29 14:44:02.009] I: BLE Connected
[2025-07-29 14:44:02.239] I: 190834 [DL]DFU Image upload started
[2025-07-29 14:44:03.059] I: Connection parameters updated.
[2025-07-29 14:44:03.059]  interval: 9, latency: 0, timeout: 42
[2025-07-29 14:46:21.800] I: OTA Stage Change from (13)->(14)
[2025-07-29 14:46:21.819] I: 330409 [DL]Image 2 download completed successfully
[2025-07-29 14:46:21.849] I: 330433 [DL]Current number of connections: 0/1
[2025-07-29 14:46:21.849] I: 330437 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:46:21.849] I: BLE Disconnected: 13
[2025-07-29 14:46:29.500] I: 338089 [DL]Current number of connections: 1/1
[2025-07-29 14:46:29.500] I: BLE Connected
[2025-07-29 14:46:29.739] I: 338323 [DL]Current number of connections: 0/1
[2025-07-29 14:46:29.739] I: BLE Disconnected: 13
[2025-07-29 14:46:33.569] I: 342155 [DL]Current number of connections: 1/1
[2025-07-29 14:46:33.569] I: BLE Connected
[2025-07-29 14:46:33.779] I: 342368 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-29 14:46:33.799] I: 342403 [DL]Current number of connections: 0/1
[2025-07-29 14:46:33.817] I: BLE Disconnected: 13
[2025-07-29 14:46:40.720] I: 349304 [DL]Current number of connections: 1/1
[2025-07-29 14:46:40.720] I: BLE Connected
[2025-07-29 14:46:40.940] I: 349524 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-29 14:46:40.956] I: 349558 [DL]Current number of connections: 0/1
[2025-07-29 14:46:40.970] I: BLE Disconnected: 13
[2025-07-29 14:46:48.379] I: 356968 [DL]Current number of connections: 1/1
[2025-07-29 14:46:48.379] I: BLE Connected
[2025-07-29 14:46:48.569] I: STM Pending =0, Redpine Pending = 0
[2025-07-29 14:46:48.679] I: Count = 4
[2025-07-29 14:46:48.679] I: dfu_header_data.image_count: 4
[2025-07-29 14:46:49.429] I: Connection parameters updated.
[2025-07-29 14:46:49.429]  interval: 9, latency: 0, timeout: 42
[2025-07-29 14:46:49.560] I: IMG Integrity Verified Successfully: 0
[2025-07-29 14:46:52.520] I: IMG Integrity Verified Successfully: 1
[2025-07-29 14:46:52.599] I: IMG Integrity Verified Successfully: 2
[2025-07-29 14:46:52.909] I: IMG Integrity Verified Successfully: 3
[2025-07-29 14:46:52.909] I: OTA Bundle(STM32 + RS9116 + PN76) image integrity Verified
[2025-07-29 14:46:52.909] I: OTA Stage Change from (14)->(30)
[2025-07-29 14:46:53.020] I: Updated ota meta data
[2025-07-29 14:46:53.020] I: Operating Mode Command: Mode:10, State:31
[2025-07-29 14:46:53.020] E: Sending UART cmd(5) st 0
[2025-07-29 14:46:53.020] I: Operating mode event
[2025-07-29 14:46:53.062] I: Received response of command id 5
[2025-07-29 14:46:53.062] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-29 14:46:53.062] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:46:53.062] I: STM OTAU Pending: Reset Nordic Triggered
[2025-07-29 14:46:53.062] I: OTA Stage Change from (30)->(30)
[2025-07-29 14:46:53.062] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:46:53.062] I: Set Kwikset Lock App State 49
[2025-07-29 14:46:53.062] I: Matter is disabled
[2025-07-29 14:46:53.100] I: 361692 [DL]Current number of connections: 0/1
[2025-07-29 14:46:53.100] I: BLE Disconnected: 13
[2025-07-29 14:47:38.129] 
[2025-07-29 14:47:38.129] 
[2025-07-29 14:47:38.129] uart:~$ *** Booting My Application v23.49.0-de86e88ec64e ***
[2025-07-29 14:47:38.179] *** Using nRF Connect SDK v2.7.0-5cb85570ca43 ***
[2025-07-29 14:47:38.179] *** Using Zephyr OS v3.6.99-100befc70c74 ***
[2025-07-29 14:47:38.179] I: KWIKSET HALO 3 PLUS VERSION: 17.31.00.02
[2025-07-29 14:47:38.179] I: 51 [DL]BLE address: D8:35:74:34:40:FA
[2025-07-29 14:47:38.309] I: No users indexes stored
[2025-07-29 14:47:38.309] I: No stored indexes for credential of type: 1
[2025-07-29 14:47:38.309] I: No stored indexes for credential of type: 2
[2025-07-29 14:47:38.309] I: No stored indexes for credential of type: 3
[2025-07-29 14:47:38.309] I: ========== User Index: 0x01 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.309] I: ========== User Index: 0x02 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.309] I: ========== User Index: 0x03 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.309] I: ========== User Index: 0x04 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.309] I: ========== User Index: 0x05 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.309] I: ========== User Index: 0x06 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.309] I: ========== User Index: 0x07 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.309] I: ========== User Index: 0x08 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.339] I: ========== User Index: 0x09 User ID: 0xffffffff ==========
[2025-07-29 14:47:38.339] I: ========== User Index: 0x0a User ID: 0xffffffff ==========
[2025-07-29 14:47:38.339] I: ========== User Index: 0x0b User ID: 0xffffffff ==========
[2025-07-29 14:47:38.339] I: Board config kwiksetmdb_nrf5340_cpuapp
[2025-07-29 14:47:38.339] I: IMAGE_VERSION 17310002
[2025-07-29 14:47:38.339] I: build time: Jun 18 2025 10:48:56
[2025-07-29 14:47:38.339] I: 162 [DL]CHIP task running
[2025-07-29 14:47:38.339] I: Init CHIP stack
[2025-07-29 14:47:38.339] I: 168 [DL]OpenThread started: OK
[2025-07-29 14:47:38.339] I: 171 [DL]Setting OpenThread device type to SLEEPY END DEVICE
[2025-07-29 14:47:38.339] I: 177 [SWU]New firmware image confirmed
[2025-07-29 14:47:38.339] I: 180 [SWU]DFU_BLEAdvertising_Init
[2025-07-29 14:47:38.360] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-29 14:47:38.709] I: NFC Boot Event PN7642 FW VERSION 17.01.00.02
[2025-07-29 14:47:38.709] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-29 14:47:38.709] I: 
[2025-07-29 14:47:38.709] Boot Event Received
[2025-07-29 14:47:38.709] 
[2025-07-29 14:47:38.709] I: Booted NFC IC in Normal Operation Mode.
[2025-07-29 14:47:38.709] 
[2025-07-29 14:47:38.709] I: 264 [SVR]Subscription persistence not supported
[2025-07-29 14:47:38.709] I: 268 [SVR]Server initializing...
[2025-07-29 14:47:38.709] I: 272 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2025-07-29 14:47:38.709] I: 277 [DMG]AccessControl: initializing
[2025-07-29 14:47:38.709] I: 280 [DMG]Examples::AccessControlDelegate::Init
[2025-07-29 14:47:38.709] I: 285 [DMG]AccessControl: setting
[2025-07-29 14:47:38.709] I: 288 [DMG]DefaultAclStorage: initializing
[2025-07-29 14:47:38.709] I: 292 [DMG]DefaultAclStorage: 0 entries loaded
[2025-07-29 14:47:38.709] E: 296 [IN]IPV6_PKTINFO failed: 109
[2025-07-29 14:47:38.729] I: 302 [ZCL]Using ZAP configuration...
[2025-07-29 14:47:38.729] I: 307 [DMG]AccessControlCluster: initializing
[2025-07-29 14:47:38.729] ===== Attribute Received are: Cluster=30 Attribute=0 Value=0 =====
[2025-07-29 14:47:38.729] I: 319 [ZCL]Emit DSTTableEmpty event [ep=0]
[2025-07-29 14:47:38.729] I: 322 [ZCL]Initiating Admin Commissioning cluster.
[2025-07-29 14:47:38.729] I: 327 [ZCL]Door Lock server initialized
[2025-07-29 14:47:38.729] E: 331 [ZCL]DeviceInfoProvider is not registered
[2025-07-29 14:47:38.729] E: 335 [ZCL]Failed to read calendar type with error: 0x86
[2025-07-29 14:47:38.729] ===== Attribute Received are: Cluster=3 Attribute=1 Value=3 =====
[2025-07-29 14:47:38.729] I: 346 [ZCL]Door Lock cluster initialized at endpoint #1
[2025-07-29 14:47:38.729] ===== Attribute Received are: Cluster=101 Attribute=0 Value=255 =====
[2025-07-29 14:47:38.739] ===== Attribute Received are: Cluster=101 Attribute=2 Value=1 =====
[2025-07-29 14:47:38.749] ===== Attribute Received are: Cluster=101 Attribute=1 Value=0 =====
[2025-07-29 14:47:38.749] ===== Attribute Received are: Cluster=101 Attribute=11 Value=11 =====
[2025-07-29 14:47:38.749] ===== Attribute Received are: Cluster=101 Attribute=12 Value=35 =====
[2025-07-29 14:47:38.749] ===== Attribute Received are: Cluster=101 Attribute=13 Value=35 =====
[2025-07-29 14:47:38.749] ===== Attribute Received are: Cluster=101 Attribute=1c Value=35 =====
[2025-07-29 14:47:38.749] ===== Attribute Received are: Cluster=101 Attribute=19 Value=80 =====
[2025-07-29 14:47:38.749] I: 400 [DIS]Updating services using commissioning mode 0
[2025-07-29 14:47:38.749] E: 405 [DIS]Failed to remove advertised services: 3
[2025-07-29 14:47:38.749] E: 409 [DIS]Failed to finalize service update: 3
[2025-07-29 14:47:38.749] I: 414 [IN]CASE Server enabling CASE session setups
[2025-07-29 14:47:38.749] I: 419 [SVR]Joining Multicast groups
[2025-07-29 14:47:38.770] I: 422 [SVR]Server Listening...
[2025-07-29 14:47:38.770] I: 425 [DL]Device Configuration:
[2025-07-29 14:47:38.770] I: 428 [DL]  Serial Number: 1789AE57B32427844F
[2025-07-29 14:47:38.770] I: 432 [DL]  Vendor Id: 5153 (0x1421)
[2025-07-29 14:47:38.770] I: 435 [DL]  Product Id: 66 (0x42)
[2025-07-29 14:47:38.770] I: Get product name B, len 0
[2025-07-29 14:47:38.770] I: 441 [DL]  Product Name: B
[2025-07-29 14:47:38.770] I: 444 [DL]  Hardware Version: 1
[2025-07-29 14:47:38.770] I: 447 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 75655451
[2025-07-29 14:47:38.770] I: 452 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 776 (0x308)
[2025-07-29 14:47:38.770] I: 458 [DL]  Manufacturing Date: 2025-07-24
[2025-07-29 14:47:38.770] I: 462 [DL]  Device Type: 10 (0xA)
[2025-07-29 14:47:38.770] I: 465 [SVR]SetupQRCode: [MT:-QWJ08DB00.I2N6SM10]
[2025-07-29 14:47:38.770] I: 470 [SVR]Copy/paste the below URL in a browser to see the QR Code:
[2025-07-29 14:47:38.796] I: 476 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-QWJ08DB00.I2N6SM10
[2025-07-29 14:47:38.796] I: 485 [SVR]Manual pairing code: [05967546175]
[2025-07-29 14:47:38.796] I: STM32 device number: 
[2025-07-29 14:47:38.796] I: 31 37 38 39 41 45 35 37 |1789AE57
[2025-07-29 14:47:38.796] I: 42 33 32 34 32 37 38 34 |B3242784
[2025-07-29 14:47:38.796] I: 34 46                   |4F      
[2025-07-29 14:47:38.796] I: SKU number: 
[2025-07-29 14:47:38.796] I: 4b 31 37 2d 30 31       |K17-01  
[2025-07-29 14:47:38.796] I: WO number: 
[2025-07-29 14:47:38.796] I: 30 30 30 30 30 30 30 30 |00000000
[2025-07-29 14:47:38.796] I: 30                      |0       
[2025-07-29 14:47:38.796] I: Manuf Date: 
[2025-07-29 14:47:38.796] I: 32 30 32 35 2d 30 37 2d |2025-07-
[2025-07-29 14:47:38.796] I: 32 34 00 00 00 00       |24....  
[2025-07-29 14:47:38.796] I: Prod config length 6
[2025-07-29 14:47:38.810] I: Product Config: 
[2025-07-29 14:47:38.810] I: 30 78 30 30 30 31       |0x0001  
[2025-07-29 14:47:38.810] I: Prod Config Read 1
[2025-07-29 14:47:38.810] I: User intend flow enabled, set commissioning flow to kUserActionRequired
[2025-07-29 14:47:38.810] I: Factory Data Version length 2
[2025-07-29 14:47:38.810] I: Factory Data Ver: 
[2025-07-29 14:47:38.810] I: 30 31                   |01      
[2025-07-29 14:47:38.810] I: Payload value in string format: MT:-QWJ04TC00.I2N60Q4P0ILT70VYYR1JFSK14YDB0-0LJ1-0LJ1-0LJ1IHLC0AUZL1XIKJ17AZL1UV700CXYR1K6Y12NNZR1YC-L1-2ZR1OADO1KB40
[2025-07-29 14:47:38.810] I: Pairing Code value in string format: 459675461705153000660
[2025-07-29 14:47:38.810] I: ============== Updating product finish and color to 15, 2, product Name Halo Select Plus ==============
[2025-07-29 14:47:38.810] E: 576 [DL]Long dispatch time: 411 ms, for event type 2
[2025-07-29 14:47:38.810] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-29 14:47:40.309] I: Syncing up on message 9a
[2025-07-29 14:47:40.309] I: STM32 counter to 1
[2025-07-29 14:47:40.309] I: BLE Device ID: 2784
[2025-07-29 14:47:40.309] I: Device is provisioned
[2025-07-29 14:47:40.309] I: network state 0
[2025-07-29 14:47:40.309] E: Sending UART cmd(3) st 0
[2025-07-29 14:47:40.309] I: BLE Name set: HU:2784 errCode: 0
[2025-07-29 14:47:40.309] I: Received response of command id 9a
[2025-07-29 14:47:40.309] I: Command 0x9A Received
[2025-07-29 14:47:40.309] I: Firmware Attribute event
[2025-07-29 14:47:40.309] I: Received response of command id 30
[2025-07-29 14:47:40.339] I: Received DC Eco Config REQ
[2025-07-29 14:47:40.339] I: DC Eco Config Resp
[2025-07-29 14:47:40.339] I: Received DC eco config req
[2025-07-29 14:47:40.339] I: 80 72 03 00 10 00 04 1b |.r......
[2025-07-29 14:47:40.339] I: 17 05                   |..      
[2025-07-29 14:47:40.339] E: Sending UART cmd(72) st 0
[2025-07-29 14:47:42.312] I: Syncing up on message 3
[2025-07-29 14:47:42.312] I: Sys init req
[2025-07-29 14:47:42.312] E: Sending UART cmd(3) st 0
[2025-07-29 14:47:42.312] I: System init Response
[2025-07-29 14:47:42.312] I: Received response of command id 3
[2025-07-29 14:47:42.312] I: Update sync timer
[2025-07-29 14:47:42.312] I: Received Sys Init Resp
[2025-07-29 14:47:42.312] I: battery mode 0
[2025-07-29 14:47:42.312] I: battery percentage 5a
[2025-07-29 14:47:42.312] I: battery type 1
[2025-07-29 14:47:42.312] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:47:42.789] I: Syncing up on message 5
[2025-07-29 14:47:42.789] I: Operating mode req
[2025-07-29 14:47:42.840] E: Sending UART cmd(5) st 0
[2025-07-29 14:47:42.840] I: Operating mode response
[2025-07-29 14:47:42.840] I: Received response of command id 5
[2025-07-29 14:47:42.840] I: Received Lock Op Mode Resp, mode 10, App state 31
[2025-07-29 14:47:42.840] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:47:42.840] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:47:42.840] I: Set Kwikset Lock App State 49
[2025-07-29 14:47:42.840] I: Matter is disabled
[2025-07-29 14:47:43.339] I: Syncing up on message 10
[2025-07-29 14:47:43.339] I: Lock state req
[2025-07-29 14:47:43.339] E: Sending UART cmd(10) st 0
[2025-07-29 14:47:43.339] I: Lock State Response
[2025-07-29 14:47:43.339] I: Received response of command id 10
[2025-07-29 14:47:43.339] I: Received Lock State Response, lock st: 12
[2025-07-29 14:47:43.339] I: Found matching nordic source of operation 0
[2025-07-29 14:47:43.339] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 14:47:43.339] I: Unlock action completed
[2025-07-29 14:47:43.339] I: Updating LockState attribute
[2025-07-29 14:47:43.339] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 14:47:43.789] I: Syncing up on message 20
[2025-07-29 14:47:43.830] I: Lock setting req
[2025-07-29 14:47:43.830] E: Sending UART cmd(20) st 0
[2025-07-29 14:47:43.830] I: Lock General Setting Response
[2025-07-29 14:47:43.830] I: Received response of command id 20
[2025-07-29 14:47:43.830] I: Received Lock General Setting resp
[2025-07-29 14:47:43.830] I: Matter Not Enabled do not set
[2025-07-29 14:47:44.290] I: Syncing up on message 51
[2025-07-29 14:47:44.290] I: Battery info req
[2025-07-29 14:47:44.290] E: Sending UART cmd(51) st 0
[2025-07-29 14:47:44.339] I: Received response of command id 51
[2025-07-29 14:47:44.339] I: Received Battery Info resp
[2025-07-29 14:47:44.339] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 14:47:44.339] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 14:47:44.339] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 14:47:44.800] I: All message synced.
[2025-07-29 14:48:08.319] I: STM system init timer expired, System Init Event not received from STM32
[2025-07-29 14:48:08.319] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-29 14:48:08.319] I: STM Pending =1, Redpine Pending = 1
[2025-07-29 14:48:08.319] I: STM Post OTA Pending
[2025-07-29 14:48:08.319] I: Redpine Post OTA Pending
[2025-07-29 14:48:08.319] E: Sending UART cmd(9e) st 0
[2025-07-29 14:48:08.319] I: BLE Name set: HU:2784 errCode: 0
[2025-07-29 14:48:08.329] I: 30191 [SWU]SMP BLE advertising started
[2025-07-29 14:48:08.329] I: 30196 [DL]DFU over SMP started
[2025-07-29 14:48:09.209] I: IMG Integrity Verified Successfully: 0
[2025-07-29 14:48:12.200] I: IMG Integrity Verified Successfully: 1
[2025-07-29 14:48:12.279] I: IMG Integrity Verified Successfully: 2
[2025-07-29 14:48:12.590] I: IMG Integrity Verified Successfully: 3
[2025-07-29 14:48:12.590] I: OTA Stage Change from (ff)->(32)
[2025-07-29 14:48:12.590] I: OTA device_id = 5 : DISCOVERY_REQ
[2025-07-29 14:48:12.669] I: SECURE_STM : IB_DEVICE_DISCOVERY_REQUEST (80) 
[2025-07-29 14:48:12.705] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-29 14:48:12.705] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-29 14:48:12.705] I: STM New OTA Firmware Version = 17 5 4 1b
[2025-07-29 14:48:12.705] I: OTA device_id = 5 : FW_UPDATE_START_REQ
[2025-07-29 14:48:12.705] I: SECURE_STM : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-29 14:48:19.070] I: STM OTA Progress = 10
[2025-07-29 14:48:25.390] I: STM OTA Progress = 20
[2025-07-29 14:48:31.709] I: STM OTA Progress = 30
[2025-07-29 14:48:38.138] I: STM OTA Progress = 40
[2025-07-29 14:48:44.454] I: STM OTA Progress = 50
[2025-07-29 14:48:50.773] I: STM OTA Progress = 60
[2025-07-29 14:48:57.105] I: STM OTA Progress = 70
[2025-07-29 14:49:03.420] I: STM OTA Progress = 80
[2025-07-29 14:49:09.759] I: STM OTA Progress = 90
[2025-07-29 14:49:16.070] I: STM OTA Progress = 100
[2025-07-29 14:49:16.762] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-29 14:49:16.762] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-29 14:49:34.359] I: Sending Sys Init Resp
[2025-07-29 14:49:34.400] I: Device is provisioned
[2025-07-29 14:49:34.400] I: network state 0
[2025-07-29 14:49:34.400] E: Sending UART cmd(3) st 0
[2025-07-29 14:49:34.400] I: Received DC App Config REQ
[2025-07-29 14:49:34.400] I: DC App Config Resp
[2025-07-29 14:49:34.400] I: Received DC config req
[2025-07-29 14:49:34.400] I: 80 70 03 00 10 10 08 00 |.p......
[2025-07-29 14:49:34.400] I: 50 1e                   |P.      
[2025-07-29 14:49:34.400] I: Matter enabled state 0
[2025-07-29 14:49:34.400] I: Get Matter Commission State
[2025-07-29 14:49:34.400] I: network state 0
[2025-07-29 14:49:34.409] I: network state 0
[2025-07-29 14:49:34.409] E: Sending UART cmd(70) st 0
[2025-07-29 14:49:34.470] I: Lock State Event
[2025-07-29 14:49:34.470] I: Received response of command id 10
[2025-07-29 14:49:34.470] I: Received Lock State event, lock st: 12
[2025-07-29 14:49:34.470] I: Found matching nordic source of operation 0
[2025-07-29 14:49:34.470] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 14:49:34.470] I: Unlock action completed
[2025-07-29 14:49:34.470] I: Updating LockState attribute
[2025-07-29 14:49:34.470] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 14:49:34.500] I: Received DC Eco Config REQ
[2025-07-29 14:49:34.500] I: DC Eco Config Resp
[2025-07-29 14:49:34.500] I: Received DC eco config req
[2025-07-29 14:49:34.530] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-29 14:49:34.530] I: c4 1e                   |..      
[2025-07-29 14:49:34.530] E: Sending UART cmd(72) st 0
[2025-07-29 14:49:34.670] I: General Lock Setting event
[2025-07-29 14:49:34.700] I: Received response of command id 20
[2025-07-29 14:49:34.700] I: Received Lock General Setting event
[2025-07-29 14:49:34.700] I: Matter Not Enabled do not set
[2025-07-29 14:49:34.790] I: Firmware Attribute event
[2025-07-29 14:49:34.790] I: Received response of command id 30
[2025-07-29 14:49:34.871] I: Hardware Attribute event
[2025-07-29 14:49:34.871] I: Received response of command id 31
[2025-07-29 14:49:34.950] I: Operating mode event
[2025-07-29 14:49:34.950] I: Received response of command id 5
[2025-07-29 14:49:34.950] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-29 14:49:34.952] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:49:34.952] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:49:34.952] I: Set Kwikset Lock App State 49
[2025-07-29 14:49:34.952] I: Matter is disabled
[2025-07-29 14:49:35.072] I: Battery Info event
[2025-07-29 14:49:35.072] I: Received response of command id 51
[2025-07-29 14:49:35.072] I: Received Battery info event
[2025-07-29 14:49:35.072] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 14:49:35.072] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 14:49:35.072] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 14:49:35.150] I: System info event
[2025-07-29 14:49:35.180] I: Received System Info Event
[2025-07-29 14:49:35.180] W: Time invalid, set time
[2025-07-29 14:49:35.180] I: Get system time
[2025-07-29 14:49:35.180] I: System Real time in seconds 373662943
[2025-07-29 14:49:35.180] I: Time sync status flag 0
[2025-07-29 14:49:35.180] E: Time not sync, keep default value
[2025-07-29 14:49:35.209] I: System init event
[2025-07-29 14:49:35.209] I: Received response of command id 3
[2025-07-29 14:49:35.280] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-29 14:49:35.280] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:49:35.280] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-29 14:49:35.280] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-29 14:49:35.280] I: OTA device_id = 5 : FW_UPDATE_COMPLETE_REQ
[2025-07-29 14:49:35.280] I: SECURE_STM : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-29 14:49:35.280] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-29 14:49:35.280] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-29 14:49:37.720] I: Sending Sys Init Resp
[2025-07-29 14:49:37.720] I: Device is provisioned
[2025-07-29 14:49:37.720] I: network state 0
[2025-07-29 14:49:37.720] E: Sending UART cmd(3) st 0
[2025-07-29 14:49:37.720] I: Received DC App Config REQ
[2025-07-29 14:49:37.720] I: DC App Config Resp
[2025-07-29 14:49:37.720] I: Received DC config req
[2025-07-29 14:49:37.720] I: 80 70 03 00 10 10 04 1b |.p......
[2025-07-29 14:49:37.720] I: 00 62                   |.b      
[2025-07-29 14:49:37.720] I: Matter enabled state 0
[2025-07-29 14:49:37.720] I: Get Matter Commission State
[2025-07-29 14:49:37.720] I: network state 0
[2025-07-29 14:49:37.729] I: network state 0
[2025-07-29 14:49:37.729] E: Sending UART cmd(70) st 0
[2025-07-29 14:49:37.789] I: Lock State Event
[2025-07-29 14:49:37.789] I: Received response of command id 10
[2025-07-29 14:49:37.789] I: Received Lock State event, lock st: 12
[2025-07-29 14:49:37.789] I: Found matching nordic source of operation 0
[2025-07-29 14:49:37.789] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 14:49:37.789] I: Unlock action completed
[2025-07-29 14:49:37.789] I: Updating LockState attribute
[2025-07-29 14:49:37.789] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 14:49:37.820] I: Received DC Eco Config REQ
[2025-07-29 14:49:37.820] I: DC Eco Config Resp
[2025-07-29 14:49:37.850] I: Received DC eco config req
[2025-07-29 14:49:37.850] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-29 14:49:37.850] I: c4 62                   |.b      
[2025-07-29 14:49:37.850] E: Sending UART cmd(72) st 0
[2025-07-29 14:49:38.020] I: General Lock Setting event
[2025-07-29 14:49:38.020] I: Received response of command id 20
[2025-07-29 14:49:38.020] I: Received Lock General Setting event
[2025-07-29 14:49:38.020] I: Matter Not Enabled do not set
[2025-07-29 14:49:38.133] I: Firmware Attribute event
[2025-07-29 14:49:38.133] I: Received response of command id 30
[2025-07-29 14:49:38.190] I: Hardware Attribute event
[2025-07-29 14:49:38.190] I: Received response of command id 31
[2025-07-29 14:49:38.260] I: Operating mode event
[2025-07-29 14:49:38.260] I: Received response of command id 5
[2025-07-29 14:49:38.260] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-29 14:49:38.260] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:49:38.260] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:49:38.260] I: Set Kwikset Lock App State 49
[2025-07-29 14:49:38.260] I: Matter is disabled
[2025-07-29 14:49:38.389] I: Battery Info event
[2025-07-29 14:49:38.389] I: Received response of command id 51
[2025-07-29 14:49:38.389] I: Received Battery info event
[2025-07-29 14:49:38.389] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 14:49:38.389] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 14:49:38.389] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 14:49:38.470] I: System info event
[2025-07-29 14:49:38.500] I: Received System Info Event
[2025-07-29 14:49:38.500] W: Time invalid, set time
[2025-07-29 14:49:38.500] I: Get system time
[2025-07-29 14:49:38.500] I: System Real time in seconds 373662943
[2025-07-29 14:49:38.500] I: Time sync status flag 0
[2025-07-29 14:49:38.500] E: Time not sync, keep default value
[2025-07-29 14:49:38.530] I: System init event
[2025-07-29 14:49:38.530] I: Received response of command id 3
[2025-07-29 14:49:38.574] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-29 14:49:38.574] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:49:38.574] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-29 14:49:38.574] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-29 14:49:38.574] I: STM New OTA Firmware Version = 17 5 4 1b
[2025-07-29 14:49:38.574] I: STM Secure OTA Successful
[2025-07-29 14:49:38.680] I: Cleared STM OTA Meta Data
[2025-07-29 14:49:38.680] I: OTA Stage Change from (32)->(33)
[2025-07-29 14:49:38.680] I: Redpine OTA started
[2025-07-29 14:49:38.680] I: OTA Stage Change from (33)->(34)
[2025-07-29 14:49:38.680] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-29 14:49:45.670] I: STM Reset Count 0
[2025-07-29 14:49:45.700] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-29 14:49:45.700] I: STM_QSPI : IB_DEVICE_DISCOVERY_REQUEST (80)
[2025-07-29 14:49:45.700] I: OTA device_id = 4 : FW_VERSION_REQ
[2025-07-29 14:49:45.700] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-29 14:49:45.700] I: Redpine Current Firmware Version: 2.c.0.3
[2025-07-29 14:49:45.730] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-29 14:49:45.730] I: Skip Redpine OTA, Older OTA Version Request Received
[2025-07-29 14:49:45.810] I: Clear Redpine OTA Meta Data
[2025-07-29 14:49:45.842] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-29 14:49:45.842] I: STM Pending =2, Redpine Pending = 2
[2025-07-29 14:49:45.842] I: PN76 IMG 1 Post OTA Pending
[2025-07-29 14:49:45.842] E: Sending UART cmd(9e) st 0
[2025-07-29 14:49:45.842] I: 127713 [SWU]Software update is already enabled
[2025-07-29 14:49:45.920] I: IMG Integrity Verified Successfully: 2
[2025-07-29 14:49:46.210] I: IMG Integrity Verified Successfully: 3
[2025-07-29 14:49:46.249] I: OTA Stage Change from (34)->(3a)
[2025-07-29 14:49:46.249] I: PN76_IMG1_DEVICE_DFU_MULTI_IMG_ID
[2025-07-29 14:49:46.249] I: PN76_IMG Update from OTA Task Event
[2025-07-29 14:49:46.249] I: 
[2025-07-29 14:49:46.249] 
[2025-07-29 14:49:46.249] --------------- UPDATING PN7642 NXP FIRMWARE --------------------
[2025-07-29 14:49:46.249] 
[2025-07-29 14:49:46.249] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-29 14:49:46.290] I: pNXPFWInfo->img_offset = 0x35149a
[2025-07-29 14:49:46.299] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-29 14:49:46.300] I: Reading version of firmware in QSPI flash: MetaData 0x3f60217
[2025-07-29 14:49:46.300] I: NXP FW Version 2 f6 : 2 f6
[2025-07-29 14:49:46.300] I: PN76 NXP FW VERSION IS EQUAL
[2025-07-29 14:49:46.300] I: 
[2025-07-29 14:49:46.300] PN7642 Firmware of type 0 Successfully Updated !!!
[2025-07-29 14:49:46.423] I: Cleared PN76 Img1 OTA Meta Data
[2025-07-29 14:49:46.423] I: OTA Stage Change from (3a)->(3a)
[2025-07-29 14:49:46.423] I: PN76_IMG2_DEVICE_DFU_MULTI_IMG_ID
[2025-07-29 14:49:46.423] I: PN76_IMG Update from OTA Task Event
[2025-07-29 14:49:46.423] I: 
[2025-07-29 14:49:46.423] 
[2025-07-29 14:49:46.423] --------------- UPDATING PN7642 APPLICATION FIRMWARE -------------
[2025-07-29 14:49:46.423] 
[2025-07-29 14:49:46.423] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-29 14:49:46.460] I: pCustAppFWInfo->img_offset = 0x35c28c
[2025-07-29 14:49:46.460] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-29 14:49:46.460] I: Reading version of firmware in QSPI flash: MetaData 0x3f60217
[2025-07-29 14:49:46.460] I: PN76 NXP APP FW VERSION IS HIGHER
[2025-07-29 14:49:46.766] I: ----> PN7642 OTA Progress = 10 %
[2025-07-29 14:49:47.030] I: ----> PN7642 OTA Progress = 20 %
[2025-07-29 14:49:47.290] I: ----> PN7642 OTA Progress = 30 %
[2025-07-29 14:49:47.550] I: ----> PN7642 OTA Progress = 40 %
[2025-07-29 14:49:47.821] I: ----> PN7642 OTA Progress = 50 %
[2025-07-29 14:49:48.070] I: ----> PN7642 OTA Progress = 60 %
[2025-07-29 14:49:48.330] I: ----> PN7642 OTA Progress = 70 %
[2025-07-29 14:49:48.604] I: ----> PN7642 OTA Progress = 80 %
[2025-07-29 14:49:48.860] I: ----> PN7642 OTA Progress = 90 %
[2025-07-29 14:49:49.110] I: ----> PN7642 OTA Progress = 100 %
[2025-07-29 14:49:49.140] I: Whole pn7642 FW Image downloaded ....
[2025-07-29 14:49:49.140] I: 
[2025-07-29 14:49:49.140] 
[2025-07-29 14:49:49.140] I: 
[2025-07-29 14:49:49.140] PN7642 Firmware of type 1 Successfully Updated !!!
[2025-07-29 14:49:49.226] I: Cleared PN76 Img2 OTA Meta Data
[2025-07-29 14:49:49.330] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-29 14:49:49.330] I: NFC Boot Event PN7642 FW VERSION 17.01.00.03
[2025-07-29 14:49:49.330] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-29 14:49:49.330] I: 
[2025-07-29 14:49:49.330] Boot Event Received
[2025-07-29 14:49:49.330] 
[2025-07-29 14:49:49.330] I: Booted NFC IC in Normal Operation Mode.
[2025-07-29 14:49:49.330] 
[2025-07-29 14:49:49.330] I: OTA Stage Change from (3a)->(3b)
[2025-07-29 14:49:49.330] I: post_stm_reset_event : init_pending_ota_update
[2025-07-29 14:49:49.330] I: All pending FW Updates are completed.
[2025-07-29 14:49:49.330] I: STM32 Reset Count = 0
[2025-07-29 14:49:49.330] I: REBOOT_STM: Send STM32 Reboot Command, Count (0)
[2025-07-29 14:49:51.619] I: Sending Sys Init Resp
[2025-07-29 14:49:51.619] I: Device is provisioned
[2025-07-29 14:49:51.660] I: network state 0
[2025-07-29 14:49:51.660] E: Sending UART cmd(3) st 0
[2025-07-29 14:49:51.660] I: Received DC App Config REQ
[2025-07-29 14:49:51.660] I: DC App Config Resp
[2025-07-29 14:49:51.660] I: Received DC config req
[2025-07-29 14:49:51.660] I: 80 70 03 00 10 10 00 03 |.p......
[2025-07-29 14:49:51.660] I: 00 62                   |.b      
[2025-07-29 14:49:51.660] I: Matter enabled state 0
[2025-07-29 14:49:51.660] I: Get Matter Commission State
[2025-07-29 14:49:51.660] I: network state 0
[2025-07-29 14:49:51.660] I: network state 0
[2025-07-29 14:49:51.660] E: Sending UART cmd(70) st 0
[2025-07-29 14:49:51.720] I: Lock State Event
[2025-07-29 14:49:51.720] I: Received response of command id 10
[2025-07-29 14:49:51.720] I: Received Lock State event, lock st: 12
[2025-07-29 14:49:51.720] I: Found matching nordic source of operation 0
[2025-07-29 14:49:51.720] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 14:49:51.720] I: Unlock action completed
[2025-07-29 14:49:51.720] I: Updating LockState attribute
[2025-07-29 14:49:51.720] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 14:49:51.760] I: Received DC Eco Config REQ
[2025-07-29 14:49:51.760] I: DC Eco Config Resp
[2025-07-29 14:49:51.779] I: Received DC eco config req
[2025-07-29 14:49:51.779] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-29 14:49:51.779] I: c4 62                   |.b      
[2025-07-29 14:49:51.779] E: Sending UART cmd(72) st 0
[2025-07-29 14:49:51.930] I: General Lock Setting event
[2025-07-29 14:49:51.952] I: Received response of command id 20
[2025-07-29 14:49:51.952] I: Received Lock General Setting event
[2025-07-29 14:49:51.952] I: Matter Not Enabled do not set
[2025-07-29 14:49:52.050] I: Firmware Attribute event
[2025-07-29 14:49:52.070] I: Received response of command id 30
[2025-07-29 14:49:52.130] I: Hardware Attribute event
[2025-07-29 14:49:52.130] I: Received response of command id 31
[2025-07-29 14:49:52.200] I: Operating mode event
[2025-07-29 14:49:52.200] I: Received response of command id 5
[2025-07-29 14:49:52.200] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-29 14:49:52.200] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:49:52.200] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:49:52.200] I: Set Kwikset Lock App State 49
[2025-07-29 14:49:52.200] I: Matter is disabled
[2025-07-29 14:49:52.320] I: Battery Info event
[2025-07-29 14:49:52.320] I: Received response of command id 51
[2025-07-29 14:49:52.320] I: Received Battery info event
[2025-07-29 14:49:52.320] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 14:49:52.320] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 14:49:52.320] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 14:49:52.400] I: System info event
[2025-07-29 14:49:52.440] I: Received System Info Event
[2025-07-29 14:49:52.440] W: Time invalid, set time
[2025-07-29 14:49:52.440] I: Get system time
[2025-07-29 14:49:52.440] I: System Real time in seconds 373662943
[2025-07-29 14:49:52.440] I: Time sync status flag 0
[2025-07-29 14:49:52.440] E: Time not sync, keep default value
[2025-07-29 14:49:52.500] I: System init event
[2025-07-29 14:49:52.500] I: Received response of command id 3
[2025-07-29 14:49:52.500] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-29 14:49:52.500] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:49:59.329] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-29 14:49:59.329] I: stop_ota_finalization_timer
[2025-07-29 14:49:59.370] I: After OTAU, Redpine Firmware Version: 2.c.0.3
[2025-07-29 14:49:59.370] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-29 14:49:59.370] I: After OTAU, Secure STM Firmware Version: 17 5 4 1b
[2025-07-29 14:49:59.370] I: Send Op Mode command to release Redpine BLE and WiFI
[2025-07-29 14:49:59.370] I: Operating Mode Command: Mode:10, State:f0
[2025-07-29 14:49:59.370] E: Sending UART cmd(5) st 0
[2025-07-29 14:49:59.499] I: Operating mode event
[2025-07-29 14:49:59.499] I: Received response of command id 5
[2025-07-29 14:49:59.499] I: Received Lock Op Mode Event, mode 10, App state 10
[2025-07-29 14:49:59.499] I: Lock Current Mode : 10, Lock Current State = 10
[2025-07-29 14:49:59.499] I: stop_ota_finalization_timer
[2025-07-29 14:49:59.499] I: STM32 HALO APP STATE IS ACTIVATED NORMAL
[2025-07-29 14:49:59.499] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:49:59.499] I: Set Kwikset Lock App State 16
[2025-07-29 14:49:59.510] I: Matter enabled state 0
[2025-07-29 14:49:59.510] I: Matter is disabled
[2025-07-29 14:49:59.510] I: OTA_HOUSEKEEPING
[2025-07-29 14:49:59.510] I: OTA Stage Change from (3b)->(80)
[2025-07-29 14:49:59.510] I: Start Erasing OTA bundle from nRF External Flash
[2025-07-29 14:50:05.050] I: System info event
[2025-07-29 14:50:05.050] I: Received System Info Event
[2025-07-29 14:50:05.069] I: Time is set in STM
[2025-07-29 14:50:08.560] I: STM Boot Up Properly, Stopped STM Reboot Timer
[2025-07-29 14:51:00.062] I: Bundle Image Erased from nRF External Flash: 0
[2025-07-29 14:51:00.139] I: OTAU Completed Successfully
[2025-07-29 14:51:00.260] I: Cleared OTA Meta Data
[2025-07-29 14:51:00.260] I: OTA Stage Change from (80)->(90)
[2025-07-29 14:51:02.259] I: All message synced.
[2025-07-29 14:51:15.240] I: STOP BLE Advertisment
[2025-07-29 14:51:15.270] I: 217136 [DL]DFU over SMP stopped
[2025-07-29 14:51:15.270] E: Sending UART cmd(9e) st 0
[2025-07-29 14:53:57.940] I: Updated ota meta data
[2025-07-29 14:53:57.940] I: Operating Mode Command: Mode:10, State:34
[2025-07-29 14:53:57.940] E: Sending UART cmd(5) st 0
[2025-07-29 14:53:58.000] I: Operating mode event
[2025-07-29 14:53:58.000] I: Received response of command id 5
[2025-07-29 14:53:58.000] I: Received Lock Op Mode Event, mode 10, App state 34
[2025-07-29 14:53:58.000] I: Lock Current Mode : 10, Lock Current State = 34
[2025-07-29 14:53:58.000] I: STM32 HALO APP STATE IS BLE OTAU TRANSFER
[2025-07-29 14:53:58.000] E: Sending UART cmd(9e) st 0
[2025-07-29 14:53:58.000] I: BLE Name set: HU:2784 errCode: 0
[2025-07-29 14:53:58.000] I: 379866 [SWU]SMP BLE advertising started
[2025-07-29 14:53:58.000] I: 379871 [DL]DFU over SMP started
[2025-07-29 14:53:58.000] I: OTA Stage Change from (90)->(11)
[2025-07-29 14:53:58.000] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:53:58.000] I: Set Kwikset Lock App State 52
[2025-07-29 14:53:58.010] I: Matter is disabled
[2025-07-29 14:54:13.020] I: 394911 [DL]DFU-BLE-Connected
[2025-07-29 14:54:13.020] I: stop_ble_advertisment_timer
[2025-07-29 14:54:13.040] I: 394916 [DL]Current number of connections: 1/1
[2025-07-29 14:54:13.040] I: BLE Connected
[2025-07-29 14:54:13.280] I: 395151 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:54:13.280] I: 395154 [DL]Current number of connections: 0/1
[2025-07-29 14:54:13.280] I: BLE Disconnected: 13
[2025-07-29 14:54:17.660] I: 399530 [DL]DFU-BLE-Connected
[2025-07-29 14:54:17.660] I: stop_ble_advertisment_timer
[2025-07-29 14:54:17.660] I: 399535 [DL]Current number of connections: 1/1
[2025-07-29 14:54:17.660] I: BLE Connected
[2025-07-29 14:54:17.870] I: 399753 [DL]DFU Image upload started
[2025-07-29 14:54:18.700] I: Connection parameters updated.
[2025-07-29 14:54:18.722]  interval: 9, latency: 0, timeout: 42
[2025-07-29 14:54:25.390] I: OTA Stage Change from (11)->(12)
[2025-07-29 14:54:25.413] I: 407288 [DL]Image 0 download completed successfully
[2025-07-29 14:54:25.510] I: 407379 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:54:25.510] I: 407383 [DL]Current number of connections: 0/1
[2025-07-29 14:54:25.510] I: BLE Disconnected: 13
[2025-07-29 14:54:37.746] I: 419610 [DL]DFU-BLE-Connected
[2025-07-29 14:54:37.746] I: stop_ble_advertisment_timer
[2025-07-29 14:54:37.746] I: 419615 [DL]Current number of connections: 1/1
[2025-07-29 14:54:37.746] I: BLE Connected
[2025-07-29 14:54:37.970] I: 419847 [DL]DFU Image upload started
[2025-07-29 14:54:38.790] I: Connection parameters updated.
[2025-07-29 14:54:38.790]  interval: 9, latency: 0, timeout: 42
[2025-07-29 14:55:15.480] I: OTA Stage Change from (12)->(13)
[2025-07-29 14:55:15.480] I: 457378 [DL]Image 1 download completed successfully
[2025-07-29 14:55:15.580] I: 457471 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:55:15.600] I: 457475 [DL]Current number of connections: 0/1
[2025-07-29 14:55:15.600] I: BLE Disconnected: 13
[2025-07-29 14:55:22.480] I: 464372 [DL]DFU-BLE-Connected
[2025-07-29 14:55:22.500] I: stop_ble_advertisment_timer
[2025-07-29 14:55:22.500] I: 464377 [DL]Current number of connections: 1/1
[2025-07-29 14:55:22.500] I: BLE Connected
[2025-07-29 14:55:22.720] I: 464606 [DL]DFU Image upload started
[2025-07-29 14:55:23.540] I: Connection parameters updated.
[2025-07-29 14:55:23.560]  interval: 9, latency: 0, timeout: 42
[2025-07-29 14:57:14.640] I: OTA Stage Change from (13)->(14)
[2025-07-29 14:57:14.651] I: 576531 [DL]Image 2 download completed successfully
[2025-07-29 14:57:14.730] I: 576627 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:57:14.750] I: 576630 [DL]Current number of connections: 0/1
[2025-07-29 14:57:14.750] I: BLE Disconnected: 13
[2025-07-29 14:57:21.630] I: 583505 [DL]DFU-BLE-Connected
[2025-07-29 14:57:21.630] I: stop_ble_advertisment_timer
[2025-07-29 14:57:21.630] I: 583510 [DL]Current number of connections: 1/1
[2025-07-29 14:57:21.640] I: BLE Connected
[2025-07-29 14:57:21.870] I: 583744 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:57:21.870] I: 583748 [DL]Current number of connections: 0/1
[2025-07-29 14:57:21.870] I: BLE Disconnected: 13
[2025-07-29 14:57:25.951] I: 587842 [DL]DFU-BLE-Connected
[2025-07-29 14:57:25.970] I: stop_ble_advertisment_timer
[2025-07-29 14:57:25.970] I: 587848 [DL]Current number of connections: 1/1
[2025-07-29 14:57:25.970] I: BLE Connected
[2025-07-29 14:57:26.160] I: 588053 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-29 14:57:26.200] I: 588079 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:57:26.200] I: 588083 [DL]Current number of connections: 0/1
[2025-07-29 14:57:26.200] I: BLE Disconnected: 13
[2025-07-29 14:57:33.896] I: 595762 [DL]DFU-BLE-Connected
[2025-07-29 14:57:33.896] I: stop_ble_advertisment_timer
[2025-07-29 14:57:33.896] I: 595768 [DL]Current number of connections: 1/1
[2025-07-29 14:57:33.896] I: BLE Connected
[2025-07-29 14:57:34.110] I: 595981 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-29 14:57:34.130] I: 596007 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:57:34.130] I: 596010 [DL]Current number of connections: 0/1
[2025-07-29 14:57:34.130] I: BLE Disconnected: 13
[2025-07-29 14:57:42.101] I: 603971 [DL]DFU-BLE-Connected
[2025-07-29 14:57:42.101] I: stop_ble_advertisment_timer
[2025-07-29 14:57:42.101] I: 603976 [DL]Current number of connections: 1/1
[2025-07-29 14:57:42.101] I: BLE Connected
[2025-07-29 14:57:42.280] I: STM Pending =0, Redpine Pending = 0
[2025-07-29 14:57:42.371] I: Count = 4
[2025-07-29 14:57:42.371] I: dfu_header_data.image_count: 4
[2025-07-29 14:57:43.149] I: Connection parameters updated.
[2025-07-29 14:57:43.150]  interval: 9, latency: 0, timeout: 42
[2025-07-29 14:57:43.270] I: IMG Integrity Verified Successfully: 0
[2025-07-29 14:57:46.262] I: IMG Integrity Verified Successfully: 1
[2025-07-29 14:57:46.349] I: IMG Integrity Verified Successfully: 2
[2025-07-29 14:57:46.680] I: IMG Integrity Verified Successfully: 3
[2025-07-29 14:57:46.710] I: OTA Bundle(STM32 + RS9116 + PN76) image integrity Verified
[2025-07-29 14:57:46.710] I: OTA Stage Change from (14)->(30)
[2025-07-29 14:57:46.810] I: Updated ota meta data
[2025-07-29 14:57:46.810] I: Operating Mode Command: Mode:10, State:31
[2025-07-29 14:57:46.810] E: Sending UART cmd(5) st 0
[2025-07-29 14:57:46.810] I: Operating mode event
[2025-07-29 14:57:46.850] I: Received response of command id 5
[2025-07-29 14:57:46.850] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-29 14:57:46.850] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:57:46.850] I: STM OTAU Pending: Reset Nordic Triggered
[2025-07-29 14:57:46.850] I: OTA Stage Change from (30)->(30)
[2025-07-29 14:57:46.850] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:57:46.850] I: Set Kwikset Lock App State 49
[2025-07-29 14:57:46.850] I: Matter is disabled
[2025-07-29 14:57:46.880] I: 608775 [DL]DFU-BLE-Disconnected : 19
[2025-07-29 14:57:46.900] I: 608779 [DL]Current number of connections: 0/1
[2025-07-29 14:57:46.900] I: BLE Disconnected: 13
[2025-07-29 14:58:34.370] 
[2025-07-29 14:58:34.370] uart:~$ *** Booting My Application v23.55.2-2f9996e8c87c ***
[2025-07-29 14:58:34.420] *** Using nRF Connect SDK v2.8.0-a2386bfc8401 ***
[2025-07-29 14:58:34.420] *** Using Zephyr OS v3.7.99-0bc3393fb112 ***
[2025-07-29 14:58:34.420] I: KWIKSET HALO 3 PLUS VERSION: 17.37.02.03
[2025-07-29 14:58:34.420] I: 51 [DL]BLE address: F8:56:F6:AC:64:61
[2025-07-29 14:58:34.442] I: No users indexes stored
[2025-07-29 14:58:34.442] I: No stored indexes for credential of type: 1
[2025-07-29 14:58:34.550] I: No stored indexes for credential of type: 2
[2025-07-29 14:58:34.550] I: ========== User Index: 0x01 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x02 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x03 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x04 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x05 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x06 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x07 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x08 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x09 User ID: 0xffffffff ==========
[2025-07-29 14:58:34.550] I: ========== User Index: 0x0a User ID: 0xffffffff ==========
[2025-07-29 14:58:34.570] I: ========== User Index: 0x0b User ID: 0xffffffff ==========
[2025-07-29 14:58:34.570] I: Board config kwiksetmdb_nrf5340_cpuapp
[2025-07-29 14:58:34.570] I: IMAGE_VERSION 17370203
[2025-07-29 14:58:34.570] I: build time: Jul 29 2025 12:22:21
[2025-07-29 14:58:34.570] I: 158 [DL]CHIP task running
[2025-07-29 14:58:34.570] I: Init CHIP stack
[2025-07-29 14:58:34.570] I: 164 [DL]OpenThread started: OK
[2025-07-29 14:58:34.570] I: 167 [DL]Setting OpenThread device type to SLEEPY END DEVICE
[2025-07-29 14:58:34.570] I: 173 [SWU]New firmware image confirmed
[2025-07-29 14:58:34.570] I: 177 [SWU]DFU_BLEAdvertising_Init
[2025-07-29 14:58:34.960] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-29 14:58:34.960] I: NFC Boot Event PN7642 FW VERSION 17.01.00.03
[2025-07-29 14:58:34.960] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-29 14:58:34.960] I: 
[2025-07-29 14:58:34.960] Boot Event Received
[2025-07-29 14:58:34.960] 
[2025-07-29 14:58:34.960] I: Booted NFC IC in Normal Operation Mode.
[2025-07-29 14:58:34.960] 
[2025-07-29 14:58:34.960] I: 260 [SVR]Subscription persistence not supported
[2025-07-29 14:58:34.960] I: 265 [SVR]Server initializing...
[2025-07-29 14:58:34.960] I: 268 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2025-07-29 14:58:34.960] I: 273 [DMG]AccessControl: initializing
[2025-07-29 14:58:34.970] I: 277 [DMG]Examples::AccessControlDelegate::Init
[2025-07-29 14:58:34.970] I: 281 [DMG]AccessControl: setting
[2025-07-29 14:58:34.970] I: 284 [DMG]DefaultAclStorage: initializing
[2025-07-29 14:58:34.970] I: 288 [DMG]DefaultAclStorage: 0 entries loaded
[2025-07-29 14:58:35.000] E: 293 [IN]IPV6_PKTINFO failed: 109
[2025-07-29 14:58:35.000] I: 298 [ZCL]Using ZAP configuration...
[2025-07-29 14:58:35.000] I: 303 [DMG]AccessControlCluster: initializing
[2025-07-29 14:58:35.000] Unhandled cluster ID: 0x  30
[2025-07-29 14:58:35.000] 
[2025-07-29 14:58:35.000] ===== Attribute Received are: Cluster=30 Attribute=0 Value=0 =====
[2025-07-29 14:58:35.000] I: 318 [ZCL]Emit DSTTableEmpty event [ep=0]
[2025-07-29 14:58:35.000] I: 322 [ZCL]Initiating Admin Commissioning cluster.
[2025-07-29 14:58:35.000] I: 326 [ZCL]Door Lock server initialized
[2025-07-29 14:58:35.000] E: 330 [ZCL]DeviceInfoProvider is not registered
[2025-07-29 14:58:35.000] E: 334 [ZCL]Failed to read calendar type with error: 0x86
[2025-07-29 14:58:35.000] Unhandled cluster ID: 0x   3
[2025-07-29 14:58:35.000] 
[2025-07-29 14:58:35.000] ===== Attribute Received are: Cluster=3 Attribute=1 Value=3 =====
[2025-07-29 14:58:35.016] I: 348 [ZCL]Door Lock cluster initialized at endpoint #1
[2025-07-29 14:58:35.016] ===== Attribute Received are: Cluster=101 Attribute=0 Value=255 =====
[2025-07-29 14:58:35.016] ===== Attribute Received are: Cluster=101 Attribute=2 Value=1 =====
[2025-07-29 14:58:35.016] ===== Attribute Received are: Cluster=101 Attribute=1 Value=0 =====
[2025-07-29 14:58:35.016] ===== Attribute Received are: Cluster=101 Attribute=11 Value=11 =====
[2025-07-29 14:58:35.016] ===== Attribute Received are: Cluster=101 Attribute=12 Value=35 =====
[2025-07-29 14:58:35.016] ===== Attribute Received are: Cluster=101 Attribute=13 Value=35 =====
[2025-07-29 14:58:35.016] ===== Attribute Received are: Cluster=101 Attribute=1c Value=35 =====
[2025-07-29 14:58:35.016] ===== Attribute Received are: Cluster=101 Attribute=19 Value=80 =====
[2025-07-29 14:58:35.016] I: 401 [DIS]Updating services using commissioning mode 0
[2025-07-29 14:58:35.016] E: 406 [DIS]Failed to remove advertised services: 3
[2025-07-29 14:58:35.032] E: 411 [DIS]Failed to finalize service update: 3
[2025-07-29 14:58:35.032] I: 415 [IN]CASE Server enabling CASE session setups
[2025-07-29 14:58:35.032] I: 420 [SVR]Joining Multicast groups
[2025-07-29 14:58:35.032] I: 424 [SVR]Server Listening...
[2025-07-29 14:58:35.032] I: 427 [DL]Device Configuration:
[2025-07-29 14:58:35.032] I: 430 [DL]  Serial Number: 1789AE57B32427844F
[2025-07-29 14:58:35.032] I: 434 [DL]  Vendor Id: 5153 (0x1421)
[2025-07-29 14:58:35.032] I: 437 [DL]  Product Id: 66 (0x42)
[2025-07-29 14:58:35.032] I: Get product name B, len 0
[2025-07-29 14:58:35.032] I: 443 [DL]  Product Name: B
[2025-07-29 14:58:35.032] I: 445 [DL]  Hardware Version: 1
[2025-07-29 14:58:35.034] I: 448 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 75655451
[2025-07-29 14:58:35.034] I: 454 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 776 (0x308)
[2025-07-29 14:58:35.034] I: 460 [DL]  Manufacturing Date: 2025-07-24
[2025-07-29 14:58:35.050] I: 464 [DL]  Device Type: 10 (0xA)
[2025-07-29 14:58:35.050] I: 467 [SVR]SetupQRCode: [MT:-QWJ08DB00.I2N6SM10]
[2025-07-29 14:58:35.050] I: 471 [SVR]Copy/paste the below URL in a browser to see the QR Code:
[2025-07-29 14:58:35.050] I: 478 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-QWJ08DB00.I2N6SM10
[2025-07-29 14:58:35.050] I: 486 [SVR]Manual pairing code: [05967546175]
[2025-07-29 14:58:35.050] I: STM32 device number: 
[2025-07-29 14:58:35.050] I: 31 37 38 39 41 45 35 37 |1789AE57
[2025-07-29 14:58:35.050] I: 42 33 32 34 32 37 38 34 |B3242784
[2025-07-29 14:58:35.050] I: 34 46                   |4F      
[2025-07-29 14:58:35.050] I: SKU number: 
[2025-07-29 14:58:35.050] I: 4b 31 37 2d 30 31       |K17-01  
[2025-07-29 14:58:35.050] I: WO number: 
[2025-07-29 14:58:35.050] I: 30 30 30 30 30 30 30 30 |00000000
[2025-07-29 14:58:35.050] I: 30                      |0       
[2025-07-29 14:58:35.070] I: Manuf Date: 
[2025-07-29 14:58:35.070] I: 32 30 32 35 2d 30 37 2d |2025-07-
[2025-07-29 14:58:35.070] I: 32 34 00 00 00 00       |24....  
[2025-07-29 14:58:35.070] I: Prod config length 6
[2025-07-29 14:58:35.070] I: Product Config: 
[2025-07-29 14:58:35.070] I: 30 78 30 30 30 31       |0x0001  
[2025-07-29 14:58:35.070] I: Prod Config Read 1
[2025-07-29 14:58:35.070] I: User intend flow enabled, set commissioning flow to kUserActionRequired
[2025-07-29 14:58:35.070] I: Factory Data Version length 2
[2025-07-29 14:58:35.070] I: Factory Data Ver: 
[2025-07-29 14:58:35.070] I: 30 31                   |01      
[2025-07-29 14:58:35.070] I: Payload value in string format: MT:-QWJ04TC00.I2N60Q4P0ILT70VYYR1JFSK14YDB0-0LJ1-0LJ1-0LJ1IHLC0AUZL1XIKJ17AZL1UV700CXYR1K6Y12NNZR1YC-L1-2ZR1OADO1KB40
[2025-07-29 14:58:35.070] I: Pairing Code value in string format: 459675461705153000660
[2025-07-29 14:58:35.070] I: ============== Updating product finish and color to 15, 2, product Name Halo Select Plus ==============
[2025-07-29 14:58:35.090] E: 577 [DL]Long dispatch time: 416 ms, for event type 2
[2025-07-29 14:58:35.090] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-29 14:58:36.510] I: Syncing up on message 9a
[2025-07-29 14:58:36.510] I: STM32 counter to 1
[2025-07-29 14:58:36.550] I: BLE Device ID: 2784
[2025-07-29 14:58:36.550] I: Device is provisioned
[2025-07-29 14:58:36.550] I: network state 0
[2025-07-29 14:58:36.550] E: Sending UART cmd(3) st 0
[2025-07-29 14:58:36.550] I: BLE Name set: HU:2784 errCode: 0
[2025-07-29 14:58:36.550] I: Received response of command id 9a
[2025-07-29 14:58:36.550] I: Command 0x9A Received
[2025-07-29 14:58:36.550] I: Firmware Attribute event
[2025-07-29 14:58:36.580] I: Received response of command id 30
[2025-07-29 14:58:36.580] I: Received DC Eco Config REQ
[2025-07-29 14:58:36.580] I: DC Eco Config Resp
[2025-07-29 14:58:36.580] I: Received DC eco config req
[2025-07-29 14:58:36.580] I: 80 72 03 00 10 00 04 1a |.r......
[2025-07-29 14:58:36.580] I: 17 05                   |..      
[2025-07-29 14:58:36.580] E: Sending UART cmd(72) st 0
[2025-07-29 14:58:38.551] I: Syncing up on message 3
[2025-07-29 14:58:38.551] I: Sys init req
[2025-07-29 14:58:38.551] E: Sending UART cmd(3) st 0
[2025-07-29 14:58:38.551] I: System init Response
[2025-07-29 14:58:38.551] I: Received response of command id 3
[2025-07-29 14:58:38.551] I: Update sync timer
[2025-07-29 14:58:38.551] I: Received Sys Init Resp
[2025-07-29 14:58:38.560] I: battery mode 0
[2025-07-29 14:58:38.560] I: battery percentage 5a
[2025-07-29 14:58:38.560] I: battery type 1
[2025-07-29 14:58:38.560] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:58:39.030] I: Syncing up on message 5
[2025-07-29 14:58:39.030] I: Operating mode req
[2025-07-29 14:58:39.080] E: Sending UART cmd(5) st 0
[2025-07-29 14:58:39.080] I: Operating mode response
[2025-07-29 14:58:39.080] I: Received response of command id 5
[2025-07-29 14:58:39.080] I: Received Lock Op Mode Resp, mode 10, App state 31
[2025-07-29 14:58:39.080] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 14:58:39.080] I: Set Kwikset Lock App Mode 16
[2025-07-29 14:58:39.080] I: Set Kwikset Lock App State 49
[2025-07-29 14:58:39.080] I: Matter is disabled
[2025-07-29 14:58:39.590] I: Syncing up on message 10
[2025-07-29 14:58:39.590] I: Lock state req
[2025-07-29 14:58:39.590] E: Sending UART cmd(10) st 0
[2025-07-29 14:58:39.590] I: Lock State Response
[2025-07-29 14:58:39.590] I: Received response of command id 10
[2025-07-29 14:58:39.590] I: Received Lock State Response, lock st: 12
[2025-07-29 14:58:39.590] I: Found matching nordic source of operation 0
[2025-07-29 14:58:39.590] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 14:58:39.590] I: Unlock action completed
[2025-07-29 14:58:39.590] I: Updating LockState attribute
[2025-07-29 14:58:39.590] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 14:58:40.030] I: Syncing up on message 20
[2025-07-29 14:58:40.030] I: Lock setting req
[2025-07-29 14:58:40.090] E: Sending UART cmd(20) st 0
[2025-07-29 14:58:40.090] I: Lock General Setting Response
[2025-07-29 14:58:40.090] I: Received response of command id 20
[2025-07-29 14:58:40.090] I: Received Lock General Setting resp
[2025-07-29 14:58:40.090] I: Sound Volume Attribute Update, sound volume 1
[2025-07-29 14:58:40.090] SoundVolume attribute change
[2025-07-29 14:58:40.090] 
[2025-07-29 14:58:40.100] I: == Sound Volume Attribute Update Callback, sound volume 2 ==
[2025-07-29 14:58:40.100] I: No change in sound volume, return
[2025-07-29 14:58:40.100] ===== Attribute Received are: Cluster=101 Attribute=24 Value=2 =====
[2025-07-29 14:58:40.100] I: Matter Not Enabled do not set
[2025-07-29 14:58:40.591] I: Syncing up on message 51
[2025-07-29 14:58:40.591] I: Battery info req
[2025-07-29 14:58:40.591] E: Sending UART cmd(51) st 0
[2025-07-29 14:58:40.591] I: Received response of command id 51
[2025-07-29 14:58:40.591] I: Received Battery Info resp
[2025-07-29 14:58:40.591] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 14:58:40.591] Unhandled cluster ID: 0x  2f
[2025-07-29 14:58:40.591] 
[2025-07-29 14:58:40.591] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 14:58:40.591] Unhandled cluster ID: 0x  2f
[2025-07-29 14:58:40.591] 
[2025-07-29 14:58:40.591] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 14:58:41.030] I: All message synced.
[2025-07-29 14:59:04.570] I: STM system init timer expired, System Init Event not received from STM32
[2025-07-29 14:59:04.570] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-29 14:59:04.570] I: STM Pending =1, Redpine Pending = 1
[2025-07-29 14:59:04.570] I: STM Post OTA Pending
[2025-07-29 14:59:04.570] I: Redpine Post OTA Pending
[2025-07-29 14:59:04.570] E: Sending UART cmd(9e) st 0
[2025-07-29 14:59:04.570] I: BLE Name set: HU:2784 errCode: 0
[2025-07-29 14:59:04.570] I: 30188 [SWU]SMP BLE advertising started
[2025-07-29 14:59:04.570] I: 30192 [DL]DFU over SMP started
[2025-07-29 14:59:05.430] I: IMG Integrity Verified Successfully: 0
[2025-07-29 14:59:08.397] I: IMG Integrity Verified Successfully: 1
[2025-07-29 14:59:08.478] I: IMG Integrity Verified Successfully: 2
[2025-07-29 14:59:08.823] I: IMG Integrity Verified Successfully: 3
[2025-07-29 14:59:08.823] I: OTA Stage Change from (ff)->(32)
[2025-07-29 14:59:08.823] I: OTA device_id = 5 : DISCOVERY_REQ
[2025-07-29 14:59:08.901] I: SECURE_STM : IB_DEVICE_DISCOVERY_REQUEST (80) 
[2025-07-29 14:59:08.950] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-29 14:59:08.950] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-29 14:59:08.950] I: OTA device_id = 5 : FW_UPDATE_START_REQ
[2025-07-29 14:59:08.950] I: SECURE_STM : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-29 14:59:15.330] I: STM OTA Progress = 10
[2025-07-29 14:59:21.700] I: STM OTA Progress = 20
[2025-07-29 14:59:28.045] I: STM OTA Progress = 30
[2025-07-29 14:59:34.490] I: STM OTA Progress = 40
[2025-07-29 14:59:40.843] I: STM OTA Progress = 50
[2025-07-29 14:59:47.211] I: STM OTA Progress = 60
[2025-07-29 14:59:53.561] I: STM OTA Progress = 70
[2025-07-29 14:59:59.920] I: STM OTA Progress = 80
[2025-07-29 15:00:06.291] I: STM OTA Progress = 90
[2025-07-29 15:00:12.640] I: STM OTA Progress = 100
[2025-07-29 15:00:13.321] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-29 15:00:13.340] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-29 15:00:31.020] I: Sending Sys Init Resp
[2025-07-29 15:00:31.020] I: Device is provisioned
[2025-07-29 15:00:31.020] I: network state 0
[2025-07-29 15:00:31.020] E: Sending UART cmd(3) st 0
[2025-07-29 15:00:31.020] I: Received DC App Config REQ
[2025-07-29 15:00:31.020] I: DC App Config Resp
[2025-07-29 15:00:31.020] I: Received DC config req
[2025-07-29 15:00:31.020] I: 80 70 03 00 10 10 08 00 |.p......
[2025-07-29 15:00:31.020] I: 50 1e                   |P.      
[2025-07-29 15:00:31.020] I: Matter enabled state 0
[2025-07-29 15:00:31.020] I: Get Matter Commission State
[2025-07-29 15:00:31.020] I: network state 0
[2025-07-29 15:00:31.030] I: network state 0
[2025-07-29 15:00:31.030] E: Sending UART cmd(70) st 0
[2025-07-29 15:00:31.091] I: Lock State Event
[2025-07-29 15:00:31.091] I: Received response of command id 10
[2025-07-29 15:00:31.091] I: Received Lock State event, lock st: 12
[2025-07-29 15:00:31.091] I: Found matching nordic source of operation 0
[2025-07-29 15:00:31.091] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 15:00:31.091] I: Unlock action completed
[2025-07-29 15:00:31.091] I: Updating LockState attribute
[2025-07-29 15:00:31.091] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 15:00:31.121] I: Received DC Eco Config REQ
[2025-07-29 15:00:31.150] I: DC Eco Config Resp
[2025-07-29 15:00:31.150] I: Received DC eco config req
[2025-07-29 15:00:31.150] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-29 15:00:31.150] I: c4 1e                   |..      
[2025-07-29 15:00:31.150] E: Sending UART cmd(72) st 0
[2025-07-29 15:00:31.330] I: General Lock Setting event
[2025-07-29 15:00:31.330] I: Received response of command id 20
[2025-07-29 15:00:31.330] I: Received Lock General Setting event
[2025-07-29 15:00:31.330] I: Sound Volume Attribute Update, sound volume 1
[2025-07-29 15:00:31.330] I: Matter Not Enabled do not set
[2025-07-29 15:00:31.440] I: Firmware Attribute event
[2025-07-29 15:00:31.440] I: Received response of command id 30
[2025-07-29 15:00:31.490] I: Hardware Attribute event
[2025-07-29 15:00:31.490] I: Received response of command id 31
[2025-07-29 15:00:31.571] I: Operating mode event
[2025-07-29 15:00:31.571] I: Received response of command id 5
[2025-07-29 15:00:31.571] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-29 15:00:31.571] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 15:00:31.571] I: Set Kwikset Lock App Mode 16
[2025-07-29 15:00:31.571] I: Set Kwikset Lock App State 49
[2025-07-29 15:00:31.571] I: Matter is disabled
[2025-07-29 15:00:31.705] I: Battery Info event
[2025-07-29 15:00:31.705] I: Received response of command id 51
[2025-07-29 15:00:31.705] I: Received Battery info event
[2025-07-29 15:00:31.705] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 15:00:31.705] Unhandled cluster ID: 0x  2f
[2025-07-29 15:00:31.705] 
[2025-07-29 15:00:31.705] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 15:00:31.705] Unhandled cluster ID: 0x  2f
[2025-07-29 15:00:31.705] 
[2025-07-29 15:00:31.705] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 15:00:31.810] I: System info event
[2025-07-29 15:00:31.810] I: Received System Info Event
[2025-07-29 15:00:31.810] W: Time invalid, set time
[2025-07-29 15:00:31.810] I: Get system time
[2025-07-29 15:00:31.810] I: System Real time in seconds 373663017
[2025-07-29 15:00:31.810] I: Time sync status flag 0
[2025-07-29 15:00:31.810] E: Time not sync, keep default value
[2025-07-29 15:00:31.915] I: System init event
[2025-07-29 15:00:31.915] I: Received response of command id 3
[2025-07-29 15:00:31.915] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-29 15:00:31.915] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 15:00:31.915] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-29 15:00:31.915] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-29 15:00:31.915] I: OTA device_id = 5 : FW_UPDATE_COMPLETE_REQ
[2025-07-29 15:00:31.915] I: SECURE_STM : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-29 15:00:31.915] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-29 15:00:31.915] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-29 15:00:34.340] I: Sending Sys Init Resp
[2025-07-29 15:00:34.340] I: Device is provisioned
[2025-07-29 15:00:34.391] I: network state 0
[2025-07-29 15:00:34.391] E: Sending UART cmd(3) st 0
[2025-07-29 15:00:34.391] I: Received DC App Config REQ
[2025-07-29 15:00:34.391] I: DC App Config Resp
[2025-07-29 15:00:34.391] I: Received DC config req
[2025-07-29 15:00:34.391] I: 80 70 03 00 10 10 04 1a |.p......
[2025-07-29 15:00:34.391] I: 00 62                   |.b      
[2025-07-29 15:00:34.391] I: Matter enabled state 0
[2025-07-29 15:00:34.391] I: Get Matter Commission State
[2025-07-29 15:00:34.391] I: network state 0
[2025-07-29 15:00:34.391] I: network state 0
[2025-07-29 15:00:34.396] E: Sending UART cmd(70) st 0
[2025-07-29 15:00:34.451] I: Lock State Event
[2025-07-29 15:00:34.451] I: Received response of command id 10
[2025-07-29 15:00:34.451] I: Received Lock State event, lock st: 12
[2025-07-29 15:00:34.451] I: Found matching nordic source of operation 0
[2025-07-29 15:00:34.451] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 15:00:34.451] I: Unlock action completed
[2025-07-29 15:00:34.451] I: Updating LockState attribute
[2025-07-29 15:00:34.451] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 15:00:34.483] I: Received DC Eco Config REQ
[2025-07-29 15:00:34.513] I: DC Eco Config Resp
[2025-07-29 15:00:34.513] I: Received DC eco config req
[2025-07-29 15:00:34.513] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-29 15:00:34.513] I: c4 62                   |.b      
[2025-07-29 15:00:34.513] E: Sending UART cmd(72) st 0
[2025-07-29 15:00:34.671] I: General Lock Setting event
[2025-07-29 15:00:34.671] I: Received response of command id 20
[2025-07-29 15:00:34.701] I: Received Lock General Setting event
[2025-07-29 15:00:34.701] I: Sound Volume Attribute Update, sound volume 1
[2025-07-29 15:00:34.701] I: Matter Not Enabled do not set
[2025-07-29 15:00:34.810] I: Firmware Attribute event
[2025-07-29 15:00:34.810] I: Received response of command id 30
[2025-07-29 15:00:34.870] I: Hardware Attribute event
[2025-07-29 15:00:34.870] I: Received response of command id 31
[2025-07-29 15:00:34.941] I: Operating mode event
[2025-07-29 15:00:34.941] I: Received response of command id 5
[2025-07-29 15:00:34.941] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-29 15:00:34.941] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 15:00:34.941] I: Set Kwikset Lock App Mode 16
[2025-07-29 15:00:34.941] I: Set Kwikset Lock App State 49
[2025-07-29 15:00:34.941] I: Matter is disabled
[2025-07-29 15:00:35.070] I: Battery Info event
[2025-07-29 15:00:35.070] I: Received response of command id 51
[2025-07-29 15:00:35.070] I: Received Battery info event
[2025-07-29 15:00:35.070] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 15:00:35.070] Unhandled cluster ID: 0x  2f
[2025-07-29 15:00:35.070] 
[2025-07-29 15:00:35.070] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 15:00:35.070] Unhandled cluster ID: 0x  2f
[2025-07-29 15:00:35.070] 
[2025-07-29 15:00:35.070] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 15:00:35.171] I: System info event
[2025-07-29 15:00:35.171] I: Received System Info Event
[2025-07-29 15:00:35.171] W: Time invalid, set time
[2025-07-29 15:00:35.171] I: Get system time
[2025-07-29 15:00:35.171] I: System Real time in seconds 373663017
[2025-07-29 15:00:35.180] I: Time sync status flag 0
[2025-07-29 15:00:35.180] E: Time not sync, keep default value
[2025-07-29 15:00:35.261] I: System init event
[2025-07-29 15:00:35.261] I: Received response of command id 3
[2025-07-29 15:00:35.261] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-29 15:00:35.261] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 15:00:35.261] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-29 15:00:35.261] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-29 15:00:35.261] I: STM New OTA Firmware Version = 17 5 4 1a
[2025-07-29 15:00:35.261] I: STM Secure OTA Successful
[2025-07-29 15:00:35.370] I: Cleared STM OTA Meta Data
[2025-07-29 15:00:35.370] I: OTA Stage Change from (32)->(33)
[2025-07-29 15:00:35.370] I: Redpine OTA started
[2025-07-29 15:00:35.370] I: OTA Stage Change from (33)->(34)
[2025-07-29 15:00:35.370] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-29 15:00:42.360] I: STM Reset Count 0
[2025-07-29 15:00:42.390] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-29 15:00:42.390] I: STM_QSPI : IB_DEVICE_DISCOVERY_REQUEST (80)
[2025-07-29 15:00:42.390] I: OTA device_id = 4 : FW_VERSION_REQ
[2025-07-29 15:00:42.390] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-29 15:00:42.390] I: Redpine Current Firmware Version: 2.c.0.3
[2025-07-29 15:00:42.411] I: OTA device_id = 4 : FW_UPDATE_START_REQ
[2025-07-29 15:00:42.510] I: STM_QSPI : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-29 15:01:05.231] I: STM Boot Up Properly, Stopped STM Reboot Timer
[2025-07-29 15:01:21.871] I: Redpine Image Stored into STM QSPI, Progress = 10
[2025-07-29 15:01:55.331] I: Redpine Image Stored into STM QSPI, Progress = 20
[2025-07-29 15:02:15.981] I: Redpine Image Stored into STM QSPI, Progress = 30
[2025-07-29 15:02:36.720] I: Redpine Image Stored into STM QSPI, Progress = 40
[2025-07-29 15:02:57.391] I: Redpine Image Stored into STM QSPI, Progress = 50
[2025-07-29 15:03:18.131] I: Redpine Image Stored into STM QSPI, Progress = 60
[2025-07-29 15:03:38.921] I: Redpine Image Stored into STM QSPI, Progress = 70
[2025-07-29 15:03:59.641] I: Redpine Image Stored into STM QSPI, Progress = 80
[2025-07-29 15:04:20.361] I: Redpine Image Stored into STM QSPI, Progress = 90
[2025-07-29 15:04:41.171] I: Redpine Image Stored into STM QSPI, Progress = 100
[2025-07-29 15:04:43.301] I: OTA device_id = 4 : FW_UPDATE_COMPLETE_REQ
[2025-07-29 15:04:43.731] I: STM_QSPI : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-29 15:04:43.861] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (0)
[2025-07-29 15:04:48.641] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (10)
[2025-07-29 15:04:53.531] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (20)
[2025-07-29 15:04:58.471] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (30)
[2025-07-29 15:05:03.431] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (40)
[2025-07-29 15:05:08.381] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (50)
[2025-07-29 15:05:13.311] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (60)
[2025-07-29 15:05:18.281] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (70)
[2025-07-29 15:05:23.231] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (80)
[2025-07-29 15:05:28.111] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (90)
[2025-07-29 15:05:32.911] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (100)
[2025-07-29 15:06:02.311] I: STM_QSPI : IB_FW_UPDATE_REBOOT_REQUEST (80) 
[2025-07-29 15:06:02.451] I: Clear Redpine OTA Meta Data
[2025-07-29 15:06:02.451] I: Redpine OTA Successful
[2025-07-29 15:06:02.451] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-29 15:06:02.451] I: STM Pending =2, Redpine Pending = 2
[2025-07-29 15:06:02.451] I: PN76 IMG 1 Post OTA Pending
[2025-07-29 15:06:02.451] E: Sending UART cmd(9e) st 0
[2025-07-29 15:06:02.451] I: 448079 [SWU]DFU over SMP was already started
[2025-07-29 15:06:02.531] I: IMG Integrity Verified Successfully: 2
[2025-07-29 15:06:02.901] I: IMG Integrity Verified Successfully: 3
[2025-07-29 15:06:02.901] I: OTA Stage Change from (34)->(3a)
[2025-07-29 15:06:02.901] I: PN76_IMG1_DEVICE_DFU_MULTI_IMG_ID
[2025-07-29 15:06:02.901] I: PN76_IMG Update from OTA Task Event
[2025-07-29 15:06:02.901] I: 
[2025-07-29 15:06:02.901] 
[2025-07-29 15:06:02.901] --------------- UPDATING PN7642 NXP FIRMWARE --------------------
[2025-07-29 15:06:02.901] 
[2025-07-29 15:06:02.901] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-29 15:06:02.941] I: pNXPFWInfo->img_offset = 0x351497
[2025-07-29 15:06:02.941] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-29 15:06:02.941] I: Reading version of firmware in QSPI flash: MetaData 0x2f60217
[2025-07-29 15:06:02.941] I: PN76 NXP FW VERSION VALIDATION SKIPPED, OTAU TEST BUNDLE
[2025-07-29 15:06:03.051] I: ----> PN7642 OTA Progress = 10 %
[2025-07-29 15:06:03.111] I: ----> PN7642 OTA Progress = 20 %
[2025-07-29 15:06:03.181] I: ----> PN7642 OTA Progress = 30 %
[2025-07-29 15:06:03.241] I: ----> PN7642 OTA Progress = 40 %
[2025-07-29 15:06:03.311] I: ----> PN7642 OTA Progress = 50 %
[2025-07-29 15:06:03.371] I: ----> PN7642 OTA Progress = 60 %
[2025-07-29 15:06:03.431] I: ----> PN7642 OTA Progress = 70 %
[2025-07-29 15:06:03.501] I: ----> PN7642 OTA Progress = 80 %
[2025-07-29 15:06:03.641] I: ----> PN7642 OTA Progress = 100 %
[2025-07-29 15:06:03.641] I: Whole pn7642 FW Image downloaded ....
[2025-07-29 15:06:03.681] I: 
[2025-07-29 15:06:03.681] 
[2025-07-29 15:06:03.681] I: 
[2025-07-29 15:06:03.681] PN7642 Firmware of type 0 Successfully Updated !!!
[2025-07-29 15:06:03.681] I: PN76 Image Update Successful for Device ID(7)
[2025-07-29 15:06:03.801] I: Cleared PN76 Img1 OTA Meta Data
[2025-07-29 15:06:03.801] I: OTA Stage Change from (3a)->(3a)
[2025-07-29 15:06:03.801] I: PN76_IMG2_DEVICE_DFU_MULTI_IMG_ID
[2025-07-29 15:06:03.801] I: PN76_IMG Update from OTA Task Event
[2025-07-29 15:06:03.801] I: 
[2025-07-29 15:06:03.801] 
[2025-07-29 15:06:03.801] --------------- UPDATING PN7642 APPLICATION FIRMWARE -------------
[2025-07-29 15:06:03.801] 
[2025-07-29 15:06:03.801] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-29 15:06:03.841] I: pCustAppFWInfo->img_offset = 0x35c289
[2025-07-29 15:06:03.841] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-29 15:06:03.841] I: Reading version of firmware in QSPI flash: MetaData 0x2f60217
[2025-07-29 15:06:03.841] I: PN76 APP FW VERSION VALIDATION SKIPPED, OTAU TEST BUNDLE
[2025-07-29 15:06:04.141] I: ----> PN7642 OTA Progress = 10 %
[2025-07-29 15:06:04.411] I: ----> PN7642 OTA Progress = 20 %
[2025-07-29 15:06:04.671] I: ----> PN7642 OTA Progress = 30 %
[2025-07-29 15:06:04.944] I: ----> PN7642 OTA Progress = 40 %
[2025-07-29 15:06:05.201] I: ----> PN7642 OTA Progress = 50 %
[2025-07-29 15:06:05.472] I: ----> PN7642 OTA Progress = 60 %
[2025-07-29 15:06:05.731] I: ----> PN7642 OTA Progress = 70 %
[2025-07-29 15:06:06.001] I: ----> PN7642 OTA Progress = 80 %
[2025-07-29 15:06:06.251] I: ----> PN7642 OTA Progress = 90 %
[2025-07-29 15:06:06.554] I: ----> PN7642 OTA Progress = 100 %
[2025-07-29 15:06:06.554] I: Whole pn7642 FW Image downloaded ....
[2025-07-29 15:06:06.554] I: 
[2025-07-29 15:06:06.554] 
[2025-07-29 15:06:06.554] I: 
[2025-07-29 15:06:06.554] PN7642 Firmware of type 1 Successfully Updated !!!
[2025-07-29 15:06:06.554] I: PN76 Image Update Successful for Device ID(8)
[2025-07-29 15:06:06.631] I: Cleared PN76 Img2 OTA Meta Data
[2025-07-29 15:06:07.161] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-29 15:06:07.211] I: NFC Boot Event PN7642 FW VERSION 17.01.00.02
[2025-07-29 15:06:07.211] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-29 15:06:07.211] I: 
[2025-07-29 15:06:07.211] Boot Event Received
[2025-07-29 15:06:07.211] 
[2025-07-29 15:06:07.211] I: Booted NFC IC in Normal Operation Mode.
[2025-07-29 15:06:07.211] 
[2025-07-29 15:06:07.211] I: OTA Stage Change from (3a)->(3b)
[2025-07-29 15:06:07.211] I: post_stm_reset_event : init_pending_ota_update
[2025-07-29 15:06:07.211] I: All pending FW Updates are completed.
[2025-07-29 15:06:07.211] I: STM32 Reset Count = 0
[2025-07-29 15:06:07.211] I: REBOOT_STM: Send STM32 Reboot Command, Count (0)
[2025-07-29 15:06:09.531] I: Sending Sys Init Resp
[2025-07-29 15:06:09.531] I: Device is provisioned
[2025-07-29 15:06:09.531] I: network state 0
[2025-07-29 15:06:09.531] E: Sending UART cmd(3) st 0
[2025-07-29 15:06:09.531] I: Received DC App Config REQ
[2025-07-29 15:06:09.531] I: DC App Config Resp
[2025-07-29 15:06:09.531] I: Received DC config req
[2025-07-29 15:06:09.531] I: 80 70 03 00 10 10 19 00 |.p......
[2025-07-29 15:06:09.531] I: 50 62                   |Pb      
[2025-07-29 15:06:09.531] I: Matter enabled state 0
[2025-07-29 15:06:09.531] I: Get Matter Commission State
[2025-07-29 15:06:09.531] I: network state 0
[2025-07-29 15:06:09.541] I: network state 0
[2025-07-29 15:06:09.541] E: Sending UART cmd(70) st 0
[2025-07-29 15:06:09.601] I: Lock State Event
[2025-07-29 15:06:09.601] I: Received response of command id 10
[2025-07-29 15:06:09.601] I: Received Lock State event, lock st: 12
[2025-07-29 15:06:09.601] I: Found matching nordic source of operation 0
[2025-07-29 15:06:09.601] I: ******** TESTING Real Source 0x0000 ********
[2025-07-29 15:06:09.601] I: Unlock action completed
[2025-07-29 15:06:09.601] I: Updating LockState attribute
[2025-07-29 15:06:09.601] ===== Attribute Received are: Cluster=101 Attribute=0 Value=2 =====
[2025-07-29 15:06:09.631] I: Received DC Eco Config REQ
[2025-07-29 15:06:09.661] I: DC Eco Config Resp
[2025-07-29 15:06:09.661] I: Received DC eco config req
[2025-07-29 15:06:09.661] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-29 15:06:09.661] I: c4 62                   |.b      
[2025-07-29 15:06:09.661] E: Sending UART cmd(72) st 0
[2025-07-29 15:06:09.831] I: General Lock Setting event
[2025-07-29 15:06:09.831] I: Received response of command id 20
[2025-07-29 15:06:09.831] I: Received Lock General Setting event
[2025-07-29 15:06:09.831] I: Sound Volume Attribute Update, sound volume 1
[2025-07-29 15:06:09.831] I: Matter Not Enabled do not set
[2025-07-29 15:06:09.941] I: Firmware Attribute event
[2025-07-29 15:06:09.941] I: Received response of command id 30
[2025-07-29 15:06:10.001] I: Hardware Attribute event
[2025-07-29 15:06:10.001] I: Received response of command id 31
[2025-07-29 15:06:10.084] I: Operating mode event
[2025-07-29 15:06:10.084] I: Received response of command id 5
[2025-07-29 15:06:10.084] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-29 15:06:10.084] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 15:06:10.084] I: Set Kwikset Lock App Mode 16
[2025-07-29 15:06:10.084] I: Set Kwikset Lock App State 49
[2025-07-29 15:06:10.084] I: Matter is disabled
[2025-07-29 15:06:10.211] I: Battery Info event
[2025-07-29 15:06:10.211] I: Received response of command id 51
[2025-07-29 15:06:10.211] I: Received Battery info event
[2025-07-29 15:06:10.211] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-29 15:06:10.211] Unhandled cluster ID: 0x  2f
[2025-07-29 15:06:10.211] 
[2025-07-29 15:06:10.211] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-29 15:06:10.211] Unhandled cluster ID: 0x  2f
[2025-07-29 15:06:10.211] 
[2025-07-29 15:06:10.211] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-29 15:06:10.311] I: System info event
[2025-07-29 15:06:10.311] I: Received System Info Event
[2025-07-29 15:06:10.311] W: Time invalid, set time
[2025-07-29 15:06:10.311] I: Get system time
[2025-07-29 15:06:10.311] I: System Real time in seconds 373663017
[2025-07-29 15:06:10.311] I: Time sync status flag 0
[2025-07-29 15:06:10.311] E: Time not sync, keep default value
[2025-07-29 15:06:10.383] I: System init event
[2025-07-29 15:06:10.383] I: Received response of command id 3
[2025-07-29 15:06:10.383] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-29 15:06:10.383] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-29 15:06:10.383] I: STM Image confirm timer was stopped
[2025-07-29 15:06:17.251] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-29 15:06:17.251] I: stop_ota_finalization_timer
[2025-07-29 15:06:17.251] I: After OTAU, Redpine Firmware Version: 2.c.0.3
[2025-07-29 15:06:17.251] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-29 15:06:17.251] I: After OTAU, Secure STM Firmware Version: 17 5 4 1a
[2025-07-29 15:06:17.251] I: Send Op Mode command to release Redpine BLE and WiFI
[2025-07-29 15:06:17.251] I: Operating Mode Command: Mode:10, State:f0
[2025-07-29 15:06:17.251] E: Sending UART cmd(5) st 0
[2025-07-29 15:06:17.301] I: Operating mode event
[2025-07-29 15:06:17.301] I: Received response of command id 5
[2025-07-29 15:06:17.301] I: Received Lock Op Mode Event, mode 10, App state 10
[2025-07-29 15:06:17.301] I: Lock Current Mode : 10, Lock Current State = 10
[2025-07-29 15:06:17.301] I: stop_ota_finalization_timer
[2025-07-29 15:06:17.301] I: STM32 HALO APP STATE IS ACTIVATED NORMAL
[2025-07-29 15:06:17.301] I: Set Kwikset Lock App Mode 16
[2025-07-29 15:06:17.301] I: Set Kwikset Lock App State 16
[2025-07-29 15:06:17.301] I: Matter enabled state 0
[2025-07-29 15:06:17.301] I: Matter is disabled
[2025-07-29 15:06:17.301] I: OTA_HOUSEKEEPING
[2025-07-29 15:06:17.301] I: OTA Stage Change from (3b)->(80)
[2025-07-29 15:06:17.311] I: Start Erasing OTA bundle from nRF External Flash
[2025-07-29 15:06:23.031] I: System info event
[2025-07-29 15:06:23.031] I: Received System Info Event
[2025-07-29 15:06:23.031] I: Time is set in STM
[2025-07-29 15:07:18.441] I: Bundle Image Erased from nRF External Flash: 0
[2025-07-29 15:07:18.441] I: OTAU Completed Successfully
[2025-07-29 15:07:18.551] I: Cleared OTA Meta Data
[2025-07-29 15:07:18.551] I: OTA Stage Change from (80)->(90)
[2025-07-29 15:07:20.554] I: All message synced.
[2025-07-29 15:07:33.541] I: STOP BLE Advertisment
[2025-07-29 15:07:33.561] I: 539185 [DL]DFU over SMP stopped
[2025-07-29 15:07:33.561] E: Sending UART cmd(9e) st 0
[2025-07-29 15:10:20.879] I: Updated ota meta data
[2025-07-29 15:10:20.879] I: Operating Mode Command: Mode:10, State:34
[2025-07-29 15:10:20.891] E: Sending UART cmd(5) st 0
[2025-07-29 15:10:20.971] I: Operating mode event
[2025-07-29 15:10:21.031] I: Received response of command id 5
[2025-07-29 15:10:21.031] I: Received Lock Op Mode Event, mode 10, App state 34
[2025-07-29 15:10:21.031] I: Lock Current Mode : 10, Lock Current State = 34
[2025-07-29 15:10:21.031] I: STM32 HALO APP STATE IS BLE OTAU TRANSFER
[2025-07-29 15:10:21.031] E: Sending UART cmd(9e) st 0
[2025-07-29 15:10:21.031] I: BLE Name set: HU:2784 errCode: 0
[2025-07-29 15:10:21.031] I: 706648 [SWU]SMP BLE advertising started
[2025-07-29 15:10:21.031] I: 706652 [DL]DFU over SMP started
[2025-07-29 15:10:21.031] I: OTA Stage Change from (90)->(11)
[2025-07-29 15:10:21.031] I: Set Kwikset Lock App Mode 16
[2025-07-29 15:10:21.031] I: Set Kwikset Lock App State 52
[2025-07-29 15:10:21.031] I: Matter is disabled
[2025-07-29 15:10:36.292] I: 721935 [DL]Current number of connections: 1/1
[2025-07-29 15:10:36.301] I: BLE Connected
[2025-07-29 15:10:36.531] I: 722172 [DL]Current number of connections: 0/1
[2025-07-29 15:10:36.531] I: BLE Disconnected: 13
[2025-07-29 15:10:40.881] I: 726512 [DL]Current number of connections: 1/1
[2025-07-29 15:10:40.881] I: BLE Connected
[2025-07-29 15:10:41.092] I: 726731 [DL]DFU Image upload started
[2025-07-29 15:10:41.921] I: Connection parameters updated.
[2025-07-29 15:10:41.941]  interval: 9, latency: 0, timeout: 42
[2025-07-29 15:10:41.941] E: No available ACL buffers!
[2025-07-29 15:10:41.941] E: Unexpected first L2CAP frame
[2025-07-29 15:11:00.791] I: OTA Stage Change from (11)->(12)
[2025-07-29 15:11:00.811] I: 746439 [DL]Image 0 download completed successfully
[2025-07-29 15:14:56.342] I: OTA Stage Change from (12)->(11)
[2025-07-29 15:14:56.352] I: Lock Already in OTAU Transport/Update mode
[2025-07-29 15:14:56.352] E: Sending UART cmd(9e) st 0
[2025-07-29 15:14:56.352] I: 981981 [SWU]DFU over SMP was already started
[2025-07-29 15:15:59.052] I: OTA Stage Change from (11)->(11)
[2025-07-29 15:15:59.052] I: Lock Already in OTAU Transport/Update mode
[2025-07-29 15:15:59.052] E: Sending UART cmd(9e) st 0
[2025-07-29 15:15:59.052] I: 1044683 [SWU]DFU over SMP was already started
[2025-07-29 15:17:01.602] I: OTA Stage Change from (11)->(11)
[2025-07-29 15:17:01.602] I: Lock Already in OTAU Transport/Update mode
[2025-07-29 15:17:01.602] E: Sending UART cmd(9e) st 0
[2025-07-29 15:17:01.602] I: 1107236 [SWU]DFU over SMP was already started
[2025-07-29 15:18:04.662] I: OTA Stage Change from (11)->(11)
[2025-07-29 15:18:04.662] I: Lock Already in OTAU Transport/Update mode
[2025-07-29 15:18:04.662] E: Sending UART cmd(9e) st 0
[2025-07-29 15:18:04.662] I: 1170302 [SWU]DFU over SMP was already started
