Re: [PATCH 2/2] [RFC] xen/console: Provide timestamps as an offset since boot.

[Andrew Cooper <andrew.cooper3@citrix.com>]

On 27/02/14 16:21, Tim Deegan wrote:
> At 14:03 +0000 on 27 Feb (1393506187), Andrew Cooper wrote:
>> Some latent bugs are emphasised by these changes.  There are steps in time
>> when the TSC scale is calculated, and when the platform time is initialised ...
>>
>>     (XEN) [    0.000000] Using scheduler: SMP Credit Scheduler (credit)
>>     (XEN) [   27.553075] Detected 2793.232 MHz processor.
>>     (XEN) [   27.558277] Initing memory sharing.
>>     (XEN) [   27.562502] Cannot set CPU feature mask on CPU#0
>>     (XEN) [   27.567852] mce_intel.c:717: MCA Capability: BCAST 0 SER 0 CMCI 0 firstbank 0 extended MCE MSR 18
>>     (XEN) [   27.577687] Intel machine check reporting enabled
>>     (XEN) [   27.583147] PCI: MCFG configuration 0: base e0000000 segment 0000 buses 00 - 3f
>>     (XEN) [   27.591407] PCI: MCFG area at e0000000 reserved in E820
>>     (XEN) [   27.597369] PCI: Using MCFG for segment 0000 bus 00-3f
>>     (XEN) [   27.603238] I/O virtualisation disabled
>>     (XEN) [   27.608093] ENABLING IO-APIC IRQs
>>     (XEN) [   27.612136]  -> Using new ACK method
>>     (XEN) [   27.616601] ..TIMER: vector=0xF0 apic1=0 pin1=2 apic2=-1 pin2=-1
>>     (XEN) [    0.153431] Platform timer is 14.318MHz HPET
> The patch below fixes the first step for me.  I haven't been able to
> understand the exact mechanism of the second one yet.  With this patch
> applied, of course, the second step is not visible -- which doesn't
> mean it's gone away.
>
> Cheers,
>
> Tim.
>
> commit d986516ce297bbcf3181225105dbc67edfa7c37e
> Author: Tim Deegan <tim@xen.org>
> Date:   Thu Feb 27 16:17:02 2014 +0000
>
>     x86/time: Always count s_time from Xen boot.
>     
>     In the early-boot clock, before the calibration routines kick in,
>     count time from Xen boot rather than from when the BSP's TSC was 0.
>     
>     Signed-off-by: Tim Deegan <tim@xen.org>

This does indeed fix the first step, although I will continue debugging
the second without this present.

However, as a time from boot, it would make more sense for the beginning
of __start_xen() (or even in the early asm code) to stash the TSC value
sideways.  I will see how easy this is to do.

~Andrew

>
> diff --git a/xen/arch/x86/time.c b/xen/arch/x86/time.c
> index 82492c1..2bc2b2d 100644
> --- a/xen/arch/x86/time.c
> +++ b/xen/arch/x86/time.c
> @@ -1456,6 +1456,7 @@ void __init early_time_init(void)
>      u64 tmp = init_pit_and_calibrate_tsc();
>  
>      set_time_scale(&this_cpu(cpu_time).tsc_scale, tmp);
> +    rdtscll(this_cpu(cpu_time).local_tsc_stamp);
>  
>      do_div(tmp, 1000);
>      cpu_khz = (unsigned long)tmp;
>