From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1755774AbeDWRBd (ORCPT ); Mon, 23 Apr 2018 13:01:33 -0400 Received: from mga01.intel.com ([192.55.52.88]:65510 "EHLO mga01.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1755573AbeDWRBc (ORCPT ); Mon, 23 Apr 2018 13:01:32 -0400 X-Amp-Result: UNKNOWN X-Amp-Original-Verdict: FILE UNKNOWN X-Amp-File-Uploaded: False X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.49,318,1520924400"; d="scan'208";a="39794569" Date: Mon, 23 Apr 2018 20:01:28 +0300 From: Imre Deak To: Thomas Gleixner Cc: LKML , Peter Zijlstra , Ville =?iso-8859-1?Q?Syrj=E4l=E4?= , Mika Kuoppala , Chris Wilson Subject: Re: Early timeouts due to inaccurate jiffies during system suspend/resume Message-ID: <20180423170128.mf7g26rniimm7asf@ideak-desk.fi.intel.com> Reply-To: imre.deak@intel.com References: <20180419013200.wxkzqfdacfsijci5@ideak-desk.fi.intel.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: NeoMutt/20170113 (1.7.2) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Thu, Apr 19, 2018 at 01:05:39PM +0200, Thomas Gleixner wrote: > On Thu, 19 Apr 2018, Imre Deak wrote: > > Hi, > > > > while checking bug [1], I noticed that jiffies based timing loops like > > > > expire = jiffies + timeout + 1; > > while (!time_after(jiffies, expire)) > > do_something; > > > > can last shorter than expected (that is less than timeout). > > Yes, that can happen when the timer interrupt is delayed long enough for > whatever reason. If you need accurate timing then you need to use > ktime_get(). Thanks. I always regarded jiffies as non-accurate, but something that gives a minimum time delay guarantee (when adjusted by +1 as above). I wonder if there are other callers in kernel that don't expect an early timeout. We switched now to using ktime_get_raw() in the i915 driver. > > > After some ftracing it seems like jiffies gets stale due to a missed > > LAPIC timer interrupt after the interrupt is armed in > > lapic_next_deadline() and before jiffies is sampled at 2. above. > > Eventually the interrupt does get delivered, at which point jiffies gets > > updated via tick_do_update_jiffies64() with a >1 ticks increment. > > Between lapic_next_deadline() and the - late - delivery of the interrupt > > the CPU on which the interrupt is armed doesn't go idle. > > That's odd. I have no real explanation for that. Looks like the reason is IRQ latency. For reference here are the longest ones I found with irqsoff ftracing, all running with IRQs disabled during system resume: hpet_rtc_interrupt()->hpet_rtc_timer_reinit(): do { ... } while(!hpet_cnt_ahead(...)); takes sometimes up to ~40msec for me. hpet_rtc_interrupt()->mc146818_get_time(): if (mc146818_is_updating()) mdelay(20); driver_probe_device->atkbd_connect()->i8042_port_close()->__i8042_command()->i8042_wait_write(): takes sometimes up to ~10msec for me. All the above paired with asynchronous calling of the drivers' resume hooks may result in the jumps in jiffies I saw. --Imre