Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

logging: 32 bit float values don't work. #18351

Closed
deadsy opened this issue Aug 17, 2019 · 17 comments · Fixed by #31535
Closed

logging: 32 bit float values don't work. #18351

deadsy opened this issue Aug 17, 2019 · 17 comments · Fixed by #31535
Assignees
Labels
area: Logging bug The issue is a bug, or the PR is fixing a bug priority: low Low impact/importance bug Stale
Milestone

Comments

@deadsy
Copy link

deadsy commented Aug 17, 2019

Code

float x = 1.234f;
printf("this is a 32 bit float %f\n", x);
LOG_INF("this is a 32 bit float %f", x);

Output

***** Booting Zephyr OS build v2.0.0-rc1-50-g70640334730b *****
....
this is a 32 bit float 1.234000
[00:00:00.008,000] ggm.main: this is a 32 bit float 0.000000

Notes
CONFIG_LOG_ENABLE_FANCY_OUTPUT_FORMATTING=y
This uses the minimal libc print formatter for the log messages. The print formatter works for float formatting when invoked via printf, suggesting that the float value is somehow being clobbered in the log functions.

Environment

  • OS: Linux
  • Toolchain: gcc-arm-none-eabi-8-2018-q4-major
  • Board: mimxrt1020_evk
@deadsy deadsy added the bug The issue is a bug, or the PR is fixing a bug label Aug 17, 2019
@pabigot
Copy link
Collaborator

pabigot commented Aug 17, 2019

A summary of the analysis only; I'd prefer @nordic-krch take on this task as it appears to be complex.

The path this code takes through the logging system involves counting the number of arguments and caching one log_arg_t value for each one in an array, then reconstructing the original call stack in the output context.

The count is a simple scan for the number of conversion specifiers. It does not take into account length modifiers or the specifier character itself, and so is incorrect when any given argument exceeds the size of log_arg_t on the target, as is the case with %f and %llu on 32-bit hosts. Any conversions that follow the oversized conversion will also be incorrect.

A fix requires an analysis of the format string to determine the number of log_arg_t values required for each conversion. This analysis will be specific to the selected back-end formatter (either z_prf() or z_vprintk()) and any Kconfig symbols that control the behavior of that formatter.

@ioannisg ioannisg added this to the v2.1.0 milestone Aug 20, 2019
@ioannisg ioannisg added the priority: low Low impact/importance bug label Aug 20, 2019
@dleach02 dleach02 removed this from the v2.1.0 milestone Dec 10, 2019
@dleach02
Copy link
Member

Removing 2.1 milestone

@github-actions
Copy link

This issue has been marked as stale because it has been open (more than) 60 days with no activity. Remove the stale label or add a comment saying that you would like to have the label removed otherwise this issue will automatically be closed in 14 days. Note, that you can always re-open a closed issue at any time.

@koffes
Copy link
Collaborator

koffes commented Oct 11, 2020

This is still an issue.
The following example has been compiled with:
CONFIG_NEWLIB_LIBC_FLOAT_PRINTF=y
CONFIG_NEWLIB_LIBC=y

float32_t val = 1.2345;
char buf[25];
sprintf(buf, "sprintf %f", val);
LOG_WRN("%s", log_strdup(buf)); //Yields: "sprintf 1.234500"
printk("printk %f\n", val); //Yields: "printk %f"
printf("printf %f\n", val); //Yields: "printf 1.234500" 
LOG_WRN("LOG_WRN %f", val); //Yields: "LOG_WRN %f"

If these configs are enabled the system should be able to print floating point numbers regardless of print method, If this is not feasible/desirable, there should be some ASSERT or warning when using %f or %e.

@koffes
Copy link
Collaborator

koffes commented Oct 11, 2020

@carlescufi can this issue be reopened?

@pabigot
Copy link
Collaborator

pabigot commented Oct 11, 2020

Yes. It shouldn't have been closed.

@pabigot
Copy link
Collaborator

pabigot commented Oct 27, 2020

The count is a simple scan for the number of conversion specifiers. It does not take into account length modifiers or the specifier character itself, and so is incorrect when any given argument exceeds the size of log_arg_t

This is something that might be addressed if we build a fully-functional Zephyr API for printf-style formatting with stream output, which is the subject of #29203 (comment).

@pabigot
Copy link
Collaborator

pabigot commented Nov 16, 2020

With cbprintf_arglen it should now be possible to fix this and all the other bugs related to passing 64-bit values for log formatting. @nordic-krch @carlescufi

@nordic-krch
Copy link
Contributor

@pabigot noted, i will take a look at that.

@github-actions
Copy link

This issue has been marked as stale because it has been open (more than) 60 days with no activity. Remove the stale label or add a comment saying that you would like to have the label removed otherwise this issue will automatically be closed in 14 days. Note, that you can always re-open a closed issue at any time.

@github-actions github-actions bot added the Stale label Jan 17, 2021
@deadsy
Copy link
Author

deadsy commented Jan 17, 2021

I'm running zephyr 2.4.0.
It still doesn't work.

@github-actions github-actions bot removed the Stale label Jan 18, 2021
@nordic-krch
Copy link
Contributor

yes, it will be addressed soon, see #30353.

@carlescufi carlescufi added this to the v2.6.0 milestone Feb 9, 2021
@github-actions
Copy link

This issue has been marked as stale because it has been open (more than) 60 days with no activity. Remove the stale label or add a comment saying that you would like to have the label removed otherwise this issue will automatically be closed in 14 days. Note, that you can always re-open a closed issue at any time.

@nordic-krch
Copy link
Contributor

floats can now be logged with new logging. Currently legacy version is the default one, so it has to be explicitly enabled (CONFIG_LOG2_MODE_DEFERRED).

@manoj153
Copy link
Contributor

manoj153 commented May 24, 2021

floats can now be logged with new logging. Currently legacy version is the default one, so it has to be explicitly enabled (CONFIG_LOG2_MODE_DEFERRED).

hi have tried setting CONFIG_LOG2_MODE_DEFERRED=y with the latest zephyr build and yet to print float types,
%f, is just printing out as "%f" , instead of given variable's value so if this makes sense this issue has to be re-open I think

@nordic-krch
Copy link
Contributor

@manoj153 please check if float formatting is enabled in cbprintf CBPRINTF_FP_SUPPORT.

@manoj153
Copy link
Contributor

manoj153 commented Aug 2, 2021

CBPRINTF_FP_SUPPORT

yes that helps. works now

simensrostad added a commit to simensrostad/fw-nrfconnect-nrf that referenced this issue Oct 7, 2021
Use deferred logging v2.

After the change to deferred logging, floats were not properly printed
anymore. This patch fixes this issue by using version 2 of deferred
logging.

Fix suggested in
zephyrproject-rtos/zephyr#18351 and
documented in
https://docs.zephyrproject.org/latest/reference/logging/index.html

Signed-off-by: Simen S. Røstad <simen.rostad@nordicsemi.no>
rlubos pushed a commit to nrfconnect/sdk-nrf that referenced this issue Oct 8, 2021
Use deferred logging v2.

After the change to deferred logging, floats were not properly printed
anymore. This patch fixes this issue by using version 2 of deferred
logging.

Fix suggested in
zephyrproject-rtos/zephyr#18351 and
documented in
https://docs.zephyrproject.org/latest/reference/logging/index.html

Signed-off-by: Simen S. Røstad <simen.rostad@nordicsemi.no>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area: Logging bug The issue is a bug, or the PR is fixing a bug priority: low Low impact/importance bug Stale
Projects
None yet
9 participants