• State Verified Answer
  • Replies 22 replies
  • Answers 1 answer
  • Subscribers 90 subscribers
  • Views 5265 views
  • Users 0 members are here
Attachments (0)
Nordic Case Info
  • Case ID: 257540
Options
This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

first secure connection after DFU fails. SDK17 S113

Allen

Hello.

After performing a secure DFU download, the first attempt to open a secure NUS connection fails with an NRF_ERROR_INVALID_PARAM error. After resetting the device, all subsequent connections are successful. I have traced this to the call to BLE_GATS_EVT_WRITE handling in gatt_cache_manager.c. gscm_local_db_cache_update() fails in pdb_write_buf_store() because the peer_id is not tagged as allocated?

Below is a log. The first part is the connection attempt right after the DFU operation. The second part is the connection after reset which is successful.

0> REBOOT (52)
0> Bluetooth Name NM04-000078
0> Board Type D045
0> Model Type ETM
0> FPGA Ver Model 4 Version 4
0> Firmware Ver 2.1.399
0> Firmware Type FIELD
0> SoftDevice Ver 7.2.0
0> BootLoader Ver 7 (INSTALLED)
0> Mfg Data Ver 4
0> Sys Config Ver 12
0> API Versions OK
0> Bluetooth Enabled
0> UART Enabled
0> 0:00:00.000 BLE terminated
0> BLE: Local BDADDR xE49C814C1039
0> 0:00:01.439 PWR: Entering normal power
0> 0:00:01.442 STIM STATE: x02
0> 0:00:01.442 ADV: Sys=FFFFFFFF Dev=0 VBat=3956 Amp={63 63 63 63} Sched=00/FF Err=00 Col=02 Prg=F Ins=0 Post=0 Stim=1 LowP=0 LowB=0 Sess=1 BLE=1 Buzz=0
0> 0:00:01.566 STIM EVENT[01]: x0E
0> 0:00:01.567 STIM STATE: x03
0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED
0> 0:00:02.103 Detected ID x00000244 (Patient x00000244, Reference xFFFFFFFF)
0> 0:00:02.103 update_implant_trim_data
0> 0:00:02.104 Trim not found
0> 0:00:02.106 Connected to patient device x00000244
0> 0:00:02.106 STIM EVENT[02]: x0F
0> 0:00:02.107 STIM STATE: x0E
0> 0:00:02.112 STIM EVENT[03]: x2B
0> 0:00:02.112 STIM STATE: x06
0> 0:00:02.140 ADV: Sys=FFFFFFFF Dev=0 VBat=3956 Amp={63 63 63 63} Sched=00/FF Err=00 Col=02 Prg=F Ins=1 Post=0 Stim=2 LowP=0 LowB=0 Sess=1 BLE=1 Buzz=0
0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED
0> SD: 10 BLE_GAP_EVT_CONNECTED
0> BLE: Remote x67F4C478945C
0> NCE: bd_addr1 xE49C814C1039
0> NCE: bd_addr2 x67F4C478945C
0> PK: device passkey F3E47DDFF77F8B74
0> BLE: GAP connected. Unauthenticated timer restarted
0> PM: PM_EVT_BONDED_PEER_CONNECTED
0> PM: PM_EVT_CONN_SEC_PARAMS_REQ
0> PM: PM_EVT_BONDED_PEER_CONNECTED evt_id=0 get_id=0
0> PM: Connected to a previously bonded device.
0> PM: PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED
0> 0:00:13.263 BLE terminated
0> PMM: CONNECTED, stored 0 peers
0> PM: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
0> 0:00:13.296 ADV: Sys=FFFFFFFF Dev=0 VBat=3956 Amp={63 63 63 63} Sched=00/FF Err=00 Col=02 Prg=F Ins=1 Post=0 Stim=2 LowP=0 LowB=0 Sess=1 BLE=0 Buzz=0
0> SD: 3A SD_BLE_GATTC_EXCHANGE_MTU_REQUEST
0> SD: 24 BLE_GAP_EVT_DATA_LENGTH_UPDATE
0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED
0> SD: 12 BLE_GAP_EVT_CONN_PARAM_UPDATE
0> SD: 14 BLE_GAP_EVT_SEC_INFO_REQUEST
0> PM: PM_EVT_CONN_SEC_START
0> SD: 1A BLE_GAP_EVT_CONN_SEC_UPDATE
0> PM: PM_EVT_CONN_SEC_SUCCEEDED
0> PM: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
0> PM: Connection secured. Procedure: 0 Role: 1 conn_handle: 0
0> PMM: CONNECTED, stored 0 peers
0> SD: 50 BLE_GATTS_EVT_WRITE
0> B gcm_ble_evt_handler EVT_WRITE
0> pdb_write_buf_get id=0 err=0
0> sd_ble_gatts_sys_attr_get id=0 err=0
0> pdb_write_buf_store id=0 err=7
0> local_db_update_in_evt err=7
0> PM: PM_EVT_ERROR_UNEXPECTED
0> ERROR 7 [NRF_ERROR_INVALID_PARAM] at ..\components\ble\peer_manager\peer_manager_handler.c:294
0> PC at: 0x000361d5
0> ERROR 7 [NRF_ERROR_INVALID_PARAM] at ble_driver.c:1805
0> PC at: 0x00028345
0> E gcm_ble_evt_handler EVT_WRITE
0> on_write:453 resp 0
0> on_write:561 resp 0
0> SD: 12 BLE_GAP_EVT_CONN_PARAM_UPDATE
0> 0:00:14.394 ADV: Sys=FFFFFFFF Dev=0 VBat=3921 Amp={63 63 63 63} Sched=00/FF Err=00 Col=02 Prg=F Ins=1 Post=0 Stim=2 LowP=0 LowB=0 Sess=1 BLE=0 Buzz=0
0>
0> REBOOT (53)
0>
0> ERROR 7 [NRF_ERROR_INVALID_PARAM] at ble_driver.c:1805
0> PC at: 0x00028345
0> Bluetooth Name NM04-000078
0> Board Type D045
0> Model Type ETM
0> FPGA Ver Model 4 Version 4
0> Firmware Ver 2.1.399
0> Firmware Type FIELD
0> SoftDevice Ver 7.2.0
0> BootLoader Ver 7 (INSTALLED)
0> Mfg Data Ver 4
0> Sys Config Ver 12
0> API Versions OK
0> Bluetooth Enabled
0> UART Enabled
0> Stimulation Enabled
0> Acceleration Disabled (0)
0> Force Error Disabled (0)
0> Electrode Map Field 8 Contact
0> Reboot Reason Restart
0>
0> 0:00:00.000 BLE terminated
0> peer 0 rank 0 stamp 0:00:37.499
0> BLE: Local BDADDR xE49C814C1039
0> 0:00:01.436 PWR: Entering normal power
0> 0:00:01.439 STIM STATE: x02
0> 0:00:01.439 ADV: Sys=FFFFFFFF Dev=0 VBat=3961 Amp={63 63 63 63} Sched=00/FF Err=00 Col=02 Prg=F Ins=0 Post=0 Stim=1 LowP=0 LowB=0 Sess=1 BLE=1 Buzz=0
0> 0:00:01.564 STIM EVENT[01]: x0E
0> 0:00:01.564 STIM STATE: x03
0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED
0> 0:00:02.100 Detected ID x00000244 (Patient x00000244, Reference xFFFFFFFF)
0> 0:00:02.100 update_implant_trim_data
0> 0:00:02.101 Trim not found
0> 0:00:02.103 Connected to patient device x00000244
0> 0:00:02.103 STIM EVENT[02]: x0F
0> 0:00:02.104 STIM STATE: x0E
0> 0:00:02.109 STIM EVENT[03]: x2B
0> 0:00:02.109 STIM STATE: x06
0> 0:00:02.137 ADV: Sys=FFFFFFFF Dev=0 VBat=3961 Amp={63 63 63 63} Sched=00/FF Err=00 Col=02 Prg=F Ins=1 Post=0 Stim=2 LowP=0 LowB=0 Sess=1 BLE=1 Buzz=0
0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED
0> SD: 10 BLE_GAP_EVT_CONNECTED
0> BLE: Remote x67F4C478945C
0> NCE: bd_addr1 xE49C814C1039
0> NCE: bd_addr2 x67F4C478945C
0> PK: device passkey C6DB518BE8DD4913
0> BLE: GAP connected. Unauthenticated timer restarted
0> PM: PM_EVT_BONDED_PEER_CONNECTED
0> PM: PM_EVT_CONN_SEC_PARAMS_REQ
0> PM: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
0> PM: PM_EVT_BONDED_PEER_CONNECTED evt_id=0 get_id=0
0> PM: Connected to a previously bonded device.
0> PM: PM_EVT_LOCAL_DB_CACHE_APPLY_FAILED
0> 0:00:03.193 BLE terminated
0> PMM: CONNECTED, stored 1 peers
0> 0:00:03.233 ADV: Sys=FFFFFFFF Dev=0 VBat=3961 Amp={63 63 63 63} Sched=00/FF Err=00 Col=02 Prg=F Ins=1 Post=0 Stim=2 LowP=0 LowB=0 Sess=1 BLE=0 Buzz=0
0> SD: 3A SD_BLE_GATTC_EXCHANGE_MTU_REQUEST
0> SD: 50 BLE_GATTS_EVT_WRITE
0> B gcm_ble_evt_handler EVT_WRITE
0> pdb_write_buf_get id=0 err=0
0> sd_ble_gatts_sys_attr_get id=0 err=0
0> pdb_write_buf_store id=0 err=0
0> local_db_update_in_evt err=0
0> E gcm_ble_evt_handler EVT_WRITE
0> on_write:453 resp 0
0> on_write:561 resp 0
0> PM: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
0> SD: 24 BLE_GAP_EVT_DATA_LENGTH_UPDATE
0> SD: 14 BLE_GAP_EVT_SEC_INFO_REQUEST
0> PM: PM_EVT_CONN_SEC_START
0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED
0> SD: 1A BLE_GAP_EVT_CONN_SEC_UPDATE
0> PM: PM_EVT_CONN_SEC_SUCCEEDED
0> PM: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
0> PM: Connection secured. Procedure: 0 Role: 1 conn_handle: 0
0> PMM: CONNECTED, stored 1 peers
0> SD: 50 BLE_GATTS_EVT_WRITE
0> B gcm_ble_evt_handler EVT_WRITE
0> pdb_write_buf_get id=0 err=0
0> sd_ble_gatts_sys_attr_get id=0 err=0
0> pdb_write_buf_store id=0 err=0
0> local_db_update_in_evt err=0
0> E gcm_ble_evt_handler EVT_WRITE
0> on_write:453 resp 0
0> on_write:561 resp 0
0> PM: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
0> SD: 35 SD_BLE_GATTC_CHAR_VALUE_BY_UUID_READ
0> SD: 55 BLE_GATTS_EVT_EXCHANGE_MTU_REQUEST
0> SD: 36 SD_BLE_GATTC_READ
0> PM: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
0> SD: 23 BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST
0> SD: 24 BLE_GAP_EVT_DATA_LENGTH_UPDATE
0> SD: 51 BLE_GATTS_EVT_RW_AUTHORIZE_REQUEST
0> on_write:453 resp 1
0> BLE_NUS_EVT_HOST_PASSKEY_DATA
0> BLE: ble_host_passkey[16]=17 8D 53 60 01 FD 42 65 EE 8F A6 A9 54 DC 17 8F
0> NCE: bd_addr1 x67F4C478945C
0> NCE: bd_addr2 xE49C814C1039
0> PK: passkey EE8FA6A954DC178F
0> PK: ptr EE8FA6A954DC178F
0> CDB: oldest table[0].timestamp = 51
0> CDB: table[0].addr = 68EB8938A770, .timestamp = 38158
0> CDB: oldest table[1].timestamp = 4294967285
0> CDB: table[1].addr = 5A5F58810DBC, .timestamp = 23936
0> CDB: oldest table[2].timestamp = 4294967293
0> CDB: table[2].addr = 4ED340F5FCA3, .timestamp = 34401
0> CDB: table[3].addr = 4353F39350AF, .timestamp = 4564
0> 56CDFFSD: 50 BLE_GATTS_EVT_WRITE
0> B gcm_ble_evt_handler EVT_WRITE
0> E gcm_ble_evt_handler EVT_WRITE
0> on_write:453 resp 0
0> BLE_NUS_EVT_RX_DATA
0> 0:00:04.664 BLE detected
0>
0>
0> on_write:561 resp 0
0> 0:00:04.666 Sess Start
0> Session Type=Engineering
0> BLE: Connection in session. Session timer restarted
0> 0:00:04.666 STIM EVENT[04]: x09 (255)
0> 0:00:04.666 ACK: 001000
0>
0> PMM: ENTER_UNPROTECTED, active id=x0000
0> PM_PEER_DATA_ID_APPLICATION 4
0> data_id 4
0> PM: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
0> SD: 57 BLE_GATTS_EVT_HVN_TX_COMPLETE
0> SD: 50 BLE_GATTS_EVT_WRITE
0> B gcm_ble_evt_handler EVT_WRITE
0> E gcm_ble_evt_handler EVT_WRITE
0> on_write:453 resp 0
0> BLE_NUS_EVT_RX_DATA
0>
0> on_write:561 resp 0
0> 0:00:04.755 Rd Ver
0> Firmware=2.1.399 SecurityVer=2 AdvertiseVer=4 UnrestictedVer=9 RemoteVer=4 ProgrammingVer=14 EngineeringVer=12 FPGAModel=4 FPGAVer=4 ImplantVer=1 Bootloader=7 SD_FWID=x0102 SD_Ver=7.2.0 Model=ETM Type=FIELD_BLE_UART
0> 0:00:04.755 ACK: 002016
0>
0> SD: 57 BLE_GATTS_EVT_HVN_TX_COMPLETE

  • 0 in reply to Allen

    Application sdk_config.h
    #define FDS_VIRTUAL_PAGES 4

    Bootloader sdk_config.h
    #define NRF_DFU_APP_DATA_AREA_SIZE 12288
    This is the current configuration. I believe they match. 1024 page size * 4 num pages * 3 = 12288?
    Not sure why it is x3
  • 0 in reply to Allen

    Hi,

    Then this cold be the problem. NRF_DFU_APP_DATA_AREA_SIZE is in bytes, and each flash page is 1024 words = 4096 bytes (this is where the 4 comes from in your calculation, and 3 is the number of pages). Your value of 12288 matches 3 FDS pages, not 4.

  • 0 in reply to Einar Thorsrud

    dfu_data_types.h has this code which confused me. The constant 3 should actually be number of pages or something to make it clearer.

    #ifndef NRF_DFU_APP_DATA_AREA_SIZE
    #define NRF_DFU_APP_DATA_AREA_SIZE (CODE_PAGE_SIZE * 3)
    #endif

    --------------------------------------------------------------------------------------------------

    Changing the number of FDS_VIRTUAL_PAGES pages to 3, to match the bootloader NRF_DFU_APP_DATA_AREA_SIZE 12288, did resolve the problem!

    Thank you for the help!

  • 0 in reply to Allen

    There is one additional twist to this problem.

    I have verified that the reset issue is due to a mismatch between the the reserved flash size. 

    • when the size of FDS_VIRTUAL_PAGES is increased, the first attempt to make a BLE connection causes a reset. However it recovered with the next boot.
    • when the size of FDS_VIRTUAL_PAGES is decreased, the device goes into a reset loop where pm_init() returns NRF_INTERNAL_ERROR.

    Is there a way to correct this problem? It appears the bonds need to be deleted before the peer manager is initialized to work.

  • 0 in reply to Allen

    Hi,

    Changing the number of FDS pages through DFU does not work out of the box. Basically, there are two different scenarios:

    1. If you add an additional FDS page, this may or may not be empty. If the page is empty, it will be initialized by FDS and used. If it is not empty, it will not be used (see line 706-711 in fds.c in SDK 17.0.2.

    2. If you remove FDS pages, then you may remove data and/or swap pages (those shift around after every garbage collection so you can never know). If you remove data page(s), you risk loosing data such as bonding information. If only data pages are deleted, you "just" loose data. If the swap page is removed, fds_init() will return the FDS_ERR_NO_PAGES error.

    So the only way to get a predictable and consistent behavior when updating an existing product via DFU while changing the number of FDS pages is to delete all those pages before you initialize FDS. In that case all data will be lost, but FDS will initializes the empty pages and you will be good to go.

Related