Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751530AbdFHTHO (ORCPT ); Thu, 8 Jun 2017 15:07:14 -0400 Received: from mail-wr0-f196.google.com ([209.85.128.196]:35483 "EHLO mail-wr0-f196.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751448AbdFHTHL (ORCPT ); Thu, 8 Jun 2017 15:07:11 -0400 Date: Thu, 8 Jun 2017 21:07:05 +0200 From: Frederic Weisbecker To: "Levin, Alexander (Sasha Levin)" Cc: Thomas Gleixner , Ingo Molnar , LKML , Peter Zijlstra , Rik van Riel , James Hartsock , "stable@vger.kernel.org" , Tim Wright , Pavel Machek Subject: [PATCH] nohz: Fix spurious warning when hrtimer and clockevent get out of sync Message-ID: <20170608190702.GB27757@lerouge> References: <1492783255-5051-1-git-send-email-fweisbec@gmail.com> <1492783255-5051-3-git-send-email-fweisbec@gmail.com> <20170603080638.7okm4ztp7zuphc4b@sasha-lappy> <20170603124237.GA25077@lerouge> <20170603125259.scyapxq2fftqiiz3@sasha-lappy> <20170606145227.GB22016@lerouge> <20170607040801.4r7iqfzynf3d3xom@sasha-lappy> <20170607141400.GA29571@lerouge> <20170607213349.wtc2xhljlx5zjv5f@sasha-lappy> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20170607213349.wtc2xhljlx5zjv5f@sasha-lappy> User-Agent: Mutt/1.5.24 (2015-08-30) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 4578 Lines: 123 On Wed, Jun 07, 2017 at 09:36:45PM +0000, Levin, Alexander (Sasha Levin) wrote: > On Wed, Jun 07, 2017 at 04:14:03PM +0200, Frederic Weisbecker wrote: > > On Wed, Jun 07, 2017 at 04:17:41AM +0000, Levin, Alexander (Sasha Levin) wrote: > > > > Thanks Sasha! > > > > > > > > I couldn't reproduce it, that config boots fine on my kvm. > > > > Would you have the time to dump some traces for me? > > > > > > > > I'd need you to add this boot option: trace_event=hrtimer_cancel,hrtimer_start,hrtimer_expire_entry > > > > And boot your kernel with the below patch. This will dump the timer traces to your console. > > > > I would be very interested in the resulting console dump file. > > > > > > Attached. Let me know if you need anything else. > > > > Great! So now I can deduce that the problem doesn't come from the nohz code as > > ts->next_tick matches the hrtimer deadline. But the dev->next_event from the > > clockevent seems to be out of line. > > > > Sorry to bother you again, but I'm chasing this bug for several weeks now and > > you're one of the rare person who can reproduce it. So I may need some more > > tracing details. > > I take payment in beers ;) Duly noted ;-) > > But really, not a problem. > > > Here is another version of the debugging patch (not a delta), I added more trace_printk, > > namely the places where we set this dev->next_event. Can you please apply the below and do > > the dump again? > > Attached. Awesome, these traces have been very helpful! So now I think I get what's going on. Can you please test the following fix? Thanks a lot! --- >From 604a46c3e821c61411cee2205fa1cb65e5b04174 Mon Sep 17 00:00:00 2001 From: Frederic Weisbecker Date: Thu, 8 Jun 2017 16:32:58 +0200 Subject: [PATCH] nohz: Fix spurious warning when hrtimer and clockevent get out of sync The sanity check ensuring that the tick expiry cache (ts->next_tick) is actually in sync with the hardware clock (dev->next_event) makes the wrong assumption that the clock can't be programmed later than the hrtimer deadline. In fact the clock hardware can be programmed later on some conditions such as: * The hrtimer deadline is already in the past. * The hrtimer deadline is earlier than the minimum delay supported by the hardware. Such conditions can be met when we program the tick, for example if the last jiffies update hasn't been seen by the current CPU yet, we may program the hrtimer to a deadline that is earlier than ktime_get() because last_jiffies_update is our timestamp base to compute the next tick. As a result, we can randomly observe such warning: WARNING: CPU: 5 PID: 0 at kernel/time/tick-sched.c:794 tick_nohz_stop_sched_tick kernel/time/tick-sched.c:791 [inline] Call Trace: tick_nohz_irq_exit tick_irq_exit irq_exit exiting_irq smp_call_function_interrupt smp_call_function_single_interrupt call_function_single_interrupt Therefore, let's rather make sure that the tick expiry cache is sync'ed with the tick hrtimer deadline, against which it is not supposed to drift away. The clock hardware instead has its own will and can't be used as a reliable comparison point. Reported-by: Sasha Levin Cc: Thomas Gleixner Cc: Ingo Molnar Cc: Peter Zijlstra Cc: Rik van Riel Cc: James Hartsock Cc: Tim Wright Signed-off-by: Frederic Weisbecker --- kernel/time/tick-sched.c | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c index 9d31f1e..b55547f 100644 --- a/kernel/time/tick-sched.c +++ b/kernel/time/tick-sched.c @@ -768,7 +768,8 @@ static ktime_t tick_nohz_stop_sched_tick(struct tick_sched *ts, /* Skip reprogram of event if its not changed */ if (ts->tick_stopped && (expires == ts->next_tick)) { /* Sanity check: make sure clockevent is actually programmed */ - if (likely(dev->next_event <= ts->next_tick)) + if (tick != KTIME_MAX && + ts->next_tick == hrtimer_get_expires(&ts->sched_timer)) goto out; WARN_ON_ONCE(1); @@ -806,8 +807,10 @@ static ktime_t tick_nohz_stop_sched_tick(struct tick_sched *ts, goto out; } + hrtimer_set_expires(&ts->sched_timer, tick); + if (ts->nohz_mode == NOHZ_MODE_HIGHRES) - hrtimer_start(&ts->sched_timer, tick, HRTIMER_MODE_ABS_PINNED); + hrtimer_start_expires(&ts->sched_timer, HRTIMER_MODE_ABS_PINNED); else tick_program_event(tick, 1); out: -- 2.7.4