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

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

On 27/02/14 17:50, Andrew Cooper wrote:
> 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

And indeed, stashing the TSC in head.S result in:

(XEN) [    0.000000] IRQ limits: 24 GSI, 376 MSI/MSI-X
(XEN) [    0.000000] Using scheduler: SMP Credit Scheduler (credit)
(XEN) [    1.013174] Detected 2793.250 MHz processor.
(XEN) [    1.018377] Initing memory sharing.
(XEN) [    1.022601] Cannot set CPU feature mask on CPU#0
(XEN) [    1.027950] mce_intel.c:717: MCA Capability: BCAST 0 SER 0 CMCI
0 firstbank 0 extended MCE MSR 18
(XEN) [    1.037785] Intel machine check reporting enabled
(XEN) [    1.043245] PCI: MCFG configuration 0: base e0000000 segment
0000 buses 00 - 3f
(XEN) [    1.051509] PCI: MCFG area at e0000000 reserved in E820
(XEN) [    1.057471] PCI: Using MCFG for segment 0000 bus 00-3f
(XEN) [    1.063340] I/O virtualisation disabled
(XEN) [    1.068198] ENABLING IO-APIC IRQs
(XEN) [    1.072241]  -> Using new ACK method
(XEN) [    1.076706] ..TIMER: vector=0xF0 apic1=0 pin1=2 apic2=-1 pin2=-1
(XEN) [    0.470790] Platform timer is 14.318MHz HPET
(XEN) [    0.475474] Allocated console ring of 16 KiB.

Which is a rather more accurate time-since-boot, until the the platform
timer starts up and steps time backwards.

~Andrew