[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20180423170128.mf7g26rniimm7asf@ideak-desk.fi.intel.com>
Date: Mon, 23 Apr 2018 20:01:28 +0300
From: Imre Deak <imre.deak@...el.com>
To: Thomas Gleixner <tglx@...utronix.de>
Cc: LKML <linux-kernel@...r.kernel.org>,
Peter Zijlstra <peterz@...radead.org>,
Ville Syrjälä
<ville.syrjala@...ux.intel.com>,
Mika Kuoppala <mika.kuoppala@...el.com>,
Chris Wilson <chris@...is-wilson.co.uk>
Subject: Re: Early timeouts due to inaccurate jiffies during system
suspend/resume
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
Powered by blists - more mailing lists