Subject: Re: [PATCH] x86/tsc: RFC: re-synchronize TSCs to boot cpu TSC
To: Thomas Gleixner <tglx@linutronix.de>
References: <1481179042-968-1-git-send-email-sroland@vmware.com>
 <alpine.DEB.2.20.1612080854420.3400@nanos>
 <6194ea73-99dd-ceca-6f8d-e945ca717c75@hispeed.ch>
 <alpine.DEB.2.20.1612090953570.3794@nanos>
Cc: Ingo Molnar <mingo@redhat.com>, "H. Peter Anvin" <hpa@zytor.com>,
        x86@kernel.org, linux-kernel@vger.kernel.org
From: Roland Scheidegger <rscheidegger_lists@hispeed.ch>
Message-ID: <38f3ca77-ce32-d180-106a-e7242c635394@hispeed.ch>
Date: Fri, 9 Dec 2016 17:46:26 +0100
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101
 Thunderbird/45.5.1
MIME-Version: 1.0
In-Reply-To: <alpine.DEB.2.20.1612090953570.3794@nanos>
Content-Type: text/plain; charset=windows-1252
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
Content-Length: 1953
Lines: 61

Am 09.12.2016 um 10:59 schrieb Thomas Gleixner:
> On Fri, 9 Dec 2016, Roland Scheidegger wrote:
>>
>> I saw some system lockups though:
>> When doing a cold boot, this kernel never managed to boot up. The last
>> message seen is:
>> x86: Booting SMP configuration:
>> .... node  #0, CPUs:        #1
> 
> Weird. That really would be interesting to figure out what goes wrong
> there. What bothers me is that we don't see something like this:
> 
>> [    0.172334] TSC ADJUST differs: Reference CPU0: -577421768610 CPU1:
>> -577423766270
> 
> Can you please apply the debug patch below and provide the output ?
Ok, this is the output (minus some typos maybe...):

x86: Booting SMP configuration:
.... node #0, CPUs:     #1
TSC ADJUST: CPU1: -2806491604
TSC source sync 0 -> 1 runs 3
TSC ADJUST differs: Reference CPU0: -2805503200 CPU1: -2806491604
TSC ADJUST synchronize: Reference CPU0: -2805503200 CPU1: -2806491604
TSC target sync skip
TSC source sync skipped

And that's it.


> 
> 
>> [    0.094492] x86: Booting SMP configuration:
>> [    0.094534] .... node  #0, CPUs:        #1
>> [    0.172334] TSC ADJUST differs: Reference CPU0: -577421768610 CPU1:
>> -577423766270
> 
> What on earth is this BIOS doing? That's a couple of minutes back in time.
Looks like that's only after a reset, after a cold boot the numbers are
significantly smaller (1 sec or so?). Though the difference between
these two is nearly a million cycles too, so might be similar between
min and max for all.


> 
> And the difference between the max and min adjust value is 2050932 cycles.
> 
>> Without the patches on cold boot it just was as expected:
>> [    0.093700] x86: Booting SMP configuration:
>> [    0.093737] .... node  #0, CPUs:        #1
>> [    0.174304] TSC synchronization [CPU#0 -> CPU#1]:
>> [    0.174375] Measured 1837188 cycles TSC warp between CPUs, turning
>> off TSC clock.
> 
> Not surprising given the above numbers.
> 

Hope that helps,

Roland