linux-kernel - Re: x86-tip tsc/tick gripage

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:   Thu, 27 Apr 2017 07:26:55 +0200
From:   Mike Galbraith <efault@....de>
To:     Peter Zijlstra <peterz@...radead.org>
Cc:     Ingo Molnar <mingo@...nel.org>,
        "Paul E. McKenney" <paulmck@...ibm.com>,
        LKML <linux-kernel@...r.kernel.org>, Ingo Molnar <mingo@...e.hu>,
        Thomas Gleixner <tglx@...utronix.de>,
        Frederic Weisbecker <fweisbec@...il.com>
Subject: Re: x86-tip tsc/tick gripage

On Wed, 2017-04-26 at 14:30 +0200, Mike Galbraith wrote:
> On Wed, 2017-04-26 at 13:39 +0200, Mike Galbraith wrote:
> > On Wed, 2017-04-26 at 12:26 +0200, Peter Zijlstra wrote:
> > > On Wed, Apr 26, 2017 at 10:57:42AM +0200, Mike Galbraith wrote:
> > > 
> > > > Both still lose their TSC.
> > > > 
> > > > [   11.982468] tsc: Refined TSC clocksource calibration: 2260.999 MHz
> > > > [   11.994275] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x20974a4d8bb, max_idle_ns: 440795246623 ns
> > > > [   13.064172] clocksource: Switched to clocksource tsc
> > > > [  240.247851] clocksource: timekeeping watchdog on CPU23: Marking clocksource 'tsc' as unstable because the skew is too large:
> > > > [  240.462501] clocksource:                       'tsc' cs_now: 108fe5be09f cs_last: b90a6a0676 mask: ffffffffffffffff
> > > > [  240.675057] tsc: Marking TSC unstable due to clocksource watchdog
> > > 
> > > 
> > > And they didn't use to? We don't typically write to TSC or TSC_ADJUST
> > > and thus would not cause such behaviour.
> > 
> > Nope.
> 
> DL980 seems perfectly happy with master.today.. so off we go.

hm, this bit of huge trace looks less than wonderful.

          <idle>-0     [041] ..s2   317.304657: timer_expire_entry: timer=ffffffff820d6600 function=clocksource_watchdog now=4294971392
          <idle>-0     [041] d.s4   317.304660: timer_start: timer=ffffffff820d6600 function=clocksource_watchdog expires=4294916631 [timeout=-54761] cpu=42 idx=19 flags=
          <idle>-0     [041] ..s2   317.304660: timer_expire_exit: timer=ffffffff820d6600                                             ^^^^^^^^^^^^^^

1.1 megalines later, we finally meet function=clocksource_watchdog
again, and have a cow.
          <idle>-0     [043] d.s3   489.511620: timer_cancel: timer=ffffffff820d6600
          <idle>-0     [043] ..s2   489.511621: timer_expire_entry: timer=ffffffff820d6600 function=clocksource_watchdog now=4295014443
          <idle>-0     [043] ..s2   489.511628: clocksource_watchdog: timekeeping watchdog on CPU43: Marking clocksource 'tsc' as unstable because the skew is too large:
          <idle>-0     [043] ..s2   489.511630: clocksource_watchdog:                       'hpet' wd_now: a1cbfa1a wd_last: ed7acfe mask: ffffffff
          <idle>-0     [043] ..s2   489.511630: clocksource_watchdog:                       'tsc' cs_now: 1c24ee60f22 cs_last: 167a92e836f mask: ffffffffffffffff