NRF_LOG_HEXDUMP_* raises Data Access Violation Fault if a large buffer is used

[martinspedro]

Hi to all,

I have found that using SDK17.0.0 on NRF52832, whenever I try to use NRF_LOG_HEXDUMP_DEBUG for a large buffer (more than a 1000 elements), I get a Data Access Violation Fault.

I understand that since the NRF_LOG is deferred and my buffer is allocated in stack, I can get the buffer pointer to be corrupted. 
Aware of that, after calling the NRF_LOG_HEXDUMP_DEBUG I call the NRF_LOG_FINAL_FLUSH, in order to fully flush the logs.
I have also changed the NRF_LOG_BUFSIZE to 4096, in order to fully store my buffer (1800 bytes)

I have also noticed that the output of my calls to NRF_LOG_HEXDUMP_DEBUG are capped at 80 bytes (8 columns x 10 rows), even if the buffer contains more data and and the length argument of the NRF_LOG_HEXDUMP_DEBUG call is more than 80 bytes.

Below is a code snippet. I have tried to dump the buffer immediately after creation (even if it is all zeroes), just to remove the possibility of errors in functions that manipulate the buffer contents. Still getting Data Access Violation Fault.

uint8_t cert_buffer[1800] = {0};
NRF_LOG_HEXDUMP_INFO(cert_buffer, 1800);
NRF_LOG_FINAL_FLUSH();

Am I missing something or is this a bug? Can anyone reproduce this behavior?

Thanks in advance,

Pedro

[ovrebekk]

Hi

Each byte of RAW data is converted to an ASCII hex presentation, so essentially each byte of raw data becomes multiple bytes of log data. 

Does it work if you try to send a shorter dump, such as 500 bytes?

Best regards
Torbjørn

[martinspedro]

Hi ovrebekk,

I took the conversion from hex to ASCII in consideration. Since I couldn't pinpoint if that conversion was done when storing or printing the data, I made the NRF_LOG buffer bigger than required. From hex to ASCII, you double the amount of bytes required to store a character, so 2*1800 < 4096, which means that the full buffer should fit inside NRF_LOG buffer.

Note that the max amount of data printed is always capped at 80 bytes of hexadecimal data.

ovrebekk said:

Does it work if you try to send a shorter dump, such as 500 bytes?

It doesn't raises a Data Access Violation Fault, but data is still capped at 80 hex bytes

[ovrebekk]

Hi 

Are you able to share your sdk_config.h file?

I got some help from one of the developers, and he was able to print buffers longer than 80 bytes. 

For the data access violation fault, have you tried to increase the size of the call stack?

Best regards
Torbjørn

[martinspedro]

Hi,

Sharing the sdk_config.h and the app_config.h (I define the USE_APP_CONFIG in my Makefile).

From your answer, I believe that one thing might not be clear: I have no data access violation fault when I manipulate the buffer (for instance, R/W operations and passing it as an argument to other functions). Only when calling the NRF_LOG_HEXDUMP_* I have a data access violation fault.

I have tried increasing the call stack (already at 8192), but no differences.

ovrebekk said:

I got some help from one of the developers, and he was able to print buffers longer than 80 bytes.

Thank you for testing. I believe the 80 chars "limit" might be a problem in my configs.
Nevertheless, was the developer able to reproduce the data access violation fault?

app_config.h1715.sdk_config.h

Best regards,

Pedro

[ovrebekk]

Hi Pedro

Yes, the developer was able to reproduce the stack overflow issue as well, when using an 1800 byte buffer. 

Thanks for sharing the config files, I have shared them with the developer and will get back to you. 

Best regards
Torbjørn

[martinspedro]

Thank you for the quick response, ovrebekk.

Please ping me when you have news.

Best regards,

Pedro