Provide a might-sleep function to allow waiting for console printers
to catch up to the latest logged message.
Use pr_flush() whenever it is desirable to get buffered messages
printed before continuing: suspend_console(), resume_console(),
console_stop(), console_start(), console_unblank().
Signed-off-by: John Ogness <[email protected]>
---
include/linux/printk.h | 7 ++++
kernel/printk/printk.c | 83 ++++++++++++++++++++++++++++++++++++++++++
2 files changed, 90 insertions(+)
diff --git a/include/linux/printk.h b/include/linux/printk.h
index b70a42f94031..091fba7283e1 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -170,6 +170,8 @@ extern void __printk_safe_exit(void);
#define printk_deferred_enter __printk_safe_enter
#define printk_deferred_exit __printk_safe_exit
+extern bool pr_flush(int timeout_ms, bool reset_on_progress);
+
/*
* Please don't use printk_ratelimit(), because it shares ratelimiting state
* with all other unrelated printk_ratelimit() callsites. Instead use
@@ -220,6 +222,11 @@ static inline void printk_deferred_exit(void)
{
}
+static inline bool pr_flush(int timeout_ms, bool reset_on_progress)
+{
+ return true;
+}
+
static inline int printk_ratelimit(void)
{
return 0;
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 06f0b29d909d..d0369afaf365 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2274,6 +2274,8 @@ asmlinkage __visible int _printk(const char *fmt, ...)
}
EXPORT_SYMBOL(_printk);
+static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress);
+
#else /* CONFIG_PRINTK */
#define CONSOLE_LOG_MAX 0
@@ -2306,6 +2308,7 @@ static void call_console_driver(struct console *con, const char *text, size_t le
{
}
static bool suppress_message_printing(int level) { return false; }
+static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress) { return true; }
#endif /* CONFIG_PRINTK */
@@ -2493,6 +2496,7 @@ void suspend_console(void)
if (!console_suspend_enabled)
return;
pr_info("Suspending console(s) (use no_console_suspend to debug)\n");
+ pr_flush(1000, true);
console_lock();
console_suspended = 1;
up_console_sem();
@@ -2505,6 +2509,7 @@ void resume_console(void)
down_console_sem();
console_suspended = 0;
console_unlock();
+ pr_flush(1000, true);
}
/**
@@ -2882,6 +2887,9 @@ void console_unblank(void)
if ((c->flags & CON_ENABLED) && c->unblank)
c->unblank();
console_unlock();
+
+ if (!oops_in_progress)
+ pr_flush(1000, true);
}
/**
@@ -2940,6 +2948,7 @@ struct tty_driver *console_device(int *index)
*/
void console_stop(struct console *console)
{
+ __pr_flush(console, 1000, true);
console_lock();
console->flags &= ~CON_ENABLED;
console_unlock();
@@ -2951,6 +2960,7 @@ void console_start(struct console *console)
console_lock();
console->flags |= CON_ENABLED;
console_unlock();
+ __pr_flush(console, 1000, true);
}
EXPORT_SYMBOL(console_start);
@@ -3321,6 +3331,79 @@ static int __init printk_late_init(void)
late_initcall(printk_late_init);
#if defined CONFIG_PRINTK
+/* If @con is specified, only wait for that console. Otherwise wait for all. */
+static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress)
+{
+ int remaining = timeout_ms;
+ struct console *c;
+ u64 last_diff = 0;
+ u64 printk_seq;
+ u64 diff;
+ u64 seq;
+
+ might_sleep();
+
+ seq = prb_next_seq(prb);
+
+ for (;;) {
+ diff = 0;
+
+ console_lock();
+ for_each_console(c) {
+ if (con && con != c)
+ continue;
+ if (!console_is_usable(c))
+ continue;
+ printk_seq = c->seq;
+ if (printk_seq < seq)
+ diff += seq - printk_seq;
+ }
+ console_unlock();
+
+ if (diff != last_diff && reset_on_progress)
+ remaining = timeout_ms;
+
+ if (diff == 0 || remaining == 0)
+ break;
+
+ if (remaining < 0) {
+ /* no timeout limit */
+ msleep(100);
+ } else if (remaining < 100) {
+ msleep(remaining);
+ remaining = 0;
+ } else {
+ msleep(100);
+ remaining -= 100;
+ }
+
+ last_diff = diff;
+ }
+
+ return (diff == 0);
+}
+
+/**
+ * pr_flush() - Wait for printing threads to catch up.
+ *
+ * @timeout_ms: The maximum time (in ms) to wait.
+ * @reset_on_progress: Reset the timeout if forward progress is seen.
+ *
+ * A value of 0 for @timeout_ms means no waiting will occur. A value of -1
+ * represents infinite waiting.
+ *
+ * If @reset_on_progress is true, the timeout will be reset whenever any
+ * printer has been seen to make some forward progress.
+ *
+ * Context: Process context. May sleep while acquiring console lock.
+ * Return: true if all enabled printers are caught up.
+ */
+bool pr_flush(int timeout_ms, bool reset_on_progress)
+{
+ return __pr_flush(NULL, timeout_ms, reset_on_progress);
+}
+EXPORT_SYMBOL(pr_flush);
+
/*
* Delayed printk version, for scheduler-internal messages:
*/
--
2.30.2
On Tue 2022-04-05 15:31:31, John Ogness wrote:
> Provide a might-sleep function to allow waiting for console printers
> to catch up to the latest logged message.
>
> Use pr_flush() whenever it is desirable to get buffered messages
> printed before continuing: suspend_console(), resume_console(),
> console_stop(), console_start(), console_unblank().
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 06f0b29d909d..d0369afaf365 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3321,6 +3331,79 @@ static int __init printk_late_init(void)
> late_initcall(printk_late_init);
>
> #if defined CONFIG_PRINTK
> +/* If @con is specified, only wait for that console. Otherwise wait for all. */
> +static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress)
> +{
> + int remaining = timeout_ms;
> + struct console *c;
> + u64 last_diff = 0;
> + u64 printk_seq;
> + u64 diff;
> + u64 seq;
> +
> + might_sleep();
> +
> + seq = prb_next_seq(prb);
I auggest to add here:
/*
* Try to flush the messages when kthreads are not available
* and there is not other console lock owner.
*/
if (console_trylock())
console_unlock()
> +
> + for (;;) {
> + diff = 0;
> +
> + console_lock();
> + for_each_console(c) {
> + if (con && con != c)
> + continue;
> + if (!console_is_usable(c))
> + continue;
> + printk_seq = c->seq;
> + if (printk_seq < seq)
> + diff += seq - printk_seq;
> + }
> + console_unlock();
This is a bit sub-optimal when the kthreads are not available or
are disabled. In this case, the messages are flushed [*] by
the console_unlock() and the diff is outdated.
As a result, the code would non-necessarily sleep 100ms before
it realizes that the job is done.
One might argue that the problem will be only when there are
non-handled messages and in situations when the delay probably
is not critical.
Well, it is ugly to keep it this way. I suggest to add the extra
console_trylock()/unlock() at the beginning.
> +
> + if (diff != last_diff && reset_on_progress)
> + remaining = timeout_ms;
> +
> + if (diff == 0 || remaining == 0)
> + break;
> +
> + if (remaining < 0) {
> + /* no timeout limit */
> + msleep(100);
> + } else if (remaining < 100) {
> + msleep(remaining);
> + remaining = 0;
> + } else {
> + msleep(100);
> + remaining -= 100;
> + }
> +
> + last_diff = diff;
> + }
> +
> + return (diff == 0);
> +}
Otherwise, it looks good to me. It is an interesting function.
I wonder if it gets popular also outside printk code. ;-)
Best Regards,
Petr
On 2022-04-06, Petr Mladek <[email protected]> wrote:
>> @@ -3321,6 +3331,79 @@ static int __init printk_late_init(void)
>> late_initcall(printk_late_init);
>>
>> #if defined CONFIG_PRINTK
>> +/* If @con is specified, only wait for that console. Otherwise wait for all. */
>> +static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress)
>> +{
>> + int remaining = timeout_ms;
>> + struct console *c;
>> + u64 last_diff = 0;
>> + u64 printk_seq;
>> + u64 diff;
>> + u64 seq;
>> +
>> + might_sleep();
>> +
>> + seq = prb_next_seq(prb);
>
> I suggest to add here:
>
> /*
> * Try to flush the messages when kthreads are not available
> * and there is not other console lock owner.
> */
> if (console_trylock())
> console_unlock()
At this point in the series, we do not have kthreads yet. ;-)
And besides, you are implying that there are messages in the ringbuffer,
but _nobody_ is printing them. That would be a bug in our
implementation.
>> +
>> + for (;;) {
>> + diff = 0;
>> +
>> + console_lock();
>> + for_each_console(c) {
>> + if (con && con != c)
>> + continue;
>> + if (!console_is_usable(c))
>> + continue;
>> + printk_seq = c->seq;
>> + if (printk_seq < seq)
>> + diff += seq - printk_seq;
>> + }
>> + console_unlock();
>
> This is a bit sub-optimal when the kthreads are not available or
> are disabled. In this case, the messages are flushed [*] by
> the console_unlock() and the diff is outdated.
The messages must be flushed by another context. It is wrong to rely on
this context to do the flushing. In direct mode, those messages should
have been flushed before the above console_lock() succeeded. Otherwise
it is a bug. (For threaded mode, console_unlock() does not flush
anyway.)
> Well, it is ugly to keep it this way.
If you don't mind, I will not change this function for v3. I do not want
to start sprinkling console_trylock()/console_unlock() calls all over
the code to cover up possible bugs and races in the implementation.
John