2015-12-02 20:07:19

by Andy Lutomirski

[permalink] [raw]
Subject: Skylake (XPS 13 9350) TSC is way off

[ 0.000000] tsc: PIT calibration matches HPET. 2 loops
[ 0.000000] tsc: Detected 2399.975 MHz processor
[ 0.090897] TSC deadline timer enabled
[ 1.960034] tsc: Refined TSC clocksource calibration: 2400.007 MHz
[ 1.960039] clocksource: tsc: mask: 0xffffffffffffffff max_cycles:
0x22983e30402, max_idle_ns: 440795260848 ns
[ 2.959936] clocksource: Switched to clocksource tsc
[ 87.168211] Adjusting tsc more than 11% (5941981 vs 7759439)

This is more or less Linus' latest tree (v4.4-rc3 plus some unrelated
platform driver patches).

--Andy


2015-12-02 22:53:04

by Brown, Len

[permalink] [raw]
Subject: RE: Skylake (XPS 13 9350) TSC is way off

+adrian

> [ 0.000000] tsc: PIT calibration matches HPET. 2 loops
> [ 0.000000] tsc: Detected 2399.975 MHz processor
> [ 0.090897] TSC deadline timer enabled
> [ 1.960034] tsc: Refined TSC clocksource calibration: 2400.007 MHz
> [ 1.960039] clocksource: tsc: mask: 0xffffffffffffffff max_cycles:
> 0x22983e30402, max_idle_ns: 440795260848 ns
> [ 2.959936] clocksource: Switched to clocksource tsc
> [ 87.168211] Adjusting tsc more than 11% (5941981 vs 7759439)
>
> This is more or less Linus' latest tree (v4.4-rc3 plus some unrelated
> platform driver patches).

Hi Andy,
Thanks for the note.
I'll send you a debug version of turbostat, off list,
since the list will just block mail with that attachment.

thanks,
-Len

????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay?ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?

2015-12-02 23:26:00

by Andy Lutomirski

[permalink] [raw]
Subject: Re: Skylake (XPS 13 9350) TSC is way off

[cc: John Stultz]

On Wed, Dec 2, 2015 at 2:52 PM, Brown, Len <[email protected]> wrote:
> +adrian
>
>> [ 0.000000] tsc: PIT calibration matches HPET. 2 loops
>> [ 0.000000] tsc: Detected 2399.975 MHz processor
>> [ 0.090897] TSC deadline timer enabled
>> [ 1.960034] tsc: Refined TSC clocksource calibration: 2400.007 MHz
>> [ 1.960039] clocksource: tsc: mask: 0xffffffffffffffff max_cycles:
>> 0x22983e30402, max_idle_ns: 440795260848 ns
>> [ 2.959936] clocksource: Switched to clocksource tsc
>> [ 87.168211] Adjusting tsc more than 11% (5941981 vs 7759439)
>>
>> This is more or less Linus' latest tree (v4.4-rc3 plus some unrelated
>> platform driver patches).
>
> Hi Andy,
> Thanks for the note.
> I'll send you a debug version of turbostat, off list,
> since the list will just block mail with that attachment.

turbostat version 4.10 10 Dec, 2015 - Len Brown <[email protected]>
CPUID(0): GenuineIntel 22 CPUID levels; family:model:stepping 0x6:4e:3 (6:78:3)
CPUID(1): SSE3 MONITOR EIST TM2 TSC MSR ACPI-TM TM
CPUID(6): APERF, DTS, PTM, HWP, HWPnotify, HWPwindow, HWPepp, No-HWPpkg, EPB
cpu1: MSR_IA32_MISC_ENABLE: 0x00850089 (TCC EIST MONITOR)
CPUID(0x15): eax_crystal: 2 ebx_tsc: 200 ecx_crystal_hz: 0
TSC: 2400 MHz (24000000 Hz * 200 / 2 / 1000000)
CPUID(0x16): base_mhz: 2400 max_mhz: 2800 bus_mhz: 100
RAPL: 17476 sec. Joule Counter Range, at 15 Watts
cpu1: MSR_PLATFORM_INFO: 0x4043df1011800
4 * 100 = 400 MHz max efficiency frequency
24 * 100 = 2400 MHz base frequency
cpu1: MSR_IA32_POWER_CTL: 0x0024005d (C1E auto-promotion: DISabled)
cpu1: MSR_TURBO_RATIO_LIMIT: 0x1b1b1b1c
27 * 100 = 2700 MHz max turbo 4 active cores
27 * 100 = 2700 MHz max turbo 3 active cores
27 * 100 = 2700 MHz max turbo 2 active cores
28 * 100 = 2800 MHz max turbo 1 active cores
cpu1: MSR_CONFIG_TDP_NOMINAL: 0x00000017 (base_ratio=7)
cpu1: MSR_CONFIG_TDP_LEVEL_1: 0x0008003c (PKG_MIN_PWR_LVL1=0
PKG_MAX_PWR_LVL1=0 LVL1_RATIO=8 PKG_TDP_LVL1=60)
cpu1: MSR_CONFIG_TDP_LEVEL_2: 0x001800c8 (PKG_MIN_PWR_LVL2=0
PKG_MAX_PWR_LVL2=0 LVL2_RATIO=8 PKG_TDP_LVL2=200)
cpu1: MSR_CONFIG_TDP_CONTROL: 0x00000000 ( lock=0)
cpu1: MSR_TURBO_ACTIVATION_RATIO: 0x00000000 (MAX_NON_TURBO_RATIO=0 lock=0)
cpu1: MSR_NHM_SNB_PKG_CST_CFG_CTL: 0x1e008006 (UNdemote-C3,
UNdemote-C1, demote-C3, demote-C1, locked: pkg-cstate-limit=6: pc8)
cpu0: MSR_PM_ENABLE: 0x00000001 (HWP)
cpu0: MSR_HWP_CAPABILITIES: 0x0105171c (high 0x1c guar 0x17 eff 0x5 low 0x1)
cpu0: MSR_HWP_REQUEST: 0x80001c04 (min 0x4 max 0x1c des 0x0 epp 0x80
window 0x0 pkg 0x0)
cpu0: MSR_HWP_INTERRUPT: 0x00000001 (EN_Guaranteed_Perf_Change,
Dis_Excursion_Min)
cpu0: MSR_HWP_STATUS: 0x00000000 (No-Guaranteed_Perf_Change, No-Excursion_Min)
cpu0: MSR_IA32_ENERGY_PERF_BIAS: 0x00000006 (balanced)
cpu0: MSR_RAPL_POWER_UNIT: 0x000a0e03 (0.125000 Watts, 0.000061
Joules, 0.000977 sec.)
cpu0: MSR_PKG_POWER_INFO: 0x00000078 (15 W TDP, RAPL 0 - 0 W, 0.000000 sec.)
cpu0: MSR_PKG_POWER_LIMIT: 0x4280c800dd8078 (UNlocked)
cpu0: PKG Limit #1: ENabled (15.000000 Watts, 28.000000 sec, clamp ENabled)
cpu0: PKG Limit #2: ENabled (25.000000 Watts, 0.002441* sec, clamp DISabled)
cpu0: MSR_DRAM_POWER_LIMIT: 0x5400de00000000 (UNlocked)
cpu0: DRAM Limit: DISabled (0.000000 Watts, 0.000977 sec, clamp DISabled)
cpu0: MSR_IA32_TEMPERATURE_TARGET: 0x00640000 (100 C)
cpu0: MSR_IA32_PACKAGE_THERM_STATUS: 0x88340800 (48 C)
cpu0: MSR_IA32_THERM_STATUS: 0x88350800 (47 C +/- 1)
cpu1: MSR_IA32_THERM_STATUS: 0x88340800 (48 C +/- 1)
Core CPU Avg_MHz %Busy Bzy_MHz TSC_MHz SMI CPU%c1
CPU%c3 CPU%c6 CPU%c7 CoreTmp PkgTmp Totl%C0 Any%C0 GFX%C0 CPUGFX%
Pkg%pc2 Pkg%pc3 Pkg%pc6 Pkg%pc7 Pkg%pc8 Pkg%pc9 Pk%pc10 PkgWatt
RAMWatt PKG_% RAM_%
- - 16 2.84 549 2399 0 4.13
0.02 0.63 92.39 46 46 12.21 10.77 2.48 0.80
14.33 71.53 0.00 0.00 0.00 0.00 0.00 1.95 0.54
0.00 0.00
0 0 11 1.92 563 2399 0 2.48
0.02 0.80 94.78 46 46 12.21 10.78 2.48 0.80
14.34 71.55 0.00 0.00 0.00 0.00 0.00 1.95 0.54
0.00 0.00
0 2 8 1.39 550 2399 0 3.04
1 1 13 2.04 622 2400 0 7.48
0.02 0.45 90.01 45
1 3 31 6.01 520 2400 0 3.51
1.002561 sec

In case it's at all useful, adjtimex -p says:

mode: 0
offset: 0
frequency: 135641
maxerror: 37498
esterror: 1532
status: 8192
time_constant: 2
precision: 1
tolerance: 32768000
tick: 10000
raw time: 1449098317s 671243180us = 1449098317.671243180

this suggests a rather small correction, so I really have no idea what
"Adjusting tsc more than 11% (8039115 vs 7759462)" means.

John, you wrote this code. What does the error message mean?

--Andy

2015-12-02 23:38:39

by John Stultz

[permalink] [raw]
Subject: Re: Skylake (XPS 13 9350) TSC is way off

On Wed, Dec 2, 2015 at 3:25 PM, Andy Lutomirski <[email protected]> wrote:
> In case it's at all useful, adjtimex -p says:
>
> mode: 0
> offset: 0
> frequency: 135641
> maxerror: 37498
> esterror: 1532
> status: 8192
> time_constant: 2
> precision: 1
> tolerance: 32768000
> tick: 10000
> raw time: 1449098317s 671243180us = 1449098317.671243180
>
> this suggests a rather small correction, so I really have no idea what
> "Adjusting tsc more than 11% (8039115 vs 7759462)" means.
>
> John, you wrote this code. What does the error message mean?

Basally the internal correction adjustments are getting pulled further
then it is supposed to (its concerning since in some cases we push the
clocksource mult value to be quite large, and so making a large
adjustment could possibly cause an overflow).

Awhile back I had intended to cap the max adjustment, but out of
caution I put in a warning instead to see how often this might occur.

I've seen it reported sometimes while folks were running trinity or
under a VM (suggesting that due to system delays timekeeping
management may have been delayed and the internal time error had grown
quite far, so the internal correction was being somewhat aggressive).
Though more recently (3.17 era) we've changed the internal adjustment
code to try to be more conservative to avoid over-steering w/ NOHZ, so
I'd expect fewer of these.

On a hunch, are you running chrony instead of ntpd?

thanks
-john

2015-12-02 23:42:25

by Andy Lutomirski

[permalink] [raw]
Subject: Re: Skylake (XPS 13 9350) TSC is way off

On Wed, Dec 2, 2015 at 3:38 PM, John Stultz <[email protected]> wrote:
> On Wed, Dec 2, 2015 at 3:25 PM, Andy Lutomirski <[email protected]> wrote:
>> In case it's at all useful, adjtimex -p says:
>>
>> mode: 0
>> offset: 0
>> frequency: 135641
>> maxerror: 37498
>> esterror: 1532
>> status: 8192
>> time_constant: 2
>> precision: 1
>> tolerance: 32768000
>> tick: 10000
>> raw time: 1449098317s 671243180us = 1449098317.671243180
>>
>> this suggests a rather small correction, so I really have no idea what
>> "Adjusting tsc more than 11% (8039115 vs 7759462)" means.
>>
>> John, you wrote this code. What does the error message mean?
>
> Basally the internal correction adjustments are getting pulled further
> then it is supposed to (its concerning since in some cases we push the
> clocksource mult value to be quite large, and so making a large
> adjustment could possibly cause an overflow).
>
> Awhile back I had intended to cap the max adjustment, but out of
> caution I put in a warning instead to see how often this might occur.
>
> I've seen it reported sometimes while folks were running trinity or
> under a VM (suggesting that due to system delays timekeeping
> management may have been delayed and the internal time error had grown
> quite far, so the internal correction was being somewhat aggressive).
> Though more recently (3.17 era) we've changed the internal adjustment
> code to try to be more conservative to avoid over-steering w/ NOHZ, so
> I'd expect fewer of these.
>

The trouble for me is that it's not clear from the message what rate
doesn't agree with what rate (kernel's unadjusted rate vs adjtimex's
request?), and the units are incomprehensible. If the issue is that
adjtimex(2) has asked for X PPM of adjustment and X is greater than Y,
could we display that directly?

> On a hunch, are you running chrony instead of ntpd?

Yes, this is indeed chrony.

--Andy

2015-12-02 23:42:36

by John Stultz

[permalink] [raw]
Subject: Re: Skylake (XPS 13 9350) TSC is way off

On Wed, Dec 2, 2015 at 3:38 PM, John Stultz <[email protected]> wrote:
> On Wed, Dec 2, 2015 at 3:25 PM, Andy Lutomirski <[email protected]> wrote:
>> In case it's at all useful, adjtimex -p says:
>>
>> mode: 0
>> offset: 0
>> frequency: 135641
>> maxerror: 37498
>> esterror: 1532
>> status: 8192
>> time_constant: 2
>> precision: 1
>> tolerance: 32768000
>> tick: 10000
>> raw time: 1449098317s 671243180us = 1449098317.671243180
>>
>> this suggests a rather small correction, so I really have no idea what
>> "Adjusting tsc more than 11% (8039115 vs 7759462)" means.
>>
>> John, you wrote this code. What does the error message mean?

Also, is there a behavior issue you're seeing or is this just a
concern about the warning? I assumed it was the first, but digging up
the thread here I'm not sure I see any specific problems listed.

thanks
-john

2015-12-02 23:55:13

by John Stultz

[permalink] [raw]
Subject: Re: Skylake (XPS 13 9350) TSC is way off

On Wed, Dec 2, 2015 at 3:42 PM, Andy Lutomirski <[email protected]> wrote:
> On Wed, Dec 2, 2015 at 3:38 PM, John Stultz <[email protected]> wrote:
>> On Wed, Dec 2, 2015 at 3:25 PM, Andy Lutomirski <[email protected]> wrote:
>>> In case it's at all useful, adjtimex -p says:
>>>
>>> mode: 0
>>> offset: 0
>>> frequency: 135641
>>> maxerror: 37498
>>> esterror: 1532
>>> status: 8192
>>> time_constant: 2
>>> precision: 1
>>> tolerance: 32768000
>>> tick: 10000
>>> raw time: 1449098317s 671243180us = 1449098317.671243180
>>>
>>> this suggests a rather small correction, so I really have no idea what
>>> "Adjusting tsc more than 11% (8039115 vs 7759462)" means.
>>>
>>> John, you wrote this code. What does the error message mean?
>>
>> Basally the internal correction adjustments are getting pulled further
>> then it is supposed to (its concerning since in some cases we push the
>> clocksource mult value to be quite large, and so making a large
>> adjustment could possibly cause an overflow).
>>
>> Awhile back I had intended to cap the max adjustment, but out of
>> caution I put in a warning instead to see how often this might occur.
>>
>> I've seen it reported sometimes while folks were running trinity or
>> under a VM (suggesting that due to system delays timekeeping
>> management may have been delayed and the internal time error had grown
>> quite far, so the internal correction was being somewhat aggressive).
>> Though more recently (3.17 era) we've changed the internal adjustment
>> code to try to be more conservative to avoid over-steering w/ NOHZ, so
>> I'd expect fewer of these.
>>
>
> The trouble for me is that it's not clear from the message what rate
> doesn't agree with what rate (kernel's unadjusted rate vs adjtimex's
> request?), and the units are incomprehensible. If the issue is that
> adjtimex(2) has asked for X PPM of adjustment and X is greater than Y,
> could we display that directly?

Sorry, yes, its the clocksource adjusted mult vs original mult values.

And its having to do with the internal correction (ie, what we've
actually done) logic, not the adjtimex requested adjustment (what we
were asked to do).

>> On a hunch, are you running chrony instead of ntpd?
>
> Yes, this is indeed chrony.

Ok. I'll have to look closer. The last time that message came up it
was in a report of a bug that chrony uncovered with the internal
correction being too slow. I know chrony is much more aggressive
compared to ntpd in tweaking the freq value for the initial converging
correction at startup, so maybe that along with something else is
causing us to get out of spec.

>From the values I see in the message, it looks like you're not
overflowing mult, and the smallish freq value from adjtimex you're
seeing now look fine, so I suspect you're not actually hitting a
problem, but we're momentarily outside what the code is designed for.

Still need to figure out why and fix that, of course. :)

thanks
-john

2015-12-02 23:59:52

by Andy Lutomirski

[permalink] [raw]
Subject: Re: Skylake (XPS 13 9350) TSC is way off

On Wed, Dec 2, 2015 at 3:42 PM, John Stultz <[email protected]> wrote:
> On Wed, Dec 2, 2015 at 3:38 PM, John Stultz <[email protected]> wrote:
>> On Wed, Dec 2, 2015 at 3:25 PM, Andy Lutomirski <[email protected]> wrote:
>>> In case it's at all useful, adjtimex -p says:
>>>
>>> mode: 0
>>> offset: 0
>>> frequency: 135641
>>> maxerror: 37498
>>> esterror: 1532
>>> status: 8192
>>> time_constant: 2
>>> precision: 1
>>> tolerance: 32768000
>>> tick: 10000
>>> raw time: 1449098317s 671243180us = 1449098317.671243180
>>>
>>> this suggests a rather small correction, so I really have no idea what
>>> "Adjusting tsc more than 11% (8039115 vs 7759462)" means.
>>>
>>> John, you wrote this code. What does the error message mean?
>
> Also, is there a behavior issue you're seeing or is this just a
> concern about the warning? I assumed it was the first, but digging up
> the thread here I'm not sure I see any specific problems listed.

No, there's no actual problem I'm aware of other than the error
message. Skylake's TSC is different from other chips, and this is
Skylake, and I was worried that something was wrong with the initial
calibration. It seems like the initial calibration may be fine,
though.

--Andy

2015-12-03 03:25:16

by Brown, Len

[permalink] [raw]
Subject: RE: Skylake (XPS 13 9350) TSC is way off

> >> [ 0.000000] tsc: PIT calibration matches HPET. 2 loops
> >> [ 0.000000] tsc: Detected 2399.975 MHz processor
> >> [ 0.090897] TSC deadline timer enabled
> >> [ 1.960034] tsc: Refined TSC clocksource calibration: 2400.007 MHz

> turbostat version 4.10 10 Dec, 2015 - Len Brown <[email protected]>
> CPUID(0): GenuineIntel 22 CPUID levels; family:model:stepping 0x6:4e:3 (6:78:3)
> CPUID(1): SSE3 MONITOR EIST TM2 TSC MSR ACPI-TM TM
> CPUID(6): APERF, DTS, PTM, HWP, HWPnotify, HWPwindow, HWPepp, No-HWPpkg, EPB
> cpu1: MSR_IA32_MISC_ENABLE: 0x00850089 (TCC EIST MONITOR)
> CPUID(0x15): eax_crystal: 2 ebx_tsc: 200 ecx_crystal_hz: 0
> TSC: 2400 MHz (24000000 Hz * 200 / 2 / 1000000)
> CPUID(0x16): base_mhz: 2400 max_mhz: 2800 bus_mhz: 100


Both the initial and refined TSC calibration are right on the money -- 2400 MHz.
Further, this system happens to also have a base frequency of 2400 MHz,
so tsc_khz = cpu_khz = 2,400,000, exactly. It would stray from that value
only based on the ppm error of the base 24 MHz crystal.

Anything other than that value is error.

-Len

> RAPL: 17476 sec. Joule Counter Range, at 15 Watts
> cpu1: MSR_PLATFORM_INFO: 0x4043df1011800
> 4 * 100 = 400 MHz max efficiency frequency
> 24 * 100 = 2400 MHz base frequency
> cpu1: MSR_IA32_POWER_CTL: 0x0024005d (C1E auto-promotion: DISabled)
> cpu1: MSR_TURBO_RATIO_LIMIT: 0x1b1b1b1c
> 27 * 100 = 2700 MHz max turbo 4 active cores
> 27 * 100 = 2700 MHz max turbo 3 active cores
> 27 * 100 = 2700 MHz max turbo 2 active cores
> 28 * 100 = 2800 MHz max turbo 1 active cores
> cpu1: MSR_CONFIG_TDP_NOMINAL: 0x00000017 (base_ratio=7)
> cpu1: MSR_CONFIG_TDP_LEVEL_1: 0x0008003c (PKG_MIN_PWR_LVL1=0
> PKG_MAX_PWR_LVL1=0 LVL1_RATIO=8 PKG_TDP_LVL1=60)
> cpu1: MSR_CONFIG_TDP_LEVEL_2: 0x001800c8 (PKG_MIN_PWR_LVL2=0
> PKG_MAX_PWR_LVL2=0 LVL2_RATIO=8 PKG_TDP_LVL2=200)
> cpu1: MSR_CONFIG_TDP_CONTROL: 0x00000000 ( lock=0)
> cpu1: MSR_TURBO_ACTIVATION_RATIO: 0x00000000 (MAX_NON_TURBO_RATIO=0
> lock=0)
> cpu1: MSR_NHM_SNB_PKG_CST_CFG_CTL: 0x1e008006 (UNdemote-C3,
> UNdemote-C1, demote-C3, demote-C1, locked: pkg-cstate-limit=6: pc8)
> cpu0: MSR_PM_ENABLE: 0x00000001 (HWP)
> cpu0: MSR_HWP_CAPABILITIES: 0x0105171c (high 0x1c guar 0x17 eff 0x5 low
> 0x1)
> cpu0: MSR_HWP_REQUEST: 0x80001c04 (min 0x4 max 0x1c des 0x0 epp 0x80
> window 0x0 pkg 0x0)
> cpu0: MSR_HWP_INTERRUPT: 0x00000001 (EN_Guaranteed_Perf_Change,
> Dis_Excursion_Min)
> cpu0: MSR_HWP_STATUS: 0x00000000 (No-Guaranteed_Perf_Change, No-
> Excursion_Min)
> cpu0: MSR_IA32_ENERGY_PERF_BIAS: 0x00000006 (balanced)
> cpu0: MSR_RAPL_POWER_UNIT: 0x000a0e03 (0.125000 Watts, 0.000061
> Joules, 0.000977 sec.)
> cpu0: MSR_PKG_POWER_INFO: 0x00000078 (15 W TDP, RAPL 0 - 0 W, 0.000000
> sec.)
> cpu0: MSR_PKG_POWER_LIMIT: 0x4280c800dd8078 (UNlocked)
> cpu0: PKG Limit #1: ENabled (15.000000 Watts, 28.000000 sec, clamp
> ENabled)
> cpu0: PKG Limit #2: ENabled (25.000000 Watts, 0.002441* sec, clamp
> DISabled)
> cpu0: MSR_DRAM_POWER_LIMIT: 0x5400de00000000 (UNlocked)
> cpu0: DRAM Limit: DISabled (0.000000 Watts, 0.000977 sec, clamp DISabled)
> cpu0: MSR_IA32_TEMPERATURE_TARGET: 0x00640000 (100 C)
> cpu0: MSR_IA32_PACKAGE_THERM_STATUS: 0x88340800 (48 C)
> cpu0: MSR_IA32_THERM_STATUS: 0x88350800 (47 C +/- 1)
> cpu1: MSR_IA32_THERM_STATUS: 0x88340800 (48 C +/- 1)
> Core CPU Avg_MHz %Busy Bzy_MHz TSC_MHz SMI CPU%c1
> CPU%c3 CPU%c6 CPU%c7 CoreTmp PkgTmp Totl%C0 Any%C0 GFX%C0 CPUGFX%
> Pkg%pc2 Pkg%pc3 Pkg%pc6 Pkg%pc7 Pkg%pc8 Pkg%pc9 Pk%pc10 PkgWatt
> RAMWatt PKG_% RAM_%
> - - 16 2.84 549 2399 0 4.13
> 0.02 0.63 92.39 46 46 12.21 10.77 2.48 0.80
> 14.33 71.53 0.00 0.00 0.00 0.00 0.00 1.95 0.54
> 0.00 0.00
> 0 0 11 1.92 563 2399 0 2.48
> 0.02 0.80 94.78 46 46 12.21 10.78 2.48 0.80
> 14.34 71.55 0.00 0.00 0.00 0.00 0.00 1.95 0.54
> 0.00 0.00
> 0 2 8 1.39 550 2399 0 3.04
> 1 1 13 2.04 622 2400 0 7.48
> 0.02 0.45 90.01 45
> 1 3 31 6.01 520 2400 0 3.51
> 1.002561 sec
>
> In case it's at all useful, adjtimex -p says:
>
> mode: 0
> offset: 0
> frequency: 135641
> maxerror: 37498
> esterror: 1532
> status: 8192
> time_constant: 2
> precision: 1
> tolerance: 32768000
> tick: 10000
> raw time: 1449098317s 671243180us = 1449098317.671243180
>
> this suggests a rather small correction, so I really have no idea what
> "Adjusting tsc more than 11% (8039115 vs 7759462)" means.
>
> John, you wrote this code. What does the error message mean?
>
> --Andy
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay?ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?

2015-12-21 08:10:14

by Jon Masters

[permalink] [raw]
Subject: Re: Skylake (XPS 13 9350) TSC is way off

On 12/2/15, 6:55 PM, John Stultz wrote:
> On Wed, Dec 2, 2015 at 3:42 PM, Andy Lutomirski <[email protected]> wrote:

>>> On a hunch, are you running chrony instead of ntpd?
>>
>> Yes, this is indeed chrony.
>
> Ok. I'll have to look closer. The last time that message came up it
> was in a report of a bug that chrony uncovered with the internal
> correction being too slow. I know chrony is much more aggressive
> compared to ntpd in tweaking the freq value for the initial converging
> correction at startup, so maybe that along with something else is
> causing us to get out of spec.

Can you copy me on followup? I'm seeing similar behavior with chrony on
recent kernels on a couple of different ARM server prototype systems.

Jon.

2015-12-21 21:56:28

by John Stultz

[permalink] [raw]
Subject: Re: Skylake (XPS 13 9350) TSC is way off

On Mon, Dec 21, 2015 at 12:10 AM, Jon Masters <[email protected]> wrote:
> On 12/2/15, 6:55 PM, John Stultz wrote:
>>
>> On Wed, Dec 2, 2015 at 3:42 PM, Andy Lutomirski <[email protected]> wrote:
>
>
>>>> On a hunch, are you running chrony instead of ntpd?
>>>
>>>
>>> Yes, this is indeed chrony.
>>
>>
>> Ok. I'll have to look closer. The last time that message came up it
>> was in a report of a bug that chrony uncovered with the internal
>> correction being too slow. I know chrony is much more aggressive
>> compared to ntpd in tweaking the freq value for the initial converging
>> correction at startup, so maybe that along with something else is
>> causing us to get out of spec.
>
>
> Can you copy me on followup? I'm seeing similar behavior with chrony on
> recent kernels on a couple of different ARM server prototype systems.

A patch for this just landed in tip/timers/core and is pending for 4.5
http://git.kernel.org/cgit/linux/kernel/git/tip/tip.git/commit/?id=ec02b076ceab63f99e5b3d80fd223d777266c236

thanks
-john