BLE on_write rx buffer does not keep values

[TouchTheFishy]

Hi!

I am trying to flash a component on my custom embedded PCB that embarks a NRF52832 through BLE. To do this, I run on my PC a python script that reads from a hex file (too big to be stored on the device) and sends it through BLE to the NRF so the data can be flashed through I2C.

Although a strange behaviour is observed:

The python script sends the following array :

[0x01, 0x80, 0x02, 0x1D]

In the "on_write" handler on my NRF I have the following code:

static void on_write(ble_ppg_debug_t *p_ppg_debug, ble_gatts_evt_write_t write)
{
    switch (write.uuid.uuid)
    {
        case PPG_DEBUG_UPDATE_GET_DATA:
            NRF_LOG_INFO("RCV GET UPDATE_DATA val = %d \r\n", write.data[0]);
            NRF_LOG_FLUSH();
            uint32_t cmd_delay = 0;
            bool end_of_page_reached = (bool)write.data[0];
            uint8_t payload_size = (write.len - 1);
            NRF_LOG_INFO("%02x %02x %02x %02x %02x %02x", write.data[0], write.data[1], write.data[2], write.data[3], write.data[4], write.data[5]);
            NRF_LOG_FLUSH();
            break;
    }

The logs print

[0x01, 0x80, 0x02, 0x1D, 0x00, 0x00]

Which is correct

Although, with the same array sent, when I use the code

switch (write.uuid.uuid)
    {
        case PPG_DEBUG_UPDATE_GET_DATA:
            NRF_LOG_INFO("RCV GET UPDATE_DATA val = %d \r\n", write.data[0]);
            NRF_LOG_FLUSH();
            uint32_t cmd_delay = 0;
            bool end_of_page_reached = (bool)write.data[0];
            uint8_t payload_size = (write.len - 1);
            uint8_t rx_buffer[243];
            for (uint8_t i = 0; i < payload_size; i++)
            {
                rx_buffer[i] = write.data[i + 1];
            }
            NRF_LOG_INFO("%02x %02x %02x %02x %02x %02x", rx_buffer[0], rx_buffer[1], rx_buffer[2], rx_buffer[3], rx_buffer[4], rx_buffer[5]);
            NRF_LOG_FLUSH();
            break;
    }

the logs print

[0x80, 0x00, 0x00, 0x80, 0x00, 0x00]

Does anyone know how I could use this data received through BLE?

Thanks!

I am using

• NRF52832
• Ubuntu 20.04
• Python3 with Bleak library
• RTT logs

Not Logged in

[Einar Thorsrud]

Hi,

I suspect the problem here is with the logger, as the log processing is deferred. From logger module documentation:

Since the logs are not processed directly, it is risky to pass pointers as arguments, especially to variables that do not have static addresses, for example variables allocated on the stack. By the time the log is processed, the pointer can point to invalid data.

The easiest way to solve this is to make your rx_buffer static. You can refer to the logger documentation for more details and other ways of handling this.

[TouchTheFishy]

Hi Einar,

I have tried to make my buffer static but it doesn't help.

Also, I don't think that the issue is related to the logs. The array I receive through BLE is then sent through I2C and my analog decoder shows the same values as the logs.

chromechrome

[Einar Thorsrud]

TouchTheFishy said:

I have tried to make my buffer static but it doesn't help.

I see, then I am out of ideas for now. Please keep this static though (or fix in a different way), as this is a potential source for problems though there could also be something else here.

TouchTheFishy said:

Also, I don't think that the issue is related to the logs. The array I receive through BLE is then sent through I2C and my analog decoder shows the same values as the logs.

Can you elaborate? The only difference between the two code snippets is that in the second you copy the data to a variable on the stack, and then log the data. Have you also done some other changes which you do not show here?

Update: Can you log the value of write.len also?

[TouchTheFishy]

Einar Thorsrud said:

The only difference between the two code snippets is that in the second you copy the data to a variable on the stack, and then log the data.

Yes apologies, I removed some code to put an emphasis on the problematic part. Also, I have tried removing the i2c communication but it didn't help so I figured the problem was't related to the i2c. Here's the full switch statement:

case PPG_DEBUG_UPDATE_DATA_INPUT:
            NRF_LOG_INFO("RCV GET UPDATE_DATA val = %d \r\n", write.data[0]);
            NRF_LOG_FLUSH();
            // The first byte of the message is to inform if we reached the end of the firmware page
            // This has to be done since the firmware had to be flashed page by page, each page being >8KB long
            // and the nrf drivers do not allow transaction bigger than 244 bytes
            // So we need to interrupt the TWI transfer after each transmission until the end of page is reached.
            uint32_t cmd_delay = 0;
            memcpy(rx_buffer, write.data, write.len);
            bool end_of_page_reached = (bool)rx_buffer[0];
            uint8_t payload_size = (write.len - 1);
            NRF_LOG_INFO("payload size : %d", payload_size);
            NRF_LOG_FLUSH();
            if (end_of_page_reached)
            {
                NRF_LOG_INFO("%02x %02x %02x %02x", rx_buffer[1], rx_buffer[2], rx_buffer[3], rx_buffer[4]);
                cmd_delay = set_ppg_cmd_delay( rx_buffer[2]);
                NRF_LOG_INFO("cmd delay set to %d", cmd_delay);
                NRF_LOG_FLUSH();
            }
            int8_t err = hub_write_nonstop(rx_buffer +1, payload_size, cmd_delay, NULL, 0, end_of_page_reached);
            if(err != NRF_SUCCESS)
            {
                NRF_LOG_ERROR("Error while transmitting data. err no :%d", err)
                NRF_LOG_FLUSH();
            }
            ble_ppg_debug_send_notif(p_ppg_debug, p_ppg_debug->ppg_debug_send_update_status, &err, 1);
            break;

When I log the 

write.len

 i get the expected value (5)

chromechrome

Not Logged in

chromechrome

chromechrome

[Einar Thorsrud]

Hi,

I am not sure what I can say from this. I think you would need to show more of the code and explain what it does and how you see if fail in details. From this, all I see is that you call some functions you have implemented but I have no idea what these do, how they are implemented and how things fail (other than that you see corrupted data at some point).

[TouchTheFishy]

Well basically, ignoring all the code I added (since removing/adding it doesn't change anything on the issue reported above) I can summarize this way. When sending [01 80 02 1D] through BLE, this is the code I run on the NRF:

NRF_LOG_INFO("%02x %02x %02x %02x %02x", write.data[0], write.data[1], write.data[2], write.data[3], write.data[4]);
NRF_LOG_FLUSH();

prints:

[01 80 02 1D]

While

NRF_LOG_INFO("%02x %02x %02x %02x", write.data[0], write.data[1], write.data[2], write.data[3]);
NRF_LOG_FLUSH();
memcpy(rx_buffer, write.data, write.len);

prints:

[01 80 00 E0]

Not Logged in

chromechrome

[Einar Thorsrud]

OK, I see. There is nothing wrong in either of these two code snippets. This probably indicates that in the second case you for some reason trigger or see a memory corruption issue of some sort, though there is nothing here that indicates what. It could be related to something completely different that happens to be part of your application. I notice that the rx_buffer is quite large. Could there be a stack overflow, perhaps?

[TouchTheFishy]

I have also tried setting the buffer to a size of 5 but doesn't help either

chromechrome