sprintf needs to be reset every 128 characters?

[humming]

After having a problems with a function using vsnprintf, I finally boiled it down to sprintf. Every 128 characters that has been run through sprintf, it truncates the output.

Steps I used to reproduce it:

* I took the simplest example I could find which used the logging functionality (examples/peripheral/temperature)

* Changed the main function to after printing the temperature, do the following:

        NRF_LOG_INFO("Actual temperature: %d", (int) temp);
        nrf_delay_ms(500);

+        size_t rc = sprintf(buf, "01234567890123456789");
+        NRF_LOG_INFO("Result: %s (%d)", nrf_log_push(buf), rc);

        NRF_LOG_FLUSH();

* (buf is a global char array with size 32)

* Added RTT functionlity to get the logs through Segger RTT

* This resulted in the output to be as follows:

<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 0 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 0 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27
<info> app: Result: 01234567890123456789 (20)
<info> app: Actual temperature: 27

Note that it prints 128 ((20 + \0) * 6 + 1 + \0) characters before truncating, this repeats constantly. It still thinks it printed 20 characters however.

This is on SDK 15.3.0, btw.

[Edvin]

Hello,

This believe this actually a limitation in the logging module. However, I see that you try to print this quite "slow", by delaying 500ms. The issue is that it looks like you base this delay on nrf_delay_ms(500), which will halt the processor for 500ms. This means that it doesn't have time to process the logging module. Try to use the app_timer to trigger the NRF logs instead. You can look in the ble_app_hrs example how to use the app_timer.

Hint: you need to use these functions: app_timer_init(), app_timer_create() and app_timer_start().

Best regards,

Edvin

[humming]

Yeah, did some more testing today and the problem is with the logging module, as previously suggested.

The problem seems to be with nrf_log_push, the following test does not print everything:

for(...) {
   NRF_LOG_INFO("%s", nrf_log_push("abcdefhijk"));
}
   

Every 128 characters or so, the output is dropped...