Skip to content

Conversation

cfriedt
Copy link
Member

@cfriedt cfriedt commented Oct 15, 2023

Many releases ago, specifying to block indefinitely in the log processing thread would do just that.

However, a subtle bug was introduced such that specifying -1 for CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS would have the exact opposite effect than what was intended.

As per Kconfig, a value of -1 should translate to a timeout of K_FOREVER. However, conversion via K_MSEC(-1) results in a k_timeout_t that is equal to K_NO_WAIT.

Add a dedicated check to to ensure that a value of -1 is correctly interpreted as K_FOREVER in log_core.c.

For reference, the blocking feature was described in #15196, added in #16194, and it would appear that the regression happened in c5f2cde.

Fixes #63965

@cfriedt cfriedt force-pushed the log-mode-block-in-thread branch 2 times, most recently from 1021133 to 440b747 Compare October 15, 2023 14:29
Many releases ago, specifying to block indefinitely in the log
processing thread would do just that.

However, a subtle bug was introduced  such that specifying -1
for `CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS` would have the
exact opposite effect than what was intended.

As per Kconfig, a value of -1 should translate to a timeout of
`K_FOREVER`. However, conversion via `K_MSEC(-1)` results in
a `k_timeout_t` that is equal to `K_NO_WAIT` rather than the
intent which is `K_FOREVER`.

Add a dedicated check to to ensure that a value of -1 is
correctly interpreted as `K_FOREVER` in `log_core.c`.

For reference, the blocking feature was described in zephyrproject-rtos#15196,
added in zephyrproject-rtos#16194, and it would appear that the regression
happened in c5f2cde.

Signed-off-by: Christopher Friedt <cfriedt@meta.com>
@cfriedt cfriedt force-pushed the log-mode-block-in-thread branch from 440b747 to 6fc1d5a Compare October 15, 2023 14:29
@cfriedt
Copy link
Member Author

cfriedt commented Oct 15, 2023

Assertions that can demonstrate the issue above

__ASSERT_NO_MSG(K_TIMEOUT_EQ(K_NO_WAIT, K_MSEC(-1)));
__ASSERT_NO_MSG(!K_TIMEOUT_EQ(K_FOREVER, K_MSEC(-1)));

@cfriedt cfriedt marked this pull request as ready for review October 15, 2023 17:16
@cfriedt cfriedt requested a review from nordic-krch as a code owner October 15, 2023 17:16
@zephyrbot zephyrbot requested a review from dcpleung October 15, 2023 17:17
@cfriedt cfriedt requested review from jgl-meta, luchnikov, ycsin, fabiobaltieri and jhedberg and removed request for dcpleung October 15, 2023 17:17
@cfriedt cfriedt added bug The issue is a bug, or the PR is fixing a bug Regression Something, which was working, does not anymore priority: medium Medium impact/importance bug labels Oct 15, 2023
@cfriedt cfriedt added this to the v3.5.0 milestone Oct 15, 2023
K_MSEC(CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS));
return (struct log_msg *)mpsc_pbuf_alloc(
buffer, wlen,
(CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS == -1)
Copy link
Member Author

@cfriedt cfriedt Oct 15, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A future enhancement would be to generalize this for any timeout value < 0.

Copy link
Member

@ycsin ycsin left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

good catch!

@carlescufi carlescufi merged commit 137097f into zephyrproject-rtos:main Oct 16, 2023
@cfriedt cfriedt deleted the log-mode-block-in-thread branch October 16, 2023 10:32
@henrikbrixandersen
Copy link
Member

Shouldn't this be backported?

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: medium Medium impact/importance bug Regression Something, which was working, does not anymore
Projects
None yet
Development

Successfully merging this pull request may close these issues.

logging: log_core: regression in handling of CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS
7 participants