[printk,v2,19/26] printk: Avoid console_lock dance if no legacy or boot consoles
Commit Message
Currently the console lock is used to attempt legacy-type
printing even if there are no legacy or boot consoles registered.
If no such consoles are registered, the console lock does not
need to be taken.
Add tracking of legacy console registration and use it with
boot console tracking to avoid unnecessary code paths, i.e.
do not use the console lock if there are no boot consoles
and no legacy consoles.
Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
kernel/printk/internal.h | 12 ++++++++
kernel/printk/printk.c | 59 ++++++++++++++++++++++++++++++----------
2 files changed, 56 insertions(+), 15 deletions(-)
Comments
On Sun 2024-02-18 20:03:19, John Ogness wrote:
> Currently the console lock is used to attempt legacy-type
> printing even if there are no legacy or boot consoles registered.
> If no such consoles are registered, the console lock does not
> need to be taken.
>
> Add tracking of legacy console registration and use it with
> boot console tracking to avoid unnecessary code paths, i.e.
> do not use the console lock if there are no boot consoles
> and no legacy consoles.
>
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3958,7 +3983,11 @@ void defer_console_output(void)
> * New messages may have been added directly to the ringbuffer
> * using vprintk_store(), so wake any waiters as well.
> */
> - __wake_up_klogd(PRINTK_PENDING_WAKEUP | PRINTK_PENDING_OUTPUT);
> + int val = PRINTK_PENDING_WAKEUP;
> +
> + if (printing_via_unlock)
> + val |= PRINTK_PENDING_OUTPUT;
> + __wake_up_klogd(val);
I was thinking about handling this in wake_up_klogd_work_func().
But then I saw that __wake_up_klogd() already handled
PRINTK_PENDING_WAKEUP a similar way. And it even did not
queue the work when there was nothing to do.
It would be nice to handle both on the same place.
It would even untangle the condition in __wake_up_klogd().
Something like:
static void __wake_up_klogd(int val)
{
if (!printk_percpu_data_ready())
return;
preempt_disable();
/*
* Guarantee any new records can be seen by tasks preparing to wait
* before this context checks if the wait queue is empty.
*
* The full memory barrier within wq_has_sleeper() pairs with the full
* memory barrier within set_current_state() of
* prepare_to_wait_event(), which is called after ___wait_event() adds
* the waiter but before it has checked the wait condition.
*
* This pairs with devkmsg_read:A and syslog_print:A.
*/
if (!wq_has_sleeper(&log_wait)) /* LMM(__wake_up_klogd:A) */
val &= ~PRINTK_PENDING_WAKEUP;
/*
* Simple read is safe. register_console() would flush a newly
* registered legacy console when writing the message about
* that it has been enabled.
*/
if (!printing_via_unlock)
val &= ~PRINTK_PENDING_OUTPUT;
if (val) {
this_cpu_or(printk_pending, val);
irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
}
preempt_enable();
}
Otherwise, it looks good.
Best Regards,
Petr
Adding Paul into Cc.
On Sun 2024-02-18 20:03:19, John Ogness wrote:
> Currently the console lock is used to attempt legacy-type
> printing even if there are no legacy or boot consoles registered.
> If no such consoles are registered, the console lock does not
> need to be taken.
>
> Add tracking of legacy console registration and use it with
> boot console tracking to avoid unnecessary code paths, i.e.
> do not use the console lock if there are no boot consoles
> and no legacy consoles.
>
> --- a/kernel/printk/internal.h
> +++ b/kernel/printk/internal.h
> @@ -44,6 +44,16 @@ enum printk_info_flags {
> };
>
> extern struct printk_ringbuffer *prb;
> +extern bool have_legacy_console;
> +extern bool have_boot_console;
> +
> +/*
> + * Specifies if the console lock/unlock dance is needed for console
> + * printing. If @have_boot_console is true, the nbcon consoles will
> + * be printed serially along with the legacy consoles because nbcon
> + * consoles cannot print simultaneously with boot consoles.
> + */
> +#define printing_via_unlock (have_legacy_console || have_boot_console)
>
> __printf(4, 0)
> int vprintk_store(int facility, int level,
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -463,6 +463,13 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
> /* syslog_lock protects syslog_* variables and write access to clear_seq. */
> static DEFINE_MUTEX(syslog_lock);
>
> +/*
> + * Specifies if a legacy console is registered. If legacy consoles are
> + * present, it is necessary to perform the console_lock/console_unlock dance
> + * whenever console flushing should occur.
> + */
> +bool have_legacy_console;
> +
> /*
> * Specifies if a boot console is registered. If boot consoles are present,
> * nbcon consoles cannot print simultaneously and must be synchronized by
> @@ -3790,22 +3807,28 @@ 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. */
> - console_lock();
> - console_unlock();
> + if (printing_via_unlock) {
> + console_lock();
> + console_unlock();
> + }
>
> for (;;) {
> unsigned long begin_jiffies;
> unsigned long slept_jiffies;
>
> + locked = false;
> diff = 0;
>
> - /*
> - * Hold the console_lock to guarantee safe access to
> - * console->seq. Releasing console_lock flushes more
> - * records in case @seq is still not printed on all
> - * usable consoles.
> - */
> - console_lock();
> + if (printing_via_unlock) {
> + /*
> + * Hold the console_lock to guarantee safe access to
> + * console->seq. Releasing console_lock flushes more
> + * records in case @seq is still not printed on all
> + * usable consoles.
> + */
> + console_lock();
> + locked = true;
> + }
>
> cookie = console_srcu_read_lock();
> for_each_console_srcu(c) {
> @@ -3836,7 +3860,8 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
> if (diff != last_diff && reset_on_progress)
> remaining_jiffies = timeout_jiffies;
>
> - console_unlock();
> + if (locked)
> + console_unlock();
Is this actually safe?
What prevents the compiler from optimizing out the "locked" variable
and reading "printing_via_unlock" once again here?
It is not exactly the same but it is similar to "invented loads"
described at
https://lwn.net/Articles/793253/#Invented%20Loads
The writes affecting printing_via_unlock are not synchronized
by console_lock().
Should we do the following?
/*
* Specifies if the console lock/unlock dance is needed for console
* printing. If @have_boot_console is true, the nbcon consoles will
* be printed serially along with the legacy consoles because nbcon
* consoles cannot print simultaneously with boot consoles.
*
* Prevent compiler speculations when checking the values.
*/
#define printing_via_unlock (READ_ONCE(have_legacy_console) || \
READ_ONCE(have_boot_console))
or
if (printing_via_unlock) {
[...]
WRITE_ONCE(locked, true);
}
Or am I too paranoid?
Best Regards,
Petr
On Thu, Feb 29, 2024 at 05:19:04PM +0100, Petr Mladek wrote:
> Adding Paul into Cc.
>
> On Sun 2024-02-18 20:03:19, John Ogness wrote:
> > Currently the console lock is used to attempt legacy-type
> > printing even if there are no legacy or boot consoles registered.
> > If no such consoles are registered, the console lock does not
> > need to be taken.
> >
> > Add tracking of legacy console registration and use it with
> > boot console tracking to avoid unnecessary code paths, i.e.
> > do not use the console lock if there are no boot consoles
> > and no legacy consoles.
> >
> > --- a/kernel/printk/internal.h
> > +++ b/kernel/printk/internal.h
> > @@ -44,6 +44,16 @@ enum printk_info_flags {
> > };
> >
> > extern struct printk_ringbuffer *prb;
> > +extern bool have_legacy_console;
> > +extern bool have_boot_console;
> > +
> > +/*
> > + * Specifies if the console lock/unlock dance is needed for console
> > + * printing. If @have_boot_console is true, the nbcon consoles will
> > + * be printed serially along with the legacy consoles because nbcon
> > + * consoles cannot print simultaneously with boot consoles.
> > + */
> > +#define printing_via_unlock (have_legacy_console || have_boot_console)
> >
> > __printf(4, 0)
> > int vprintk_store(int facility, int level,
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -463,6 +463,13 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
> > /* syslog_lock protects syslog_* variables and write access to clear_seq. */
> > static DEFINE_MUTEX(syslog_lock);
> >
> > +/*
> > + * Specifies if a legacy console is registered. If legacy consoles are
> > + * present, it is necessary to perform the console_lock/console_unlock dance
> > + * whenever console flushing should occur.
> > + */
> > +bool have_legacy_console;
> > +
> > /*
> > * Specifies if a boot console is registered. If boot consoles are present,
> > * nbcon consoles cannot print simultaneously and must be synchronized by
> > @@ -3790,22 +3807,28 @@ 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. */
> > - console_lock();
> > - console_unlock();
> > + if (printing_via_unlock) {
> > + console_lock();
> > + console_unlock();
> > + }
> >
> > for (;;) {
> > unsigned long begin_jiffies;
> > unsigned long slept_jiffies;
> >
> > + locked = false;
> > diff = 0;
> >
> > - /*
> > - * Hold the console_lock to guarantee safe access to
> > - * console->seq. Releasing console_lock flushes more
> > - * records in case @seq is still not printed on all
> > - * usable consoles.
> > - */
> > - console_lock();
> > + if (printing_via_unlock) {
> > + /*
> > + * Hold the console_lock to guarantee safe access to
> > + * console->seq. Releasing console_lock flushes more
> > + * records in case @seq is still not printed on all
> > + * usable consoles.
> > + */
> > + console_lock();
> > + locked = true;
> > + }
> >
> > cookie = console_srcu_read_lock();
> > for_each_console_srcu(c) {
> > @@ -3836,7 +3860,8 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
> > if (diff != last_diff && reset_on_progress)
> > remaining_jiffies = timeout_jiffies;
> >
> > - console_unlock();
> > + if (locked)
> > + console_unlock();
>
> Is this actually safe?
>
> What prevents the compiler from optimizing out the "locked" variable
> and reading "printing_via_unlock" once again here?
>
> It is not exactly the same but it is similar to "invented loads"
> described at
> https://lwn.net/Articles/793253/#Invented%20Loads
>
> The writes affecting printing_via_unlock are not synchronized
> by console_lock().
If there are no compiler barriers between those two regions of code,
that could happen. Compiler barriers are of course barrier(), but also
almost all atomic and locking operations.
But without comments, any intervening compiler barriers might well be
removed in some future bug-fix effort. Let's face it, that could happen
even with comments.
> Should we do the following?
>
> /*
> * Specifies if the console lock/unlock dance is needed for console
> * printing. If @have_boot_console is true, the nbcon consoles will
> * be printed serially along with the legacy consoles because nbcon
> * consoles cannot print simultaneously with boot consoles.
> *
> * Prevent compiler speculations when checking the values.
> */
> #define printing_via_unlock (READ_ONCE(have_legacy_console) || \
> READ_ONCE(have_boot_console))
>
>
> or
>
> if (printing_via_unlock) {
> [...]
> WRITE_ONCE(locked, true);
> }
>
> Or am I too paranoid?
Not by my standards, not that this would be saying much. ;-)
I prefer the approach adding the READ_ONCE(), especially if "locked"
happens to be a local variable.
Thanx, Paul
@@ -44,6 +44,16 @@ enum printk_info_flags {
};
extern struct printk_ringbuffer *prb;
+extern bool have_legacy_console;
+extern bool have_boot_console;
+
+/*
+ * Specifies if the console lock/unlock dance is needed for console
+ * printing. If @have_boot_console is true, the nbcon consoles will
+ * be printed serially along with the legacy consoles because nbcon
+ * consoles cannot print simultaneously with boot consoles.
+ */
+#define printing_via_unlock (have_legacy_console || have_boot_console)
__printf(4, 0)
int vprintk_store(int facility, int level,
@@ -123,6 +133,8 @@ static inline bool console_is_usable(struct console *con, short flags)
#define PRINTK_MESSAGE_MAX 0
#define PRINTKRB_RECORD_MAX 0
+#define printing_via_unlock (false)
+
/*
* In !PRINTK builds we still export console_sem
* semaphore and some of console functions (console_unlock()/etc.), so
@@ -463,6 +463,13 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
/* syslog_lock protects syslog_* variables and write access to clear_seq. */
static DEFINE_MUTEX(syslog_lock);
+/*
+ * Specifies if a legacy console is registered. If legacy consoles are
+ * present, it is necessary to perform the console_lock/console_unlock dance
+ * whenever console flushing should occur.
+ */
+bool have_legacy_console;
+
/*
* Specifies if a boot console is registered. If boot consoles are present,
* nbcon consoles cannot print simultaneously and must be synchronized by
@@ -2344,7 +2351,7 @@ asmlinkage int vprintk_emit(int facility, int level,
printed_len = vprintk_store(facility, level, dev_info, fmt, args);
/* If called from the scheduler, we can not call up(). */
- if (!in_sched) {
+ if (!in_sched && printing_via_unlock) {
/*
* The caller may be holding system-critical or
* timing-sensitive locks. Disable preemption during
@@ -2645,7 +2652,7 @@ void resume_console(void)
*/
static int console_cpu_notify(unsigned int cpu)
{
- if (!cpuhp_tasks_frozen) {
+ if (!cpuhp_tasks_frozen && printing_via_unlock) {
/* If trylock fails, someone else is doing the printing */
if (console_trylock())
console_unlock();
@@ -3188,7 +3195,8 @@ void console_flush_on_panic(enum con_flush_mode mode)
nbcon_atomic_flush_all();
- console_flush_all(false, &next_seq, &handover);
+ if (printing_via_unlock)
+ console_flush_all(false, &next_seq, &handover);
}
/*
@@ -3513,8 +3521,11 @@ void register_console(struct console *newcon)
newcon->dropped = 0;
console_init_seq(newcon, bootcon_registered);
- if (newcon->flags & CON_NBCON)
+ if (newcon->flags & CON_NBCON) {
nbcon_init(newcon);
+ } else {
+ have_legacy_console = true;
+ }
if (newcon->flags & CON_BOOT)
have_boot_console = true;
@@ -3571,6 +3582,7 @@ EXPORT_SYMBOL(register_console);
/* Must be called under console_list_lock(). */
static int unregister_console_locked(struct console *console)
{
+ bool found_legacy_con = false;
bool found_boot_con = false;
struct console *c;
int res;
@@ -3627,9 +3639,13 @@ static int unregister_console_locked(struct console *console)
for_each_console(c) {
if (c->flags & CON_BOOT)
found_boot_con = true;
+ if (!(c->flags & CON_NBCON))
+ found_legacy_con = true;
}
if (!found_boot_con)
have_boot_console = false;
+ if (!found_legacy_con)
+ have_legacy_console = false;
return res;
}
@@ -3781,6 +3797,7 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
u64 last_diff = 0;
u64 printk_seq;
short flags;
+ bool locked;
int cookie;
u64 diff;
u64 seq;
@@ -3790,22 +3807,28 @@ 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. */
- console_lock();
- console_unlock();
+ if (printing_via_unlock) {
+ console_lock();
+ console_unlock();
+ }
for (;;) {
unsigned long begin_jiffies;
unsigned long slept_jiffies;
+ locked = false;
diff = 0;
- /*
- * Hold the console_lock to guarantee safe access to
- * console->seq. Releasing console_lock flushes more
- * records in case @seq is still not printed on all
- * usable consoles.
- */
- console_lock();
+ if (printing_via_unlock) {
+ /*
+ * Hold the console_lock to guarantee safe access to
+ * console->seq. Releasing console_lock flushes more
+ * records in case @seq is still not printed on all
+ * usable consoles.
+ */
+ console_lock();
+ locked = true;
+ }
cookie = console_srcu_read_lock();
for_each_console_srcu(c) {
@@ -3825,6 +3848,7 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
if (flags & CON_NBCON) {
printk_seq = nbcon_seq_read(c);
} else {
+ WARN_ON_ONCE(!locked);
printk_seq = c->seq;
}
@@ -3836,7 +3860,8 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
if (diff != last_diff && reset_on_progress)
remaining_jiffies = timeout_jiffies;
- console_unlock();
+ if (locked)
+ console_unlock();
/* Note: @diff is 0 if there are no usable consoles. */
if (diff == 0 || remaining_jiffies == 0)
@@ -3958,7 +3983,11 @@ void defer_console_output(void)
* New messages may have been added directly to the ringbuffer
* using vprintk_store(), so wake any waiters as well.
*/
- __wake_up_klogd(PRINTK_PENDING_WAKEUP | PRINTK_PENDING_OUTPUT);
+ int val = PRINTK_PENDING_WAKEUP;
+
+ if (printing_via_unlock)
+ val |= PRINTK_PENDING_OUTPUT;
+ __wake_up_klogd(val);
}
void printk_trigger_flush(void)