Wall-Clock-Time-Jump after migration [xen-4.1]

Wall-Clock-Time-Jump after migration [xen-4.1]

[Philipp Hahn]

Hello,

I'm trying to understand Xens implementation of (wall-)clock time and
observed a strange behaviour:

Summary: When a Linux-PV-domU is migrated between two hosts, the
"ntpdate" time jumps.

Environment: xen-4.1 with linux-3.2 and linux-3.10, ntpdate running in
all dom[0U].

1. If I start a new domU (just kernel and InitRamFS with busybox as to
minimize the processes involved), the wall-clock-time if off by ~283
(=4m43s) seconds:

dom0: Tue Deb 16 14:48:12 UTC 2016 (before starting domU)
domU: Tue Feb 16 14:43:32 UTC 2016 (after boot, which takes ~3s)

If I then run "ntpdate" that domU, the offset is corrected:
> 16 Feb 14:51:59 ntpdate[150]: step time server X.X.73.241 offset 283.697217 sec


Q: Where does the initial time for the domU come from?

As a PV domain the domU does not have /dev/rtc and ntpdate hasn't been
run yet, so the time is what the domU got from Xen, I guess.


Q: Where does that offset of ~283s come from?

From reading the Xen source code I guess it was the error of the RTC
clock of the dom0, when the host was booted. The dom0 uses NTP to
correct its time, but that difference never got re-applied back to the
hypervisor.
My understanding is, that the Hypervisor initialized its time from the
RTC and changing the time in dom0 only updates the delta between the
Hypervisor-clock and the dom0 (struct domain.time_offset_seconds), but
not the Hypervisor-clock itself, which keeps counting seconds since
boot. As each domX hat its own "time_offset_seconds", each new domU is
still off by that initial delta.
> # hwclock --show                                                                                                                                                                                          
> Di 16 Feb 2016 16:32:46 CET  -0.203211 seconds



Q: Is the shard_info.wc_sec supposed to be updated?

I used `xm dump-core domU` and `readelf -x .xen_shared_info core` to get
the content from "stuct whared_info -> wc_sec" of the domU:
> 0x00000c00 02000000 d10dc654 edc99a3b

Using offsetof() and big-endian to little-endian I get:
> LANG=C TZ=UTC date -d @$((0x54c60dd1))
> Mon Jan 26 09:50:09 UTC 2015

Adding the uptime of that system of ~1 year I nearly get now():
> # LANG=C TZ=UTC date -d @$((0x54c60dd1+$(cut -c1-8 /proc/uptime)));LANG=C TZ=UTC date
> Tue Feb 16 15:04:16 UTC 2016
> Tue Feb 16 15:04:37 UTC 2016

To me that looks like its the time of boot, but not the current
wall-clock time. Did I do something wrong or what do I misunderstand?


2. If I repeat the same steps with starting the domU on my second host,
I do get different offsets:
dom0: Tue Feb 16 15:10:55 UTC 2016 (before starting domU)
domU: Tue Feb 16 15:10:33 UTC 2016 (after boot taking ~3s)

The delta is ~22s, which ntpdate confirms:
> 16 Feb 15:13:06 ntpdate[149]: step time server X.X.73.241 offset 26.009473 sec

> # hwclock --show                                                                                                                                                                                              
> Di 16 Feb 2016 16:32:42 CET  -0.916229 seconds



3. If I migrate the domain from the first host to the second while
running "ntpdate" in a loop, I see the clock jumping ~257s, which
matches the difference between the time_offset_seconds between the hosts
(283 - 22):
> 16 Feb 15:21:17 ntpdate[154]: adjust time server X.X.73.241 offset 0.000546 sec
> 16 Feb 15:17:07 ntpdate[155]: step time server X.X.73.241 offset -257.532775 sec
> 16 Feb 15:17:15 ntpdate[156]: adjust time server X.X.73.241 offset -0.000493 sec
> 16 Feb 15:17:24 ntpdate[157]: adjust time server X.X.73.241 offset 0.000374 sec
> 16 Feb 15:17:32 ntpdate[158]: adjust time server X.X.73.241 offset 0.000010 sec
> 16 Feb 15:17:40 ntpdate[159]: adjust time server X.X.73.241 offset 0.000170 sec
> 16 Feb 15:17:48 ntpdate[160]: adjust time server X.X.73.241 offset 0.000269 sec
> 16 Feb 15:17:56 ntpdate[161]: adjust time server X.X.73.241 offset -0.000194 sec
> 16 Feb 15:18:04 ntpdate[162]: adjust time server X.X.73.241 offset 0.000287 sec
> 16 Feb 15:18:12 ntpdate[163]: adjust time server X.X.73.241 offset 0.000146 sec

To me that looks like "time_offset_seconds" is migrated, but as "wc_sec"
between the two hosts is not synchronized, the time jumps.

Q: Is that a known problem and has it been fixed in newer versions of Xen?


Q: Is there some recommended procedure to synchronize the time of
multiple hypervisors, like perhaps:
  1. boot xen once
  2. correct time using NTP
  3. write time to RTC
  4. reboot the hypervisor so it can read the corrected RTC
  5. onyl now start domUs and migrate them


Correct wall-clock time is essential, so I'm looking for a stable
solution to have correct wall-clock-time in our domUs. The jump of
several seconds is unacceptable and NTPd would take to long to slew that
clock back to reality. That's why we're using ntpdate, as we want to go
back to real-time as fast as possible.


Thanks in advance.

Philipp Hahn
-- 
Philipp Hahn
Open Source Software Engineer

Univention GmbH
be open.
Mary-Somerville-Str. 1
D-28359 Bremen
Tel.: +49 421 22232-0
Fax : +49 421 22232-99
hahn@univention.de

http://www.univention.de/
Geschäftsführer: Peter H. Ganten
HRB 20755 Amtsgericht Bremen
Steuer-Nr.: 71-597-02876

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
http://lists.xen.org/xen-devel

Re: Wall-Clock-Time-Jump after migration [xen-4.1]

[David Vrabel]

On 16/02/16 15:38, Philipp Hahn wrote:
> Hello,
> 
> I'm trying to understand Xens implementation of (wall-)clock time and
> observed a strange behaviour:
> 
> Summary: When a Linux-PV-domU is migrated between two hosts, the
> "ntpdate" time jumps.
> 
> Environment: xen-4.1 with linux-3.2 and linux-3.10, ntpdate running in
> all dom[0U].

You might need the following commits in your dom0 kernel, all of which
are in 3.11 and later.

3565184ed0c1ea46bea5b792da5f72a83c43e49b
7c4c3a0f18ba57ea2a2985034532303d2929902a
0eb071651474952c8b6daecd36b378e2d01be22c
04397fe94ad65289884b9862b6a0c722ececaadf
780427f0e113b4c77dfff4d258c05a902cdb0eb9
5584880e44e49c587059801faa2a9f7d22619c48
47433b8c9d7480a3eebd99df38e857ce85a37cee

David

Re: Wall-Clock-Time-Jump after migration [xen-4.1] [SOLVED]

[Philipp Hahn]

Hello,

to answer my own questions:

Am 16.02.2016 um 16:38 schrieb Philipp Hahn:
> Summary: When a Linux-PV-domU is migrated between two hosts, the
> "ntpdate" time jumps.
...
> 1. If I start a new domU (just kernel and InitRamFS with busybox as to
> minimize the processes involved), the wall-clock-time if off by ~283
> (=4m43s) seconds:
> 
> dom0: Tue Deb 16 14:48:12 UTC 2016 (before starting domU)
> domU: Tue Feb 16 14:43:32 UTC 2016 (after boot, which takes ~3s)
> 
> If I then run "ntpdate" that domU, the offset is corrected:
>> 16 Feb 14:51:59 ntpdate[150]: step time server X.X.73.241 offset 283.697217 sec
> 
> Q: Where does the initial time for the domU come from?

Wall-clock (WC) from Xen Hypervisor.

> Q: Where does that offset of ~283s come from?

The Hypervisor reads the HW-RTC once on boot to initialize its WC.
When the dom0 runs ntpdate, only "time_offset_seconds" get updated, so
dom0-WC is correct, but any new domU starts with "time_offset_seconds=0"
again and is off by that initial difference again.
You could reboot the Hypervisor, so it could read the corrected RTC
after calling 'hwclock --systohc'.

> Q: Is the shard_info.wc_sec supposed to be updated?

No: "wc_set" is more-or-less constant.
The current time is calculated by adding "wc_set + tsc_to_sec()",  so
"wc_set" is the offset calculated from "wc_time@boot" - tsc@boot()".

'wc_sec' can be updated through "XENPF_settime".

> 3. If I migrate the domain from the first host to the second while
> running "ntpdate" in a loop, I see the clock jumping ~257s, which
> matches the difference between the time_offset_seconds between the hosts
> (283 - 22):
...
> To me that looks like "time_offset_seconds" is migrated, but as "wc_sec"
> between the two hosts is not synchronized, the time jumps.
> 
> Q: Is that a known problem and has it been fixed in newer versions of Xen?

The Linux kernel has a hook to call XENPF_settime from its
"update-RTC-every-11-minutes" (sync_cmos_work) work queue, but the code
path is disabled when the time is *not* NTP-synchronized:

> kernel/time/ntp.c:454
> »···static void sync_cmos_clock(struct work_struct *work)
> »···»···if (!ntp_synced()) {

> Q: Is there some recommended procedure to synchronize the time of
> multiple hypervisors, like perhaps:

Run "ntpd" in dom0 instead of "ntpdate":
Then ntp_synced() returns True, x86_platform.set_wallclock() gets called
to update the Hypervisor wall-time clock using XENPF_settime{32,64},
then every new domU will get a reasonably correct wall-time-clock on
domain creation, ...

You can check the status of "time_status" calling "ntptime":
> # ntptime 
...
> ntp_adjtime() returns code 5 (ERROR)
...
>   status 0x2041 (PLL,UNSYNC,NANO),

It's a bit-filed; if UNSYNC=0x40 is set, Xens WC will not get updated.


@David: Thank you for looking into that and sending the list of commits.
It helped me to get a better understanding of the interaction between
the Linux dom0 and Xen Hypervisor.


Thank you for the adventure; I hope that info helps others to get it
right from the beginning.


Philipp Hahn

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
http://lists.xen.org/xen-devel