This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

NRF_LOG_PUSH seems to be outputting invalid data intermittently

Hi!

I'm using the nRF52840 DK with SDK 15.2 and on Windows 10. I have been testing USB communication and while I was testing input and output data, some of the data I was outputting in the RTT viewer with NRF_LOG_INFO() was invalid. What I mean by that is that the data sent through USB into Putty is the same as the data printed with NRF_LOG_INFO():

To produce this, I used the usbd_cdc_acm_pca10056 example. Originally, this example does not print in the Viewer and I had to make some changes to the config file:

I also added the following to main.c:

That weird output was generated using this:

I was able to bypass the problem and get normal output when avoiding NRF_LOG_PUSH:

I find it weird to NRF_LOG_PUSH doesn't work as supposed since it is advised here.

I also tried adding NRF_LOG_FLUSH() after the call to NRF_LOG_PROCESS() but it did improve the output. I also tried adding some delay (thinking that the output would be generated to quickly for RTT Viewer) using both nrf_delay_ms() and nrf_delay_us() and it didn't do anything.

I also linked the config file used and the main source file.

sdk_config.h

Thanks for looking into this bug!

Parents
  • Hi,

    There is a lot of configs that you can play around with in your sdk_config.h file to help solve this issue. I'm not sure exactly which one is causing this in your application:

    Best regards,
    Jørgen

  • Hi,

    I tested the output from the logger modifying each config you sent and none of them did anything to the output. However, that got me thinking and I went back on this page and read that NRF_LOG_STR_PUSH_BUFFER_SIZE is closely linked to the usage of NRF_LOG_PUSH(). I also tried NRF_LOG_HEXDUMP_INFO and  NRF_LOG_RAW_HEXDUMP_INFO. These last two do print properly. However, they print a lot of extra data which makes it not ideal. So I tested extensively with NRF_LOG_STR_PUSH_BUFFER_SIZE and found the following results when outputting incrementing data (the numbers mentioned are those where there is an error printing, so incrementing values not size values):

    NRF_LOG_STR_PUSH_BUFFER SIZE First error Interval between errors Last error recorded
    512 235 74 975
    1024 309 147 1038
    2048 309 293 895
    4096 601 562 1163
    8192 1163 9174 10337

    After the last error recorded, the buffer seems to have stabilized and doesn't output any more errors, but I might not be printing enough data. For these tests, the string printed is the following:

    Also, I tested using a different string for an NRF_LOG_STR_PUSH_BUFFER_SIZE of 512:

    And the first error is at 104; with an interval of 86 and the last error at 1043.

    Hopefully, that would tell you a bit more. I can always rely on NRF_LOG_RAW_HEXDUMP_INFO but this wouldn't be ideal.

    Thank you so much for your help

Reply
  • Hi,

    I tested the output from the logger modifying each config you sent and none of them did anything to the output. However, that got me thinking and I went back on this page and read that NRF_LOG_STR_PUSH_BUFFER_SIZE is closely linked to the usage of NRF_LOG_PUSH(). I also tried NRF_LOG_HEXDUMP_INFO and  NRF_LOG_RAW_HEXDUMP_INFO. These last two do print properly. However, they print a lot of extra data which makes it not ideal. So I tested extensively with NRF_LOG_STR_PUSH_BUFFER_SIZE and found the following results when outputting incrementing data (the numbers mentioned are those where there is an error printing, so incrementing values not size values):

    NRF_LOG_STR_PUSH_BUFFER SIZE First error Interval between errors Last error recorded
    512 235 74 975
    1024 309 147 1038
    2048 309 293 895
    4096 601 562 1163
    8192 1163 9174 10337

    After the last error recorded, the buffer seems to have stabilized and doesn't output any more errors, but I might not be printing enough data. For these tests, the string printed is the following:

    Also, I tested using a different string for an NRF_LOG_STR_PUSH_BUFFER_SIZE of 512:

    And the first error is at 104; with an interval of 86 and the last error at 1043.

    Hopefully, that would tell you a bit more. I can always rely on NRF_LOG_RAW_HEXDUMP_INFO but this wouldn't be ideal.

    Thank you so much for your help

Children
No Data