From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754166AbcHSGdf (ORCPT ); Fri, 19 Aug 2016 02:33:35 -0400 Received: from mail-pf0-f195.google.com ([209.85.192.195]:32884 "EHLO mail-pf0-f195.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752904AbcHSGd2 (ORCPT ); Fri, 19 Aug 2016 02:33:28 -0400 Date: Fri, 19 Aug 2016 15:32:36 +0900 From: Sergey Senozhatsky To: Petr Mladek Cc: Sergey Senozhatsky , Viresh Kumar , Jan Kara , Andrew Morton , Sergey Senozhatsky , Jan Kara , Tejun Heo , Tetsuo Handa , "linux-kernel@vger.kernel.org" , Byungchul Park , vlevenetz@mm-sol.com, Greg Kroah-Hartman Subject: Re: [PATCH v10 1/2] printk: Make printk() completely async Message-ID: <20160819063236.GA584@swordfish> References: <1459789048-1337-1-git-send-email-sergey.senozhatsky@gmail.com> <1459789048-1337-2-git-send-email-sergey.senozhatsky@gmail.com> <20160404155149.a3e3307def2d1315e2099c63@linux-foundation.org> <20160406082758.GA3554@quack.suse.cz> <20160812094447.GD7339@pathway.suse.cz> <20160818022712.GB500@swordfish> <20160818093329.GL13300@pathway.suse.cz> <20160818095144.GA425@swordfish> <20160818105629.GE26194@pathway.suse.cz> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20160818105629.GE26194@pathway.suse.cz> User-Agent: Mutt/1.7.0 (2016-08-17) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On (08/18/16 12:56), Petr Mladek wrote: > On Thu 2016-08-18 18:51:44, Sergey Senozhatsky wrote: > > On (08/18/16 11:33), Petr Mladek wrote: > > [..] > > > > > 2. Force synchronous printk inside WARN()/BUG() macros. > > > > > > > > will it help? semaphore up() calls wake_up_process() regardless the context. > > > > not to mention that we still may have spin_dump() enabled. > > > > > > Good point. That changes my preferences :-) > > > > > > > > > > > > 3. Force printk_deferred() inside WARN()/BUG() macros via the per-CPU > > > > > printk_func. > > > > > > > > > > It might be elegant. But we do not want this outside the scheduler > > > > > code. Therefore we would need special variants of WARN_*_SCHED() > > > > > BUG_*_SCHED() macros. > > > > > > Also we need to make sure that everything will be done on a single CPU > > > as the printk_func is per-CPU variable. > > > > lib/dump_stack.c dump_stack() disables local IRQs, so we will stay > > on the same CPU. > > It is less important to stay of the same CPU if you use > printk_deferred() directly. But it us must to have if you > use it via the printk_func per-CPU variable. > > The advantage of the printk_func trick is that it is transparent. > You do not need to modify any existing functions used by WARN()/BUG() > macros. good point. so something like below, perhaps. I'm less sure about deferred BUG()/BUG_ON(): #define DEFERRED_BUG() do { \ printk_deferred_enter(); \ BUG(); \ printk_deferred_exit(); \ } while (0) \ #define DEFERRED_BUG_ON(condition) do { \ printk_deferred_enter(); \ BUG_ON(condition); \ printk_deferred_exit(); \ } while (0) depending on .config BUG() may never return back -- passing control to do_exit(), so printk_deferred_exit() won't be executed. thus we probably need to have a per-cpu variable that would indicate that we are in deferred_bug. hm... but do we really need deferred BUG() in the first place? Signed-off-by: Sergey Senozhatsky --- include/asm-generic/bug.h | 50 +++++++++++++++++++++++++++++++++++++++++++++++ include/linux/printk.h | 6 ++++++ kernel/printk/internal.h | 18 +---------------- kernel/printk/printk.c | 42 ++++++++++++++++++++++++++++++++++----- 4 files changed, 94 insertions(+), 22 deletions(-) diff --git a/include/asm-generic/bug.h b/include/asm-generic/bug.h index 6f96247..d72ee1e 100644 --- a/include/asm-generic/bug.h +++ b/include/asm-generic/bug.h @@ -60,6 +60,10 @@ struct bug_entry { * significant issues that need prompt attention if they should ever * appear at runtime. Use the versions with printk format strings * to provide better diagnostics. + * + * DEFERRED_WARN macros call printk_deferred() to print the messages + * and are meant to be used from the contexts where direct printk() + * can deadlock the system. */ #ifndef __WARN_TAINT extern __printf(3, 4) @@ -145,6 +149,52 @@ void __warn(const char *file, int line, void *caller, unsigned taint, unlikely(__ret_warn_once); \ }) +#define DEFERRED_WARN_ON(condition) ({ \ + int __ret_warn_on = !!(condition); \ + if (unlikely(__ret_warn_on)) { \ + printk_deferred_enter(); \ + __WARN(); \ + printk_deferred_exit(); \ + } \ + unlikely(__ret_warn_on); \ +}) + +#define DEFERRED_WARN(condition, format...) ({ \ + int __ret_warn_on = !!(condition); \ + if (unlikely(__ret_warn_on)) { \ + printk_deferred_enter(); \ + __WARN_printf(format); \ + printk_deferred_exit(); \ + } \ + unlikely(__ret_warn_on); \ +}) + +#define DEFERRED_WARN_ON_ONCE(condition) ({ \ + static bool __section(.data.unlikely) __warned; \ + int __ret_warn_once = !!(condition); \ + \ + if (unlikely(__ret_warn_once && !__warned)) { \ + __warned = true; \ + printk_deferred_enter(); \ + WARN_ON(1); \ + printk_deferred_exit(); \ + } \ + unlikely(__ret_warn_once); \ +}) + +#define DEFERRED_WARN_ONCE(condition, format...) ({ \ + static bool __section(.data.unlikely) __warned; \ + int __ret_warn_once = !!(condition); \ + \ + if (unlikely(__ret_warn_once && !__warned)) { \ + __warned = true; \ + printk_deferred_enter(); \ + WARN(1, format); \ + printk_deferred_exit(); \ + } \ + unlikely(__ret_warn_once); \ +}) + #else /* !CONFIG_BUG */ #ifndef HAVE_ARCH_BUG #define BUG() do {} while (1) diff --git a/include/linux/printk.h b/include/linux/printk.h index 696a56b..5142654 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -193,6 +193,9 @@ void __init setup_log_buf(int early); __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 void printk_deferred_enter(void); +extern void printk_deferred_exit(void); #else static inline __printf(1, 0) int vprintk(const char *s, va_list args) @@ -252,6 +255,9 @@ static inline void dump_stack_print_info(const char *log_lvl) static inline void show_regs_print_info(const char *log_lvl) { } + +static void printk_deferred_enter(void) {} +static void printk_deferred_exit(void) {} #endif extern asmlinkage void dump_stack(void) __cold; diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h index 7fd2838..70f1cf2 100644 --- a/kernel/printk/internal.h +++ b/kernel/printk/internal.h @@ -19,23 +19,12 @@ typedef __printf(1, 0) int (*printk_func_t)(const char *fmt, va_list args); int __printf(1, 0) vprintk_default(const char *fmt, va_list args); +DECLARE_PER_CPU(printk_func_t, printk_func); #ifdef CONFIG_PRINTK_NMI extern raw_spinlock_t logbuf_lock; -/* - * printk() could not take logbuf_lock in NMI context. Instead, - * it temporary stores the strings into a per-CPU buffer. - * The alternative implementation is chosen transparently - * via per-CPU variable. - */ -DECLARE_PER_CPU(printk_func_t, printk_func); -static inline __printf(1, 0) int vprintk_func(const char *fmt, va_list args) -{ - return this_cpu_read(printk_func)(fmt, args); -} - extern atomic_t nmi_message_lost; static inline int get_nmi_message_lost(void) { @@ -44,11 +33,6 @@ static inline int get_nmi_message_lost(void) #else /* CONFIG_PRINTK_NMI */ -static inline __printf(1, 0) int vprintk_func(const char *fmt, va_list args) -{ - return vprintk_default(fmt, args); -} - static inline int get_nmi_message_lost(void) { return 0; diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 0d3e026..6e260a0 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -2026,7 +2026,17 @@ asmlinkage __visible int printk(const char *fmt, ...) int r; va_start(args, fmt); - r = vprintk_func(fmt, args); + /* + * printk() could not take logbuf_lock in NMI context. Instead, + * it temporary stores the strings into a per-CPU buffer. The + * alternative implementation is chosen transparently via per-CPU + * variable. + * + * We also switch printk_func from default to vprintk_deferred() + * when in DEFERRED_WARN()/DEFERRED_BUG(), because it may be + * unsafe to execute vprintk_default(). + */ + r = this_cpu_read(printk_func)(fmt, args); va_end(args); return r; @@ -3037,6 +3047,17 @@ void wake_up_klogd(void) preempt_enable(); } +static int vprintk_deferred(const char *fmt, va_list args) +{ + int r; + + r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, 0, fmt, args); + __this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT); + irq_work_queue(this_cpu_ptr(&wake_up_klogd_work)); + + return r; +} + int printk_deferred(const char *fmt, ...) { va_list args; @@ -3044,16 +3065,27 @@ int printk_deferred(const char *fmt, ...) preempt_disable(); va_start(args, fmt); - r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, 0, fmt, args); + r = vprintk_deferred(fmt, args); va_end(args); - - __this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT); - irq_work_queue(this_cpu_ptr(&wake_up_klogd_work)); preempt_enable(); return r; } +void printk_deferred_enter(void) +{ + preempt_disable(); + this_cpu_write(printk_func, vprintk_deferred); +} +EXPORT_SYMBOL(printk_deferred_enter); + +void printk_deferred_exit(void) +{ + this_cpu_write(printk_func, vprintk_default); + preempt_enable(); +} +EXPORT_SYMBOL(printk_deferred_exit); + /* * printk rate limiting, lifted from the networking subsystem. * -- 2.9.3