From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752544AbbE0XOP (ORCPT ); Wed, 27 May 2015 19:14:15 -0400 Received: from mail.linuxfoundation.org ([140.211.169.12]:58627 "EHLO mail.linuxfoundation.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752248AbbE0XOL (ORCPT ); Wed, 27 May 2015 19:14:11 -0400 Date: Wed, 27 May 2015 16:14:09 -0700 From: Andrew Morton To: Petr Mladek Cc: Frederic Weisbecker , Steven Rostedt , Dave Anderson , "Paul E. McKenney" , Kay Sievers , Jiri Kosina , Michal Hocko , Jan Kara , linux-kernel@vger.kernel.org, Wang Long , peifeiyue@huawei.com, dzickus@redhat.com, morgan.wang@huawei.com, sasha.levin@oracle.com Subject: Re: [PATCH 02/10] printk: Try harder to get logbuf_lock on NMI Message-Id: <20150527161409.c1c37d25af1c09c340bd04a3@linux-foundation.org> In-Reply-To: <1432557993-20458-3-git-send-email-pmladek@suse.cz> References: <1432557993-20458-1-git-send-email-pmladek@suse.cz> <1432557993-20458-3-git-send-email-pmladek@suse.cz> X-Mailer: Sylpheed 3.4.1 (GTK+ 2.24.23; x86_64-pc-linux-gnu) Mime-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Mon, 25 May 2015 14:46:25 +0200 Petr Mladek wrote: > If the logbuf_lock is not available immediately, it does not mean > that there is a deadlock. We should try harder and wait a bit. > > On the other hand, we must not forget that we are in NMI and the timeout > has to be rather small. It must not cause dangerous stalls. > > I even got full system freeze when the timeout was 10ms and I printed > backtraces from all CPUs. In this case, all CPUs were blocked for > too long. > > ... > > --- a/kernel/printk/printk.c > +++ b/kernel/printk/printk.c > @@ -231,6 +231,8 @@ static DEFINE_RAW_SPINLOCK(logbuf_lock); > > #ifdef CONFIG_PRINTK > DECLARE_WAIT_QUEUE_HEAD(log_wait); > +/* cpu currently holding logbuf_lock */ > +static unsigned int logbuf_cpu = UINT_MAX; > /* the next printk record to read by syslog(READ) or /proc/kmsg */ > static u64 syslog_seq; > static u32 syslog_idx; > @@ -1610,6 +1612,38 @@ static size_t cont_print_text(char *text, size_t size) > return textlen; > } > > +/* > + * This value defines the maximum delay that we spend waiting for logbuf_lock > + * in NMI context. 100us looks like a good compromise. Note that, for example, > + * syslog_print_all() might hold the lock for quite some time. On the other > + * hand, waiting 10ms caused system freeze when many backtraces were printed > + * in NMI. > + */ > +#define TRY_LOCKBUF_LOCK_MAX_DELAY_NS 100000UL > + > +/* We must be careful in NMI when we managed to preempt a running printk */ > +static int try_logbuf_lock_in_nmi(void) > +{ > + u64 start_time, current_time; > + int this_cpu = smp_processor_id(); > + > + /* no way if we are already locked on this CPU */ > + if (logbuf_cpu == this_cpu) > + return 0; > + > + /* try hard to get the lock but do not wait forever */ > + start_time = cpu_clock(this_cpu); > + current_time = start_time; > + while (current_time - start_time < TRY_LOCKBUF_LOCK_MAX_DELAY_NS) { > + if (raw_spin_trylock(&logbuf_lock)) > + return 1; > + cpu_relax(); > + current_time = cpu_clock(this_cpu); > + } (Looks at the read_seqcount_retry() in kernel/time/sched_clock.c:sched_clock()) Running cpu_clock() in NMI context seems a generally bad idea. Using an ndelay/udelay wait loop here would be safer? There are many sites in kernel/printk/printk.c which take logbuf_lock, but this patch only sets logbuf_cpu in one of those cases: vprintk_emit(). I suggest adding helper functions to take/release logbuf_lock. And rename logbuf_lock to something else to ensure that nobody accidentally takes the lock directly.