Re: Skylake (XPS 13 9350) TSC is way off

[Andy Lutomirski <luto@kernel.org>]

[cc: John Stultz]

On Wed, Dec 2, 2015 at 2:52 PM, Brown, Len <len.brown@intel.com> 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 <lenb@kernel.org>
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