2024-06-03 23:25:26

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 00/18] add threaded printing + the rest

Hi,

This is v2 of a series to implement threaded console printing as well
as some other minor pieces (such as proc and sysfs support). This
series is only a subset of the original v1 [0]. In particular, this
series represents patches 11, 12, 15 of the v1 series. For information
about the motivation of the nbcon consoles, please read the cover
letter of v1.

This series provides the remaining pieces of the printk rework. All
other components are either already mainline or are currently in
linux-next. In particular this series does:

- Implement dedicated printing threads per nbcon console.

- Implement "threadprintk" boot argument to force threading of legacy
consoles.

- Implement nbcon support for proc and sysfs console-related files.

- Provide a new helper function nbcon_reacquire() to allow nbcon
console drivers to reacquire ownership.

Note that this series does *not* provide an nbcon console driver. That
will come in a follow-up series.

Also note that the first 3 patches of the series are either already
mainline or are queued for 6.11. They are included in this series for
completeness when applied to the printk for-next branch.

Much has changed since v1 and the patches no longer correlate
1:1. Here is an attempt to list the changes:

- Implement a special dedicated thread to force threading of legacy
console drivers.

- Add "threadprintk" boot argument to force threading of legacy
console drivers. (For PREEMPT_RT, this is automatically enabled.)

- Add sparse notation for console_srcu_read_lock/unlock().

- Define a dedicated wait queue for the legacy thread.

- Stop threads on shutdown/reboot for a clean transition to atomic
printing.

- Print a replay message when a higher priority printer context takes
over another printer context.

- Reset lockdep context for legacy printing on !PREEMPT_RT to avoid
false positive lockdep splats.

- Use write_thread() callback if printing from console_flush_all() and
@do_cond_resched is 1.

- Do not allocate separate pbufs for printing threads. Use the same
pbufs that the atomic printer uses.

- Wake printing threads without considering nbcon lock state.

- Implement rcuwait_has_sleeper() to check for waiting tasks instead
of using a custom atomic variable @kthread_waiting.

John Ogness

[0] https://lore.kernel.org/lkml/[email protected]

John Ogness (13):
printk: Atomic print in printk context on shutdown
printk: nbcon: Add context to console_is_usable()
printk: nbcon: Stop threads on shutdown/reboot
printk: nbcon: Start printing threads
printk: Provide helper for message prepending
printk: nbcon: Show replay message on takeover
printk: Add kthread for all legacy consoles
proc: consoles: Add notation to c_start/c_stop
proc: Add nbcon support for /proc/consoles
tty: sysfs: Add nbcon support for 'active'
printk: Provide threadprintk boot argument
printk: Avoid false positive lockdep report for legacy printing
printk: nbcon: Add function for printers to reacquire ownership

Sreenath Vijayan (3):
printk: Add function to replay kernel log on consoles
tty/sysrq: Replay kernel log messages on consoles via sysrq
printk: Rename console_replay_all() and update context

Thomas Gleixner (2):
printk: nbcon: Introduce printing kthreads
printk: nbcon: Add printer thread wakeups

.../admin-guide/kernel-parameters.txt | 12 +
Documentation/admin-guide/sysrq.rst | 9 +
drivers/tty/sysrq.c | 13 +-
drivers/tty/tty_io.c | 9 +-
fs/proc/consoles.c | 16 +-
include/linux/console.h | 38 ++
include/linux/printk.h | 6 +-
kernel/printk/internal.h | 55 +-
kernel/printk/nbcon.c | 421 ++++++++++++++-
kernel/printk/printk.c | 482 +++++++++++++++---
10 files changed, 945 insertions(+), 116 deletions(-)


base-commit: f3760c80d06a838495185c0fe341c043e6495142
--
2.39.2



2024-06-03 23:25:27

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 02/18] tty/sysrq: Replay kernel log messages on consoles via sysrq

From: Sreenath Vijayan <[email protected]>

When terminal is unresponsive, one cannot use dmesg to view
the printk ring buffer messages. Also, syslog services may be
disabled, especially on embedded systems, to check the messages
after a reboot. In this scenario, replay the messages in printk
ring buffer on consoles via sysrq by pressing sysrq+R.

The console loglevel will determine which all kernel log messages
are displayed. The messages will be displayed only when
console_trylock() succeeds. Users could repeat the sysrq key when
it fails. If the owner of console subsystem lock is stuck,
repeating the key won't work.

Suggested-by: Petr Mladek <[email protected]>
Signed-off-by: Shimoyashiki Taichi <[email protected]>
Reviewed-by: John Ogness <[email protected]>
Signed-off-by: Sreenath Vijayan <[email protected]>
Link: https://lore.kernel.org/r/cc3b9b1aae60a236c6aed1dc7b0ffa2c7cd1f183.1710220326.git.sreenath.vijayan@sony.com
Signed-off-by: Greg Kroah-Hartman <[email protected]>
---
Documentation/admin-guide/sysrq.rst | 9 +++++++++
drivers/tty/sysrq.c | 13 ++++++++++++-
2 files changed, 21 insertions(+), 1 deletion(-)

diff --git a/Documentation/admin-guide/sysrq.rst b/Documentation/admin-guide/sysrq.rst
index 2f2e5bd440f9..a85b3384d1e7 100644
--- a/Documentation/admin-guide/sysrq.rst
+++ b/Documentation/admin-guide/sysrq.rst
@@ -161,6 +161,8 @@ Command Function
will be printed to your console. (``0``, for example would make
it so that only emergency messages like PANICs or OOPSes would
make it to your console.)
+
+``R`` Replay the kernel log messages on consoles.
=========== ===================================================================

Okay, so what can I use them for?
@@ -211,6 +213,13 @@ processes.
"just thaw ``it(j)``" is useful if your system becomes unresponsive due to a
frozen (probably root) filesystem via the FIFREEZE ioctl.

+``Replay logs(R)`` is useful to view the kernel log messages when system is hung
+or you are not able to use dmesg command to view the messages in printk buffer.
+User may have to press the key combination multiple times if console system is
+busy. If it is completely locked up, then messages won't be printed. Output
+messages depend on current console loglevel, which can be modified using
+sysrq[0-9] (see above).
+
Sometimes SysRq seems to get 'stuck' after using it, what can I do?
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index 02217e3c916b..e5974b8239c9 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -450,6 +450,17 @@ static const struct sysrq_key_op sysrq_unrt_op = {
.enable_mask = SYSRQ_ENABLE_RTNICE,
};

+static void sysrq_handle_replay_logs(u8 key)
+{
+ console_replay_all();
+}
+static struct sysrq_key_op sysrq_replay_logs_op = {
+ .handler = sysrq_handle_replay_logs,
+ .help_msg = "replay-kernel-logs(R)",
+ .action_msg = "Replay kernel logs on consoles",
+ .enable_mask = SYSRQ_ENABLE_DUMP,
+};
+
/* Key Operations table and lock */
static DEFINE_SPINLOCK(sysrq_key_table_lock);

@@ -519,7 +530,7 @@ static const struct sysrq_key_op *sysrq_key_table[62] = {
NULL, /* O */
NULL, /* P */
NULL, /* Q */
- NULL, /* R */
+ &sysrq_replay_logs_op, /* R */
NULL, /* S */
NULL, /* T */
NULL, /* U */
--
2.39.2


2024-06-03 23:25:27

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 01/18] printk: Add function to replay kernel log on consoles

From: Sreenath Vijayan <[email protected]>

Add a generic function console_replay_all() for replaying
the kernel log on consoles, in any context. It would allow
viewing the logs on an unresponsive terminal via sysrq.

Reuse the existing code from console_flush_on_panic() for
resetting the sequence numbers, by introducing a new helper
function __console_rewind_all(). It is safe to be called
under console_lock().

Try to acquire lock on the console subsystem without waiting.
If successful, reset the sequence number to oldest available
record on all consoles and call console_unlock() which will
automatically flush the messages to the consoles.

Suggested-by: John Ogness <[email protected]>
Suggested-by: Petr Mladek <[email protected]>
Signed-off-by: Shimoyashiki Taichi <[email protected]>
Reviewed-by: John Ogness <[email protected]>
Signed-off-by: Sreenath Vijayan <[email protected]>
Link: https://lore.kernel.org/r/90ee131c643a5033d117b556c0792de65129d4c3.1710220326.git.sreenath.vijayan@sony.com
Signed-off-by: Greg Kroah-Hartman <[email protected]>
---
include/linux/printk.h | 6 +++-
kernel/printk/printk.c | 77 +++++++++++++++++++++++++++++-------------
2 files changed, 58 insertions(+), 25 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index 69f40a71c438..784d2298f4cf 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -195,6 +195,7 @@ void show_regs_print_info(const char *log_lvl);
extern asmlinkage void dump_stack_lvl(const char *log_lvl) __cold;
extern asmlinkage void dump_stack(void) __cold;
void printk_trigger_flush(void);
+void console_replay_all(void);
void printk_legacy_allow_panic_sync(void);
extern bool nbcon_device_try_acquire(struct console *con);
extern void nbcon_device_release(struct console *con);
@@ -279,6 +280,10 @@ static inline void printk_trigger_flush(void)
{
}

+static inline void console_replay_all(void)
+{
+}
+
static inline void printk_legacy_allow_panic_sync(void)
{
}
@@ -295,7 +300,6 @@ static inline void nbcon_device_release(struct console *con)
static inline void nbcon_atomic_flush_unsafe(void)
{
}
-
#endif

bool this_cpu_in_panic(void);
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index b4a202591e06..b3fe1b6d7dbd 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3201,6 +3201,40 @@ void console_unblank(void)
pr_flush(1000, true);
}

+/*
+ * Rewind all consoles to the oldest available record.
+ *
+ * IMPORTANT: The function is safe only when called under
+ * console_lock(). It is not enforced because
+ * it is used as a best effort in panic().
+ */
+static void __console_rewind_all(void)
+{
+ struct console *c;
+ short flags;
+ int cookie;
+ u64 seq;
+
+ seq = prb_first_valid_seq(prb);
+
+ cookie = console_srcu_read_lock();
+ for_each_console_srcu(c) {
+ flags = console_srcu_read_flags(c);
+
+ if (flags & CON_NBCON) {
+ nbcon_seq_force(c, seq);
+ } else {
+ /*
+ * This assignment is safe only when called under
+ * console_lock(). On panic, legacy consoles are
+ * only best effort.
+ */
+ c->seq = seq;
+ }
+ }
+ console_srcu_read_unlock(cookie);
+}
+
/**
* console_flush_on_panic - flush console content on panic
* @mode: flush all messages in buffer or just the pending ones
@@ -3229,30 +3263,8 @@ void console_flush_on_panic(enum con_flush_mode mode)
*/
console_may_schedule = 0;

- if (mode == CONSOLE_REPLAY_ALL) {
- struct console *c;
- short flags;
- int cookie;
- u64 seq;
-
- seq = prb_first_valid_seq(prb);
-
- cookie = console_srcu_read_lock();
- for_each_console_srcu(c) {
- flags = console_srcu_read_flags(c);
-
- if (flags & CON_NBCON) {
- nbcon_seq_force(c, seq);
- } else {
- /*
- * This is an unsynchronized assignment. On
- * panic legacy consoles are only best effort.
- */
- c->seq = seq;
- }
- }
- console_srcu_read_unlock(cookie);
- }
+ if (mode == CONSOLE_REPLAY_ALL)
+ __console_rewind_all();

nbcon_atomic_flush_pending();

@@ -4447,6 +4459,23 @@ void kmsg_dump_rewind(struct kmsg_dump_iter *iter)
}
EXPORT_SYMBOL_GPL(kmsg_dump_rewind);

+/**
+ * console_replay_all - replay kernel log on consoles
+ *
+ * Try to obtain lock on console subsystem and replay all
+ * available records in printk buffer on the consoles.
+ * Does nothing if lock is not obtained.
+ *
+ * Context: Any context.
+ */
+void console_replay_all(void)
+{
+ if (console_trylock()) {
+ __console_rewind_all();
+ /* Consoles are flushed as part of console_unlock(). */
+ console_unlock();
+ }
+}
#endif

#ifdef CONFIG_SMP
--
2.39.2


2024-06-03 23:25:38

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 03/18] printk: Rename console_replay_all() and update context

From: Sreenath Vijayan <[email protected]>

Rename console_replay_all() to console_try_replay_all() to make
clear that the implementation is best effort. Also, the function
should not be called in NMI context as it takes locks, so update
the comment in code.

Fixes: 693f75b91a91 ("printk: Add function to replay kernel log on consoles")
Fixes: 1b743485e27f ("tty/sysrq: Replay kernel log messages on consoles via sysrq")
Suggested-by: Petr Mladek <[email protected]>
Signed-off-by: Shimoyashiki Taichi <[email protected]>
Signed-off-by: Sreenath Vijayan <[email protected]>
Link: https://lore.kernel.org/r/Zlguq/[email protected]@sony.com
Reviewed-by: Petr Mladek <[email protected]>
Signed-off-by: Petr Mladek <[email protected]>
---
drivers/tty/sysrq.c | 2 +-
include/linux/printk.h | 4 ++--
kernel/printk/printk.c | 6 +++---
3 files changed, 6 insertions(+), 6 deletions(-)

diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index e5974b8239c9..53f8c2329c30 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -452,7 +452,7 @@ static const struct sysrq_key_op sysrq_unrt_op = {

static void sysrq_handle_replay_logs(u8 key)
{
- console_replay_all();
+ console_try_replay_all();
}
static struct sysrq_key_op sysrq_replay_logs_op = {
.handler = sysrq_handle_replay_logs,
diff --git a/include/linux/printk.h b/include/linux/printk.h
index 784d2298f4cf..20e1942f63ae 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -195,7 +195,7 @@ void show_regs_print_info(const char *log_lvl);
extern asmlinkage void dump_stack_lvl(const char *log_lvl) __cold;
extern asmlinkage void dump_stack(void) __cold;
void printk_trigger_flush(void);
-void console_replay_all(void);
+void console_try_replay_all(void);
void printk_legacy_allow_panic_sync(void);
extern bool nbcon_device_try_acquire(struct console *con);
extern void nbcon_device_release(struct console *con);
@@ -280,7 +280,7 @@ static inline void printk_trigger_flush(void)
{
}

-static inline void console_replay_all(void)
+static inline void console_try_replay_all(void)
{
}

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index b3fe1b6d7dbd..5dcc05e1aa56 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -4460,15 +4460,15 @@ void kmsg_dump_rewind(struct kmsg_dump_iter *iter)
EXPORT_SYMBOL_GPL(kmsg_dump_rewind);

/**
- * console_replay_all - replay kernel log on consoles
+ * console_try_replay_all - try to replay kernel log on consoles
*
* Try to obtain lock on console subsystem and replay all
* available records in printk buffer on the consoles.
* Does nothing if lock is not obtained.
*
- * Context: Any context.
+ * Context: Any, except for NMI.
*/
-void console_replay_all(void)
+void console_try_replay_all(void)
{
if (console_trylock()) {
__console_rewind_all();
--
2.39.2


2024-06-03 23:26:01

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

From: Thomas Gleixner <[email protected]>

Provide the main implementation for running a printer kthread
per nbcon console that is takeover/handover aware.

Co-developed-by: John Ogness <[email protected]>
Signed-off-by: John Ogness <[email protected]>
Signed-off-by: Thomas Gleixner (Intel) <[email protected]>
---
include/linux/console.h | 26 ++++++
kernel/printk/internal.h | 26 ++++++
kernel/printk/nbcon.c | 196 +++++++++++++++++++++++++++++++++++++--
kernel/printk/printk.c | 34 +++++++
4 files changed, 275 insertions(+), 7 deletions(-)

diff --git a/include/linux/console.h b/include/linux/console.h
index 4aaf053840ee..4de42ec1527c 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -17,6 +17,7 @@
#include <linux/atomic.h>
#include <linux/bits.h>
#include <linux/rculist.h>
+#include <linux/rcuwait.h>
#include <linux/types.h>
#include <linux/vesa.h>

@@ -324,6 +325,8 @@ struct nbcon_write_context {
* @nbcon_seq: Sequence number of the next record for nbcon to print
* @nbcon_device_ctxt: Context available for non-printing operations
* @pbufs: Pointer to nbcon private buffer
+ * @kthread: Printer kthread for this console
+ * @rcuwait: RCU-safe wait object for @kthread waking
*/
struct console {
char name[16];
@@ -373,6 +376,27 @@ struct console {
*/
void (*write_atomic)(struct console *con, struct nbcon_write_context *wctxt);

+ /**
+ * @write_thread:
+ *
+ * NBCON callback to write out text in task context.
+ *
+ * This callback is called after device_lock() and with the nbcon
+ * console acquired. Any necessary driver synchronization should have
+ * been performed by the device_lock() callback.
+ *
+ * This callback is always called from task context but with migration
+ * disabled.
+ *
+ * The same criteria for console ownership verification and unsafe
+ * sections applies as with write_atomic(). The difference between
+ * this callback and write_atomic() is that this callback is used
+ * during normal operation and is always called from task context.
+ * This allows drivers to operate in their own locking context for
+ * synchronizing output to the hardware.
+ */
+ void (*write_thread)(struct console *con, struct nbcon_write_context *wctxt);
+
/**
* @device_lock:
*
@@ -420,6 +444,8 @@ struct console {
atomic_long_t __private nbcon_seq;
struct nbcon_context __private nbcon_device_ctxt;
struct printk_buffers *pbufs;
+ struct task_struct *kthread;
+ struct rcuwait rcuwait;
};

#ifdef CONFIG_LOCKDEP
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 0439cf2fdc22..38680c6b2b39 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -92,6 +92,7 @@ enum nbcon_prio nbcon_get_default_prio(void);
void nbcon_atomic_flush_pending(void);
bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
int cookie);
+void nbcon_kthread_create(struct console *con);

/*
* Check if the given console is currently capable and allowed to print
@@ -110,6 +111,8 @@ static inline bool console_is_usable(struct console *con, short flags)
if (flags & CON_NBCON) {
if (!con->write_atomic)
return false;
+ if (!con->write_thread)
+ return false;
} else {
if (!con->write)
return false;
@@ -126,12 +129,35 @@ static inline bool console_is_usable(struct console *con, short flags)
return true;
}

+/**
+ * nbcon_kthread_wake - Wake up a printk thread
+ * @con: Console to operate on
+ */
+static inline void nbcon_kthread_wake(struct console *con)
+{
+ /*
+ * Guarantee any new records can be seen by tasks preparing to wait
+ * before this context checks if the rcuwait is empty.
+ *
+ * The full memory barrier in rcuwait_wake_up() pairs with the full
+ * memory barrier within set_current_state() of
+ * ___rcuwait_wait_event(), which is called after prepare_to_rcuwait()
+ * adds the waiter but before it has checked the wait condition.
+ *
+ * This pairs with nbcon_kthread_func:A.
+ */
+ rcuwait_wake_up(&con->rcuwait); /* LMM(nbcon_kthread_wake:A) */
+}
+
#else

#define PRINTK_PREFIX_MAX 0
#define PRINTK_MESSAGE_MAX 0
#define PRINTKRB_RECORD_MAX 0

+static inline void nbcon_kthread_wake(struct console *con) { }
+static inline void nbcon_kthread_create(struct console *con) { }
+
/*
* In !PRINTK builds we still export console_sem
* semaphore and some of console functions (console_unlock()/etc.), so
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 6e9e24aa0a7f..89b340ca303c 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -10,6 +10,7 @@
#include <linux/export.h>
#include <linux/init.h>
#include <linux/irqflags.h>
+#include <linux/kthread.h>
#include <linux/minmax.h>
#include <linux/percpu.h>
#include <linux/preempt.h>
@@ -837,6 +838,7 @@ EXPORT_SYMBOL_GPL(nbcon_exit_unsafe);
/**
* nbcon_emit_next_record - Emit a record in the acquired context
* @wctxt: The write context that will be handed to the write function
+ * @use_atomic: True if the write_atomic() callback is to be used
*
* Return: True if this context still owns the console. False if
* ownership was handed over or taken.
@@ -850,7 +852,7 @@ EXPORT_SYMBOL_GPL(nbcon_exit_unsafe);
* When true is returned, @wctxt->ctxt.backlog indicates whether there are
* still records pending in the ringbuffer,
*/
-static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt)
+static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt, bool use_atomic)
{
struct nbcon_context *ctxt = &ACCESS_PRIVATE(wctxt, ctxt);
struct console *con = ctxt->console;
@@ -899,8 +901,14 @@ static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt)
nbcon_state_read(con, &cur);
wctxt->unsafe_takeover = cur.unsafe_takeover;

- if (con->write_atomic) {
+ if (use_atomic &&
+ con->write_atomic) {
con->write_atomic(con, wctxt);
+
+ } else if (!use_atomic &&
+ con->write_thread) {
+ con->write_thread(con, wctxt);
+
} else {
/*
* This function should never be called for legacy consoles.
@@ -936,6 +944,120 @@ static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt)
return nbcon_context_exit_unsafe(ctxt);
}

+/**
+ * nbcon_kthread_should_wakeup - Check whether a printer thread should wakeup
+ * @con: Console to operate on
+ * @ctxt: The nbcon context from nbcon_context_try_acquire()
+ *
+ * Return: True if the thread should shutdown or if the console is
+ * allowed to print and a record is available. False otherwise.
+ *
+ * After the thread wakes up, it must first check if it should shutdown before
+ * attempting any printing.
+ */
+static bool nbcon_kthread_should_wakeup(struct console *con, struct nbcon_context *ctxt)
+{
+ bool ret = false;
+ short flags;
+ int cookie;
+
+ if (kthread_should_stop())
+ return true;
+
+ cookie = console_srcu_read_lock();
+
+ flags = console_srcu_read_flags(con);
+ if (console_is_usable(con, flags)) {
+ /* Bring the sequence in @ctxt up to date */
+ ctxt->seq = nbcon_seq_read(con);
+
+ ret = prb_read_valid(prb, ctxt->seq, NULL);
+ }
+
+ console_srcu_read_unlock(cookie);
+ return ret;
+}
+
+/**
+ * nbcon_kthread_func - The printer thread function
+ * @__console: Console to operate on
+ *
+ * Return: 0
+ */
+static int nbcon_kthread_func(void *__console)
+{
+ struct console *con = __console;
+ struct nbcon_write_context wctxt = {
+ .ctxt.console = con,
+ .ctxt.prio = NBCON_PRIO_NORMAL,
+ };
+ struct nbcon_context *ctxt = &ACCESS_PRIVATE(&wctxt, ctxt);
+ short con_flags;
+ bool backlog;
+ int cookie;
+ int ret;
+
+wait_for_event:
+ /*
+ * Guarantee this task is visible on the rcuwait before
+ * checking the wake condition.
+ *
+ * The full memory barrier within set_current_state() of
+ * ___rcuwait_wait_event() pairs with the full memory
+ * barrier within rcuwait_has_sleeper().
+ *
+ * This pairs with rcuwait_has_sleeper:A and nbcon_kthread_wake:A.
+ */
+ ret = rcuwait_wait_event(&con->rcuwait,
+ nbcon_kthread_should_wakeup(con, ctxt),
+ TASK_INTERRUPTIBLE); /* LMM(nbcon_kthread_func:A) */
+
+ if (kthread_should_stop())
+ return 0;
+
+ /* Wait was interrupted by a spurious signal, go back to sleep. */
+ if (ret)
+ goto wait_for_event;
+
+ do {
+ backlog = false;
+
+ cookie = console_srcu_read_lock();
+
+ con_flags = console_srcu_read_flags(con);
+
+ if (console_is_usable(con, con_flags)) {
+ unsigned long lock_flags;
+
+ con->device_lock(con, &lock_flags);
+
+ /*
+ * Ensure this stays on the CPU to make handover and
+ * takeover possible.
+ */
+ cant_migrate();
+
+ if (nbcon_context_try_acquire(ctxt)) {
+ /*
+ * If the emit fails, this context is no
+ * longer the owner.
+ */
+ if (nbcon_emit_next_record(&wctxt, false)) {
+ nbcon_context_release(ctxt);
+ backlog = ctxt->backlog;
+ }
+ }
+
+ con->device_unlock(con, lock_flags);
+ }
+
+ console_srcu_read_unlock(cookie);
+
+ } while (backlog);
+
+ goto wait_for_event;
+}
+
/* Track the nbcon emergency nesting per CPU. */
static DEFINE_PER_CPU(unsigned int, nbcon_pcpu_emergency_nesting);
static unsigned int early_nbcon_pcpu_emergency_nesting __initdata;
@@ -1012,7 +1134,7 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
* The higher priority printing context takes over responsibility
* to print the pending records.
*/
- if (!nbcon_emit_next_record(wctxt))
+ if (!nbcon_emit_next_record(wctxt, true))
return false;

nbcon_context_release(ctxt);
@@ -1113,7 +1235,7 @@ static int __nbcon_atomic_flush_pending_con(struct console *con, u64 stop_seq,
* handed over or taken over. In both cases the context is no
* longer valid.
*/
- if (!nbcon_emit_next_record(&wctxt))
+ if (!nbcon_emit_next_record(&wctxt, true))
return -EAGAIN;

if (!ctxt->backlog) {
@@ -1172,10 +1294,10 @@ static void nbcon_atomic_flush_pending_con(struct console *con, u64 stop_seq,

/*
* If flushing was successful but more records are available, this
- * context must flush those remaining records because there is no
- * other context that will do it.
+ * context must flush those remaining records if the printer thread
+ * is not available do it.
*/
- if (prb_read_valid(prb, nbcon_seq_read(con), NULL)) {
+ if (!con->kthread && prb_read_valid(prb, nbcon_seq_read(con), NULL)) {
stop_seq = prb_next_reserve_seq(prb);
goto again;
}
@@ -1332,6 +1454,63 @@ void nbcon_cpu_emergency_flush(void)
}
}

+/*
+ * nbcon_kthread_stop - Stop a printer thread
+ * @con: Console to operate on
+ */
+static void nbcon_kthread_stop(struct console *con)
+{
+ lockdep_assert_console_list_lock_held();
+
+ if (!con->kthread)
+ return;
+
+ kthread_stop(con->kthread);
+ con->kthread = NULL;
+}
+
+/**
+ * nbcon_kthread_create - Create a printer thread
+ * @con: Console to operate on
+ *
+ * If it fails, let the console proceed. The atomic part might
+ * be usable and useful.
+ */
+void nbcon_kthread_create(struct console *con)
+{
+ struct task_struct *kt;
+
+ lockdep_assert_console_list_lock_held();
+
+ if (!(con->flags & CON_NBCON) || !con->write_thread)
+ return;
+
+ if (con->kthread)
+ return;
+
+ /*
+ * Printer threads cannot be started as long as any boot console is
+ * registered because there is no way to synchronize the hardware
+ * registers between boot console code and regular console code.
+ */
+ if (have_boot_console)
+ return;
+
+ kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name, con->index);
+ if (IS_ERR(kt)) {
+ con_printk(KERN_ERR, con, "failed to start printing thread\n");
+ return;
+ }
+
+ con->kthread = kt;
+
+ /*
+ * It is important that console printing threads are scheduled
+ * shortly after a printk call and with generous runtime budgets.
+ */
+ sched_set_normal(con->kthread, -20);
+}
+
/**
* nbcon_alloc - Allocate buffers needed by the nbcon console
* @con: Console to allocate buffers for
@@ -1377,6 +1556,7 @@ void nbcon_init(struct console *con, u64 init_seq)
/* nbcon_alloc() must have been called and successful! */
BUG_ON(!con->pbufs);

+ rcuwait_init(&con->rcuwait);
nbcon_seq_force(con, init_seq);
nbcon_state_set(con, &state);
}
@@ -1389,6 +1569,7 @@ void nbcon_free(struct console *con)
{
struct nbcon_state state = { };

+ nbcon_kthread_stop(con);
nbcon_state_set(con, &state);

/* Boot consoles share global printk buffers. */
@@ -1458,6 +1639,7 @@ void nbcon_device_release(struct console *con)
*/
cookie = console_srcu_read_lock();
if (console_is_usable(con, console_srcu_read_flags(con)) &&
+ !con->kthread &&
prb_read_valid(prb, nbcon_seq_read(con), NULL)) {
__nbcon_atomic_flush_pending_con(con, prb_next_reserve_seq(prb), false);
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 5dcc05e1aa56..137bd9a721c4 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2685,6 +2685,8 @@ void suspend_console(void)
void resume_console(void)
{
struct console *con;
+ short flags;
+ int cookie;

if (!console_suspend_enabled)
return;
@@ -2701,6 +2703,14 @@ void resume_console(void)
*/
synchronize_srcu(&console_srcu);

+ cookie = console_srcu_read_lock();
+ for_each_console_srcu(con) {
+ flags = console_srcu_read_flags(con);
+ if (flags & CON_NBCON)
+ nbcon_kthread_wake(con);
+ }
+ console_srcu_read_unlock(cookie);
+
pr_flush(1000, true);
}

@@ -3021,6 +3031,13 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
u64 printk_seq;
bool progress;

+ /*
+ * console_flush_all() is only for legacy consoles,
+ * unless the nbcon console has no kthread printer.
+ */
+ if ((flags & CON_NBCON) && con->kthread)
+ continue;
+
if (!console_is_usable(con, flags))
continue;
any_usable = true;
@@ -3326,9 +3343,26 @@ EXPORT_SYMBOL(console_stop);

void console_start(struct console *console)
{
+ short flags;
+ int cookie;
+
console_list_lock();
console_srcu_write_flags(console, console->flags | CON_ENABLED);
console_list_unlock();
+
+ /*
+ * Ensure that all SRCU list walks have completed. The related
+ * printing context must be able to see it is enabled so that
+ * it is guaranteed to wake up and resume printing.
+ */
+ synchronize_srcu(&console_srcu);
+
+ cookie = console_srcu_read_lock();
+ flags = console_srcu_read_flags(console);
+ if (flags & CON_NBCON)
+ nbcon_kthread_wake(console);
+ console_srcu_read_unlock(cookie);
+
__pr_flush(console, 1000, true);
}
EXPORT_SYMBOL(console_start);
--
2.39.2


2024-06-03 23:26:31

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 06/18] printk: nbcon: Add context to console_is_usable()

The nbcon consoles have two callbacks to be used for different
contexts. In order to determine if an nbcon console is usable,
console_is_usable() needs to know if it is a context that will
use the write_atomic() callback or the write_thread() callback.

Add an extra parameter @use_atomic to specify this.

Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/internal.h | 16 ++++++++++------
kernel/printk/nbcon.c | 8 ++++----
kernel/printk/printk.c | 6 ++++--
3 files changed, 18 insertions(+), 12 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 38680c6b2b39..243d3d3bc889 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -100,7 +100,7 @@ void nbcon_kthread_create(struct console *con);
* which can also play a role in deciding if @con can be used to print
* records.
*/
-static inline bool console_is_usable(struct console *con, short flags)
+static inline bool console_is_usable(struct console *con, short flags, bool use_atomic)
{
if (!(flags & CON_ENABLED))
return false;
@@ -109,10 +109,13 @@ static inline bool console_is_usable(struct console *con, short flags)
return false;

if (flags & CON_NBCON) {
- if (!con->write_atomic)
- return false;
- if (!con->write_thread)
- return false;
+ if (use_atomic) {
+ if (!con->write_atomic)
+ return false;
+ } else {
+ if (!con->write_thread)
+ return false;
+ }
} else {
if (!con->write)
return false;
@@ -177,7 +180,8 @@ static inline void nbcon_atomic_flush_pending(void) { }
static inline bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
int cookie) { return false; }

-static inline bool console_is_usable(struct console *con, short flags) { return false; }
+static inline bool console_is_usable(struct console *con, short flags,
+ bool use_atomic) { return false; }

#endif /* CONFIG_PRINTK */

diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 19f0db6945e4..4200953d368e 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -967,7 +967,7 @@ static bool nbcon_kthread_should_wakeup(struct console *con, struct nbcon_contex
cookie = console_srcu_read_lock();

flags = console_srcu_read_flags(con);
- if (console_is_usable(con, flags)) {
+ if (console_is_usable(con, flags, false)) {
/* Bring the sequence in @ctxt up to date */
ctxt->seq = nbcon_seq_read(con);

@@ -1026,7 +1026,7 @@ static int nbcon_kthread_func(void *__console)

con_flags = console_srcu_read_flags(con);

- if (console_is_usable(con, con_flags)) {
+ if (console_is_usable(con, con_flags, false)) {
unsigned long lock_flags;

con->device_lock(con, &lock_flags);
@@ -1322,7 +1322,7 @@ static void __nbcon_atomic_flush_pending(u64 stop_seq, bool allow_unsafe_takeove
if (!(flags & CON_NBCON))
continue;

- if (!console_is_usable(con, flags))
+ if (!console_is_usable(con, flags, true))
continue;

if (nbcon_seq_read(con) >= stop_seq)
@@ -1639,7 +1639,7 @@ void nbcon_device_release(struct console *con)
* the console is usable throughout flushing.
*/
cookie = console_srcu_read_lock();
- if (console_is_usable(con, console_srcu_read_flags(con)) &&
+ if (console_is_usable(con, console_srcu_read_flags(con), true) &&
(!con->kthread || (system_state > SYSTEM_RUNNING)) &&
prb_read_valid(prb, nbcon_seq_read(con), NULL)) {
__nbcon_atomic_flush_pending_con(con, prb_next_reserve_seq(prb), false);
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index b58db15d2033..a2c4fe3d21cc 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3043,7 +3043,7 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
if ((flags & CON_NBCON) && con->kthread)
continue;

- if (!console_is_usable(con, flags))
+ if (!console_is_usable(con, flags, true))
continue;
any_usable = true;

@@ -4018,8 +4018,10 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
* that they make forward progress, so only increment
* @diff for usable consoles.
*/
- if (!console_is_usable(c, flags))
+ if (!console_is_usable(c, flags, true) &&
+ !console_is_usable(c, flags, false)) {
continue;
+ }

if (flags & CON_NBCON) {
printk_seq = nbcon_seq_read(c);
--
2.39.2


2024-06-03 23:26:36

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 07/18] printk: nbcon: Add printer thread wakeups

From: Thomas Gleixner <[email protected]>

Add a function to wakeup the printer threads. The printer threads
are woken when:

- a record is added to the printk ringbuffer
- consoles are resumed
- triggered via printk_trigger_flush()
- consoles should be replayed via sysrq

The actual waking is performed via irq_work so that the function
can be called from any context.

Co-developed-by: John Ogness <[email protected]>
Signed-off-by: John Ogness <[email protected]>
Signed-off-by: Thomas Gleixner (Intel) <[email protected]>
---
include/linux/console.h | 3 +++
kernel/printk/internal.h | 1 +
kernel/printk/nbcon.c | 56 ++++++++++++++++++++++++++++++++++++++++
kernel/printk/printk.c | 8 ++++++
4 files changed, 68 insertions(+)

diff --git a/include/linux/console.h b/include/linux/console.h
index 4de42ec1527c..adcc1a74aeee 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -16,6 +16,7 @@

#include <linux/atomic.h>
#include <linux/bits.h>
+#include <linux/irq_work.h>
#include <linux/rculist.h>
#include <linux/rcuwait.h>
#include <linux/types.h>
@@ -327,6 +328,7 @@ struct nbcon_write_context {
* @pbufs: Pointer to nbcon private buffer
* @kthread: Printer kthread for this console
* @rcuwait: RCU-safe wait object for @kthread waking
+ * @irq_work: Defer @kthread waking to IRQ work context
*/
struct console {
char name[16];
@@ -446,6 +448,7 @@ struct console {
struct printk_buffers *pbufs;
struct task_struct *kthread;
struct rcuwait rcuwait;
+ struct irq_work irq_work;
};

#ifdef CONFIG_LOCKDEP
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 243d3d3bc889..b2b5c10a4321 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -93,6 +93,7 @@ void nbcon_atomic_flush_pending(void);
bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
int cookie);
void nbcon_kthread_create(struct console *con);
+void nbcon_wake_threads(void);

/*
* Check if the given console is currently capable and allowed to print
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 4200953d368e..4ab47cc014a3 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -1058,6 +1058,61 @@ static int nbcon_kthread_func(void *__console)
goto wait_for_event;
}

+/**
+ * nbcon_irq_work - irq work to wake printk thread
+ * @irq_work: The irq work to operate on
+ */
+static void nbcon_irq_work(struct irq_work *irq_work)
+{
+ struct console *con = container_of(irq_work, struct console, irq_work);
+
+ nbcon_kthread_wake(con);
+}
+
+static inline bool rcuwait_has_sleeper(struct rcuwait *w)
+{
+ bool has_sleeper;
+
+ rcu_read_lock();
+ /*
+ * Guarantee any new records can be seen by tasks preparing to wait
+ * before this context checks if the rcuwait is empty.
+ *
+ * This full memory barrier pairs with the full memory barrier within
+ * set_current_state() of ___rcuwait_wait_event(), which is called
+ * after prepare_to_rcuwait() adds the waiter but before it has
+ * checked the wait condition.
+ *
+ * This pairs with nbcon_kthread_func:A.
+ */
+ smp_mb(); /* LMM(rcuwait_has_sleeper:A) */
+ has_sleeper = !!rcu_dereference(w->task);
+ rcu_read_unlock();
+
+ return has_sleeper;
+}
+
+/**
+ * nbcon_wake_threads - Wake up printing threads using irq_work
+ */
+void nbcon_wake_threads(void)
+{
+ struct console *con;
+ int cookie;
+
+ cookie = console_srcu_read_lock();
+ for_each_console_srcu(con) {
+ /*
+ * Only schedule irq_work if the printing thread is
+ * actively waiting. If not waiting, the thread will
+ * notice by itself that it has work to do.
+ */
+ if (con->kthread && rcuwait_has_sleeper(&con->rcuwait))
+ irq_work_queue(&con->irq_work);
+ }
+ console_srcu_read_unlock(cookie);
+}
+
/* Track the nbcon emergency nesting per CPU. */
static DEFINE_PER_CPU(unsigned int, nbcon_pcpu_emergency_nesting);
static unsigned int early_nbcon_pcpu_emergency_nesting __initdata;
@@ -1558,6 +1613,7 @@ void nbcon_init(struct console *con, u64 init_seq)
BUG_ON(!con->pbufs);

rcuwait_init(&con->rcuwait);
+ init_irq_work(&con->irq_work, nbcon_irq_work);
nbcon_seq_force(con, init_seq);
nbcon_state_set(con, &state);
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index a2c4fe3d21cc..457c01311a95 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2402,6 +2402,8 @@ asmlinkage int vprintk_emit(int facility, int level,
}
}

+ nbcon_wake_threads();
+
if (do_trylock_unlock) {
/*
* The caller may be holding system-critical or
@@ -2708,6 +2710,10 @@ void resume_console(void)
*/
synchronize_srcu(&console_srcu);

+ /*
+ * Since this runs in task context, wake the threaded printers
+ * directly rather than scheduling irq_work to do it.
+ */
cookie = console_srcu_read_lock();
for_each_console_srcu(con) {
flags = console_srcu_read_flags(con);
@@ -4178,6 +4184,7 @@ void defer_console_output(void)

void printk_trigger_flush(void)
{
+ nbcon_wake_threads();
defer_console_output();
}

@@ -4513,6 +4520,7 @@ void console_try_replay_all(void)
{
if (console_trylock()) {
__console_rewind_all();
+ nbcon_wake_threads();
/* Consoles are flushed as part of console_unlock(). */
console_unlock();
}
--
2.39.2


2024-06-03 23:28:57

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 08/18] printk: nbcon: Stop threads on shutdown/reboot

Register a syscore_ops shutdown function to stop all threaded
printers on shutdown/reboot. This allows printk to cleanly
transition back to atomic printing in order to provide a robust
mechanism for outputting the final messages.

Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/nbcon.c | 31 +++++++++++++++++++++++++++++++
1 file changed, 31 insertions(+)

diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 4ab47cc014a3..f60d47b5db8a 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -18,6 +18,7 @@
#include <linux/smp.h>
#include <linux/stddef.h>
#include <linux/string.h>
+#include <linux/syscore_ops.h>
#include <linux/types.h>
#include "internal.h"
#include "printk_ringbuffer.h"
@@ -1703,3 +1704,33 @@ void nbcon_device_release(struct console *con)
console_srcu_read_unlock(cookie);
}
EXPORT_SYMBOL_GPL(nbcon_device_release);
+
+/**
+ * printk_kthread_shutdown - shutdown all threaded printers
+ *
+ * On system shutdown all threaded printers are stopped. This allows printk
+ * to transition back to atomic printing, thus providing a robust mechanism
+ * for the final shutdown/reboot messages to be output.
+ */
+static void printk_kthread_shutdown(void)
+{
+ struct console *con;
+
+ console_list_lock();
+ for_each_console(con) {
+ if (con->flags & CON_NBCON)
+ nbcon_kthread_stop(con);
+ }
+ console_list_unlock();
+}
+
+static struct syscore_ops printk_syscore_ops = {
+ .shutdown = printk_kthread_shutdown,
+};
+
+static int __init printk_init_ops(void)
+{
+ register_syscore_ops(&printk_syscore_ops);
+ return 0;
+}
+device_initcall(printk_init_ops);
--
2.39.2


2024-06-03 23:29:25

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 14/18] proc: Add nbcon support for /proc/consoles

Update /proc/consoles output to show 'W' if an nbcon write
callback is implemented (write_atomic or write_thread).

Also update /proc/consoles output to show 'N' if it is an
nbcon console.

Signed-off-by: John Ogness <[email protected]>
---
fs/proc/consoles.c | 14 +++++++++++---
1 file changed, 11 insertions(+), 3 deletions(-)

diff --git a/fs/proc/consoles.c b/fs/proc/consoles.c
index 7036fdfa0bec..c3c01ec2273c 100644
--- a/fs/proc/consoles.c
+++ b/fs/proc/consoles.c
@@ -21,12 +21,14 @@ static int show_console_dev(struct seq_file *m, void *v)
{ CON_ENABLED, 'E' },
{ CON_CONSDEV, 'C' },
{ CON_BOOT, 'B' },
+ { CON_NBCON, 'N' },
{ CON_PRINTBUFFER, 'p' },
{ CON_BRL, 'b' },
{ CON_ANYTIME, 'a' },
};
char flags[ARRAY_SIZE(con_flags) + 1];
struct console *con = v;
+ char con_write = '-';
unsigned int a;
dev_t dev = 0;

@@ -57,9 +59,15 @@ static int show_console_dev(struct seq_file *m, void *v)
seq_setwidth(m, 21 - 1);
seq_printf(m, "%s%d", con->name, con->index);
seq_pad(m, ' ');
- seq_printf(m, "%c%c%c (%s)", con->read ? 'R' : '-',
- con->write ? 'W' : '-', con->unblank ? 'U' : '-',
- flags);
+ if (con->flags & CON_NBCON) {
+ if (con->write_atomic || con->write_thread)
+ con_write = 'W';
+ } else {
+ if (con->write)
+ con_write = 'W';
+ }
+ seq_printf(m, "%c%c%c (%s)", con->read ? 'R' : '-', con_write,
+ con->unblank ? 'U' : '-', flags);
if (dev)
seq_printf(m, " %4d:%d", MAJOR(dev), MINOR(dev));

--
2.39.2


2024-06-03 23:29:30

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 13/18] proc: consoles: Add notation to c_start/c_stop

fs/proc/consoles.c:78:13: warning: context imbalance in 'c_start'
- wrong count at exit
fs/proc/consoles.c:104:13: warning: context imbalance in 'c_stop'
- unexpected unlock

Signed-off-by: John Ogness <[email protected]>
---
fs/proc/consoles.c | 2 ++
1 file changed, 2 insertions(+)

diff --git a/fs/proc/consoles.c b/fs/proc/consoles.c
index e0758fe7936d..7036fdfa0bec 100644
--- a/fs/proc/consoles.c
+++ b/fs/proc/consoles.c
@@ -68,6 +68,7 @@ static int show_console_dev(struct seq_file *m, void *v)
}

static void *c_start(struct seq_file *m, loff_t *pos)
+ __acquires(&console_mutex)
{
struct console *con;
loff_t off = 0;
@@ -94,6 +95,7 @@ static void *c_next(struct seq_file *m, void *v, loff_t *pos)
}

static void c_stop(struct seq_file *m, void *v)
+ __releases(&console_mutex)
{
console_list_unlock();
}
--
2.39.2


2024-06-03 23:30:07

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 16/18] printk: Provide threadprintk boot argument

For PREEMPT_RT, legacy console printing is performed in a dedicated
kthread. However, this behavior can also be interesting for other
preemption models as it minimizes the duration of printk() calls by
deferring all printing.

Provide a new boot argument "threadprintk" that will create the
dedicated kthread for legacy console printing for !PREEMPT_RT
systems.

The implementation is the same as the "threadirqs" boot argument.

Users should be aware that if this option is enabled, the shutdown,
reboot, and panic messages probably will not be visible on the
legacy consoles.

Non-legacy consoles (NBCON) already have their own dedicated kernel
threads for printing and reliable shutdown, reboot, and panic
printing. This option really only applies to legacy consoles.

Users can view /proc/consoles to see if their console driver is
legacy or not. NBCON console drivers are shown with 'N'.

Signed-off-by: John Ogness <[email protected]>
---
Documentation/admin-guide/kernel-parameters.txt | 12 ++++++++++++
kernel/printk/internal.h | 4 +++-
kernel/printk/printk.c | 11 +++++++++++
3 files changed, 26 insertions(+), 1 deletion(-)

diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index 45d95614ec44..17977dd4fafa 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -6572,6 +6572,18 @@
Force threading of all interrupt handlers except those
marked explicitly IRQF_NO_THREAD.

+ threadprintk [KNL]
+ Force threaded printing of all legacy consoles. Be
+ aware that with this option, the shutdown, reboot, and
+ panic messages may not be printed on the legacy
+ consoles. Also, earlycon/earlyprintk printing will be
+ delayed until a regular console or the kthread is
+ available.
+
+ Users can view /proc/consoles to see if their console
+ driver is legacy or not. Non-legacy (NBCON) console
+ drivers are already threaded and are shown with 'N'.
+
topology= [S390,EARLY]
Format: {off | on}
Specify if the kernel should make use of the cpu
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index b66dfa865591..48c3564f95eb 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -3,6 +3,7 @@
* internal.h - printk internal definitions
*/
#include <linux/console.h>
+#include <linux/jump_label.h>
#include <linux/percpu.h>
#include <linux/types.h>

@@ -24,7 +25,8 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
#ifdef CONFIG_PREEMPT_RT
# define force_printkthreads() (true)
#else
-# define force_printkthreads() (false)
+DECLARE_STATIC_KEY_FALSE(force_printkthreads_key);
+# define force_printkthreads() (static_branch_unlikely(&force_printkthreads_key))
#endif

#ifdef CONFIG_PRINTK
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1c63fd0c1166..ea2d66152256 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -195,6 +195,17 @@ static int __init control_devkmsg(char *str)
}
__setup("printk.devkmsg=", control_devkmsg);

+#if !defined(CONFIG_PREEMPT_RT)
+DEFINE_STATIC_KEY_FALSE(force_printkthreads_key);
+
+static int __init setup_forced_printkthreads(char *arg)
+{
+ static_branch_enable(&force_printkthreads_key);
+ return 0;
+}
+early_param("threadprintk", setup_forced_printkthreads);
+#endif
+
char devkmsg_log_str[DEVKMSG_STR_MAX_SIZE] = "ratelimit";
#if defined(CONFIG_PRINTK) && defined(CONFIG_SYSCTL)
int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
--
2.39.2


2024-06-03 23:30:09

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 17/18] printk: Avoid false positive lockdep report for legacy printing

Legacy console printing from printk() caller context may invoke
the console driver from atomic context. This leads to a lockdep
splat because the console driver will acquire a sleeping lock
and the caller may already hold a spinning lock. This is noticed
by lockdep on !PREEMPT_RT configurations because it will lead to
a problem on PREEMPT_RT.

However, on PREEMPT_RT the printing path from atomic context is
always avoided and the console driver is always invoked from a
dedicated thread. Thus the lockdep splat on !PREEMPT_RT is a
false positive.

For !PREEMPT_RT override the lock-context before invoking the
console driver to avoid the false positive.

Do not override the lock-context for PREEMPT_RT in order to
allow lockdep to catch any real locking context issues related
to the write callback usage.

Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/printk.c | 31 ++++++++++++++++++++++++++++++-
1 file changed, 30 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index ea2d66152256..5e9778f69206 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2980,6 +2980,33 @@ bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
return true;
}

+/*
+ * Legacy console printing from printk() caller context does not respect
+ * raw_spinlock/spinlock nesting. For !PREEMPT_RT the lockdep warning is a
+ * false positive. For PREEMPT_RT the false positive condition does not
+ * occur.
+ *
+ * This map is used to establish LD_WAIT_SLEEP context for the console write
+ * callbacks when legacy printing to avoid false positive lockdep complaints,
+ * thus allowing lockdep to continue to function for real issues.
+ */
+#ifdef CONFIG_PREEMPT_RT
+static inline void printk_legacy_lock_map_acquire_try(void) { }
+static inline void printk_legacy_lock_map_release(void) { }
+#else
+static DEFINE_WAIT_OVERRIDE_MAP(printk_legacy_map, LD_WAIT_SLEEP);
+
+static inline void printk_legacy_lock_map_acquire_try(void)
+{
+ lock_map_acquire_try(&printk_legacy_map);
+}
+
+static inline void printk_legacy_lock_map_release(void)
+{
+ lock_map_release(&printk_legacy_map);
+}
+#endif /* CONFIG_PREEMPT_RT */
+
/*
* Used as the printk buffers for non-panic, serialized console printing.
* This is for legacy (!CON_NBCON) as well as all boot (CON_BOOT) consoles.
@@ -3035,7 +3062,7 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
/*
* With forced threading this function is either in a thread
* or panic context. So there is no need for concern about
- * printk reentrance or handovers.
+ * printk reentrance, handovers, or lockdep complaints.
*/

con->write(con, outbuf, pmsg.outbuf_len);
@@ -3057,7 +3084,9 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
/* Do not trace print latency. */
stop_critical_timings();

+ printk_legacy_lock_map_acquire_try();
con->write(con, outbuf, pmsg.outbuf_len);
+ printk_legacy_lock_map_release();

start_critical_timings();

--
2.39.2


2024-06-03 23:30:31

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 15/18] tty: sysfs: Add nbcon support for 'active'

Allow the 'active' attribute to list nbcon consoles.

Signed-off-by: John Ogness <[email protected]>
---
drivers/tty/tty_io.c | 9 +++++++--
1 file changed, 7 insertions(+), 2 deletions(-)

diff --git a/drivers/tty/tty_io.c b/drivers/tty/tty_io.c
index 407b0d87b7c1..c9c914bc033c 100644
--- a/drivers/tty/tty_io.c
+++ b/drivers/tty/tty_io.c
@@ -3567,8 +3567,13 @@ static ssize_t show_cons_active(struct device *dev,
for_each_console(c) {
if (!c->device)
continue;
- if (!c->write)
- continue;
+ if (c->flags & CON_NBCON) {
+ if (!c->write_atomic && !c->write_thread)
+ continue;
+ } else {
+ if (!c->write)
+ continue;
+ }
if ((c->flags & CON_ENABLED) == 0)
continue;
cs[i++] = c;
--
2.39.2


2024-06-03 23:30:38

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 12/18] printk: Add kthread for all legacy consoles

The write callback of legacy consoles makes use of spinlocks.
This is not permitted with PREEMPT_RT in atomic contexts.

For PREEMPT_RT, create a new kthread to handle printing of all
the legacy consoles (and nbcon consoles if boot consoles are
registered).

Since, if running from the kthread, the consoles are printing
in a task context, the legacy nbcon printing can use the
device_lock(), write_thread(), device_unlock() callbacks for
printing.

Introduce the macro force_printkthreads() to query if the
forced threading of legacy consoles is in effect.

These changes only affect CONFIG_PREEMPT_RT.

Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/internal.h | 11 +-
kernel/printk/nbcon.c | 54 ++++++---
kernel/printk/printk.c | 241 ++++++++++++++++++++++++++++++++-------
3 files changed, 246 insertions(+), 60 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 9e027e08918d..b66dfa865591 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -21,6 +21,12 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
(con->flags & CON_BOOT) ? "boot" : "", \
con->name, con->index, ##__VA_ARGS__)

+#ifdef CONFIG_PREEMPT_RT
+# define force_printkthreads() (true)
+#else
+# define force_printkthreads() (false)
+#endif
+
#ifdef CONFIG_PRINTK

#ifdef CONFIG_PRINTK_CALLER
@@ -92,9 +98,10 @@ void nbcon_free(struct console *con);
enum nbcon_prio nbcon_get_default_prio(void);
void nbcon_atomic_flush_pending(void);
bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
- int cookie);
+ int cookie, bool use_atomic);
void nbcon_kthread_create(struct console *con);
void nbcon_wake_threads(void);
+void nbcon_legacy_kthread_create(void);

/*
* Check if the given console is currently capable and allowed to print
@@ -181,7 +188,7 @@ static inline void nbcon_free(struct console *con) { }
static inline enum nbcon_prio nbcon_get_default_prio(void) { return NBCON_PRIO_NONE; }
static inline void nbcon_atomic_flush_pending(void) { }
static inline bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
- int cookie) { return false; }
+ int cookie, bool use_atomic) { return false; }

static inline bool console_is_usable(struct console *con, short flags,
bool use_atomic) { return false; }
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 8c92b076c745..e8060b5abdf8 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -1185,9 +1185,10 @@ enum nbcon_prio nbcon_get_default_prio(void)
}

/*
- * nbcon_atomic_emit_one - Print one record for an nbcon console using the
- * write_atomic() callback
+ * nbcon_emit_one - Print one record for an nbcon console using the
+ * specified callback
* @wctxt: An initialized write context struct to use for this context
+ * @use_atomic: True if the write_atomic() callback is to be used
*
* Return: True, when a record has been printed and there are still
* pending records. The caller might want to continue flushing.
@@ -1200,7 +1201,7 @@ enum nbcon_prio nbcon_get_default_prio(void)
* This is an internal helper to handle the locking of the console before
* calling nbcon_emit_next_record().
*/
-static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
+static bool nbcon_emit_one(struct nbcon_write_context *wctxt, bool use_atomic)
{
struct nbcon_context *ctxt = &ACCESS_PRIVATE(wctxt, ctxt);

@@ -1215,7 +1216,7 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
* The higher priority printing context takes over responsibility
* to print the pending records.
*/
- if (!nbcon_emit_next_record(wctxt, true))
+ if (!nbcon_emit_next_record(wctxt, use_atomic))
return false;

nbcon_context_release(ctxt);
@@ -1232,6 +1233,7 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
* both the console_lock and the SRCU read lock. Otherwise it
* is set to false.
* @cookie: The cookie from the SRCU read lock.
+ * @use_atomic: True if the write_atomic() callback is to be used
*
* Context: Any context except NMI.
* Return: True, when a record has been printed and there are still
@@ -1247,26 +1249,38 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
* Essentially it is the nbcon version of console_emit_next_record().
*/
bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
- int cookie)
+ int cookie, bool use_atomic)
{
struct nbcon_write_context wctxt = { };
struct nbcon_context *ctxt = &ACCESS_PRIVATE(&wctxt, ctxt);
unsigned long flags;
bool progress;

- /* Use the same procedure as console_emit_next_record(). */
- printk_safe_enter_irqsave(flags);
- console_lock_spinning_enable();
- stop_critical_timings();
+ ctxt->console = con;

- ctxt->console = con;
- ctxt->prio = nbcon_get_default_prio();
+ if (use_atomic) {
+ /* Use the same procedure as console_emit_next_record(). */
+ printk_safe_enter_irqsave(flags);
+ console_lock_spinning_enable();
+ stop_critical_timings();

- progress = nbcon_atomic_emit_one(&wctxt);
+ ctxt->prio = nbcon_get_default_prio();
+ progress = nbcon_emit_one(&wctxt, use_atomic);

- start_critical_timings();
- *handover = console_lock_spinning_disable_and_check(cookie);
- printk_safe_exit_irqrestore(flags);
+ start_critical_timings();
+ *handover = console_lock_spinning_disable_and_check(cookie);
+ printk_safe_exit_irqrestore(flags);
+ } else {
+ *handover = false;
+
+ con->device_lock(con, &flags);
+ cant_migrate();
+
+ ctxt->prio = nbcon_get_default_prio();
+ progress = nbcon_emit_one(&wctxt, use_atomic);
+
+ con->device_unlock(con, flags);
+ }

return progress;
}
@@ -1494,7 +1508,9 @@ void nbcon_cpu_emergency_exit(void)
* to handle it.
*/
do_trigger_flush = true;
- if (printing_via_unlock && !is_printk_deferred()) {
+ if (!force_printkthreads() &&
+ printing_via_unlock &&
+ !is_printk_deferred()) {
if (console_trylock()) {
do_trigger_flush = false;
console_unlock();
@@ -1530,7 +1546,9 @@ void nbcon_cpu_emergency_flush(void)

nbcon_atomic_flush_pending();

- if (printing_via_unlock && !is_printk_deferred()) {
+ if (!force_printkthreads() &&
+ printing_via_unlock &&
+ !is_printk_deferred()) {
if (console_trylock())
console_unlock();
}
@@ -1601,6 +1619,8 @@ static int __init printk_setup_threads(void)
printk_threads_enabled = true;
for_each_console(con)
nbcon_kthread_create(con);
+ if (force_printkthreads() && printing_via_unlock)
+ nbcon_legacy_kthread_create();
console_list_unlock();
return 0;
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index cf0d612329bf..1c63fd0c1166 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -487,6 +487,9 @@ bool have_boot_console;

#ifdef CONFIG_PRINTK
DECLARE_WAIT_QUEUE_HEAD(log_wait);
+
+static DECLARE_WAIT_QUEUE_HEAD(legacy_wait);
+
/* All 3 protected by @syslog_lock. */
/* the next printk record to read by syslog(READ) or /proc/kmsg */
static u64 syslog_seq;
@@ -2345,7 +2348,8 @@ asmlinkage int vprintk_emit(int facility, int level,
const struct dev_printk_info *dev_info,
const char *fmt, va_list args)
{
- bool do_trylock_unlock = printing_via_unlock;
+ bool do_trylock_unlock = !force_printkthreads() &&
+ printing_via_unlock;
int printed_len;

/* Suppress unimportant messages after panic happens */
@@ -2468,6 +2472,14 @@ EXPORT_SYMBOL(_printk);
static bool pr_flush(int timeout_ms, bool reset_on_progress);
static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress);

+static struct task_struct *nbcon_legacy_kthread;
+
+static inline void wake_up_legacy_kthread(void)
+{
+ if (nbcon_legacy_kthread)
+ wake_up_interruptible(&legacy_wait);
+}
+
#else /* CONFIG_PRINTK */

#define printk_time false
@@ -2481,6 +2493,8 @@ static u64 syslog_seq;
static bool pr_flush(int timeout_ms, bool reset_on_progress) { return true; }
static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress) { return true; }

+static inline void nbcon_legacy_kthread_create(void) { }
+static inline void wake_up_legacy_kthread(void) { }
#endif /* CONFIG_PRINTK */

#ifdef CONFIG_EARLY_PRINTK
@@ -2726,6 +2740,8 @@ void resume_console(void)
}
console_srcu_read_unlock(cookie);

+ wake_up_legacy_kthread();
+
pr_flush(1000, true);
}

@@ -2740,7 +2756,9 @@ void resume_console(void)
*/
static int console_cpu_notify(unsigned int cpu)
{
- if (!cpuhp_tasks_frozen && printing_via_unlock) {
+ if (!force_printkthreads() &&
+ !cpuhp_tasks_frozen &&
+ printing_via_unlock) {
/* If trylock fails, someone else is doing the printing */
if (console_trylock())
console_unlock();
@@ -3000,31 +3018,43 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
con->dropped = 0;
}

- /*
- * While actively printing out messages, if another printk()
- * were to occur on another CPU, it may wait for this one to
- * finish. This task can not be preempted if there is a
- * waiter waiting to take over.
- *
- * Interrupts are disabled because the hand over to a waiter
- * must not be interrupted until the hand over is completed
- * (@console_waiter is cleared).
- */
- printk_safe_enter_irqsave(flags);
- console_lock_spinning_enable();
+ /* Write everything out to the hardware. */

- /* Do not trace print latency. */
- stop_critical_timings();
+ if (force_printkthreads()) {
+ /*
+ * With forced threading this function is either in a thread
+ * or panic context. So there is no need for concern about
+ * printk reentrance or handovers.
+ */

- /* Write everything out to the hardware. */
- con->write(con, outbuf, pmsg.outbuf_len);
+ con->write(con, outbuf, pmsg.outbuf_len);
+ con->seq = pmsg.seq + 1;
+ } else {
+ /*
+ * While actively printing out messages, if another printk()
+ * were to occur on another CPU, it may wait for this one to
+ * finish. This task can not be preempted if there is a
+ * waiter waiting to take over.
+ *
+ * Interrupts are disabled because the hand over to a waiter
+ * must not be interrupted until the hand over is completed
+ * (@console_waiter is cleared).
+ */
+ printk_safe_enter_irqsave(flags);
+ console_lock_spinning_enable();

- start_critical_timings();
+ /* Do not trace print latency. */
+ stop_critical_timings();

- con->seq = pmsg.seq + 1;
+ con->write(con, outbuf, pmsg.outbuf_len);

- *handover = console_lock_spinning_disable_and_check(cookie);
- printk_safe_exit_irqrestore(flags);
+ start_critical_timings();
+
+ con->seq = pmsg.seq + 1;
+
+ *handover = console_lock_spinning_disable_and_check(cookie);
+ printk_safe_exit_irqrestore(flags);
+ }
skip:
return true;
}
@@ -3088,12 +3118,13 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
if ((flags & CON_NBCON) && con->kthread)
continue;

- if (!console_is_usable(con, flags, true))
+ if (!console_is_usable(con, flags, !do_cond_resched))
continue;
any_usable = true;

if (flags & CON_NBCON) {
- progress = nbcon_legacy_emit_next_record(con, handover, cookie);
+ progress = nbcon_legacy_emit_next_record(con, handover, cookie,
+ !do_cond_resched);
printk_seq = nbcon_seq_read(con);
} else {
progress = console_emit_next_record(con, handover, cookie);
@@ -3132,19 +3163,7 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
return false;
}

-/**
- * console_unlock - unblock the console subsystem from printing
- *
- * Releases the console_lock which the caller holds to block printing of
- * the console subsystem.
- *
- * While the console_lock was held, console output may have been buffered
- * by printk(). If this is the case, console_unlock(); emits
- * the output prior to releasing the lock.
- *
- * console_unlock(); may be called from any context.
- */
-void console_unlock(void)
+static void console_flush_and_unlock(void)
{
bool do_cond_resched;
bool handover;
@@ -3188,6 +3207,32 @@ void console_unlock(void)
*/
} while (prb_read_valid(prb, next_seq, NULL) && console_trylock());
}
+
+/**
+ * console_unlock - unblock the console subsystem from printing
+ *
+ * Releases the console_lock which the caller holds to block printing of
+ * the console subsystem.
+ *
+ * While the console_lock was held, console output may have been buffered
+ * by printk(). If this is the case, console_unlock(); emits
+ * the output prior to releasing the lock.
+ *
+ * console_unlock(); may be called from any context.
+ */
+void console_unlock(void)
+{
+ /*
+ * Forced threading relies on kthread and atomic consoles for
+ * printing. It never attempts to print from console_unlock().
+ */
+ if (force_printkthreads()) {
+ __console_unlock();
+ return;
+ }
+
+ console_flush_and_unlock();
+}
EXPORT_SYMBOL(console_unlock);

/**
@@ -3411,12 +3456,107 @@ void console_start(struct console *console)
flags = console_srcu_read_flags(console);
if (flags & CON_NBCON)
nbcon_kthread_wake(console);
+ else
+ wake_up_legacy_kthread();
console_srcu_read_unlock(cookie);

__pr_flush(console, 1000, true);
}
EXPORT_SYMBOL(console_start);

+#ifdef CONFIG_PRINTK
+static bool printer_should_wake(void)
+{
+ bool available = false;
+ struct console *con;
+ int cookie;
+
+ if (kthread_should_stop())
+ return true;
+
+ cookie = console_srcu_read_lock();
+ for_each_console_srcu(con) {
+ short flags = console_srcu_read_flags(con);
+ u64 printk_seq;
+
+ /*
+ * The legacy printer thread is only for legacy consoles,
+ * unless the nbcon console has no kthread printer.
+ */
+ if ((flags & CON_NBCON) && con->kthread)
+ continue;
+
+ if (!console_is_usable(con, flags, false))
+ continue;
+
+ if (flags & CON_NBCON) {
+ printk_seq = nbcon_seq_read(con);
+ } else {
+ /*
+ * It is safe to read @seq because only this
+ * thread context updates @seq.
+ */
+ printk_seq = con->seq;
+ }
+
+ if (prb_read_valid(prb, printk_seq, NULL)) {
+ available = true;
+ break;
+ }
+ }
+ console_srcu_read_unlock(cookie);
+
+ return available;
+}
+
+static int nbcon_legacy_kthread_func(void *unused)
+{
+ int error;
+
+ for (;;) {
+ error = wait_event_interruptible(legacy_wait, printer_should_wake());
+
+ if (kthread_should_stop())
+ break;
+
+ if (error)
+ continue;
+
+ console_lock();
+ console_flush_and_unlock();
+ }
+
+ return 0;
+}
+
+void nbcon_legacy_kthread_create(void)
+{
+ struct task_struct *kt;
+
+ lockdep_assert_held(&console_mutex);
+
+ if (!force_printkthreads())
+ return;
+
+ if (!printk_threads_enabled || nbcon_legacy_kthread)
+ return;
+
+ kt = kthread_run(nbcon_legacy_kthread_func, NULL, "pr/legacy");
+ if (IS_ERR(kt)) {
+ pr_err("unable to start legacy printing thread\n");
+ return;
+ }
+
+ nbcon_legacy_kthread = kt;
+
+ /*
+ * It is important that console printing threads are scheduled
+ * shortly after a printk call and with generous runtime budgets.
+ */
+ sched_set_normal(nbcon_legacy_kthread, -20);
+}
+#endif /* CONFIG_PRINTK */
+
static int __read_mostly keep_bootcon;

static int __init keep_bootcon_setup(char *str)
@@ -3706,6 +3846,7 @@ void register_console(struct console *newcon)
} else {
have_legacy_console = true;
newcon->seq = init_seq;
+ nbcon_legacy_kthread_create();
}

if (newcon->flags & CON_BOOT)
@@ -3873,6 +4014,13 @@ static int unregister_console_locked(struct console *console)
nbcon_kthread_create(c);
}

+#ifdef CONFIG_PRINTK
+ if (!printing_via_unlock && nbcon_legacy_kthread) {
+ kthread_stop(nbcon_legacy_kthread);
+ nbcon_legacy_kthread = NULL;
+ }
+#endif
+
return res;
}

@@ -4031,7 +4179,11 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre

seq = prb_next_reserve_seq(prb);

- /* Flush the consoles so that records up to @seq are printed. */
+ /*
+ * Flush the consoles so that records up to @seq are printed.
+ * Otherwise this function will just wait for the threaded printers
+ * to print up to @seq.
+ */
if (printing_via_unlock) {
console_lock();
console_unlock();
@@ -4146,9 +4298,16 @@ static void wake_up_klogd_work_func(struct irq_work *irq_work)
int pending = this_cpu_xchg(printk_pending, 0);

if (pending & PRINTK_PENDING_OUTPUT) {
- /* If trylock fails, someone else is doing the printing */
- if (console_trylock())
- console_unlock();
+ if (force_printkthreads()) {
+ wake_up_legacy_kthread();
+ } else {
+ /*
+ * If trylock fails, some other context
+ * will do the printing.
+ */
+ if (console_trylock())
+ console_unlock();
+ }
}

if (pending & PRINTK_PENDING_WAKEUP)
--
2.39.2


2024-06-03 23:30:58

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 18/18] printk: nbcon: Add function for printers to reacquire ownership

Since ownership can be lost at any time due to handover or
takeover, a printing context _must_ be prepared to back out
immediately and carefully. However, there are scenarios where
the printing context must reacquire ownership in order to
finalize or revert hardware changes.

One such example is when interrupts are disabled during
printing. No other context will automagically re-enable the
interrupts. For this case, the disabling context _must_
reacquire nbcon ownership so that it can re-enable the
interrupts.

Provide nbcon_reacquire() for exactly this purpose. It allows a
printing context to reacquire ownership using the same priority
as its previous ownership.

Note that after a successful reacquire the printing context
will have no output buffer because that has been lost. This
function cannot be used to resume printing.

Signed-off-by: John Ogness <[email protected]>
---
include/linux/console.h | 6 ++++++
kernel/printk/nbcon.c | 41 +++++++++++++++++++++++++++++++++++++++++
2 files changed, 47 insertions(+)

diff --git a/include/linux/console.h b/include/linux/console.h
index 9927f08ac054..96c0923d023b 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -372,6 +372,10 @@ struct console {
*
* The callback should allow the takeover whenever it is safe. It
* increases the chance to see messages when the system is in trouble.
+ * If the driver must reacquire ownership in order to finalize or
+ * revert hardware changes, nbcon_reacquire() can be used. However,
+ * on reacquire the buffer content is no longer available. A
+ * reacquire cannot be used to resume printing.
*
* The callback can be called from any context (including NMI).
* Therefore it must avoid usage of any locking and instead rely
@@ -591,6 +595,7 @@ extern void nbcon_cpu_emergency_flush(void);
extern bool nbcon_can_proceed(struct nbcon_write_context *wctxt);
extern bool nbcon_enter_unsafe(struct nbcon_write_context *wctxt);
extern bool nbcon_exit_unsafe(struct nbcon_write_context *wctxt);
+extern void nbcon_reacquire(struct nbcon_write_context *wctxt);
#else
static inline void nbcon_cpu_emergency_enter(void) { }
static inline void nbcon_cpu_emergency_exit(void) { }
@@ -598,6 +603,7 @@ static inline void nbcon_cpu_emergency_flush(void) { }
static inline bool nbcon_can_proceed(struct nbcon_write_context *wctxt) { return false; }
static inline bool nbcon_enter_unsafe(struct nbcon_write_context *wctxt) { return false; }
static inline bool nbcon_exit_unsafe(struct nbcon_write_context *wctxt) { return false; }
+static inline void nbcon_reacquire(struct nbcon_write_context *wctxt) { }
#endif

extern int console_set_on_cmdline;
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index e8060b5abdf8..4b9645e7ed70 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -838,6 +838,38 @@ bool nbcon_exit_unsafe(struct nbcon_write_context *wctxt)
}
EXPORT_SYMBOL_GPL(nbcon_exit_unsafe);

+/**
+ * nbcon_reacquire - Reacquire a console after losing ownership while printing
+ * @wctxt: The write context that was handed to the write callback
+ *
+ * Since ownership can be lost at any time due to handover or takeover, a
+ * printing context _must_ be prepared to back out immediately and
+ * carefully. However, there are scenarios where the printing context must
+ * reacquire ownership in order to finalize or revert hardware changes.
+ *
+ * This function allows a printing context to reacquire ownership using the
+ * same priority as its previous ownership.
+ *
+ * Note that after a successful reacquire the printing context will have no
+ * output buffer because that has been lost. This function cannot be used to
+ * resume printing.
+ */
+void nbcon_reacquire(struct nbcon_write_context *wctxt)
+{
+ struct nbcon_context *ctxt = &ACCESS_PRIVATE(wctxt, ctxt);
+ struct console *con = ctxt->console;
+ struct nbcon_state cur;
+
+ while (!nbcon_context_try_acquire(ctxt))
+ cpu_relax();
+
+ wctxt->outbuf = NULL;
+ wctxt->len = 0;
+ nbcon_state_read(con, &cur);
+ wctxt->unsafe_takeover = cur.unsafe_takeover;
+}
+EXPORT_SYMBOL_GPL(nbcon_reacquire);
+
/**
* nbcon_emit_next_record - Emit a record in the acquired context
* @wctxt: The write context that will be handed to the write function
@@ -945,6 +977,15 @@ static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt, bool use_a
return false;
}

+ if (!wctxt->outbuf) {
+ /*
+ * Ownership was lost and reacquired by the driver.
+ * Handle it as if ownership was lost.
+ */
+ nbcon_context_release(ctxt);
+ return false;
+ }
+
/*
* Since any dropped message was successfully output, reset the
* dropped count for the console.
--
2.39.2


2024-06-03 23:33:38

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 05/18] printk: Atomic print in printk context on shutdown

For nbcon consoles, normally the printing is handled by the
dedicated console printing threads. However, on shutdown the
printing threads may not get a chance to print the final
messages.

When shutting down or rebooting (system_state > SYSTEM_RUNNING),
perform atomic printing from the printk() caller context.

Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/nbcon.c | 5 +++--
kernel/printk/printk.c | 7 ++++++-
2 files changed, 9 insertions(+), 3 deletions(-)

diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 89b340ca303c..19f0db6945e4 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -1297,7 +1297,8 @@ static void nbcon_atomic_flush_pending_con(struct console *con, u64 stop_seq,
* context must flush those remaining records if the printer thread
* is not available do it.
*/
- if (!con->kthread && prb_read_valid(prb, nbcon_seq_read(con), NULL)) {
+ if ((!con->kthread || (system_state > SYSTEM_RUNNING)) &&
+ prb_read_valid(prb, nbcon_seq_read(con), NULL)) {
stop_seq = prb_next_reserve_seq(prb);
goto again;
}
@@ -1639,7 +1640,7 @@ void nbcon_device_release(struct console *con)
*/
cookie = console_srcu_read_lock();
if (console_is_usable(con, console_srcu_read_flags(con)) &&
- !con->kthread &&
+ (!con->kthread || (system_state > SYSTEM_RUNNING)) &&
prb_read_valid(prb, nbcon_seq_read(con), NULL)) {
__nbcon_atomic_flush_pending_con(con, prb_next_reserve_seq(prb), false);
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 137bd9a721c4..b58db15d2033 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2389,12 +2389,17 @@ asmlinkage int vprintk_emit(int facility, int level,
*
* - When this CPU is in panic.
*
+ * - During shutdown, since the printing threads may not get
+ * a chance to print the final messages.
+ *
* Note that if boot consoles are registered, the console
* lock/unlock dance must be relied upon instead because nbcon
* consoles cannot print simultaneously with boot consoles.
*/
- if (is_panic_context)
+ if (is_panic_context ||
+ (system_state > SYSTEM_RUNNING)) {
nbcon_atomic_flush_pending();
+ }
}

if (do_trylock_unlock) {
--
2.39.2


2024-06-03 23:33:53

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 10/18] printk: Provide helper for message prepending

In order to support prepending different texts to printk
messages, split out the prepending code into a helper
function.

Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/printk.c | 38 +++++++++++++++++++++++++++-----------
1 file changed, 27 insertions(+), 11 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 4613f9145a8e..fcbf794a0aaf 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2806,30 +2806,25 @@ static void __console_unlock(void)
#ifdef CONFIG_PRINTK

/*
- * Prepend the message in @pmsg->pbufs->outbuf with a "dropped message". This
- * is achieved by shifting the existing message over and inserting the dropped
- * message.
+ * Prepend the message in @pmsg->pbufs->outbuf with the message in
+ * @pmsg->pbufs->scratchbuf. This is achieved by shifting the existing message
+ * over and inserting the scratchbuf message.
*
* @pmsg is the printk message to prepend.
*
- * @dropped is the dropped count to report in the dropped message.
+ * @len is the length of the message in @pmsg->pbufs->scratchbuf.
*
* If the message text in @pmsg->pbufs->outbuf does not have enough space for
- * the dropped message, the message text will be sufficiently truncated.
+ * the scratchbuf message, the message text will be sufficiently truncated.
*
* If @pmsg->pbufs->outbuf is modified, @pmsg->outbuf_len is updated.
*/
-void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
+static void __console_prepend_scratch(struct printk_message *pmsg, size_t len)
{
struct printk_buffers *pbufs = pmsg->pbufs;
- const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
const size_t outbuf_sz = sizeof(pbufs->outbuf);
char *scratchbuf = &pbufs->scratchbuf[0];
char *outbuf = &pbufs->outbuf[0];
- size_t len;
-
- len = scnprintf(scratchbuf, scratchbuf_sz,
- "** %lu printk messages dropped **\n", dropped);

/*
* Make sure outbuf is sufficiently large before prepending.
@@ -2851,6 +2846,27 @@ void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
pmsg->outbuf_len += len;
}

+/*
+ * Prepend the message in @pmsg->pbufs->outbuf with a "dropped message".
+ * @pmsg->outbuf_len is updated appropriately.
+ *
+ * @pmsg is the printk message to prepend.
+ *
+ * @dropped is the dropped count to report in the dropped message.
+ */
+void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
+{
+ struct printk_buffers *pbufs = pmsg->pbufs;
+ const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
+ char *scratchbuf = &pbufs->scratchbuf[0];
+ size_t len;
+
+ len = scnprintf(scratchbuf, scratchbuf_sz,
+ "** %lu printk messages dropped **\n", dropped);
+
+ __console_prepend_scratch(pmsg, len);
+}
+
/*
* Read and format the specified record (or a later record if the specified
* record is not available).
--
2.39.2


2024-06-03 23:33:53

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 11/18] printk: nbcon: Show replay message on takeover

An emergency or panic context can takeover console ownership
while the current owner was printing a printk message. The
atomic printer will re-print the message that the previous
owner was printing. However, this can look confusing to the
user and may even seem as though a message was lost.

[3430014.1
[3430014.181123] usb 1-2: Product: USB Audio

Add a new field @nbcon_prev_seq to struct console to track
the sequence number to print that was assigned to the previous
console owner. If this matches the sequence number to print
that the current owner is assigned, then a takeover must have
occurred. In this case, print an additional message to inform
the user that the previous message is being printed again.

[3430014.1
** replaying previous printk message **
[3430014.181123] usb 1-2: Product: USB Audio

Signed-off-by: John Ogness <[email protected]>
---
include/linux/console.h | 3 +++
kernel/printk/internal.h | 1 +
kernel/printk/nbcon.c | 24 ++++++++++++++++++++++++
kernel/printk/printk.c | 19 +++++++++++++++++++
4 files changed, 47 insertions(+)

diff --git a/include/linux/console.h b/include/linux/console.h
index adcc1a74aeee..9927f08ac054 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -325,6 +325,7 @@ struct nbcon_write_context {
* @nbcon_state: State for nbcon consoles
* @nbcon_seq: Sequence number of the next record for nbcon to print
* @nbcon_device_ctxt: Context available for non-printing operations
+ * @nbcon_prev_seq: Seq num the previous nbcon owner was assigned to print
* @pbufs: Pointer to nbcon private buffer
* @kthread: Printer kthread for this console
* @rcuwait: RCU-safe wait object for @kthread waking
@@ -445,6 +446,8 @@ struct console {
atomic_t __private nbcon_state;
atomic_long_t __private nbcon_seq;
struct nbcon_context __private nbcon_device_ctxt;
+ atomic_long_t __private nbcon_prev_seq;
+
struct printk_buffers *pbufs;
struct task_struct *kthread;
struct rcuwait rcuwait;
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 5d4722310850..9e027e08918d 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -233,4 +233,5 @@ bool printk_get_next_message(struct printk_message *pmsg, u64 seq,

#ifdef CONFIG_PRINTK
void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped);
+void console_prepend_replay(struct printk_message *pmsg);
#endif
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 480a0ced2708..8c92b076c745 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -866,6 +866,7 @@ static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt, bool use_a
unsigned long con_dropped;
struct nbcon_state cur;
unsigned long dropped;
+ unsigned long ulseq;

/*
* The printk buffers are filled within an unsafe section. This
@@ -891,6 +892,28 @@ static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt, bool use_a
if (dropped && !is_extended)
console_prepend_dropped(&pmsg, dropped);

+ /*
+ * If the previous owner was assigned the same record, this context
+ * has taken over ownership and is replaying the record. Prepend a
+ * message to let the user know the record is replayed.
+ */
+ ulseq = atomic_long_read(&ACCESS_PRIVATE(con, nbcon_prev_seq));
+ if (__ulseq_to_u64seq(prb, ulseq) == pmsg.seq) {
+ console_prepend_replay(&pmsg);
+ } else {
+ /*
+ * Ensure this context is still the owner before trying to
+ * update @nbcon_prev_seq. Otherwise the value in @ulseq may
+ * not be from the previous owner.
+ */
+ nbcon_state_read(con, &cur);
+ if (!nbcon_context_can_proceed(ctxt, &cur))
+ return false;
+
+ atomic_long_try_cmpxchg(&ACCESS_PRIVATE(con, nbcon_prev_seq), &ulseq,
+ __u64seq_to_ulseq(pmsg.seq));
+ }
+
if (!nbcon_context_exit_unsafe(ctxt))
return false;

@@ -1631,6 +1654,7 @@ void nbcon_init(struct console *con, u64 init_seq)
rcuwait_init(&con->rcuwait);
init_irq_work(&con->irq_work, nbcon_irq_work);
nbcon_seq_force(con, init_seq);
+ atomic_long_set(&ACCESS_PRIVATE(con, nbcon_prev_seq), -1UL);
nbcon_state_set(con, &state);
nbcon_kthread_create(con);
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fcbf794a0aaf..cf0d612329bf 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2867,6 +2867,25 @@ void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
__console_prepend_scratch(pmsg, len);
}

+/*
+ * Prepend the message in @pmsg->pbufs->outbuf with a "replay message".
+ * @pmsg->outbuf_len is updated appropriately.
+ *
+ * @pmsg is the printk message to prepend.
+ */
+void console_prepend_replay(struct printk_message *pmsg)
+{
+ struct printk_buffers *pbufs = pmsg->pbufs;
+ const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
+ char *scratchbuf = &pbufs->scratchbuf[0];
+ size_t len;
+
+ len = scnprintf(scratchbuf, scratchbuf_sz,
+ "** replaying previous printk message **\n");
+
+ __console_prepend_scratch(pmsg, len);
+}
+
/*
* Read and format the specified record (or a later record if the specified
* record is not available).
--
2.39.2


2024-06-03 23:34:23

by John Ogness

[permalink] [raw]
Subject: [PATCH printk v2 09/18] printk: nbcon: Start printing threads

If there are no boot consoles, the printing threads are started
in early_initcall.

If there are boot consoles, the printing threads are started
after the last boot console has unregistered. The printing
threads do not need to be concerned about boot consoles because
boot consoles cannot register once a non-boot console has
registered.

Until a printing thread of a console has started, that console
will print using atomic_write() in the printk() caller context.

Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/internal.h | 2 ++
kernel/printk/nbcon.c | 18 +++++++++++++++++-
kernel/printk/printk.c | 14 ++++++++++++++
3 files changed, 33 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index b2b5c10a4321..5d4722310850 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -48,6 +48,7 @@ struct printk_ringbuffer;
struct dev_printk_info;

extern struct printk_ringbuffer *prb;
+extern bool printk_threads_enabled;

__printf(4, 0)
int vprintk_store(int facility, int level,
@@ -161,6 +162,7 @@ static inline void nbcon_kthread_wake(struct console *con)

static inline void nbcon_kthread_wake(struct console *con) { }
static inline void nbcon_kthread_create(struct console *con) { }
+#define printk_threads_enabled (false)

/*
* In !PRINTK builds we still export console_sem
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index f60d47b5db8a..480a0ced2708 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -213,6 +213,8 @@ static void nbcon_seq_try_update(struct nbcon_context *ctxt, u64 new_seq)
}
}

+bool printk_threads_enabled __ro_after_init;
+
/**
* nbcon_context_try_acquire_direct - Try to acquire directly
* @ctxt: The context of the caller
@@ -1542,7 +1544,7 @@ void nbcon_kthread_create(struct console *con)
if (!(con->flags & CON_NBCON) || !con->write_thread)
return;

- if (con->kthread)
+ if (!printk_threads_enabled || con->kthread)
return;

/*
@@ -1568,6 +1570,19 @@ void nbcon_kthread_create(struct console *con)
sched_set_normal(con->kthread, -20);
}

+static int __init printk_setup_threads(void)
+{
+ struct console *con;
+
+ console_list_lock();
+ printk_threads_enabled = true;
+ for_each_console(con)
+ nbcon_kthread_create(con);
+ console_list_unlock();
+ return 0;
+}
+early_initcall(printk_setup_threads);
+
/**
* nbcon_alloc - Allocate buffers needed by the nbcon console
* @con: Console to allocate buffers for
@@ -1617,6 +1632,7 @@ void nbcon_init(struct console *con, u64 init_seq)
init_irq_work(&con->irq_work, nbcon_irq_work);
nbcon_seq_force(con, init_seq);
nbcon_state_set(con, &state);
+ nbcon_kthread_create(con);
}

/**
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 457c01311a95..4613f9145a8e 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2389,6 +2389,9 @@ asmlinkage int vprintk_emit(int facility, int level,
*
* - When this CPU is in panic.
*
+ * - When booting, before the printing threads have been
+ * started.
+ *
* - During shutdown, since the printing threads may not get
* a chance to print the final messages.
*
@@ -2397,6 +2400,7 @@ asmlinkage int vprintk_emit(int facility, int level,
* consoles cannot print simultaneously with boot consoles.
*/
if (is_panic_context ||
+ !printk_threads_enabled ||
(system_state > SYSTEM_RUNNING)) {
nbcon_atomic_flush_pending();
}
@@ -3742,6 +3746,7 @@ EXPORT_SYMBOL(register_console);
static int unregister_console_locked(struct console *console)
{
bool use_device_lock = (console->flags & CON_NBCON) && console->write_atomic;
+ bool is_boot_con = (console->flags & CON_BOOT);
bool found_legacy_con = false;
bool found_nbcon_con = false;
bool found_boot_con = false;
@@ -3824,6 +3829,15 @@ static int unregister_console_locked(struct console *console)
if (!found_nbcon_con)
have_nbcon_console = found_nbcon_con;

+ /*
+ * When the last boot console unregisters, start up the
+ * printing threads.
+ */
+ if (is_boot_con && !have_boot_console) {
+ for_each_console(c)
+ nbcon_kthread_create(c);
+ }
+
return res;
}

--
2.39.2


2024-06-04 12:00:37

by Greg Kroah-Hartman

[permalink] [raw]
Subject: Re: [PATCH printk v2 15/18] tty: sysfs: Add nbcon support for 'active'

On Tue, Jun 04, 2024 at 01:30:50AM +0206, John Ogness wrote:
> Allow the 'active' attribute to list nbcon consoles.
>
> Signed-off-by: John Ogness <[email protected]>
> ---
> drivers/tty/tty_io.c | 9 +++++++--
> 1 file changed, 7 insertions(+), 2 deletions(-)

Acked-by: Greg Kroah-Hartman <[email protected]>

2024-06-04 13:34:59

by Juri Lelli

[permalink] [raw]
Subject: Re: [PATCH printk v2 00/18] add threaded printing + the rest

Hi John,

On 04/06/24 01:30, John Ogness wrote:
> Hi,
>
> This is v2 of a series to implement threaded console printing as well
> as some other minor pieces (such as proc and sysfs support). This
> series is only a subset of the original v1 [0]. In particular, this
> series represents patches 11, 12, 15 of the v1 series. For information
> about the motivation of the nbcon consoles, please read the cover
> letter of v1.
>
> This series provides the remaining pieces of the printk rework. All
> other components are either already mainline or are currently in
> linux-next. In particular this series does:

Our QE reported something like the following while testing the latest
rt-devel branch (I then could reproduce with this set applied on top of
linux-next).

---
... kernel: INFO: task khugepaged:351 blocked for more than 1 seconds.
... kernel: Not tainted 6.9.0-thrdprintk+ #3
... kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
... kernel: task:khugepaged state:D stack:0 pid:351 tgid:351 ppid:2 flags:0x00004000
... kernel: Call Trace:
... kernel: <TASK>
... kernel: __schedule+0x2bd/0x7f0
... kernel: ? __lock_release.isra.0+0x5e/0x170
... kernel: schedule+0x3d/0x100
... kernel: schedule_timeout+0x1ca/0x1f0
... kernel: ? mark_held_locks+0x49/0x80
... kernel: ? _raw_spin_unlock_irq+0x24/0x50
... kernel: ? lockdep_hardirqs_on+0x77/0x100
... kernel: __wait_for_common+0xb7/0x220
... kernel: ? __pfx_schedule_timeout+0x10/0x10
... kernel: __flush_work+0x70/0x90
... kernel: ? __pfx_wq_barrier_func+0x10/0x10
... kernel: __lru_add_drain_all+0x179/0x210
... kernel: khugepaged+0x73/0x200
... kernel: ? lockdep_hardirqs_on+0x77/0x100
... kernel: ? _raw_spin_unlock_irqrestore+0x38/0x60
... kernel: ? __pfx_khugepaged+0x10/0x10
... kernel: kthread+0xec/0x120
... kernel: ? __pfx_kthread+0x10/0x10
... kernel: ret_from_fork+0x2d/0x50
... kernel: ? __pfx_kthread+0x10/0x10
... kernel: ret_from_fork_asm+0x1a/0x30
... kernel: </TASK>
... kernel:
... Showing all locks held in the system:
... kernel: 1 lock held by khungtaskd/345:
... kernel: #0: ffffffff8cbff1c0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x32/0x1d0
... kernel: BUG: using smp_processor_id() in preemptible [00000000] code: khungtaskd/345
... kernel: caller is nbcon_get_cpu_emergency_nesting+0x25/0x40
... kernel: CPU: 30 PID: 345 Comm: khungtaskd Kdump: loaded Not tainted 6.9.0-thrdprintk+ #3
... kernel: Hardware name: Dell Inc. PowerEdge R740/04FC42, BIOS 2.10.2 02/24/2021
... kernel: Call Trace:
... kernel: <TASK>
... kernel: dump_stack_lvl+0x7f/0xa0
... kernel: check_preemption_disabled+0xbf/0xe0
... kernel: nbcon_get_cpu_emergency_nesting+0x25/0x40
... kernel: nbcon_cpu_emergency_flush+0xa/0x60
... kernel: debug_show_all_locks+0x9d/0x1d0
... kernel: check_hung_uninterruptible_tasks+0x4f0/0x540
... kernel: ? check_hung_uninterruptible_tasks+0x185/0x540
... kernel: ? __pfx_watchdog+0x10/0x10
... kernel: watchdog+0x99/0xa0
... kernel: kthread+0xec/0x120
... kernel: ? __pfx_kthread+0x10/0x10
... kernel: ret_from_fork+0x2d/0x50
... kernel: ? __pfx_kthread+0x10/0x10
... kernel: ret_from_fork_asm+0x1a/0x30
... kernel: </TASK>
---

It requires DEBUG_PREEMPT and LOCKDEP enabled, sched_rt_runtime_us = -1
and a while(1) loop running at FIFO for some time (I also set sysctl
kernel.hung_task_timeout_secs=1 to speed up reproduction).

Looks like check_hung_uninterruptible_tasks() requires some care as you
did already in linux-next for panic, rcu and lockdep ("Make emergency
sections ...")?

Thanks,
Juri


2024-06-05 08:09:28

by John Ogness

[permalink] [raw]
Subject: Re: [PATCH printk v2 00/18] add threaded printing + the rest

Hi Juri,

On 2024-06-04, Juri Lelli <[email protected]> wrote:
> Our QE reported something like the following while testing the latest
> rt-devel branch (I then could reproduce with this set applied on top of
> linux-next).
>
> ---
> ... kernel: INFO: task khugepaged:351 blocked for more than 1 seconds.
> ... kernel: Not tainted 6.9.0-thrdprintk+ #3
> ... kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> ... kernel: task:khugepaged state:D stack:0 pid:351 tgid:351 ppid:2 flags:0x00004000
> ... kernel: Call Trace:
> ... kernel: <TASK>
> ... kernel: __schedule+0x2bd/0x7f0
> ... kernel: ? __lock_release.isra.0+0x5e/0x170
> ... kernel: schedule+0x3d/0x100
> ... kernel: schedule_timeout+0x1ca/0x1f0
> ... kernel: ? mark_held_locks+0x49/0x80
> ... kernel: ? _raw_spin_unlock_irq+0x24/0x50
> ... kernel: ? lockdep_hardirqs_on+0x77/0x100
> ... kernel: __wait_for_common+0xb7/0x220
> ... kernel: ? __pfx_schedule_timeout+0x10/0x10
> ... kernel: __flush_work+0x70/0x90
> ... kernel: ? __pfx_wq_barrier_func+0x10/0x10
> ... kernel: __lru_add_drain_all+0x179/0x210
> ... kernel: khugepaged+0x73/0x200
> ... kernel: ? lockdep_hardirqs_on+0x77/0x100
> ... kernel: ? _raw_spin_unlock_irqrestore+0x38/0x60
> ... kernel: ? __pfx_khugepaged+0x10/0x10
> ... kernel: kthread+0xec/0x120
> ... kernel: ? __pfx_kthread+0x10/0x10
> ... kernel: ret_from_fork+0x2d/0x50
> ... kernel: ? __pfx_kthread+0x10/0x10
> ... kernel: ret_from_fork_asm+0x1a/0x30
> ... kernel: </TASK>
> ... kernel:
> ... Showing all locks held in the system:
> ... kernel: 1 lock held by khungtaskd/345:
> ... kernel: #0: ffffffff8cbff1c0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x32/0x1d0
> ... kernel: BUG: using smp_processor_id() in preemptible [00000000] code: khungtaskd/345
> ... kernel: caller is nbcon_get_cpu_emergency_nesting+0x25/0x40
> ... kernel: CPU: 30 PID: 345 Comm: khungtaskd Kdump: loaded Not tainted 6.9.0-thrdprintk+ #3
> ... kernel: Hardware name: Dell Inc. PowerEdge R740/04FC42, BIOS 2.10.2 02/24/2021
> ... kernel: Call Trace:
> ... kernel: <TASK>
> ... kernel: dump_stack_lvl+0x7f/0xa0
> ... kernel: check_preemption_disabled+0xbf/0xe0
> ... kernel: nbcon_get_cpu_emergency_nesting+0x25/0x40
> ... kernel: nbcon_cpu_emergency_flush+0xa/0x60
> ... kernel: debug_show_all_locks+0x9d/0x1d0
> ... kernel: check_hung_uninterruptible_tasks+0x4f0/0x540
> ... kernel: ? check_hung_uninterruptible_tasks+0x185/0x540
> ... kernel: ? __pfx_watchdog+0x10/0x10
> ... kernel: watchdog+0x99/0xa0
> ... kernel: kthread+0xec/0x120
> ... kernel: ? __pfx_kthread+0x10/0x10
> ... kernel: ret_from_fork+0x2d/0x50
> ... kernel: ? __pfx_kthread+0x10/0x10
> ... kernel: ret_from_fork_asm+0x1a/0x30
> ... kernel: </TASK>
> ---
>
> It requires DEBUG_PREEMPT and LOCKDEP enabled, sched_rt_runtime_us = -1
> and a while(1) loop running at FIFO for some time (I also set sysctl
> kernel.hung_task_timeout_secs=1 to speed up reproduction).
>
> Looks like check_hung_uninterruptible_tasks() requires some care as you
> did already in linux-next for panic, rcu and lockdep ("Make emergency
> sections ...")?

Yes, that probably is a good candidate for emergency mode.

However, your report is also identifying a real issue:
nbcon_cpu_emergency_flush() was implemented to be callable from
non-emergency contexts (in which case it should do nothing). However, in
order to check if it is an emergency context, migration needs to be
disabled.

Perhaps the below change can be made for v2 of this series?

John

diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 4b9645e7ed70..eeaf8465f492 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -1581,8 +1581,19 @@ void nbcon_cpu_emergency_exit(void)
*/
void nbcon_cpu_emergency_flush(void)
{
+ bool is_emergency;
+
+ /*
+ * If the current context is not an emergency context, preemption
+ * might be enabled. To be sure, disable preemption when checking
+ * if this is an emergency context.
+ */
+ preempt_disable();
+ is_emergency = (*nbcon_get_cpu_emergency_nesting() != 0);
+ preempt_enable();
+
/* The explicit flush is needed only in the emergency context. */
- if (*(nbcon_get_cpu_emergency_nesting()) == 0)
+ if (!is_emergency)
return;

nbcon_atomic_flush_pending();

2024-06-05 09:37:30

by Juri Lelli

[permalink] [raw]
Subject: Re: [PATCH printk v2 00/18] add threaded printing + the rest

On 05/06/24 10:15, John Ogness wrote:

...

> Yes, that probably is a good candidate for emergency mode.
>
> However, your report is also identifying a real issue:
> nbcon_cpu_emergency_flush() was implemented to be callable from
> non-emergency contexts (in which case it should do nothing). However, in
> order to check if it is an emergency context, migration needs to be
> disabled.

I see.

> Perhaps the below change can be made for v2 of this series?

Yes, this seems to cure it.

Thanks for the super quick reply and patch!

Best,
Juri

> diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
> index 4b9645e7ed70..eeaf8465f492 100644
> --- a/kernel/printk/nbcon.c
> +++ b/kernel/printk/nbcon.c
> @@ -1581,8 +1581,19 @@ void nbcon_cpu_emergency_exit(void)
> */
> void nbcon_cpu_emergency_flush(void)
> {
> + bool is_emergency;
> +
> + /*
> + * If the current context is not an emergency context, preemption
> + * might be enabled. To be sure, disable preemption when checking
> + * if this is an emergency context.
> + */
> + preempt_disable();
> + is_emergency = (*nbcon_get_cpu_emergency_nesting() != 0);
> + preempt_enable();
> +
> /* The explicit flush is needed only in the emergency context. */
> - if (*(nbcon_get_cpu_emergency_nesting()) == 0)
> + if (!is_emergency)
> return;
>
> nbcon_atomic_flush_pending();
>


2024-06-07 13:17:28

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On Tue 2024-06-04 01:30:39, John Ogness wrote:
> From: Thomas Gleixner <[email protected]>
>
> Provide the main implementation for running a printer kthread
> per nbcon console that is takeover/handover aware.

The changes done by this patch deserve a more detailed commit message ;-)

I updated this commit message in parallel with commenting the related
code changes. My later comment might explain the motivation for
writing the commit message this way.

<proposal>
Provide the main implementation for running a printer kthread per
nbcon console that is takeover/handover aware.

Once the kthread is running and available, it gets responsible for
flushing any pending messages which were added in NBCON_PRIO_NORMAL
context. Namely the legacy console_flush_all() and device_release()
do not longer flush the console. And nbcon_atomic_flush_pending()
used by nbcon_cpu_emergency_exit() does not longer flush messages
added after the emergency ones.

The kthread uses a new write_thread() callback with both device_lock()
and acquired the console context.

The console ownership handling is necessary for synchronization against
write_atomic() which is synchronized only via the console context
ownership.

The device_lock() serializes acquiring the console context with
NBCON_PRIO_NORMAL. It is needed when the device_lock() does not
disable preemption. It prevents the following race:

CPU0 CPU1

[ task A ]

nbcon_context_try_acquire()
# success with NORMAL prio
# .unsafe == false; // safe for takeover

[ schedule: task A -> B ]


WARN_ON()
nbcon_atomic_flush_pending()
nbcon_context_try_acquire()
# success with EMERGENCY prio

# flushing
nbcon_context_release()

# HERE: con->nbcon_state is free
# to take by anyone !!!


nbcon_context_try_acquire()
# success with NORMAL prio [ task B ]

[ schedule: task B -> A ]

nbcon_enter_unsafe()
nbcon_context_can_proceed()

BUG: nbcon_context_can_proceed() returns "true" because
the console is owned by a context on CPU0 with
NBCON_PRIO_NORMAL.

But it should return "false". The console is owned
by a context from task B and we do the check
in a context from task A.

The write context in the kthread will stay safe only when either of
the following conditions are true:

1. The kthread is the only context which acquires the console
with NBCON_PRIO_NORMAL.

2. Other caller acquires the console context with NBCON_PRIO_NORMAL
under the device_lock.

3. Other caller acquires the console context with NBCON_PRIO_NORMAL
with disabled preemption. It will release the context before
rescheduling.

It is even double guaranteed. First, __nbcon_atomic_flush_pending_con()
is called:

+ with disabled interrupts from nbcon_atomic_flush_pending_con()
+ under device_lock() from nbcon_device_release()

Second, they are not longer called with NBCON_PRIO_NORMAL when
con->kthread exists.

Also note that the kthreads are running with nice -20 so that they are
scheduled shortly after a printk call and with generous runtime
budgets.

This patch provides just the basic functionality. The followup changes
will add the necessary integration, for example, creating the kthreads
at the right time or waking them when a new message appear.
</proposal>

BTW: It really looks like the safety is double guaranteed. Maybe
the con->device_lock() is not needed in nbcon_kthread_func()
after all. Well, I would keep it to be on the safe side.

> --- a/include/linux/console.h
> +++ b/include/linux/console.h
> @@ -373,6 +376,27 @@ struct console {
> */
> void (*write_atomic)(struct console *con, struct nbcon_write_context *wctxt);
>
> + /**
> + * @write_thread:
> + *
> + * NBCON callback to write out text in task context.
> + *
> + * This callback is called after device_lock() and with the nbcon
> + * console acquired. Any necessary driver synchronization should have
> + * been performed by the device_lock() callback.
> + *
> + * This callback is always called from task context but with migration
> + * disabled.
> + *
> + * The same criteria for console ownership verification and unsafe
> + * sections applies as with write_atomic(). The difference between
> + * this callback and write_atomic() is that this callback is used
> + * during normal operation and is always called from task context.
> + * This allows drivers to operate in their own locking context for
> + * synchronizing output to the hardware.
> + */

The description is not bad. It seems to include all the important
information. Except than I still needed to scratch my head around it
to understand the real purpose and rules.

Namely, the following sentences are kind of vague and bring questions
which I had in the past before I understood all the relations:

1. "Any necessary driver synchronization should have been performed
by the device_lock() callback."

Q: Why do we need to take both device_lock() and the context then?
Q: Why the acquired context is not enough?

2. "This allows drivers to operate in their own locking context for
synchronizing output to the hardware."

Q: What exactly does this sentence mean?
Q: What is the driver?
Q: What are the output callbacks?
Q: How exactly is this related to write_atomic() and write_thread()?
Q: Is the context more strict or relaxed, in which way?

Also I still keep in my mind that nbcon_context_try_acquire() is not
safe with NBCON_NORMAL_PRIO with enabled preemption. There is
the race discussed in the previous patchset, see
https://lore.kernel.org/r/[email protected]

I wonder if we could be more strigthforward.

<my-take>
/**
* @write_thread:
*
* NBCON callback to write out text in task context.
*
* This callback must be called only in task context with both
* device_lock() and the nbcon console acquired.
*
* The same rules for console ownership verification and unsafe
* sections handling applies as with write_atomic().
*
* The console ownership handling is necessary for synchronization
* against write_atomic() which is synchronized only via the context.
*
* The device_lock() serializes acquiring the console context
* with NBCON_PRIO_NORMAL. It is necessary when the device_lock()
* does not disable preemption. The console context locking is
* not able to detect a race in the following scenario:
*
* 1. [Task A] owns a context with NBCON_PRIO_NORMAL on [CPU X]
* and is scheduled.
*
* 2. Another context takes over the lock with NBCON_PRIO_EMERGENCY
* and releases it.
*
* 3. [Task B] acquires a context with NBCON_PRIO_NORMAL on [CPU X]
* and is scheduled.
*
* 4. [Task A] gets running on [CPU X] and see that the console is
* is still owned by a task on [CPU X] with NBON_PRIO_NORMAL.
* It can't detect that it is actually owned by another task.
*/
</my-take>

My variant describes the purpose of device_lock() quite different way.
But I think that this is the real purpose and we must be clear about
it.

Sigh, I was not able to describe the race reasonably a shorter
way. Maybe, we should move this detailed explanation above,
nbcon_context_try_acquire() and use just a reference here.

> + void (*write_thread)(struct console *con, struct nbcon_write_context *wctxt);
> +
> /**
> * @device_lock:
> *
> --- a/kernel/printk/nbcon.c
> +++ b/kernel/printk/nbcon.c
> @@ -936,6 +944,120 @@ static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt)
> return nbcon_context_exit_unsafe(ctxt);
> }
>
> +/**
> + * nbcon_kthread_should_wakeup - Check whether a printer thread should wakeup
> + * @con: Console to operate on
> + * @ctxt: The nbcon context from nbcon_context_try_acquire()
> + *
> + * Return: True if the thread should shutdown or if the console is
> + * allowed to print and a record is available. False otherwise.
> + *
> + * After the thread wakes up, it must first check if it should shutdown before
> + * attempting any printing.
> + */
> +static bool nbcon_kthread_should_wakeup(struct console *con, struct nbcon_context *ctxt)
> +{
> + bool ret = false;
> + short flags;
> + int cookie;
> +
> + if (kthread_should_stop())
> + return true;
> +
> + cookie = console_srcu_read_lock();
> +
> + flags = console_srcu_read_flags(con);
> + if (console_is_usable(con, flags)) {
> + /* Bring the sequence in @ctxt up to date */
> + ctxt->seq = nbcon_seq_read(con);
> +
> + ret = prb_read_valid(prb, ctxt->seq, NULL);
> + }
> +
> + console_srcu_read_unlock(cookie);
> + return ret;
> +}
> +
> +/**
> + * nbcon_kthread_func - The printer thread function
> + * @__console: Console to operate on
> + *
> + * Return: 0
> + */
> +static int nbcon_kthread_func(void *__console)
> +{
> + struct console *con = __console;
> + struct nbcon_write_context wctxt = {
> + .ctxt.console = con,
> + .ctxt.prio = NBCON_PRIO_NORMAL,
> + };
> + struct nbcon_context *ctxt = &ACCESS_PRIVATE(&wctxt, ctxt);
> + short con_flags;
> + bool backlog;
> + int cookie;
> + int ret;
> +
> +wait_for_event:
> + /*
> + * Guarantee this task is visible on the rcuwait before
> + * checking the wake condition.
> + *
> + * The full memory barrier within set_current_state() of
> + * ___rcuwait_wait_event() pairs with the full memory
> + * barrier within rcuwait_has_sleeper().
> + *
> + * This pairs with rcuwait_has_sleeper:A and nbcon_kthread_wake:A.
> + */
> + ret = rcuwait_wait_event(&con->rcuwait,
> + nbcon_kthread_should_wakeup(con, ctxt),
> + TASK_INTERRUPTIBLE); /* LMM(nbcon_kthread_func:A) */
> +
> + if (kthread_should_stop())
> + return 0;
> +
> + /* Wait was interrupted by a spurious signal, go back to sleep. */
> + if (ret)
> + goto wait_for_event;
> +
> + do {
> + backlog = false;
> +

I am not sure how obvious is that we take the lock around the entire
operation. In principle, the console could not disappear. So it might
look like it is not really necessary. But it actually plays important
role when stopping/suspending the console. I would add a comment:

/*
* Keep the read lock around the entire operation so that
* synchronize_srcu() could prove that the kthread stopped
* or suspended printing.
*/

> + cookie = console_srcu_read_lock();
> +
> + con_flags = console_srcu_read_flags(con);
> +
> + if (console_is_usable(con, con_flags)) {
> + unsigned long lock_flags;
> +
> + con->device_lock(con, &lock_flags);
> +
> + /*
> + * Ensure this stays on the CPU to make handover and
> + * takeover possible.
> + */
> + cant_migrate();
> +
> + if (nbcon_context_try_acquire(ctxt)) {
> + /*
> + * If the emit fails, this context is no
> + * longer the owner.
> + */
> + if (nbcon_emit_next_record(&wctxt, false)) {
> + nbcon_context_release(ctxt);
> + backlog = ctxt->backlog;
> + }
> + }
> +
> + con->device_unlock(con, lock_flags);
> + }
> +
> + console_srcu_read_unlock(cookie);
> +
> + } while (backlog);

Thinking loudly:

We do not check kthread_should_stop() in the cycle. It means that it
would flush all messages before stopping the kthread. But only
when it is already in the cycle. It would not flush the messages
in the following scenario:

CPU0 CPU1

printk("Unregistering console\n");
nbcon_wake_threads();
irq_work_queue(&con->irq_work);

kthread_stop(con->thread);

nbcon_kthread_func()
rcuwait_wait_event()
nbcon_kthread_should_wakeup()

if (kthread_should_stop())
// true
return 0

Result: The kthread did not flush the pending messages in this case.

I do not have strong opinion. Well, it would make sense to flush
all messages before stopping the kthread,

Maybe, we should move kthread_should_stop() check here.

Maybe, we should move the flushing cycle into a separate function
and the kthread might look like:

do {
rcuwait_wait_event(&con->rcuwait,
nbcon_kthread_should_wakeup(con, ctxt),
TASK_INTERRUPTIBLE); /* LMM(nbcon_kthread_func:A) */

nbcon_kthread_flush();
while (!kthread_should_stop);

Note that I did not add the check for the spurious signal. It looks
just like an optimization. IMHO, it is not worth the code churn.
Also the spurious signal does not mean that there are no
pending messages. And if we want to flush everything before exiting...

Anyway, we probably should document the (desired) behavior in the function
description.

> +
> + goto wait_for_event;
> +}
> +
> /* Track the nbcon emergency nesting per CPU. */
> static DEFINE_PER_CPU(unsigned int, nbcon_pcpu_emergency_nesting);
> static unsigned int early_nbcon_pcpu_emergency_nesting __initdata;
> @@ -1332,6 +1454,63 @@ void nbcon_cpu_emergency_flush(void)
> }
> }
>
> +/*
> + * nbcon_kthread_stop - Stop a printer thread
> + * @con: Console to operate on
> + */
> +static void nbcon_kthread_stop(struct console *con)
> +{
> + lockdep_assert_console_list_lock_held();
> +
> + if (!con->kthread)
> + return;
> +
> + kthread_stop(con->kthread);
> + con->kthread = NULL;
> +}
> +
> +/**
> + * nbcon_kthread_create - Create a printer thread
> + * @con: Console to operate on
> + *
> + * If it fails, let the console proceed. The atomic part might
> + * be usable and useful.
> + */
> +void nbcon_kthread_create(struct console *con)
> +{
> + struct task_struct *kt;
> +
> + lockdep_assert_console_list_lock_held();
> +
> + if (!(con->flags & CON_NBCON) || !con->write_thread)
> + return;
> +
> + if (con->kthread)
> + return;
> +
> + /*
> + * Printer threads cannot be started as long as any boot console is
> + * registered because there is no way to synchronize the hardware
> + * registers between boot console code and regular console code.
> + */
> + if (have_boot_console)
> + return;
> +
> + kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name, con->index);
> + if (IS_ERR(kt)) {
> + con_printk(KERN_ERR, con, "failed to start printing thread\n");
> + return;

I am a bit surprised that we ignore the error here.

Hmm, it likely works in this patch because the legacy code would still
flush the console when con->thread is not assigned.

But it would stop working later when the legacy loop is disabled
by the global @printk_threads_enabled variable.


> + }
> +

Thinking loudly:

The kthread is running and started processing messages at this moment.
But con->kthraed is not set yet.

All this is done under @console_list_lock. It only guarantees that
the struct console would not disappear while some code access it under
console_srcu_read_lock().

The value is used in console_flush_all() and in nbcon_device_release()
to decide whether to flush the console directly or not.

I first though that console_flush_all() and nbcon_device_release()
could flush the messages using write_atomic() in parallel with
the kthread and it might create the race with NBCON_PRIO_NORMAL
context ownership.

But both calls will ignore this console until it is added into
@console_list which is done later under con->device_lock().

Not to say that:

+ console_flush_all() acquires the nbcon context with interrupts
disabled => race prevented

+ nbcon_device_release() acquires the nbcon context under device
lock => serialized with the kthread

So we are on the safe side (double guaranteed). Well, it took me quite
some time to realize this. It might be worth a comment.

<proposal>
/*
* Some users check con->kthread to decide whether to flush
* the messages directly using con->write_atomic(). Note that
* possible races with the kthread are double prevented.
*
* First, the users ignore this console until it is added into
* @console_list which is done under con->device_lock().
* Second, the calls would be additionaly serialized by acquiring
* the console context.
*/
</proposal>
> + con->kthread = kt;
> +
> + /*
> + * It is important that console printing threads are scheduled
> + * shortly after a printk call and with generous runtime budgets.
> + */
> + sched_set_normal(con->kthread, -20);

I would prefer to move this into a separate patch. I feel that it
might be kind of controversial and subject to a change in the future.
We should not hide this "tiny" detail in this mega patch ;-)

That said, the low "nice" value makes perfect sense to me.
And I makes me feel comfortable.

> +}
> +
> /**
> * nbcon_alloc - Allocate buffers needed by the nbcon console
> * @con: Console to allocate buffers for
> @@ -1458,6 +1639,7 @@ void nbcon_device_release(struct console *con)
> */
> cookie = console_srcu_read_lock();
> if (console_is_usable(con, console_srcu_read_flags(con)) &&
> + !con->kthread &&

This would deserve updating the comment like in nbcon_atomic_flush_pending_con().

> prb_read_valid(prb, nbcon_seq_read(con), NULL)) {
> __nbcon_atomic_flush_pending_con(con, prb_next_reserve_seq(prb), false);
> }

Best Regards,
Petr

2024-06-10 12:09:31

by John Ogness

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On 2024-06-07, Petr Mladek <[email protected]> wrote:
> I updated this commit message in parallel with commenting the related
> code changes. My later comment might explain the motivation for
> writing the commit message this way.

I am OK with your proposed commit message. Thank you for taking the time
to fill in all the details.

> <proposal>

[...]

> The write context in the kthread will stay safe only when either of
> the following conditions are true:
>
> 1. The kthread is the only context which acquires the console
> with NBCON_PRIO_NORMAL.
>
> 2. Other caller acquires the console context with NBCON_PRIO_NORMAL
> under the device_lock.
>
> 3. Other caller acquires the console context with NBCON_PRIO_NORMAL
> with disabled preemption. It will release the context before
> rescheduling.
>
> It is even double guaranteed. First, __nbcon_atomic_flush_pending_con()
> is called:
>
> + with disabled interrupts from nbcon_atomic_flush_pending_con()
> + under device_lock() from nbcon_device_release()

[...]

> </proposal>
>
> BTW: It really looks like the safety is double guaranteed. Maybe
> the con->device_lock() is not needed in nbcon_kthread_func()
> after all. Well, I would keep it to be on the safe side.

For the threaded case it is technically correct to say the safety is
double guaranteed. But the outer safety (device_lock()) can provide a
preemptible lock, which is the key for the non-interference property of
the threaded printers.

For example, for an nbcon framebuffer console, device_lock() most likely
will be a mutex.

During normal operation, the inner safety (console context) will never
be contended. That really only exists to synchronize the atomic case.

>> --- a/include/linux/console.h
>> +++ b/include/linux/console.h
>> @@ -373,6 +376,27 @@ struct console {
>> */
>> void (*write_atomic)(struct console *con, struct nbcon_write_context *wctxt);
>>
>> + /**
>> + * @write_thread:
>> + *
>> + * NBCON callback to write out text in task context.
>> + *
>> + * This callback is called after device_lock() and with the nbcon
>> + * console acquired. Any necessary driver synchronization should have
>> + * been performed by the device_lock() callback.
>> + *
>> + * This callback is always called from task context but with migration
>> + * disabled.
>> + *
>> + * The same criteria for console ownership verification and unsafe
>> + * sections applies as with write_atomic(). The difference between
>> + * this callback and write_atomic() is that this callback is used
>> + * during normal operation and is always called from task context.
>> + * This allows drivers to operate in their own locking context for
>> + * synchronizing output to the hardware.
>> + */
>
> The description is not bad. It seems to include all the important
> information. Except than I still needed to scratch my head around it
> to understand the real purpose and rules.
>
> Namely, the following sentences are kind of vague and bring questions
> which I had in the past before I understood all the relations:
>
> 1. "Any necessary driver synchronization should have been performed
> by the device_lock() callback."
>
> Q: Why do we need to take both device_lock() and the context then?

The device_lock() enables the non-interference property during normal
operation. OTOH the context is taken to synchronize against non-normal
(emergency/panic) operation.

> Q: Why the acquired context is not enough?

Because the context _requires_ disabling preemption during all driver
activity, which is a major source of interference to the system.

If you only care about UART drivers and !PREEMPT_RT, then there really
is not much difference between spinning on a spinlock vs. spinning on a
context. But for non-UART drivers or PREEMPT_RT, there is a huge
difference between blocking on device_lock() with preemption enabled vs.
spinning on a context.

I think it really helps to see the importance if you assume
device_lock() is a mutex. (All the printk code must also make this
assumption.)

> 2. "This allows drivers to operate in their own locking context for
> synchronizing output to the hardware."
>
> Q: What exactly does this sentence mean?

For example, if a console driver uses a mutex to synchronize hardware
access, it can implement this callback knowing it is under that
mutex. This also applies for any locking mechanism the driver might use.

> Q: What is the driver?

The code that implements _all_ access to the hardware for _all_
purposes.

> Q: What are the output callbacks?

I am not referring to callbacks. I am referring to any code in the
driver that is accessing the parts of the hardware that are related to
outputting kernel messages.

> Q: How exactly is this related to write_atomic() and write_thread()?

Both nbcon console write callbacks must synchronize against other
activities of the driver. For write_thread(), it is primarily via
device_lock().

> Q: Is the context more strict or relaxed, in which way?

If device_lock() is using a locking mechanism that does not disable
preemption, write_thread() is quite a bit more relaxed than the disabled
preemption context of write_atomic().

> Also I still keep in my mind that nbcon_context_try_acquire() is not
> safe with NBCON_NORMAL_PRIO with enabled preemption. There is
> the race discussed in the previous patchset, see
> https://lore.kernel.org/r/[email protected]
>
> I wonder if we could be more strigthforward.
>
> <my-take>
> /**
> * @write_thread:
> *
> * NBCON callback to write out text in task context.
> *
> * This callback must be called only in task context with both
> * device_lock() and the nbcon console acquired.
> *
> * The same rules for console ownership verification and unsafe
> * sections handling applies as with write_atomic().
> *
> * The console ownership handling is necessary for synchronization
> * against write_atomic() which is synchronized only via the context.
> *
> * The device_lock() serializes acquiring the console context
> * with NBCON_PRIO_NORMAL. It is necessary when the device_lock()
> * does not disable preemption. The console context locking is
> * not able to detect a race in the following scenario:
> *
> * 1. [Task A] owns a context with NBCON_PRIO_NORMAL on [CPU X]
> * and is scheduled.
> *
> * 2. Another context takes over the lock with NBCON_PRIO_EMERGENCY
> * and releases it.
> *
> * 3. [Task B] acquires a context with NBCON_PRIO_NORMAL on [CPU X]
> * and is scheduled.
> *
> * 4. [Task A] gets running on [CPU X] and see that the console is
> * is still owned by a task on [CPU X] with NBON_PRIO_NORMAL.
> * It can't detect that it is actually owned by another task.
> */
> </my-take>
>
> My variant describes the purpose of device_lock() quite different way.
> But I think that this is the real purpose and we must be clear about
> it.

I would move that last part (starting with "The device_lock()
serializes...") into the kerneldoc for device_lock(). It really has
nothing to do with the write_thread() callback.

> Sigh, I was not able to describe the race reasonably a shorter
> way. Maybe, we should move this detailed explanation above,
> nbcon_context_try_acquire() and use just a reference here.

How about putting it as kerneldoc for nbcon_owner_matches() and refer to
it there from the device_lock() kerneldoc (or vice versa)?

For the write_thread() kerneldoc we could refer to the device_lock()
kerneldoc.

>> +/**
>> + * nbcon_kthread_func - The printer thread function
>> + * @__console: Console to operate on
>> + *
>> + * Return: 0
>> + */
>> +static int nbcon_kthread_func(void *__console)
>> +{
>> + struct console *con = __console;
>> + struct nbcon_write_context wctxt = {
>> + .ctxt.console = con,
>> + .ctxt.prio = NBCON_PRIO_NORMAL,
>> + };
>> + struct nbcon_context *ctxt = &ACCESS_PRIVATE(&wctxt, ctxt);
>> + short con_flags;
>> + bool backlog;
>> + int cookie;
>> + int ret;
>> +
>> +wait_for_event:
>> + /*
>> + * Guarantee this task is visible on the rcuwait before
>> + * checking the wake condition.
>> + *
>> + * The full memory barrier within set_current_state() of
>> + * ___rcuwait_wait_event() pairs with the full memory
>> + * barrier within rcuwait_has_sleeper().
>> + *
>> + * This pairs with rcuwait_has_sleeper:A and nbcon_kthread_wake:A.
>> + */
>> + ret = rcuwait_wait_event(&con->rcuwait,
>> + nbcon_kthread_should_wakeup(con, ctxt),
>> + TASK_INTERRUPTIBLE); /* LMM(nbcon_kthread_func:A) */
>> +
>> + if (kthread_should_stop())
>> + return 0;
>> +
>> + /* Wait was interrupted by a spurious signal, go back to sleep. */
>> + if (ret)
>> + goto wait_for_event;
>> +
>> + do {
>> + backlog = false;
>> +
>
> I am not sure how obvious is that we take the lock around the entire
> operation. In principle, the console could not disappear. So it might
> look like it is not really necessary. But it actually plays important
> role when stopping/suspending the console. I would add a comment:
>
> /*
> * Keep the read lock around the entire operation so that
> * synchronize_srcu() could prove that the kthread stopped
> * or suspended printing.
> */

Agreed.

>> + cookie = console_srcu_read_lock();
>> +
>> + con_flags = console_srcu_read_flags(con);
>> +
>> + if (console_is_usable(con, con_flags)) {
>> + unsigned long lock_flags;
>> +
>> + con->device_lock(con, &lock_flags);
>> +
>> + /*
>> + * Ensure this stays on the CPU to make handover and
>> + * takeover possible.
>> + */
>> + cant_migrate();
>> +
>> + if (nbcon_context_try_acquire(ctxt)) {
>> + /*
>> + * If the emit fails, this context is no
>> + * longer the owner.
>> + */
>> + if (nbcon_emit_next_record(&wctxt, false)) {
>> + nbcon_context_release(ctxt);
>> + backlog = ctxt->backlog;
>> + }
>> + }
>> +
>> + con->device_unlock(con, lock_flags);
>> + }
>> +
>> + console_srcu_read_unlock(cookie);
>> +
>> + } while (backlog);
>
> Thinking loudly:
>
> We do not check kthread_should_stop() in the cycle. It means that it
> would flush all messages before stopping the kthread. But only
> when it is already in the cycle. It would not flush the messages
> in the following scenario:
>
> CPU0 CPU1
>
> printk("Unregistering console\n");
> nbcon_wake_threads();
> irq_work_queue(&con->irq_work);
>
> kthread_stop(con->thread);
>
> nbcon_kthread_func()
> rcuwait_wait_event()
> nbcon_kthread_should_wakeup()
>
> if (kthread_should_stop())
> // true
> return 0
>
> Result: The kthread did not flush the pending messages in this case.

Nice catch. How about if we add the following to
unregister_console_locked():

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index f2ac7aaab234..fab69ca7f938 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3995,6 +3995,8 @@ static int unregister_console_locked(struct console *console)
if (res > 0)
return 0;

+ __pr_flush(console, 1000, true);
+
/* Disable it unconditionally */
console_srcu_write_flags(console, console->flags & ~CON_ENABLED);

>> + kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name, con->index);
>> + if (IS_ERR(kt)) {
>> + con_printk(KERN_ERR, con, "failed to start printing thread\n");
>> + return;
>
> I am a bit surprised that we ignore the error here.
>
>
> Hmm, it likely works in this patch because the legacy code would still
> flush the console when con->thread is not assigned.
>
> But it would stop working later when the legacy loop is disabled
> by the global @printk_threads_enabled variable.

The thread failing to start is a serious issue. Particularly for
PREEMPT_RT. Probably it should be something like:

if (WARN_ON(IS_ERR(kt))) {

In fact, I nbcon_atomic_flush_pending_con() and nbcon_device_release()
need to check @printk_threads_enabled _instead_ of con->kthread. Once
"threading mode" has been activated, there should be _no_ atomic
printing during normal operation.

> The kthread is running and started processing messages at this moment.
> But con->kthread is not set yet.

[...]

> It might be worth a comment.
>
> <proposal>
> /*
> * Some users check con->kthread to decide whether to flush
> * the messages directly using con->write_atomic(). Note that
> * possible races with the kthread are double prevented.
> *
> * First, the users ignore this console until it is added into
> * @console_list which is done under con->device_lock().
> * Second, the calls would be additionaly serialized by acquiring
> * the console context.
> */
> </proposal>

It is enough to mention only the calling context. How about:

/*
* Some users check con->kthread to decide whether to flush the
* messages directly using con->write_atomic(). A possible race
* with the kthread is prevented because all printing is
* serialized by acquiring the console context.
*/

>> + con->kthread = kt;

>> + /*
>> + * It is important that console printing threads are scheduled
>> + * shortly after a printk call and with generous runtime budgets.
>> + */
>> + sched_set_normal(con->kthread, -20);
>
> I would prefer to move this into a separate patch. I feel that it
> might be kind of controversial and subject to a change in the future.
> We should not hide this "tiny" detail in this mega patch ;-)

OK.

>> @@ -1458,6 +1639,7 @@ void nbcon_device_release(struct console *con)
>> */
>> cookie = console_srcu_read_lock();
>> if (console_is_usable(con, console_srcu_read_flags(con)) &&
>> + !con->kthread &&
>
> This would deserve updating the comment like in
> nbcon_atomic_flush_pending_con().

OK.

John

2024-06-11 14:51:42

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On Mon 2024-06-10 14:15:10, John Ogness wrote:
> On 2024-06-07, Petr Mladek <[email protected]> wrote:
> > I updated this commit message in parallel with commenting the related
> > code changes. My later comment might explain the motivation for
> > writing the commit message this way.
>
> I am OK with your proposed commit message. Thank you for taking the time
> to fill in all the details.

We should probably update it a bit so that it describes the role
of the device_lock() more precisely. See the discussion below.
> > <proposal>
>
> [...]
>
> > The write context in the kthread will stay safe only when either of
> > the following conditions are true:
> >
> > 1. The kthread is the only context which acquires the console
> > with NBCON_PRIO_NORMAL.
> >
> > 2. Other caller acquires the console context with NBCON_PRIO_NORMAL
> > under the device_lock.
> >
> > 3. Other caller acquires the console context with NBCON_PRIO_NORMAL
> > with disabled preemption. It will release the context before
> > rescheduling.
> >
> > It is even double guaranteed. First, __nbcon_atomic_flush_pending_con()
> > is called:
> >
> > + with disabled interrupts from nbcon_atomic_flush_pending_con()
> > + under device_lock() from nbcon_device_release()
>
> [...]
>
> > </proposal>
> >
> > BTW: It really looks like the safety is double guaranteed. Maybe
> > the con->device_lock() is not needed in nbcon_kthread_func()
> > after all. Well, I would keep it to be on the safe side.
>
> For the threaded case it is technically correct to say the safety is
> double guaranteed. But the outer safety (device_lock()) can provide a
> preemptible lock, which is the key for the non-interference property of
> the threaded printers.
>
> For example, for an nbcon framebuffer console, device_lock() most likely
> will be a mutex.
>
> During normal operation, the inner safety (console context) will never
> be contended. That really only exists to synchronize the atomic case.

I see. For example, the spin_lock_irqsave() in __uart_port_lock_irqsave()
will be sleeping lock in RT => preserving RT guarantees. And it will
make sure that the inner nbcon_context_try_acquire() would never
have to spin => never break the RT guarantees.

It makes perfect sense. Do I get it correctly?

> >> --- a/include/linux/console.h
> >> +++ b/include/linux/console.h
> >> @@ -373,6 +376,27 @@ struct console {
> >> */
> >> void (*write_atomic)(struct console *con, struct nbcon_write_context *wctxt);
> >>
> >> + /**
> >> + * @write_thread:
> >> + *
> >> + * NBCON callback to write out text in task context.
> >> + *
> >> + * This callback is called after device_lock() and with the nbcon
> >> + * console acquired. Any necessary driver synchronization should have
> >> + * been performed by the device_lock() callback.
> >> + *
> >> + * This callback is always called from task context but with migration
> >> + * disabled.
> >> + *
> >> + * The same criteria for console ownership verification and unsafe
> >> + * sections applies as with write_atomic(). The difference between
> >> + * this callback and write_atomic() is that this callback is used
> >> + * during normal operation and is always called from task context.
> >> + * This allows drivers to operate in their own locking context for
> >> + * synchronizing output to the hardware.
> >> + */
> >
> > The description is not bad. It seems to include all the important
> > information. Except than I still needed to scratch my head around it
> > to understand the real purpose and rules.
> >
> > Namely, the following sentences are kind of vague and bring questions
> > which I had in the past before I understood all the relations:
> >
> > 1. "Any necessary driver synchronization should have been performed
> > by the device_lock() callback."
> >
> > Q: Why do we need to take both device_lock() and the context then?
>
> The device_lock() enables the non-interference property during normal
> operation. OTOH the context is taken to synchronize against non-normal
> (emergency/panic) operation.
>
> > Q: Why the acquired context is not enough?
>
> Because the context _requires_ disabling preemption during all driver
> activity, which is a major source of interference to the system.
>
> If you only care about UART drivers and !PREEMPT_RT, then there really
> is not much difference between spinning on a spinlock vs. spinning on a
> context. But for non-UART drivers or PREEMPT_RT, there is a huge
> difference between blocking on device_lock() with preemption enabled vs.
> spinning on a context.

This helped a lot. My brain is not trained to see these RT-specific
effects.


> I think it really helps to see the importance if you assume
> device_lock() is a mutex. (All the printk code must also make this
> assumption.)

From my POV, the game changer is the RT aspect. I knew that
for graphics console drivers the mutex was a nice-to-have thing.
I did not realize that for RT it was a must-to-have thing.

I mean, I did not realize that nbcon_console_try_acquire() was
not RT friendly. We could also say that nbcon_console_try_acquire()
is not acceptable for RT as the primary synchronization primitive.

> > I wonder if we could be more strigthforward.
> >
> > <my-take>
> > /**
> > * @write_thread:
> > *
> > * NBCON callback to write out text in task context.
> > *
> > * This callback must be called only in task context with both
> > * device_lock() and the nbcon console acquired.
> > *
> > * The same rules for console ownership verification and unsafe
> > * sections handling applies as with write_atomic().
> > *
> > * The console ownership handling is necessary for synchronization
> > * against write_atomic() which is synchronized only via the context.
> > *
> > * The device_lock() serializes acquiring the console context
> > * with NBCON_PRIO_NORMAL. It is necessary when the device_lock()
> > * does not disable preemption. The console context locking is
> > * not able to detect a race in the following scenario:
> > *
> > * 1. [Task A] owns a context with NBCON_PRIO_NORMAL on [CPU X]
> > * and is scheduled.
> > *
> > * 2. Another context takes over the lock with NBCON_PRIO_EMERGENCY
> > * and releases it.
> > *
> > * 3. [Task B] acquires a context with NBCON_PRIO_NORMAL on [CPU X]
> > * and is scheduled.
> > *
> > * 4. [Task A] gets running on [CPU X] and see that the console is
> > * is still owned by a task on [CPU X] with NBON_PRIO_NORMAL.
> > * It can't detect that it is actually owned by another task.
> > */
> > </my-take>
> >
> > My variant describes the purpose of device_lock() quite different way.
> > But I think that this is the real purpose and we must be clear about
> > it.
>
> I would move that last part (starting with "The device_lock()
> serializes...") into the kerneldoc for device_lock(). It really has
> nothing to do with the write_thread() callback.

I agree that describing the details of the race is not important here.

Well, I would still like to describe the role of device_lock()
for write_kthread(). It would help even me to create a better
mental model ;-)

What about the following?

<proposal-2>
/**
* @write_thread:
*
* NBCON callback to write out text in task context.
*
* This callback must be called only in task context with both
* device_lock() and the nbcon console acquired with
* NBCON_PRIO_NORMAL.
*
* The same rules for console ownership verification and unsafe
* sections handling applies as with write_atomic().
*
* The console ownership handling is necessary for synchronization
* against write_atomic() which is synchronized only via the context.
*
* The device_lock() provides the primary serialization for operations
* on the device. It might be as relaxed (mutex)[*] or as tight
* (disabled preemption and interrupts) as needed. It allows
* the kthread to operate in the least restrictive mode[**].
*
* [*] Standalone nbcon_context_try_acquire() is not safe with
* the preemption enabled, see nbcon_owner_matches(). But it
* can be safe when always called in the preemptive context
* under the device_lock().
*
* [**] The device_lock() makes sure that nbcon_context_try_acquire()
* would never need to spin which is important especially with
* PREEMPT_RT.
*/
</proposal-2>


> > Sigh, I was not able to describe the race reasonably a shorter
> > way. Maybe, we should move this detailed explanation above,
> > nbcon_context_try_acquire() and use just a reference here.
>
> How about putting it as kerneldoc for nbcon_owner_matches() and refer to
> it there from the device_lock() kerneldoc (or vice versa)?

Yup. nbcon_owner_matches() looks like the right place for details
about the possible race.

> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3995,6 +3995,8 @@ static int unregister_console_locked(struct console *console)
> if (res > 0)
> return 0;
>
> + __pr_flush(console, 1000, true);
> +
> /* Disable it unconditionally */
> console_srcu_write_flags(console, console->flags & ~CON_ENABLED);

Makes sense.

And it actually means that it is too late to flush messages
when kthread_should_stop() returns true. So, it does not matter if
we check it in the while(backlog) loop or not. Well, it might be
worth a comment in the code.

> >> + kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name, con->index);
> >> + if (IS_ERR(kt)) {
> >> + con_printk(KERN_ERR, con, "failed to start printing thread\n");
> >> + return;
> >
> > I am a bit surprised that we ignore the error here.
> >
> >
> > Hmm, it likely works in this patch because the legacy code would still
> > flush the console when con->thread is not assigned.
> >
> > But it would stop working later when the legacy loop is disabled
> > by the global @printk_threads_enabled variable.
>
> The thread failing to start is a serious issue. Particularly for
> PREEMPT_RT.

I agree.

> Probably it should be something like:
>
> if (WARN_ON(IS_ERR(kt))) {

Might make sense.

> In fact, I nbcon_atomic_flush_pending_con() and nbcon_device_release()
> need to check @printk_threads_enabled _instead_ of con->kthread. Once
> "threading mode" has been activated, there should be _no_ atomic
> printing during normal operation.

OK, we have two possibilities when a kthread could not get started:

1. printk() could fallback to flushing messages via write_atomic()
in the legacy console_unlock() loop.

It might break RT guarantees but people would see the messages.


2. The affected console would flush the messages only in emergency
or panic mode.

This would preserve RT guarantees. And printk() would still be
able to show emergency and panic messages, including the WARN_ON()
about that the printk kthread did not start.


It seems that you prefer the 2nd variant. But you are RT-biased ;-)
I would personally prefer the 1st variant. But I am printk-biased ;-)

Honestly, if the system is not able to start the kthread then
it is probably useless anyway. I would prefer if printk keeps working
so that people know what is going on ;-)

> > The kthread is running and started processing messages at this moment.
> > But con->kthread is not set yet.
>
> [...]
>
> > It might be worth a comment.
> >
> > <proposal>
> > /*
> > * Some users check con->kthread to decide whether to flush
> > * the messages directly using con->write_atomic(). Note that
> > * possible races with the kthread are double prevented.
> > *
> > * First, the users ignore this console until it is added into
> > * @console_list which is done under con->device_lock().
> > * Second, the calls would be additionaly serialized by acquiring
> > * the console context.
> > */
> > </proposal>
>
> It is enough to mention only the calling context. How about:
>
> /*
> * Some users check con->kthread to decide whether to flush the
> * messages directly using con->write_atomic(). A possible race
> * with the kthread is prevented because all printing is
> * serialized by acquiring the console context.
> */

I am not sure what is more important. In fact, all these users
check con->kthread only when the console is on @console_list.
So, maybe the note about #console_list is more useful.

BTW: uart_port_lock() allows access to the device and it acquires
the context only when the console appears on @console_list.
Well, the access is serialized by the device_lock.

> >> + con->kthread = kt;

After all, I would add two comments, like these:

<proposal-2>
/*
* Any access to the console device is serialized either by
* device_lock() or console context or both.
*/
kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name, con->index);
[...]

/*
* Some users check con->kthread to decide whether to flush
* the messages directly using con->write_atomic(). But they
* do so only when the console is already in @console_list.
*/
con->kthread = kt;
</proposal-2>

Best Regards,
Petr

2024-06-12 08:51:28

by John Ogness

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On 2024-06-11, Petr Mladek <[email protected]> wrote:
>> During normal operation, the inner safety (console context) will never
>> be contended. That really only exists to synchronize the atomic case.
>
> I see. For example, the spin_lock_irqsave() in __uart_port_lock_irqsave()
> will be sleeping lock in RT => preserving RT guarantees. And it will
> make sure that the inner nbcon_context_try_acquire() would never
> have to spin => never break the RT guarantees.
>
> It makes perfect sense. Do I get it correctly?

Yes.

> Well, I would still like to describe the role of device_lock()
> for write_kthread(). It would help even me to create a better
> mental model ;-)
>
> What about the following?
>
> <proposal-2>
> /**
> * @write_thread:
> *
> * NBCON callback to write out text in task context.
> *
> * This callback must be called only in task context with both
> * device_lock() and the nbcon console acquired with
> * NBCON_PRIO_NORMAL.
> *
> * The same rules for console ownership verification and unsafe
> * sections handling applies as with write_atomic().
> *
> * The console ownership handling is necessary for synchronization
> * against write_atomic() which is synchronized only via the context.
> *
> * The device_lock() provides the primary serialization for operations
> * on the device. It might be as relaxed (mutex)[*] or as tight
> * (disabled preemption and interrupts) as needed. It allows
> * the kthread to operate in the least restrictive mode[**].
> *
> * [*] Standalone nbcon_context_try_acquire() is not safe with
> * the preemption enabled, see nbcon_owner_matches(). But it
> * can be safe when always called in the preemptive context
> * under the device_lock().
> *
> * [**] The device_lock() makes sure that nbcon_context_try_acquire()
> * would never need to spin which is important especially with
> * PREEMPT_RT.
> */
> </proposal-2>

OK. I will use this.

>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -3995,6 +3995,8 @@ static int unregister_console_locked(struct console *console)
>> if (res > 0)
>> return 0;
>>
>> + __pr_flush(console, 1000, true);
>> +
>> /* Disable it unconditionally */
>> console_srcu_write_flags(console, console->flags & ~CON_ENABLED);
>
> Makes sense.
>
> And it actually means that it is too late to flush messages
> when kthread_should_stop() returns true. So, it does not matter if
> we check it in the while(backlog) loop or not. Well, it might be
> worth a comment in the code.

I will add a comment for this.

>> The thread failing to start is a serious issue. Particularly for
>> PREEMPT_RT.
>
> I agree.
>
>> Probably it should be something like:
>>
>> if (WARN_ON(IS_ERR(kt))) {
>
> Might make sense.

I will add this for v2.

> Honestly, if the system is not able to start the kthread then
> it is probably useless anyway. I would prefer if printk keeps working
> so that people know what is going on ;-)

OK. For v2 I will change it to fallback to the legacy printing for those
consoles that do not have a kthread.

> After all, I would add two comments, like these:
>
> <proposal-2>
> /*
> * Any access to the console device is serialized either by
> * device_lock() or console context or both.
> */
> kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name,
> con->index);
> [...]
>
> /*
> * Some users check con->kthread to decide whether to flush
> * the messages directly using con->write_atomic(). But they
> * do so only when the console is already in @console_list.
> */

I do not understand how @console_list is related to racing between
non-thread and thread. kthreads are not only created during
registration. For example, they can be created much later when the last
boot console unregisters.

I am OK with the first comment of this proposal. I do not understand the
second comment.

> con->kthread = kt;
> </proposal-2>

John

2024-06-12 09:25:37

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On Wed 2024-06-12 10:57:11, John Ogness wrote:
> On 2024-06-11, Petr Mladek <[email protected]> wrote:
> >> --- a/kernel/printk/printk.c
> >> +++ b/kernel/printk/printk.c
> >> The thread failing to start is a serious issue. Particularly for
> >> PREEMPT_RT.
> >
> > I agree.
> >
> >> Probably it should be something like:
> >>
> >> if (WARN_ON(IS_ERR(kt))) {
> >
> > Might make sense.
>
> I will add this for v2.
>
> > Honestly, if the system is not able to start the kthread then
> > it is probably useless anyway. I would prefer if printk keeps working
> > so that people know what is going on ;-)
>
> OK. For v2 I will change it to fallback to the legacy printing for those
> consoles that do not have a kthread.
>
> > After all, I would add two comments, like these:
> >
> > <proposal-2>
> > /*
> > * Any access to the console device is serialized either by
> > * device_lock() or console context or both.
> > */
> > kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name,
> > con->index);
> > [...]
> >
> > /*
> > * Some users check con->kthread to decide whether to flush
> > * the messages directly using con->write_atomic(). But they
> > * do so only when the console is already in @console_list.
> > */
>
> I do not understand how @console_list is related to racing between
> non-thread and thread. kthreads are not only created during
> registration. For example, they can be created much later when the last
> boot console unregisters.

I had in mind two particular code paths:

1. The check of con->kthread in nbcon_device_release() before
calling __nbcon_atomic_flush_pending_con().

But it is called only when __uart_port_using_nbcon() returns true.
And it would fail when nbcon_kthread_create() is called because

checks hlist_unhashed_lockless(&up->cons->node)

would fail. Which checks of the console is in @console_list


2. The following check in console_flush_all()

if ((flags & CON_NBCON) && con->kthread)
continue;

The result affects whether the legacy flush would call
nbcon_legacy_emit_next_record().

But this is called only for_each_console_srcu(con)
=> it could not race with nbcon_kthread_create()
because this console is not in @console_list at this moment.

By other words, I was curious whether some other code paths might
call con->write_atomic() while the kthread is already running.

It is not that important because it would be safe anyway.
I was checking this before I realized that it would be safe.

Anyway, the information about that the console is not in @console_list
when we set con->kthread still looks useful. At minimum,
the check would be racy if the console was on the list.

Does it make any sense now?

> I am OK with the first comment of this proposal. I do not understand the
> second comment.

Feel free to propose another comment. Or you could ignore the proposal
if you think that it does more harm than good.

Best Regards,
Petr


2024-06-12 11:18:34

by John Ogness

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On 2024-06-12, Petr Mladek <[email protected]> wrote:
>> > After all, I would add two comments, like these:
>> >
>> > <proposal-2>
>> > /*
>> > * Any access to the console device is serialized either by
>> > * device_lock() or console context or both.
>> > */
>> > kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name,
>> > con->index);
>> > [...]
>> >
>> > /*
>> > * Some users check con->kthread to decide whether to flush
>> > * the messages directly using con->write_atomic(). But they
>> > * do so only when the console is already in @console_list.
>> > */
>>
>> I do not understand how @console_list is related to racing between
>> non-thread and thread. kthreads are not only created during
>> registration. For example, they can be created much later when the last
>> boot console unregisters.
>
> I had in mind two particular code paths:
>
> 1. The check of con->kthread in nbcon_device_release() before
> calling __nbcon_atomic_flush_pending_con().
>
> But it is called only when __uart_port_using_nbcon() returns true.
> And it would fail when nbcon_kthread_create() is called because
>
> checks hlist_unhashed_lockless(&up->cons->node)
>
> would fail. Which checks of the console is in @console_list
>
>
> 2. The following check in console_flush_all()
>
> if ((flags & CON_NBCON) && con->kthread)
> continue;
>
> The result affects whether the legacy flush would call
> nbcon_legacy_emit_next_record().
>
> But this is called only for_each_console_srcu(con)
> => it could not race with nbcon_kthread_create()
> because this console is not in @console_list at this moment.
>
> By other words, I was curious whether some other code paths might
> call con->write_atomic() while the kthread is already running.
>
> It is not that important because it would be safe anyway.
> I was checking this before I realized that it would be safe.

Yes, it must be safe because it can happen at any time. For example,
when flushing after an emergency section.

> Anyway, the information about that the console is not in @console_list
> when we set con->kthread still looks useful.

Except that it is not always true. If boot consoles are registered, the
kthread is created later, after the console _is_ in
@console_list. Setting con->kthread really has nothing to do with
@console_list.

> At minimum, the check would be racy if the console was on the list.

The con->kthread check _is_ racey, but it doesn't matter. Perhaps you
just want to make it clear that it is racey but it does not matter.

How about:

/*
* Some users check con->kthread to decide whether to flush
* the messages directly using con->write_atomic(). Although
* racey, such a check for that purpose is safe because both
* threaded and atomic printing are serialized by the
* console context.
*/
con->kthread = kt;

John

2024-06-12 11:34:54

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On Wed 2024-06-12 13:24:24, John Ogness wrote:
> On 2024-06-12, Petr Mladek <[email protected]> wrote:
> >> > After all, I would add two comments, like these:
> >> >
> >> > <proposal-2>
> >> > /*
> >> > * Any access to the console device is serialized either by
> >> > * device_lock() or console context or both.
> >> > */
> >> > kt = kthread_run(nbcon_kthread_func, con, "pr/%s%d", con->name,
> >> > con->index);
> >> > [...]
> >> >
> >> > /*
> >> > * Some users check con->kthread to decide whether to flush
> >> > * the messages directly using con->write_atomic(). But they
> >> > * do so only when the console is already in @console_list.
> >> > */
> >>
> >> I do not understand how @console_list is related to racing between
> >> non-thread and thread. kthreads are not only created during
> >> registration. For example, they can be created much later when the last
> >> boot console unregisters.
> >
> > I had in mind two particular code paths:
> >
> > 1. The check of con->kthread in nbcon_device_release() before
> > calling __nbcon_atomic_flush_pending_con().
> >
> > But it is called only when __uart_port_using_nbcon() returns true.
> > And it would fail when nbcon_kthread_create() is called because
> >
> > checks hlist_unhashed_lockless(&up->cons->node)
> >
> > would fail. Which checks of the console is in @console_list
> >
> >
> > 2. The following check in console_flush_all()
> >
> > if ((flags & CON_NBCON) && con->kthread)
> > continue;
> >
> > The result affects whether the legacy flush would call
> > nbcon_legacy_emit_next_record().
> >
> > But this is called only for_each_console_srcu(con)
> > => it could not race with nbcon_kthread_create()
> > because this console is not in @console_list at this moment.
> >
> > By other words, I was curious whether some other code paths might
> > call con->write_atomic() while the kthread is already running.
> >
> > It is not that important because it would be safe anyway.
> > I was checking this before I realized that it would be safe.
>
> Yes, it must be safe because it can happen at any time. For example,
> when flushing after an emergency section.
>
> > Anyway, the information about that the console is not in @console_list
> > when we set con->kthread still looks useful.
>
> Except that it is not always true. If boot consoles are registered, the
> kthread is created later, after the console _is_ in
> @console_list. Setting con->kthread really has nothing to do with
> @console_list.

Right. I have missed this.

> > At minimum, the check would be racy if the console was on the list.
>
> The con->kthread check _is_ racey, but it doesn't matter. Perhaps you
> just want to make it clear that it is racey but it does not matter.
>
> How about:
>
> /*
> * Some users check con->kthread to decide whether to flush
> * the messages directly using con->write_atomic(). Although
> * racey, such a check for that purpose is safe because both
> * threaded and atomic printing are serialized by the
> * console context.
> */
> con->kthread = kt;

Yes, it sounds good.

Best Regards,
Petr

2024-06-13 12:34:27

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH printk v2 05/18] printk: Atomic print in printk context on shutdown

On Tue 2024-06-04 01:30:40, John Ogness wrote:
> For nbcon consoles, normally the printing is handled by the
> dedicated console printing threads. However, on shutdown the
> printing threads may not get a chance to print the final
> messages.
>
> When shutting down or rebooting (system_state > SYSTEM_RUNNING),
> perform atomic printing from the printk() caller context.
>
> Signed-off-by: John Ogness <[email protected]>

Sigh, the checks/logic gets really complicated. But I can't think
of anything better at the moment. And it seems that the check for
the system state is added at the right locations.

Reviewed-by: Petr Mladek <[email protected]>

Best Regards,
Petr

2024-06-13 12:45:11

by Petr Mladek

[permalink] [raw]
Subject: atomic_flush vs boot consoles - was: Re: [PATCH printk v2 05/18] printk: Atomic print in printk context on shutdown

On Tue 2024-06-04 01:30:40, John Ogness wrote:
> For nbcon consoles, normally the printing is handled by the
> dedicated console printing threads. However, on shutdown the
> printing threads may not get a chance to print the final
> messages.
>
> When shutting down or rebooting (system_state > SYSTEM_RUNNING),
> perform atomic printing from the printk() caller context.
>
> Signed-off-by: John Ogness <[email protected]>
> ---
> kernel/printk/nbcon.c | 5 +++--
> kernel/printk/printk.c | 7 ++++++-
> 2 files changed, 9 insertions(+), 3 deletions(-)
>
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2389,12 +2389,17 @@ asmlinkage int vprintk_emit(int facility, int level,
> *
> * - When this CPU is in panic.
> *
> + * - During shutdown, since the printing threads may not get
> + * a chance to print the final messages.
> + *
> * Note that if boot consoles are registered, the console
> * lock/unlock dance must be relied upon instead because nbcon
> * consoles cannot print simultaneously with boot consoles.
> */
> - if (is_panic_context)
> + if (is_panic_context ||
> + (system_state > SYSTEM_RUNNING)) {
> nbcon_atomic_flush_pending();
> + }
> }

I was curious why we do not need to add this check also to
console_flush_all() which checks con->kthread as well.

I realized that we call it only when

#define printing_via_unlock (have_legacy_console || have_boot_console)

=> it handles nbcon consoles only when there is still a boot console.

It actually have to handle them in this case because the boot consoles
can be serialized only via console_lock().

In fact, nbcon_atomic_flush_pending() is not safe when there are boot
consoles. This is handled in vprintk_emit(). But it is not enforced
on several other locations.

I played with a possible solutions. The conditions around the console
calls are getting more and more complicated. I am going to send a
solution which looks acceptable to me.

Best Regards,
Petr

2024-06-13 13:17:25

by Petr Mladek

[permalink] [raw]
Subject: [PATCH] printk: nbcon_atomic_flush_pending() is safe only when there is no boot console

Boot consoles are not serialized with the nbcon consoles via the nbcon
console context or con->device_lock(). The serialization is possible only
via the legacy console_lock().

The decision whether nbcon_atomic_flush_pending() should and can be
called safely is similar and closely related to the decision
whether the legacy loop should be used.

Define printing_via_context_safe symmetrically with printing_via_unlock.
Allow to call nbcon_atomic_flush_pending() only when it is needed and safe.

Signed-off-by: Petr Mladek <[email protected]>
---
kernel/printk/internal.h | 10 ++++++++++
kernel/printk/nbcon.c | 9 +++++++--
kernel/printk/printk.c | 7 ++++---
3 files changed, 21 insertions(+), 5 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 38680c6b2b39..bafec0a27da3 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -182,6 +182,7 @@ static inline bool console_is_usable(struct console *con, short flags) { return
#endif /* CONFIG_PRINTK */

extern bool have_boot_console;
+extern bool have_nbcon_console;
extern bool have_legacy_console;

/*
@@ -192,6 +193,15 @@ extern bool have_legacy_console;
*/
#define printing_via_unlock (have_legacy_console || have_boot_console)

+/*
+ * Specifies if printing on nbcon consoles is needed and also safe
+ * when serialized only by the nbcon context. If @have_boot_console
+ * is true, the nbcon consoles must be serialized with the boot
+ * consoles using the legacy console_lock().
+ */
+#define printing_via_context_safe (have_nbcon_console || !have_boot_console)
+
+
extern struct printk_buffers printk_shared_pbufs;

/**
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 89b340ca303c..9b2df848718c 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -1404,7 +1404,8 @@ void nbcon_cpu_emergency_exit(void)
* for the emergency messages is NBCON_PRIO_EMERGENCY.
*/
if (*cpu_emergency_nesting == 1) {
- nbcon_atomic_flush_pending();
+ if (printing_via_context_safe)
+ nbcon_atomic_flush_pending();

/*
* Safely attempt to flush the legacy consoles in this
@@ -1446,7 +1447,8 @@ void nbcon_cpu_emergency_flush(void)
if (*(nbcon_get_cpu_emergency_nesting()) == 0)
return;

- nbcon_atomic_flush_pending();
+ if (printing_via_context_safe)
+ nbcon_atomic_flush_pending();

if (printing_via_unlock && !is_printk_deferred()) {
if (console_trylock())
@@ -1637,6 +1639,9 @@ void nbcon_device_release(struct console *con)
* was locked. The console_srcu_read_lock must be taken to ensure
* the console is usable throughout flushing.
*/
+ if (!printing_via_context_safe)
+ return;
+
cookie = console_srcu_read_lock();
if (console_is_usable(con, console_srcu_read_flags(con)) &&
!con->kthread &&
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 137bd9a721c4..3183db5b4180 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -475,7 +475,7 @@ bool have_legacy_console;
* synchronous printing of legacy consoles will not occur during panic until
* the backtrace has been stored to the ringbuffer.
*/
-static bool have_nbcon_console;
+bool have_nbcon_console;

/*
* Specifies if a boot console is registered. If boot consoles are present,
@@ -2370,7 +2370,7 @@ asmlinkage int vprintk_emit(int facility, int level,

printed_len = vprintk_store(facility, level, dev_info, fmt, args);

- if (have_nbcon_console && !have_boot_console) {
+ if (printing_via_context_safe) {
bool is_panic_context = this_cpu_in_panic();

/*
@@ -3283,7 +3283,8 @@ void console_flush_on_panic(enum con_flush_mode mode)
if (mode == CONSOLE_REPLAY_ALL)
__console_rewind_all();

- nbcon_atomic_flush_pending();
+ if (printing_via_context_safe)
+ nbcon_atomic_flush_pending();

if (printing_via_unlock)
console_flush_all(false, &next_seq, &handover);
--
2.45.2


2024-06-13 13:25:30

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH printk v2 06/18] printk: nbcon: Add context to console_is_usable()

On Tue 2024-06-04 01:30:41, John Ogness wrote:
> The nbcon consoles have two callbacks to be used for different
> contexts. In order to determine if an nbcon console is usable,
> console_is_usable() needs to know if it is a context that will
> use the write_atomic() callback or the write_thread() callback.
>
> Add an extra parameter @use_atomic to specify this.
>
> Signed-off-by: John Ogness <[email protected]>
> ---
> kernel/printk/internal.h | 16 ++++++++++------
> kernel/printk/nbcon.c | 8 ++++----
> kernel/printk/printk.c | 6 ++++--
> 3 files changed, 18 insertions(+), 12 deletions(-)
>
> diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
> index 38680c6b2b39..243d3d3bc889 100644
> --- a/kernel/printk/internal.h
> +++ b/kernel/printk/internal.h
> @@ -100,7 +100,7 @@ void nbcon_kthread_create(struct console *con);
> * which can also play a role in deciding if @con can be used to print
> * records.
> */
> -static inline bool console_is_usable(struct console *con, short flags)
> +static inline bool console_is_usable(struct console *con, short flags, bool use_atomic)
> {
> if (!(flags & CON_ENABLED))
> return false;
> @@ -109,10 +109,13 @@ static inline bool console_is_usable(struct console *con, short flags)
> return false;
>
> if (flags & CON_NBCON) {
> - if (!con->write_atomic)
> - return false;
> - if (!con->write_thread)
> - return false;
> + if (use_atomic) {
> + if (!con->write_atomic)
> + return false;
> + } else {
> + if (!con->write_thread)
> + return false;
> + }
> } else {
> if (!con->write)
> return false;
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -4018,8 +4018,10 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
> * that they make forward progress, so only increment
> * @diff for usable consoles.
> */
> - if (!console_is_usable(c, flags))
> + if (!console_is_usable(c, flags, true) &&
> + !console_is_usable(c, flags, false)) {
> continue;
> + }
>
> if (flags & CON_NBCON) {
> printk_seq = nbcon_seq_read(c);

I wonder if it is worth it. Do we seriously want to support nbcon
without con->write_kthread() or con->write_atomic() callbacks?

For example, I see in kernel/printk/printk.c:

void register_console(struct console *newcon)
{
bool use_device_lock = (newcon->flags & CON_NBCON) && newcon->write_atomic;


We would need to extend this check if we wanted to allow nbcon
consoles without con->nbcon_atomic()...

Best Regards,
Petr

2024-06-13 15:08:48

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH printk v2 07/18] printk: nbcon: Add printer thread wakeups

On Tue 2024-06-04 01:30:42, John Ogness wrote:
> From: Thomas Gleixner <[email protected]>
>
> Add a function to wakeup the printer threads. The printer threads
> are woken when:
>
> - a record is added to the printk ringbuffer
> - consoles are resumed
> - triggered via printk_trigger_flush()
> - consoles should be replayed via sysrq
>
> The actual waking is performed via irq_work so that the function
> can be called from any context.
>
> --- a/kernel/printk/nbcon.c
> +++ b/kernel/printk/nbcon.c
> @@ -1058,6 +1058,61 @@ static int nbcon_kthread_func(void *__console)
> goto wait_for_event;
> }
>
> +/**
> + * nbcon_irq_work - irq work to wake printk thread
> + * @irq_work: The irq work to operate on
> + */
> +static void nbcon_irq_work(struct irq_work *irq_work)
> +{
> + struct console *con = container_of(irq_work, struct console, irq_work);
> +
> + nbcon_kthread_wake(con);
> +}
> +
> +static inline bool rcuwait_has_sleeper(struct rcuwait *w)
> +{
> + bool has_sleeper;
> +
> + rcu_read_lock();
> + /*
> + * Guarantee any new records can be seen by tasks preparing to wait
> + * before this context checks if the rcuwait is empty.
> + *
> + * This full memory barrier pairs with the full memory barrier within
> + * set_current_state() of ___rcuwait_wait_event(), which is called
> + * after prepare_to_rcuwait() adds the waiter but before it has
> + * checked the wait condition.
> + *
> + * This pairs with nbcon_kthread_func:A.
> + */
> + smp_mb(); /* LMM(rcuwait_has_sleeper:A) */
> + has_sleeper = !!rcu_dereference(w->task);

We should use the existing API rcuwait_active().

> + rcu_read_unlock();
> +
> + return has_sleeper;
> +}
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2402,6 +2402,8 @@ asmlinkage int vprintk_emit(int facility, int level,
> }
> }
>
> + nbcon_wake_threads();

This need to be called only when there is a nbcon console
and no boot console and it has not been flushed explicitly.

I think that we could move this slightly above:

if (have_nbcon_console && !have_boot_console) {
[...]
if (is_panic_context ||
!printk_threads_enabled ||
(system_state > SYSTEM_RUNNING)) {
nbcon_atomic_flush_pending();
} else {
nbcon_wake_threads();
}
}

> +
> if (do_trylock_unlock) {
> /*
> * The caller may be holding system-critical or
> @@ -2708,6 +2710,10 @@ void resume_console(void)
> */
> synchronize_srcu(&console_srcu);
>
> + /*
> + * Since this runs in task context, wake the threaded printers
> + * directly rather than scheduling irq_work to do it.
> + */
> cookie = console_srcu_read_lock();
> for_each_console_srcu(con) {
> flags = console_srcu_read_flags(con);

The wake up call has already been added in 4th patch of this patchset.

I would slightly prefer to move it from the 4th patch to this one.
Same with start_console(). But it is not super important.


> @@ -4178,6 +4184,7 @@ void defer_console_output(void)
>
> void printk_trigger_flush(void)
> {
> + nbcon_wake_threads();

IMHO, this is not needed. vprintk_emit() always either flushes nbcon
consoles directly or wakes them.

In each case, it is not needed when printk_trigger_flush() is called
from nbcon_cpu_emergency_exit().

Hmm, I am not sure about the situation in nmi_trigger_cpumask_backtrace().
printk_trigger_flush() is called there to queue the IRQ work yet
another CPU to be on the safe side. But the irq_work used by
nbcon is per-console (not per-CPU). I guess that an attempt to
queue it on 2nd CPU would be a NOP.

> defer_console_output();
> }
>
> @@ -4513,6 +4520,7 @@ void console_try_replay_all(void)
> {
> if (console_trylock()) {
> __console_rewind_all();
> + nbcon_wake_threads();
> /* Consoles are flushed as part of console_unlock(). */
> console_unlock();
> }

Just an idea. We probably could do better for nbcon consoles. Like try
to flush them directly with emergency prio. But it can be done
in a separate patch later.

Best Regards,
Petr

2024-06-13 15:10:16

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH] printk: nbcon_atomic_flush_pending() is safe only when there is no boot console

On Thu 2024-06-13 14:52:24, Petr Mladek wrote:
> Boot consoles are not serialized with the nbcon consoles via the nbcon
> console context or con->device_lock(). The serialization is possible only
> via the legacy console_lock().
>
> The decision whether nbcon_atomic_flush_pending() should and can be
> called safely is similar and closely related to the decision
> whether the legacy loop should be used.
>
> Define printing_via_context_safe symmetrically with printing_via_unlock.
> Allow to call nbcon_atomic_flush_pending() only when it is needed and safe.
>
> --- a/kernel/printk/internal.h
> +++ b/kernel/printk/internal.h
> @@ -192,6 +193,15 @@ extern bool have_legacy_console;
> */
> #define printing_via_unlock (have_legacy_console || have_boot_console)
>
> +/*
> + * Specifies if printing on nbcon consoles is needed and also safe
> + * when serialized only by the nbcon context. If @have_boot_console
> + * is true, the nbcon consoles must be serialized with the boot
> + * consoles using the legacy console_lock().
> + */
> +#define printing_via_context_safe (have_nbcon_console || !have_boot_console)

Oops, this should be:

#define printing_via_context_safe (have_nbcon_console && !have_boot_console)


Best Regards,
Petr

2024-06-13 15:21:45

by John Ogness

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On 2024-06-11, Petr Mladek <[email protected]> wrote:
> Honestly, if the system is not able to start the kthread then
> it is probably useless anyway. I would prefer if printk keeps working
> so that people know what is going on ;-)

I have been looking into and thinking about this some more. I do not
like the idea of the system doing some sort of fallback if some of the
kthreads fail to start. Not only does it complicate the code, but it
greatly increases the variants of how the system during runtime.

I (strongly) suggest the following:

- The kthread is created in nbcon_alloc(). If the kthread fails, then
nbcon_alloc() fails and the console will not register.

- nbcon_kthread_should_wakeup() will return false if the console is not
registered or if @have_boot_console=1.

Then there would be no need to ever check con->kthread. Instead we can
rely on the global state of the system transitioning to relying on
threading.

I think it is totally appropriate that register_console() fails if the
kthread cannot be created, just as it already fails if the kmalloc() for
the pbufs fails.

Any objections?

John

P.S. There are other minor details involved, such as calling
kthread_stop() before removing a console from the list. But I have gone
through all these and it appears to generally simplify things a lot.

2024-06-14 07:44:19

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH printk v2 04/18] printk: nbcon: Introduce printing kthreads

On Thu 2024-06-13 17:27:33, John Ogness wrote:
> On 2024-06-11, Petr Mladek <[email protected]> wrote:
> > Honestly, if the system is not able to start the kthread then
> > it is probably useless anyway. I would prefer if printk keeps working
> > so that people know what is going on ;-)
>
> I have been looking into and thinking about this some more. I do not
> like the idea of the system doing some sort of fallback if some of the
> kthreads fail to start. Not only does it complicate the code, but it
> greatly increases the variants of how the system during runtime.

Fair enough.

> I (strongly) suggest the following:
>
> - The kthread is created in nbcon_alloc(). If the kthread fails, then
> nbcon_alloc() fails and the console will not register.
>
> - nbcon_kthread_should_wakeup() will return false if the console is not
> registered or if @have_boot_console=1.

I like this.

I guess that this would require moving some pieces from nbcon_init
to nbcon_alloc(). It might make sense to move there everything except
for setting the initial seq number.

> Then there would be no need to ever check con->kthread. Instead we can
> rely on the global state of the system transitioning to relying on
> threading.
>
> I think it is totally appropriate that register_console() fails if the
> kthread cannot be created, just as it already fails if the kmalloc() for
> the pbufs fails.
>
> Any objections?

Not from my side ;-)

Best Regards,
Petr