SDK 15.3 Secure Serial UART Bootloader does not handle NRF_DFU_OP_OBJECT_WRITE (data)

[Pierre B.]

Hi,

I am currently trying to use SDK 15.3 secure serial UART bootloader (from the example in nRF5_SDK_15.3.0_59ac345\examples\dfu\secure_bootloader\pca10040_uart) on a custom chip embedding an nRF52832 and a GSM chip, communicating between themselves via UART. In order to adapt the given example to my particular case, I just added in nrf_dfu_init() function the power-on of the GSM chip. I also modified UART configuration (pinout, HWFC activated, baudrate = 57600).

After calling this function, the bootloader then loops forever (loop_forever() function), and waits for commands, via UART, from the GSM chip. The GSM chip basically connects to server, downloads new firmware, checks if a firmware upgrade is needed, and "if true" starts to transfer said firmware to nRF52832.

Here is the detailed communication between GSM and nRF52832, from the GSM chip point of view:

<--Sent CMD: 02, len: 4-->
Received 0x02 0x01

<--Sent CMD: 07, len: 2-->
Received 0x07 0x01

<--Sent CMD: 06, len: 3-->
Received 0x06 0x01

<--Sent CMD: 01, len: 7-->
Received 0x01 0x01

<--Sent CMD: 08, len: 130--> (command)
<--Sent CMD: 08, len: 16-->  (command)
<--Sent CMD: 03, len: 2-->
Received 0x03 0x01
<-- Received CALC CRC message response -->
<-- Received CRC: 912423956 (36627C14), local CRC: 912423956(36627C14) -->
<-- Received offset: 141, local offset: 141 -->

<--Sent CMD: 04, len: 2-->
Received 0x04 0x01

<--Sent CMD: 06, len: 3-->
Received 0x06 0x01

<--Sent CMD: 01, len: 7-->
Received 0x01 0x01

<--Sent CMD: 08, len: 129-->	(data)
<-- Sent 127 bytes, local CRC: -1046533821(C19F2943) -->
<--Sent CMD: 08, len: 129-->	(data)
<-- Sent 254 bytes, local CRC: -340869425(EBAEBECF) -->
<--Sent CMD: 08, len: 129-->	(data)
<-- Sent 381 bytes, local CRC: -793576822(D0B2FA8A) -->
<--Sent CMD: 08, len: 129-->	(data)
<-- Sent 508 bytes, local CRC: 143380219(088BCEFB) -->

...


<--Sent CMD: 08, len: 34-->	(data)
<-- Sent 4096 bytes, local CRC: 1943765718(73DB82D6) -->

<--Sent CMD: 03, len: 2-->

This command sequence is right and was working perfectly fine with a secure serial UART bootloader I used with SDK 12.1. The problem here is that after having received and handled successfully the 2 first chunks of data (lines 30 and 32), so 254 bytes, the nRF52832 seems to stop receiving the data, or at least handling it: it does not go into the case NRF_DFU_OP_OBJECT_WRITE from the nrf_dfu_serial_on_packet_received() function anymore. As so of course it doesn't reply to the CRC command (0x03, line 45) sent by the GSM chip, which is waiting for a CRC answer before proceeding with sending next data packet.

Now I am having trouble understanding the source of this issue. I thought at first that it could be a full buffer issue, but it is supposed to be freed asynchronously. I then thought the GSM chip was sending chunks of data too quickly for the nRF52832 to handle, but even after adding a 500ms delay between each chunks (originally 100ms), the issue is still there.

Also, for some reason the logs are not working properly, which does not help debugging... Some of them seems to be missing on the viewer, and they appear very slowly, like they are flushed 30 seconds after being called (and again, not all of them...). So for now my only way of debugging, which is also how I know of this issue, is a buzzer embedded on the board.

Thank you in advance for any help !

[Hung Bui]

Hi Pierre, 

We would need to have the logging from the bootloader to really tell what could be wrong. 

Capturing a logic trace on the UART line when you do DFU with your GSM chip and when you do DFU with a PC would also help pointing out what's wrong. 

My understanding is that: 

- On SDK v12.1 your bootloader + GSM works perfectly fine

- On SDK v15.3 you can do DFU using PC but can't do that with GSM ? 

Is it correct ? 

I would suggest to try with SDK v15.2 , we have some change in SDK v15.3 that may be the cause of the issue.  

[Pierre B.]

Ok I think I found out. The GSM is sending chunk of data of 127 bytes whereas the bootloader seems to be expecting only chunks of 64 bytes.

This brings me to another question, how can I change this value ? I tried to modify RX_BUF_SIZE (defined in nrf_dfu_serial_uart.c from (64) to (127), and also tried other values, but it didn't change anything from the fact that it will only accepts 64 bytes data packets.

[Hung Bui]

Could you check what is the MTU you get when you send a MTU Get command (0x07) ? Changing the RX_BUF_SIZE  should work.

As far as I know we don't have the serial secure bootloader in SDK v12.x , which bootloader did you use for that ? 

[Pierre B.]

For RX_BUF_SIZE = 64, MTU = 131 and for RX_BUF_SIZE = 127, MTU = 257.

So MTU = UART_SLIP_MTU (defined as 2 *(RX_BUF_SIZE + 1)+1), which seems quite logic.

I agree it should work, but if I modify RX_BUF_SIZE from 64 originally to 127 in order to be able to receive 127 bytes data packets send by GSM chip, I obtain the issue first presented. For now it only works if I force the GSM chip to send 64 bytes data packets, but that can not be a long term solution for backend reasons.

I used the dfu bootloader example that was provided with SDK 12.1 and modified it, using files from a more recent SDK version, in order to work with UART.

[Hung Bui]

Could you check if the code get into on_rx_complete () ? and then what is passed to nrf_dfu_serial_on_packet_received ? when the ret_code == NRF_SUCCESS what is the length of the m_slip.p_buffer ?

[Pierre B.]

When RX_BUF_SIZE = 127 and the GSM chip sends 127 bytes data packets, just like in the log attached to my original post, the code goes into on_rx_complete() only for the first two chunks of data (lines 30 and 32 of the log), it doesn't anymore after that.

I can not have any more details as I can't have access to the nRF52 log from this part.

[Pierre B.]

So apparently, whatever the value of RX_BUF_SIZE (127 or higher), the max length in bytes of data packet I can send is between 100 and 110 per packet. It works with 100 bytes data packets, but not with 110 bytes data packets.

[Pierre B.]

UPDATE: With RX_BUF_SIZE = 127 and GSM chip sending 100 bytes data packets, on_rx_complete() pass to nrf_dfu_serial_on_packet_received() a length of 101 bytes (m_slip.current_index), and the length of m_slip.p_buffer is 4 (sizeof(m_slip.p_buffer)).

It also appears that the issue come specifically from nrf_nvmc_write_words() in nrf_nvmc.c file.

static inline void wait_for_flash_ready(void)
{
    while (NRF_NVMC->READY == NVMC_READY_READY_Busy) {}
}

...

void nrf_nvmc_write_words(uint32_t address, const uint32_t * src, uint32_t num_words)
{
    uint32_t i;

    // Enable write.
    NRF_NVMC->CONFIG = NVMC_CONFIG_WEN_Wen;
    __ISB();
    __DSB();
    
    //Point 1
    
    for (i = 0; i < num_words; i++)
    {
        ((uint32_t*)address)[i] = src[i];
        wait_for_flash_ready();
    }

    //Point 2
    
    NRF_NVMC->CONFIG = NVMC_CONFIG_WEN_Ren;
    __ISB();
    __DSB();
}

The first time nRF52 receives a 127 bytes data packet with WRITE command (line 30 of the GSM log), code gets to //Point 1 and to //Point 2 without any visible issue. But for the second packet (line 32 of the GSM log), code gets to //Point 1 but never to //Point2. It would seem that it is stuck waiting for flash to be ready this time.

Any possible reason for that ?

[Hung Bui]

sizeof(m_slip.p_buffer) is only the size of the pointer, not the size of the array, you should find the size of the packet in m_slip.current_index. 

How do you detect that it stuck in point 1 can can't get to point 2 ? I don't think it would stuck in wait_for_flash_ready(). It only checks the hardware register and we haven't seen any case the hardware (writing to flash) wouldn't work. 

I would suggest to print out log instead of line stepping .

How do you find that the issue is from nrf_nvmc_write_words () ?