[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

RE: [Xen-devel] Kernel printk timestamps and walltime drift

  • To: "Keir Fraser" <keir.fraser@xxxxxxxxxxxxx>, "xen-devel" <xen-devel@xxxxxxxxxxxxxxxxxxx>
  • From: "Roger Cruz" <rcruz@xxxxxxxxxxxxxxxxxxxxxxxx>
  • Date: Fri, 13 Jun 2008 16:10:48 -0400
  • Delivery-date: Fri, 13 Jun 2008 13:11:11 -0700
  • List-id: Xen developer discussion <xen-devel.lists.xensource.com>
  • Thread-index: AcjM0Rhtsp0FqzEJQH+pTArFmFSulQACI1i0ACgZ8YAAApu8UAACeOCZAABf+DA=
  • Thread-topic: [Xen-devel] Kernel printk timestamps and walltime drift

Hi Keir,

Thanks for taking the time to answer my question.

I do not know how the kernel times are getting computed exactly.  This
is an area of Linux which I'm not very familiar with.  

Prior to my test on the reference debian VM, I performed exactly the
same test on a Linux VM we build based on the Citrix-provided Linux
2.6.18 sources (my understanding is that these are the sources dom0 is
using, correct me if wrong) and saw the same drift.  That's why I
decided to do a test on a reference VM to make sure it was not caused by
our own VM.

When I looked at the Linux 2.6.18 sources to try to track down how these
times are computed, I found the following for an x86, 32-bit platform...

MtcAbsDbgPrint -> vprintk -> printk_clock  -> sched_clock -> rdtscll

MtcAbsTimeGetTimestampGmt -> current_kernel_time -> return timespec
variable "xtime"
"xtime" is in UTC and I believe it's updated as a result of the timer
interrupt in the sequence below

do_timer_interrupt_hook-> do_timer-> update_times  ->update_wall_time ->
updates "xtime"

Note that I'm not 100% of these call sequences since they were derived
by looking at the sources and not tracing it with any debugger.  This is
how I came to conclude that the kernel timestamps (generated as a result
of us calling vprintk) are derived from the RDTSC instruction.  It is my
understanding that the TSC values are derived by the hypervisor from the
actual CPU register and some computed offset.  I have yet to examine
this code myself.

The walltime appears to be generated from periodic timer ticks that
update "xtime".  These values have always been correct.  Only the ones
that get generated with the vprintk appear to slip when compared to this
wall time.


-----Original Message-----
From: Keir Fraser [mailto:keir.fraser@xxxxxxxxxxxxx] 
Sent: Friday, June 13, 2008 3:48 PM
To: Roger Cruz; xen-devel
Subject: Re: [Xen-devel] Kernel printk timestamps and walltime drift

On 13/6/08 19:49, "Roger Cruz" <rcruz@xxxxxxxxxxxxxxxxxxxxxxxx> wrote:

> You can see that the kernel time in the brackets (host up time in
> seconds) should have given us a difference of 3600 seconds when ran
> an hr period. I, however, got 3592.770286, a slip of  7+ seconds.
> ran a similar experiment and over the course of 12hrs, the kernel
> timestamps lose 97 seconds!
> So unless I'm misunderstanding the printk times, the problem is either
> with the way the Linux OS converts TSC cycles to seconds not being
> accurate  OR how the hypervisor feeds the VM-ified TSC counts to the
> guest VM. 
> Note that I'm sure the walltime was correct as I could monitor the
> printed walltime against an atomic clock in another window and it
> matched (within the precision of my eyes moving back and forth, of
> course).

Do you know how the Debian kernel is computing its kernel-log

One possibility here is that Xen system time is running at a slightly
different rate from wallclock (because the platform timer (PIT, HPET,
is not running at exactly its stated frequency) and ntp running in dom0
keeps Xen's wallclock reference in sync -- it does not affect Xen's
time. If the Debian kernel were perhaps based on jiffies rather than
I think that might explain the drift.

This hypothesis would require Xen's system time to be drifting at around
2000ppm, which is not great. I would expect a platform timer to be
within a
few 100ppm of its advertised frequency, really (and with jitter of much
than 10ppm).

 -- Keir

Xen-devel mailing list



Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.