[2025-07-30 13:07:14.132] 
[2025-07-30 13:07:14.132] 
[2025-07-30 13:07:14.132] uart:~$ *** Booting My Application v23.49.0-de86e88ec64e ***
[2025-07-30 13:07:14.177] *** Using nRF Connect SDK v2.7.0-5cb85570ca43 ***
[2025-07-30 13:07:14.177] *** Using Zephyr OS v3.6.99-100befc70c74 ***
[2025-07-30 13:07:14.177] I: KWIKSET HALO 3 PLUS VERSION: 17.31.00.02
[2025-07-30 13:07:14.177] I: 50 [DL]BLE address: F7:92:6E:9F:EC:28
[2025-07-30 13:07:14.192] I: No users indexes stored
[2025-07-30 13:07:14.192] I: No stored indexes for credential of type: 1
[2025-07-30 13:07:14.311] I: No stored indexes for credential of type: 2
[2025-07-30 13:07:14.311] I: No stored indexes for credential of type: 3
[2025-07-30 13:07:14.311] I: ========== User Index: 0x01 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.311] I: ========== User Index: 0x02 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.311] I: ========== User Index: 0x03 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.311] I: ========== User Index: 0x04 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.311] I: ========== User Index: 0x05 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.311] I: ========== User Index: 0x06 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.311] I: ========== User Index: 0x07 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.311] I: ========== User Index: 0x08 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.311] I: ========== User Index: 0x09 User ID: 0xffffffff ==========
[2025-07-30 13:07:14.332] I: ========== User Index: 0x0a User ID: 0xffffffff ==========
[2025-07-30 13:07:14.332] I: ========== User Index: 0x0b User ID: 0xffffffff ==========
[2025-07-30 13:07:14.332] I: Board config kwiksetmdb_nrf5340_cpuapp
[2025-07-30 13:07:14.332] I: IMAGE_VERSION 17310002
[2025-07-30 13:07:14.332] I: build time: Jun 18 2025 10:48:56
[2025-07-30 13:07:14.332] I: 161 [DL]CHIP task running
[2025-07-30 13:07:14.332] I: Init CHIP stack
[2025-07-30 13:07:14.332] I: 167 [DL]OpenThread started: OK
[2025-07-30 13:07:14.332] I: 170 [DL]Setting OpenThread device type to SLEEPY END DEVICE
[2025-07-30 13:07:14.332] I: 176 [SWU]New firmware image confirmed
[2025-07-30 13:07:14.332] I: 180 [SWU]DFU_BLEAdvertising_Init
[2025-07-30 13:07:14.357] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-30 13:07:14.712] I: NFC Boot Event PN7642 FW VERSION 17.01.00.02
[2025-07-30 13:07:14.712] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-30 13:07:14.712] I: 
[2025-07-30 13:07:14.712] Boot Event Received
[2025-07-30 13:07:14.712] 
[2025-07-30 13:07:14.712] I: Booted NFC IC in Normal Operation Mode.
[2025-07-30 13:07:14.712] 
[2025-07-30 13:07:14.712] I: 263 [SVR]Subscription persistence not supported
[2025-07-30 13:07:14.712] I: 268 [SVR]Server initializing...
[2025-07-30 13:07:14.712] I: 271 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2025-07-30 13:07:14.712] I: 277 [DMG]AccessControl: initializing
[2025-07-30 13:07:14.712] I: 280 [DMG]Examples::AccessControlDelegate::Init
[2025-07-30 13:07:14.712] I: 285 [DMG]AccessControl: setting
[2025-07-30 13:07:14.712] I: 288 [DMG]DefaultAclStorage: initializing
[2025-07-30 13:07:14.712] I: 291 [DMG]DefaultAclStorage: 0 entries loaded
[2025-07-30 13:07:14.732] E: 296 [IN]IPV6_PKTINFO failed: 109
[2025-07-30 13:07:14.732] I: 302 [ZCL]Using ZAP configuration...
[2025-07-30 13:07:14.732] I: 307 [DMG]AccessControlCluster: initializing
[2025-07-30 13:07:14.732] ===== Attribute Received are: Cluster=30 Attribute=0 Value=0 =====
[2025-07-30 13:07:14.732] I: 318 [ZCL]Emit DSTTableEmpty event [ep=0]
[2025-07-30 13:07:14.732] I: 322 [ZCL]Initiating Admin Commissioning cluster.
[2025-07-30 13:07:14.732] I: 327 [ZCL]Door Lock server initialized
[2025-07-30 13:07:14.732] E: 330 [ZCL]DeviceInfoProvider is not registered
[2025-07-30 13:07:14.732] E: 335 [ZCL]Failed to read calendar type with error: 0x86
[2025-07-30 13:07:14.732] ===== Attribute Received are: Cluster=3 Attribute=1 Value=3 =====
[2025-07-30 13:07:14.732] I: 346 [ZCL]Door Lock cluster initialized at endpoint #1
[2025-07-30 13:07:14.732] ===== Attribute Received are: Cluster=101 Attribute=0 Value=255 =====
[2025-07-30 13:07:14.732] ===== Attribute Received are: Cluster=101 Attribute=2 Value=1 =====
[2025-07-30 13:07:14.752] ===== Attribute Received are: Cluster=101 Attribute=1 Value=0 =====
[2025-07-30 13:07:14.752] ===== Attribute Received are: Cluster=101 Attribute=11 Value=11 =====
[2025-07-30 13:07:14.752] ===== Attribute Received are: Cluster=101 Attribute=12 Value=35 =====
[2025-07-30 13:07:14.752] ===== Attribute Received are: Cluster=101 Attribute=13 Value=35 =====
[2025-07-30 13:07:14.752] ===== Attribute Received are: Cluster=101 Attribute=1c Value=35 =====
[2025-07-30 13:07:14.752] ===== Attribute Received are: Cluster=101 Attribute=19 Value=80 =====
[2025-07-30 13:07:14.752] I: 399 [DIS]Updating services using commissioning mode 0
[2025-07-30 13:07:14.752] E: 404 [DIS]Failed to remove advertised services: 3
[2025-07-30 13:07:14.752] E: 409 [DIS]Failed to finalize service update: 3
[2025-07-30 13:07:14.752] I: 413 [IN]CASE Server enabling CASE session setups
[2025-07-30 13:07:14.772] I: 418 [SVR]Joining Multicast groups
[2025-07-30 13:07:14.772] I: 422 [SVR]Server Listening...
[2025-07-30 13:07:14.772] I: 424 [DL]Device Configuration:
[2025-07-30 13:07:14.772] I: 427 [DL]  Serial Number: 1789AE57B32427844F
[2025-07-30 13:07:14.772] I: 432 [DL]  Vendor Id: 5153 (0x1421)
[2025-07-30 13:07:14.772] I: 435 [DL]  Product Id: 66 (0x42)
[2025-07-30 13:07:14.772] I: Get product name B, len 0
[2025-07-30 13:07:14.772] I: 441 [DL]  Product Name: B
[2025-07-30 13:07:14.772] I: 443 [DL]  Hardware Version: 1
[2025-07-30 13:07:14.772] I: 446 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 75655451
[2025-07-30 13:07:14.772] I: 451 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 776 (0x308)
[2025-07-30 13:07:14.772] I: 458 [DL]  Manufacturing Date: 2025-07-24
[2025-07-30 13:07:14.772] I: 462 [DL]  Device Type: 10 (0xA)
[2025-07-30 13:07:14.772] I: 465 [SVR]SetupQRCode: [MT:-QWJ08DB00.I2N6SM10]
[2025-07-30 13:07:14.772] I: 469 [SVR]Copy/paste the below URL in a browser to see the QR Code:
[2025-07-30 13:07:14.799] I: 475 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-QWJ08DB00.I2N6SM10
[2025-07-30 13:07:14.799] I: 484 [SVR]Manual pairing code: [05967546175]
[2025-07-30 13:07:14.799] I: STM32 device number: 
[2025-07-30 13:07:14.799] I: 31 37 38 39 41 45 35 37 |1789AE57
[2025-07-30 13:07:14.799] I: 42 33 32 34 32 37 38 34 |B3242784
[2025-07-30 13:07:14.799] I: 34 46                   |4F      
[2025-07-30 13:07:14.799] I: SKU number: 
[2025-07-30 13:07:14.799] I: 4b 31 37 2d 30 31       |K17-01  
[2025-07-30 13:07:14.799] I: WO number: 
[2025-07-30 13:07:14.799] I: 30 30 30 30 30 30 30 30 |00000000
[2025-07-30 13:07:14.799] I: 30                      |0       
[2025-07-30 13:07:14.799] I: Manuf Date: 
[2025-07-30 13:07:14.799] I: 32 30 32 35 2d 30 37 2d |2025-07-
[2025-07-30 13:07:14.799] I: 32 34 00 00 00 00       |24....  
[2025-07-30 13:07:14.799] I: Prod config length 6
[2025-07-30 13:07:14.814] I: Product Config: 
[2025-07-30 13:07:14.814] I: 30 78 30 30 30 31       |0x0001  
[2025-07-30 13:07:14.814] I: Prod Config Read 1
[2025-07-30 13:07:14.814] I: User intend flow enabled, set commissioning flow to kUserActionRequired
[2025-07-30 13:07:14.814] I: Factory Data Version length 2
[2025-07-30 13:07:14.814] I: Factory Data Ver: 
[2025-07-30 13:07:14.814] I: 30 31                   |01      
[2025-07-30 13:07:14.814] I: Payload value in string format: MT:-QWJ04TC00.I2N60Q4P0ILT70VYYR1JFSK14YDB0-0LJ1-0LJ1-0LJ1IHLC0AUZL1XIKJ17AZL1UV700CXYR1K6Y12NNZR1YC-L1-2ZR1OADO1KB40
[2025-07-30 13:07:14.814] I: Pairing Code value in string format: 459675461705153000660
[2025-07-30 13:07:14.814] I: ============== Updating product finish and color to 15, 2, product Name Halo Select Plus ==============
[2025-07-30 13:07:14.814] E: 575 [DL]Long dispatch time: 411 ms, for event type 2
[2025-07-30 13:07:14.814] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:07:16.262] I: Syncing up on message 9a
[2025-07-30 13:07:16.311] I: STM32 counter to 1
[2025-07-30 13:07:16.311] I: BLE Device ID: 2784
[2025-07-30 13:07:16.311] I: Device is provisioned
[2025-07-30 13:07:16.311] I: network state 0
[2025-07-30 13:07:16.311] E: Sending UART cmd(3) st 0
[2025-07-30 13:07:16.311] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:07:16.311] I: Received response of command id 9a
[2025-07-30 13:07:16.311] I: Command 0x9A Received
[2025-07-30 13:07:16.311] I: Firmware Attribute event
[2025-07-30 13:07:16.311] I: Received response of command id 30
[2025-07-30 13:07:16.342] I: Received DC Eco Config REQ
[2025-07-30 13:07:16.342] I: DC Eco Config Resp
[2025-07-30 13:07:16.342] I: Received DC eco config req
[2025-07-30 13:07:16.342] I: 80 72 03 00 10 00 04 1b |.r......
[2025-07-30 13:07:16.342] I: 17 05                   |..      
[2025-07-30 13:07:16.342] E: Sending UART cmd(72) st 0
[2025-07-30 13:07:18.312] I: Syncing up on message 3
[2025-07-30 13:07:18.312] I: Sys init req
[2025-07-30 13:07:18.312] E: Sending UART cmd(3) st 0
[2025-07-30 13:07:18.312] I: System init Response
[2025-07-30 13:07:18.312] I: Received response of command id 3
[2025-07-30 13:07:18.312] I: Update sync timer
[2025-07-30 13:07:18.312] I: Received Sys Init Resp
[2025-07-30 13:07:18.312] I: battery mode 0
[2025-07-30 13:07:18.312] I: battery percentage 5a
[2025-07-30 13:07:18.312] I: battery type 1
[2025-07-30 13:07:18.312] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:07:18.792] I: Syncing up on message 5
[2025-07-30 13:07:18.792] I: Operating mode req
[2025-07-30 13:07:18.832] E: Sending UART cmd(5) st 0
[2025-07-30 13:07:18.832] I: Operating mode response
[2025-07-30 13:07:18.832] I: Received response of command id 5
[2025-07-30 13:07:18.832] I: Received Lock Op Mode Resp, mode 10, App state 31
[2025-07-30 13:07:18.832] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:07:18.832] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:07:18.832] I: Set Kwikset Lock App State 49
[2025-07-30 13:07:18.832] I: Matter is disabled
[2025-07-30 13:07:19.342] I: Syncing up on message 10
[2025-07-30 13:07:19.342] I: Lock state req
[2025-07-30 13:07:19.342] E: Sending UART cmd(10) st 0
[2025-07-30 13:07:19.342] I: Lock State Response
[2025-07-30 13:07:19.342] I: Received response of command id 10
[2025-07-30 13:07:19.342] I: Received Lock State Response, lock st: 11
[2025-07-30 13:07:19.342] I: Found matching nordic source of operation 0
[2025-07-30 13:07:19.342] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:07:19.342] I: Lock action completed
[2025-07-30 13:07:19.342] I: Updating LockState attribute
[2025-07-30 13:07:19.342] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:07:19.792] I: Syncing up on message 20
[2025-07-30 13:07:19.822] I: Lock setting req
[2025-07-30 13:07:19.831] E: Sending UART cmd(20) st 0
[2025-07-30 13:07:19.831] I: Lock General Setting Response
[2025-07-30 13:07:19.831] I: Received response of command id 20
[2025-07-30 13:07:19.831] I: Received Lock General Setting resp
[2025-07-30 13:07:19.831] I: Matter Not Enabled do not set
[2025-07-30 13:07:20.292] I: Syncing up on message 51
[2025-07-30 13:07:20.292] I: Battery info req
[2025-07-30 13:07:20.292] E: Sending UART cmd(51) st 0
[2025-07-30 13:07:20.332] I: Received response of command id 51
[2025-07-30 13:07:20.332] I: Received Battery Info resp
[2025-07-30 13:07:20.332] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:07:20.332] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:07:20.332] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:07:20.804] I: All message synced.
[2025-07-30 13:07:44.282] I: STM system init timer expired, System Init Event not received from STM32
[2025-07-30 13:07:44.322] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-30 13:07:44.322] I: STM Pending =1, Redpine Pending = 1
[2025-07-30 13:07:44.322] I: STM Post OTA Pending
[2025-07-30 13:07:44.322] I: Redpine Post OTA Pending
[2025-07-30 13:07:44.322] E: Sending UART cmd(9e) st 0
[2025-07-30 13:07:44.322] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:07:44.322] I: 30191 [SWU]SMP BLE advertising started
[2025-07-30 13:07:44.322] I: 30196 [DL]DFU over SMP started
[2025-07-30 13:07:45.202] I: IMG Integrity Verified Successfully: 0
[2025-07-30 13:07:48.192] I: IMG Integrity Verified Successfully: 1
[2025-07-30 13:07:48.272] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:07:48.562] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:07:48.592] I: OTA Stage Change from (ff)->(32)
[2025-07-30 13:07:48.592] I: OTA device_id = 5 : DISCOVERY_REQ
[2025-07-30 13:07:48.715] I: SECURE_STM : IB_DEVICE_DISCOVERY_REQUEST (80) 
[2025-07-30 13:07:48.715] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:07:48.715] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-30 13:07:48.715] I: STM New OTA Firmware Version = 17 5 4 1b
[2025-07-30 13:07:48.715] I: OTA device_id = 5 : FW_UPDATE_START_REQ
[2025-07-30 13:07:48.715] I: SECURE_STM : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-30 13:07:55.062] I: STM OTA Progress = 10
[2025-07-30 13:08:01.401] I: STM OTA Progress = 20
[2025-07-30 13:08:07.714] I: STM OTA Progress = 30
[2025-07-30 13:08:14.142] I: STM OTA Progress = 40
[2025-07-30 13:08:20.461] I: STM OTA Progress = 50
[2025-07-30 13:08:26.782] I: STM OTA Progress = 60
[2025-07-30 13:08:33.092] I: STM OTA Progress = 70
[2025-07-30 13:08:39.434] I: STM OTA Progress = 80
[2025-07-30 13:08:45.752] I: STM OTA Progress = 90
[2025-07-30 13:08:52.067] I: STM OTA Progress = 100
[2025-07-30 13:08:52.742] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-30 13:08:52.754] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-30 13:09:10.392] I: Sending Sys Init Resp
[2025-07-30 13:09:10.392] I: Device is provisioned
[2025-07-30 13:09:10.392] I: network state 0
[2025-07-30 13:09:10.392] E: Sending UART cmd(3) st 0
[2025-07-30 13:09:10.392] I: Received DC App Config REQ
[2025-07-30 13:09:10.392] I: DC App Config Resp
[2025-07-30 13:09:10.392] I: Received DC config req
[2025-07-30 13:09:10.392] I: 80 70 03 00 10 10 08 00 |.p......
[2025-07-30 13:09:10.392] I: 50 1e                   |P.      
[2025-07-30 13:09:10.392] I: Matter enabled state 0
[2025-07-30 13:09:10.392] I: Get Matter Commission State
[2025-07-30 13:09:10.392] I: network state 0
[2025-07-30 13:09:10.392] I: network state 0
[2025-07-30 13:09:10.392] E: Sending UART cmd(70) st 0
[2025-07-30 13:09:10.456] I: Lock State Event
[2025-07-30 13:09:10.456] I: Received response of command id 10
[2025-07-30 13:09:10.456] I: Received Lock State event, lock st: 11
[2025-07-30 13:09:10.456] I: Found matching nordic source of operation 0
[2025-07-30 13:09:10.456] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:09:10.456] I: Lock action completed
[2025-07-30 13:09:10.456] I: Updating LockState attribute
[2025-07-30 13:09:10.456] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:09:10.492] I: Received DC Eco Config REQ
[2025-07-30 13:09:10.518] I: DC Eco Config Resp
[2025-07-30 13:09:10.518] I: Received DC eco config req
[2025-07-30 13:09:10.518] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:09:10.518] I: c4 1e                   |..      
[2025-07-30 13:09:10.518] E: Sending UART cmd(72) st 0
[2025-07-30 13:09:10.692] I: General Lock Setting event
[2025-07-30 13:09:10.692] I: Received response of command id 20
[2025-07-30 13:09:10.692] I: Received Lock General Setting event
[2025-07-30 13:09:10.692] I: Matter Not Enabled do not set
[2025-07-30 13:09:10.802] I: Firmware Attribute event
[2025-07-30 13:09:10.802] I: Received response of command id 30
[2025-07-30 13:09:10.862] I: Hardware Attribute event
[2025-07-30 13:09:10.862] I: Received response of command id 31
[2025-07-30 13:09:10.932] I: Operating mode event
[2025-07-30 13:09:10.932] I: Received response of command id 5
[2025-07-30 13:09:10.932] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:09:10.932] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:09:10.932] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:09:10.932] I: Set Kwikset Lock App State 49
[2025-07-30 13:09:10.932] I: Matter is disabled
[2025-07-30 13:09:11.052] I: Battery Info event
[2025-07-30 13:09:11.052] I: Received response of command id 51
[2025-07-30 13:09:11.052] I: Received Battery info event
[2025-07-30 13:09:11.052] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:09:11.052] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:09:11.052] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:09:11.132] I: System info event
[2025-07-30 13:09:11.162] I: Received System Info Event
[2025-07-30 13:09:11.162] W: Time invalid, set time
[2025-07-30 13:09:11.162] I: Get system time
[2025-07-30 13:09:11.162] I: System Real time in seconds 373662943
[2025-07-30 13:09:11.162] I: Time sync status flag 0
[2025-07-30 13:09:11.162] E: Time not sync, keep default value
[2025-07-30 13:09:11.202] I: System init event
[2025-07-30 13:09:11.262] I: Received response of command id 3
[2025-07-30 13:09:11.262] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:09:11.262] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:09:11.262] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:09:11.262] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-30 13:09:11.262] I: OTA device_id = 5 : FW_UPDATE_COMPLETE_REQ
[2025-07-30 13:09:11.262] I: SECURE_STM : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-30 13:09:11.262] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-30 13:09:11.262] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-30 13:09:13.712] I: Sending Sys Init Resp
[2025-07-30 13:09:13.753] I: Device is provisioned
[2025-07-30 13:09:13.753] I: network state 0
[2025-07-30 13:09:13.753] E: Sending UART cmd(3) st 0
[2025-07-30 13:09:13.753] I: Received DC App Config REQ
[2025-07-30 13:09:13.753] I: DC App Config Resp
[2025-07-30 13:09:13.753] I: Received DC config req
[2025-07-30 13:09:13.753] I: 80 70 03 00 10 10 04 1b |.p......
[2025-07-30 13:09:13.753] I: 00 62                   |.b      
[2025-07-30 13:09:13.753] I: Matter enabled state 0
[2025-07-30 13:09:13.753] I: Get Matter Commission State
[2025-07-30 13:09:13.753] I: network state 0
[2025-07-30 13:09:13.753] I: network state 0
[2025-07-30 13:09:13.753] E: Sending UART cmd(70) st 0
[2025-07-30 13:09:13.782] I: Lock State Event
[2025-07-30 13:09:13.782] I: Received response of command id 10
[2025-07-30 13:09:13.822] I: Received Lock State event, lock st: 11
[2025-07-30 13:09:13.822] I: Found matching nordic source of operation 0
[2025-07-30 13:09:13.822] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:09:13.822] I: Lock action completed
[2025-07-30 13:09:13.822] I: Updating LockState attribute
[2025-07-30 13:09:13.822] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:09:13.882] I: Received DC Eco Config REQ
[2025-07-30 13:09:13.882] I: DC Eco Config Resp
[2025-07-30 13:09:13.882] I: Received DC eco config req
[2025-07-30 13:09:13.882] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:09:13.882] I: c4 62                   |.b      
[2025-07-30 13:09:13.882] E: Sending UART cmd(72) st 0
[2025-07-30 13:09:14.052] I: General Lock Setting event
[2025-07-30 13:09:14.052] I: Received response of command id 20
[2025-07-30 13:09:14.062] I: Received Lock General Setting event
[2025-07-30 13:09:14.062] I: Matter Not Enabled do not set
[2025-07-30 13:09:14.153] I: Firmware Attribute event
[2025-07-30 13:09:14.153] I: Received response of command id 30
[2025-07-30 13:09:14.232] I: Hardware Attribute event
[2025-07-30 13:09:14.232] I: Received response of command id 31
[2025-07-30 13:09:14.302] I: Operating mode event
[2025-07-30 13:09:14.302] I: Received response of command id 5
[2025-07-30 13:09:14.302] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:09:14.302] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:09:14.302] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:09:14.302] I: Set Kwikset Lock App State 49
[2025-07-30 13:09:14.302] I: Matter is disabled
[2025-07-30 13:09:14.422] I: Battery Info event
[2025-07-30 13:09:14.422] I: Received response of command id 51
[2025-07-30 13:09:14.422] I: Received Battery info event
[2025-07-30 13:09:14.422] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:09:14.422] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:09:14.422] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:09:14.532] I: System info event
[2025-07-30 13:09:14.542] I: Received System Info Event
[2025-07-30 13:09:14.542] W: Time invalid, set time
[2025-07-30 13:09:14.542] I: Get system time
[2025-07-30 13:09:14.542] I: System Real time in seconds 373662943
[2025-07-30 13:09:14.542] I: Time sync status flag 0
[2025-07-30 13:09:14.542] E: Time not sync, keep default value
[2025-07-30 13:09:14.622] I: System init event
[2025-07-30 13:09:14.622] I: Received response of command id 3
[2025-07-30 13:09:14.624] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:09:14.624] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:09:14.624] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:09:14.624] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-30 13:09:14.624] I: STM New OTA Firmware Version = 17 5 4 1b
[2025-07-30 13:09:14.624] I: STM Secure OTA Successful
[2025-07-30 13:09:14.730] I: Cleared STM OTA Meta Data
[2025-07-30 13:09:14.730] I: OTA Stage Change from (32)->(33)
[2025-07-30 13:09:14.730] I: Redpine OTA started
[2025-07-30 13:09:14.730] I: OTA Stage Change from (33)->(34)
[2025-07-30 13:09:14.730] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-30 13:09:21.719] I: STM Reset Count 0
[2025-07-30 13:09:21.752] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-30 13:09:21.752] I: STM_QSPI : IB_DEVICE_DISCOVERY_REQUEST (80)
[2025-07-30 13:09:21.752] I: OTA device_id = 4 : FW_VERSION_REQ
[2025-07-30 13:09:21.752] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-30 13:09:21.752] I: Redpine Current Firmware Version: 2.c.0.3
[2025-07-30 13:09:21.772] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-30 13:09:21.772] I: Skip Redpine OTA, Older OTA Version Request Received
[2025-07-30 13:09:21.852] I: Clear Redpine OTA Meta Data
[2025-07-30 13:09:21.892] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-30 13:09:21.892] I: STM Pending =2, Redpine Pending = 2
[2025-07-30 13:09:21.892] I: PN76 IMG 1 Post OTA Pending
[2025-07-30 13:09:21.892] E: Sending UART cmd(9e) st 0
[2025-07-30 13:09:21.892] I: 127759 [SWU]Software update is already enabled
[2025-07-30 13:09:21.972] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:09:22.252] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:09:22.300] I: OTA Stage Change from (34)->(3a)
[2025-07-30 13:09:22.300] I: PN76_IMG1_DEVICE_DFU_MULTI_IMG_ID
[2025-07-30 13:09:22.302] I: PN76_IMG Update from OTA Task Event
[2025-07-30 13:09:22.302] I: 
[2025-07-30 13:09:22.302] 
[2025-07-30 13:09:22.302] --------------- UPDATING PN7642 NXP FIRMWARE --------------------
[2025-07-30 13:09:22.302] 
[2025-07-30 13:09:22.302] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-30 13:09:22.342] I: pNXPFWInfo->img_offset = 0x35149a
[2025-07-30 13:09:22.342] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-30 13:09:22.342] I: Reading version of firmware in QSPI flash: MetaData 0x3f60217
[2025-07-30 13:09:22.342] I: NXP FW Version 2 f6 : 2 f6
[2025-07-30 13:09:22.342] I: PN76 NXP FW VERSION IS EQUAL
[2025-07-30 13:09:22.342] I: 
[2025-07-30 13:09:22.342] PN7642 Firmware of type 0 Successfully Updated !!!
[2025-07-30 13:09:22.422] I: Cleared PN76 Img1 OTA Meta Data
[2025-07-30 13:09:22.462] I: OTA Stage Change from (3a)->(3a)
[2025-07-30 13:09:22.462] I: PN76_IMG2_DEVICE_DFU_MULTI_IMG_ID
[2025-07-30 13:09:22.462] I: PN76_IMG Update from OTA Task Event
[2025-07-30 13:09:22.462] I: 
[2025-07-30 13:09:22.462] 
[2025-07-30 13:09:22.462] --------------- UPDATING PN7642 APPLICATION FIRMWARE -------------
[2025-07-30 13:09:22.462] 
[2025-07-30 13:09:22.462] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-30 13:09:22.504] I: pCustAppFWInfo->img_offset = 0x35c28c
[2025-07-30 13:09:22.504] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-30 13:09:22.504] I: Reading version of firmware in QSPI flash: MetaData 0x3f60217
[2025-07-30 13:09:22.504] I: PN76 NXP APP FW VERSION IS HIGHER
[2025-07-30 13:09:22.805] I: ----> PN7642 OTA Progress = 10 %
[2025-07-30 13:09:23.082] I: ----> PN7642 OTA Progress = 20 %
[2025-07-30 13:09:23.332] I: ----> PN7642 OTA Progress = 30 %
[2025-07-30 13:09:23.592] I: ----> PN7642 OTA Progress = 40 %
[2025-07-30 13:09:23.842] I: ----> PN7642 OTA Progress = 50 %
[2025-07-30 13:09:24.122] I: ----> PN7642 OTA Progress = 60 %
[2025-07-30 13:09:24.372] I: ----> PN7642 OTA Progress = 70 %
[2025-07-30 13:09:24.642] I: ----> PN7642 OTA Progress = 80 %
[2025-07-30 13:09:24.905] I: ----> PN7642 OTA Progress = 90 %
[2025-07-30 13:09:25.162] I: ----> PN7642 OTA Progress = 100 %
[2025-07-30 13:09:25.162] I: Whole pn7642 FW Image downloaded ....
[2025-07-30 13:09:25.182] I: 
[2025-07-30 13:09:25.182] 
[2025-07-30 13:09:25.182] I: 
[2025-07-30 13:09:25.182] PN7642 Firmware of type 1 Successfully Updated !!!
[2025-07-30 13:09:25.262] I: Cleared PN76 Img2 OTA Meta Data
[2025-07-30 13:09:25.372] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-30 13:09:25.372] I: NFC Boot Event PN7642 FW VERSION 17.01.00.03
[2025-07-30 13:09:25.372] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-30 13:09:25.372] I: 
[2025-07-30 13:09:25.372] Boot Event Received
[2025-07-30 13:09:25.372] 
[2025-07-30 13:09:25.372] I: Booted NFC IC in Normal Operation Mode.
[2025-07-30 13:09:25.372] 
[2025-07-30 13:09:25.372] I: OTA Stage Change from (3a)->(3b)
[2025-07-30 13:09:25.372] I: post_stm_reset_event : init_pending_ota_update
[2025-07-30 13:09:25.372] I: All pending FW Updates are completed.
[2025-07-30 13:09:25.372] I: STM32 Reset Count = 0
[2025-07-30 13:09:25.372] I: REBOOT_STM: Send STM32 Reboot Command, Count (0)
[2025-07-30 13:09:27.742] I: Sending Sys Init Resp
[2025-07-30 13:09:27.742] I: Device is provisioned
[2025-07-30 13:09:27.742] I: network state 0
[2025-07-30 13:09:27.742] E: Sending UART cmd(3) st 0
[2025-07-30 13:09:27.742] I: Received DC App Config REQ
[2025-07-30 13:09:27.742] I: DC App Config Resp
[2025-07-30 13:09:27.742] I: Received DC config req
[2025-07-30 13:09:27.742] I: 80 70 03 00 10 10 00 03 |.p......
[2025-07-30 13:09:27.742] I: 00 62                   |.b      
[2025-07-30 13:09:27.742] I: Matter enabled state 0
[2025-07-30 13:09:27.742] I: Get Matter Commission State
[2025-07-30 13:09:27.742] I: network state 0
[2025-07-30 13:09:27.752] I: network state 0
[2025-07-30 13:09:27.752] E: Sending UART cmd(70) st 0
[2025-07-30 13:09:27.812] I: Lock State Event
[2025-07-30 13:09:27.812] I: Received response of command id 10
[2025-07-30 13:09:27.812] I: Received Lock State event, lock st: 11
[2025-07-30 13:09:27.812] I: Found matching nordic source of operation 0
[2025-07-30 13:09:27.812] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:09:27.812] I: Lock action completed
[2025-07-30 13:09:27.812] I: Updating LockState attribute
[2025-07-30 13:09:27.812] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:09:27.842] I: Received DC Eco Config REQ
[2025-07-30 13:09:27.872] I: DC Eco Config Resp
[2025-07-30 13:09:27.872] I: Received DC eco config req
[2025-07-30 13:09:27.872] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:09:27.872] I: c4 62                   |.b      
[2025-07-30 13:09:27.872] E: Sending UART cmd(72) st 0
[2025-07-30 13:09:28.052] I: General Lock Setting event
[2025-07-30 13:09:28.052] I: Received response of command id 20
[2025-07-30 13:09:28.052] I: Received Lock General Setting event
[2025-07-30 13:09:28.052] I: Matter Not Enabled do not set
[2025-07-30 13:09:28.148] I: Firmware Attribute event
[2025-07-30 13:09:28.150] I: Received response of command id 30
[2025-07-30 13:09:28.222] I: Hardware Attribute event
[2025-07-30 13:09:28.222] I: Received response of command id 31
[2025-07-30 13:09:28.292] I: Operating mode event
[2025-07-30 13:09:28.302] I: Received response of command id 5
[2025-07-30 13:09:28.302] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:09:28.302] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:09:28.302] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:09:28.302] I: Set Kwikset Lock App State 49
[2025-07-30 13:09:28.302] I: Matter is disabled
[2025-07-30 13:09:28.422] I: Battery Info event
[2025-07-30 13:09:28.422] I: Received response of command id 51
[2025-07-30 13:09:28.422] I: Received Battery info event
[2025-07-30 13:09:28.422] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:09:28.422] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:09:28.422] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:09:28.532] I: System info event
[2025-07-30 13:09:28.532] I: Received System Info Event
[2025-07-30 13:09:28.532] W: Time invalid, set time
[2025-07-30 13:09:28.532] I: Get system time
[2025-07-30 13:09:28.532] I: System Real time in seconds 373662943
[2025-07-30 13:09:28.532] I: Time sync status flag 0
[2025-07-30 13:09:28.532] E: Time not sync, keep default value
[2025-07-30 13:09:28.592] I: System init event
[2025-07-30 13:09:28.592] I: Received response of command id 3
[2025-07-30 13:09:28.592] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:09:28.592] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:09:35.412] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-30 13:09:35.412] I: stop_ota_finalization_timer
[2025-07-30 13:09:35.412] I: After OTAU, Redpine Firmware Version: 2.c.0.3
[2025-07-30 13:09:35.412] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-30 13:09:35.412] I: After OTAU, Secure STM Firmware Version: 17 5 4 1b
[2025-07-30 13:09:35.412] I: Send Op Mode command to release Redpine BLE and WiFI
[2025-07-30 13:09:35.412] I: Operating Mode Command: Mode:10, State:f0
[2025-07-30 13:09:35.412] E: Sending UART cmd(5) st 0
[2025-07-30 13:09:35.462] I: Operating mode event
[2025-07-30 13:09:35.462] I: Received response of command id 5
[2025-07-30 13:09:35.462] I: Received Lock Op Mode Event, mode 10, App state 10
[2025-07-30 13:09:35.462] I: Lock Current Mode : 10, Lock Current State = 10
[2025-07-30 13:09:35.462] I: stop_ota_finalization_timer
[2025-07-30 13:09:35.462] I: STM32 HALO APP STATE IS ACTIVATED NORMAL
[2025-07-30 13:09:35.462] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:09:35.462] I: Set Kwikset Lock App State 16
[2025-07-30 13:09:35.462] I: Matter enabled state 0
[2025-07-30 13:09:35.472] I: Matter is disabled
[2025-07-30 13:09:35.472] I: OTA_HOUSEKEEPING
[2025-07-30 13:09:35.472] I: OTA Stage Change from (3b)->(80)
[2025-07-30 13:09:35.472] I: Start Erasing OTA bundle from nRF External Flash
[2025-07-30 13:09:41.122] I: System info event
[2025-07-30 13:09:41.122] I: Received System Info Event
[2025-07-30 13:09:41.122] I: Time is set in STM
[2025-07-30 13:09:44.592] I: STM Boot Up Properly, Stopped STM Reboot Timer
[2025-07-30 13:10:36.012] I: Bundle Image Erased from nRF External Flash: 0
[2025-07-30 13:10:36.092] I: OTAU Completed Successfully
[2025-07-30 13:10:36.189] I: Cleared OTA Meta Data
[2025-07-30 13:10:36.202] I: OTA Stage Change from (80)->(90)
[2025-07-30 13:10:38.202] I: All message synced.
[2025-07-30 13:10:51.212] I: STOP BLE Advertisment
[2025-07-30 13:10:51.212] I: 217086 [DL]DFU over SMP stopped
[2025-07-30 13:10:51.212] E: Sending UART cmd(9e) st 0
[2025-07-30 13:13:33.333] I: Updated ota meta data
[2025-07-30 13:13:33.333] I: Operating Mode Command: Mode:10, State:34
[2025-07-30 13:13:33.349] E: Sending UART cmd(5) st 0
[2025-07-30 13:13:33.422] I: Operating mode event
[2025-07-30 13:13:33.483] I: Received response of command id 5
[2025-07-30 13:13:33.483] I: Received Lock Op Mode Event, mode 10, App state 34
[2025-07-30 13:13:33.483] I: Lock Current Mode : 10, Lock Current State = 34
[2025-07-30 13:13:33.483] I: STM32 HALO APP STATE IS BLE OTAU TRANSFER
[2025-07-30 13:13:33.483] E: Sending UART cmd(9e) st 0
[2025-07-30 13:13:33.483] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:13:33.483] I: 379346 [SWU]SMP BLE advertising started
[2025-07-30 13:13:33.483] I: 379351 [DL]DFU over SMP started
[2025-07-30 13:13:33.483] I: OTA Stage Change from (90)->(11)
[2025-07-30 13:13:33.483] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:13:33.483] I: Set Kwikset Lock App State 52
[2025-07-30 13:13:33.492] I: Matter is disabled
[2025-07-30 13:13:48.533] I: 394423 [DL]DFU-BLE-Connected
[2025-07-30 13:13:48.533] I: stop_ble_advertisment_timer
[2025-07-30 13:13:48.552] I: 394429 [DL]Current number of connections: 1/1
[2025-07-30 13:13:48.552] I: BLE Connected
[2025-07-30 13:13:48.792] I: 394663 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:13:48.792] I: 394666 [DL]Current number of connections: 0/1
[2025-07-30 13:13:48.792] I: BLE Disconnected: 13
[2025-07-30 13:13:53.673] I: 399537 [DL]DFU-BLE-Connected
[2025-07-30 13:13:53.673] I: stop_ble_advertisment_timer
[2025-07-30 13:13:53.673] I: 399542 [DL]Current number of connections: 1/1
[2025-07-30 13:13:53.673] I: BLE Connected
[2025-07-30 13:13:53.876] I: 399756 [DL]DFU Image upload started
[2025-07-30 13:13:54.712] I: Connection parameters updated.
[2025-07-30 13:13:54.732]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:14:01.223] I: OTA Stage Change from (11)->(12)
[2025-07-30 13:14:01.223] I: 407097 [DL]Image 0 download completed successfully
[2025-07-30 13:14:01.323] I: 407195 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:14:01.323] I: 407199 [DL]Current number of connections: 0/1
[2025-07-30 13:14:01.323] I: BLE Disconnected: 13
[2025-07-30 13:14:13.282] I: 419178 [DL]DFU-BLE-Connected
[2025-07-30 13:14:13.312] I: stop_ble_advertisment_timer
[2025-07-30 13:14:13.312] I: 419184 [DL]Current number of connections: 1/1
[2025-07-30 13:14:13.312] I: BLE Connected
[2025-07-30 13:14:13.513] I: 419404 [DL]DFU Image upload started
[2025-07-30 13:14:14.342] I: Connection parameters updated.
[2025-07-30 13:14:14.352]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:14:50.272] I: OTA Stage Change from (12)->(13)
[2025-07-30 13:14:50.292] I: 456167 [DL]Image 1 download completed successfully
[2025-07-30 13:14:50.392] I: 456267 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:14:50.392] I: 456271 [DL]Current number of connections: 0/1
[2025-07-30 13:14:50.392] I: BLE Disconnected: 13
[2025-07-30 13:14:57.833] I: 463701 [DL]DFU-BLE-Connected
[2025-07-30 13:14:57.833] I: stop_ble_advertisment_timer
[2025-07-30 13:14:57.833] I: 463706 [DL]Current number of connections: 1/1
[2025-07-30 13:14:57.833] I: BLE Connected
[2025-07-30 13:14:58.057] I: 463946 [DL]DFU Image upload started
[2025-07-30 13:14:58.872] I: Connection parameters updated.
[2025-07-30 13:14:58.872]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:16:49.602] I: OTA Stage Change from (13)->(14)
[2025-07-30 13:16:49.602] I: 575494 [DL]Image 2 download completed successfully
[2025-07-30 13:16:49.693] I: 575587 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:16:49.693] I: 575591 [DL]Current number of connections: 0/1
[2025-07-30 13:16:49.712] I: BLE Disconnected: 13
[2025-07-30 13:16:56.642] I: 582511 [DL]DFU-BLE-Connected
[2025-07-30 13:16:56.642] I: stop_ble_advertisment_timer
[2025-07-30 13:16:56.642] I: 582516 [DL]Current number of connections: 1/1
[2025-07-30 13:16:56.642] I: BLE Connected
[2025-07-30 13:16:56.853] I: 582731 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:16:56.853] I: 582735 [DL]Current number of connections: 0/1
[2025-07-30 13:16:56.853] I: BLE Disconnected: 13
[2025-07-30 13:17:00.713] I: 586583 [DL]DFU-BLE-Connected
[2025-07-30 13:17:00.713] I: stop_ble_advertisment_timer
[2025-07-30 13:17:00.713] I: 586588 [DL]Current number of connections: 1/1
[2025-07-30 13:17:00.713] I: BLE Connected
[2025-07-30 13:17:00.913] I: 586792 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-30 13:17:00.942] I: 586819 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:17:00.942] I: 586822 [DL]Current number of connections: 0/1
[2025-07-30 13:17:00.942] I: BLE Disconnected: 13
[2025-07-30 13:17:08.353] I: 594242 [DL]DFU-BLE-Connected
[2025-07-30 13:17:08.373] I: stop_ble_advertisment_timer
[2025-07-30 13:17:08.373] I: 594248 [DL]Current number of connections: 1/1
[2025-07-30 13:17:08.373] I: BLE Connected
[2025-07-30 13:17:08.579] I: 594450 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-30 13:17:08.603] I: 594476 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:17:08.603] I: 594480 [DL]Current number of connections: 0/1
[2025-07-30 13:17:08.603] I: BLE Disconnected: 13
[2025-07-30 13:17:16.283] I: 602153 [DL]DFU-BLE-Connected
[2025-07-30 13:17:16.283] I: stop_ble_advertisment_timer
[2025-07-30 13:17:16.283] I: 602158 [DL]Current number of connections: 1/1
[2025-07-30 13:17:16.283] I: BLE Connected
[2025-07-30 13:17:16.473] I: STM Pending =0, Redpine Pending = 0
[2025-07-30 13:17:16.573] I: Count = 4
[2025-07-30 13:17:16.573] I: dfu_header_data.image_count: 4
[2025-07-30 13:17:17.333] I: Connection parameters updated.
[2025-07-30 13:17:17.333]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:17:17.462] I: IMG Integrity Verified Successfully: 0
[2025-07-30 13:17:20.453] I: IMG Integrity Verified Successfully: 1
[2025-07-30 13:17:20.533] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:17:20.893] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:17:20.893] I: OTA Bundle(STM32 + RS9116 + PN76) image integrity Verified
[2025-07-30 13:17:20.893] I: OTA Stage Change from (14)->(30)
[2025-07-30 13:17:20.993] I: Updated ota meta data
[2025-07-30 13:17:20.993] I: Operating Mode Command: Mode:10, State:31
[2025-07-30 13:17:20.993] E: Sending UART cmd(5) st 0
[2025-07-30 13:17:20.993] I: Operating mode event
[2025-07-30 13:17:21.033] I: Received response of command id 5
[2025-07-30 13:17:21.033] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:17:21.033] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:17:21.033] I: STM OTAU Pending: Reset Nordic Triggered
[2025-07-30 13:17:21.033] I: OTA Stage Change from (30)->(30)
[2025-07-30 13:17:21.042] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:17:21.042] I: Set Kwikset Lock App State 49
[2025-07-30 13:17:21.042] I: Matter is disabled
[2025-07-30 13:17:21.083] I: 606960 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:17:21.083] I: 606963 [DL]Current number of connections: 0/1
[2025-07-30 13:17:21.083] I: BLE Disconnected: 13
[2025-07-30 13:18:08.523] 
[2025-07-30 13:18:08.523] uart:~$ *** Booting My Application v23.55.5-2f9996e8c87c ***
[2025-07-30 13:18:08.543] *** Using nRF Connect SDK v2.8.0-a2386bfc8401 ***
[2025-07-30 13:18:08.572] *** Using Zephyr OS v3.7.99-0bc3393fb112 ***
[2025-07-30 13:18:08.572] I: KWIKSET HALO 3 PLUS VERSION: 17.37.05.03
[2025-07-30 13:18:08.572] I: 51 [DL]BLE address: FC:88:19:F6:29:1A
[2025-07-30 13:18:08.582] I: No users indexes stored
[2025-07-30 13:18:08.582] I: No stored indexes for credential of type: 1
[2025-07-30 13:18:08.698] I: No stored indexes for credential of type: 2
[2025-07-30 13:18:08.698] I: ========== User Index: 0x01 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x02 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x03 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x04 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x05 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x06 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x07 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x08 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x09 User ID: 0xffffffff ==========
[2025-07-30 13:18:08.698] I: ========== User Index: 0x0a User ID: 0xffffffff ==========
[2025-07-30 13:18:08.713] I: ========== User Index: 0x0b User ID: 0xffffffff ==========
[2025-07-30 13:18:08.713] I: Board config kwiksetmdb_nrf5340_cpuapp
[2025-07-30 13:18:08.713] I: IMAGE_VERSION 17370503
[2025-07-30 13:18:08.713] I: build time: Jul 29 2025 13:32:25
[2025-07-30 13:18:08.713] I: 158 [DL]CHIP task running
[2025-07-30 13:18:08.713] I: Init CHIP stack
[2025-07-30 13:18:08.713] I: 164 [DL]OpenThread started: OK
[2025-07-30 13:18:08.713] I: 167 [DL]Setting OpenThread device type to SLEEPY END DEVICE
[2025-07-30 13:18:08.713] I: 173 [SWU]New firmware image confirmed
[2025-07-30 13:18:08.713] I: 176 [SWU]DFU_BLEAdvertising_Init
[2025-07-30 13:18:09.103] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-30 13:18:09.103] I: NFC Boot Event PN7642 FW VERSION 17.01.00.03
[2025-07-30 13:18:09.103] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-30 13:18:09.103] I: 
[2025-07-30 13:18:09.103] Boot Event Received
[2025-07-30 13:18:09.103] 
[2025-07-30 13:18:09.103] I: Booted NFC IC in Normal Operation Mode.
[2025-07-30 13:18:09.103] 
[2025-07-30 13:18:09.103] I: 260 [SVR]Subscription persistence not supported
[2025-07-30 13:18:09.103] I: 264 [SVR]Server initializing...
[2025-07-30 13:18:09.103] I: 268 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2025-07-30 13:18:09.103] I: 273 [DMG]AccessControl: initializing
[2025-07-30 13:18:09.113] I: 277 [DMG]Examples::AccessControlDelegate::Init
[2025-07-30 13:18:09.113] I: 281 [DMG]AccessControl: setting
[2025-07-30 13:18:09.113] I: 284 [DMG]DefaultAclStorage: initializing
[2025-07-30 13:18:09.113] I: 288 [DMG]DefaultAclStorage: 0 entries loaded
[2025-07-30 13:18:09.133] E: 292 [IN]IPV6_PKTINFO failed: 109
[2025-07-30 13:18:09.133] I: 298 [ZCL]Using ZAP configuration...
[2025-07-30 13:18:09.133] I: 303 [DMG]AccessControlCluster: initializing
[2025-07-30 13:18:09.133] Unhandled cluster ID: 0x  30
[2025-07-30 13:18:09.133] 
[2025-07-30 13:18:09.133] ===== Attribute Received are: Cluster=30 Attribute=0 Value=0 =====
[2025-07-30 13:18:09.133] I: 317 [ZCL]Emit DSTTableEmpty event [ep=0]
[2025-07-30 13:18:09.133] I: 321 [ZCL]Initiating Admin Commissioning cluster.
[2025-07-30 13:18:09.133] I: 326 [ZCL]Door Lock server initialized
[2025-07-30 13:18:09.133] E: 330 [ZCL]DeviceInfoProvider is not registered
[2025-07-30 13:18:09.133] E: 334 [ZCL]Failed to read calendar type with error: 0x86
[2025-07-30 13:18:09.133] Unhandled cluster ID: 0x   3
[2025-07-30 13:18:09.133] 
[2025-07-30 13:18:09.133] ===== Attribute Received are: Cluster=3 Attribute=1 Value=3 =====
[2025-07-30 13:18:09.153] I: 347 [ZCL]Door Lock cluster initialized at endpoint #1
[2025-07-30 13:18:09.153] ===== Attribute Received are: Cluster=101 Attribute=0 Value=255 =====
[2025-07-30 13:18:09.153] ===== Attribute Received are: Cluster=101 Attribute=2 Value=1 =====
[2025-07-30 13:18:09.153] ===== Attribute Received are: Cluster=101 Attribute=1 Value=0 =====
[2025-07-30 13:18:09.153] ===== Attribute Received are: Cluster=101 Attribute=11 Value=11 =====
[2025-07-30 13:18:09.153] ===== Attribute Received are: Cluster=101 Attribute=12 Value=35 =====
[2025-07-30 13:18:09.153] ===== Attribute Received are: Cluster=101 Attribute=13 Value=35 =====
[2025-07-30 13:18:09.153] ===== Attribute Received are: Cluster=101 Attribute=1c Value=35 =====
[2025-07-30 13:18:09.153] ===== Attribute Received are: Cluster=101 Attribute=19 Value=80 =====
[2025-07-30 13:18:09.153] I: 401 [DIS]Updating services using commissioning mode 0
[2025-07-30 13:18:09.153] E: 406 [DIS]Failed to remove advertised services: 3
[2025-07-30 13:18:09.177] E: 411 [DIS]Failed to finalize service update: 3
[2025-07-30 13:18:09.177] I: 415 [IN]CASE Server enabling CASE session setups
[2025-07-30 13:18:09.177] I: 420 [SVR]Joining Multicast groups
[2025-07-30 13:18:09.177] I: 423 [SVR]Server Listening...
[2025-07-30 13:18:09.177] I: 426 [DL]Device Configuration:
[2025-07-30 13:18:09.177] I: 429 [DL]  Serial Number: 1789AE57B32427844F
[2025-07-30 13:18:09.177] I: 433 [DL]  Vendor Id: 5153 (0x1421)
[2025-07-30 13:18:09.177] I: 437 [DL]  Product Id: 66 (0x42)
[2025-07-30 13:18:09.177] I: Get product name B, len 0
[2025-07-30 13:18:09.177] I: 442 [DL]  Product Name: B
[2025-07-30 13:18:09.177] I: 445 [DL]  Hardware Version: 1
[2025-07-30 13:18:09.182] I: 448 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 75655451
[2025-07-30 13:18:09.182] I: 453 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 776 (0x308)
[2025-07-30 13:18:09.182] I: 460 [DL]  Manufacturing Date: 2025-07-24
[2025-07-30 13:18:09.204] I: 464 [DL]  Device Type: 10 (0xA)
[2025-07-30 13:18:09.204] I: 467 [SVR]SetupQRCode: [MT:-QWJ08DB00.I2N6SM10]
[2025-07-30 13:18:09.204] I: 471 [SVR]Copy/paste the below URL in a browser to see the QR Code:
[2025-07-30 13:18:09.204] I: 477 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-QWJ08DB00.I2N6SM10
[2025-07-30 13:18:09.204] I: 486 [SVR]Manual pairing code: [05967546175]
[2025-07-30 13:18:09.204] I: STM32 device number: 
[2025-07-30 13:18:09.204] I: 31 37 38 39 41 45 35 37 |1789AE57
[2025-07-30 13:18:09.204] I: 42 33 32 34 32 37 38 34 |B3242784
[2025-07-30 13:18:09.204] I: 34 46                   |4F      
[2025-07-30 13:18:09.204] I: SKU number: 
[2025-07-30 13:18:09.204] I: 4b 31 37 2d 30 31       |K17-01  
[2025-07-30 13:18:09.204] I: WO number: 
[2025-07-30 13:18:09.204] I: 30 30 30 30 30 30 30 30 |00000000
[2025-07-30 13:18:09.204] I: 30                      |0       
[2025-07-30 13:18:09.213] I: Manuf Date: 
[2025-07-30 13:18:09.213] I: 32 30 32 35 2d 30 37 2d |2025-07-
[2025-07-30 13:18:09.213] I: 32 34 00 00 00 00       |24....  
[2025-07-30 13:18:09.213] I: Prod config length 6
[2025-07-30 13:18:09.213] I: Product Config: 
[2025-07-30 13:18:09.213] I: 30 78 30 30 30 31       |0x0001  
[2025-07-30 13:18:09.213] I: Prod Config Read 1
[2025-07-30 13:18:09.213] I: User intend flow enabled, set commissioning flow to kUserActionRequired
[2025-07-30 13:18:09.213] I: Factory Data Version length 2
[2025-07-30 13:18:09.213] I: Factory Data Ver: 
[2025-07-30 13:18:09.213] I: 30 31                   |01      
[2025-07-30 13:18:09.213] I: Payload value in string format: MT:-QWJ04TC00.I2N60Q4P0ILT70VYYR1JFSK14YDB0-0LJ1-0LJ1-0LJ1IHLC0AUZL1XIKJ17AZL1UV700CXYR1K6Y12NNZR1YC-L1-2ZR1OADO1KB40
[2025-07-30 13:18:09.213] I: Pairing Code value in string format: 459675461705153000660
[2025-07-30 13:18:09.213] I: ============== Updating product finish and color to 15, 2, product Name Halo Select Plus ==============
[2025-07-30 13:18:09.233] E: 577 [DL]Long dispatch time: 417 ms, for event type 2
[2025-07-30 13:18:09.233] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:18:10.663] I: Syncing up on message 9a
[2025-07-30 13:18:10.663] I: STM32 counter to 1
[2025-07-30 13:18:10.700] I: BLE Device ID: 2784
[2025-07-30 13:18:10.700] I: Device is provisioned
[2025-07-30 13:18:10.700] I: network state 0
[2025-07-30 13:18:10.700] E: Sending UART cmd(3) st 0
[2025-07-30 13:18:10.700] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:18:10.700] I: Received response of command id 9a
[2025-07-30 13:18:10.700] I: Command 0x9A Received
[2025-07-30 13:18:10.700] I: Firmware Attribute event
[2025-07-30 13:18:10.700] I: Received response of command id 30
[2025-07-30 13:18:10.723] I: Received DC Eco Config REQ
[2025-07-30 13:18:10.723] I: DC Eco Config Resp
[2025-07-30 13:18:10.723] I: Received DC eco config req
[2025-07-30 13:18:10.723] I: 80 72 03 00 10 00 04 1a |.r......
[2025-07-30 13:18:10.723] I: 17 05                   |..      
[2025-07-30 13:18:10.723] E: Sending UART cmd(72) st 0
[2025-07-30 13:18:12.702] I: Syncing up on message 3
[2025-07-30 13:18:12.702] I: Sys init req
[2025-07-30 13:18:12.702] E: Sending UART cmd(3) st 0
[2025-07-30 13:18:12.707] I: System init Response
[2025-07-30 13:18:12.707] I: Received response of command id 3
[2025-07-30 13:18:12.707] I: Update sync timer
[2025-07-30 13:18:12.707] I: Received Sys Init Resp
[2025-07-30 13:18:12.707] I: battery mode 0
[2025-07-30 13:18:12.707] I: battery percentage 5a
[2025-07-30 13:18:12.707] I: battery type 1
[2025-07-30 13:18:12.707] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:18:13.182] I: Syncing up on message 5
[2025-07-30 13:18:13.182] I: Operating mode req
[2025-07-30 13:18:13.223] E: Sending UART cmd(5) st 0
[2025-07-30 13:18:13.223] I: Operating mode response
[2025-07-30 13:18:13.223] I: Received response of command id 5
[2025-07-30 13:18:13.223] I: Received Lock Op Mode Resp, mode 10, App state 31
[2025-07-30 13:18:13.223] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:18:13.223] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:18:13.223] I: Set Kwikset Lock App State 49
[2025-07-30 13:18:13.223] I: Matter is disabled
[2025-07-30 13:18:13.733] I: Syncing up on message 10
[2025-07-30 13:18:13.733] I: Lock state req
[2025-07-30 13:18:13.733] E: Sending UART cmd(10) st 0
[2025-07-30 13:18:13.733] I: Lock State Response
[2025-07-30 13:18:13.733] I: Received response of command id 10
[2025-07-30 13:18:13.733] I: Received Lock State Response, lock st: 11
[2025-07-30 13:18:13.733] I: Found matching nordic source of operation 0
[2025-07-30 13:18:13.733] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:18:13.733] I: Lock action completed
[2025-07-30 13:18:13.733] I: Updating LockState attribute
[2025-07-30 13:18:13.733] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:18:14.173] I: Syncing up on message 20
[2025-07-30 13:18:14.233] I: Lock setting req
[2025-07-30 13:18:14.233] E: Sending UART cmd(20) st 0
[2025-07-30 13:18:14.233] I: Lock General Setting Response
[2025-07-30 13:18:14.233] I: Received response of command id 20
[2025-07-30 13:18:14.233] I: Received Lock General Setting resp
[2025-07-30 13:18:14.233] I: Sound Volume Attribute Update, sound volume 1
[2025-07-30 13:18:14.233] SoundVolume attribute change
[2025-07-30 13:18:14.233] 
[2025-07-30 13:18:14.233] I: == Sound Volume Attribute Update Callback, sound volume 2 ==
[2025-07-30 13:18:14.233] I: No change in sound volume, return
[2025-07-30 13:18:14.233] ===== Attribute Received are: Cluster=101 Attribute=24 Value=2 =====
[2025-07-30 13:18:14.233] I: Matter Not Enabled do not set
[2025-07-30 13:18:14.733] I: Syncing up on message 51
[2025-07-30 13:18:14.733] I: Battery info req
[2025-07-30 13:18:14.733] E: Sending UART cmd(51) st 0
[2025-07-30 13:18:14.733] I: Received response of command id 51
[2025-07-30 13:18:14.733] I: Received Battery Info resp
[2025-07-30 13:18:14.733] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:18:14.733] Unhandled cluster ID: 0x  2f
[2025-07-30 13:18:14.733] 
[2025-07-30 13:18:14.733] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:18:14.733] Unhandled cluster ID: 0x  2f
[2025-07-30 13:18:14.733] 
[2025-07-30 13:18:14.733] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:18:15.172] I: All message synced.
[2025-07-30 13:18:38.717] I: STM system init timer expired, System Init Event not received from STM32
[2025-07-30 13:18:38.717] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-30 13:18:38.717] I: STM Pending =1, Redpine Pending = 1
[2025-07-30 13:18:38.717] I: STM Post OTA Pending
[2025-07-30 13:18:38.717] I: Redpine Post OTA Pending
[2025-07-30 13:18:38.717] E: Sending UART cmd(9e) st 0
[2025-07-30 13:18:38.717] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:18:38.717] I: 30187 [SWU]SMP BLE advertising started
[2025-07-30 13:18:38.717] I: 30191 [DL]DFU over SMP started
[2025-07-30 13:18:39.572] I: IMG Integrity Verified Successfully: 0
[2025-07-30 13:18:42.540] I: IMG Integrity Verified Successfully: 1
[2025-07-30 13:18:42.613] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:18:42.966] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:18:42.966] I: OTA Stage Change from (ff)->(32)
[2025-07-30 13:18:42.966] I: OTA device_id = 5 : DISCOVERY_REQ
[2025-07-30 13:18:43.043] I: SECURE_STM : IB_DEVICE_DISCOVERY_REQUEST (80) 
[2025-07-30 13:18:43.093] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:18:43.093] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-30 13:18:43.093] I: OTA device_id = 5 : FW_UPDATE_START_REQ
[2025-07-30 13:18:43.093] I: SECURE_STM : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-30 13:18:49.473] I: STM OTA Progress = 10
[2025-07-30 13:18:55.823] I: STM OTA Progress = 20
[2025-07-30 13:19:02.173] I: STM OTA Progress = 30
[2025-07-30 13:19:08.613] I: STM OTA Progress = 40
[2025-07-30 13:19:14.963] I: STM OTA Progress = 50
[2025-07-30 13:19:21.313] I: STM OTA Progress = 60
[2025-07-30 13:19:27.683] I: STM OTA Progress = 70
[2025-07-30 13:19:34.033] I: STM OTA Progress = 80
[2025-07-30 13:19:40.383] I: STM OTA Progress = 90
[2025-07-30 13:19:46.743] I: STM OTA Progress = 100
[2025-07-30 13:19:47.433] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-30 13:19:47.453] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-30 13:20:05.043] I: Sending Sys Init Resp
[2025-07-30 13:20:05.093] I: Device is provisioned
[2025-07-30 13:20:05.093] I: network state 0
[2025-07-30 13:20:05.093] E: Sending UART cmd(3) st 0
[2025-07-30 13:20:05.093] I: Received DC App Config REQ
[2025-07-30 13:20:05.093] I: DC App Config Resp
[2025-07-30 13:20:05.093] I: Received DC config req
[2025-07-30 13:20:05.093] I: 80 70 03 00 10 10 08 00 |.p......
[2025-07-30 13:20:05.093] I: 50 1e                   |P.      
[2025-07-30 13:20:05.093] I: Matter enabled state 0
[2025-07-30 13:20:05.093] I: Get Matter Commission State
[2025-07-30 13:20:05.093] I: network state 0
[2025-07-30 13:20:05.093] I: network state 0
[2025-07-30 13:20:05.093] E: Sending UART cmd(70) st 0
[2025-07-30 13:20:05.155] I: Lock State Event
[2025-07-30 13:20:05.155] I: Received response of command id 10
[2025-07-30 13:20:05.155] I: Received Lock State event, lock st: 11
[2025-07-30 13:20:05.155] I: Found matching nordic source of operation 0
[2025-07-30 13:20:05.155] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:20:05.155] I: Lock action completed
[2025-07-30 13:20:05.155] I: Updating LockState attribute
[2025-07-30 13:20:05.155] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:20:05.183] I: Received DC Eco Config REQ
[2025-07-30 13:20:05.193] I: DC Eco Config Resp
[2025-07-30 13:20:05.213] I: Received DC eco config req
[2025-07-30 13:20:05.213] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:20:05.213] I: c4 1e                   |..      
[2025-07-30 13:20:05.213] E: Sending UART cmd(72) st 0
[2025-07-30 13:20:05.363] I: General Lock Setting event
[2025-07-30 13:20:05.393] I: Received response of command id 20
[2025-07-30 13:20:05.393] I: Received Lock General Setting event
[2025-07-30 13:20:05.393] I: Sound Volume Attribute Update, sound volume 1
[2025-07-30 13:20:05.393] I: Matter Not Enabled do not set
[2025-07-30 13:20:05.495] I: Firmware Attribute event
[2025-07-30 13:20:05.495] I: Received response of command id 30
[2025-07-30 13:20:05.553] I: Hardware Attribute event
[2025-07-30 13:20:05.553] I: Received response of command id 31
[2025-07-30 13:20:05.633] I: Operating mode event
[2025-07-30 13:20:05.633] I: Received response of command id 5
[2025-07-30 13:20:05.633] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:20:05.633] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:20:05.633] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:20:05.633] I: Set Kwikset Lock App State 49
[2025-07-30 13:20:05.633] I: Matter is disabled
[2025-07-30 13:20:05.763] I: Battery Info event
[2025-07-30 13:20:05.763] I: Received response of command id 51
[2025-07-30 13:20:05.763] I: Received Battery info event
[2025-07-30 13:20:05.763] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:20:05.763] Unhandled cluster ID: 0x  2f
[2025-07-30 13:20:05.763] 
[2025-07-30 13:20:05.763] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:20:05.763] Unhandled cluster ID: 0x  2f
[2025-07-30 13:20:05.763] 
[2025-07-30 13:20:05.763] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:20:05.863] I: System info event
[2025-07-30 13:20:05.863] I: Received System Info Event
[2025-07-30 13:20:05.863] W: Time invalid, set time
[2025-07-30 13:20:05.863] I: Get system time
[2025-07-30 13:20:05.863] I: System Real time in seconds 373663017
[2025-07-30 13:20:05.863] I: Time sync status flag 0
[2025-07-30 13:20:05.863] E: Time not sync, keep default value
[2025-07-30 13:20:05.893] I: System init event
[2025-07-30 13:20:05.976] I: Received response of command id 3
[2025-07-30 13:20:05.976] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:20:05.976] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:20:05.976] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:20:05.976] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-30 13:20:05.976] I: OTA device_id = 5 : FW_UPDATE_COMPLETE_REQ
[2025-07-30 13:20:05.976] I: SECURE_STM : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-30 13:20:05.976] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-30 13:20:05.976] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-30 13:20:08.353] I: Sending Sys Init Resp
[2025-07-30 13:20:08.403] I: Device is provisioned
[2025-07-30 13:20:08.408] I: network state 0
[2025-07-30 13:20:08.408] E: Sending UART cmd(3) st 0
[2025-07-30 13:20:08.408] I: Received DC App Config REQ
[2025-07-30 13:20:08.408] I: DC App Config Resp
[2025-07-30 13:20:08.408] I: Received DC config req
[2025-07-30 13:20:08.408] I: 80 70 03 00 10 10 04 1a |.p......
[2025-07-30 13:20:08.408] I: 00 62                   |.b      
[2025-07-30 13:20:08.408] I: Matter enabled state 0
[2025-07-30 13:20:08.408] I: Get Matter Commission State
[2025-07-30 13:20:08.408] I: network state 0
[2025-07-30 13:20:08.413] I: network state 0
[2025-07-30 13:20:08.413] E: Sending UART cmd(70) st 0
[2025-07-30 13:20:08.473] I: Lock State Event
[2025-07-30 13:20:08.473] I: Received response of command id 10
[2025-07-30 13:20:08.473] I: Received Lock State event, lock st: 11
[2025-07-30 13:20:08.473] I: Found matching nordic source of operation 0
[2025-07-30 13:20:08.473] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:20:08.473] I: Lock action completed
[2025-07-30 13:20:08.473] I: Updating LockState attribute
[2025-07-30 13:20:08.473] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:20:08.503] I: Received DC Eco Config REQ
[2025-07-30 13:20:08.503] I: DC Eco Config Resp
[2025-07-30 13:20:08.533] I: Received DC eco config req
[2025-07-30 13:20:08.533] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:20:08.533] I: c4 62                   |.b      
[2025-07-30 13:20:08.533] E: Sending UART cmd(72) st 0
[2025-07-30 13:20:08.708] I: General Lock Setting event
[2025-07-30 13:20:08.708] I: Received response of command id 20
[2025-07-30 13:20:08.708] I: Received Lock General Setting event
[2025-07-30 13:20:08.708] I: Sound Volume Attribute Update, sound volume 1
[2025-07-30 13:20:08.708] I: Matter Not Enabled do not set
[2025-07-30 13:20:08.813] I: Firmware Attribute event
[2025-07-30 13:20:08.813] I: Received response of command id 30
[2025-07-30 13:20:08.873] I: Hardware Attribute event
[2025-07-30 13:20:08.873] I: Received response of command id 31
[2025-07-30 13:20:08.943] I: Operating mode event
[2025-07-30 13:20:08.943] I: Received response of command id 5
[2025-07-30 13:20:08.943] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:20:08.943] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:20:08.943] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:20:08.943] I: Set Kwikset Lock App State 49
[2025-07-30 13:20:08.943] I: Matter is disabled
[2025-07-30 13:20:09.073] I: Battery Info event
[2025-07-30 13:20:09.073] I: Received response of command id 51
[2025-07-30 13:20:09.073] I: Received Battery info event
[2025-07-30 13:20:09.073] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:20:09.073] Unhandled cluster ID: 0x  2f
[2025-07-30 13:20:09.073] 
[2025-07-30 13:20:09.073] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:20:09.073] Unhandled cluster ID: 0x  2f
[2025-07-30 13:20:09.073] 
[2025-07-30 13:20:09.073] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:20:09.183] I: System info event
[2025-07-30 13:20:09.183] I: Received System Info Event
[2025-07-30 13:20:09.183] W: Time invalid, set time
[2025-07-30 13:20:09.183] I: Get system time
[2025-07-30 13:20:09.183] I: System Real time in seconds 373663017
[2025-07-30 13:20:09.183] I: Time sync status flag 0
[2025-07-30 13:20:09.183] E: Time not sync, keep default value
[2025-07-30 13:20:09.270] I: System init event
[2025-07-30 13:20:09.270] I: Received response of command id 3
[2025-07-30 13:20:09.270] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:20:09.270] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:20:09.270] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:20:09.270] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-30 13:20:09.270] I: STM New OTA Firmware Version = 17 5 4 1a
[2025-07-30 13:20:09.270] I: STM Secure OTA Successful
[2025-07-30 13:20:09.365] I: Cleared STM OTA Meta Data
[2025-07-30 13:20:09.365] I: OTA Stage Change from (32)->(33)
[2025-07-30 13:20:09.383] I: Redpine OTA started
[2025-07-30 13:20:09.383] I: OTA Stage Change from (33)->(34)
[2025-07-30 13:20:09.383] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-30 13:20:16.373] I: STM Reset Count 0
[2025-07-30 13:20:16.373] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-30 13:20:16.423] I: STM_QSPI : IB_DEVICE_DISCOVERY_REQUEST (80)
[2025-07-30 13:20:16.423] I: OTA device_id = 4 : FW_VERSION_REQ
[2025-07-30 13:20:16.423] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-30 13:20:16.423] I: Redpine Current Firmware Version: 2.c.0.3
[2025-07-30 13:20:16.423] I: OTA device_id = 4 : FW_UPDATE_START_REQ
[2025-07-30 13:20:16.523] I: STM_QSPI : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-30 13:20:39.233] I: STM Boot Up Properly, Stopped STM Reboot Timer
[2025-07-30 13:20:55.949] I: Redpine Image Stored into STM QSPI, Progress = 10
[2025-07-30 13:21:29.523] I: Redpine Image Stored into STM QSPI, Progress = 20
[2025-07-30 13:21:50.183] I: Redpine Image Stored into STM QSPI, Progress = 30
[2025-07-30 13:22:10.973] I: Redpine Image Stored into STM QSPI, Progress = 40
[2025-07-30 13:22:31.673] I: Redpine Image Stored into STM QSPI, Progress = 50
[2025-07-30 13:22:52.383] I: Redpine Image Stored into STM QSPI, Progress = 60
[2025-07-30 13:23:13.193] I: Redpine Image Stored into STM QSPI, Progress = 70
[2025-07-30 13:23:33.903] I: Redpine Image Stored into STM QSPI, Progress = 80
[2025-07-30 13:23:54.633] I: Redpine Image Stored into STM QSPI, Progress = 90
[2025-07-30 13:24:15.423] I: Redpine Image Stored into STM QSPI, Progress = 100
[2025-07-30 13:24:17.553] I: OTA device_id = 4 : FW_UPDATE_COMPLETE_REQ
[2025-07-30 13:24:17.983] I: STM_QSPI : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-30 13:24:18.133] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (0)
[2025-07-30 13:24:22.954] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (10)
[2025-07-30 13:24:27.823] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (20)
[2025-07-30 13:24:32.763] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (30)
[2025-07-30 13:24:37.763] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (40)
[2025-07-30 13:24:42.723] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (50)
[2025-07-30 13:24:47.693] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (60)
[2025-07-30 13:24:52.663] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (70)
[2025-07-30 13:24:57.623] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (80)
[2025-07-30 13:25:02.533] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (90)
[2025-07-30 13:25:07.364] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (100)
[2025-07-30 13:25:36.764] I: STM_QSPI : IB_FW_UPDATE_REBOOT_REQUEST (80) 
[2025-07-30 13:25:36.884] I: Clear Redpine OTA Meta Data
[2025-07-30 13:25:36.893] I: Redpine OTA Successful
[2025-07-30 13:25:36.893] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-30 13:25:36.893] I: STM Pending =2, Redpine Pending = 2
[2025-07-30 13:25:36.893] I: PN76 IMG 1 Post OTA Pending
[2025-07-30 13:25:36.893] E: Sending UART cmd(9e) st 0
[2025-07-30 13:25:36.893] I: 448371 [SWU]DFU over SMP was already started
[2025-07-30 13:25:36.968] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:25:37.333] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:25:37.333] I: OTA Stage Change from (34)->(3a)
[2025-07-30 13:25:37.333] I: PN76_IMG1_DEVICE_DFU_MULTI_IMG_ID
[2025-07-30 13:25:37.333] I: PN76_IMG Update from OTA Task Event
[2025-07-30 13:25:37.333] I: 
[2025-07-30 13:25:37.333] 
[2025-07-30 13:25:37.333] --------------- UPDATING PN7642 NXP FIRMWARE --------------------
[2025-07-30 13:25:37.333] 
[2025-07-30 13:25:37.333] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-30 13:25:37.373] I: pNXPFWInfo->img_offset = 0x351497
[2025-07-30 13:25:37.373] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-30 13:25:37.373] I: Reading version of firmware in QSPI flash: MetaData 0x2f60217
[2025-07-30 13:25:37.373] I: PN76 NXP FW VERSION VALIDATION SKIPPED, OTAU TEST BUNDLE
[2025-07-30 13:25:37.485] I: ----> PN7642 OTA Progress = 10 %
[2025-07-30 13:25:37.556] I: ----> PN7642 OTA Progress = 20 %
[2025-07-30 13:25:37.613] I: ----> PN7642 OTA Progress = 30 %
[2025-07-30 13:25:37.684] I: ----> PN7642 OTA Progress = 40 %
[2025-07-30 13:25:37.743] I: ----> PN7642 OTA Progress = 50 %
[2025-07-30 13:25:37.803] I: ----> PN7642 OTA Progress = 60 %
[2025-07-30 13:25:37.873] I: ----> PN7642 OTA Progress = 70 %
[2025-07-30 13:25:37.933] I: ----> PN7642 OTA Progress = 80 %
[2025-07-30 13:25:38.114] I: ----> PN7642 OTA Progress = 100 %
[2025-07-30 13:25:38.114] I: Whole pn7642 FW Image downloaded ....
[2025-07-30 13:25:38.114] I: 
[2025-07-30 13:25:38.114] 
[2025-07-30 13:25:38.114] I: 
[2025-07-30 13:25:38.114] PN7642 Firmware of type 0 Successfully Updated !!!
[2025-07-30 13:25:38.114] I: PN76 Image Update Successful for Device ID(7)
[2025-07-30 13:25:38.233] I: Cleared PN76 Img1 OTA Meta Data
[2025-07-30 13:25:38.233] I: OTA Stage Change from (3a)->(3a)
[2025-07-30 13:25:38.233] I: PN76_IMG2_DEVICE_DFU_MULTI_IMG_ID
[2025-07-30 13:25:38.233] I: PN76_IMG Update from OTA Task Event
[2025-07-30 13:25:38.233] I: 
[2025-07-30 13:25:38.233] 
[2025-07-30 13:25:38.233] --------------- UPDATING PN7642 APPLICATION FIRMWARE -------------
[2025-07-30 13:25:38.233] 
[2025-07-30 13:25:38.233] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-30 13:25:38.273] I: pCustAppFWInfo->img_offset = 0x35c289
[2025-07-30 13:25:38.273] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-30 13:25:38.273] I: Reading version of firmware in QSPI flash: MetaData 0x2f60217
[2025-07-30 13:25:38.273] I: PN76 APP FW VERSION VALIDATION SKIPPED, OTAU TEST BUNDLE
[2025-07-30 13:25:38.583] I: ----> PN7642 OTA Progress = 10 %
[2025-07-30 13:25:38.853] I: ----> PN7642 OTA Progress = 20 %
[2025-07-30 13:25:39.104] I: ----> PN7642 OTA Progress = 30 %
[2025-07-30 13:25:39.383] I: ----> PN7642 OTA Progress = 40 %
[2025-07-30 13:25:39.636] I: ----> PN7642 OTA Progress = 50 %
[2025-07-30 13:25:39.903] I: ----> PN7642 OTA Progress = 60 %
[2025-07-30 13:25:40.164] I: ----> PN7642 OTA Progress = 70 %
[2025-07-30 13:25:40.433] I: ----> PN7642 OTA Progress = 80 %
[2025-07-30 13:25:40.694] I: ----> PN7642 OTA Progress = 90 %
[2025-07-30 13:25:40.943] I: ----> PN7642 OTA Progress = 100 %
[2025-07-30 13:25:40.983] I: Whole pn7642 FW Image downloaded ....
[2025-07-30 13:25:40.983] I: 
[2025-07-30 13:25:40.983] 
[2025-07-30 13:25:40.983] I: 
[2025-07-30 13:25:40.983] PN7642 Firmware of type 1 Successfully Updated !!!
[2025-07-30 13:25:40.983] I: PN76 Image Update Successful for Device ID(8)
[2025-07-30 13:25:41.043] I: Cleared PN76 Img2 OTA Meta Data
[2025-07-30 13:25:41.623] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-30 13:25:41.623] I: NFC Boot Event PN7642 FW VERSION 17.01.00.02
[2025-07-30 13:25:41.623] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-30 13:25:41.623] I: 
[2025-07-30 13:25:41.623] Boot Event Received
[2025-07-30 13:25:41.623] 
[2025-07-30 13:25:41.623] I: Booted NFC IC in Normal Operation Mode.
[2025-07-30 13:25:41.623] 
[2025-07-30 13:25:41.623] I: OTA Stage Change from (3a)->(3b)
[2025-07-30 13:25:41.623] I: post_stm_reset_event : init_pending_ota_update
[2025-07-30 13:25:41.623] I: All pending FW Updates are completed.
[2025-07-30 13:25:41.623] I: STM32 Reset Count = 0
[2025-07-30 13:25:41.623] I: REBOOT_STM: Send STM32 Reboot Command, Count (0)
[2025-07-30 13:25:43.964] I: Sending Sys Init Resp
[2025-07-30 13:25:44.003] I: Device is provisioned
[2025-07-30 13:25:44.003] I: network state 0
[2025-07-30 13:25:44.003] E: Sending UART cmd(3) st 0
[2025-07-30 13:25:44.003] I: Received DC App Config REQ
[2025-07-30 13:25:44.003] I: DC App Config Resp
[2025-07-30 13:25:44.003] I: Received DC config req
[2025-07-30 13:25:44.003] I: 80 70 03 00 10 10 19 00 |.p......
[2025-07-30 13:25:44.003] I: 50 62                   |Pb      
[2025-07-30 13:25:44.003] I: Matter enabled state 0
[2025-07-30 13:25:44.003] I: Get Matter Commission State
[2025-07-30 13:25:44.003] I: network state 0
[2025-07-30 13:25:44.003] I: network state 0
[2025-07-30 13:25:44.003] E: Sending UART cmd(70) st 0
[2025-07-30 13:25:44.036] I: Lock State Event
[2025-07-30 13:25:44.036] I: Received response of command id 10
[2025-07-30 13:25:44.074] I: Received Lock State event, lock st: 11
[2025-07-30 13:25:44.074] I: Found matching nordic source of operation 0
[2025-07-30 13:25:44.074] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:25:44.074] I: Lock action completed
[2025-07-30 13:25:44.074] I: Updating LockState attribute
[2025-07-30 13:25:44.074] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:25:44.103] I: Received DC Eco Config REQ
[2025-07-30 13:25:44.134] I: DC Eco Config Resp
[2025-07-30 13:25:44.134] I: Received DC eco config req
[2025-07-30 13:25:44.134] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:25:44.134] I: c4 62                   |.b      
[2025-07-30 13:25:44.134] E: Sending UART cmd(72) st 0
[2025-07-30 13:25:44.313] I: General Lock Setting event
[2025-07-30 13:25:44.313] I: Received response of command id 20
[2025-07-30 13:25:44.313] I: Received Lock General Setting event
[2025-07-30 13:25:44.313] I: Sound Volume Attribute Update, sound volume 1
[2025-07-30 13:25:44.313] I: Matter Not Enabled do not set
[2025-07-30 13:25:44.423] I: Firmware Attribute event
[2025-07-30 13:25:44.423] I: Received response of command id 30
[2025-07-30 13:25:44.483] I: Hardware Attribute event
[2025-07-30 13:25:44.483] I: Received response of command id 31
[2025-07-30 13:25:44.553] I: Operating mode event
[2025-07-30 13:25:44.553] I: Received response of command id 5
[2025-07-30 13:25:44.553] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:25:44.553] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:25:44.553] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:25:44.553] I: Set Kwikset Lock App State 49
[2025-07-30 13:25:44.553] I: Matter is disabled
[2025-07-30 13:25:44.683] I: Battery Info event
[2025-07-30 13:25:44.683] I: Received response of command id 51
[2025-07-30 13:25:44.683] I: Received Battery info event
[2025-07-30 13:25:44.683] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:25:44.683] Unhandled cluster ID: 0x  2f
[2025-07-30 13:25:44.683] 
[2025-07-30 13:25:44.683] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:25:44.683] Unhandled cluster ID: 0x  2f
[2025-07-30 13:25:44.683] 
[2025-07-30 13:25:44.683] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:25:44.763] I: System info event
[2025-07-30 13:25:44.763] I: Received System Info Event
[2025-07-30 13:25:44.784] W: Time invalid, set time
[2025-07-30 13:25:44.784] I: Get system time
[2025-07-30 13:25:44.784] I: System Real time in seconds 373663017
[2025-07-30 13:25:44.784] I: Time sync status flag 0
[2025-07-30 13:25:44.784] E: Time not sync, keep default value
[2025-07-30 13:25:44.856] I: System init event
[2025-07-30 13:25:44.856] I: Received response of command id 3
[2025-07-30 13:25:44.856] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:25:44.856] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:25:44.856] I: STM Image confirm timer was stopped
[2025-07-30 13:25:51.673] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-30 13:25:51.673] I: stop_ota_finalization_timer
[2025-07-30 13:25:51.673] I: After OTAU, Redpine Firmware Version: 2.c.0.3
[2025-07-30 13:25:51.673] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-30 13:25:51.673] I: After OTAU, Secure STM Firmware Version: 17 5 4 1a
[2025-07-30 13:25:51.673] I: Send Op Mode command to release Redpine BLE and WiFI
[2025-07-30 13:25:51.673] I: Operating Mode Command: Mode:10, State:f0
[2025-07-30 13:25:51.673] E: Sending UART cmd(5) st 0
[2025-07-30 13:25:51.723] I: Operating mode event
[2025-07-30 13:25:51.723] I: Received response of command id 5
[2025-07-30 13:25:51.723] I: Received Lock Op Mode Event, mode 10, App state 10
[2025-07-30 13:25:51.723] I: Lock Current Mode : 10, Lock Current State = 10
[2025-07-30 13:25:51.723] I: stop_ota_finalization_timer
[2025-07-30 13:25:51.723] I: STM32 HALO APP STATE IS ACTIVATED NORMAL
[2025-07-30 13:25:51.723] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:25:51.723] I: Set Kwikset Lock App State 16
[2025-07-30 13:25:51.723] I: Matter enabled state 0
[2025-07-30 13:25:51.723] I: Matter is disabled
[2025-07-30 13:25:51.723] I: OTA_HOUSEKEEPING
[2025-07-30 13:25:51.723] I: OTA Stage Change from (3b)->(80)
[2025-07-30 13:25:51.723] I: Start Erasing OTA bundle from nRF External Flash
[2025-07-30 13:25:57.884] I: System info event
[2025-07-30 13:25:57.903] I: Received System Info Event
[2025-07-30 13:25:57.903] I: Time is set in STM
[2025-07-30 13:26:52.803] I: Bundle Image Erased from nRF External Flash: 0
[2025-07-30 13:26:52.803] I: OTAU Completed Successfully
[2025-07-30 13:26:52.913] I: Cleared OTA Meta Data
[2025-07-30 13:26:52.913] I: OTA Stage Change from (80)->(90)
[2025-07-30 13:26:54.914] I: All message synced.
[2025-07-30 13:27:07.903] I: STOP BLE Advertisment
[2025-07-30 13:27:07.924] I: 539403 [DL]DFU over SMP stopped
[2025-07-30 13:27:07.924] E: Sending UART cmd(9e) st 0
[2025-07-30 13:29:54.584] I: Updated ota meta data
[2025-07-30 13:29:54.604] I: Operating Mode Command: Mode:10, State:34
[2025-07-30 13:29:54.604] E: Sending UART cmd(5) st 0
[2025-07-30 13:29:54.664] I: Operating mode event
[2025-07-30 13:29:54.664] I: Received response of command id 5
[2025-07-30 13:29:54.664] I: Received Lock Op Mode Event, mode 10, App state 34
[2025-07-30 13:29:54.664] I: Lock Current Mode : 10, Lock Current State = 34
[2025-07-30 13:29:54.664] I: STM32 HALO APP STATE IS BLE OTAU TRANSFER
[2025-07-30 13:29:54.664] E: Sending UART cmd(9e) st 0
[2025-07-30 13:29:54.664] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:29:54.664] I: 706135 [SWU]SMP BLE advertising started
[2025-07-30 13:29:54.664] I: 706139 [DL]DFU over SMP started
[2025-07-30 13:29:54.664] I: OTA Stage Change from (90)->(11)
[2025-07-30 13:29:54.664] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:29:54.664] I: Set Kwikset Lock App State 52
[2025-07-30 13:29:54.664] I: Matter is disabled
[2025-07-30 13:30:09.761] I: 721240 [DL]Current number of connections: 1/1
[2025-07-30 13:30:09.761] I: BLE Connected
[2025-07-30 13:30:09.983] I: 721463 [DL]Current number of connections: 0/1
[2025-07-30 13:30:09.983] I: BLE Disconnected: 13
[2025-07-30 13:30:13.804] I: 725304 [DL]Current number of connections: 1/1
[2025-07-30 13:30:13.814] I: BLE Connected
[2025-07-30 13:30:14.029] I: 725526 [DL]DFU Image upload started
[2025-07-30 13:30:14.854] I: Connection parameters updated.
[2025-07-30 13:30:14.874]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:30:23.804] I: OTA Stage Change from (11)->(12)
[2025-07-30 13:30:23.804] I: 735292 [DL]Image 0 download completed successfully
[2025-07-30 13:30:23.834] I: 735319 [DL]Current number of connections: 0/1
[2025-07-30 13:30:23.834] I: 735323 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:30:23.834] I: BLE Disconnected: 13
[2025-07-30 13:30:36.334] I: 747817 [DL]Current number of connections: 1/1
[2025-07-30 13:30:36.334] I: BLE Connected
[2025-07-30 13:30:36.554] I: 748056 [DL]DFU Image upload started
[2025-07-30 13:30:37.413] I: Connection parameters updated.
[2025-07-30 13:30:37.413]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:30:37.413] E: No available ACL buffers!
[2025-07-30 13:30:37.413] E: Unexpected first L2CAP frame
[2025-07-30 13:31:43.444] I: OTA Stage Change from (12)->(13)
[2025-07-30 13:31:43.444] I: 814928 [DL]Image 1 download completed successfully
[2025-07-30 13:31:43.471] I: 814953 [DL]Current number of connections: 0/1
[2025-07-30 13:31:43.474] I: 814958 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:31:43.474] I: BLE Disconnected: 13
[2025-07-30 13:31:50.644] I: 822129 [DL]Current number of connections: 1/1
[2025-07-30 13:31:50.644] I: BLE Connected
[2025-07-30 13:31:50.864] I: 822365 [DL]DFU Image upload started
[2025-07-30 13:31:51.694] I: Connection parameters updated.
[2025-07-30 13:31:51.694]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:31:51.694] E: No available ACL buffers!
[2025-07-30 13:31:51.714] E: Unexpected first L2CAP frame
[2025-07-30 13:34:38.474] I: OTA Stage Change from (13)->(14)
[2025-07-30 13:34:38.474] I: 989965 [DL]Image 2 download completed successfully
[2025-07-30 13:34:38.504] I: 989987 [DL]Current number of connections: 0/1
[2025-07-30 13:34:38.504] I: 989991 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:34:38.504] I: BLE Disconnected: 13
[2025-07-30 13:34:46.654] I: 998160 [DL]Current number of connections: 1/1
[2025-07-30 13:34:46.654] I: BLE Connected
[2025-07-30 13:34:46.904] I: 998390 [DL]Current number of connections: 0/1
[2025-07-30 13:34:46.904] I: BLE Disconnected: 13
[2025-07-30 13:34:51.504] I: 1002994 [DL]Current number of connections: 1/1
[2025-07-30 13:34:51.504] I: BLE Connected
[2025-07-30 13:34:51.734] I: 1003224 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-30 13:34:51.764] I: 1003250 [DL]Current number of connections: 0/1
[2025-07-30 13:34:51.764] I: BLE Disconnected: 13
[2025-07-30 13:34:59.154] I: 1010659 [DL]Current number of connections: 1/1
[2025-07-30 13:34:59.164] I: BLE Connected
[2025-07-30 13:34:59.374] I: 1010859 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-30 13:34:59.401] I: 1010885 [DL]Current number of connections: 0/1
[2025-07-30 13:34:59.401] I: BLE Disconnected: 13
[2025-07-30 13:35:07.614] I: 1019101 [DL]Current number of connections: 1/1
[2025-07-30 13:35:07.614] I: BLE Connected
[2025-07-30 13:35:07.824] I: STM Pending =0, Redpine Pending = 0
[2025-07-30 13:35:07.914] I: Count = 4
[2025-07-30 13:35:07.914] I: dfu_header_data.image_count: 4
[2025-07-30 13:35:08.664] I: Connection parameters updated.
[2025-07-30 13:35:08.664]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:35:08.804] I: IMG Integrity Verified Successfully: 0
[2025-07-30 13:35:11.745] I: IMG Integrity Verified Successfully: 1
[2025-07-30 13:35:11.844] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:35:12.144] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:35:12.144] I: OTA Bundle(STM32 + RS9116 + PN76) image integrity Verified
[2025-07-30 13:35:12.144] I: OTA Stage Change from (14)->(30)
[2025-07-30 13:35:12.254] I: Updated ota meta data
[2025-07-30 13:35:12.254] I: Operating Mode Command: Mode:10, State:31
[2025-07-30 13:35:12.254] E: Sending UART cmd(5) st 0
[2025-07-30 13:35:12.334] I: 1023834 [DL]Current number of connections: 0/1
[2025-07-30 13:35:12.334] I: BLE Disconnected: 13
[2025-07-30 13:35:12.378] I: Operating mode event
[2025-07-30 13:35:12.378] I: Received response of command id 5
[2025-07-30 13:35:12.378] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:35:12.378] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:35:12.378] I: STM OTAU Pending: Reset Nordic Triggered
[2025-07-30 13:35:12.378] I: OTA Stage Change from (30)->(30)
[2025-07-30 13:35:12.378] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:35:12.378] I: Set Kwikset Lock App State 49
[2025-07-30 13:35:12.378] I: Matter is disabled
[2025-07-30 13:35:57.397] 
[2025-07-30 13:35:57.397] 
[2025-07-30 13:35:57.397] uart:~$ *** Booting My Application v23.49.0-de86e88ec64e ***
[2025-07-30 13:35:57.447] *** Using nRF Connect SDK v2.7.0-5cb85570ca43 ***
[2025-07-30 13:35:57.447] *** Using Zephyr OS v3.6.99-100befc70c74 ***
[2025-07-30 13:35:57.447] I: KWIKSET HALO 3 PLUS VERSION: 17.31.00.02
[2025-07-30 13:35:57.447] I: 50 [DL]BLE address: CE:67:A4:02:71:9B
[2025-07-30 13:35:57.464] I: No users indexes stored
[2025-07-30 13:35:57.464] I: No stored indexes for credential of type: 1
[2025-07-30 13:35:57.584] I: No stored indexes for credential of type: 2
[2025-07-30 13:35:57.584] I: No stored indexes for credential of type: 3
[2025-07-30 13:35:57.584] I: ========== User Index: 0x01 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.584] I: ========== User Index: 0x02 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.584] I: ========== User Index: 0x03 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.584] I: ========== User Index: 0x04 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.584] I: ========== User Index: 0x05 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.584] I: ========== User Index: 0x06 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.584] I: ========== User Index: 0x07 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.584] I: ========== User Index: 0x08 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.584] I: ========== User Index: 0x09 User ID: 0xffffffff ==========
[2025-07-30 13:35:57.604] I: ========== User Index: 0x0a User ID: 0xffffffff ==========
[2025-07-30 13:35:57.604] I: ========== User Index: 0x0b User ID: 0xffffffff ==========
[2025-07-30 13:35:57.604] I: Board config kwiksetmdb_nrf5340_cpuapp
[2025-07-30 13:35:57.604] I: IMAGE_VERSION 17310002
[2025-07-30 13:35:57.604] I: build time: Jun 18 2025 10:48:56
[2025-07-30 13:35:57.604] I: 161 [DL]CHIP task running
[2025-07-30 13:35:57.604] I: Init CHIP stack
[2025-07-30 13:35:57.604] I: 167 [DL]OpenThread started: OK
[2025-07-30 13:35:57.604] I: 170 [DL]Setting OpenThread device type to SLEEPY END DEVICE
[2025-07-30 13:35:57.604] I: 176 [SWU]New firmware image confirmed
[2025-07-30 13:35:57.604] I: 180 [SWU]DFU_BLEAdvertising_Init
[2025-07-30 13:35:57.624] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-30 13:35:57.984] I: NFC Boot Event PN7642 FW VERSION 17.01.00.02
[2025-07-30 13:35:57.984] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-30 13:35:57.984] I: 
[2025-07-30 13:35:57.984] Boot Event Received
[2025-07-30 13:35:57.984] 
[2025-07-30 13:35:57.984] I: Booted NFC IC in Normal Operation Mode.
[2025-07-30 13:35:57.984] 
[2025-07-30 13:35:57.984] I: 263 [SVR]Subscription persistence not supported
[2025-07-30 13:35:57.984] I: 268 [SVR]Server initializing...
[2025-07-30 13:35:57.984] I: 271 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2025-07-30 13:35:57.984] I: 276 [DMG]AccessControl: initializing
[2025-07-30 13:35:57.995] I: 280 [DMG]Examples::AccessControlDelegate::Init
[2025-07-30 13:35:57.995] I: 284 [DMG]AccessControl: setting
[2025-07-30 13:35:57.995] I: 288 [DMG]DefaultAclStorage: initializing
[2025-07-30 13:35:57.995] I: 291 [DMG]DefaultAclStorage: 0 entries loaded
[2025-07-30 13:35:58.004] E: 296 [IN]IPV6_PKTINFO failed: 109
[2025-07-30 13:35:58.004] I: 302 [ZCL]Using ZAP configuration...
[2025-07-30 13:35:58.004] I: 306 [DMG]AccessControlCluster: initializing
[2025-07-30 13:35:58.004] ===== Attribute Received are: Cluster=30 Attribute=0 Value=0 =====
[2025-07-30 13:35:58.004] I: 318 [ZCL]Emit DSTTableEmpty event [ep=0]
[2025-07-30 13:35:58.004] I: 322 [ZCL]Initiating Admin Commissioning cluster.
[2025-07-30 13:35:58.004] I: 327 [ZCL]Door Lock server initialized
[2025-07-30 13:35:58.004] E: 330 [ZCL]DeviceInfoProvider is not registered
[2025-07-30 13:35:58.004] E: 335 [ZCL]Failed to read calendar type with error: 0x86
[2025-07-30 13:35:58.004] ===== Attribute Received are: Cluster=3 Attribute=1 Value=3 =====
[2025-07-30 13:35:58.004] I: 346 [ZCL]Door Lock cluster initialized at endpoint #1
[2025-07-30 13:35:58.009] ===== Attribute Received are: Cluster=101 Attribute=0 Value=255 =====
[2025-07-30 13:35:58.009] ===== Attribute Received are: Cluster=101 Attribute=2 Value=1 =====
[2025-07-30 13:35:58.026] ===== Attribute Received are: Cluster=101 Attribute=1 Value=0 =====
[2025-07-30 13:35:58.026] ===== Attribute Received are: Cluster=101 Attribute=11 Value=11 =====
[2025-07-30 13:35:58.026] ===== Attribute Received are: Cluster=101 Attribute=12 Value=35 =====
[2025-07-30 13:35:58.026] ===== Attribute Received are: Cluster=101 Attribute=13 Value=35 =====
[2025-07-30 13:35:58.026] ===== Attribute Received are: Cluster=101 Attribute=1c Value=35 =====
[2025-07-30 13:35:58.026] ===== Attribute Received are: Cluster=101 Attribute=19 Value=80 =====
[2025-07-30 13:35:58.026] I: 399 [DIS]Updating services using commissioning mode 0
[2025-07-30 13:35:58.026] E: 404 [DIS]Failed to remove advertised services: 3
[2025-07-30 13:35:58.026] E: 409 [DIS]Failed to finalize service update: 3
[2025-07-30 13:35:58.026] I: 413 [IN]CASE Server enabling CASE session setups
[2025-07-30 13:35:58.044] I: 418 [SVR]Joining Multicast groups
[2025-07-30 13:35:58.044] I: 422 [SVR]Server Listening...
[2025-07-30 13:35:58.044] I: 424 [DL]Device Configuration:
[2025-07-30 13:35:58.044] I: 427 [DL]  Serial Number: 1789AE57B32427844F
[2025-07-30 13:35:58.044] I: 432 [DL]  Vendor Id: 5153 (0x1421)
[2025-07-30 13:35:58.044] I: 435 [DL]  Product Id: 66 (0x42)
[2025-07-30 13:35:58.044] I: Get product name B, len 0
[2025-07-30 13:35:58.044] I: 441 [DL]  Product Name: B
[2025-07-30 13:35:58.044] I: 443 [DL]  Hardware Version: 1
[2025-07-30 13:35:58.044] I: 446 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 75655451
[2025-07-30 13:35:58.044] I: 451 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 776 (0x308)
[2025-07-30 13:35:58.044] I: 458 [DL]  Manufacturing Date: 2025-07-24
[2025-07-30 13:35:58.044] I: 462 [DL]  Device Type: 10 (0xA)
[2025-07-30 13:35:58.044] I: 465 [SVR]SetupQRCode: [MT:-QWJ08DB00.I2N6SM10]
[2025-07-30 13:35:58.044] I: 469 [SVR]Copy/paste the below URL in a browser to see the QR Code:
[2025-07-30 13:35:58.064] I: 475 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-QWJ08DB00.I2N6SM10
[2025-07-30 13:35:58.064] I: 484 [SVR]Manual pairing code: [05967546175]
[2025-07-30 13:35:58.064] I: STM32 device number: 
[2025-07-30 13:35:58.064] I: 31 37 38 39 41 45 35 37 |1789AE57
[2025-07-30 13:35:58.064] I: 42 33 32 34 32 37 38 34 |B3242784
[2025-07-30 13:35:58.064] I: 34 46                   |4F      
[2025-07-30 13:35:58.064] I: SKU number: 
[2025-07-30 13:35:58.064] I: 4b 31 37 2d 30 31       |K17-01  
[2025-07-30 13:35:58.064] I: WO number: 
[2025-07-30 13:35:58.064] I: 30 30 30 30 30 30 30 30 |00000000
[2025-07-30 13:35:58.064] I: 30                      |0       
[2025-07-30 13:35:58.064] I: Manuf Date: 
[2025-07-30 13:35:58.064] I: 32 30 32 35 2d 30 37 2d |2025-07-
[2025-07-30 13:35:58.064] I: 32 34 00 00 00 00       |24....  
[2025-07-30 13:35:58.064] I: Prod config length 6
[2025-07-30 13:35:58.090] I: Product Config: 
[2025-07-30 13:35:58.090] I: 30 78 30 30 30 31       |0x0001  
[2025-07-30 13:35:58.090] I: Prod Config Read 1
[2025-07-30 13:35:58.090] I: User intend flow enabled, set commissioning flow to kUserActionRequired
[2025-07-30 13:35:58.090] I: Factory Data Version length 2
[2025-07-30 13:35:58.090] I: Factory Data Ver: 
[2025-07-30 13:35:58.090] I: 30 31                   |01      
[2025-07-30 13:35:58.090] I: Payload value in string format: MT:-QWJ04TC00.I2N60Q4P0ILT70VYYR1JFSK14YDB0-0LJ1-0LJ1-0LJ1IHLC0AUZL1XIKJ17AZL1UV700CXYR1K6Y12NNZR1YC-L1-2ZR1OADO1KB40
[2025-07-30 13:35:58.090] I: Pairing Code value in string format: 459675461705153000660
[2025-07-30 13:35:58.090] I: ============== Updating product finish and color to 15, 2, product Name Halo Select Plus ==============
[2025-07-30 13:35:58.090] E: 575 [DL]Long dispatch time: 411 ms, for event type 2
[2025-07-30 13:35:58.090] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:35:59.534] I: Syncing up on message 9a
[2025-07-30 13:35:59.584] I: STM32 counter to 1
[2025-07-30 13:35:59.584] I: BLE Device ID: 2784
[2025-07-30 13:35:59.584] I: Device is provisioned
[2025-07-30 13:35:59.584] I: network state 0
[2025-07-30 13:35:59.584] E: Sending UART cmd(3) st 0
[2025-07-30 13:35:59.584] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:35:59.584] I: Received response of command id 9a
[2025-07-30 13:35:59.584] I: Command 0x9A Received
[2025-07-30 13:35:59.584] I: Firmware Attribute event
[2025-07-30 13:35:59.584] I: Received response of command id 30
[2025-07-30 13:35:59.615] I: Received DC Eco Config REQ
[2025-07-30 13:35:59.615] I: DC Eco Config Resp
[2025-07-30 13:35:59.615] I: Received DC eco config req
[2025-07-30 13:35:59.615] I: 80 72 03 00 10 00 04 1b |.r......
[2025-07-30 13:35:59.615] I: 17 05                   |..      
[2025-07-30 13:35:59.615] E: Sending UART cmd(72) st 0
[2025-07-30 13:36:01.584] I: Syncing up on message 3
[2025-07-30 13:36:01.584] I: Sys init req
[2025-07-30 13:36:01.584] E: Sending UART cmd(3) st 0
[2025-07-30 13:36:01.584] I: System init Response
[2025-07-30 13:36:01.584] I: Received response of command id 3
[2025-07-30 13:36:01.584] I: Update sync timer
[2025-07-30 13:36:01.584] I: Received Sys Init Resp
[2025-07-30 13:36:01.584] I: battery mode 0
[2025-07-30 13:36:01.584] I: battery percentage 5a
[2025-07-30 13:36:01.584] I: battery type 1
[2025-07-30 13:36:01.584] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:36:02.064] I: Syncing up on message 5
[2025-07-30 13:36:02.064] I: Operating mode req
[2025-07-30 13:36:02.114] E: Sending UART cmd(5) st 0
[2025-07-30 13:36:02.114] I: Operating mode response
[2025-07-30 13:36:02.114] I: Received response of command id 5
[2025-07-30 13:36:02.114] I: Received Lock Op Mode Resp, mode 10, App state 31
[2025-07-30 13:36:02.114] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:36:02.114] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:36:02.114] I: Set Kwikset Lock App State 49
[2025-07-30 13:36:02.114] I: Matter is disabled
[2025-07-30 13:36:02.614] I: Syncing up on message 10
[2025-07-30 13:36:02.614] I: Lock state req
[2025-07-30 13:36:02.614] E: Sending UART cmd(10) st 0
[2025-07-30 13:36:02.614] I: Lock State Response
[2025-07-30 13:36:02.614] I: Received response of command id 10
[2025-07-30 13:36:02.614] I: Received Lock State Response, lock st: 11
[2025-07-30 13:36:02.614] I: Found matching nordic source of operation 0
[2025-07-30 13:36:02.614] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:36:02.614] I: Lock action completed
[2025-07-30 13:36:02.614] I: Updating LockState attribute
[2025-07-30 13:36:02.614] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:36:03.064] I: Syncing up on message 20
[2025-07-30 13:36:03.104] I: Lock setting req
[2025-07-30 13:36:03.104] E: Sending UART cmd(20) st 0
[2025-07-30 13:36:03.104] I: Lock General Setting Response
[2025-07-30 13:36:03.104] I: Received response of command id 20
[2025-07-30 13:36:03.104] I: Received Lock General Setting resp
[2025-07-30 13:36:03.104] I: Matter Not Enabled do not set
[2025-07-30 13:36:03.564] I: Syncing up on message 51
[2025-07-30 13:36:03.564] I: Battery info req
[2025-07-30 13:36:03.564] E: Sending UART cmd(51) st 0
[2025-07-30 13:36:03.604] I: Received response of command id 51
[2025-07-30 13:36:03.604] I: Received Battery Info resp
[2025-07-30 13:36:03.604] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:36:03.604] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:36:03.604] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:36:04.074] I: All message synced.
[2025-07-30 13:36:27.554] I: STM system init timer expired, System Init Event not received from STM32
[2025-07-30 13:36:27.594] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-30 13:36:27.594] I: STM Pending =1, Redpine Pending = 1
[2025-07-30 13:36:27.594] I: STM Post OTA Pending
[2025-07-30 13:36:27.594] I: Redpine Post OTA Pending
[2025-07-30 13:36:27.594] E: Sending UART cmd(9e) st 0
[2025-07-30 13:36:27.594] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:36:27.594] I: 30191 [SWU]SMP BLE advertising started
[2025-07-30 13:36:27.594] I: 30195 [DL]DFU over SMP started
[2025-07-30 13:36:28.478] I: IMG Integrity Verified Successfully: 0
[2025-07-30 13:36:31.464] I: IMG Integrity Verified Successfully: 1
[2025-07-30 13:36:31.544] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:36:31.834] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:36:31.854] I: OTA Stage Change from (ff)->(32)
[2025-07-30 13:36:31.854] I: OTA device_id = 5 : DISCOVERY_REQ
[2025-07-30 13:36:31.936] I: SECURE_STM : IB_DEVICE_DISCOVERY_REQUEST (80) 
[2025-07-30 13:36:31.984] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:36:31.984] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-30 13:36:31.984] I: STM New OTA Firmware Version = 17 5 4 1b
[2025-07-30 13:36:31.984] I: OTA device_id = 5 : FW_UPDATE_START_REQ
[2025-07-30 13:36:31.984] I: SECURE_STM : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-30 13:36:38.334] I: STM OTA Progress = 10
[2025-07-30 13:36:44.634] I: STM OTA Progress = 20
[2025-07-30 13:36:50.954] I: STM OTA Progress = 30
[2025-07-30 13:36:57.365] I: STM OTA Progress = 40
[2025-07-30 13:37:03.684] I: STM OTA Progress = 50
[2025-07-30 13:37:09.994] I: STM OTA Progress = 60
[2025-07-30 13:37:16.304] I: STM OTA Progress = 70
[2025-07-30 13:37:22.615] I: STM OTA Progress = 80
[2025-07-30 13:37:28.934] I: STM OTA Progress = 90
[2025-07-30 13:37:35.256] I: STM OTA Progress = 100
[2025-07-30 13:37:35.944] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-30 13:37:35.944] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-30 13:37:53.605] I: Sending Sys Init Resp
[2025-07-30 13:37:53.605] I: Device is provisioned
[2025-07-30 13:37:53.605] I: network state 0
[2025-07-30 13:37:53.605] E: Sending UART cmd(3) st 0
[2025-07-30 13:37:53.605] I: Received DC App Config REQ
[2025-07-30 13:37:53.605] I: DC App Config Resp
[2025-07-30 13:37:53.605] I: Received DC config req
[2025-07-30 13:37:53.605] I: 80 70 03 00 10 10 08 00 |.p......
[2025-07-30 13:37:53.605] I: 50 1e                   |P.      
[2025-07-30 13:37:53.605] I: Matter enabled state 0
[2025-07-30 13:37:53.605] I: Get Matter Commission State
[2025-07-30 13:37:53.605] I: network state 0
[2025-07-30 13:37:53.616] I: network state 0
[2025-07-30 13:37:53.616] E: Sending UART cmd(70) st 0
[2025-07-30 13:37:53.675] I: Lock State Event
[2025-07-30 13:37:53.675] I: Received response of command id 10
[2025-07-30 13:37:53.675] I: Received Lock State event, lock st: 11
[2025-07-30 13:37:53.675] I: Found matching nordic source of operation 0
[2025-07-30 13:37:53.675] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:37:53.675] I: Lock action completed
[2025-07-30 13:37:53.675] I: Updating LockState attribute
[2025-07-30 13:37:53.675] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:37:53.705] I: Received DC Eco Config REQ
[2025-07-30 13:37:53.705] I: DC Eco Config Resp
[2025-07-30 13:37:53.734] I: Received DC eco config req
[2025-07-30 13:37:53.734] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:37:53.734] I: c4 1e                   |..      
[2025-07-30 13:37:53.734] E: Sending UART cmd(72) st 0
[2025-07-30 13:37:53.874] I: General Lock Setting event
[2025-07-30 13:37:53.904] I: Received response of command id 20
[2025-07-30 13:37:53.904] I: Received Lock General Setting event
[2025-07-30 13:37:53.904] I: Matter Not Enabled do not set
[2025-07-30 13:37:53.995] I: Firmware Attribute event
[2025-07-30 13:37:54.016] I: Received response of command id 30
[2025-07-30 13:37:54.075] I: Hardware Attribute event
[2025-07-30 13:37:54.075] I: Received response of command id 31
[2025-07-30 13:37:54.144] I: Operating mode event
[2025-07-30 13:37:54.144] I: Received response of command id 5
[2025-07-30 13:37:54.144] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:37:54.144] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:37:54.144] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:37:54.144] I: Set Kwikset Lock App State 49
[2025-07-30 13:37:54.144] I: Matter is disabled
[2025-07-30 13:37:54.264] I: Battery Info event
[2025-07-30 13:37:54.264] I: Received response of command id 51
[2025-07-30 13:37:54.264] I: Received Battery info event
[2025-07-30 13:37:54.264] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:37:54.264] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:37:54.264] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:37:54.351] I: System info event
[2025-07-30 13:37:54.384] I: Received System Info Event
[2025-07-30 13:37:54.384] W: Time invalid, set time
[2025-07-30 13:37:54.384] I: Get system time
[2025-07-30 13:37:54.384] I: System Real time in seconds 373662943
[2025-07-30 13:37:54.384] I: Time sync status flag 0
[2025-07-30 13:37:54.384] E: Time not sync, keep default value
[2025-07-30 13:37:54.484] I: System init event
[2025-07-30 13:37:54.484] I: Received response of command id 3
[2025-07-30 13:37:54.484] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:37:54.484] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:37:54.484] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:37:54.484] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-30 13:37:54.484] I: OTA device_id = 5 : FW_UPDATE_COMPLETE_REQ
[2025-07-30 13:37:54.484] I: SECURE_STM : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-30 13:37:54.484] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-30 13:37:54.484] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-30 13:37:56.874] I: Sending Sys Init Resp
[2025-07-30 13:37:56.874] I: Device is provisioned
[2025-07-30 13:37:56.917] I: network state 0
[2025-07-30 13:37:56.917] E: Sending UART cmd(3) st 0
[2025-07-30 13:37:56.917] I: Received DC App Config REQ
[2025-07-30 13:37:56.917] I: DC App Config Resp
[2025-07-30 13:37:56.917] I: Received DC config req
[2025-07-30 13:37:56.917] I: 80 70 03 00 10 10 04 1b |.p......
[2025-07-30 13:37:56.917] I: 00 62                   |.b      
[2025-07-30 13:37:56.917] I: Matter enabled state 0
[2025-07-30 13:37:56.917] I: Get Matter Commission State
[2025-07-30 13:37:56.917] I: network state 0
[2025-07-30 13:37:56.917] I: network state 0
[2025-07-30 13:37:56.924] E: Sending UART cmd(70) st 0
[2025-07-30 13:37:56.985] I: Lock State Event
[2025-07-30 13:37:56.985] I: Received response of command id 10
[2025-07-30 13:37:56.985] I: Received Lock State event, lock st: 11
[2025-07-30 13:37:56.985] I: Found matching nordic source of operation 0
[2025-07-30 13:37:56.985] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:37:56.985] I: Lock action completed
[2025-07-30 13:37:56.985] I: Updating LockState attribute
[2025-07-30 13:37:56.985] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:37:57.015] I: Received DC Eco Config REQ
[2025-07-30 13:37:57.015] I: DC Eco Config Resp
[2025-07-30 13:37:57.019] I: Received DC eco config req
[2025-07-30 13:37:57.044] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:37:57.044] I: c4 62                   |.b      
[2025-07-30 13:37:57.044] E: Sending UART cmd(72) st 0
[2025-07-30 13:37:57.214] I: General Lock Setting event
[2025-07-30 13:37:57.214] I: Received response of command id 20
[2025-07-30 13:37:57.214] I: Received Lock General Setting event
[2025-07-30 13:37:57.214] I: Matter Not Enabled do not set
[2025-07-30 13:37:57.304] I: Firmware Attribute event
[2025-07-30 13:37:57.304] I: Received response of command id 30
[2025-07-30 13:37:57.384] I: Hardware Attribute event
[2025-07-30 13:37:57.384] I: Received response of command id 31
[2025-07-30 13:37:57.454] I: Operating mode event
[2025-07-30 13:37:57.454] I: Received response of command id 5
[2025-07-30 13:37:57.454] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:37:57.454] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:37:57.454] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:37:57.454] I: Set Kwikset Lock App State 49
[2025-07-30 13:37:57.454] I: Matter is disabled
[2025-07-30 13:37:57.584] I: Battery Info event
[2025-07-30 13:37:57.584] I: Received response of command id 51
[2025-07-30 13:37:57.584] I: Received Battery info event
[2025-07-30 13:37:57.584] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:37:57.584] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:37:57.584] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:37:57.694] I: System info event
[2025-07-30 13:37:57.694] I: Received System Info Event
[2025-07-30 13:37:57.694] W: Time invalid, set time
[2025-07-30 13:37:57.694] I: Get system time
[2025-07-30 13:37:57.694] I: System Real time in seconds 373662943
[2025-07-30 13:37:57.694] I: Time sync status flag 0
[2025-07-30 13:37:57.694] E: Time not sync, keep default value
[2025-07-30 13:37:57.784] I: System init event
[2025-07-30 13:37:57.784] I: Received response of command id 3
[2025-07-30 13:37:57.784] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:37:57.784] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:37:57.784] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:37:57.784] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-30 13:37:57.784] I: STM New OTA Firmware Version = 17 5 4 1b
[2025-07-30 13:37:57.784] I: STM Secure OTA Successful
[2025-07-30 13:37:57.884] I: Cleared STM OTA Meta Data
[2025-07-30 13:37:57.884] I: OTA Stage Change from (32)->(33)
[2025-07-30 13:37:57.884] I: Redpine OTA started
[2025-07-30 13:37:57.884] I: OTA Stage Change from (33)->(34)
[2025-07-30 13:37:57.884] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-30 13:38:04.874] I: STM Reset Count 0
[2025-07-30 13:38:04.934] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-30 13:38:04.934] I: STM_QSPI : IB_DEVICE_DISCOVERY_REQUEST (80)
[2025-07-30 13:38:04.934] I: OTA device_id = 4 : FW_VERSION_REQ
[2025-07-30 13:38:04.934] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-30 13:38:04.934] I: Redpine Current Firmware Version: 2.c.0.3
[2025-07-30 13:38:04.934] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-30 13:38:04.934] I: Skip Redpine OTA, Older OTA Version Request Received
[2025-07-30 13:38:05.015] I: Clear Redpine OTA Meta Data
[2025-07-30 13:38:05.015] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-30 13:38:05.044] I: STM Pending =2, Redpine Pending = 2
[2025-07-30 13:38:05.044] I: PN76 IMG 1 Post OTA Pending
[2025-07-30 13:38:05.044] E: Sending UART cmd(9e) st 0
[2025-07-30 13:38:05.044] I: 127646 [SWU]Software update is already enabled
[2025-07-30 13:38:05.124] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:38:05.414] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:38:05.454] I: OTA Stage Change from (34)->(3a)
[2025-07-30 13:38:05.454] I: PN76_IMG1_DEVICE_DFU_MULTI_IMG_ID
[2025-07-30 13:38:05.454] I: PN76_IMG Update from OTA Task Event
[2025-07-30 13:38:05.454] I: 
[2025-07-30 13:38:05.454] 
[2025-07-30 13:38:05.454] --------------- UPDATING PN7642 NXP FIRMWARE --------------------
[2025-07-30 13:38:05.454] 
[2025-07-30 13:38:05.454] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-30 13:38:05.504] I: pNXPFWInfo->img_offset = 0x35149a
[2025-07-30 13:38:05.504] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-30 13:38:05.504] I: Reading version of firmware in QSPI flash: MetaData 0x3f60217
[2025-07-30 13:38:05.504] I: NXP FW Version 2 f6 : 2 f6
[2025-07-30 13:38:05.504] I: PN76 NXP FW VERSION IS EQUAL
[2025-07-30 13:38:05.504] I: 
[2025-07-30 13:38:05.504] PN7642 Firmware of type 0 Successfully Updated !!!
[2025-07-30 13:38:05.624] I: Cleared PN76 Img1 OTA Meta Data
[2025-07-30 13:38:05.624] I: OTA Stage Change from (3a)->(3a)
[2025-07-30 13:38:05.624] I: PN76_IMG2_DEVICE_DFU_MULTI_IMG_ID
[2025-07-30 13:38:05.624] I: PN76_IMG Update from OTA Task Event
[2025-07-30 13:38:05.624] I: 
[2025-07-30 13:38:05.624] 
[2025-07-30 13:38:05.624] --------------- UPDATING PN7642 APPLICATION FIRMWARE -------------
[2025-07-30 13:38:05.624] 
[2025-07-30 13:38:05.624] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-30 13:38:05.665] I: pCustAppFWInfo->img_offset = 0x35c28c
[2025-07-30 13:38:05.665] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-30 13:38:05.665] I: Reading version of firmware in QSPI flash: MetaData 0x3f60217
[2025-07-30 13:38:05.665] I: PN76 NXP APP FW VERSION IS HIGHER
[2025-07-30 13:38:05.965] I: ----> PN7642 OTA Progress = 10 %
[2025-07-30 13:38:06.245] I: ----> PN7642 OTA Progress = 20 %
[2025-07-30 13:38:06.494] I: ----> PN7642 OTA Progress = 30 %
[2025-07-30 13:38:06.755] I: ----> PN7642 OTA Progress = 40 %
[2025-07-30 13:38:07.005] I: ----> PN7642 OTA Progress = 50 %
[2025-07-30 13:38:07.284] I: ----> PN7642 OTA Progress = 60 %
[2025-07-30 13:38:07.534] I: ----> PN7642 OTA Progress = 70 %
[2025-07-30 13:38:07.808] I: ----> PN7642 OTA Progress = 80 %
[2025-07-30 13:38:08.064] I: ----> PN7642 OTA Progress = 90 %
[2025-07-30 13:38:08.324] I: ----> PN7642 OTA Progress = 100 %
[2025-07-30 13:38:08.324] I: Whole pn7642 FW Image downloaded ....
[2025-07-30 13:38:08.344] I: 
[2025-07-30 13:38:08.344] 
[2025-07-30 13:38:08.344] I: 
[2025-07-30 13:38:08.344] PN7642 Firmware of type 1 Successfully Updated !!!
[2025-07-30 13:38:08.425] I: Cleared PN76 Img2 OTA Meta Data
[2025-07-30 13:38:08.534] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-30 13:38:08.534] I: NFC Boot Event PN7642 FW VERSION 17.01.00.03
[2025-07-30 13:38:08.534] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-30 13:38:08.534] I: 
[2025-07-30 13:38:08.534] Boot Event Received
[2025-07-30 13:38:08.534] 
[2025-07-30 13:38:08.534] I: Booted NFC IC in Normal Operation Mode.
[2025-07-30 13:38:08.534] 
[2025-07-30 13:38:08.534] I: OTA Stage Change from (3a)->(3b)
[2025-07-30 13:38:08.534] I: post_stm_reset_event : init_pending_ota_update
[2025-07-30 13:38:08.534] I: All pending FW Updates are completed.
[2025-07-30 13:38:08.534] I: STM32 Reset Count = 0
[2025-07-30 13:38:08.534] I: REBOOT_STM: Send STM32 Reboot Command, Count (0)
[2025-07-30 13:38:10.834] I: Sending Sys Init Resp
[2025-07-30 13:38:10.834] I: Device is provisioned
[2025-07-30 13:38:10.834] I: network state 0
[2025-07-30 13:38:10.834] E: Sending UART cmd(3) st 0
[2025-07-30 13:38:10.834] I: Received DC App Config REQ
[2025-07-30 13:38:10.845] I: DC App Config Resp
[2025-07-30 13:38:10.845] I: Received DC config req
[2025-07-30 13:38:10.845] I: 80 70 03 00 10 10 00 03 |.p......
[2025-07-30 13:38:10.845] I: 00 62                   |.b      
[2025-07-30 13:38:10.845] I: Matter enabled state 0
[2025-07-30 13:38:10.845] I: Get Matter Commission State
[2025-07-30 13:38:10.845] I: network state 0
[2025-07-30 13:38:10.845] I: network state 0
[2025-07-30 13:38:10.845] E: Sending UART cmd(70) st 0
[2025-07-30 13:38:10.904] I: Lock State Event
[2025-07-30 13:38:10.904] I: Received response of command id 10
[2025-07-30 13:38:10.904] I: Received Lock State event, lock st: 11
[2025-07-30 13:38:10.904] I: Found matching nordic source of operation 0
[2025-07-30 13:38:10.904] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:38:10.904] I: Lock action completed
[2025-07-30 13:38:10.904] I: Updating LockState attribute
[2025-07-30 13:38:10.904] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:38:10.934] I: Received DC Eco Config REQ
[2025-07-30 13:38:10.934] I: DC Eco Config Resp
[2025-07-30 13:38:10.964] I: Received DC eco config req
[2025-07-30 13:38:10.964] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:38:10.964] I: c4 62                   |.b      
[2025-07-30 13:38:10.964] E: Sending UART cmd(72) st 0
[2025-07-30 13:38:11.134] I: General Lock Setting event
[2025-07-30 13:38:11.134] I: Received response of command id 20
[2025-07-30 13:38:11.134] I: Received Lock General Setting event
[2025-07-30 13:38:11.134] I: Matter Not Enabled do not set
[2025-07-30 13:38:11.234] I: Firmware Attribute event
[2025-07-30 13:38:11.234] I: Received response of command id 30
[2025-07-30 13:38:11.305] I: Hardware Attribute event
[2025-07-30 13:38:11.305] I: Received response of command id 31
[2025-07-30 13:38:11.384] I: Operating mode event
[2025-07-30 13:38:11.384] I: Received response of command id 5
[2025-07-30 13:38:11.384] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:38:11.384] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:38:11.384] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:38:11.384] I: Set Kwikset Lock App State 49
[2025-07-30 13:38:11.384] I: Matter is disabled
[2025-07-30 13:38:11.505] I: Battery Info event
[2025-07-30 13:38:11.505] I: Received response of command id 51
[2025-07-30 13:38:11.505] I: Received Battery info event
[2025-07-30 13:38:11.505] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:38:11.505] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:38:11.505] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:38:11.584] I: System info event
[2025-07-30 13:38:11.616] I: Received System Info Event
[2025-07-30 13:38:11.616] W: Time invalid, set time
[2025-07-30 13:38:11.616] I: Get system time
[2025-07-30 13:38:11.616] I: System Real time in seconds 373662943
[2025-07-30 13:38:11.616] I: Time sync status flag 0
[2025-07-30 13:38:11.616] E: Time not sync, keep default value
[2025-07-30 13:38:11.644] I: System init event
[2025-07-30 13:38:11.675] I: Received response of command id 3
[2025-07-30 13:38:11.675] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:38:11.675] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:38:18.574] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-30 13:38:18.574] I: stop_ota_finalization_timer
[2025-07-30 13:38:18.574] I: After OTAU, Redpine Firmware Version: 2.c.0.3
[2025-07-30 13:38:18.574] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-30 13:38:18.574] I: After OTAU, Secure STM Firmware Version: 17 5 4 1b
[2025-07-30 13:38:18.574] I: Send Op Mode command to release Redpine BLE and WiFI
[2025-07-30 13:38:18.574] I: Operating Mode Command: Mode:10, State:f0
[2025-07-30 13:38:18.574] E: Sending UART cmd(5) st 0
[2025-07-30 13:38:18.634] I: Operating mode event
[2025-07-30 13:38:18.634] I: Received response of command id 5
[2025-07-30 13:38:18.634] I: Received Lock Op Mode Event, mode 10, App state 10
[2025-07-30 13:38:18.634] I: Lock Current Mode : 10, Lock Current State = 10
[2025-07-30 13:38:18.634] I: stop_ota_finalization_timer
[2025-07-30 13:38:18.634] I: STM32 HALO APP STATE IS ACTIVATED NORMAL
[2025-07-30 13:38:18.634] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:38:18.634] I: Set Kwikset Lock App State 16
[2025-07-30 13:38:18.634] I: Matter enabled state 0
[2025-07-30 13:38:18.634] I: Matter is disabled
[2025-07-30 13:38:18.634] I: OTA_HOUSEKEEPING
[2025-07-30 13:38:18.634] I: OTA Stage Change from (3b)->(80)
[2025-07-30 13:38:18.634] I: Start Erasing OTA bundle from nRF External Flash
[2025-07-30 13:38:24.254] I: System info event
[2025-07-30 13:38:24.254] I: Received System Info Event
[2025-07-30 13:38:24.254] I: Time is set in STM
[2025-07-30 13:38:27.754] I: STM Boot Up Properly, Stopped STM Reboot Timer
[2025-07-30 13:39:19.054] I: Bundle Image Erased from nRF External Flash: 0
[2025-07-30 13:39:19.134] I: OTAU Completed Successfully
[2025-07-30 13:39:19.224] I: Cleared OTA Meta Data
[2025-07-30 13:39:19.244] I: OTA Stage Change from (80)->(90)
[2025-07-30 13:39:21.244] I: All message synced.
[2025-07-30 13:39:34.255] I: STOP BLE Advertisment
[2025-07-30 13:39:34.255] I: 216854 [DL]DFU over SMP stopped
[2025-07-30 13:39:34.255] E: Sending UART cmd(9e) st 0
[2025-07-30 13:42:57.905] I: Updated ota meta data
[2025-07-30 13:42:57.905] I: Operating Mode Command: Mode:10, State:34
[2025-07-30 13:42:57.905] E: Sending UART cmd(5) st 0
[2025-07-30 13:42:57.965] I: Operating mode event
[2025-07-30 13:42:57.965] I: Received response of command id 5
[2025-07-30 13:42:57.965] I: Received Lock Op Mode Event, mode 10, App state 34
[2025-07-30 13:42:57.965] I: Lock Current Mode : 10, Lock Current State = 34
[2025-07-30 13:42:57.965] I: STM32 HALO APP STATE IS BLE OTAU TRANSFER
[2025-07-30 13:42:57.965] E: Sending UART cmd(9e) st 0
[2025-07-30 13:42:57.965] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:42:57.965] I: 420556 [SWU]SMP BLE advertising started
[2025-07-30 13:42:57.965] I: 420561 [DL]DFU over SMP started
[2025-07-30 13:42:57.965] I: OTA Stage Change from (90)->(11)
[2025-07-30 13:42:57.965] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:42:57.965] I: Set Kwikset Lock App State 52
[2025-07-30 13:42:57.965] I: Matter is disabled
[2025-07-30 13:43:13.775] I: 436365 [DL]DFU-BLE-Connected
[2025-07-30 13:43:13.775] I: stop_ble_advertisment_timer
[2025-07-30 13:43:13.775] I: 436371 [DL]Current number of connections: 1/1
[2025-07-30 13:43:13.775] I: BLE Connected
[2025-07-30 13:43:13.985] I: 436590 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:43:13.985] I: 436593 [DL]Current number of connections: 0/1
[2025-07-30 13:43:13.985] I: BLE Disconnected: 13
[2025-07-30 13:43:18.325] I: 440941 [DL]DFU-BLE-Connected
[2025-07-30 13:43:18.325] I: stop_ble_advertisment_timer
[2025-07-30 13:43:18.345] I: 440946 [DL]Current number of connections: 1/1
[2025-07-30 13:43:18.345] I: BLE Connected
[2025-07-30 13:43:18.555] I: 441163 [DL]DFU Image upload started
[2025-07-30 13:43:19.395] I: Connection parameters updated.
[2025-07-30 13:43:19.395]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:43:25.895] I: OTA Stage Change from (11)->(12)
[2025-07-30 13:43:25.905] I: 448503 [DL]Image 0 download completed successfully
[2025-07-30 13:43:26.005] I: 448601 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:43:26.005] I: 448605 [DL]Current number of connections: 0/1
[2025-07-30 13:43:26.005] I: BLE Disconnected: 13
[2025-07-30 13:43:37.995] I: 460594 [DL]DFU-BLE-Connected
[2025-07-30 13:43:37.995] I: stop_ble_advertisment_timer
[2025-07-30 13:43:37.995] I: 460599 [DL]Current number of connections: 1/1
[2025-07-30 13:43:37.995] I: BLE Connected
[2025-07-30 13:43:38.227] I: 460836 [DL]DFU Image upload started
[2025-07-30 13:43:39.025] I: Connection parameters updated.
[2025-07-30 13:43:39.045]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:44:15.081] I: OTA Stage Change from (12)->(13)
[2025-07-30 13:44:15.081] I: 497681 [DL]Image 1 download completed successfully
[2025-07-30 13:44:15.185] I: 497782 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:44:15.185] I: 497785 [DL]Current number of connections: 0/1
[2025-07-30 13:44:15.185] I: BLE Disconnected: 13
[2025-07-30 13:44:22.590] I: 505208 [DL]DFU-BLE-Connected
[2025-07-30 13:44:22.615] I: stop_ble_advertisment_timer
[2025-07-30 13:44:22.615] I: 505213 [DL]Current number of connections: 1/1
[2025-07-30 13:44:22.615] I: BLE Connected
[2025-07-30 13:44:22.835] I: 505453 [DL]DFU Image upload started
[2025-07-30 13:44:23.655] I: Connection parameters updated.
[2025-07-30 13:44:23.655]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:46:13.685] I: OTA Stage Change from (13)->(14)
[2025-07-30 13:46:13.685] I: 616294 [DL]Image 2 download completed successfully
[2025-07-30 13:46:13.795] I: 616397 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:46:13.795] I: 616401 [DL]Current number of connections: 0/1
[2025-07-30 13:46:13.795] I: BLE Disconnected: 13
[2025-07-30 13:46:22.205] I: 624828 [DL]DFU-BLE-Connected
[2025-07-30 13:46:22.229] I: stop_ble_advertisment_timer
[2025-07-30 13:46:22.229] I: 624834 [DL]Current number of connections: 1/1
[2025-07-30 13:46:22.229] I: BLE Connected
[2025-07-30 13:46:22.435] I: 625056 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:46:22.435] I: 625059 [DL]Current number of connections: 0/1
[2025-07-30 13:46:22.455] I: BLE Disconnected: 13
[2025-07-30 13:46:26.565] I: 629165 [DL]DFU-BLE-Connected
[2025-07-30 13:46:26.565] I: stop_ble_advertisment_timer
[2025-07-30 13:46:26.565] I: 629171 [DL]Current number of connections: 1/1
[2025-07-30 13:46:26.565] I: BLE Connected
[2025-07-30 13:46:26.785] I: 629387 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-30 13:46:26.815] I: 629413 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:46:26.815] I: 629417 [DL]Current number of connections: 0/1
[2025-07-30 13:46:26.815] I: BLE Disconnected: 13
[2025-07-30 13:46:33.996] I: 636590 [DL]DFU-BLE-Connected
[2025-07-30 13:46:33.996] I: stop_ble_advertisment_timer
[2025-07-30 13:46:33.996] I: 636596 [DL]Current number of connections: 1/1
[2025-07-30 13:46:33.996] I: BLE Connected
[2025-07-30 13:46:34.205] I: 636812 [DL]DFU_ImgConfirmHandler: Nordic Image Confirmed by MCUMgr
[2025-07-30 13:46:34.235] I: 636838 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:46:34.235] I: 636842 [DL]Current number of connections: 0/1
[2025-07-30 13:46:34.235] I: BLE Disconnected: 13
[2025-07-30 13:46:41.605] I: 644231 [DL]DFU-BLE-Connected
[2025-07-30 13:46:41.626] I: stop_ble_advertisment_timer
[2025-07-30 13:46:41.626] I: 644237 [DL]Current number of connections: 1/1
[2025-07-30 13:46:41.626] I: BLE Connected
[2025-07-30 13:46:41.825] I: STM Pending =0, Redpine Pending = 0
[2025-07-30 13:46:41.935] I: Count = 4
[2025-07-30 13:46:41.935] I: dfu_header_data.image_count: 4
[2025-07-30 13:46:42.685] I: Connection parameters updated.
[2025-07-30 13:46:42.685]  interval: 9, latency: 0, timeout: 42
[2025-07-30 13:46:42.825] I: IMG Integrity Verified Successfully: 0
[2025-07-30 13:46:45.815] I: IMG Integrity Verified Successfully: 1
[2025-07-30 13:46:45.895] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:46:46.235] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:46:46.255] I: OTA Bundle(STM32 + RS9116 + PN76) image integrity Verified
[2025-07-30 13:46:46.255] I: OTA Stage Change from (14)->(30)
[2025-07-30 13:46:46.355] I: Updated ota meta data
[2025-07-30 13:46:46.355] I: Operating Mode Command: Mode:10, State:31
[2025-07-30 13:46:46.355] E: Sending UART cmd(5) st 0
[2025-07-30 13:46:46.355] I: Operating mode event
[2025-07-30 13:46:46.395] I: Received response of command id 5
[2025-07-30 13:46:46.395] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:46:46.395] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:46:46.395] I: STM OTAU Pending: Reset Nordic Triggered
[2025-07-30 13:46:46.395] I: OTA Stage Change from (30)->(30)
[2025-07-30 13:46:46.395] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:46:46.395] I: Set Kwikset Lock App State 49
[2025-07-30 13:46:46.395] I: Matter is disabled
[2025-07-30 13:46:46.433] I: 649052 [DL]DFU-BLE-Disconnected : 19
[2025-07-30 13:46:46.455] I: 649055 [DL]Current number of connections: 0/1
[2025-07-30 13:46:46.455] I: BLE Disconnected: 13
[2025-07-30 13:47:33.875] 
[2025-07-30 13:47:33.875] uart:~$ *** Booting My Application v23.55.5-2f9996e8c87c ***
[2025-07-30 13:47:33.915] *** Using nRF Connect SDK v2.8.0-a2386bfc8401 ***
[2025-07-30 13:47:33.915] *** Using Zephyr OS v3.7.99-0bc3393fb112 ***
[2025-07-30 13:47:33.915] I: KWIKSET HALO 3 PLUS VERSION: 17.37.05.03
[2025-07-30 13:47:33.915] I: 51 [DL]BLE address: EC:51:1A:0E:47:9B
[2025-07-30 13:47:33.935] I: No users indexes stored
[2025-07-30 13:47:33.935] I: No stored indexes for credential of type: 1
[2025-07-30 13:47:34.045] I: No stored indexes for credential of type: 2
[2025-07-30 13:47:34.045] I: ========== User Index: 0x01 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x02 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x03 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x04 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x05 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x06 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x07 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x08 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x09 User ID: 0xffffffff ==========
[2025-07-30 13:47:34.045] I: ========== User Index: 0x0a User ID: 0xffffffff ==========
[2025-07-30 13:47:34.077] I: ========== User Index: 0x0b User ID: 0xffffffff ==========
[2025-07-30 13:47:34.077] I: Board config kwiksetmdb_nrf5340_cpuapp
[2025-07-30 13:47:34.077] I: IMAGE_VERSION 17370503
[2025-07-30 13:47:34.077] I: build time: Jul 29 2025 13:32:25
[2025-07-30 13:47:34.077] I: 158 [DL]CHIP task running
[2025-07-30 13:47:34.077] I: Init CHIP stack
[2025-07-30 13:47:34.077] I: 164 [DL]OpenThread started: OK
[2025-07-30 13:47:34.077] I: 167 [DL]Setting OpenThread device type to SLEEPY END DEVICE
[2025-07-30 13:47:34.077] I: 173 [SWU]New firmware image confirmed
[2025-07-30 13:47:34.077] I: 176 [SWU]DFU_BLEAdvertising_Init
[2025-07-30 13:47:34.455] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-30 13:47:34.455] I: NFC Boot Event PN7642 FW VERSION 17.01.00.03
[2025-07-30 13:47:34.455] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-30 13:47:34.455] I: 
[2025-07-30 13:47:34.455] Boot Event Received
[2025-07-30 13:47:34.455] 
[2025-07-30 13:47:34.455] I: Booted NFC IC in Normal Operation Mode.
[2025-07-30 13:47:34.455] 
[2025-07-30 13:47:34.455] I: 260 [SVR]Subscription persistence not supported
[2025-07-30 13:47:34.455] I: 264 [SVR]Server initializing...
[2025-07-30 13:47:34.455] I: 268 [TS]Last Known Good Time: 2023-10-14T01:16:48
[2025-07-30 13:47:34.455] I: 273 [DMG]AccessControl: initializing
[2025-07-30 13:47:34.455] I: 277 [DMG]Examples::AccessControlDelegate::Init
[2025-07-30 13:47:34.455] I: 281 [DMG]AccessControl: setting
[2025-07-30 13:47:34.455] I: 284 [DMG]DefaultAclStorage: initializing
[2025-07-30 13:47:34.455] I: 288 [DMG]DefaultAclStorage: 0 entries loaded
[2025-07-30 13:47:34.485] E: 292 [IN]IPV6_PKTINFO failed: 109
[2025-07-30 13:47:34.485] I: 298 [ZCL]Using ZAP configuration...
[2025-07-30 13:47:34.485] I: 303 [DMG]AccessControlCluster: initializing
[2025-07-30 13:47:34.485] Unhandled cluster ID: 0x  30
[2025-07-30 13:47:34.485] 
[2025-07-30 13:47:34.485] ===== Attribute Received are: Cluster=30 Attribute=0 Value=0 =====
[2025-07-30 13:47:34.485] I: 318 [ZCL]Emit DSTTableEmpty event [ep=0]
[2025-07-30 13:47:34.485] I: 321 [ZCL]Initiating Admin Commissioning cluster.
[2025-07-30 13:47:34.485] I: 326 [ZCL]Door Lock server initialized
[2025-07-30 13:47:34.485] E: 330 [ZCL]DeviceInfoProvider is not registered
[2025-07-30 13:47:34.485] E: 334 [ZCL]Failed to read calendar type with error: 0x86
[2025-07-30 13:47:34.485] Unhandled cluster ID: 0x   3
[2025-07-30 13:47:34.485] 
[2025-07-30 13:47:34.495] ===== Attribute Received are: Cluster=3 Attribute=1 Value=3 =====
[2025-07-30 13:47:34.505] I: 348 [ZCL]Door Lock cluster initialized at endpoint #1
[2025-07-30 13:47:34.505] ===== Attribute Received are: Cluster=101 Attribute=0 Value=255 =====
[2025-07-30 13:47:34.505] ===== Attribute Received are: Cluster=101 Attribute=2 Value=1 =====
[2025-07-30 13:47:34.505] ===== Attribute Received are: Cluster=101 Attribute=1 Value=0 =====
[2025-07-30 13:47:34.505] ===== Attribute Received are: Cluster=101 Attribute=11 Value=11 =====
[2025-07-30 13:47:34.505] ===== Attribute Received are: Cluster=101 Attribute=12 Value=35 =====
[2025-07-30 13:47:34.505] ===== Attribute Received are: Cluster=101 Attribute=13 Value=35 =====
[2025-07-30 13:47:34.505] ===== Attribute Received are: Cluster=101 Attribute=1c Value=35 =====
[2025-07-30 13:47:34.505] ===== Attribute Received are: Cluster=101 Attribute=19 Value=80 =====
[2025-07-30 13:47:34.505] I: 401 [DIS]Updating services using commissioning mode 0
[2025-07-30 13:47:34.505] E: 406 [DIS]Failed to remove advertised services: 3
[2025-07-30 13:47:34.525] E: 411 [DIS]Failed to finalize service update: 3
[2025-07-30 13:47:34.525] I: 415 [IN]CASE Server enabling CASE session setups
[2025-07-30 13:47:34.525] I: 420 [SVR]Joining Multicast groups
[2025-07-30 13:47:34.525] I: 424 [SVR]Server Listening...
[2025-07-30 13:47:34.525] I: 426 [DL]Device Configuration:
[2025-07-30 13:47:34.525] I: 429 [DL]  Serial Number: 1789AE57B32427844F
[2025-07-30 13:47:34.525] I: 434 [DL]  Vendor Id: 5153 (0x1421)
[2025-07-30 13:47:34.525] I: 437 [DL]  Product Id: 66 (0x42)
[2025-07-30 13:47:34.525] I: Get product name B, len 0
[2025-07-30 13:47:34.525] I: 443 [DL]  Product Name: B
[2025-07-30 13:47:34.525] I: 445 [DL]  Hardware Version: 1
[2025-07-30 13:47:34.530] I: 448 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 75655451
[2025-07-30 13:47:34.530] I: 453 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 776 (0x308)
[2025-07-30 13:47:34.530] I: 460 [DL]  Manufacturing Date: 2025-07-24
[2025-07-30 13:47:34.547] I: 464 [DL]  Device Type: 10 (0xA)
[2025-07-30 13:47:34.547] I: 467 [SVR]SetupQRCode: [MT:-QWJ08DB00.I2N6SM10]
[2025-07-30 13:47:34.547] I: 471 [SVR]Copy/paste the below URL in a browser to see the QR Code:
[2025-07-30 13:47:34.547] I: 477 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-QWJ08DB00.I2N6SM10
[2025-07-30 13:47:34.547] I: 486 [SVR]Manual pairing code: [05967546175]
[2025-07-30 13:47:34.547] I: STM32 device number: 
[2025-07-30 13:47:34.547] I: 31 37 38 39 41 45 35 37 |1789AE57
[2025-07-30 13:47:34.547] I: 42 33 32 34 32 37 38 34 |B3242784
[2025-07-30 13:47:34.547] I: 34 46                   |4F      
[2025-07-30 13:47:34.547] I: SKU number: 
[2025-07-30 13:47:34.547] I: 4b 31 37 2d 30 31       |K17-01  
[2025-07-30 13:47:34.547] I: WO number: 
[2025-07-30 13:47:34.547] I: 30 30 30 30 30 30 30 30 |00000000
[2025-07-30 13:47:34.547] I: 30                      |0       
[2025-07-30 13:47:34.572] I: Manuf Date: 
[2025-07-30 13:47:34.572] I: 32 30 32 35 2d 30 37 2d |2025-07-
[2025-07-30 13:47:34.572] I: 32 34 00 00 00 00       |24....  
[2025-07-30 13:47:34.572] I: Prod config length 6
[2025-07-30 13:47:34.572] I: Product Config: 
[2025-07-30 13:47:34.572] I: 30 78 30 30 30 31       |0x0001  
[2025-07-30 13:47:34.572] I: Prod Config Read 1
[2025-07-30 13:47:34.572] I: User intend flow enabled, set commissioning flow to kUserActionRequired
[2025-07-30 13:47:34.572] I: Factory Data Version length 2
[2025-07-30 13:47:34.572] I: Factory Data Ver: 
[2025-07-30 13:47:34.572] I: 30 31                   |01      
[2025-07-30 13:47:34.572] I: Payload value in string format: MT:-QWJ04TC00.I2N60Q4P0ILT70VYYR1JFSK14YDB0-0LJ1-0LJ1-0LJ1IHLC0AUZL1XIKJ17AZL1UV700CXYR1K6Y12NNZR1YC-L1-2ZR1OADO1KB40
[2025-07-30 13:47:34.572] I: Pairing Code value in string format: 459675461705153000660
[2025-07-30 13:47:34.572] I: ============== Updating product finish and color to 15, 2, product Name Halo Select Plus ==============
[2025-07-30 13:47:34.585] E: 577 [DL]Long dispatch time: 417 ms, for event type 2
[2025-07-30 13:47:34.585] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:47:36.006] I: Syncing up on message 9a
[2025-07-30 13:47:36.006] I: STM32 counter to 1
[2025-07-30 13:47:36.045] I: BLE Device ID: 2784
[2025-07-30 13:47:36.045] I: Device is provisioned
[2025-07-30 13:47:36.045] I: network state 0
[2025-07-30 13:47:36.045] E: Sending UART cmd(3) st 0
[2025-07-30 13:47:36.045] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:47:36.045] I: Received response of command id 9a
[2025-07-30 13:47:36.045] I: Command 0x9A Received
[2025-07-30 13:47:36.045] I: Firmware Attribute event
[2025-07-30 13:47:36.076] I: Received response of command id 30
[2025-07-30 13:47:36.076] I: Received DC Eco Config REQ
[2025-07-30 13:47:36.076] I: DC Eco Config Resp
[2025-07-30 13:47:36.076] I: Received DC eco config req
[2025-07-30 13:47:36.076] I: 80 72 03 00 10 00 04 1a |.r......
[2025-07-30 13:47:36.076] I: 17 05                   |..      
[2025-07-30 13:47:36.076] E: Sending UART cmd(72) st 0
[2025-07-30 13:47:38.045] I: Syncing up on message 3
[2025-07-30 13:47:38.045] I: Sys init req
[2025-07-30 13:47:38.045] E: Sending UART cmd(3) st 0
[2025-07-30 13:47:38.045] I: System init Response
[2025-07-30 13:47:38.045] I: Received response of command id 3
[2025-07-30 13:47:38.045] I: Update sync timer
[2025-07-30 13:47:38.045] I: Received Sys Init Resp
[2025-07-30 13:47:38.045] I: battery mode 0
[2025-07-30 13:47:38.045] I: battery percentage 5a
[2025-07-30 13:47:38.045] I: battery type 1
[2025-07-30 13:47:38.045] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:47:38.525] I: Syncing up on message 5
[2025-07-30 13:47:38.525] I: Operating mode req
[2025-07-30 13:47:38.565] E: Sending UART cmd(5) st 0
[2025-07-30 13:47:38.565] I: Operating mode response
[2025-07-30 13:47:38.565] I: Received response of command id 5
[2025-07-30 13:47:38.565] I: Received Lock Op Mode Resp, mode 10, App state 31
[2025-07-30 13:47:38.565] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:47:38.565] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:47:38.565] I: Set Kwikset Lock App State 49
[2025-07-30 13:47:38.565] I: Matter is disabled
[2025-07-30 13:47:39.075] I: Syncing up on message 10
[2025-07-30 13:47:39.075] I: Lock state req
[2025-07-30 13:47:39.075] E: Sending UART cmd(10) st 0
[2025-07-30 13:47:39.075] I: Lock State Response
[2025-07-30 13:47:39.075] I: Received response of command id 10
[2025-07-30 13:47:39.075] I: Received Lock State Response, lock st: 11
[2025-07-30 13:47:39.075] I: Found matching nordic source of operation 0
[2025-07-30 13:47:39.075] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:47:39.075] I: Lock action completed
[2025-07-30 13:47:39.075] I: Updating LockState attribute
[2025-07-30 13:47:39.075] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:47:39.525] I: Syncing up on message 20
[2025-07-30 13:47:39.585] I: Lock setting req
[2025-07-30 13:47:39.585] E: Sending UART cmd(20) st 0
[2025-07-30 13:47:39.585] I: Lock General Setting Response
[2025-07-30 13:47:39.585] I: Received response of command id 20
[2025-07-30 13:47:39.585] I: Received Lock General Setting resp
[2025-07-30 13:47:39.585] I: Sound Volume Attribute Update, sound volume 1
[2025-07-30 13:47:39.585] SoundVolume attribute change
[2025-07-30 13:47:39.585] 
[2025-07-30 13:47:39.585] I: == Sound Volume Attribute Update Callback, sound volume 2 ==
[2025-07-30 13:47:39.585] I: No change in sound volume, return
[2025-07-30 13:47:39.585] ===== Attribute Received are: Cluster=101 Attribute=24 Value=2 =====
[2025-07-30 13:47:39.585] I: Matter Not Enabled do not set
[2025-07-30 13:47:40.075] I: Syncing up on message 51
[2025-07-30 13:47:40.075] I: Battery info req
[2025-07-30 13:47:40.075] E: Sending UART cmd(51) st 0
[2025-07-30 13:47:40.075] I: Received response of command id 51
[2025-07-30 13:47:40.075] I: Received Battery Info resp
[2025-07-30 13:47:40.075] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:47:40.075] Unhandled cluster ID: 0x  2f
[2025-07-30 13:47:40.075] 
[2025-07-30 13:47:40.075] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:47:40.075] Unhandled cluster ID: 0x  2f
[2025-07-30 13:47:40.075] 
[2025-07-30 13:47:40.075] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:47:40.527] I: All message synced.
[2025-07-30 13:48:04.055] I: STM system init timer expired, System Init Event not received from STM32
[2025-07-30 13:48:04.055] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-30 13:48:04.055] I: STM Pending =1, Redpine Pending = 1
[2025-07-30 13:48:04.055] I: STM Post OTA Pending
[2025-07-30 13:48:04.055] I: Redpine Post OTA Pending
[2025-07-30 13:48:04.055] E: Sending UART cmd(9e) st 0
[2025-07-30 13:48:04.055] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:48:04.055] I: 30187 [SWU]SMP BLE advertising started
[2025-07-30 13:48:04.055] I: 30191 [DL]DFU over SMP started
[2025-07-30 13:48:04.927] I: IMG Integrity Verified Successfully: 0
[2025-07-30 13:48:07.865] I: IMG Integrity Verified Successfully: 1
[2025-07-30 13:48:07.965] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:48:08.311] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:48:08.311] I: OTA Stage Change from (ff)->(32)
[2025-07-30 13:48:08.311] I: OTA device_id = 5 : DISCOVERY_REQ
[2025-07-30 13:48:08.385] I: SECURE_STM : IB_DEVICE_DISCOVERY_REQUEST (80) 
[2025-07-30 13:48:08.438] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:48:08.438] I: STM Current Firmware Version: 17 5 4 1b
[2025-07-30 13:48:08.438] I: OTA device_id = 5 : FW_UPDATE_START_REQ
[2025-07-30 13:48:08.438] I: SECURE_STM : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-30 13:48:14.815] I: STM OTA Progress = 10
[2025-07-30 13:48:21.186] I: STM OTA Progress = 20
[2025-07-30 13:48:27.535] I: STM OTA Progress = 30
[2025-07-30 13:48:33.995] I: STM OTA Progress = 40
[2025-07-30 13:48:40.345] I: STM OTA Progress = 50
[2025-07-30 13:48:46.695] I: STM OTA Progress = 60
[2025-07-30 13:48:53.055] I: STM OTA Progress = 70
[2025-07-30 13:48:59.405] I: STM OTA Progress = 80
[2025-07-30 13:49:05.755] I: STM OTA Progress = 90
[2025-07-30 13:49:12.105] I: STM OTA Progress = 100
[2025-07-30 13:49:12.795] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-30 13:49:12.815] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-30 13:49:30.465] I: Sending Sys Init Resp
[2025-07-30 13:49:30.465] I: Device is provisioned
[2025-07-30 13:49:30.505] I: network state 0
[2025-07-30 13:49:30.505] E: Sending UART cmd(3) st 0
[2025-07-30 13:49:30.505] I: Received DC App Config REQ
[2025-07-30 13:49:30.505] I: DC App Config Resp
[2025-07-30 13:49:30.505] I: Received DC config req
[2025-07-30 13:49:30.505] I: 80 70 03 00 10 10 08 00 |.p......
[2025-07-30 13:49:30.505] I: 50 1e                   |P.      
[2025-07-30 13:49:30.505] I: Matter enabled state 0
[2025-07-30 13:49:30.505] I: Get Matter Commission State
[2025-07-30 13:49:30.505] I: network state 0
[2025-07-30 13:49:30.505] I: network state 0
[2025-07-30 13:49:30.515] E: Sending UART cmd(70) st 0
[2025-07-30 13:49:30.545] I: Lock State Event
[2025-07-30 13:49:30.545] I: Received response of command id 10
[2025-07-30 13:49:30.575] I: Received Lock State event, lock st: 11
[2025-07-30 13:49:30.575] I: Found matching nordic source of operation 0
[2025-07-30 13:49:30.575] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:49:30.575] I: Lock action completed
[2025-07-30 13:49:30.575] I: Updating LockState attribute
[2025-07-30 13:49:30.575] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:49:30.615] I: Received DC Eco Config REQ
[2025-07-30 13:49:30.615] I: DC Eco Config Resp
[2025-07-30 13:49:30.636] I: Received DC eco config req
[2025-07-30 13:49:30.636] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:49:30.636] I: c4 1e                   |..      
[2025-07-30 13:49:30.636] E: Sending UART cmd(72) st 0
[2025-07-30 13:49:30.785] I: General Lock Setting event
[2025-07-30 13:49:30.818] I: Received response of command id 20
[2025-07-30 13:49:30.818] I: Received Lock General Setting event
[2025-07-30 13:49:30.818] I: Sound Volume Attribute Update, sound volume 1
[2025-07-30 13:49:30.818] I: Matter Not Enabled do not set
[2025-07-30 13:49:30.925] I: Firmware Attribute event
[2025-07-30 13:49:30.925] I: Received response of command id 30
[2025-07-30 13:49:30.985] I: Hardware Attribute event
[2025-07-30 13:49:30.985] I: Received response of command id 31
[2025-07-30 13:49:31.055] I: Operating mode event
[2025-07-30 13:49:31.055] I: Received response of command id 5
[2025-07-30 13:49:31.055] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:49:31.055] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:49:31.055] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:49:31.055] I: Set Kwikset Lock App State 49
[2025-07-30 13:49:31.055] I: Matter is disabled
[2025-07-30 13:49:31.185] I: Battery Info event
[2025-07-30 13:49:31.185] I: Received response of command id 51
[2025-07-30 13:49:31.185] I: Received Battery info event
[2025-07-30 13:49:31.185] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:49:31.185] Unhandled cluster ID: 0x  2f
[2025-07-30 13:49:31.185] 
[2025-07-30 13:49:31.185] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:49:31.185] Unhandled cluster ID: 0x  2f
[2025-07-30 13:49:31.185] 
[2025-07-30 13:49:31.185] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:49:31.285] I: System info event
[2025-07-30 13:49:31.285] I: Received System Info Event
[2025-07-30 13:49:31.285] W: Time invalid, set time
[2025-07-30 13:49:31.285] I: Get system time
[2025-07-30 13:49:31.285] I: System Real time in seconds 373663017
[2025-07-30 13:49:31.285] I: Time sync status flag 0
[2025-07-30 13:49:31.285] E: Time not sync, keep default value
[2025-07-30 13:49:31.395] I: System init event
[2025-07-30 13:49:31.395] I: Received response of command id 3
[2025-07-30 13:49:31.395] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:49:31.395] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:49:31.395] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:49:31.395] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-30 13:49:31.395] I: OTA device_id = 5 : FW_UPDATE_COMPLETE_REQ
[2025-07-30 13:49:31.395] I: SECURE_STM : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-30 13:49:31.395] I: OTA device_id = 5 : FW_UPDATE_REBOOT_REQ
[2025-07-30 13:49:31.395] I: SECURE_STM : REBOOT_COMMAND (80)
[2025-07-30 13:49:33.885] I: Sending Sys Init Resp
[2025-07-30 13:49:33.885] I: Device is provisioned
[2025-07-30 13:49:33.885] I: network state 0
[2025-07-30 13:49:33.885] E: Sending UART cmd(3) st 0
[2025-07-30 13:49:33.885] I: Received DC App Config REQ
[2025-07-30 13:49:33.885] I: DC App Config Resp
[2025-07-30 13:49:33.885] I: Received DC config req
[2025-07-30 13:49:33.885] I: 80 70 03 00 10 10 04 1a |.p......
[2025-07-30 13:49:33.885] I: 00 62                   |.b      
[2025-07-30 13:49:33.885] I: Matter enabled state 0
[2025-07-30 13:49:33.885] I: Get Matter Commission State
[2025-07-30 13:49:33.885] I: network state 0
[2025-07-30 13:49:33.890] I: network state 0
[2025-07-30 13:49:33.890] E: Sending UART cmd(70) st 0
[2025-07-30 13:49:33.945] I: Lock State Event
[2025-07-30 13:49:33.945] I: Received response of command id 10
[2025-07-30 13:49:33.945] I: Received Lock State event, lock st: 11
[2025-07-30 13:49:33.945] I: Found matching nordic source of operation 0
[2025-07-30 13:49:33.945] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:49:33.945] I: Lock action completed
[2025-07-30 13:49:33.945] I: Updating LockState attribute
[2025-07-30 13:49:33.945] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:49:33.976] I: Received DC Eco Config REQ
[2025-07-30 13:49:33.976] I: DC Eco Config Resp
[2025-07-30 13:49:34.006] I: Received DC eco config req
[2025-07-30 13:49:34.006] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:49:34.006] I: c4 62                   |.b      
[2025-07-30 13:49:34.006] E: Sending UART cmd(72) st 0
[2025-07-30 13:49:34.185] I: General Lock Setting event
[2025-07-30 13:49:34.195] I: Received response of command id 20
[2025-07-30 13:49:34.195] I: Received Lock General Setting event
[2025-07-30 13:49:34.195] I: Sound Volume Attribute Update, sound volume 1
[2025-07-30 13:49:34.195] I: Matter Not Enabled do not set
[2025-07-30 13:49:34.296] I: Firmware Attribute event
[2025-07-30 13:49:34.296] I: Received response of command id 30
[2025-07-30 13:49:34.355] I: Hardware Attribute event
[2025-07-30 13:49:34.355] I: Received response of command id 31
[2025-07-30 13:49:34.432] I: Operating mode event
[2025-07-30 13:49:34.432] I: Received response of command id 5
[2025-07-30 13:49:34.432] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:49:34.432] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:49:34.432] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:49:34.432] I: Set Kwikset Lock App State 49
[2025-07-30 13:49:34.432] I: Matter is disabled
[2025-07-30 13:49:34.555] I: Battery Info event
[2025-07-30 13:49:34.555] I: Received response of command id 51
[2025-07-30 13:49:34.555] I: Received Battery info event
[2025-07-30 13:49:34.555] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:49:34.555] Unhandled cluster ID: 0x  2f
[2025-07-30 13:49:34.555] 
[2025-07-30 13:49:34.555] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:49:34.555] Unhandled cluster ID: 0x  2f
[2025-07-30 13:49:34.555] 
[2025-07-30 13:49:34.555] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:49:34.635] I: System info event
[2025-07-30 13:49:34.635] I: Received System Info Event
[2025-07-30 13:49:34.655] W: Time invalid, set time
[2025-07-30 13:49:34.655] I: Get system time
[2025-07-30 13:49:34.655] I: System Real time in seconds 373663017
[2025-07-30 13:49:34.655] I: Time sync status flag 0
[2025-07-30 13:49:34.655] E: Time not sync, keep default value
[2025-07-30 13:49:34.745] I: System init event
[2025-07-30 13:49:34.745] I: Received response of command id 3
[2025-07-30 13:49:34.745] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:49:34.745] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:49:34.745] I: OTA device_id = 5 : FW_VERSION_REQ
[2025-07-30 13:49:34.745] I: STM Current Firmware Version: 17 5 4 1a
[2025-07-30 13:49:34.745] I: STM New OTA Firmware Version = 17 5 4 1a
[2025-07-30 13:49:34.745] I: STM Secure OTA Successful
[2025-07-30 13:49:34.855] I: Cleared STM OTA Meta Data
[2025-07-30 13:49:34.855] I: OTA Stage Change from (32)->(33)
[2025-07-30 13:49:34.855] I: Redpine OTA started
[2025-07-30 13:49:34.855] I: OTA Stage Change from (33)->(34)
[2025-07-30 13:49:34.855] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-30 13:49:41.836] I: STM Reset Count 0
[2025-07-30 13:49:41.875] I: OTA device_id = 4 : DISCOVERY_REQ
[2025-07-30 13:49:41.875] I: STM_QSPI : IB_DEVICE_DISCOVERY_REQUEST (80)
[2025-07-30 13:49:41.875] I: OTA device_id = 4 : FW_VERSION_REQ
[2025-07-30 13:49:41.875] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-30 13:49:41.875] I: Redpine Current Firmware Version: 2.c.0.3
[2025-07-30 13:49:41.896] I: OTA device_id = 4 : FW_UPDATE_START_REQ
[2025-07-30 13:49:41.995] I: STM_QSPI : IB_FW_UPDATE_START_REQUEST (80)
[2025-07-30 13:50:04.716] I: STM Boot Up Properly, Stopped STM Reboot Timer
[2025-07-30 13:50:21.436] I: Redpine Image Stored into STM QSPI, Progress = 10
[2025-07-30 13:50:54.935] I: Redpine Image Stored into STM QSPI, Progress = 20
[2025-07-30 13:51:15.576] I: Redpine Image Stored into STM QSPI, Progress = 30
[2025-07-30 13:51:36.255] I: Redpine Image Stored into STM QSPI, Progress = 40
[2025-07-30 13:51:56.886] I: Redpine Image Stored into STM QSPI, Progress = 50
[2025-07-30 13:52:17.596] I: Redpine Image Stored into STM QSPI, Progress = 60
[2025-07-30 13:52:38.395] I: Redpine Image Stored into STM QSPI, Progress = 70
[2025-07-30 13:52:59.106] I: Redpine Image Stored into STM QSPI, Progress = 80
[2025-07-30 13:53:19.866] I: Redpine Image Stored into STM QSPI, Progress = 90
[2025-07-30 13:53:40.658] I: Redpine Image Stored into STM QSPI, Progress = 100
[2025-07-30 13:53:42.786] I: OTA device_id = 4 : FW_UPDATE_COMPLETE_REQ
[2025-07-30 13:53:43.216] I: STM_QSPI : IB_FW_UPDATE_COMPLETE_REQUEST (80) 
[2025-07-30 13:53:43.346] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (0)
[2025-07-30 13:53:48.145] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (10)
[2025-07-30 13:53:53.006] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (20)
[2025-07-30 13:53:57.965] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (30)
[2025-07-30 13:54:02.926] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (40)
[2025-07-30 13:54:07.899] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (50)
[2025-07-30 13:54:12.836] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (60)
[2025-07-30 13:54:17.786] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (70)
[2025-07-30 13:54:22.736] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (80)
[2025-07-30 13:54:27.629] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (90)
[2025-07-30 13:54:32.460] I: STM_QSPI : STM QSPI to Redpine SPI Image Transfer Ongoing (100)
[2025-07-30 13:55:01.966] I: STM_QSPI : IB_FW_UPDATE_REBOOT_REQUEST (80) 
[2025-07-30 13:55:02.096] I: Clear Redpine OTA Meta Data
[2025-07-30 13:55:02.096] I: Redpine OTA Successful
[2025-07-30 13:55:02.096] I: Check Pending Firmware upgrade for STM, Redpine & PN76
[2025-07-30 13:55:02.096] I: STM Pending =2, Redpine Pending = 2
[2025-07-30 13:55:02.096] I: PN76 IMG 1 Post OTA Pending
[2025-07-30 13:55:02.096] E: Sending UART cmd(9e) st 0
[2025-07-30 13:55:02.096] I: 448229 [SWU]DFU over SMP was already started
[2025-07-30 13:55:02.176] I: IMG Integrity Verified Successfully: 2
[2025-07-30 13:55:02.536] I: IMG Integrity Verified Successfully: 3
[2025-07-30 13:55:02.536] I: OTA Stage Change from (34)->(3a)
[2025-07-30 13:55:02.536] I: PN76_IMG1_DEVICE_DFU_MULTI_IMG_ID
[2025-07-30 13:55:02.536] I: PN76_IMG Update from OTA Task Event
[2025-07-30 13:55:02.536] I: 
[2025-07-30 13:55:02.536] 
[2025-07-30 13:55:02.536] --------------- UPDATING PN7642 NXP FIRMWARE --------------------
[2025-07-30 13:55:02.546] 
[2025-07-30 13:55:02.546] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-30 13:55:02.576] I: pNXPFWInfo->img_offset = 0x351497
[2025-07-30 13:55:02.576] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-30 13:55:02.576] I: Reading version of firmware in QSPI flash: MetaData 0x2f60217
[2025-07-30 13:55:02.576] I: PN76 NXP FW VERSION VALIDATION SKIPPED, OTAU TEST BUNDLE
[2025-07-30 13:55:02.696] I: ----> PN7642 OTA Progress = 10 %
[2025-07-30 13:55:02.756] I: ----> PN7642 OTA Progress = 20 %
[2025-07-30 13:55:02.816] I: ----> PN7642 OTA Progress = 30 %
[2025-07-30 13:55:02.886] I: ----> PN7642 OTA Progress = 40 %
[2025-07-30 13:55:02.946] I: ----> PN7642 OTA Progress = 50 %
[2025-07-30 13:55:03.016] I: ----> PN7642 OTA Progress = 60 %
[2025-07-30 13:55:03.078] I: ----> PN7642 OTA Progress = 70 %
[2025-07-30 13:55:03.136] I: ----> PN7642 OTA Progress = 80 %
[2025-07-30 13:55:03.318] I: ----> PN7642 OTA Progress = 100 %
[2025-07-30 13:55:03.318] I: Whole pn7642 FW Image downloaded ....
[2025-07-30 13:55:03.318] I: 
[2025-07-30 13:55:03.318] 
[2025-07-30 13:55:03.318] I: 
[2025-07-30 13:55:03.318] PN7642 Firmware of type 0 Successfully Updated !!!
[2025-07-30 13:55:03.318] I: PN76 Image Update Successful for Device ID(7)
[2025-07-30 13:55:03.444] I: Cleared PN76 Img1 OTA Meta Data
[2025-07-30 13:55:03.444] I: OTA Stage Change from (3a)->(3a)
[2025-07-30 13:55:03.444] I: PN76_IMG2_DEVICE_DFU_MULTI_IMG_ID
[2025-07-30 13:55:03.444] I: PN76_IMG Update from OTA Task Event
[2025-07-30 13:55:03.444] I: 
[2025-07-30 13:55:03.444] 
[2025-07-30 13:55:03.444] --------------- UPDATING PN7642 APPLICATION FIRMWARE -------------
[2025-07-30 13:55:03.444] 
[2025-07-30 13:55:03.444] I: pn7642_UpdateSecureFirmWareUpdate()::Rebooting pn7642 in HDLL Secure FW Download Mode
[2025-07-30 13:55:03.476] I: pCustAppFWInfo->img_offset = 0x35c289
[2025-07-30 13:55:03.476] I: Getting the current FW versions in pn7642 DL_GET_VERSION
[2025-07-30 13:55:03.476] I: Reading version of firmware in QSPI flash: MetaData 0x2f60217
[2025-07-30 13:55:03.476] I: PN76 APP FW VERSION VALIDATION SKIPPED, OTAU TEST BUNDLE
[2025-07-30 13:55:03.786] I: ----> PN7642 OTA Progress = 10 %
[2025-07-30 13:55:04.056] I: ----> PN7642 OTA Progress = 20 %
[2025-07-30 13:55:04.306] I: ----> PN7642 OTA Progress = 30 %
[2025-07-30 13:55:04.586] I: ----> PN7642 OTA Progress = 40 %
[2025-07-30 13:55:04.836] I: ----> PN7642 OTA Progress = 50 %
[2025-07-30 13:55:05.106] I: ----> PN7642 OTA Progress = 60 %
[2025-07-30 13:55:05.366] I: ----> PN7642 OTA Progress = 70 %
[2025-07-30 13:55:05.636] I: ----> PN7642 OTA Progress = 80 %
[2025-07-30 13:55:05.896] I: ----> PN7642 OTA Progress = 90 %
[2025-07-30 13:55:06.146] I: ----> PN7642 OTA Progress = 100 %
[2025-07-30 13:55:06.186] I: Whole pn7642 FW Image downloaded ....
[2025-07-30 13:55:06.186] I: 
[2025-07-30 13:55:06.186] 
[2025-07-30 13:55:06.186] I: 
[2025-07-30 13:55:06.186] PN7642 Firmware of type 1 Successfully Updated !!!
[2025-07-30 13:55:06.186] I: PN76 Image Update Successful for Device ID(8)
[2025-07-30 13:55:06.266] I: Cleared PN76 Img2 OTA Meta Data
[2025-07-30 13:55:06.797] I: NFC Boot Event Wake Up Reason: 0x00000001
[2025-07-30 13:55:06.836] I: NFC Boot Event PN7642 FW VERSION 17.01.00.02
[2025-07-30 13:55:06.836] I: NFC Boot Event PN7642 Secure FW Version 02.f6
[2025-07-30 13:55:06.836] I: 
[2025-07-30 13:55:06.836] Boot Event Received
[2025-07-30 13:55:06.836] 
[2025-07-30 13:55:06.836] I: Booted NFC IC in Normal Operation Mode.
[2025-07-30 13:55:06.836] 
[2025-07-30 13:55:06.836] I: OTA Stage Change from (3a)->(3b)
[2025-07-30 13:55:06.836] I: post_stm_reset_event : init_pending_ota_update
[2025-07-30 13:55:06.836] I: All pending FW Updates are completed.
[2025-07-30 13:55:06.836] I: STM32 Reset Count = 0
[2025-07-30 13:55:06.846] I: REBOOT_STM: Send STM32 Reboot Command, Count (0)
[2025-07-30 13:55:09.116] I: Sending Sys Init Resp
[2025-07-30 13:55:09.116] I: Device is provisioned
[2025-07-30 13:55:09.116] I: network state 0
[2025-07-30 13:55:09.156] E: Sending UART cmd(3) st 0
[2025-07-30 13:55:09.156] I: Received DC App Config REQ
[2025-07-30 13:55:09.156] I: DC App Config Resp
[2025-07-30 13:55:09.156] I: Received DC config req
[2025-07-30 13:55:09.156] I: 80 70 03 00 10 10 19 00 |.p......
[2025-07-30 13:55:09.156] I: 50 62                   |Pb      
[2025-07-30 13:55:09.156] I: Matter enabled state 0
[2025-07-30 13:55:09.156] I: Get Matter Commission State
[2025-07-30 13:55:09.156] I: network state 0
[2025-07-30 13:55:09.156] I: network state 0
[2025-07-30 13:55:09.156] E: Sending UART cmd(70) st 0
[2025-07-30 13:55:09.186] I: Lock State Event
[2025-07-30 13:55:09.186] I: Received response of command id 10
[2025-07-30 13:55:09.226] I: Received Lock State event, lock st: 11
[2025-07-30 13:55:09.226] I: Found matching nordic source of operation 0
[2025-07-30 13:55:09.226] I: ******** TESTING Real Source 0x0000 ********
[2025-07-30 13:55:09.226] I: Lock action completed
[2025-07-30 13:55:09.226] I: Updating LockState attribute
[2025-07-30 13:55:09.226] ===== Attribute Received are: Cluster=101 Attribute=0 Value=1 =====
[2025-07-30 13:55:09.256] I: Received DC Eco Config REQ
[2025-07-30 13:55:09.286] I: DC Eco Config Resp
[2025-07-30 13:55:09.286] I: Received DC eco config req
[2025-07-30 13:55:09.286] I: 80 72 03 00 10 00 f5 e0 |.r......
[2025-07-30 13:55:09.286] I: c4 62                   |.b      
[2025-07-30 13:55:09.286] E: Sending UART cmd(72) st 0
[2025-07-30 13:55:09.466] I: General Lock Setting event
[2025-07-30 13:55:09.466] I: Received response of command id 20
[2025-07-30 13:55:09.466] I: Received Lock General Setting event
[2025-07-30 13:55:09.466] I: Sound Volume Attribute Update, sound volume 1
[2025-07-30 13:55:09.466] I: Matter Not Enabled do not set
[2025-07-30 13:55:09.566] I: Firmware Attribute event
[2025-07-30 13:55:09.566] I: Received response of command id 30
[2025-07-30 13:55:09.626] I: Hardware Attribute event
[2025-07-30 13:55:09.626] I: Received response of command id 31
[2025-07-30 13:55:09.706] I: Operating mode event
[2025-07-30 13:55:09.706] I: Received response of command id 5
[2025-07-30 13:55:09.706] I: Received Lock Op Mode Event, mode 10, App state 31
[2025-07-30 13:55:09.706] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:55:09.706] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:55:09.706] I: Set Kwikset Lock App State 49
[2025-07-30 13:55:09.706] I: Matter is disabled
[2025-07-30 13:55:09.826] I: Battery Info event
[2025-07-30 13:55:09.826] I: Received response of command id 51
[2025-07-30 13:55:09.826] I: Received Battery info event
[2025-07-30 13:55:09.826] I: Matter App Battery info update: Batt level 5a, Batt st 0, Batt type 1
[2025-07-30 13:55:09.826] Unhandled cluster ID: 0x  2f
[2025-07-30 13:55:09.826] 
[2025-07-30 13:55:09.826] ===== Attribute Received are: Cluster=2f Attribute=e Value=0 =====
[2025-07-30 13:55:09.826] Unhandled cluster ID: 0x  2f
[2025-07-30 13:55:09.826] 
[2025-07-30 13:55:09.826] ===== Attribute Received are: Cluster=2f Attribute=c Value=180 =====
[2025-07-30 13:55:09.906] I: System info event
[2025-07-30 13:55:09.906] I: Received System Info Event
[2025-07-30 13:55:09.906] W: Time invalid, set time
[2025-07-30 13:55:09.936] I: Get system time
[2025-07-30 13:55:09.936] I: System Real time in seconds 373663017
[2025-07-30 13:55:09.936] I: Time sync status flag 0
[2025-07-30 13:55:09.936] E: Time not sync, keep default value
[2025-07-30 13:55:10.004] I: System init event
[2025-07-30 13:55:10.004] I: Received response of command id 3
[2025-07-30 13:55:10.004] I: STM32 Bootup, Received STM32 System Initialization Event
[2025-07-30 13:55:10.004] I: Lock Current Mode : 10, Lock Current State = 31
[2025-07-30 13:55:10.004] I: STM Image confirm timer was stopped
[2025-07-30 13:55:16.886] I: STM_QSPI : IB_FW_VERSION_REQUEST
[2025-07-30 13:55:16.886] I: stop_ota_finalization_timer
[2025-07-30 13:55:16.886] I: After OTAU, Redpine Firmware Version: 2.c.0.3
[2025-07-30 13:55:16.886] I: Redpine New OTA Firmware Version = 2 c 0 3
[2025-07-30 13:55:16.886] I: After OTAU, Secure STM Firmware Version: 17 5 4 1a
[2025-07-30 13:55:16.886] I: Send Op Mode command to release Redpine BLE and WiFI
[2025-07-30 13:55:16.886] I: Operating Mode Command: Mode:10, State:f0
[2025-07-30 13:55:16.886] E: Sending UART cmd(5) st 0
[2025-07-30 13:55:17.026] I: Operating mode event
[2025-07-30 13:55:17.026] I: Received response of command id 5
[2025-07-30 13:55:17.026] I: Received Lock Op Mode Event, mode 10, App state 10
[2025-07-30 13:55:17.026] I: Lock Current Mode : 10, Lock Current State = 10
[2025-07-30 13:55:17.026] I: stop_ota_finalization_timer
[2025-07-30 13:55:17.026] I: STM32 HALO APP STATE IS ACTIVATED NORMAL
[2025-07-30 13:55:17.026] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:55:17.026] I: Set Kwikset Lock App State 16
[2025-07-30 13:55:17.026] I: Matter enabled state 0
[2025-07-30 13:55:17.026] I: Matter is disabled
[2025-07-30 13:55:17.026] I: OTA_HOUSEKEEPING
[2025-07-30 13:55:17.026] I: OTA Stage Change from (3b)->(80)
[2025-07-30 13:55:17.031] I: Start Erasing OTA bundle from nRF External Flash
[2025-07-30 13:55:23.016] I: System info event
[2025-07-30 13:55:23.016] I: Received System Info Event
[2025-07-30 13:55:23.016] I: Time is set in STM
[2025-07-30 13:56:18.212] I: Bundle Image Erased from nRF External Flash: 0
[2025-07-30 13:56:18.212] I: OTAU Completed Successfully
[2025-07-30 13:56:18.316] I: Cleared OTA Meta Data
[2025-07-30 13:56:18.316] I: OTA Stage Change from (80)->(90)
[2025-07-30 13:56:20.318] I: All message synced.
[2025-07-30 13:56:33.306] I: STOP BLE Advertisment
[2025-07-30 13:56:33.326] I: 539459 [DL]DFU over SMP stopped
[2025-07-30 13:56:33.326] E: Sending UART cmd(9e) st 0
[2025-07-30 13:59:44.546] I: Updated ota meta data
[2025-07-30 13:59:44.546] I: Operating Mode Command: Mode:10, State:34
[2025-07-30 13:59:44.566] E: Sending UART cmd(5) st 0
[2025-07-30 13:59:44.626] I: Operating mode event
[2025-07-30 13:59:44.626] I: Received response of command id 5
[2025-07-30 13:59:44.626] I: Received Lock Op Mode Event, mode 10, App state 34
[2025-07-30 13:59:44.626] I: Lock Current Mode : 10, Lock Current State = 34
[2025-07-30 13:59:44.626] I: STM32 HALO APP STATE IS BLE OTAU TRANSFER
[2025-07-30 13:59:44.626] E: Sending UART cmd(9e) st 0
[2025-07-30 13:59:44.626] I: BLE Name set: HU:2784 errCode: 0
[2025-07-30 13:59:44.626] I: 730754 [SWU]SMP BLE advertising started
[2025-07-30 13:59:44.626] I: 730758 [DL]DFU over SMP started
[2025-07-30 13:59:44.626] I: OTA Stage Change from (90)->(11)
[2025-07-30 13:59:44.626] I: Set Kwikset Lock App Mode 16
[2025-07-30 13:59:44.626] I: Set Kwikset Lock App State 52
[2025-07-30 13:59:44.626] I: Matter is disabled
[2025-07-30 13:59:59.387] I: 745523 [DL]Current number of connections: 1/1
[2025-07-30 13:59:59.387] I: BLE Connected
[2025-07-30 13:59:59.610] I: 745767 [DL]Current number of connections: 0/1
[2025-07-30 13:59:59.626] I: BLE Disconnected: 13
[2025-07-30 14:00:03.987] I: 750125 [DL]Current number of connections: 1/1
[2025-07-30 14:00:03.987] I: BLE Connected
[2025-07-30 14:00:04.197] I: 750347 [DL]DFU Image upload started
[2025-07-30 14:00:05.056] I: Connection parameters updated.
[2025-07-30 14:00:05.056]  interval: 9, latency: 0, timeout: 42
[2025-07-30 14:00:05.056] E: No available ACL buffers!
[2025-07-30 14:00:05.056] E: Unexpected first L2CAP frame
[2025-07-30 14:00:23.777] I: OTA Stage Change from (11)->(12)
[2025-07-30 14:00:23.796] I: 769935 [DL]Image 0 download completed successfully
[2025-07-30 14:04:39.779] I: OTA Stage Change from (12)->(11)
[2025-07-30 14:04:39.779] I: Lock Already in OTAU Transport/Update mode
[2025-07-30 14:04:39.779] E: Sending UART cmd(9e) st 0
[2025-07-30 14:04:39.779] I: 1025924 [SWU]DFU over SMP was already started
[2025-07-30 14:05:41.536] I: OTA Stage Change from (11)->(11)
[2025-07-30 14:05:41.536] I: Lock Already in OTAU Transport/Update mode
[2025-07-30 14:05:41.536] E: Sending UART cmd(9e) st 0
[2025-07-30 14:05:41.536] I: 1087682 [SWU]DFU over SMP was already started
[2025-07-30 14:06:43.227] I: OTA Stage Change from (11)->(11)
[2025-07-30 14:06:43.227] I: Lock Already in OTAU Transport/Update mode
[2025-07-30 14:06:43.227] E: Sending UART cmd(9e) st 0
[2025-07-30 14:06:43.227] I: 1149369 [SWU]DFU over SMP was already started
[2025-07-30 14:07:44.917] I: OTA Stage Change from (11)->(11)
[2025-07-30 14:07:44.917] I: Lock Already in OTAU Transport/Update mode
[2025-07-30 14:07:44.917] E: Sending UART cmd(9e) st 0
[2025-07-30 14:07:44.917] I: 1211061 [SWU]DFU over SMP was already started
[2025-07-30 14:08:46.527] I: OTA Stage Change from (11)->(11)
[2025-07-30 14:08:46.527] I: Lock Already in OTAU Transport/Update mode
[2025-07-30 14:08:46.527] E: Sending UART cmd(9e) st 0
[2025-07-30 14:08:46.527] I: 1272674 [SWU]DFU over SMP was already started
[2025-07-30 14:09:47.927] I: OTA Stage Change from (11)->(11)
[2025-07-30 14:09:47.957] I: Lock Already in OTAU Transport/Update mode
[2025-07-30 14:09:47.957] E: Sending UART cmd(9e) st 0
[2025-07-30 14:09:47.957] I: 1334101 [SWU]DFU over SMP was already started
[2025-07-30 14:10:49.447] I: OTA Stage Change from (11)->(11)
[2025-07-30 14:10:49.447] I: Lock Already in OTAU Transport/Update mode
[2025-07-30 14:10:49.447] E: Sending UART cmd(9e) st 0
[2025-07-30 14:10:49.447] I: 1395600 [SWU]DFU over SMP was already started
