Subject: printk: remove deferred printing From: John Ogness <john.ogness@linutronix.de> Date: Mon Nov 30 01:42:08 2020 +0106 From: John Ogness <john.ogness@linutronix.de> 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 defer functions and context tracking. Signed-off-by: John Ogness <john.ogness@linutronix.de> Signed-off-by: Thomas Gleixner <tglx@linutronix.de> --- arch/arm/kernel/smp.c | 2 - arch/powerpc/kexec/crash.c | 3 - arch/x86/kernel/dumpstack_32.c | 2 - arch/x86/kernel/dumpstack_64.c | 3 + arch/x86/kernel/i8259.c | 3 - arch/x86/kernel/unwind_frame.c | 16 +++----- arch/x86/kernel/unwind_orc.c | 2 - drivers/char/random.c | 5 +- include/linux/printk.h | 34 ------------------ include/linux/suspend.h | 10 +---- kernel/power/main.c | 10 +---- kernel/printk/Makefile | 1 kernel/printk/internal.h | 36 ------------------- kernel/printk/printk.c | 74 +++++++++++++--------------------------- kernel/printk/printk_safe.c | 52 ---------------------------- kernel/sched/core.c | 9 ++-- kernel/sched/deadline.c | 2 - kernel/sched/fair.c | 5 -- kernel/sched/psi.c | 14 +++---- kernel/sched/rt.c | 2 - kernel/time/clockevents.c | 9 +--- kernel/time/ntp.c | 14 ++----- kernel/time/timekeeping.c | 30 ++++++++-------- kernel/time/timekeeping_debug.c | 2 - kernel/workqueue.c | 4 -- lib/ratelimit.c | 4 -- 26 files changed, 83 insertions(+), 265 deletions(-) delete mode 100644 kernel/printk/internal.h delete mode 100644 kernel/printk/printk_safe.c --- @ arch/arm/kernel/smp.c:670 @ static void do_handle_IPI(int ipinr) break; case IPI_CPU_BACKTRACE: - printk_deferred_enter(); nmi_cpu_backtrace(get_irq_regs()); - printk_deferred_exit(); break; default: --- a/arch/powerpc/kexec/crash.c +++ b/arch/powerpc/kexec/crash.c @ arch/arm/kernel/smp.c:315 @ void default_machine_crash_shutdown(stru unsigned int i; int (*old_handler)(struct pt_regs *regs); - /* Avoid hardlocking with irresponsive CPU holding logbuf_lock */ - printk_deferred_enter(); - /* * This function is only called after the system * has panicked or is otherwise in a critical state. --- a/arch/x86/kernel/dumpstack_32.c +++ b/arch/x86/kernel/dumpstack_32.c @ arch/arm/kernel/smp.c:144 @ int get_stack_info(unsigned long *stack, */ if (visit_mask) { if (*visit_mask & (1UL << info->type)) { - printk_deferred_once(KERN_WARNING "WARNING: stack recursion on stack type %d\n", info->type); + pr_warn_once("WARNING: stack recursion on stack type %d\n", info->type); goto unknown; } *visit_mask |= 1UL << info->type; --- a/arch/x86/kernel/dumpstack_64.c +++ b/arch/x86/kernel/dumpstack_64.c @ arch/arm/kernel/smp.c:204 @ int get_stack_info(unsigned long *stack, if (visit_mask) { if (*visit_mask & (1UL << info->type)) { if (task == current) - printk_deferred_once(KERN_WARNING "WARNING: stack recursion on stack type %d\n", info->type); + pr_warn_once("WARNING: stack recursion on stack type %d\n", + info->type); goto unknown; } *visit_mask |= 1UL << info->type; --- a/arch/x86/kernel/i8259.c +++ b/arch/x86/kernel/i8259.c @ arch/arm/kernel/smp.c:210 @ static void mask_and_ack_8259A(struct ir * lets ACK and report it. [once per IRQ] */ if (!(spurious_irq_mask & irqmask)) { - printk_deferred(KERN_DEBUG - "spurious 8259A interrupt: IRQ%d.\n", irq); + printk(KERN_DEBUG "spurious 8259A interrupt: IRQ%d.\n", irq); spurious_irq_mask |= irqmask; } atomic_inc(&irq_err_count); --- a/arch/x86/kernel/unwind_frame.c +++ b/arch/x86/kernel/unwind_frame.c @ arch/arm/kernel/smp.c:44 @ static void unwind_dump(struct unwind_st dumped_before = true; - printk_deferred("unwind stack type:%d next_sp:%p mask:0x%lx graph_idx:%d\n", - state->stack_info.type, state->stack_info.next_sp, - state->stack_mask, state->graph_idx); + printk("unwind stack type:%d next_sp:%p mask:0x%lx graph_idx:%d\n", + state->stack_info.type, state->stack_info.next_sp, + state->stack_mask, state->graph_idx); for (sp = PTR_ALIGN(state->orig_sp, sizeof(long)); sp; sp = PTR_ALIGN(stack_info.next_sp, sizeof(long))) { @ arch/arm/kernel/smp.c:62 @ static void unwind_dump(struct unwind_st if (zero) { if (!prev_zero) - printk_deferred("%p: %0*x ...\n", - sp, BITS_PER_LONG/4, 0); + printk("%p: %0*x ...\n", sp, BITS_PER_LONG/4, 0); continue; } - printk_deferred("%p: %0*lx (%pB)\n", - sp, BITS_PER_LONG/4, word, (void *)word); + printk("%p: %0*lx (%pB)\n", sp, BITS_PER_LONG/4, word, (void *)word); } } } @ arch/arm/kernel/smp.c:343 @ bool unwind_next_frame(struct unwind_sta goto the_end; if (state->regs) { - printk_deferred_once(KERN_WARNING + pr_warn_once( "WARNING: kernel stack regs at %p in %s:%d has bad 'bp' value %p\n", state->regs, state->task->comm, state->task->pid, next_bp); unwind_dump(state); } else { - printk_deferred_once(KERN_WARNING + pr_warn_once( "WARNING: kernel stack frame pointer at %p in %s:%d has bad value %p\n", state->bp, state->task->comm, state->task->pid, next_bp); --- a/arch/x86/kernel/unwind_orc.c +++ b/arch/x86/kernel/unwind_orc.c @ arch/arm/kernel/smp.c:12 @ #include <asm/orc_lookup.h> #define orc_warn(fmt, ...) \ - printk_deferred_once(KERN_WARNING "WARNING: " fmt, ##__VA_ARGS__) + pr_warn_once("WARNING: " fmt, ##__VA_ARGS__) #define orc_warn_current(args...) \ ({ \ --- a/drivers/char/random.c +++ b/drivers/char/random.c @ arch/arm/kernel/smp.c:1510 @ static void _warn_unseeded_randomness(co print_once = true; #endif if (__ratelimit(&unseeded_warning)) - printk_deferred(KERN_NOTICE "random: %s called from %pS " - "with crng_init=%d\n", func_name, caller, - crng_init); + pr_notice("random: %s called from %pS with crng_init=%d\n", + func_name, caller, crng_init); } /* --- a/include/linux/printk.h +++ b/include/linux/printk.h @ arch/arm/kernel/smp.c:165 @ asmlinkage __printf(1, 2) __cold int _printk(const char *fmt, ...); /* - * Special printk facility for scheduler/timekeeping use only, _DO_NOT_USE_ ! - */ -__printf(1, 2) __cold int _printk_deferred(const char *fmt, ...); - -extern void __printk_safe_enter(void); -extern void __printk_safe_exit(void); -/* - * The printk_deferred_enter/exit macros are available only as a hack for - * some code paths that need to defer all printk console printing. Interrupts - * must be disabled for the deferred duration. - */ -#define printk_deferred_enter __printk_safe_enter -#define printk_deferred_exit __printk_safe_exit - -/* * Please don't use printk_ratelimit(), because it shares ratelimiting state * with all other unrelated printk_ratelimit() callsites. Instead use * printk_ratelimited() or plain old __ratelimit(). @ arch/arm/kernel/smp.c:203 @ int _printk(const char *s, ...) { return 0; } -static inline __printf(1, 2) __cold -int _printk_deferred(const char *s, ...) -{ - return 0; -} - -static inline void printk_deferred_enter(void) -{ -} - -static inline void printk_deferred_exit(void) -{ -} static inline int printk_ratelimit(void) { @ arch/arm/kernel/smp.c:446 @ struct pi_entry { * See the vsnprintf() documentation for format string extensions over C99. */ #define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__) -#define printk_deferred(fmt, ...) \ - printk_index_wrap(_printk_deferred, fmt, ##__VA_ARGS__) /** * pr_emerg - Print an emergency-level message @ arch/arm/kernel/smp.c:583 @ struct pi_entry { #ifdef CONFIG_PRINTK #define printk_once(fmt, ...) \ DO_ONCE_LITE(printk, fmt, ##__VA_ARGS__) -#define printk_deferred_once(fmt, ...) \ - DO_ONCE_LITE(printk_deferred, fmt, ##__VA_ARGS__) #else #define printk_once(fmt, ...) \ no_printk(fmt, ##__VA_ARGS__) -#define printk_deferred_once(fmt, ...) \ - no_printk(fmt, ##__VA_ARGS__) #endif #define pr_emerg_once(fmt, ...) \ --- a/include/linux/suspend.h +++ b/include/linux/suspend.h @ arch/arm/kernel/smp.c:553 @ static inline void unlock_system_sleep(v #ifdef CONFIG_PM_SLEEP_DEBUG extern bool pm_print_times_enabled; extern bool pm_debug_messages_on; -extern __printf(2, 3) void __pm_pr_dbg(bool defer, const char *fmt, ...); +extern __printf(1, 2) void pm_pr_dbg(const char *fmt, ...); #else #define pm_print_times_enabled (false) #define pm_debug_messages_on (false) #include <linux/printk.h> -#define __pm_pr_dbg(defer, fmt, ...) \ +#define pm_pr_dbg(fmt, ...) \ no_printk(KERN_DEBUG fmt, ##__VA_ARGS__) #endif -#define pm_pr_dbg(fmt, ...) \ - __pm_pr_dbg(false, fmt, ##__VA_ARGS__) - -#define pm_deferred_pr_dbg(fmt, ...) \ - __pm_pr_dbg(true, fmt, ##__VA_ARGS__) - #ifdef CONFIG_PM_AUTOSLEEP /* kernel/power/autosleep.c */ --- a/kernel/power/main.c +++ b/kernel/power/main.c @ arch/arm/kernel/smp.c:546 @ static int __init pm_debug_messages_setu __setup("pm_debug_messages", pm_debug_messages_setup); /** - * __pm_pr_dbg - Print a suspend debug message to the kernel log. - * @defer: Whether or not to use printk_deferred() to print the message. + * pm_pr_dbg - Print a suspend debug message to the kernel log. * @fmt: Message format. * * The message will be emitted if enabled through the pm_debug_messages * sysfs attribute. */ -void __pm_pr_dbg(bool defer, const char *fmt, ...) +void pm_pr_dbg(const char *fmt, ...) { struct va_format vaf; va_list args; @ arch/arm/kernel/smp.c:565 @ void __pm_pr_dbg(bool defer, const char vaf.fmt = fmt; vaf.va = &args; - if (defer) - printk_deferred(KERN_DEBUG "PM: %pV", &vaf); - else - printk(KERN_DEBUG "PM: %pV", &vaf); + printk(KERN_DEBUG "PM: %pV", &vaf); va_end(args); } --- a/kernel/printk/Makefile +++ b/kernel/printk/Makefile @ arch/arm/kernel/smp.c:2 @ # 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 obj-$(CONFIG_PRINTK_INDEX) += index.o --- a/kernel/printk/internal.h +++ b/kernel/printk/internal.h @ arch/arm/kernel/smp.c:5 @ /* * internal.h - printk internal definitions */ -#include <linux/percpu.h> #ifdef CONFIG_PRINTK @ arch/arm/kernel/smp.c:14 @ enum printk_info_flags { LOG_CONT = 8, /* text is a fragment of a continuation line */ }; -__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); - -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) - -void defer_console_output(void); - u16 printk_parse_prefix(const char *text, int *level, enum printk_info_flags *flags); -#else - -/* - * 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) - -static inline bool printk_percpu_data_ready(void) { return false; } #endif /* CONFIG_PRINTK */ --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @ arch/arm/kernel/smp.c:47 @ #include <linux/irq_work.h> #include <linux/ctype.h> #include <linux/uio.h> +#include <linux/kdb.h> #include <linux/kgdb.h> #include <linux/kthread.h> #include <linux/clocksource.h> @ arch/arm/kernel/smp.c:232 @ 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; @ arch/arm/kernel/smp.c:241 @ static int __down_trylock_console_sem(un 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_) @ arch/arm/kernel/smp.c:405 @ static struct printk_ringbuffer *prb = & */ 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; } @ arch/arm/kernel/smp.c:2011 @ static u16 printk_sprint(char *text, u16 } __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; @ arch/arm/kernel/smp.c:2159 @ asmlinkage int vprintk_emit(int facility } 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) +{ + return vprintk_func(fmt, args); +} +EXPORT_SYMBOL(vprintk); asmlinkage __visible int _printk(const char *fmt, ...) { @ arch/arm/kernel/smp.c:3141 @ void wake_up_klogd(void) preempt_enable(); } -void defer_console_output(void) -{ -} - -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; -} - -int _printk_deferred(const char *fmt, ...) -{ - va_list args; - int r; - - va_start(args, fmt); - r = vprintk_deferred(fmt, args); - va_end(args); - - return r; -} - /* * printk rate limiting, lifted from the networking subsystem. * --- a/kernel/printk/printk_safe.c +++ /dev/null @ arch/arm/kernel/smp.c:1 @ -// SPDX-License-Identifier: GPL-2.0-or-later -/* - * printk_safe.c - Safe printk for printk-deadlock-prone contexts - */ - -#include <linux/preempt.h> -#include <linux/kdb.h> -#include <linux/smp.h> -#include <linux/cpumask.h> -#include <linux/printk.h> -#include <linux/kprobes.h> - -#include "internal.h" - -static DEFINE_PER_CPU(int, printk_context); - -/* 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); -} - -asmlinkage int vprintk(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) || in_nmi()) { - int len; - - len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args); - defer_console_output(); - return len; - } - - /* No obstacles. */ - return vprintk_default(fmt, args); -} -EXPORT_SYMBOL(vprintk); --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @ arch/arm/kernel/smp.c:2947 @ void force_compatible_cpus_allowed_ptr(s out_set_mask: if (printk_ratelimit()) { - printk_deferred("Overriding affinity for process %d (%s) to CPUs %*pbl\n", - task_pid_nr(p), p->comm, - cpumask_pr_args(override_mask)); + printk("Overriding affinity for process %d (%s) to CPUs %*pbl\n", + task_pid_nr(p), p->comm, cpumask_pr_args(override_mask)); } WARN_ON(set_cpus_allowed_ptr(p, override_mask)); @ arch/arm/kernel/smp.c:3378 @ static int select_fallback_rq(int cpu, s * leave kernel. */ if (p->mm && printk_ratelimit()) { - printk_deferred("process %d (%s) no longer affine to cpu%d\n", - task_pid_nr(p), p->comm, cpu); + printk("process %d (%s) no longer affine to cpu%d\n", + task_pid_nr(p), p->comm, cpu); } } --- a/kernel/sched/deadline.c +++ b/kernel/sched/deadline.c @ arch/arm/kernel/smp.c:803 @ static void replenish_dl_entity(struct s * entity. */ if (dl_time_before(dl_se->deadline, rq_clock(rq))) { - printk_deferred_once("sched: DL replenish lagged too much\n"); + printk_once("sched: DL replenish lagged too much\n"); dl_se->deadline = rq_clock(rq) + pi_of(dl_se)->dl_deadline; dl_se->runtime = pi_of(dl_se)->dl_runtime; } --- a/kernel/sched/fair.c +++ b/kernel/sched/fair.c @ arch/arm/kernel/smp.c:4240 @ static inline void check_schedstat_requi trace_sched_stat_iowait_enabled() || trace_sched_stat_blocked_enabled() || trace_sched_stat_runtime_enabled()) { - printk_deferred_once("Scheduler tracepoints stat_sleep, stat_iowait, " - "stat_blocked and stat_runtime require the " - "kernel parameter schedstats=enable or " - "kernel.sched_schedstats=1\n"); + printk_once("Scheduler tracepoints stat_sleep, stat_iowait, stat_blocked and stat_runtime require the kernel parameter schedstats=enable or kernel.sched_schedstats=1\n"); } #endif } --- a/kernel/sched/psi.c +++ b/kernel/sched/psi.c @ arch/arm/kernel/smp.c:713 @ static void psi_group_change(struct psi_ if (groupc->tasks[t]) { groupc->tasks[t]--; } else if (!psi_bug) { - printk_deferred(KERN_ERR "psi: task underflow! cpu=%d t=%d tasks=[%u %u %u %u] clear=%x set=%x\n", - cpu, t, groupc->tasks[0], - groupc->tasks[1], groupc->tasks[2], - groupc->tasks[3], clear, set); + pr_err("psi: task underflow! cpu=%d t=%d tasks=[%u %u %u %u] clear=%x set=%x\n", + cpu, t, groupc->tasks[0], + groupc->tasks[1], groupc->tasks[2], + groupc->tasks[3], clear, set); psi_bug = 1; } } @ arch/arm/kernel/smp.c:782 @ static void psi_flags_change(struct task if (((task->psi_flags & set) || (task->psi_flags & clear) != clear) && !psi_bug) { - printk_deferred(KERN_ERR "psi: inconsistent task state! task=%d:%s cpu=%d psi_flags=%x clear=%x set=%x\n", - task->pid, task->comm, task_cpu(task), - task->psi_flags, clear, set); + pr_err("psi: inconsistent task state! task=%d:%s cpu=%d psi_flags=%x clear=%x set=%x\n", + task->pid, task->comm, task_cpu(task), + task->psi_flags, clear, set); psi_bug = 1; } --- a/kernel/sched/rt.c +++ b/kernel/sched/rt.c @ arch/arm/kernel/smp.c:974 @ static int sched_rt_runtime_exceeded(str */ if (likely(rt_b->rt_runtime)) { rt_rq->rt_throttled = 1; - printk_deferred_once("sched: RT throttling activated\n"); + printk_once("sched: RT throttling activated\n"); } else { /* * In case we did anyway, make it go away, --- a/kernel/time/clockevents.c +++ b/kernel/time/clockevents.c @ arch/arm/kernel/smp.c:206 @ static int clockevents_increase_min_delt { /* Nothing to do if we already reached the limit */ if (dev->min_delta_ns >= MIN_DELTA_LIMIT) { - printk_deferred(KERN_WARNING - "CE: Reprogramming failure. Giving up\n"); + pr_warn("CE: Reprogramming failure. Giving up\n"); dev->next_event = KTIME_MAX; return -ETIME; } @ arch/arm/kernel/smp.c:219 @ static int clockevents_increase_min_delt if (dev->min_delta_ns > MIN_DELTA_LIMIT) dev->min_delta_ns = MIN_DELTA_LIMIT; - printk_deferred(KERN_WARNING - "CE: %s increased min_delta_ns to %llu nsec\n", - dev->name ? dev->name : "?", - (unsigned long long) dev->min_delta_ns); + pr_warn("CE: %s increased min_delta_ns to %llu nsec\n", + dev->name ? dev->name : "?", (unsigned long long) dev->min_delta_ns); return 0; } --- a/kernel/time/ntp.c +++ b/kernel/time/ntp.c @ arch/arm/kernel/smp.c:942 @ static long hardpps_update_freq(struct p time_status |= STA_PPSERROR; pps_errcnt++; pps_dec_freq_interval(); - printk_deferred(KERN_ERR - "hardpps: PPSERROR: interval too long - %lld s\n", - freq_norm.sec); + pr_err("hardpps: PPSERROR: interval too long - %lld s\n", freq_norm.sec); return 0; } @ arch/arm/kernel/smp.c:955 @ static long hardpps_update_freq(struct p delta = shift_right(ftemp - pps_freq, NTP_SCALE_SHIFT); pps_freq = ftemp; if (delta > PPS_MAXWANDER || delta < -PPS_MAXWANDER) { - printk_deferred(KERN_WARNING - "hardpps: PPSWANDER: change=%ld\n", delta); + pr_warn("hardpps: PPSWANDER: change=%ld\n", delta); time_status |= STA_PPSWANDER; pps_stbcnt++; pps_dec_freq_interval(); @ arch/arm/kernel/smp.c:999 @ static void hardpps_update_phase(long er * the time offset is updated. */ if (jitter > (pps_jitter << PPS_POPCORN)) { - printk_deferred(KERN_WARNING - "hardpps: PPSJITTER: jitter=%ld, limit=%ld\n", - jitter, (pps_jitter << PPS_POPCORN)); + pr_warn("hardpps: PPSJITTER: jitter=%ld, limit=%ld\n", + jitter, (pps_jitter << PPS_POPCORN)); time_status |= STA_PPSJITTER; pps_jitcnt++; } else if (time_status & STA_PPSTIME) { @ arch/arm/kernel/smp.c:1057 @ void __hardpps(const struct timespec64 * time_status |= STA_PPSJITTER; /* restart the frequency calibration interval */ pps_fbase = *raw_ts; - printk_deferred(KERN_ERR "hardpps: PPSJITTER: bad pulse\n"); + pr_err("hardpps: PPSJITTER: bad pulse\n"); return; } --- a/kernel/time/timekeeping.c +++ b/kernel/time/timekeeping.c @ arch/arm/kernel/smp.c:206 @ static void timekeeping_check_update(str const char *name = tk->tkr_mono.clock->name; if (offset > max_cycles) { - printk_deferred("WARNING: timekeeping: Cycle offset (%lld) is larger than allowed by the '%s' clock's max_cycles value (%lld): time overflow danger\n", - offset, name, max_cycles); - printk_deferred(" timekeeping: Your kernel is sick, but tries to cope by capping time updates\n"); + printk("WARNING: timekeeping: Cycle offset (%lld) is larger than allowed by the '%s' clock's max_cycles value (%lld): time overflow danger\n", + offset, name, max_cycles); + printk(" timekeeping: Your kernel is sick, but tries to cope by capping time updates\n"); } else { if (offset > (max_cycles >> 1)) { - printk_deferred("INFO: timekeeping: Cycle offset (%lld) is larger than the '%s' clock's 50%% safety margin (%lld)\n", - offset, name, max_cycles >> 1); - printk_deferred(" timekeeping: Your kernel is still fine, but is feeling a bit nervous\n"); + printk("INFO: timekeeping: Cycle offset (%lld) is larger than the '%s' clock's 50%% safety margin (%lld)\n", + offset, name, max_cycles >> 1); + printk(" timekeeping: Your kernel is still fine, but is feeling a bit nervous\n"); } } if (tk->underflow_seen) { if (jiffies - tk->last_warning > WARNING_FREQ) { - printk_deferred("WARNING: Underflow in clocksource '%s' observed, time update ignored.\n", name); - printk_deferred(" Please report this, consider using a different clocksource, if possible.\n"); - printk_deferred(" Your kernel is probably still fine.\n"); + printk("WARNING: Underflow in clocksource '%s' observed, time update ignored.\n", + name); + printk(" Please report this, consider using a different clocksource, if possible.\n"); + printk(" Your kernel is probably still fine.\n"); tk->last_warning = jiffies; } tk->underflow_seen = 0; @ arch/arm/kernel/smp.c:230 @ static void timekeeping_check_update(str if (tk->overflow_seen) { if (jiffies - tk->last_warning > WARNING_FREQ) { - printk_deferred("WARNING: Overflow in clocksource '%s' observed, time update capped.\n", name); - printk_deferred(" Please report this, consider using a different clocksource, if possible.\n"); - printk_deferred(" Your kernel is probably still fine.\n"); + printk("WARNING: Overflow in clocksource '%s' observed, time update capped.\n", + name); + printk(" Please report this, consider using a different clocksource, if possible.\n"); + printk(" Your kernel is probably still fine.\n"); tk->last_warning = jiffies; } tk->overflow_seen = 0; @ arch/arm/kernel/smp.c:1674 @ static void __timekeeping_inject_sleepti const struct timespec64 *delta) { if (!timespec64_valid_strict(delta)) { - printk_deferred(KERN_WARNING - "__timekeeping_inject_sleeptime: Invalid " - "sleep delta value!\n"); + pr_warn("%s: Invalid sleep delta value!\n", __func__); return; } tk_xtime_add(tk, delta); --- a/kernel/time/timekeeping_debug.c +++ b/kernel/time/timekeeping_debug.c @ arch/arm/kernel/smp.c:52 @ void tk_debug_account_sleep_time(const s int bin = min(fls(t->tv_sec), NUM_BINS-1); sleep_time_bin[bin]++; - pm_deferred_pr_dbg("Timekeeping suspended for %lld.%03lu seconds\n", + pm_pr_dbg("Timekeeping suspended for %lld.%03lu seconds\n", (s64)t->tv_sec, t->tv_nsec / NSEC_PER_MSEC); } --- a/kernel/workqueue.c +++ b/kernel/workqueue.c @ arch/arm/kernel/smp.c:4839 @ void show_workqueue_state(void) * drivers that queue work while holding locks * also taken in their write paths. */ - printk_deferred_enter(); show_pwq(pwq); - printk_deferred_exit(); } raw_spin_unlock_irqrestore(&pwq->pool->lock, flags); /* @ arch/arm/kernel/smp.c:4863 @ void show_workqueue_state(void) * queue work while holding locks also taken in their write * paths. */ - printk_deferred_enter(); pr_info("pool %d:", pool->id); pr_cont_pool_info(pool); pr_cont(" hung=%us workers=%d", @ arch/arm/kernel/smp.c:4877 @ void show_workqueue_state(void) first = false; } pr_cont("\n"); - printk_deferred_exit(); next_pool: raw_spin_unlock_irqrestore(&pool->lock, flags); /* --- a/lib/ratelimit.c +++ b/lib/ratelimit.c @ arch/arm/kernel/smp.c:50 @ int ___ratelimit(struct ratelimit_state if (time_is_before_jiffies(rs->begin + rs->interval)) { if (rs->missed) { if (!(rs->flags & RATELIMIT_MSG_ON_RELEASE)) { - printk_deferred(KERN_WARNING - "%s: %d callbacks suppressed\n", - func, rs->missed); + pr_warn("%s: %d callbacks suppressed\n", func, rs->missed); rs->missed = 0; } }