On May 21, 2019, at 2:22 PM, Nicolas Pitre <npitre@...> wrote:

Hello,

This is my first post here, however it probably won't be the last.

For a while I've been working on making Zephyr to compile for and run on
64-bit targets. That currently works with the native-posix target,
and 64-bit RISC-V is my next target.

I would like to submit my work for inclusion into the mainline Zephyr
repository. The documented submit and review procedures imply Github
forks and pull requests which involve going through hoops such as a
Javascript-capable web browser and that is not exactly like a walk in
the park for me (my background and credentials are available online if
you want to know why). That would make my life easier if there could
be some alternative way similar to how it is done with the Linux kernel.
Please let me know if that is possible.

I'm therefore posting my first patch here mainly to initiate a
conversation on this issue. Obviously I have many more of them.

----- >8
Subject: [PATCH] fix PTP clock test case

The various ptp_clock_driver_api methods receive a struct ptp_context
not a struct eth_context, and the later must be obtained from a reference
stored in the former. Failing to do so by directly interpreting
driver_data as a struct eth_context instance does end up corrupting
memory past the actual struct ptp_context storage. The test may still
pass as ptp_clock_get() reads from the same out-of-bounds memory as the
previous ptp_clock_set() and therefore the content matches, and with luck
the corrupted memory is not essential to the completion of the test.
But that wasn't my case which allowed me to find this issue.

Fix this by properly obtaining a reference to the struct eth_context
instance via the actual struct ptp_context, and adding one validation
test in my_ptp_clock_set() like the one found in eth_tx() to make sure
we got the right memory.

Signed-off-by: Nicolas Pitre <npitre@...>

diff --git a/tests/net/ptp/clock/src/main.c b/tests/net/ptp/clock/src/main.c
index 1625f6ec18..5d69164694 100644
--- a/tests/net/ptp/clock/src/main.c
+++ b/tests/net/ptp/clock/src/main.c
@@ -175,29 +175,40 @@ static u64_t timestamp_to_nsec(struct net_ptp_time *ts)
return (ts->second * NSEC_PER_SEC) + ts->nanosecond;
}

+struct ptp_context {
+ struct eth_context *eth_context;
+};
+
static int my_ptp_clock_set(struct device *dev, struct net_ptp_time *tm)
{
- struct eth_context *ctx = dev->driver_data;
+ struct ptp_context *ptp_ctx = dev->driver_data;
+ struct eth_context *eth_ctx = ptp_ctx->eth_context;

- memcpy(&ctx->time, tm, sizeof(struct net_ptp_time));
+ if (&eth_context_1 != eth_ctx && &eth_context_2 != eth_ctx) {
+ zassert_true(false, "Context pointers do not match\n");
+ }
+
+ memcpy(&eth_ctx->time, tm, sizeof(struct net_ptp_time));

return 0;
}

static int my_ptp_clock_get(struct device *dev, struct net_ptp_time *tm)
{
- struct eth_context *ctx = dev->driver_data;
+ struct ptp_context *ptp_ctx = dev->driver_data;
+ struct eth_context *eth_ctx = ptp_ctx->eth_context;

- memcpy(tm, &ctx->time, sizeof(struct net_ptp_time));
+ memcpy(tm, &eth_ctx->time, sizeof(struct net_ptp_time));

return 0;
}

static int my_ptp_clock_adjust(struct device *dev, int increment)
{
- struct eth_context *ctx = dev->driver_data;
+ struct ptp_context *ptp_ctx = dev->driver_data;
+ struct eth_context *eth_ctx = ptp_ctx->eth_context;

- ctx->time.nanosecond += increment;
+ eth_ctx->time.nanosecond += increment;

return 0;
}
@@ -207,10 +218,6 @@ static int my_ptp_clock_rate_adjust(struct device *dev, float ratio)
return 0;
}

-struct ptp_context {
- struct eth_context *eth_context;
-};
-
static struct ptp_context ptp_test_1_context;
static struct ptp_context ptp_test_2_context;

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).

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 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.

EXTERNAL EMAIL: Be careful with attachments and links.