ble_app_buttonless_dfu not advertising on nrf52811 after DFU process

[Santi Dominguez]

Hello, i've tested dfu process from secure_bootloader with different app examples with success (ble_app_blinky, ble_app_uart, even a custom application) but, when I try the same with the ble_app_buttonless_dfu example, with no change in code (main.c), my device is not advertising.

I'm on SDK16.0.0 with a custom board with nrf52811 and i've configured the mcu to use low frequency SoftDevice clock source (RC) as I've read before here in the forum (which previously was a problem and solved bootloader not advertising).

It's working (the ble_app_buttonless_dfu example advertising after DFU over dfuTarg) on the nrf52 DK (nrf52832) with low freq clock configuration and s112 SoftDevice.

Thanks in advance.

Note: bootloader's enter_method_button is disabled.

[Amanda Hsieh]

Hi Santi, 

Do you s112 v7.0.1 for nRF52811?  Could you provide the logs from the DFU master, and also the bootloader (RTT log from using _debug example bootloader project)? They are generally helpful. 

If you have nRF52840 DK, you could test with pca10056e_s112_ble_debug. 

-Amanda H.

[Santi Dominguez]

Hi Amanda,

Yes, softdevice is s112 v7.0.1, so i use --sd-req 0xCD for generating dfu packages.

I do dfu over an android-phone's NrfConnect app so I don't know (I've never done this before) if show_log>DEBUG information is what you're asking for (file attached just for clarification).

Fullscreen Log 2021-04-14 10_51_52.txt Download

nRF Connect, 2021-04-14
DfuTarg (D4:B5:30:40:71:E8)
V	10:48:46.095	Connecting to D4:B5:30:40:71:E8...
D	10:48:46.095	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	10:48:46.157	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	10:48:46.157	Connected to D4:B5:30:40:71:E8
D	10:48:46.159	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
V	10:48:46.182	Discovering services...
D	10:48:46.182	gatt.discoverServices()
I	10:48:46.785	PHY updated (TX: LE 2M, RX: LE 2M)
I	10:48:47.232	Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 6000ms)
D	10:48:47.283	[Callback] Services discovered with status: 0
I	10:48:47.283	Services discovered
V	10:48:47.301	Generic Access (0x1800)
- Device Name [R W] (0x2A00)
- Appearance [R] (0x2A01)
- Peripheral Preferred Connection Parameters [R] (0x2A04)
- Central Address Resolution [R] (0x2AA6)
Generic Attribute (0x1801)
Secure DFU Service (0xFE59)
- DFU Packet [WNR] (8ec90002-f315-4f60-9fb8-838830daea50)
- DFU Control Point [N W] (8ec90001-f315-4f60-9fb8-838830daea50)
   Client Characteristic Configuration (0x2902)
I	10:48:47.412	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
I	10:48:47.490	Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 6000ms)
D	10:50:29.598	[Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)
E	10:50:29.598	Error 8 (0x8): GATT CONN TIMEOUT
I	10:50:29.598	Disconnected
D	10:50:29.625	[Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED

I have downloaded the _debug version of the bootloader and tried to "update" with an already generated package (only the app) but OTA doesn't start, is it because I have to generate package with --debug-mode flag or is it because I use a private_key?

No, unfortunately I have not a nrf52840 DK, but i generate the nrf52811 versions of examples from all pca10056e versions deleting the two MACROs, <DEVELOP_IN_NRF52840> and <NRFX_COREDEP_DELAY_US_LOOP_CYCLES=3>.

I download the bootloader to the nrf52811 through the SWD of the nrf52832 DK (PCA10040).

Thank you so much.

[Amanda Hsieh]

Hi Santi,

Santi Dominguez said:

but OTA doesn't start, is it because I have to generate package with --debug-mode flag or is it because I use a private_key?

Why it doesn't start? Do you see any message on App or from the log? Could you provide the log on the phone and the device? 

The difference in the _debug example bootloader project is to provide the log. You could use J-Link RTT view or Segger to get the RTT log. The others function are the same. 

-Amanda H.

[Santi Dominguez]

Hi Amanda,

it shows (in the app) "Starting DFU..." and then "Disconnecting", the logs on the phone show error "INSUFFICIENT RESOURCES":

Fullscreen LOGS_PHONE.txt Download

nRF Connect, 2021-04-14
DfuTarg (D4:B5:30:40:71:E8)
V	12:39:59.202	Connecting to D4:B5:30:40:71:E8...
D	12:39:59.202	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	12:39:59.354	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	12:39:59.354	Connected to D4:B5:30:40:71:E8
D	12:39:59.357	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
V	12:39:59.396	Discovering services...
D	12:39:59.396	gatt.discoverServices()
I	12:39:59.976	PHY updated (TX: LE 2M, RX: LE 2M)
I	12:40:00.424	Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 6000ms)
D	12:40:00.471	[Callback] Services discovered with status: 0
I	12:40:00.471	Services discovered
V	12:40:00.486	Generic Access (0x1800)
- Device Name [R W] (0x2A00)
- Appearance [R] (0x2A01)
- Peripheral Preferred Connection Parameters [R] (0x2A04)
- Central Address Resolution [R] (0x2AA6)
Generic Attribute (0x1801)
Secure DFU Service (0xFE59)
- DFU Packet [WNR] (8ec90002-f315-4f60-9fb8-838830daea50)
- DFU Control Point [N W] (8ec90001-f315-4f60-9fb8-838830daea50)
   Client Characteristic Configuration (0x2902)
I	12:40:00.603	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
I	12:40:00.679	Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 6000ms)
V	12:40:12.899	[DFU] DFU service started
V	12:40:12.899	[DFU] Opening file...
I	12:40:12.899	[DFU] Firmware file opened successfully
V	12:40:12.899	[DFU] Connecting to DFU target...
D	12:40:12.899	[DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
I	12:40:12.904	[DFU] Connected to D4:B5:30:40:71:E8
V	12:40:12.904	[DFU] Discovering services...
D	12:40:12.904	[DFU] gatt.discoverServices()
I	12:40:12.906	[DFU] Services discovered
D	12:40:12.925	[DFU] wait(1000)
V	12:40:13.916	[DFU] Requesting new MTU...
D	12:40:13.916	[DFU] gatt.requestMtu(517)
I	12:40:13.980	[DFU] MTU changed to: 247
V	12:40:13.980	[DFU] Enabling notifications for 8ec90001-f315-4f60-9fb8-838830daea50
D	12:40:13.981	[DFU] gatt.setCharacteristicNotification(8ec90001-f315-4f60-9fb8-838830daea50, true)
D	12:40:13.981	[DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
I	12:40:13.982	[DFU] Data written to descr.8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 01-00
V	12:40:13.982	[DFU] Notifications enabled for 8ec90001-f315-4f60-9fb8-838830daea50
A	12:40:13.982	[DFU] Notifications enabled
D	12:40:13.982	[DFU] wait(1000)
V	12:40:14.983	[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50
D	12:40:14.983	[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50)
I	12:40:15.020	[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-06-01-00-02-00-00-00-00-00-00-00-00-00-00
I	12:40:15.021	[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-06-01-00-02-00-00-00-00-00-00-00-00-00-00
A	12:40:15.021	[DFU] Command object info received (Max size = 512, Offset = 0, CRC = 00000000)
V	12:40:15.021	[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50
D	12:40:15.021	[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50)
I	12:40:15.048	[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-02-01
I	12:40:15.049	[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-02-01
A	12:40:15.049	[DFU] Packet Receipt Notif disabled (Op Code = 2, Value = 0)
V	12:40:15.049	[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50
D	12:40:15.050	[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50)
I	12:40:15.083	[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-01-01
I	12:40:15.084	[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-01-01
A	12:40:15.086	[DFU] Command object created
V	12:40:15.087	[DFU] Writing to characteristic 8ec90002-f315-4f60-9fb8-838830daea50
D	12:40:15.088	[DFU] gatt.writeCharacteristic(8ec90002-f315-4f60-9fb8-838830daea50)
I	12:40:15.093	[DFU] Data written to 8ec90002-f315-4f60-9fb8-838830daea50, value (0x): 12-8A-01-0A-44-08-01-12-40-08-02-10-34-1A-02-CD-01-20-00-28-00-30-00-38-84-95-03-42-24-08-03-12-20-42-1D-BA-FD-88-E2-0F-D8-F6-28-CC-3A-49-59-43-C2-C9-D1-70-5A-99-A0-8C-43-E8-B3-0E-A9-A7-A2-C7-18-48-00-52-04-08-01-12-00-10-00-1A-40-5D-24-13-DF-B7-6F-73-82-73-57-17-4B-76-1A-4B-E9-10-A8-91-72-EA-88-88-CD-FD-7A-C0-3A-65-78-F4-DE-CA-32-FE-75-0C-F0-C9-91-3D-52-C3-9A-80-AD-8C-7C-4E-18-DD-4E-75-A7-43-6D-A9-E5-20-46-3C-95-F0-8C
A	12:40:15.094	[DFU] Command object sent (CRC = 565B6E51)
V	12:40:15.094	[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50
D	12:40:15.094	[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50)
I	12:40:15.126	[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-03-01-8D-00-00-00-51-6E-5B-56
I	12:40:15.132	[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-03-01-8D-00-00-00-51-6E-5B-56
A	12:40:15.138	[DFU] Checksum received (Offset = 141, CRC = 565B6E51)
V	12:40:15.139	[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50
D	12:40:15.140	[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50)
I	12:40:15.170	[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 04
I	12:40:15.321	[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-04-04
E	12:40:15.323	[DFU] Remote DFU error: INSUFFICIENT RESOURCES
V	12:40:15.323	[DFU] Disconnecting...
D	12:40:15.349	[DFU] gatt.disconnect()
I	12:40:15.349	[DFU] Disconnected
D	12:40:15.349	[DFU] gatt.refresh() (hidden)
D	12:40:15.349	[DFU] gatt.disconnect()
D	12:40:15.349	[DFU] gatt.close()
D	12:40:15.349	[DFU] wait(600)
I	12:40:15.481	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
I	12:40:15.633	Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 6000ms)

And these are the logs on the device through RTT Viewer:

Fullscreen LOGS_DEVICE.txt Download

<debu<debug> nrf_dfu_ble: Connected

<debug> nrf_dfu_ble: Received BLE_GAP_EVT_PHY_UPDATE_REQUEST.

<debug> nrf_dfu_ble: Received BLE_GAP_EVT_PHY_UPDATE (RX:2, TX:2, status:0)

<debug> nrf_dfu_ble: Received BLE_GAP_EVT_CONN_PARAM_UPDATE

<debug> nrf_dfu_ble: max_conn_interval: 12

<debug> nrf_dfu_ble: min_conn_interval: 12

<debug> nrf_dfu_ble: slave_latency: 0

<debug> nrf_dfu_ble: conn_sup_timeout: 600

<debug> nrf_dfu_ble: Received BLE_GAP_EVT_CONN_PARAM_UPDATE

<debug> nrf_dfu_ble: max_conn_interval: 6

<debug> nrf_dfu_ble: min_conn_interval: 6

<debug> nrf_dfu_ble: slave_latency: 0

<debug> nrf_dfu_ble: conn_sup_timeout: 500

<debug> nrf_dfu_ble: Received BLE_GAP_EVT_CONN_PARAM_UPDATE

<debug> nrf_dfu_ble: max_conn_interval: 12

<debug> nrf_dfu_ble: min_conn_interval: 12

<debug> nrf_dfu_ble: slave_latency: 0

<debug> nrf_dfu_ble: conn_sup_timeout: 600

<debug> nrf_dfu_ble: Received BLE_GATTS_EVT_EXCHANGE_MTU_REQUEST (request: 517, reply: 247).

<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_SELECT (command)

<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1

<debug> nrf_dfu_ble: Set receipt notif

<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_RECEIPT_NOTIF_SET

<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1

<debug> app: Shutting down transports (found: 1)

<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_CREATE (command)

<debug> app: timer_stop (0x200022E4)

<debug> app: timer_activate (0x200022E4)

<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1

<debug> nrf_dfu_ble: Buffer 0x20003010 acquired, len 141 (244)

<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_WRITE (command)

<debug> nrf_dfu_ble: Freeing buffer 0x20003010

<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1

<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_CRC_GET (command)

<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1

<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_EXECUTE (command)

<debug> nrf_dfu_validation: PB: Init packet data len: 64

<info> nrf_dfu_validation: Signature required. Checking signature.

<info> nrf_dfu_validation: Calculating hash (len: 64)

<info> nrf_dfu_validation: Verify signature

<info> nrf_dfu_validation: Image verified

<debug> app: Enter nrf_dfu_cache_prepare()

<debug> app: required_size: 0xCA84.

<debug> app: single_bank: false.

<debug> app: keep_app: false.

<debug> app: keep_softdevice: true.

<debug> app: SD_PRESENT: true.

<debug> app: Bank contents:

<debug> app: Bank 0 code: 0x00: Size: 0x0

<debug> nrf_dfu_ble: Received BLE_GAP_EVT_CONN_PARAM_UPDATE

<debug> nrf_dfu_ble: max_conn_interval: 6

<debug> nrf_dfu_ble: min_conn_interval: 6

<debug> nrf_dfu_ble: slave_latency: 0

<debug> nrf_dfu_ble: conn_sup_timeout: 500

<debug> nrf_dfu_ble: Received BLE_GAP_EVT_CONN_PARAM_UPDATE

<debug> nrf_dfu_ble: max_conn_interval: 12

<debug> nrf_dfu_ble: min_conn_interval: 12

<debug> nrf_dfu_ble: slave_latency: 0

<debug> nrf_dfu_ble: conn_sup_timeout: 600

Amanda Hsieh said:

The difference in the _debug example bootloader project is to provide the log. You could use J-Link RTT view or Segger to get the RTT log. The others function are the same.

Okay, so using the same package already generated for secure_bootloader (without debug) should do OTA as well with the debug bootloader, I wasn't totally sure of that.

[Amanda Hsieh]

Hi, 

If you take a look at DFU Transport layer documentation, found here, you'll see that NRF_DFU_RES_CODE_INSUFFICIENT_RESOURCES means that there is not enough memory for the data object, i.e. the firmware image is too large. 

What's the image size you are planning to update? Since there is 3*PAGE fds above the end address of app and the s112 is 96k(0x18000), the app is no more than 52k for nRF52811. See Memory layout  (the memory size of nRF52811 is the same as nRF52810) 

-Amanda H.