Hi,

I’m seeing an issue whereby I am unable to log strings using LOG_DBG() and %s format, for a quick example I modified the hello world sample to enable logging and change the code to this:

#define LOG_DOMAIN test_domain

#include <logging/log.h>

LOG_MODULE_REGISTER(LOG_DOMAIN);

 

void main(void)

{

                char baTmpBuf[12];

                sprintf(baTmpBuf, "ffffffff");

                LOG_DBG("Test : %s", baTmpBuf);

 

                printk("Hello World! %s\n", CONFIG_BOARD);

}

I expect to see “Test : ffffffff” but instead I am getting “Test : %*”, if I change the code to inefficiently log each character, e.g.:

                LOG_DBG("Test : %c%c%c%c%c%c%c%c", baTmpBuf[0], baTmpBuf[1], baTmpBuf[2], baTmpBuf[3], baTmpBuf[4], baTmpBuf[5], baTmpBuf[6], baTmpBuf[7]);

Then I get the expected output: “Test : ffffffff”

 

So why is %s not outputting a string? If there a configuration option I have missed? I have tried toggling “Format strings with libc” option but it doesn’t change anything. I’m testing on an nRF52840 using the nrf52840_pca10056 board file.

Thanks,
Jamie

THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.

EXTERNAL EMAIL: Be careful with attachments and links.

On 15 May 2019, at 14.27, Stefan Jaritz <stefan@kokoontech.com> wrote:

Hey Lairdjm,



Depending on you logging setup, the log of the string is done inside the "LOG_DBG" command or later.

Later means, that your main function was already left and your local variables are gone = invalid.

Try to add following lines at your proj.conf:

CONFIG_LOG=y
# CONFIG_LOG_PROCESS_THREAD=y
# CONFIG_LOG_INPLACE_PROCESS=y
CONFIG_LOG_IMMEDIATE=y
CONFIG_LOG_BACKEND_SHOW_COLOR=y

This will force the logger "execute" the log function.

Good luck!

Stefan



On 15/05/2019 11:52, lairdjm wrote:

Hi,
I’m seeing an issue whereby I am unable to log strings using LOG_DBG() and %s format, for a quick example I modified the hello world sample to enable logging and change the code to this:
#define LOG_DOMAIN test_domain
#include <logging/log.h>
LOG_MODULE_REGISTER(LOG_DOMAIN);

void main(void)
{
char baTmpBuf[12];
sprintf(baTmpBuf, "ffffffff");
LOG_DBG("Test : %s", baTmpBuf);

printk("Hello World! %s\n", CONFIG_BOARD);
}
I expect to see “Test : ffffffff” but instead I am getting “Test : %*”, if I change the code to inefficiently log each character, e.g.:
LOG_DBG("Test : %c%c%c%c%c%c%c%c", baTmpBuf[0], baTmpBuf[1], baTmpBuf[2], baTmpBuf[3], baTmpBuf[4], baTmpBuf[5],baTmpBuf[6], baTmpBuf[7]);
Then I get the expected output: “Test : ffffffff”

So why is %s not outputting a string? If there a configuration option I have missed? I have tried toggling “Format strings with libc” option but it doesn’t change anything. I’m testing on an nRF52840 using the nrf52840_pca10056 board file.
Thanks,
Jamie
THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY FURTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED RECIPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.

Hi,
To optimize time of log processing message construction is deferred. For this reason you cannot use arrays that will not live long enough for logger thread to see them.
In other words you can always use static arrays (like you do when calling `LOG_xyz("%s", "testme")`) but you must never pass anything from the stack (like in your example). You can enable `CONFIG_LOG_IMMEDIATE` but this will affect logging performance and does not actually tells you why the problem happened in the first place.

If you need to print array declared on stack you must call ` log_strdup()` to duplicate it.

Personally I am against this API and I indicated it will cause bugs as people do expect `%s` to simply output a string and they also don't read documentation for something that should just work.
But at least it makes logger faster if you look from the bright side.

Thanks,

On 20 May 2019, at 00:20, pawel.dunaj@nordicsemi.no wrote:

I think %s capability should be dropped from the logger’s format string processing and a separate API added specifically to log a C string, which makes an immediate copy.

Here I totally agree. I think that formatting of strings is such a well known standard that nobody will read the fine print for a logger to see what magic may lie under its hood. I think we should either assert that %s is never used and use some other format instead (i.e. force people to check the doc at least once when they hit an error) or keep %s for in place rendering and add new format for people who want to go faster.
Another thing is that assert is disabled by default so many people may never notice the problem (especially for error paths).

On 20 May 2019, at 00:20, pawel.dunaj@nordicsemi.no wrote:

I think %s capability should be dropped from the logger’s format string processing and a separate API added specifically to log a C string, which makes an immediate copy.

Here I totally agree. I think that formatting of strings is such a well known standard that nobody will read the fine print for a logger to see what magic may lie under its hood. I think we should either assert that %s is never used and use some other format instead (i.e. force people to check the doc at least once when they hit an error) or keep %s for in place rendering and add new format for people who want to go faster.
Another thing is that assert is disabled by default so many people may never notice the problem (especially for error paths).

On 20 May 2019, at 00:20, pawel.dunaj@nordicsemi.no wrote:

I think %s capability should be dropped from the logger’s format string processing and a separate API added specifically to log a C string, which makes an immediate copy.

Here I totally agree. I think that formatting of strings is such a well known standard that nobody will read the fine print for a logger to see what magic may lie under its hood. I think we should either assert that %s is never used and use some other format instead (i.e. force people to check the doc at least once when they hit an error) or keep %s for in place rendering and add new format for people who want to go faster.
Another thing is that assert is disabled by default so many people may never notice the problem (especially for error paths).