From f7da4649c2770d7ce424525822355f4daa165d29 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 19:55:51 +0800 Subject: [PATCH 01/16] printk: kmsg_dump: remove _nolock() variants commit d483de609b73e8ff35e9a642e93b6a3c028fb699 upstream. kmsg_dump_rewind() and kmsg_dump_get_line() are lockless, so there is no need for _nolock() variants. Remove these functions and switch all callers of the _nolock() variants. The functions without _nolock() were chosen because they are already exported to kernel modules. Signed-off-by: John Ogness --- arch/powerpc/xmon/xmon.c | 4 +-- include/linux/kmsg_dump.h | 18 +---------- kernel/debug/kdb/kdb_main.c | 8 ++--- kernel/printk/printk.c | 60 +++++-------------------------------- 4 files changed, 15 insertions(+), 75 deletions(-) diff --git a/arch/powerpc/xmon/xmon.c b/arch/powerpc/xmon/xmon.c index b71690e8245b..d62b8e053d4c 100644 --- a/arch/powerpc/xmon/xmon.c +++ b/arch/powerpc/xmon/xmon.c @@ -3017,9 +3017,9 @@ dump_log_buf(void) catch_memory_errors = 1; sync(); - kmsg_dump_rewind_nolock(&iter); + kmsg_dump_rewind(&iter); xmon_start_pagination(); - while (kmsg_dump_get_line_nolock(&iter, false, buf, sizeof(buf), &len)) { + while (kmsg_dump_get_line(&iter, false, buf, sizeof(buf), &len)) { buf[len] = '\0'; printf("%s", buf); } diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h index 2fdb10ab1799..86673930c8ea 100644 --- a/include/linux/kmsg_dump.h +++ b/include/linux/kmsg_dump.h @@ -60,18 +60,13 @@ struct kmsg_dumper { #ifdef CONFIG_PRINTK void kmsg_dump(enum kmsg_dump_reason reason); -bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, bool syslog, - char *line, size_t size, size_t *len); - bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog, char *line, size_t size, size_t *len); bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog, char *buf, size_t size, size_t *len_out); -void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter); - -void kmsg_dump_rewind(struct kmsg_dumper_iter *dumper_iter); +void kmsg_dump_rewind(struct kmsg_dumper_iter *iter); int kmsg_dump_register(struct kmsg_dumper *dumper); @@ -83,13 +78,6 @@ static inline void kmsg_dump(enum kmsg_dump_reason reason) { } -static inline bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, - bool syslog, const char *line, - size_t size, size_t *len) -{ - return false; -} - static inline bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog, const char *line, size_t size, size_t *len) { @@ -102,10 +90,6 @@ static inline bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool sysl return false; } -static inline void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter) -{ -} - static inline void kmsg_dump_rewind(struct kmsg_dumper_iter *iter) { } diff --git a/kernel/debug/kdb/kdb_main.c b/kernel/debug/kdb/kdb_main.c index 048baadd7a41..1f5c577b926e 100644 --- a/kernel/debug/kdb/kdb_main.c +++ b/kernel/debug/kdb/kdb_main.c @@ -2182,8 +2182,8 @@ static int kdb_dmesg(int argc, const char **argv) kdb_set(2, setargs); } - kmsg_dump_rewind_nolock(&iter); - while (kmsg_dump_get_line_nolock(&iter, 1, NULL, 0, NULL)) + kmsg_dump_rewind(&iter); + while (kmsg_dump_get_line(&iter, 1, NULL, 0, NULL)) n++; if (lines < 0) { @@ -2215,8 +2215,8 @@ static int kdb_dmesg(int argc, const char **argv) if (skip >= n || skip < 0) return 0; - kmsg_dump_rewind_nolock(&iter); - while (kmsg_dump_get_line_nolock(&iter, 1, buf, sizeof(buf), &len)) { + kmsg_dump_rewind(&iter); + while (kmsg_dump_get_line(&iter, 1, buf, sizeof(buf), &len)) { if (skip) { skip--; continue; diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index a6042cef080f..f16ba7e9fb81 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -3442,7 +3442,7 @@ void kmsg_dump(enum kmsg_dump_reason reason) } /** - * kmsg_dump_get_line_nolock - retrieve one kmsg log line (unlocked version) + * kmsg_dump_get_line - retrieve one kmsg log line * @iter: kmsg dumper iterator * @syslog: include the "<4>" prefixes * @line: buffer to copy the line to @@ -3457,18 +3457,18 @@ void kmsg_dump(enum kmsg_dump_reason reason) * * A return value of FALSE indicates that there are no more records to * read. - * - * The function is similar to kmsg_dump_get_line(), but grabs no locks. */ -bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, bool syslog, - char *line, size_t size, size_t *len) +bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog, + char *line, size_t size, size_t *len) { struct printk_info info; unsigned int line_count; struct printk_record r; + unsigned long flags; size_t l = 0; bool ret = false; + printk_safe_enter_irqsave(flags); prb_rec_init_rd(&r, &info, line, size); if (!iter->active) @@ -3492,40 +3492,11 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, bool syslog, iter->cur_seq = r.info->seq + 1; ret = true; out: + printk_safe_exit_irqrestore(flags); if (len) *len = l; return ret; } - -/** - * kmsg_dump_get_line - retrieve one kmsg log line - * @iter: kmsg dumper iterator - * @syslog: include the "<4>" prefixes - * @line: buffer to copy the line to - * @size: maximum size of the buffer - * @len: length of line placed into buffer - * - * Start at the beginning of the kmsg buffer, with the oldest kmsg - * record, and copy one record into the provided buffer. - * - * Consecutive calls will return the next available record moving - * towards the end of the buffer with the youngest messages. - * - * A return value of FALSE indicates that there are no more records to - * read. - */ -bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog, - char *line, size_t size, size_t *len) -{ - unsigned long flags; - bool ret; - - printk_safe_enter_irqsave(flags); - ret = kmsg_dump_get_line_nolock(iter, syslog, line, size, len); - printk_safe_exit_irqrestore(flags); - - return ret; -} EXPORT_SYMBOL_GPL(kmsg_dump_get_line); /** @@ -3614,22 +3585,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog, } EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer); -/** - * kmsg_dump_rewind_nolock - reset the iterator (unlocked version) - * @iter: kmsg dumper iterator - * - * Reset the dumper's iterator so that kmsg_dump_get_line() and - * kmsg_dump_get_buffer() can be called again and used multiple - * times within the same dumper.dump() callback. - * - * The function is similar to kmsg_dump_rewind(), but grabs no locks. - */ -void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter) -{ - iter->cur_seq = latched_seq_read_nolock(&clear_seq); - iter->next_seq = prb_next_seq(prb); -} - /** * kmsg_dump_rewind - reset the iterator * @iter: kmsg dumper iterator @@ -3643,7 +3598,8 @@ void kmsg_dump_rewind(struct kmsg_dumper_iter *iter) unsigned long flags; printk_safe_enter_irqsave(flags); - kmsg_dump_rewind_nolock(iter); + iter->cur_seq = latched_seq_read_nolock(&clear_seq); + iter->next_seq = prb_next_seq(prb); printk_safe_exit_irqrestore(flags); } EXPORT_SYMBOL_GPL(kmsg_dump_rewind); -- Gitee From 897c00216c6d644f2be0c6e7ee1e507e478cfc53 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 19:56:19 +0800 Subject: [PATCH 02/16] printk: kmsg_dump: use kmsg_dump_rewind commit 03c740cd65d2fd3ff4de04bfb3a78a01cb521e9f upstream. kmsg_dump() is open coding the kmsg_dump_rewind(). Call kmsg_dump_rewind() instead. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- kernel/printk/printk.c | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index f16ba7e9fb81..e8fee6870ed5 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -3411,7 +3411,6 @@ void kmsg_dump(enum kmsg_dump_reason reason) { struct kmsg_dumper_iter iter; struct kmsg_dumper *dumper; - unsigned long flags; rcu_read_lock(); list_for_each_entry_rcu(dumper, &dump_list, list) { @@ -3430,10 +3429,7 @@ void kmsg_dump(enum kmsg_dump_reason reason) /* initialize iterator with data about the stored records */ iter.active = true; - printk_safe_enter_irqsave(flags); - iter.cur_seq = latched_seq_read_nolock(&clear_seq); - iter.next_seq = prb_next_seq(prb); - printk_safe_exit_irqrestore(flags); + kmsg_dump_rewind(&iter); /* invoke dumper which will iterate over records */ dumper->dump(dumper, reason, &iter); -- Gitee From ad485c145d54934f0d7ab5e3df8799992e025bc9 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:10:14 +0800 Subject: [PATCH 03/16] printk: console: remove unnecessary safe buffer usage commit 32c2913fb21a70178bf9a75ac287b0626df2a05e upstream. Upon registering a console, safe buffers are activated when setting up the sequence number to replay the log. However, these are already protected by @console_sem and @syslog_lock. Remove the unnecessary safe buffer usage. Signed-off-by: John Ogness --- kernel/printk/printk.c | 10 +++------- 1 file changed, 3 insertions(+), 7 deletions(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index e8fee6870ed5..a19b561e2738 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -3025,9 +3025,7 @@ void register_console(struct console *newcon) /* * console_unlock(); will print out the buffered messages * for us. - */ - printk_safe_enter_irqsave(flags); - /* + * * We're about to replay the log buffer. Only do this to the * just-registered console to avoid excessive message spam to * the already-registered consoles. @@ -3040,11 +3038,9 @@ void register_console(struct console *newcon) exclusive_console_stop_seq = console_seq; /* Get a consistent copy of @syslog_seq. */ - raw_spin_lock(&syslog_lock); + raw_spin_lock_irqsave(&syslog_lock, flags); console_seq = syslog_seq; - raw_spin_unlock(&syslog_lock); - - printk_safe_exit_irqrestore(flags); + raw_spin_unlock_irqrestore(&syslog_lock, flags); } console_unlock(); console_sysfs_notify(); -- Gitee From 8860c02b92bbc089808d064b7aa2722e094dafb3 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:10:47 +0800 Subject: [PATCH 04/16] printk: track/limit recursion commit 4b4801741870707e597dd0f64369c541689c0242 upstream. Limit printk() recursion to 1 level. This is enough to print a stacktrace for the printk call, should a WARN or BUG occur. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- kernel/printk/printk.c | 74 ++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 71 insertions(+), 3 deletions(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index a19b561e2738..4557270169a7 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -1964,6 +1964,65 @@ static void call_console_drivers(const char *ext_text, size_t ext_len, } } +#ifdef CONFIG_PRINTK_NMI +#define NUM_RECURSION_CTX 2 +#else +#define NUM_RECURSION_CTX 1 +#endif + +struct printk_recursion { + char count[NUM_RECURSION_CTX]; +}; + +static DEFINE_PER_CPU(struct printk_recursion, percpu_printk_recursion); +static char printk_recursion_count[NUM_RECURSION_CTX]; + +static char *printk_recursion_counter(void) +{ + struct printk_recursion *rec; + char *count; + + if (!printk_percpu_data_ready()) { + count = &printk_recursion_count[0]; + } else { + rec = this_cpu_ptr(&percpu_printk_recursion); + + count = &rec->count[0]; + } + +#ifdef CONFIG_PRINTK_NMI + if (in_nmi()) + count++; +#endif + + return count; +} + +static bool printk_enter_irqsave(unsigned long *flags) +{ + char *count; + + local_irq_save(*flags); + count = printk_recursion_counter(); + /* Only 1 level of recursion allowed. */ + if (*count > 1) { + local_irq_restore(*flags); + return false; + } + (*count)++; + + return true; +} + +static void printk_exit_irqrestore(unsigned long flags) +{ + char *count; + + count = printk_recursion_counter(); + (*count)--; + local_irq_restore(flags); +} + int printk_delay_msec __read_mostly; static inline void printk_delay(void) @@ -2064,11 +2123,13 @@ int vprintk_store(int facility, int level, struct prb_reserved_entry e; enum log_flags lflags = 0; struct printk_record r; + unsigned long irqflags; u16 trunc_msg_len = 0; char prefix_buf[8]; u16 reserve_size; va_list args2; u16 text_len; + int ret = 0; u64 ts_nsec; /* @@ -2079,6 +2140,9 @@ int vprintk_store(int facility, int level, */ ts_nsec = local_clock(); + if (!printk_enter_irqsave(&irqflags)) + return 0; + /* * The sprintf needs to come first since the syslog prefix might be * passed in as a parameter. An extra byte must be reserved so that @@ -2116,7 +2180,8 @@ int vprintk_store(int facility, int level, prb_commit(&e); } - return text_len; + ret = text_len; + goto out; } } @@ -2132,7 +2197,7 @@ int vprintk_store(int facility, int level, prb_rec_init_wr(&r, reserve_size + trunc_msg_len); if (!prb_reserve(&e, prb, &r)) - return 0; + goto out; } /* fill message */ @@ -2154,7 +2219,10 @@ int vprintk_store(int facility, int level, else prb_final_commit(&e); - return (text_len + trunc_msg_len); + ret = text_len + trunc_msg_len; +out: + printk_exit_irqrestore(irqflags); + return ret; } asmlinkage int vprintk_emit(int facility, int level, -- Gitee From f338b967a121576e9b34d80318eb8d6c247ca48a Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:19:13 +0800 Subject: [PATCH 05/16] printk: remove safe buffers commit 45258d2d3694666aae3841c3cd762d7ea69a269c upstream. With @logbuf_lock removed, the high level printk functions for storing messages are lockless. Messages can be stored from any context, so there is no need for the NMI and safe buffers anymore. Remove the NMI and safe buffers. In NMI or safe contexts, store the message immediately but still use irq_work to defer the console printing. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior Reviewed-by: Huang Jian --- arch/powerpc/kernel/traps.c | 1 - arch/powerpc/kernel/watchdog.c | 5 - include/linux/printk.h | 10 - kernel/kexec_core.c | 1 - kernel/panic.c | 3 - kernel/printk/internal.h | 2 - kernel/printk/printk.c | 86 ++------- kernel/printk/printk_safe.c | 329 +-------------------------------- lib/nmi_backtrace.c | 6 - 9 files changed, 17 insertions(+), 426 deletions(-) diff --git a/arch/powerpc/kernel/traps.c b/arch/powerpc/kernel/traps.c index 069d451240fa..c053c5acd674 100644 --- a/arch/powerpc/kernel/traps.c +++ b/arch/powerpc/kernel/traps.c @@ -170,7 +170,6 @@ extern void panic_flush_kmsg_start(void) extern void panic_flush_kmsg_end(void) { - printk_safe_flush_on_panic(); kmsg_dump(KMSG_DUMP_PANIC); bust_spinlocks(0); debug_locks_off(); diff --git a/arch/powerpc/kernel/watchdog.c b/arch/powerpc/kernel/watchdog.c index 75b2a6c4db5a..db40e20d0c54 100644 --- a/arch/powerpc/kernel/watchdog.c +++ b/arch/powerpc/kernel/watchdog.c @@ -185,11 +185,6 @@ static void watchdog_smp_panic(int cpu, u64 tb) wd_smp_unlock(&flags); - printk_safe_flush(); - /* - * printk_safe_flush() seems to require another print - * before anything actually goes out to console. - */ if (sysctl_hardlockup_all_cpu_backtrace) trigger_allbutself_cpu_backtrace(); diff --git a/include/linux/printk.h b/include/linux/printk.h index fe7eb2351610..2476796c1150 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -207,8 +207,6 @@ __printf(1, 2) void dump_stack_set_arch_desc(const char *fmt, ...); void dump_stack_print_info(const char *log_lvl); void show_regs_print_info(const char *log_lvl); extern asmlinkage void dump_stack(void) __cold; -extern void printk_safe_flush(void); -extern void printk_safe_flush_on_panic(void); #else static inline __printf(1, 0) int vprintk(const char *s, va_list args) @@ -272,14 +270,6 @@ static inline void show_regs_print_info(const char *log_lvl) static inline void dump_stack(void) { } - -static inline void printk_safe_flush(void) -{ -} - -static inline void printk_safe_flush_on_panic(void) -{ -} #endif extern int kptr_restrict; diff --git a/kernel/kexec_core.c b/kernel/kexec_core.c index 2fbb261e907e..991bc3afdaa5 100644 --- a/kernel/kexec_core.c +++ b/kernel/kexec_core.c @@ -984,7 +984,6 @@ void crash_kexec(struct pt_regs *regs) old_cpu = atomic_cmpxchg(&panic_cpu, PANIC_CPU_INVALID, this_cpu); if (old_cpu == PANIC_CPU_INVALID) { /* This is the 1st CPU which comes here, so go ahead. */ - printk_safe_flush_on_panic(); __crash_kexec(regs); /* diff --git a/kernel/panic.c b/kernel/panic.c index ee28138e860e..c8cf92c95bb0 100644 --- a/kernel/panic.c +++ b/kernel/panic.c @@ -252,7 +252,6 @@ void panic(const char *fmt, ...) * Bypass the panic_cpu check and call __crash_kexec directly. */ if (!_crash_kexec_post_notifiers) { - printk_safe_flush_on_panic(); __crash_kexec(NULL); /* @@ -276,8 +275,6 @@ void panic(const char *fmt, ...) */ atomic_notifier_call_chain(&panic_notifier_list, 0, buf); - /* Call flush even twice. It tries harder with a single online CPU */ - printk_safe_flush_on_panic(); kmsg_dump(KMSG_DUMP_PANIC); /* diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h index e7acc2888c8e..e108b2ece8c7 100644 --- a/kernel/printk/internal.h +++ b/kernel/printk/internal.h @@ -23,7 +23,6 @@ __printf(1, 0) int vprintk_func(const char *fmt, va_list args); void __printk_safe_enter(void); void __printk_safe_exit(void); -void printk_safe_init(void); bool printk_percpu_data_ready(void); #define printk_safe_enter_irqsave(flags) \ @@ -67,6 +66,5 @@ __printf(1, 0) int vprintk_func(const char *fmt, va_list args) { return 0; } #define printk_safe_enter_irq() local_irq_disable() #define printk_safe_exit_irq() local_irq_enable() -static inline void printk_safe_init(void) { } static inline bool printk_percpu_data_ready(void) { return false; } #endif /* CONFIG_PRINTK */ diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 4557270169a7..8aebc6ae29d2 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -746,27 +746,22 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf, if (ret) return ret; - printk_safe_enter_irq(); if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) { if (file->f_flags & O_NONBLOCK) { ret = -EAGAIN; - printk_safe_exit_irq(); goto out; } - printk_safe_exit_irq(); ret = wait_event_interruptible(log_wait, prb_read_valid(prb, atomic64_read(&user->seq), r)); if (ret) goto out; - printk_safe_enter_irq(); } if (r->info->seq != atomic64_read(&user->seq)) { /* our last seen message is gone, return error and reset */ atomic64_set(&user->seq, r->info->seq); ret = -EPIPE; - printk_safe_exit_irq(); goto out; } @@ -776,7 +771,6 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf, &r->info->dev_info); atomic64_set(&user->seq, r->info->seq + 1); - printk_safe_exit_irq(); if (len > count) { ret = -EINVAL; @@ -811,7 +805,6 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence) if (offset) return -ESPIPE; - printk_safe_enter_irq(); switch (whence) { case SEEK_SET: /* the first record */ @@ -832,7 +825,6 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence) default: ret = -EINVAL; } - printk_safe_exit_irq(); return ret; } @@ -847,7 +839,6 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait) poll_wait(file, &log_wait, wait); - printk_safe_enter_irq(); if (prb_read_valid_info(prb, atomic64_read(&user->seq), &info, NULL)) { /* return error when data has vanished underneath us */ if (info.seq != atomic64_read(&user->seq)) @@ -855,7 +846,6 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait) else ret = EPOLLIN|EPOLLRDNORM; } - printk_safe_exit_irq(); return ret; } @@ -888,9 +878,7 @@ static int devkmsg_open(struct inode *inode, struct file *file) prb_rec_init_rd(&user->record, &user->info, &user->text_buf[0], sizeof(user->text_buf)); - printk_safe_enter_irq(); atomic64_set(&user->seq, prb_first_valid_seq(prb)); - printk_safe_exit_irq(); file->private_data = user; return 0; @@ -1056,9 +1044,6 @@ static inline void log_buf_add_cpu(void) {} static void __init set_percpu_data_ready(void) { - printk_safe_init(); - /* Make sure we set this flag only after printk_safe() init is done */ - barrier(); __printk_percpu_data_ready = true; } @@ -1156,8 +1141,6 @@ void __init setup_log_buf(int early) new_descs, ilog2(new_descs_count), new_infos); - printk_safe_enter_irqsave(flags); - log_buf_len = new_log_buf_len; log_buf = new_log_buf; new_log_buf_len = 0; @@ -1173,8 +1156,6 @@ void __init setup_log_buf(int early) */ prb = &printk_rb_dynamic; - printk_safe_exit_irqrestore(flags); - if (seq != prb_next_seq(&printk_rb_static)) { pr_err("dropped %llu messages\n", prb_next_seq(&printk_rb_static) - seq); @@ -1512,11 +1493,9 @@ static int syslog_print(char __user *buf, int size) size_t n; size_t skip; - printk_safe_enter_irq(); - raw_spin_lock(&syslog_lock); + raw_spin_lock_irq(&syslog_lock); if (!prb_read_valid(prb, syslog_seq, &r)) { - raw_spin_unlock(&syslog_lock); - printk_safe_exit_irq(); + raw_spin_unlock_irq(&syslog_lock); break; } if (r.info->seq != syslog_seq) { @@ -1545,8 +1524,7 @@ static int syslog_print(char __user *buf, int size) syslog_partial += n; } else n = 0; - raw_spin_unlock(&syslog_lock); - printk_safe_exit_irq(); + raw_spin_unlock_irq(&syslog_lock); if (!n) break; @@ -1580,7 +1558,6 @@ static int syslog_print_all(char __user *buf, int size, bool clear) return -ENOMEM; time = printk_time; - printk_safe_enter_irq(); /* * Find first record that fits, including all following records, * into the user-provided buffer for this dump. @@ -1601,23 +1578,20 @@ static int syslog_print_all(char __user *buf, int size, bool clear) break; } - printk_safe_exit_irq(); if (copy_to_user(buf + len, text, textlen)) len = -EFAULT; else len += textlen; - printk_safe_enter_irq(); if (len < 0) break; } if (clear) { - raw_spin_lock(&syslog_lock); + raw_spin_lock_irq(&syslog_lock); latched_seq_write(&clear_seq, seq); - raw_spin_unlock(&syslog_lock); + raw_spin_unlock_irq(&syslog_lock); } - printk_safe_exit_irq(); kfree(text); return len; @@ -1625,11 +1599,9 @@ static int syslog_print_all(char __user *buf, int size, bool clear) static void syslog_clear(void) { - printk_safe_enter_irq(); - raw_spin_lock(&syslog_lock); + raw_spin_lock_irq(&syslog_lock); latched_seq_write(&clear_seq, prb_next_seq(prb)); - raw_spin_unlock(&syslog_lock); - printk_safe_exit_irq(); + raw_spin_unlock_irq(&syslog_lock); } /* Return a consistent copy of @syslog_seq. */ @@ -1717,12 +1689,10 @@ int do_syslog(int type, char __user *buf, int len, int source) break; /* Number of chars in the log buffer */ case SYSLOG_ACTION_SIZE_UNREAD: - printk_safe_enter_irq(); - raw_spin_lock(&syslog_lock); + raw_spin_lock_irq(&syslog_lock); if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) { /* No unread messages. */ - raw_spin_unlock(&syslog_lock); - printk_safe_exit_irq(); + raw_spin_unlock_irq(&syslog_lock); return 0; } if (info.seq != syslog_seq) { @@ -1750,8 +1720,7 @@ int do_syslog(int type, char __user *buf, int len, int source) } error -= syslog_partial; } - raw_spin_unlock(&syslog_lock); - printk_safe_exit_irq(); + raw_spin_unlock_irq(&syslog_lock); break; /* Size of the log buffer */ case SYSLOG_ACTION_SIZE_BUFFER: @@ -2231,7 +2200,6 @@ asmlinkage int vprintk_emit(int facility, int level, { int printed_len; bool in_sched = false; - unsigned long flags; /* Suppress unimportant messages after panic happens */ if (unlikely(suppress_printk)) @@ -2251,9 +2219,7 @@ asmlinkage int vprintk_emit(int facility, int level, boot_delay_msec(level); printk_delay(); - printk_safe_enter_irqsave(flags); printed_len = vprintk_store(facility, level, dev_info, fmt, args); - printk_safe_exit_irqrestore(flags); /* If called from the scheduler, we can not call up(). */ if (!in_sched) { @@ -2665,7 +2631,6 @@ void console_unlock(void) static char ext_text[CONSOLE_EXT_LOG_MAX]; static char text[CONSOLE_LOG_MAX]; static int panic_console_dropped; - unsigned long flags; bool do_cond_resched, retry; struct printk_info info; struct printk_record r; @@ -2710,7 +2675,6 @@ void console_unlock(void) size_t ext_len = 0; size_t len; - printk_safe_enter_irqsave(flags); skip: if (!prb_read_valid(prb, console_seq, &r)) break; @@ -2769,12 +2733,8 @@ void console_unlock(void) call_console_drivers(ext_text, ext_len, text, len); start_critical_timings(); - if (console_lock_spinning_disable_and_check()) { - printk_safe_exit_irqrestore(flags); + if (console_lock_spinning_disable_and_check()) return; - } - - printk_safe_exit_irqrestore(flags); /* Allow panic_cpu to take over the consoles safely */ if (abandon_console_lock_in_panic()) @@ -2796,9 +2756,6 @@ void console_unlock(void) */ retry = prb_read_valid(prb, console_seq, NULL); - if (!abandon_console_lock_in_panic()) - printk_safe_exit_irqrestore(flags); - if (retry && !abandon_console_lock_in_panic() && console_trylock()) goto again; } @@ -2860,13 +2817,8 @@ void console_flush_on_panic(enum con_flush_mode mode) console_trylock(); console_may_schedule = 0; - if (mode == CONSOLE_REPLAY_ALL) { - unsigned long flags; - - printk_safe_enter_irqsave(flags); + if (mode == CONSOLE_REPLAY_ALL) console_seq = prb_first_valid_seq(prb); - printk_safe_exit_irqrestore(flags); - } console_unlock(); } @@ -3524,11 +3476,9 @@ bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog, struct printk_info info; unsigned int line_count; struct printk_record r; - unsigned long flags; size_t l = 0; bool ret = false; - printk_safe_enter_irqsave(flags); prb_rec_init_rd(&r, &info, line, size); if (!iter->active) @@ -3552,7 +3502,6 @@ bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog, iter->cur_seq = r.info->seq + 1; ret = true; out: - printk_safe_exit_irqrestore(flags); if (len) *len = l; return ret; @@ -3583,7 +3532,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog, { struct printk_info info; struct printk_record r; - unsigned long flags; u64 seq; u64 next_seq; size_t len = 0; @@ -3593,7 +3541,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog, if (!iter->active || !buf || !size) goto out; - printk_safe_enter_irqsave(flags); if (prb_read_valid_info(prb, iter->cur_seq, &info, NULL)) { if (info.seq != iter->cur_seq) { /* messages are gone, move to first available one */ @@ -3602,10 +3549,8 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog, } /* last entry */ - if (iter->cur_seq >= iter->next_seq) { - printk_safe_exit_irqrestore(flags); + if (iter->cur_seq >= iter->next_seq) goto out; - } /* * Find first record that fits, including all following records, @@ -3637,7 +3582,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog, iter->next_seq = next_seq; ret = true; - printk_safe_exit_irqrestore(flags); out: if (len_out) *len_out = len; @@ -3655,12 +3599,8 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer); */ void kmsg_dump_rewind(struct kmsg_dumper_iter *iter) { - unsigned long flags; - - printk_safe_enter_irqsave(flags); iter->cur_seq = latched_seq_read_nolock(&clear_seq); iter->next_seq = prb_next_seq(prb); - printk_safe_exit_irqrestore(flags); } EXPORT_SYMBOL_GPL(kmsg_dump_rewind); diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c index 7df8a88d4115..c23b127a6545 100644 --- a/kernel/printk/printk_safe.c +++ b/kernel/printk/printk_safe.c @@ -15,282 +15,9 @@ #include "internal.h" -/* - * In NMI and safe mode, printk() avoids taking locks. Instead, - * it uses an alternative implementation that temporary stores - * the strings into a per-CPU buffer. The content of the buffer - * is later flushed into the main ring buffer via IRQ work. - * - * The alternative implementation is chosen transparently - * by examining current printk() context mask stored in @printk_context - * per-CPU variable. - * - * The implementation allows to flush the strings also from another CPU. - * There are situations when we want to make sure that all buffers - * were handled or when IRQs are blocked. - */ - -#define SAFE_LOG_BUF_LEN ((1 << CONFIG_PRINTK_SAFE_LOG_BUF_SHIFT) - \ - sizeof(atomic_t) - \ - sizeof(atomic_t) - \ - sizeof(struct irq_work)) - -struct printk_safe_seq_buf { - atomic_t len; /* length of written data */ - atomic_t message_lost; - struct irq_work work; /* IRQ work that flushes the buffer */ - unsigned char buffer[SAFE_LOG_BUF_LEN]; -}; - -static DEFINE_PER_CPU(struct printk_safe_seq_buf, safe_print_seq); static DEFINE_PER_CPU(int, printk_context); -static DEFINE_RAW_SPINLOCK(safe_read_lock); - -#ifdef CONFIG_PRINTK_NMI -static DEFINE_PER_CPU(struct printk_safe_seq_buf, nmi_print_seq); -#endif - -/* Get flushed in a more safe context. */ -static void queue_flush_work(struct printk_safe_seq_buf *s) -{ - if (printk_percpu_data_ready()) - irq_work_queue(&s->work); -} - -/* - * Add a message to per-CPU context-dependent buffer. NMI and printk-safe - * have dedicated buffers, because otherwise printk-safe preempted by - * NMI-printk would have overwritten the NMI messages. - * - * The messages are flushed from irq work (or from panic()), possibly, - * from other CPU, concurrently with printk_safe_log_store(). Should this - * happen, printk_safe_log_store() will notice the buffer->len mismatch - * and repeat the write. - */ -static __printf(2, 0) int printk_safe_log_store(struct printk_safe_seq_buf *s, - const char *fmt, va_list args) -{ - int add; - size_t len; - va_list ap; - -again: - len = atomic_read(&s->len); - - /* The trailing '\0' is not counted into len. */ - if (len >= sizeof(s->buffer) - 1) { - atomic_inc(&s->message_lost); - queue_flush_work(s); - return 0; - } - - /* - * Make sure that all old data have been read before the buffer - * was reset. This is not needed when we just append data. - */ - if (!len) - smp_rmb(); - - va_copy(ap, args); - add = vscnprintf(s->buffer + len, sizeof(s->buffer) - len, fmt, ap); - va_end(ap); - if (!add) - return 0; - - /* - * Do it once again if the buffer has been flushed in the meantime. - * Note that atomic_cmpxchg() is an implicit memory barrier that - * makes sure that the data were written before updating s->len. - */ - if (atomic_cmpxchg(&s->len, len, len + add) != len) - goto again; - - queue_flush_work(s); - return add; -} - -static inline void printk_safe_flush_line(const char *text, int len) -{ - /* - * Avoid any console drivers calls from here, because we may be - * in NMI or printk_safe context (when in panic). The messages - * must go only into the ring buffer at this stage. Consoles will - * get explicitly called later when a crashdump is not generated. - */ - printk_deferred("%.*s", len, text); -} - -/* printk part of the temporary buffer line by line */ -static int printk_safe_flush_buffer(const char *start, size_t len) -{ - const char *c, *end; - bool header; - - c = start; - end = start + len; - header = true; - - /* Print line by line. */ - while (c < end) { - if (*c == '\n') { - printk_safe_flush_line(start, c - start + 1); - start = ++c; - header = true; - continue; - } - - /* Handle continuous lines or missing new line. */ - if ((c + 1 < end) && printk_get_level(c)) { - if (header) { - c = printk_skip_level(c); - continue; - } - - printk_safe_flush_line(start, c - start); - start = c++; - header = true; - continue; - } - - header = false; - c++; - } - - /* Check if there was a partial line. Ignore pure header. */ - if (start < end && !header) { - static const char newline[] = KERN_CONT "\n"; - - printk_safe_flush_line(start, end - start); - printk_safe_flush_line(newline, strlen(newline)); - } - - return len; -} - -static void report_message_lost(struct printk_safe_seq_buf *s) -{ - int lost = atomic_xchg(&s->message_lost, 0); - - if (lost) - printk_deferred("Lost %d message(s)!\n", lost); -} - -/* - * Flush data from the associated per-CPU buffer. The function - * can be called either via IRQ work or independently. - */ -static void __printk_safe_flush(struct irq_work *work) -{ - struct printk_safe_seq_buf *s = - container_of(work, struct printk_safe_seq_buf, work); - unsigned long flags; - size_t len; - int i; - - /* - * The lock has two functions. First, one reader has to flush all - * available message to make the lockless synchronization with - * writers easier. Second, we do not want to mix messages from - * different CPUs. This is especially important when printing - * a backtrace. - */ - raw_spin_lock_irqsave(&safe_read_lock, flags); - - i = 0; -more: - len = atomic_read(&s->len); - - /* - * This is just a paranoid check that nobody has manipulated - * the buffer an unexpected way. If we printed something then - * @len must only increase. Also it should never overflow the - * buffer size. - */ - if ((i && i >= len) || len > sizeof(s->buffer)) { - const char *msg = "printk_safe_flush: internal error\n"; - - printk_safe_flush_line(msg, strlen(msg)); - len = 0; - } - - if (!len) - goto out; /* Someone else has already flushed the buffer. */ - - /* Make sure that data has been written up to the @len */ - smp_rmb(); - i += printk_safe_flush_buffer(s->buffer + i, len - i); - - /* - * Check that nothing has got added in the meantime and truncate - * the buffer. Note that atomic_cmpxchg() is an implicit memory - * barrier that makes sure that the data were copied before - * updating s->len. - */ - if (atomic_cmpxchg(&s->len, len, 0) != len) - goto more; - -out: - report_message_lost(s); - raw_spin_unlock_irqrestore(&safe_read_lock, flags); -} - -/** - * printk_safe_flush - flush all per-cpu nmi buffers. - * - * The buffers are flushed automatically via IRQ work. This function - * is useful only when someone wants to be sure that all buffers have - * been flushed at some point. - */ -void printk_safe_flush(void) -{ - int cpu; - - for_each_possible_cpu(cpu) { -#ifdef CONFIG_PRINTK_NMI - __printk_safe_flush(&per_cpu(nmi_print_seq, cpu).work); -#endif - __printk_safe_flush(&per_cpu(safe_print_seq, cpu).work); - } -} - -/** - * printk_safe_flush_on_panic - flush all per-cpu nmi buffers when the system - * goes down. - * - * Similar to printk_safe_flush() but it can be called even in NMI context when - * the system goes down. It does the best effort to get NMI messages into - * the main ring buffer. - * - * Note that it could try harder when there is only one CPU online. - */ -void printk_safe_flush_on_panic(void) -{ - if (raw_spin_is_locked(&safe_read_lock)) { - if (num_online_cpus() > 1) - return; - - debug_locks_off(); - raw_spin_lock_init(&safe_read_lock); - } - - printk_safe_flush(); -} - #ifdef CONFIG_PRINTK_NMI -/* - * Safe printk() for NMI context. It uses a per-CPU buffer to - * store the message. NMIs are not nested, so there is always only - * one writer running. But the buffer might get flushed from another - * CPU, so we need to be careful. - */ -static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args) -{ - struct printk_safe_seq_buf *s = this_cpu_ptr(&nmi_print_seq); - - return printk_safe_log_store(s, fmt, args); -} - void noinstr printk_nmi_enter(void) { this_cpu_add(printk_context, PRINTK_NMI_CONTEXT_OFFSET); @@ -305,9 +32,6 @@ void noinstr printk_nmi_exit(void) * Marks a code that might produce many messages in NMI context * and the risk of losing them is more critical than eventual * reordering. - * - * It has effect only when called in NMI context. Then printk() - * will store the messages into the main logbuf directly. */ void printk_nmi_direct_enter(void) { @@ -320,27 +44,8 @@ void printk_nmi_direct_exit(void) this_cpu_and(printk_context, ~PRINTK_NMI_DIRECT_CONTEXT_MASK); } -#else - -static __printf(1, 0) int vprintk_nmi(const char *fmt, va_list args) -{ - return 0; -} - #endif /* CONFIG_PRINTK_NMI */ -/* - * Lock-less printk(), to avoid deadlocks should the printk() recurse - * into itself. It uses a per-CPU buffer to store the message, just like - * NMI. - */ -static __printf(1, 0) int vprintk_safe(const char *fmt, va_list args) -{ - struct printk_safe_seq_buf *s = this_cpu_ptr(&safe_print_seq); - - return printk_safe_log_store(s, fmt, args); -} - /* Can be preempted by NMI. */ void __printk_safe_enter(void) { @@ -365,8 +70,10 @@ __printf(1, 0) int vprintk_func(const char *fmt, va_list args) * Use the main logbuf even in NMI. But avoid calling console * drivers that might have their own locks. */ - if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK)) { - unsigned long flags; + if (this_cpu_read(printk_context) & + (PRINTK_NMI_DIRECT_CONTEXT_MASK | + PRINTK_NMI_CONTEXT_MASK | + PRINTK_SAFE_CONTEXT_MASK)) { int len; printk_safe_enter_irqsave(flags); @@ -376,34 +83,6 @@ __printf(1, 0) int vprintk_func(const char *fmt, va_list args) return len; } - /* Use extra buffer in NMI. */ - if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK) - return vprintk_nmi(fmt, args); - - /* Use extra buffer to prevent a recursion deadlock in safe mode. */ - if (this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK) - return vprintk_safe(fmt, args); - /* No obstacles. */ return vprintk_default(fmt, args); } - -void __init printk_safe_init(void) -{ - int cpu; - - for_each_possible_cpu(cpu) { - struct printk_safe_seq_buf *s; - - s = &per_cpu(safe_print_seq, cpu); - init_irq_work(&s->work, __printk_safe_flush); - -#ifdef CONFIG_PRINTK_NMI - s = &per_cpu(nmi_print_seq, cpu); - init_irq_work(&s->work, __printk_safe_flush); -#endif - } - - /* Flush pending messages that did not have scheduled IRQ works. */ - printk_safe_flush(); -} diff --git a/lib/nmi_backtrace.c b/lib/nmi_backtrace.c index 8abe1870dba4..b09a490f5f70 100644 --- a/lib/nmi_backtrace.c +++ b/lib/nmi_backtrace.c @@ -75,12 +75,6 @@ void nmi_trigger_cpumask_backtrace(const cpumask_t *mask, touch_softlockup_watchdog(); } - /* - * Force flush any remote buffers that might be stuck in IRQ context - * and therefore could not run their irq_work. - */ - printk_safe_flush(); - clear_bit_unlock(0, &backtrace_flag); put_cpu(); } -- Gitee From b451a67929220bcd756ff905bed2137edb8e3ace Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:23:16 +0800 Subject: [PATCH 06/16] printk: convert @syslog_lock to spin_lock commit 287974a589d8d23679b85d6630d53b9965705668 upstream. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- kernel/printk/printk.c | 30 +++++++++++++++--------------- 1 file changed, 15 insertions(+), 15 deletions(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 8aebc6ae29d2..66348114ceaf 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -369,7 +369,7 @@ enum log_flags { }; /* syslog_lock protects syslog_* variables and write access to clear_seq. */ -static DEFINE_RAW_SPINLOCK(syslog_lock); +static DEFINE_SPINLOCK(syslog_lock); #ifdef CONFIG_PRINTK DECLARE_WAIT_QUEUE_HEAD(log_wait); @@ -1493,9 +1493,9 @@ static int syslog_print(char __user *buf, int size) size_t n; size_t skip; - raw_spin_lock_irq(&syslog_lock); + spin_lock_irq(&syslog_lock); if (!prb_read_valid(prb, syslog_seq, &r)) { - raw_spin_unlock_irq(&syslog_lock); + spin_unlock_irq(&syslog_lock); break; } if (r.info->seq != syslog_seq) { @@ -1524,7 +1524,7 @@ static int syslog_print(char __user *buf, int size) syslog_partial += n; } else n = 0; - raw_spin_unlock_irq(&syslog_lock); + spin_unlock_irq(&syslog_lock); if (!n) break; @@ -1588,9 +1588,9 @@ static int syslog_print_all(char __user *buf, int size, bool clear) } if (clear) { - raw_spin_lock_irq(&syslog_lock); + spin_lock_irq(&syslog_lock); latched_seq_write(&clear_seq, seq); - raw_spin_unlock_irq(&syslog_lock); + spin_unlock_irq(&syslog_lock); } kfree(text); @@ -1599,9 +1599,9 @@ static int syslog_print_all(char __user *buf, int size, bool clear) static void syslog_clear(void) { - raw_spin_lock_irq(&syslog_lock); + spin_lock_irq(&syslog_lock); latched_seq_write(&clear_seq, prb_next_seq(prb)); - raw_spin_unlock_irq(&syslog_lock); + spin_unlock_irq(&syslog_lock); } /* Return a consistent copy of @syslog_seq. */ @@ -1609,9 +1609,9 @@ static u64 read_syslog_seq_irq(void) { u64 seq; - raw_spin_lock_irq(&syslog_lock); + spin_lock_irq(&syslog_lock); seq = syslog_seq; - raw_spin_unlock_irq(&syslog_lock); + spin_unlock_irq(&syslog_lock); return seq; } @@ -1689,10 +1689,10 @@ int do_syslog(int type, char __user *buf, int len, int source) break; /* Number of chars in the log buffer */ case SYSLOG_ACTION_SIZE_UNREAD: - raw_spin_lock_irq(&syslog_lock); + spin_lock_irq(&syslog_lock); if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) { /* No unread messages. */ - raw_spin_unlock_irq(&syslog_lock); + spin_unlock_irq(&syslog_lock); return 0; } if (info.seq != syslog_seq) { @@ -1720,7 +1720,7 @@ int do_syslog(int type, char __user *buf, int len, int source) } error -= syslog_partial; } - raw_spin_unlock_irq(&syslog_lock); + spin_unlock_irq(&syslog_lock); break; /* Size of the log buffer */ case SYSLOG_ACTION_SIZE_BUFFER: @@ -3058,9 +3058,9 @@ void register_console(struct console *newcon) exclusive_console_stop_seq = console_seq; /* Get a consistent copy of @syslog_seq. */ - raw_spin_lock_irqsave(&syslog_lock, flags); + spin_lock_irqsave(&syslog_lock, flags); console_seq = syslog_seq; - raw_spin_unlock_irqrestore(&syslog_lock, flags); + spin_unlock_irqrestore(&syslog_lock, flags); } console_unlock(); console_sysfs_notify(); -- Gitee From e93fdea8b618010be6a2d23e099019a2e910a11d Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:23:29 +0800 Subject: [PATCH 07/16] console: add write_atomic interface commit a981d37a178e4d5f36792aec4f470c74af3fc3aa upstream. Add a write_atomic() callback to the console. This is an optional function for console drivers. The function must be atomic (including NMI safe) for writing to the console. Console drivers must still implement the write() callback. The write_atomic() callback will only be used in special situations, such as when the kernel panics. Creating an NMI safe write_atomic() that must synchronize with write() requires a careful implementation of the console driver. To aid with the implementation, a set of console_atomic_*() functions are provided: void console_atomic_lock(unsigned int *flags); void console_atomic_unlock(unsigned int flags); These functions synchronize using a processor-reentrant spinlock (called a cpulock). Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- include/linux/console.h | 4 ++ kernel/printk/printk.c | 100 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 104 insertions(+) diff --git a/include/linux/console.h b/include/linux/console.h index bc2a749e6f0d..613df76903f5 100644 --- a/include/linux/console.h +++ b/include/linux/console.h @@ -141,6 +141,7 @@ static inline int con_debug_leave(void) struct console { char name[16]; void (*write)(struct console *, const char *, unsigned); + void (*write_atomic)(struct console *co, const char *s, unsigned int count); int (*read)(struct console *, char *, unsigned); struct tty_driver *(*device)(struct console *, int *); void (*unblank)(void); @@ -232,4 +233,7 @@ extern void console_init(void); void dummycon_register_output_notifier(struct notifier_block *nb); void dummycon_unregister_output_notifier(struct notifier_block *nb); +extern void console_atomic_lock(unsigned int *flags); +extern void console_atomic_unlock(unsigned int flags); + #endif /* _LINUX_CONSOLE_H */ diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 66348114ceaf..03642d7bbb92 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -3605,3 +3605,103 @@ void kmsg_dump_rewind(struct kmsg_dumper_iter *iter) EXPORT_SYMBOL_GPL(kmsg_dump_rewind); #endif + +struct prb_cpulock { + atomic_t owner; + unsigned long __percpu *irqflags; +}; + +#define DECLARE_STATIC_PRINTKRB_CPULOCK(name) \ +static DEFINE_PER_CPU(unsigned long, _##name##_percpu_irqflags); \ +static struct prb_cpulock name = { \ + .owner = ATOMIC_INIT(-1), \ + .irqflags = &_##name##_percpu_irqflags, \ +} + +static bool __prb_trylock(struct prb_cpulock *cpu_lock, + unsigned int *cpu_store) +{ + unsigned long *flags; + unsigned int cpu; + + cpu = get_cpu(); + + *cpu_store = atomic_read(&cpu_lock->owner); + /* memory barrier to ensure the current lock owner is visible */ + smp_rmb(); + if (*cpu_store == -1) { + flags = per_cpu_ptr(cpu_lock->irqflags, cpu); + local_irq_save(*flags); + if (atomic_try_cmpxchg_acquire(&cpu_lock->owner, + cpu_store, cpu)) { + return true; + } + local_irq_restore(*flags); + } else if (*cpu_store == cpu) { + return true; + } + + put_cpu(); + return false; +} + +/* + * prb_lock: Perform a processor-reentrant spin lock. + * @cpu_lock: A pointer to the lock object. + * @cpu_store: A "flags" pointer to store lock status information. + * + * If no processor has the lock, the calling processor takes the lock and + * becomes the owner. If the calling processor is already the owner of the + * lock, this function succeeds immediately. If lock is locked by another + * processor, this function spins until the calling processor becomes the + * owner. + * + * It is safe to call this function from any context and state. + */ +static void prb_lock(struct prb_cpulock *cpu_lock, unsigned int *cpu_store) +{ + for (;;) { + if (__prb_trylock(cpu_lock, cpu_store)) + break; + cpu_relax(); + } +} + +/* + * prb_unlock: Perform a processor-reentrant spin unlock. + * @cpu_lock: A pointer to the lock object. + * @cpu_store: A "flags" object storing lock status information. + * + * Release the lock. The calling processor must be the owner of the lock. + * + * It is safe to call this function from any context and state. + */ +static void prb_unlock(struct prb_cpulock *cpu_lock, unsigned int cpu_store) +{ + unsigned long *flags; + unsigned int cpu; + + cpu = atomic_read(&cpu_lock->owner); + atomic_set_release(&cpu_lock->owner, cpu_store); + + if (cpu_store == -1) { + flags = per_cpu_ptr(cpu_lock->irqflags, cpu); + local_irq_restore(*flags); + } + + put_cpu(); +} + +DECLARE_STATIC_PRINTKRB_CPULOCK(printk_cpulock); + +void console_atomic_lock(unsigned int *flags) +{ + prb_lock(&printk_cpulock, flags); +} +EXPORT_SYMBOL(console_atomic_lock); + +void console_atomic_unlock(unsigned int flags) +{ + prb_unlock(&printk_cpulock, flags); +} +EXPORT_SYMBOL(console_atomic_unlock); -- Gitee From 804ef7b1b7fff2006cd5aff5e8938def60178454 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:23:44 +0800 Subject: [PATCH 08/16] serial: 8250: implement write_atomic commit 7df80f240f3eaa8ba52ec86ccd37cf669634a174 upstream. Implement a non-sleeping NMI-safe write_atomic() console function in order to support emergency console printing. Since interrupts need to be disabled during transmit, all usage of the IER register is wrapped with access functions that use the console_atomic_lock() function to synchronize register access while tracking the state of the interrupts. This is necessary because write_atomic() can be called from an NMI context that has preempted write_atomic(). Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- drivers/tty/serial/8250/8250.h | 47 ++++++++++++- drivers/tty/serial/8250/8250_core.c | 17 +++-- drivers/tty/serial/8250/8250_fsl.c | 9 +++ drivers/tty/serial/8250/8250_ingenic.c | 7 ++ drivers/tty/serial/8250/8250_mtk.c | 29 +++++++- drivers/tty/serial/8250/8250_port.c | 92 ++++++++++++++++---------- include/linux/serial_8250.h | 5 ++ 7 files changed, 162 insertions(+), 44 deletions(-) diff --git a/drivers/tty/serial/8250/8250.h b/drivers/tty/serial/8250/8250.h index 34aa2714f3c9..42cd2baa7663 100644 --- a/drivers/tty/serial/8250/8250.h +++ b/drivers/tty/serial/8250/8250.h @@ -131,12 +131,55 @@ static inline void serial_dl_write(struct uart_8250_port *up, int value) up->dl_write(up, value); } +static inline void serial8250_set_IER(struct uart_8250_port *up, + unsigned char ier) +{ + struct uart_port *port = &up->port; + unsigned int flags; + bool is_console; + + is_console = uart_console(port); + + if (is_console) + console_atomic_lock(&flags); + + serial_out(up, UART_IER, ier); + + if (is_console) + console_atomic_unlock(flags); +} + +static inline unsigned char serial8250_clear_IER(struct uart_8250_port *up) +{ + struct uart_port *port = &up->port; + unsigned int clearval = 0; + unsigned int prior; + unsigned int flags; + bool is_console; + + is_console = uart_console(port); + + if (up->capabilities & UART_CAP_UUE) + clearval = UART_IER_UUE; + + if (is_console) + console_atomic_lock(&flags); + + prior = serial_port_in(port, UART_IER); + serial_port_out(port, UART_IER, clearval); + + if (is_console) + console_atomic_unlock(flags); + + return prior; +} + static inline bool serial8250_set_THRI(struct uart_8250_port *up) { if (up->ier & UART_IER_THRI) return false; up->ier |= UART_IER_THRI; - serial_out(up, UART_IER, up->ier); + serial8250_set_IER(up, up->ier); return true; } @@ -145,7 +188,7 @@ static inline bool serial8250_clear_THRI(struct uart_8250_port *up) if (!(up->ier & UART_IER_THRI)) return false; up->ier &= ~UART_IER_THRI; - serial_out(up, UART_IER, up->ier); + serial8250_set_IER(up, up->ier); return true; } diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c index 98ce484f1089..ceba24927c1e 100644 --- a/drivers/tty/serial/8250/8250_core.c +++ b/drivers/tty/serial/8250/8250_core.c @@ -275,10 +275,8 @@ static void serial8250_backup_timeout(struct timer_list *t) * Must disable interrupts or else we risk racing with the interrupt * based handler. */ - if (up->port.irq) { - ier = serial_in(up, UART_IER); - serial_out(up, UART_IER, 0); - } + if (up->port.irq) + ier = serial8250_clear_IER(up); iir = serial_in(up, UART_IIR); @@ -301,7 +299,7 @@ static void serial8250_backup_timeout(struct timer_list *t) serial8250_tx_chars(up); if (up->port.irq) - serial_out(up, UART_IER, ier); + serial8250_set_IER(up, ier); spin_unlock_irqrestore(&up->port.lock, flags); @@ -582,6 +580,14 @@ serial8250_register_ports(struct uart_driver *drv, struct device *dev) #ifdef CONFIG_SERIAL_8250_CONSOLE +static void univ8250_console_write_atomic(struct console *co, const char *s, + unsigned int count) +{ + struct uart_8250_port *up = &serial8250_ports[co->index]; + + serial8250_console_write_atomic(up, s, count); +} + static void univ8250_console_write(struct console *co, const char *s, unsigned int count) { @@ -675,6 +681,7 @@ static int univ8250_console_match(struct console *co, char *name, int idx, static struct console univ8250_console = { .name = "ttyS", + .write_atomic = univ8250_console_write_atomic, .write = univ8250_console_write, .device = uart_console_device, .setup = univ8250_console_setup, diff --git a/drivers/tty/serial/8250/8250_fsl.c b/drivers/tty/serial/8250/8250_fsl.c index fbcc90c31ca1..b33cb454ce03 100644 --- a/drivers/tty/serial/8250/8250_fsl.c +++ b/drivers/tty/serial/8250/8250_fsl.c @@ -60,9 +60,18 @@ int fsl8250_handle_irq(struct uart_port *port) /* Stop processing interrupts on input overrun */ if ((orig_lsr & UART_LSR_OE) && (up->overrun_backoff_time_ms > 0)) { + unsigned int ca_flags; unsigned long delay; + bool is_console; + is_console = uart_console(port); + + if (is_console) + console_atomic_lock(&ca_flags); up->ier = port->serial_in(port, UART_IER); + if (is_console) + console_atomic_unlock(ca_flags); + if (up->ier & (UART_IER_RLSI | UART_IER_RDI)) { port->ops->stop_rx(port); } else { diff --git a/drivers/tty/serial/8250/8250_ingenic.c b/drivers/tty/serial/8250/8250_ingenic.c index 988bf6bcce42..bcd26d672539 100644 --- a/drivers/tty/serial/8250/8250_ingenic.c +++ b/drivers/tty/serial/8250/8250_ingenic.c @@ -146,6 +146,8 @@ OF_EARLYCON_DECLARE(x1000_uart, "ingenic,x1000-uart", static void ingenic_uart_serial_out(struct uart_port *p, int offset, int value) { + unsigned int flags; + bool is_console; int ier; switch (offset) { @@ -167,7 +169,12 @@ static void ingenic_uart_serial_out(struct uart_port *p, int offset, int value) * If we have enabled modem status IRQs we should enable * modem mode. */ + is_console = uart_console(p); + if (is_console) + console_atomic_lock(&flags); ier = p->serial_in(p, UART_IER); + if (is_console) + console_atomic_unlock(flags); if (ier & UART_IER_MSI) value |= UART_MCR_MDCE | UART_MCR_FCM; diff --git a/drivers/tty/serial/8250/8250_mtk.c b/drivers/tty/serial/8250/8250_mtk.c index de48a58460f4..d246f2755fed 100644 --- a/drivers/tty/serial/8250/8250_mtk.c +++ b/drivers/tty/serial/8250/8250_mtk.c @@ -222,12 +222,37 @@ static void mtk8250_shutdown(struct uart_port *port) static void mtk8250_disable_intrs(struct uart_8250_port *up, int mask) { - serial_out(up, UART_IER, serial_in(up, UART_IER) & (~mask)); + struct uart_port *port = &up->port; + unsigned int flags; + unsigned int ier; + bool is_console; + + is_console = uart_console(port); + + if (is_console) + console_atomic_lock(&flags); + + ier = serial_in(up, UART_IER); + serial_out(up, UART_IER, ier & (~mask)); + + if (is_console) + console_atomic_unlock(flags); } static void mtk8250_enable_intrs(struct uart_8250_port *up, int mask) { - serial_out(up, UART_IER, serial_in(up, UART_IER) | mask); + struct uart_port *port = &up->port; + unsigned int flags; + unsigned int ier; + + if (uart_console(port)) + console_atomic_lock(&flags); + + ier = serial_in(up, UART_IER); + serial_out(up, UART_IER, ier | mask); + + if (uart_console(port)) + console_atomic_unlock(flags); } static void mtk8250_set_flow_ctrl(struct uart_8250_port *up, int mode) diff --git a/drivers/tty/serial/8250/8250_port.c b/drivers/tty/serial/8250/8250_port.c index 43884e8b5161..74ce9ef73c6b 100644 --- a/drivers/tty/serial/8250/8250_port.c +++ b/drivers/tty/serial/8250/8250_port.c @@ -762,7 +762,7 @@ static void serial8250_set_sleep(struct uart_8250_port *p, int sleep) serial_out(p, UART_EFR, UART_EFR_ECB); serial_out(p, UART_LCR, 0); } - serial_out(p, UART_IER, sleep ? UART_IERX_SLEEP : 0); + serial8250_set_IER(p, sleep ? UART_IERX_SLEEP : 0); if (p->capabilities & UART_CAP_EFR) { serial_out(p, UART_LCR, UART_LCR_CONF_MODE_B); serial_out(p, UART_EFR, efr); @@ -1436,7 +1436,7 @@ static void serial8250_stop_rx(struct uart_port *port) up->ier &= ~(UART_IER_RLSI | UART_IER_RDI); up->port.read_status_mask &= ~UART_LSR_DR; - serial_port_out(port, UART_IER, up->ier); + serial8250_set_IER(up, up->ier); serial8250_rpm_put(up); } @@ -1466,7 +1466,7 @@ void serial8250_em485_stop_tx(struct uart_8250_port *p) serial8250_clear_and_reinit_fifos(p); p->ier |= UART_IER_RLSI | UART_IER_RDI; - serial_port_out(&p->port, UART_IER, p->ier); + serial8250_set_IER(p, p->ier); } } EXPORT_SYMBOL_GPL(serial8250_em485_stop_tx); @@ -1708,7 +1708,7 @@ static void serial8250_disable_ms(struct uart_port *port) mctrl_gpio_disable_ms(up->gpios); up->ier &= ~UART_IER_MSI; - serial_port_out(port, UART_IER, up->ier); + serial8250_set_IER(up, up->ier); } static void serial8250_enable_ms(struct uart_port *port) @@ -1724,7 +1724,7 @@ static void serial8250_enable_ms(struct uart_port *port) up->ier |= UART_IER_MSI; serial8250_rpm_get(up); - serial_port_out(port, UART_IER, up->ier); + serial8250_set_IER(up, up->ier); serial8250_rpm_put(up); } @@ -2142,14 +2142,7 @@ static void serial8250_put_poll_char(struct uart_port *port, struct uart_8250_port *up = up_to_u8250p(port); serial8250_rpm_get(up); - /* - * First save the IER then disable the interrupts - */ - ier = serial_port_in(port, UART_IER); - if (up->capabilities & UART_CAP_UUE) - serial_port_out(port, UART_IER, UART_IER_UUE); - else - serial_port_out(port, UART_IER, 0); + ier = serial8250_clear_IER(up); wait_for_xmitr(up, BOTH_EMPTY); /* @@ -2162,7 +2155,7 @@ static void serial8250_put_poll_char(struct uart_port *port, * and restore the IER */ wait_for_xmitr(up, BOTH_EMPTY); - serial_port_out(port, UART_IER, ier); + serial8250_set_IER(up, ier); serial8250_rpm_put(up); } @@ -2465,7 +2458,7 @@ void serial8250_do_shutdown(struct uart_port *port) */ spin_lock_irqsave(&port->lock, flags); up->ier = 0; - serial_port_out(port, UART_IER, 0); + serial8250_set_IER(up, 0); spin_unlock_irqrestore(&port->lock, flags); synchronize_irq(port->irq); @@ -2821,7 +2814,7 @@ serial8250_do_set_termios(struct uart_port *port, struct ktermios *termios, if (up->capabilities & UART_CAP_RTOIE) up->ier |= UART_IER_RTOIE; - serial_port_out(port, UART_IER, up->ier); + serial8250_set_IER(up, up->ier); if (up->capabilities & UART_CAP_EFR) { unsigned char efr = 0; @@ -3289,7 +3282,7 @@ EXPORT_SYMBOL_GPL(serial8250_set_defaults); #ifdef CONFIG_SERIAL_8250_CONSOLE -static void serial8250_console_putchar(struct uart_port *port, int ch) +static void serial8250_console_putchar_locked(struct uart_port *port, int ch) { struct uart_8250_port *up = up_to_u8250p(port); @@ -3297,6 +3290,18 @@ static void serial8250_console_putchar(struct uart_port *port, int ch) serial_port_out(port, UART_TX, ch); } +static void serial8250_console_putchar(struct uart_port *port, int ch) +{ + struct uart_8250_port *up = up_to_u8250p(port); + unsigned int flags; + + wait_for_xmitr(up, UART_LSR_THRE); + + console_atomic_lock(&flags); + serial8250_console_putchar_locked(port, ch); + console_atomic_unlock(flags); +} + /* * Restore serial console when h/w power-off detected */ @@ -3318,6 +3323,32 @@ static void serial8250_console_restore(struct uart_8250_port *up) serial8250_out_MCR(up, up->mcr | UART_MCR_DTR | UART_MCR_RTS); } +void serial8250_console_write_atomic(struct uart_8250_port *up, + const char *s, unsigned int count) +{ + struct uart_port *port = &up->port; + unsigned int flags; + unsigned int ier; + + console_atomic_lock(&flags); + + touch_nmi_watchdog(); + + ier = serial8250_clear_IER(up); + + if (atomic_fetch_inc(&up->console_printing)) { + uart_console_write(port, "\n", 1, + serial8250_console_putchar_locked); + } + uart_console_write(port, s, count, serial8250_console_putchar_locked); + atomic_dec(&up->console_printing); + + wait_for_xmitr(up, BOTH_EMPTY); + serial8250_set_IER(up, ier); + + console_atomic_unlock(flags); +} + /* * Print a string to the serial port trying not to disturb * any possible real use of the port... @@ -3334,24 +3365,12 @@ void serial8250_console_write(struct uart_8250_port *up, const char *s, struct uart_port *port = &up->port; unsigned long flags; unsigned int ier; - int locked = 1; touch_nmi_watchdog(); - if (oops_in_progress) - locked = spin_trylock_irqsave(&port->lock, flags); - else - spin_lock_irqsave(&port->lock, flags); - - /* - * First save the IER then disable the interrupts - */ - ier = serial_port_in(port, UART_IER); + spin_lock_irqsave(&port->lock, flags); - if (up->capabilities & UART_CAP_UUE) - serial_port_out(port, UART_IER, UART_IER_UUE); - else - serial_port_out(port, UART_IER, 0); + ier = serial8250_clear_IER(up); /* check scratch reg to see if port powered off during system sleep */ if (up->canary && (up->canary != serial_port_in(port, UART_SCR))) { @@ -3365,7 +3384,9 @@ void serial8250_console_write(struct uart_8250_port *up, const char *s, mdelay(port->rs485.delay_rts_before_send); } + atomic_inc(&up->console_printing); uart_console_write(port, s, count, serial8250_console_putchar); + atomic_dec(&up->console_printing); /* * Finally, wait for transmitter to become empty @@ -3378,8 +3399,7 @@ void serial8250_console_write(struct uart_8250_port *up, const char *s, if (em485->tx_stopped) up->rs485_stop_tx(up); } - - serial_port_out(port, UART_IER, ier); + serial8250_set_IER(up, ier); /* * The receive handling will happen properly because the @@ -3391,8 +3411,7 @@ void serial8250_console_write(struct uart_8250_port *up, const char *s, if (up->msr_saved_flags) serial8250_modem_status(up); - if (locked) - spin_unlock_irqrestore(&port->lock, flags); + spin_unlock_irqrestore(&port->lock, flags); } static unsigned int probe_baud(struct uart_port *port) @@ -3412,6 +3431,7 @@ static unsigned int probe_baud(struct uart_port *port) int serial8250_console_setup(struct uart_port *port, char *options, bool probe) { + struct uart_8250_port *up = up_to_u8250p(port); int baud = 9600; int bits = 8; int parity = 'n'; @@ -3421,6 +3441,8 @@ int serial8250_console_setup(struct uart_port *port, char *options, bool probe) if (!port->iobase && !port->membase) return -ENODEV; + atomic_set(&up->console_printing, 0); + if (options) uart_parse_options(options, &baud, &parity, &bits, &flow); else if (probe) diff --git a/include/linux/serial_8250.h b/include/linux/serial_8250.h index 2b70f736b091..68d756373b53 100644 --- a/include/linux/serial_8250.h +++ b/include/linux/serial_8250.h @@ -7,6 +7,7 @@ #ifndef _LINUX_SERIAL_8250_H #define _LINUX_SERIAL_8250_H +#include #include #include #include @@ -125,6 +126,8 @@ struct uart_8250_port { #define MSR_SAVE_FLAGS UART_MSR_ANY_DELTA unsigned char msr_saved_flags; + atomic_t console_printing; + struct uart_8250_dma *dma; const struct uart_8250_ops *ops; @@ -180,6 +183,8 @@ void serial8250_init_port(struct uart_8250_port *up); void serial8250_set_defaults(struct uart_8250_port *up); void serial8250_console_write(struct uart_8250_port *up, const char *s, unsigned int count); +void serial8250_console_write_atomic(struct uart_8250_port *up, const char *s, + unsigned int count); int serial8250_console_setup(struct uart_port *port, char *options, bool probe); int serial8250_console_exit(struct uart_port *port); -- Gitee From eb220de3d12e8e5fef09098ecd1ba47915346e0e Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:23:58 +0800 Subject: [PATCH 09/16] printk: relocate printk_delay() and vprintk_default() commit eaf967adc484ba002cd6ed2feb1a3ad278e36951 upstream. Move printk_delay() and vprintk_default() "as is" further up so that they can be used by new functions in an upcoming commit. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- kernel/printk/printk.c | 40 ++++++++++++++++++++-------------------- 1 file changed, 20 insertions(+), 20 deletions(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 03642d7bbb92..c342f338aa2d 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -1739,6 +1739,20 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len) return do_syslog(type, buf, len, SYSLOG_FROM_READER); } +int printk_delay_msec __read_mostly; + +static inline void printk_delay(void) +{ + if (unlikely(printk_delay_msec)) { + int m = printk_delay_msec; + + while (m--) { + mdelay(1); + touch_nmi_watchdog(); + } + } +} + /* * Special console_lock variants that help to reduce the risk of soft-lockups. * They allow to pass console_lock to another printk() call using a busy wait. @@ -1992,20 +2006,6 @@ static void printk_exit_irqrestore(unsigned long flags) local_irq_restore(flags); } -int printk_delay_msec __read_mostly; - -static inline void printk_delay(void) -{ - if (unlikely(printk_delay_msec)) { - int m = printk_delay_msec; - - while (m--) { - mdelay(1); - touch_nmi_watchdog(); - } - } -} - static inline u32 printk_caller_id(void) { return in_task() ? task_pid_nr(current) : @@ -2244,18 +2244,18 @@ asmlinkage int vprintk_emit(int facility, int level, } EXPORT_SYMBOL(vprintk_emit); -asmlinkage int vprintk(const char *fmt, va_list args) -{ - return vprintk_func(fmt, args); -} -EXPORT_SYMBOL(vprintk); - int vprintk_default(const char *fmt, va_list args) { return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, fmt, args); } EXPORT_SYMBOL_GPL(vprintk_default); +asmlinkage int vprintk(const char *fmt, va_list args) +{ + return vprintk_func(fmt, args); +} +EXPORT_SYMBOL(vprintk); + /** * printk - print a kernel message * @fmt: format string -- Gitee From 8c83f267c70b73c028df17d7293c09428abf713d Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:24:09 +0800 Subject: [PATCH 10/16] printk: combine boot_delay_msec() into printk_delay() commit 5103606208f80eddf0ad5e2f381da818d96ca83f upstream. boot_delay_msec() is always called immediately before printk_delay() so just combine the two. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- kernel/printk/printk.c | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index c342f338aa2d..5b5b37fb31a9 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -1741,8 +1741,10 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len) int printk_delay_msec __read_mostly; -static inline void printk_delay(void) +static inline void printk_delay(int level) { + boot_delay_msec(level); + if (unlikely(printk_delay_msec)) { int m = printk_delay_msec; @@ -2216,8 +2218,7 @@ asmlinkage int vprintk_emit(int facility, int level, in_sched = true; } - boot_delay_msec(level); - printk_delay(); + printk_delay(level); printed_len = vprintk_store(facility, level, dev_info, fmt, args); -- Gitee From fbe76f69f17a6b94086e899393802d6eeba7d0c1 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:36:23 +0800 Subject: [PATCH 11/16] printk: change @console_seq to atomic64_t commit e12cdf90614a1cc39ad546f25eb1a9d77d3566ba upstream. In preparation for atomic printing, change @console_seq to atomic so that it can be accessed without requiring @console_sem. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- kernel/printk/printk.c | 35 ++++++++++++++++++++--------------- 1 file changed, 20 insertions(+), 15 deletions(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 5b5b37fb31a9..c8101a164748 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -379,12 +379,13 @@ static u64 syslog_seq; static size_t syslog_partial; static bool syslog_time; -/* All 3 protected by @console_sem. */ -/* the next printk record to write to the console */ -static u64 console_seq; +/* Both protected by @console_sem. */ static u64 exclusive_console_stop_seq; static unsigned long console_dropped; +/* the next printk record to write to the console */ +static atomic64_t console_seq = ATOMIC64_INIT(0); + struct latched_seq { seqcount_latch_t latch; u64 val[2]; @@ -2300,7 +2301,7 @@ EXPORT_SYMBOL(printk); #define prb_first_valid_seq(rb) 0 static u64 syslog_seq; -static u64 console_seq; +static atomic64_t console_seq = ATOMIC64_INIT(0); static u64 exclusive_console_stop_seq; static unsigned long console_dropped; @@ -2635,6 +2636,7 @@ void console_unlock(void) bool do_cond_resched, retry; struct printk_info info; struct printk_record r; + u64 seq; if (console_suspended) { up_console_sem(); @@ -2677,14 +2679,17 @@ void console_unlock(void) size_t len; skip: - if (!prb_read_valid(prb, console_seq, &r)) + seq = atomic64_read(&console_seq); + if (!prb_read_valid(prb, seq, &r)) break; - if (console_seq != r.info->seq) { - console_dropped += r.info->seq - console_seq; - console_seq = r.info->seq; + if (seq != r.info->seq) { + console_dropped += r.info->seq - seq; + atomic64_set(&console_seq, r.info->seq); + seq = r.info->seq; if (panic_in_progress() && panic_console_dropped++ > 10) suppress_panic_printk = 1; + } if (suppress_message_printing(r.info->level)) { @@ -2693,13 +2698,13 @@ void console_unlock(void) * directly to the console when we received it, and * record that has level above the console loglevel. */ - console_seq++; + atomic64_set(&console_seq, seq + 1); goto skip; } /* Output to all consoles once old messages replayed. */ if (unlikely(exclusive_console && - console_seq >= exclusive_console_stop_seq)) { + seq >= exclusive_console_stop_seq)) { exclusive_console = NULL; } @@ -2720,7 +2725,7 @@ void console_unlock(void) len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time); - console_seq++; + atomic64_set(&console_seq, seq + 1); /* * While actively printing out messages, if another printk() @@ -2755,7 +2760,7 @@ void console_unlock(void) * there's a new owner and the console_unlock() from them will do the * flush, no worries. */ - retry = prb_read_valid(prb, console_seq, NULL); + retry = prb_read_valid(prb, atomic64_read(&console_seq), NULL); if (retry && !abandon_console_lock_in_panic() && console_trylock()) goto again; @@ -2819,7 +2824,7 @@ void console_flush_on_panic(enum con_flush_mode mode) console_may_schedule = 0; if (mode == CONSOLE_REPLAY_ALL) - console_seq = prb_first_valid_seq(prb); + atomic64_set(&console_seq, prb_first_valid_seq(prb)); console_unlock(); } @@ -3056,11 +3061,11 @@ void register_console(struct console *newcon) * ignores console_lock. */ exclusive_console = newcon; - exclusive_console_stop_seq = console_seq; + exclusive_console_stop_seq = atomic64_read(&console_seq); /* Get a consistent copy of @syslog_seq. */ spin_lock_irqsave(&syslog_lock, flags); - console_seq = syslog_seq; + atomic64_set(&console_seq, syslog_seq); spin_unlock_irqrestore(&syslog_lock, flags); } console_unlock(); -- Gitee From 60647bbe6e2ca2e665ae93f83e39ad423cc3702f Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 20:36:50 +0800 Subject: [PATCH 12/16] printk: introduce kernel sync mode commit 9e7ca978f91c08f228bf1edbf2a240ee47987bc8 upstream. When the kernel performs an OOPS, enter into "sync mode": - only atomic consoles (write_atomic() callback) will print - printing occurs within vprintk_store() instead of console_unlock() CONSOLE_LOG_MAX is moved to printk.h to support the per-console buffer used in sync mode. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior Signed-off-by: Luis Claudio R. Goncalves --- include/linux/console.h | 4 ++ include/linux/printk.h | 6 ++ kernel/printk/printk.c | 133 ++++++++++++++++++++++++++++++++++++++-- 3 files changed, 137 insertions(+), 6 deletions(-) diff --git a/include/linux/console.h b/include/linux/console.h index 613df76903f5..fcc98354f733 100644 --- a/include/linux/console.h +++ b/include/linux/console.h @@ -16,6 +16,7 @@ #include #include +#include struct vc_data; struct console_font_op; @@ -151,6 +152,9 @@ struct console { short flags; short index; int cflag; +#ifdef CONFIG_PRINTK + char sync_buf[CONSOLE_LOG_MAX]; +#endif uint ispeed; uint ospeed; void *data; diff --git a/include/linux/printk.h b/include/linux/printk.h index 2476796c1150..1ebd93581acc 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -46,6 +46,12 @@ static inline const char *printk_skip_headers(const char *buffer) #define CONSOLE_EXT_LOG_MAX 8192 +/* + * The maximum size of a record formatted for console printing + * (i.e. with the prefix prepended to every line). + */ +#define CONSOLE_LOG_MAX 4096 + /* printk's without a loglevel use this.. */ #define MESSAGE_LOGLEVEL_DEFAULT CONFIG_MESSAGE_LOGLEVEL_DEFAULT diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index c8101a164748..146b2fc149cf 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -44,6 +44,7 @@ #include #include #include +#include #include #include #include @@ -372,6 +373,9 @@ enum log_flags { static DEFINE_SPINLOCK(syslog_lock); #ifdef CONFIG_PRINTK +/* Set to enable sync mode. Once set, it is never cleared. */ +static bool sync_mode; + DECLARE_WAIT_QUEUE_HEAD(log_wait); /* All 3 protected by @syslog_lock. */ /* the next printk record to read by syslog(READ) or /proc/kmsg */ @@ -411,9 +415,6 @@ static struct latched_seq clear_seq = { /* the maximum size allowed to be reserved for a record */ #define LOG_LINE_MAX (1024 - PREFIX_MAX) -/* the maximum size of a formatted record (i.e. with prefix added per line) */ -#define CONSOLE_LOG_MAX 4096 - #define LOG_LEVEL(v) ((v) & 0x07) #define LOG_FACILITY(v) ((v) >> 3 & 0xff) @@ -1756,6 +1757,91 @@ static inline void printk_delay(int level) } } +static bool kernel_sync_mode(void) +{ + return (oops_in_progress || sync_mode); +} + +static bool console_can_sync(struct console *con) +{ + if (!(con->flags & CON_ENABLED)) + return false; + if (con->write_atomic && kernel_sync_mode()) + return true; + return false; +} + +static bool call_sync_console_driver(struct console *con, const char *text, size_t text_len) +{ + if (!(con->flags & CON_ENABLED)) + return false; + if (con->write_atomic && kernel_sync_mode()) + con->write_atomic(con, text, text_len); + else + return false; + + return true; +} + +static bool have_atomic_console(void) +{ + struct console *con; + + for_each_console(con) { + if (!(con->flags & CON_ENABLED)) + continue; + if (con->write_atomic) + return true; + } + return false; +} + +static bool print_sync(struct console *con, u64 *seq) +{ + struct printk_info info; + struct printk_record r; + size_t text_len; + + prb_rec_init_rd(&r, &info, &con->sync_buf[0], sizeof(con->sync_buf)); + + if (!prb_read_valid(prb, *seq, &r)) + return false; + + text_len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time); + + if (!call_sync_console_driver(con, &con->sync_buf[0], text_len)) + return false; + + *seq = r.info->seq; + + touch_softlockup_watchdog_sync(); + clocksource_touch_watchdog(); + rcu_cpu_stall_reset(); + touch_nmi_watchdog(); + + if (text_len) + printk_delay(r.info->level); + + return true; +} + +static void print_sync_until(struct console *con, u64 seq) +{ + unsigned int flags; + u64 printk_seq; + + console_atomic_lock(&flags); + for (;;) { + printk_seq = atomic64_read(&console_seq); + if (printk_seq >= seq) + break; + if (!print_sync(con, &printk_seq)) + break; + atomic64_set(&console_seq, printk_seq + 1); + } + console_atomic_unlock(flags); +} + /* * Special console_lock variants that help to reduce the risk of soft-lockups. * They allow to pass console_lock to another printk() call using a busy wait. @@ -1940,6 +2026,8 @@ static void call_console_drivers(const char *ext_text, size_t ext_len, if (!cpu_online(smp_processor_id()) && !(con->flags & CON_ANYTIME)) continue; + if (kernel_sync_mode()) + continue; if (con->flags & CON_EXTENDED) con->write(con, ext_text, ext_len); else { @@ -2094,6 +2182,7 @@ int vprintk_store(int facility, int level, const u32 caller_id = printk_caller_id(); struct prb_reserved_entry e; enum log_flags lflags = 0; + bool final_commit = false; struct printk_record r; unsigned long irqflags; u16 trunc_msg_len = 0; @@ -2103,6 +2192,7 @@ int vprintk_store(int facility, int level, u16 text_len; int ret = 0; u64 ts_nsec; + u64 seq; /* * Since the duration of printk() can vary depending on the message @@ -2141,6 +2231,7 @@ int vprintk_store(int facility, int level, if (lflags & LOG_CONT) { prb_rec_init_wr(&r, reserve_size); if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) { + seq = r.info->seq; text_len = printk_sprint(&r.text_buf[r.info->text_len], reserve_size, facility, &lflags, fmt, args); r.info->text_len += text_len; @@ -2148,6 +2239,7 @@ int vprintk_store(int facility, int level, if (lflags & LOG_NEWLINE) { r.info->flags |= LOG_NEWLINE; prb_final_commit(&e); + final_commit = true; } else { prb_commit(&e); } @@ -2172,6 +2264,8 @@ int vprintk_store(int facility, int level, goto out; } + seq = r.info->seq; + /* fill message */ text_len = printk_sprint(&r.text_buf[0], reserve_size, facility, &lflags, fmt, args); if (trunc_msg_len) @@ -2186,13 +2280,25 @@ int vprintk_store(int facility, int level, memcpy(&r.info->dev_info, dev_info, sizeof(r.info->dev_info)); /* A message without a trailing newline can be continued. */ - if (!(lflags & LOG_NEWLINE)) + if (!(lflags & LOG_NEWLINE)) { prb_commit(&e); - else + } else { prb_final_commit(&e); + final_commit = true; + } ret = text_len + trunc_msg_len; out: + /* only the kernel may perform synchronous printing */ + if (facility == 0 && final_commit) { + struct console *con; + + for_each_console(con) { + if (console_can_sync(con)) + print_sync_until(con, seq + 1); + } + } + printk_exit_irqrestore(irqflags); return ret; } @@ -2294,12 +2400,13 @@ EXPORT_SYMBOL(printk); #else /* CONFIG_PRINTK */ -#define CONSOLE_LOG_MAX 0 #define printk_time false #define prb_read_valid(rb, seq, r) false #define prb_first_valid_seq(rb) 0 +#define kernel_sync_mode() false + static u64 syslog_seq; static atomic64_t console_seq = ATOMIC64_INIT(0); static u64 exclusive_console_stop_seq; @@ -2611,6 +2718,8 @@ static bool abandon_console_lock_in_panic(void) */ static inline int can_use_console(void) { + if (kernel_sync_mode()) + return false; return cpu_online(raw_smp_processor_id()) || have_callable_console(); } @@ -3434,6 +3543,18 @@ void kmsg_dump(enum kmsg_dump_reason reason) struct kmsg_dumper_iter iter; struct kmsg_dumper *dumper; + if (!oops_in_progress) { + /* + * If atomic consoles are available, activate kernel sync mode + * to make sure any final messages are visible. The trailing + * printk message is important to flush any pending messages. + */ + if (have_atomic_console()) { + sync_mode = true; + pr_info("enabled sync mode\n"); + } + } + rcu_read_lock(); list_for_each_entry_rcu(dumper, &dump_list, list) { enum kmsg_dump_reason max_reason = dumper->max_reason; -- Gitee From 27ab5590b64bfda22a8206ecd1b7856f361ef119 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 21:02:08 +0800 Subject: [PATCH 13/16] printk: move console printing to kthreads commit 8189a93319f7a3001b25d162a4de8dcfe7843c43 upstream. Create a kthread for each console to perform console printing. Now all console printing is fully asynchronous except for the boot console and when the kernel enters sync mode (and there are atomic consoles available). The console_lock() and console_unlock() functions now only do what their name says... locking and unlocking of the console. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior Signed-off-by: Luis Claudio R. Goncalves --- include/linux/console.h | 2 + kernel/printk/printk.c | 488 +++++++++++++++------------------------- 2 files changed, 186 insertions(+), 304 deletions(-) diff --git a/include/linux/console.h b/include/linux/console.h index fcc98354f733..3e99359e0660 100644 --- a/include/linux/console.h +++ b/include/linux/console.h @@ -155,6 +155,8 @@ struct console { #ifdef CONFIG_PRINTK char sync_buf[CONSOLE_LOG_MAX]; #endif + atomic64_t printk_seq; + struct task_struct *thread; uint ispeed; uint ospeed; void *data; diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 146b2fc149cf..a5a40b8cdba2 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -44,6 +44,7 @@ #include #include #include +#include #include #include #include @@ -280,11 +281,6 @@ static bool panic_in_progress(void) */ static int console_locked, console_suspended; -/* - * If exclusive_console is non-NULL then only this console is to be printed to. - */ -static struct console *exclusive_console; - /* * Array of consoles built from command line options (console=) */ @@ -369,10 +365,10 @@ enum log_flags { LOG_CONT = 8, /* text is a fragment of a continuation line */ }; +#ifdef CONFIG_PRINTK /* syslog_lock protects syslog_* variables and write access to clear_seq. */ static DEFINE_SPINLOCK(syslog_lock); -#ifdef CONFIG_PRINTK /* Set to enable sync mode. Once set, it is never cleared. */ static bool sync_mode; @@ -383,13 +379,6 @@ static u64 syslog_seq; static size_t syslog_partial; static bool syslog_time; -/* Both protected by @console_sem. */ -static u64 exclusive_console_stop_seq; -static unsigned long console_dropped; - -/* the next printk record to write to the console */ -static atomic64_t console_seq = ATOMIC64_INIT(0); - struct latched_seq { seqcount_latch_t latch; u64 val[2]; @@ -1768,6 +1757,8 @@ static bool console_can_sync(struct console *con) return false; if (con->write_atomic && kernel_sync_mode()) return true; + if (con->write && (con->flags & CON_BOOT) && !con->thread) + return true; return false; } @@ -1777,6 +1768,8 @@ static bool call_sync_console_driver(struct console *con, const char *text, size return false; if (con->write_atomic && kernel_sync_mode()) con->write_atomic(con, text, text_len); + else if (con->write && (con->flags & CON_BOOT) && !con->thread) + con->write(con, text, text_len); else return false; @@ -1832,212 +1825,16 @@ static void print_sync_until(struct console *con, u64 seq) console_atomic_lock(&flags); for (;;) { - printk_seq = atomic64_read(&console_seq); + printk_seq = atomic64_read(&con->printk_seq); if (printk_seq >= seq) break; if (!print_sync(con, &printk_seq)) break; - atomic64_set(&console_seq, printk_seq + 1); + atomic64_set(&con->printk_seq, printk_seq + 1); } console_atomic_unlock(flags); } -/* - * Special console_lock variants that help to reduce the risk of soft-lockups. - * They allow to pass console_lock to another printk() call using a busy wait. - */ - -#ifdef CONFIG_LOCKDEP -static struct lockdep_map console_owner_dep_map = { - .name = "console_owner" -}; -#endif - -static DEFINE_RAW_SPINLOCK(console_owner_lock); -static struct task_struct *console_owner; -static bool console_waiter; - -/** - * console_lock_spinning_enable - mark beginning of code where another - * thread might safely busy wait - * - * This basically converts console_lock into a spinlock. This marks - * the section where the console_lock owner can not sleep, because - * there may be a waiter spinning (like a spinlock). Also it must be - * ready to hand over the lock at the end of the section. - */ -static void console_lock_spinning_enable(void) -{ - raw_spin_lock(&console_owner_lock); - console_owner = current; - raw_spin_unlock(&console_owner_lock); - - /* The waiter may spin on us after setting console_owner */ - spin_acquire(&console_owner_dep_map, 0, 0, _THIS_IP_); -} - -/** - * console_lock_spinning_disable_and_check - mark end of code where another - * thread was able to busy wait and check if there is a waiter - * - * This is called at the end of the section where spinning is allowed. - * It has two functions. First, it is a signal that it is no longer - * safe to start busy waiting for the lock. Second, it checks if - * there is a busy waiter and passes the lock rights to her. - * - * Important: Callers lose the lock if there was a busy waiter. - * They must not touch items synchronized by console_lock - * in this case. - * - * Return: 1 if the lock rights were passed, 0 otherwise. - */ -static int console_lock_spinning_disable_and_check(void) -{ - int waiter; - - raw_spin_lock(&console_owner_lock); - waiter = READ_ONCE(console_waiter); - console_owner = NULL; - raw_spin_unlock(&console_owner_lock); - - if (!waiter) { - spin_release(&console_owner_dep_map, _THIS_IP_); - return 0; - } - - /* The waiter is now free to continue */ - WRITE_ONCE(console_waiter, false); - - spin_release(&console_owner_dep_map, _THIS_IP_); - - /* - * Hand off console_lock to waiter. The waiter will perform - * the up(). After this, the waiter is the console_lock owner. - */ - mutex_release(&console_lock_dep_map, _THIS_IP_); - return 1; -} - -/** - * console_trylock_spinning - try to get console_lock by busy waiting - * - * This allows to busy wait for the console_lock when the current - * owner is running in specially marked sections. It means that - * the current owner is running and cannot reschedule until it - * is ready to lose the lock. - * - * Return: 1 if we got the lock, 0 othrewise - */ -static int console_trylock_spinning(void) -{ - struct task_struct *owner = NULL; - bool waiter; - bool spin = false; - unsigned long flags; - - if (console_trylock()) - return 1; - - /* - * It's unsafe to spin once a panic has begun. If we are the - * panic CPU, we may have already halted the owner of the - * console_sem. If we are not the panic CPU, then we should - * avoid taking console_sem, so the panic CPU has a better - * chance of cleanly acquiring it later. - */ - if (panic_in_progress()) - return 0; - - printk_safe_enter_irqsave(flags); - - raw_spin_lock(&console_owner_lock); - owner = READ_ONCE(console_owner); - waiter = READ_ONCE(console_waiter); - if (!waiter && owner && owner != current) { - WRITE_ONCE(console_waiter, true); - spin = true; - } - raw_spin_unlock(&console_owner_lock); - - /* - * If there is an active printk() writing to the - * consoles, instead of having it write our data too, - * see if we can offload that load from the active - * printer, and do some printing ourselves. - * Go into a spin only if there isn't already a waiter - * spinning, and there is an active printer, and - * that active printer isn't us (recursive printk?). - */ - if (!spin) { - printk_safe_exit_irqrestore(flags); - return 0; - } - - /* We spin waiting for the owner to release us */ - spin_acquire(&console_owner_dep_map, 0, 0, _THIS_IP_); - /* Owner will clear console_waiter on hand off */ - while (READ_ONCE(console_waiter)) - cpu_relax(); - spin_release(&console_owner_dep_map, _THIS_IP_); - - printk_safe_exit_irqrestore(flags); - /* - * The owner passed the console lock to us. - * Since we did not spin on console lock, annotate - * this as a trylock. Otherwise lockdep will - * complain. - */ - mutex_acquire(&console_lock_dep_map, 0, 1, _THIS_IP_); - - return 1; -} - -/* - * Call the console drivers, asking them to write out - * log_buf[start] to log_buf[end - 1]. - * The console_lock must be held. - */ -static void call_console_drivers(const char *ext_text, size_t ext_len, - const char *text, size_t len) -{ - static char dropped_text[64]; - size_t dropped_len = 0; - struct console *con; - - trace_console_rcuidle(text, len); - - if (!console_drivers) - return; - - if (console_dropped) { - dropped_len = snprintf(dropped_text, sizeof(dropped_text), - "** %lu printk messages dropped **\n", - console_dropped); - console_dropped = 0; - } - - for_each_console(con) { - if (exclusive_console && con != exclusive_console) - continue; - if (!(con->flags & CON_ENABLED)) - continue; - if (!con->write) - continue; - if (!cpu_online(smp_processor_id()) && - !(con->flags & CON_ANYTIME)) - continue; - if (kernel_sync_mode()) - continue; - if (con->flags & CON_EXTENDED) - con->write(con, ext_text, ext_len); - else { - if (dropped_len) - con->write(con, dropped_text, dropped_len); - con->write(con, text, len); - } - } -} - #ifdef CONFIG_PRINTK_NMI #define NUM_RECURSION_CTX 2 #else @@ -2308,7 +2105,6 @@ asmlinkage int vprintk_emit(int facility, int level, const char *fmt, va_list args) { int printed_len; - bool in_sched = false; /* Suppress unimportant messages after panic happens */ if (unlikely(suppress_printk)) @@ -2320,33 +2116,11 @@ asmlinkage int vprintk_emit(int facility, int level, return 0; } - if (level == LOGLEVEL_SCHED) { + if (level == LOGLEVEL_SCHED) level = LOGLEVEL_DEFAULT; - in_sched = true; - } - - printk_delay(level); printed_len = vprintk_store(facility, level, dev_info, fmt, args); - /* If called from the scheduler, we can not call up(). */ - if (!in_sched) { - /* - * Disable preemption to avoid being preempted while holding - * console_sem which would prevent anyone from printing to - * console - */ - preempt_disable(); - /* - * Try to acquire and then immediately release the console - * semaphore. The release will print out buffers and wake up - * /dev/kmsg and syslog() users. - */ - if (console_trylock_spinning()) - console_unlock(); - preempt_enable(); - } - wake_up_klogd(); return printed_len; } @@ -2398,38 +2172,158 @@ asmlinkage __visible int printk(const char *fmt, ...) } EXPORT_SYMBOL(printk); -#else /* CONFIG_PRINTK */ +static int printk_kthread_func(void *data) +{ + struct console *con = data; + unsigned long dropped = 0; + char *dropped_text = NULL; + struct printk_info info; + struct printk_record r; + char *ext_text = NULL; + size_t dropped_len; + int ret = -ENOMEM; + char *text = NULL; + char *write_text; + u64 printk_seq; + size_t len; + int error; + u64 seq; + + if (con->flags & CON_EXTENDED) { + ext_text = kmalloc(CONSOLE_EXT_LOG_MAX, GFP_KERNEL); + if (!ext_text) + goto out; + } + text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL); + dropped_text = kmalloc(64, GFP_KERNEL); + if (!text || !dropped_text) + goto out; -#define printk_time false + if (con->flags & CON_EXTENDED) + write_text = ext_text; + else + write_text = text; -#define prb_read_valid(rb, seq, r) false -#define prb_first_valid_seq(rb) 0 + seq = atomic64_read(&con->printk_seq); -#define kernel_sync_mode() false + prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX); -static u64 syslog_seq; -static atomic64_t console_seq = ATOMIC64_INIT(0); -static u64 exclusive_console_stop_seq; -static unsigned long console_dropped; + for (;;) { + error = wait_event_interruptible(log_wait, + prb_read_valid(prb, seq, &r) || kthread_should_stop()); -static size_t record_print_text(const struct printk_record *r, - bool syslog, bool time) + if (kthread_should_stop()) + break; + + if (error) + continue; + + if (seq != r.info->seq) { + dropped += r.info->seq - seq; + seq = r.info->seq; + } + + seq++; + + if (!(con->flags & CON_ENABLED)) + continue; + + if (suppress_message_printing(r.info->level)) + continue; + + if (con->flags & CON_EXTENDED) { + len = info_print_ext_header(ext_text, + CONSOLE_EXT_LOG_MAX, + r.info); + len += msg_print_ext_body(ext_text + len, + CONSOLE_EXT_LOG_MAX - len, + &r.text_buf[0], r.info->text_len, + &r.info->dev_info); + } else { + len = record_print_text(&r, + console_msg_format & MSG_FORMAT_SYSLOG, + printk_time); + } + + printk_seq = atomic64_read(&con->printk_seq); + + console_lock(); + console_may_schedule = 0; + + if (kernel_sync_mode() && con->write_atomic) { + console_unlock(); + break; + } + + if (!(con->flags & CON_EXTENDED) && dropped) { + dropped_len = snprintf(dropped_text, 64, + "** %lu printk messages dropped **\n", + dropped); + dropped = 0; + + con->write(con, dropped_text, dropped_len); + printk_delay(r.info->level); + } + + con->write(con, write_text, len); + if (len) + printk_delay(r.info->level); + + atomic64_cmpxchg_relaxed(&con->printk_seq, printk_seq, seq); + + console_unlock(); + } +out: + kfree(dropped_text); + kfree(text); + kfree(ext_text); + pr_info("%sconsole [%s%d]: printing thread stopped\n", + (con->flags & CON_BOOT) ? "boot" : "", + con->name, con->index); + return ret; +} + +/* Must be called within console_lock(). */ +static void start_printk_kthread(struct console *con) { - return 0; + con->thread = kthread_run(printk_kthread_func, con, + "pr/%s%d", con->name, con->index); + if (IS_ERR(con->thread)) { + pr_err("%sconsole [%s%d]: unable to start printing thread\n", + (con->flags & CON_BOOT) ? "boot" : "", + con->name, con->index); + return; + } + pr_info("%sconsole [%s%d]: printing thread started\n", + (con->flags & CON_BOOT) ? "boot" : "", + con->name, con->index); } -static ssize_t info_print_ext_header(char *buf, size_t size, - struct printk_info *info) + +/* protected by console_lock */ +static bool kthreads_started; + +/* Must be called within console_lock(). */ +static void console_try_thread(struct console *con) { - return 0; + if (kthreads_started) { + start_printk_kthread(con); + return; + } + + /* + * The printing threads have not been started yet. If this console + * can print synchronously, print all unprinted messages. + */ + if (console_can_sync(con)) + print_sync_until(con, prb_next_seq(prb)); } -static ssize_t msg_print_ext_body(char *buf, size_t size, - char *text, size_t text_len, - struct dev_printk_info *dev_info) { return 0; } -static void console_lock_spinning_enable(void) { } -static int console_lock_spinning_disable_and_check(void) { return 0; } -static void call_console_drivers(const char *ext_text, size_t ext_len, - const char *text, size_t len) {} -static bool suppress_message_printing(int level) { return false; } + +#else /* CONFIG_PRINTK */ + +#define prb_first_valid_seq(rb) 0 +#define prb_next_seq(rb) 0 + +#define console_try_thread(con) #endif /* CONFIG_PRINTK */ @@ -2922,18 +2816,20 @@ void console_unblank(void) */ void console_flush_on_panic(enum con_flush_mode mode) { - /* - * If someone else is holding the console lock, trylock will fail - * and may_schedule may be set. Ignore and proceed to unlock so - * that messages are flushed out. As this can be called from any - * context and we don't want to get preempted while flushing, - * ensure may_schedule is cleared. - */ - console_trylock(); + struct console *c; + u64 seq; + + if (!console_trylock()) + return; + console_may_schedule = 0; - if (mode == CONSOLE_REPLAY_ALL) - atomic64_set(&console_seq, prb_first_valid_seq(prb)); + if (mode == CONSOLE_REPLAY_ALL) { + seq = prb_first_valid_seq(prb); + for_each_console(c) + atomic64_set(&c->printk_seq, seq); + } + console_unlock(); } @@ -3068,7 +2964,6 @@ static int try_enable_new_console(struct console *newcon, bool user_specified) */ void register_console(struct console *newcon) { - unsigned long flags; struct console *bcon = NULL; int err; @@ -3092,6 +2987,8 @@ void register_console(struct console *newcon) } } + newcon->thread = NULL; + if (console_drivers && console_drivers->flags & CON_BOOT) bcon = console_drivers; @@ -3156,27 +3053,12 @@ void register_console(struct console *newcon) if (newcon->flags & CON_EXTENDED) nr_ext_console_drivers++; - if (newcon->flags & CON_PRINTBUFFER) { - /* - * console_unlock(); will print out the buffered messages - * for us. - * - * We're about to replay the log buffer. Only do this to the - * just-registered console to avoid excessive message spam to - * the already-registered consoles. - * - * Set exclusive_console with disabled interrupts to reduce - * race window with eventual console_flush_on_panic() that - * ignores console_lock. - */ - exclusive_console = newcon; - exclusive_console_stop_seq = atomic64_read(&console_seq); + if (newcon->flags & CON_PRINTBUFFER) + atomic64_set(&newcon->printk_seq, 0); + else + atomic64_set(&newcon->printk_seq, prb_next_seq(prb)); - /* Get a consistent copy of @syslog_seq. */ - spin_lock_irqsave(&syslog_lock, flags); - atomic64_set(&console_seq, syslog_seq); - spin_unlock_irqrestore(&syslog_lock, flags); - } + console_try_thread(newcon); console_unlock(); console_sysfs_notify(); @@ -3250,6 +3132,9 @@ int unregister_console(struct console *console) console_unlock(); console_sysfs_notify(); + if (console->thread && !IS_ERR(console->thread)) + kthread_stop(console->thread); + if (console->exit) res = console->exit(console); @@ -3332,6 +3217,15 @@ static int __init printk_late_init(void) unregister_console(con); } } + +#ifdef CONFIG_PRINTK + console_lock(); + for_each_console(con) + start_printk_kthread(con); + kthreads_started = true; + console_unlock(); +#endif + ret = cpuhp_setup_state_nocalls(CPUHP_PRINTK_DEAD, "printk:dead", NULL, console_cpu_notify); WARN_ON(ret < 0); @@ -3347,7 +3241,6 @@ late_initcall(printk_late_init); * Delayed printk version, for scheduler-internal messages: */ #define PRINTK_PENDING_WAKEUP 0x01 -#define PRINTK_PENDING_OUTPUT 0x02 static DEFINE_PER_CPU(int, printk_pending); @@ -3355,14 +3248,8 @@ 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 (pending & PRINTK_PENDING_WAKEUP) - wake_up_interruptible(&log_wait); + wake_up_interruptible_all(&log_wait); } static DEFINE_PER_CPU(struct irq_work, wake_up_klogd_work) = { @@ -3385,13 +3272,6 @@ void wake_up_klogd(void) void defer_console_output(void) { - if (!printk_percpu_data_ready()) - return; - - preempt_disable(); - __this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT); - irq_work_queue(this_cpu_ptr(&wake_up_klogd_work)); - preempt_enable(); } int vprintk_deferred(const char *fmt, va_list args) -- Gitee From 3f10e24798353d5798e17513714db6402f593070 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 21:02:33 +0800 Subject: [PATCH 14/16] printk: remove deferred printing commit 4a2839e368c059d5580e5bafe3ecb7362d8b22b6 upstream. Since printing occurs either atomically or from the printing kthread, there is no need for any deferring or tracking possible recursion paths. Remove all printk context tracking. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- arch/arm/kernel/smp.c | 2 - arch/powerpc/kexec/crash.c | 3 -- include/linux/hardirq.h | 2 - include/linux/printk.h | 12 ----- kernel/printk/Makefile | 1 - kernel/printk/internal.h | 70 ----------------------------- kernel/printk/printk.c | 58 ++++++++++-------------- kernel/printk/printk_safe.c | 88 ------------------------------------- kernel/trace/trace.c | 2 - 9 files changed, 22 insertions(+), 216 deletions(-) delete mode 100644 kernel/printk/internal.h delete mode 100644 kernel/printk/printk_safe.c diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c index d94e39a21698..44383bfbf98b 100644 --- a/arch/arm/kernel/smp.c +++ b/arch/arm/kernel/smp.c @@ -671,9 +671,7 @@ static void do_handle_IPI(int ipinr) break; case IPI_CPU_BACKTRACE: - printk_nmi_enter(); nmi_cpu_backtrace(get_irq_regs()); - printk_nmi_exit(); break; default: diff --git a/arch/powerpc/kexec/crash.c b/arch/powerpc/kexec/crash.c index c9a889880214..d488311efab1 100644 --- a/arch/powerpc/kexec/crash.c +++ b/arch/powerpc/kexec/crash.c @@ -311,9 +311,6 @@ void default_machine_crash_shutdown(struct pt_regs *regs) unsigned int i; int (*old_handler)(struct pt_regs *regs); - /* Avoid hardlocking with irresponsive CPU holding logbuf_lock */ - printk_nmi_enter(); - /* * This function is only called after the system * has panicked or is otherwise in a critical state. diff --git a/include/linux/hardirq.h b/include/linux/hardirq.h index 754f67ac4326..c35b71f8644a 100644 --- a/include/linux/hardirq.h +++ b/include/linux/hardirq.h @@ -115,7 +115,6 @@ extern void rcu_nmi_exit(void); do { \ lockdep_off(); \ arch_nmi_enter(); \ - printk_nmi_enter(); \ BUG_ON(in_nmi() == NMI_MASK); \ __preempt_count_add(NMI_OFFSET + HARDIRQ_OFFSET); \ } while (0) @@ -134,7 +133,6 @@ extern void rcu_nmi_exit(void); do { \ BUG_ON(!in_nmi()); \ __preempt_count_sub(NMI_OFFSET + HARDIRQ_OFFSET); \ - printk_nmi_exit(); \ arch_nmi_exit(); \ lockdep_on(); \ } while (0) diff --git a/include/linux/printk.h b/include/linux/printk.h index 1ebd93581acc..153212445b68 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -155,18 +155,6 @@ static inline __printf(1, 2) __cold void early_printk(const char *s, ...) { } #endif -#ifdef CONFIG_PRINTK_NMI -extern void printk_nmi_enter(void); -extern void printk_nmi_exit(void); -extern void printk_nmi_direct_enter(void); -extern void printk_nmi_direct_exit(void); -#else -static inline void printk_nmi_enter(void) { } -static inline void printk_nmi_exit(void) { } -static inline void printk_nmi_direct_enter(void) { } -static inline void printk_nmi_direct_exit(void) { } -#endif /* PRINTK_NMI */ - struct dev_printk_info; #ifdef CONFIG_PRINTK diff --git a/kernel/printk/Makefile b/kernel/printk/Makefile index eee3dc9b60a9..59cb24e25f00 100644 --- a/kernel/printk/Makefile +++ b/kernel/printk/Makefile @@ -1,5 +1,4 @@ # SPDX-License-Identifier: GPL-2.0-only obj-y = printk.o -obj-$(CONFIG_PRINTK) += printk_safe.o obj-$(CONFIG_A11Y_BRAILLE_CONSOLE) += braille.o obj-$(CONFIG_PRINTK) += printk_ringbuffer.o diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h deleted file mode 100644 index e108b2ece8c7..000000000000 --- a/kernel/printk/internal.h +++ /dev/null @@ -1,70 +0,0 @@ -/* SPDX-License-Identifier: GPL-2.0-or-later */ -/* - * internal.h - printk internal definitions - */ -#include - -#ifdef CONFIG_PRINTK - -#define PRINTK_SAFE_CONTEXT_MASK 0x007ffffff -#define PRINTK_NMI_DIRECT_CONTEXT_MASK 0x008000000 -#define PRINTK_NMI_CONTEXT_MASK 0xff0000000 - -#define PRINTK_NMI_CONTEXT_OFFSET 0x010000000 - -__printf(4, 0) -int vprintk_store(int facility, int level, - const struct dev_printk_info *dev_info, - const char *fmt, va_list args); - -__printf(1, 0) int vprintk_default(const char *fmt, va_list args); -__printf(1, 0) int vprintk_deferred(const char *fmt, va_list args); -__printf(1, 0) int vprintk_func(const char *fmt, va_list args); -void __printk_safe_enter(void); -void __printk_safe_exit(void); - -bool printk_percpu_data_ready(void); - -#define printk_safe_enter_irqsave(flags) \ - do { \ - local_irq_save(flags); \ - __printk_safe_enter(); \ - } while (0) - -#define printk_safe_exit_irqrestore(flags) \ - do { \ - __printk_safe_exit(); \ - local_irq_restore(flags); \ - } while (0) - -#define printk_safe_enter_irq() \ - do { \ - local_irq_disable(); \ - __printk_safe_enter(); \ - } while (0) - -#define printk_safe_exit_irq() \ - do { \ - __printk_safe_exit(); \ - local_irq_enable(); \ - } while (0) - -void defer_console_output(void); - -#else - -__printf(1, 0) int vprintk_func(const char *fmt, va_list args) { return 0; } - -/* - * In !PRINTK builds we still export console_sem - * semaphore and some of console functions (console_unlock()/etc.), so - * printk-safe must preserve the existing local IRQ guarantees. - */ -#define printk_safe_enter_irqsave(flags) local_irq_save(flags) -#define printk_safe_exit_irqrestore(flags) local_irq_restore(flags) - -#define printk_safe_enter_irq() local_irq_disable() -#define printk_safe_exit_irq() local_irq_enable() - -static inline bool printk_percpu_data_ready(void) { return false; } -#endif /* CONFIG_PRINTK */ diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index a5a40b8cdba2..3f81c4ae658c 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -45,6 +45,7 @@ #include #include #include +#include #include #include #include @@ -60,7 +61,6 @@ #include "printk_ringbuffer.h" #include "console_cmdline.h" #include "braille.h" -#include "internal.h" int console_printk[4] = { CONSOLE_LOGLEVEL_DEFAULT, /* console_loglevel */ @@ -235,19 +235,7 @@ static int nr_ext_console_drivers; static int __down_trylock_console_sem(unsigned long ip) { - int lock_failed; - unsigned long flags; - - /* - * Here and in __up_console_sem() we need to be in safe mode, - * because spindump/WARN/etc from under console ->lock will - * deadlock in printk()->down_trylock_console_sem() otherwise. - */ - printk_safe_enter_irqsave(flags); - lock_failed = down_trylock(&console_sem); - printk_safe_exit_irqrestore(flags); - - if (lock_failed) + if (down_trylock(&console_sem)) return 1; mutex_acquire(&console_lock_dep_map, 0, 1, ip); return 0; @@ -256,13 +244,9 @@ static int __down_trylock_console_sem(unsigned long ip) static void __up_console_sem(unsigned long ip) { - unsigned long flags; - mutex_release(&console_lock_dep_map, ip); - printk_safe_enter_irqsave(flags); up(&console_sem); - printk_safe_exit_irqrestore(flags); } #define up_console_sem() __up_console_sem(_RET_IP_) @@ -439,7 +423,7 @@ static struct printk_ringbuffer *prb = &printk_rb_static; */ static bool __printk_percpu_data_ready __read_mostly; -bool printk_percpu_data_ready(void) +static bool printk_percpu_data_ready(void) { return __printk_percpu_data_ready; } @@ -1074,7 +1058,6 @@ void __init setup_log_buf(int early) struct printk_record r; size_t new_descs_size; size_t new_infos_size; - unsigned long flags; char *new_log_buf; unsigned int free; u64 seq; @@ -1972,9 +1955,9 @@ static u16 printk_sprint(char *text, u16 size, int facility, enum log_flags *lfl } __printf(4, 0) -int vprintk_store(int facility, int level, - const struct dev_printk_info *dev_info, - const char *fmt, va_list args) +static int vprintk_store(int facility, int level, + const struct dev_printk_info *dev_info, + const char *fmt, va_list args) { const u32 caller_id = printk_caller_id(); struct prb_reserved_entry e; @@ -2126,11 +2109,22 @@ asmlinkage int vprintk_emit(int facility, int level, } EXPORT_SYMBOL(vprintk_emit); -int vprintk_default(const char *fmt, va_list args) +__printf(1, 0) +static int vprintk_default(const char *fmt, va_list args) { return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, fmt, args); } -EXPORT_SYMBOL_GPL(vprintk_default); + +__printf(1, 0) +static int vprintk_func(const char *fmt, va_list args) +{ +#ifdef CONFIG_KGDB_KDB + /* Allow to pass printk() to kdb but avoid a recursion. */ + if (unlikely(kdb_trap_printk && kdb_printf_cpu < 0)) + return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args); +#endif + return vprintk_default(fmt, args); +} asmlinkage int vprintk(const char *fmt, va_list args) { @@ -3270,18 +3264,10 @@ void wake_up_klogd(void) preempt_enable(); } -void defer_console_output(void) -{ -} - -int vprintk_deferred(const char *fmt, va_list args) +__printf(1, 0) +static int vprintk_deferred(const char *fmt, va_list args) { - int r; - - r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, fmt, args); - defer_console_output(); - - return r; + return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, fmt, args); } int printk_deferred(const char *fmt, ...) diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c deleted file mode 100644 index c23b127a6545..000000000000 --- a/kernel/printk/printk_safe.c +++ /dev/null @@ -1,88 +0,0 @@ -// SPDX-License-Identifier: GPL-2.0-or-later -/* - * printk_safe.c - Safe printk for printk-deadlock-prone contexts - */ - -#include -#include -#include -#include -#include -#include -#include -#include -#include - -#include "internal.h" - -static DEFINE_PER_CPU(int, printk_context); - -#ifdef CONFIG_PRINTK_NMI -void noinstr printk_nmi_enter(void) -{ - this_cpu_add(printk_context, PRINTK_NMI_CONTEXT_OFFSET); -} - -void noinstr printk_nmi_exit(void) -{ - this_cpu_sub(printk_context, PRINTK_NMI_CONTEXT_OFFSET); -} - -/* - * Marks a code that might produce many messages in NMI context - * and the risk of losing them is more critical than eventual - * reordering. - */ -void printk_nmi_direct_enter(void) -{ - if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK) - this_cpu_or(printk_context, PRINTK_NMI_DIRECT_CONTEXT_MASK); -} - -void printk_nmi_direct_exit(void) -{ - this_cpu_and(printk_context, ~PRINTK_NMI_DIRECT_CONTEXT_MASK); -} - -#endif /* CONFIG_PRINTK_NMI */ - -/* Can be preempted by NMI. */ -void __printk_safe_enter(void) -{ - this_cpu_inc(printk_context); -} - -/* Can be preempted by NMI. */ -void __printk_safe_exit(void) -{ - this_cpu_dec(printk_context); -} - -__printf(1, 0) int vprintk_func(const char *fmt, va_list args) -{ -#ifdef CONFIG_KGDB_KDB - /* Allow to pass printk() to kdb but avoid a recursion. */ - if (unlikely(kdb_trap_printk && kdb_printf_cpu < 0)) - return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args); -#endif - - /* - * Use the main logbuf even in NMI. But avoid calling console - * drivers that might have their own locks. - */ - if (this_cpu_read(printk_context) & - (PRINTK_NMI_DIRECT_CONTEXT_MASK | - PRINTK_NMI_CONTEXT_MASK | - PRINTK_SAFE_CONTEXT_MASK)) { - int len; - - printk_safe_enter_irqsave(flags); - len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args); - printk_safe_exit_irqrestore(flags); - defer_console_output(); - return len; - } - - /* No obstacles. */ - return vprintk_default(fmt, args); -} diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 00e055d374e4..6827f72c8179 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -9399,7 +9399,6 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) tracing_off(); local_irq_save(flags); - printk_nmi_direct_enter(); /* Simulate the iterator */ trace_init_global_iter(&iter); @@ -9479,7 +9478,6 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) atomic_dec(&per_cpu_ptr(iter.array_buffer->data, cpu)->disabled); } atomic_dec(&dump_running); - printk_nmi_direct_exit(); local_irq_restore(flags); } EXPORT_SYMBOL_GPL(ftrace_dump); -- Gitee From 77b5d0f31d57e2007b629400f6f752f82850f2cb Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 21:02:42 +0800 Subject: [PATCH 15/16] printk: add console handover commit 7fc9ccf1b9b1051d1e691db02cecc137bbc4983c upstream. If earlyprintk is used, a boot console will print directly to the console immediately. The boot console will unregister itself as soon as a non-boot console registers. However, the non-boot console does not begin printing until its kthread has started. Since this happens much later, there is a long pause in the console output. If the ringbuffer is small, messages could even be dropped during the pause. Add a new CON_HANDOVER console flag to be used internally by printk in order to track which non-boot console took over from a boot console. If handover consoles have implemented write_atomic(), they are allowed to print directly to the console until their kthread can take over. Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- include/linux/console.h | 1 + kernel/printk/printk.c | 8 +++++++- 2 files changed, 8 insertions(+), 1 deletion(-) diff --git a/include/linux/console.h b/include/linux/console.h index 3e99359e0660..027278792eea 100644 --- a/include/linux/console.h +++ b/include/linux/console.h @@ -138,6 +138,7 @@ static inline int con_debug_leave(void) #define CON_ANYTIME (16) /* Safe to call when cpu is offline */ #define CON_BRL (32) /* Used for a braille device */ #define CON_EXTENDED (64) /* Use the extended output format a la /dev/kmsg */ +#define CON_HANDOVER (128) /* Device was previously a boot console. */ struct console { char name[16]; diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 3f81c4ae658c..1ab5a5a6a463 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -1740,6 +1740,8 @@ static bool console_can_sync(struct console *con) return false; if (con->write_atomic && kernel_sync_mode()) return true; + if (con->write_atomic && (con->flags & CON_HANDOVER) && !con->thread) + return true; if (con->write && (con->flags & CON_BOOT) && !con->thread) return true; return false; @@ -1751,6 +1753,8 @@ static bool call_sync_console_driver(struct console *con, const char *text, size return false; if (con->write_atomic && kernel_sync_mode()) con->write_atomic(con, text, text_len); + else if (con->write_atomic && (con->flags & CON_HANDOVER) && !con->thread) + con->write_atomic(con, text, text_len); else if (con->write && (con->flags & CON_BOOT) && !con->thread) con->write(con, text, text_len); else @@ -3024,8 +3028,10 @@ void register_console(struct console *newcon) * the real console are the same physical device, it's annoying to * see the beginning boot messages twice */ - if (bcon && ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV)) + if (bcon && ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV)) { newcon->flags &= ~CON_PRINTBUFFER; + newcon->flags |= CON_HANDOVER; + } /* * Put this console in the list - keep the -- Gitee From 2d33ebf6388121a3b86ed76ae7b3b55ce714d711 Mon Sep 17 00:00:00 2001 From: meganz009 Date: Sat, 3 Jun 2023 21:07:44 +0800 Subject: [PATCH 16/16] printk: add pr_flush() commit 52608e0a85a3d0d5b7f92648a41c21cba443778b upstream. Provide a function to allow waiting for console printers to catch up to the latest logged message. Use pr_flush() to give console printers a chance to finish in critical situations if no atomic console is available. For now pr_flush() is only used in the most common error paths: panic(), print_oops_end_marker(), report_bug(), kmsg_dump(). Signed-off-by: John Ogness Signed-off-by: Sebastian Andrzej Siewior --- include/linux/printk.h | 2 ++ kernel/panic.c | 28 +++++++++------ kernel/printk/printk.c | 79 ++++++++++++++++++++++++++++++++++++++++++ lib/bug.c | 1 + 4 files changed, 99 insertions(+), 11 deletions(-) diff --git a/include/linux/printk.h b/include/linux/printk.h index 153212445b68..7e4352467d83 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -481,6 +481,8 @@ extern int kptr_restrict; no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__) #endif +bool pr_flush(int timeout_ms, bool reset_on_progress); + /* * ratelimited messages with local ratelimit_state, * no local ratelimit_state used in the !PRINTK case diff --git a/kernel/panic.c b/kernel/panic.c index c8cf92c95bb0..1198b962402f 100644 --- a/kernel/panic.c +++ b/kernel/panic.c @@ -180,12 +180,28 @@ static void panic_print_sys_info(void) void panic(const char *fmt, ...) { static char buf[1024]; + va_list args2; va_list args; long i, i_next = 0, len; int state = 0; int old_cpu, this_cpu; bool _crash_kexec_post_notifiers = crash_kexec_post_notifiers; + console_verbose(); + pr_emerg("Kernel panic - not syncing:\n"); + va_start(args2, fmt); + va_copy(args, args2); + vprintk(fmt, args2); + va_end(args2); +#ifdef CONFIG_DEBUG_BUGVERBOSE + /* + * Avoid nested stack-dumping if a panic occurs during oops processing + */ + if (!test_taint(TAINT_DIE) && oops_in_progress <= 1) + dump_stack(); +#endif + pr_flush(1000, true); + /* * Disable local interrupts. This will prevent panic_smp_self_stop * from deadlocking the first cpu that invokes the panic, since @@ -216,26 +232,15 @@ void panic(const char *fmt, ...) if (old_cpu != PANIC_CPU_INVALID && old_cpu != this_cpu) panic_smp_self_stop(); - console_verbose(); bust_spinlocks(1); report_fault_event(smp_processor_id(), current, FATAL_FAULT, FE_PANIC, NULL); - va_start(args, fmt); len = vscnprintf(buf, sizeof(buf), fmt, args); va_end(args); if (len && buf[len - 1] == '\n') buf[len - 1] = '\0'; - pr_emerg("Kernel panic - not syncing: %s\n", buf); -#ifdef CONFIG_DEBUG_BUGVERBOSE - /* - * Avoid nested stack-dumping if a panic occurs during oops processing - */ - if (!test_taint(TAINT_DIE) && oops_in_progress <= 1) - dump_stack(); -#endif - /* * If kgdb is enabled, give it a chance to run before we stop all * the other CPUs or else we won't be able to debug processes left @@ -557,6 +562,7 @@ static void print_oops_end_marker(void) { init_oops_id(); pr_warn("---[ end trace %016llx ]---\n", (unsigned long long)oops_id); + pr_flush(1000, true); } /* diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 1ab5a5a6a463..43595c1a9f9c 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -3425,6 +3425,12 @@ void kmsg_dump(enum kmsg_dump_reason reason) sync_mode = true; pr_info("enabled sync mode\n"); } + + /* + * Give the printing threads time to flush, allowing up to + * 1s of no printing forward progress before giving up. + */ + pr_flush(1000, true); } rcu_read_lock(); @@ -3704,3 +3710,76 @@ void console_atomic_unlock(unsigned int flags) prb_unlock(&printk_cpulock, flags); } EXPORT_SYMBOL(console_atomic_unlock); + +static void pr_msleep(bool may_sleep, int ms) +{ + if (may_sleep) { + msleep(ms); + } else { + while (ms--) + udelay(1000); + } +} + +/** + * pr_flush() - Wait for printing threads to catch up. + * + * @timeout_ms: The maximum time (in ms) to wait. + * @reset_on_progress: Reset the timeout if forward progress is seen. + * + * A value of 0 for @timeout_ms means no waiting will occur. A value of -1 + * represents infinite waiting. + * + * If @reset_on_progress is true, the timeout will be reset whenever any + * printer has been seen to make some forward progress. + * + * Context: Any context. + * Return: true if all enabled printers are caught up. + */ +bool pr_flush(int timeout_ms, bool reset_on_progress) +{ + int remaining = timeout_ms; + struct console *con; + u64 last_diff = 0; + bool may_sleep; + u64 printk_seq; + u64 diff; + u64 seq; + + may_sleep = (preemptible() && !in_softirq()); + + seq = prb_next_seq(prb); + + for (;;) { + diff = 0; + + for_each_console(con) { + if (!(con->flags & CON_ENABLED)) + continue; + printk_seq = atomic64_read(&con->printk_seq); + if (printk_seq < seq) + diff += seq - printk_seq; + } + + if (diff != last_diff && reset_on_progress) + remaining = timeout_ms; + + if (!diff || remaining == 0) + break; + + if (remaining < 0) { + pr_msleep(may_sleep, 100); + } else if (remaining < 100) { + pr_msleep(may_sleep, remaining); + remaining = 0; + } else { + pr_msleep(may_sleep, 100); + remaining -= 100; + } + + last_diff = diff; + } + + return (diff == 0); +} +EXPORT_SYMBOL(pr_flush); diff --git a/lib/bug.c b/lib/bug.c index 4ab398a2de93..9c681f29e61e 100644 --- a/lib/bug.c +++ b/lib/bug.c @@ -202,6 +202,7 @@ enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs) else pr_crit("Kernel BUG at %pB [verbose debug info unavailable]\n", (void *)bugaddr); + pr_flush(1000, true); return BUG_TRAP_TYPE_BUG; } -- Gitee