Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753061AbbDGJV1 (ORCPT ); Tue, 7 Apr 2015 05:21:27 -0400 Received: from mail-wi0-f169.google.com ([209.85.212.169]:37151 "EHLO mail-wi0-f169.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751199AbbDGJV0 (ORCPT ); Tue, 7 Apr 2015 05:21:26 -0400 Date: Tue, 7 Apr 2015 11:21:21 +0200 From: Ingo Molnar To: Linus Torvalds Cc: Chris J Arges , Rafael David Tinoco , Peter Anvin , Jiang Liu , Peter Zijlstra , LKML , Jens Axboe , Frederic Weisbecker , Gema Gomez , the arch/x86 maintainers Subject: Re: [PATCH] smp/call: Detect stuck CSD locks Message-ID: <20150407092121.GA9971@gmail.com> References: <551C6A48.9060805@canonical.com> <20150402182607.GA8896@gmail.com> <551D8FAF.5070805@canonical.com> <20150402190725.GA10570@gmail.com> <551DB0E2.1020607@canonical.com> <20150403054320.GA9863@gmail.com> <5522BB49.5060704@canonical.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.5.23 (2014-03-12) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 4447 Lines: 139 * Linus Torvalds wrote: > On Mon, Apr 6, 2015 at 9:58 AM, Chris J Arges > wrote: > > > > I noticed that with this patch it never reached 'csd: Detected > > non-responsive CSD lock...' because it seems that ts_delta never reached > > CSD_LOCK_TIMEOUT. I tried adjusting the TIMEOUT value and still got a > > hang without reaching this statement. I made the ts0,ts1 values global > > and put a counter into the while loop and found that the loop iterated > > about 670 million times before the softlockup was detected. In addition > > ts0 and ts1 both had the same values upon soft lockup, and thus would > > never trip the CSD_LOCK_TIMEOUT check. > > Sounds like jiffies stops updating. Which doesn't sound unreasonable > for when there is some IPI problem. Yeah - although it weakens the 'IPI lost spuriously' hypothesis: we ought to have irqs enabled here which normally doesn't stop jiffies from updating, and the timer interrupt stopping suggests a much deeper problem than just some lost IPI ... > > How about just changing the debug patch to count iterations, and > print out a warning when it reaches ten million or so. Yeah, or replace jiffies_to_ms() with: sched_clock()/1000000 sched_clock() should be safe to call in these codepaths. Like the attached patch. (Totally untested.) Thanks, Ingo --- kernel/smp.c | 51 ++++++++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 46 insertions(+), 5 deletions(-) diff --git a/kernel/smp.c b/kernel/smp.c index f38a1e692259..e0eec1ab3ef2 100644 --- a/kernel/smp.c +++ b/kernel/smp.c @@ -98,22 +98,63 @@ void __init call_function_init(void) register_cpu_notifier(&hotplug_cfd_notifier); } +/* Locking timeout in ms: */ +#define CSD_LOCK_TIMEOUT (10*1000ULL) + +/* Print this ID in every printk line we output, to be able to easily sort them apart: */ +static int csd_bug_count; + /* * csd_lock/csd_unlock used to serialize access to per-cpu csd resources * * For non-synchronous ipi calls the csd can still be in use by the * previous function call. For multi-cpu calls its even more interesting * as we'll have to ensure no other cpu is observing our csd. + * + * ( The overhead of deadlock detection is not a big problem, this is a + * cpu_relax() loop that is actively wasting CPU cycles to poll for + * completion. ) */ -static void csd_lock_wait(struct call_single_data *csd) +static void csd_lock_wait(struct call_single_data *csd, int cpu) { - while (csd->flags & CSD_FLAG_LOCK) + int bug_id = 0; + u64 ts0, ts1, ts_delta; + + ts0 = sched_clock()/1000000; + + if (unlikely(!csd_bug_count)) { + csd_bug_count++; + printk("csd: CSD deadlock debugging initiated!\n"); + } + + while (csd->flags & CSD_FLAG_LOCK) { + ts1 = sched_clock()/1000000; + + ts_delta = ts1-ts0; + if (unlikely(ts_delta >= CSD_LOCK_TIMEOUT)) { /* Uh oh, it took too long. Why? */ + + bug_id = csd_bug_count; + csd_bug_count++; + + ts0 = ts1; /* Re-start the timeout detection */ + + printk("csd: Detected non-responsive CSD lock (#%d) on CPU#%02d, waiting %Ld.%03Ld secs for CPU#%02d\n", + bug_id, raw_smp_processor_id(), ts_delta/1000ULL, ts_delta % 1000ULL, cpu); + if (cpu >= 0) { + printk("csd: Re-sending CSD lock (#%d) IPI from CPU#%02d to CPU#%02d\n", bug_id, raw_smp_processor_id(), cpu); + arch_send_call_function_single_ipi(cpu); + } + dump_stack(); + } cpu_relax(); + } + if (unlikely(bug_id)) + printk("csd: CSD lock (#%d) got unstuck on CPU#%02d, CPU#%02d released the lock after all. Phew!\n", bug_id, raw_smp_processor_id(), cpu); } static void csd_lock(struct call_single_data *csd) { - csd_lock_wait(csd); + csd_lock_wait(csd, -1); csd->flags |= CSD_FLAG_LOCK; /* @@ -191,7 +232,7 @@ static int generic_exec_single(int cpu, struct call_single_data *csd, arch_send_call_function_single_ipi(cpu); if (wait) - csd_lock_wait(csd); + csd_lock_wait(csd, cpu); return 0; } @@ -446,7 +487,7 @@ void smp_call_function_many(const struct cpumask *mask, struct call_single_data *csd; csd = per_cpu_ptr(cfd->csd, cpu); - csd_lock_wait(csd); + csd_lock_wait(csd, cpu); } } } -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/