Bug 1148623 - Windows 7 guests reports incorrect time after a cold restart.
Summary: Windows 7 guests reports incorrect time after a cold restart.
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine
Version: 3.2.0
Hardware: All
OS: Linux
high
high
Target Milestone: ---
: 3.5.0
Assignee: Martin Betak
QA Contact: Nisim Simsolo
URL:
Whiteboard: virt
Depends On:
Blocks: 1159849
TreeView+ depends on / blocked
 
Reported: 2014-10-01 22:20 UTC by Bimal Chollera
Modified: 2019-04-28 10:07 UTC (History)
19 users (show)

Fixed In Version: org.ovirt.engine-root-3.5.0-19
Doc Type: Bug Fix
Doc Text:
Previously, the America/New_York time zone was mapped without taking the daylight savings time into account. This would result in the time of virtual machines shifting by one hour on certain dates. Now, the mapping of the America/New_York time zone takes daylight savings time into account.
Clone Of:
: 1159849 (view as bug list)
Environment:
Last Closed: 2015-02-11 18:09:19 UTC
oVirt Team: ---
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Knowledge Base (Solution) 99213 0 None None None Never
Red Hat Product Errata RHSA-2015:0158 0 normal SHIPPED_LIVE Important: Red Hat Enterprise Virtualization Manager 3.5.0 2015-02-11 22:38:50 UTC
oVirt gerrit 34369 0 master MERGED core: Fix mapping of US Eastern Standard Time Zone Never
oVirt gerrit 34604 0 ovirt-engine-3.5 MERGED core: Fix mapping of US Eastern Standard Time Zone Never

Description Bimal Chollera 2014-10-01 22:20:41 UTC
Description of problem:

Windows 7 guest reports incorrect time after a VM restart.

Version-Release number of selected component (if applicable):

RHEV-M: 
3.2.6

RHEV-H: 
6.5 (20140118.1.3.2.el6_5)
vdsm-4.10.2-30.1.el6ev.x86_64
libvirt-0.10.2-29.el6_5.9.x86_64

How reproducible:

This problem is reproducible every following the steps below.

Steps to Reproduce:
1.  Create a new Windows 7 VM with Time Zone - (GMT-05:00) US Eastern Standard Time
2.  Start the VM
3.  Verify the time on the Window and correct if neccesary.
4.  Shutdown or Poweroff the VM.
5.  Start the VM and verify the time.

Actual results:

The time on the Windows 7 VM is not set to correct time.

Expected results:

The time on the VM should correct based on the timezone.

Additional info:

Comment 1 Bimal Chollera 2014-10-01 22:25:45 UTC
Testing on: 3.2.6
==================

Installed a Windows 7 VM.
Time Zone - (GMT-05:00) US Eastern Standard Time
Created a template.
Created a pool.

1.  Windows 7 VM deployed using a template from a pool.
   
    Windows time 3:51pm - // Should be 4:51pm EST
    utc_diff = -18000   
    Windows VM timezone EST

vdsm.log:
---------
'timeOffset': '-18000', 

qemu.log:
---------
-rtc base=2014-10-01T15:49:11,driftfix=slew 


2.  Corrected the time:
    Windows time 4:51pm
    utc_diff =   3521

                                    
3.  Shutdown and Restart the system
    Windows time 9:54pm - // GMT -5
    utc_diff = 3521

vdsm.log:
----------
 'timeOffset': '3521'

qemu.log:
-----------
-rtc base=2014-10-01T21:53:36,driftfix=slew


4.  Corrected the time:
    Windows time 4:55pm
    utc_diff = -18005


5.  Shutdown and Restart the system
    Windows time 3:59pm  - // Should be 4:59 EST
    utc_diff = -18005

vdsm.log:
----------
'timeOffset': '-18005'

qemu.log:
------------
-rtc base=2014-10-01T15:58:16,driftfix=slew

6.  Changed the time 
    Windows time 5:03pm
    utc_diff = 3597

7.  Shutdown and Restart the system
    Windows time 10:06pm
    utc_diff = 3597

vdsm.log:
-----------
'timeOffset': '3597'

qemu.log:
---------
 -rtc base=2014-10-01T22:05:17,driftfix=slew

Comment 3 Bimal Chollera 2014-10-01 22:43:01 UTC
Correction on the RHEV-H libvirt revision.

Should be libvirt-0.10.2-29.el6_5.7.x86_64.

Comment 8 Marina Kalinin 2014-10-06 22:13:42 UTC
I see two problems here, please correct me, Bimal, if I am wrong.

1) The display time of Windows VM is always off by 1 Hour (18000-14400=3600) after initial creation of VM in a pool from template.

2) 5 hours diff time on VM from the requested time zone after hard reboot.


Looking through the outputs provided, seems like all the stack behaves properly and the value in the database is propagated correctly from the database to qemu.
Which points to a question, how the database is updated by engine.
What is the logic of updating utc_diff field?

Comment 9 Bimal Chollera 2014-10-06 22:34:58 UTC
1) The display time of Windows VM is always off by 1 Hour (18000-14400=3600) after initial creation of VM in a pool from template.

>> This is correct.

2) 5 hours diff time on VM from the requested time zone after hard reboot.

>>  The 5 hour diff was only seen in 3.2.6 release.
>>  On 3.4.x the time, it was off by 1 hour.  Didn't observe the 5 hour diff.

Comment 10 Marina Kalinin 2014-10-07 23:03:32 UTC
So, in 3.4, I see that timeOffset of a VM saved ok when VM is shut down.
But then, when it is started, it is updated again to the "initial run" offset value.

Looking through the code and the database values, seems to me that the logic is wrong. utc_diff is the one that is constantly updated. While time_zone is never changing. While the code says - use time_zone to calculate the offset.
Please se below:


from RunVmCommandBase.java
~~~
    /**
     * Asynchronous event, send by vds on running vm success. Vm decided successfully run when it's status turn to Up.
     * If there are vdss, not succeeded to run vm - treat them as suspicious.
     */
    public void runningSucceded() {
...
            Backend.getInstance()
                    .getResourceManager()
                    .RunVdsCommand(VDSCommandType.UpdateVmDynamicData,
                            new UpdateVmDynamicDataVDSCommandParameters(getCurrentVdsId(), getVm().getDynamicData()));   <<-- [1]
~~~
[1] here we update vm dynamic data from Vm Dynamic State which, I can't say when updated - from database or anyhow by the host? I believe by database only, so it reads the time_zone value from it.

Next, let's check businessentities/VM.java to see how we get the offset:
~~~
    /**
     * Tracking value of VM's UTC offset. Useful for long running VMs when there
     * can be significant drift over initial value computed from timeZone.
     * Note that this value is no longer being used when
     * starting VMs (The timeZone field is used to calculate that offset) and is kept
     * in sync with value reported by VDSM only for debugging purposes.
     * {@see VmInfoBuilderBase#buildVmTimeZone()}
     */
    public Integer getUtcDiff() {
        return this.vmDynamic.getUtcDiff();
    }
~~~

And now, here is what is happening in the database:
~~~
[mku] right after shutdown and adjust time:
engine_20141003202157=> select vm_name, time_zone , utc_diff from vms where vm_name ilike '%vm-1';
 vm_name |        time_zone         | utc_diff 
---------+--------------------------+----------
 vm-1    | US Eastern Standard Time |   -14402
(1 row)

[mku] right after starting the vm -> value of utc_diff is taken from time_zone:
engine_20141003202157=> select vm_name, time_zone , utc_diff from vms where vm_name ilike '%vm-1';
 vm_name |        time_zone         | utc_diff 
---------+--------------------------+----------
 vm-1    | US Eastern Standard Time |   -18000
~~~


Bottom line - todo:
We need to decide which of the two fields is going to be used all the time and which would represent the initial run. If indeed utc_diff is in vm_dynamic (compared to time_zone, which is in static), why it is not used all the time??

Comment 12 Michal Skrivanek 2014-10-09 07:40:13 UTC
(In reply to Bimal Chollera from comment #9)

> >>  The 5 hour diff was only seen in 3.2.6 release.
> >>  On 3.4.x the time, it was off by 1 hour.  Didn't observe the 5 hour diff.

yes, that's the part which was fixed in 3.3; the TZ offset (as set in the UI in Edit VM dialog, System subtab) is now always used to initialize the hw clock of the VM

Comment 13 Michal Skrivanek 2014-10-09 07:52:47 UTC
(In reply to Marina from comment #10)
> So, in 3.4, I see that timeOffset of a VM saved ok when VM is shut down.
> But then, when it is started, it is updated again to the "initial run"
> offset value.

yes. note it's the TZ in System tab (it's split in two now, the one in System is for every VM start, the one in Initial Run is for cloud-init/sysprep purposes)


> Looking through the code and the database values, seems to me that the logic
> is wrong. utc_diff is the one that is constantly updated. While time_zone is
> never changing. While the code says - use time_zone to calculate the offset.

^^ exactly, so the utc_diff is not being actively used for anything anymore. It just still gets the updates from the guest and is updated in the db…but it gets overwritten on next VM run
Note it may be that in some places the comments are nto updated appropriately, even though the second code snippet says it correctly

> Please se below:
> 
> 
> from RunVmCommandBase.java
> ~~~
>     /**
>      * Asynchronous event, send by vds on running vm success. Vm decided
> successfully run when it's status turn to Up.
>      * If there are vdss, not succeeded to run vm - treat them as suspicious.
>      */
>     public void runningSucceded() {
> ...
>             Backend.getInstance()
>                     .getResourceManager()
>                     .RunVdsCommand(VDSCommandType.UpdateVmDynamicData,
>                             new
> UpdateVmDynamicDataVDSCommandParameters(getCurrentVdsId(),
> getVm().getDynamicData()));   <<-- [1]
> ~~~
> [1] here we update vm dynamic data from Vm Dynamic State which, I can't say
> when updated - from database or anyhow by the host? I believe by database
> only, so it reads the time_zone value from it.
> 
> Next, let's check businessentities/VM.java to see how we get the offset:
> ~~~
>     /**
>      * Tracking value of VM's UTC offset. Useful for long running VMs when
> there
>      * can be significant drift over initial value computed from timeZone.
>      * Note that this value is no longer being used when
>      * starting VMs (The timeZone field is used to calculate that offset)
> and is kept
>      * in sync with value reported by VDSM only for debugging purposes.
>      * {@see VmInfoBuilderBase#buildVmTimeZone()}
>      */
>     public Integer getUtcDiff() {
>         return this.vmDynamic.getUtcDiff();
>     }
> ~~~
> 
> And now, here is what is happening in the database:
> ~~~
> [mku] right after shutdown and adjust time:
> engine_20141003202157=> select vm_name, time_zone , utc_diff from vms where
> vm_name ilike '%vm-1';
>  vm_name |        time_zone         | utc_diff 
> ---------+--------------------------+----------
>  vm-1    | US Eastern Standard Time |   -14402
> (1 row)
> 
> [mku] right after starting the vm -> value of utc_diff is taken from
> time_zone:
> engine_20141003202157=> select vm_name, time_zone , utc_diff from vms where
> vm_name ilike '%vm-1';
>  vm_name |        time_zone         | utc_diff 
> ---------+--------------------------+----------
>  vm-1    | US Eastern Standard Time |   -18000

yes so it gets reset to UTC-5 on each run. That is what's configured.
The -14402 means that during the VM run the hw clock was adjusted to UTC-4 (and drifted by 2 seconds, which is not significant) probably because of a different setting in the guest OS

> Bottom line - todo:
> We need to decide which of the two fields is going to be used all the time
> and which would represent the initial run. If indeed utc_diff is in
> vm_dynamic (compared to time_zone, which is in static), why it is not used
> all the time??

we stopped considering the dynamic updates in ~3.3. Originally it was there to preserve the drift, but that meant we had more issues…as VMs on next run were being started with intentionally skewed times. So we replaced that with this "fixed" correction to the desired TZ offset.
The downside is that the TZ selected in UI *must* match the configuration of guest OS. Reporting/alerting on the discrepancy is part of RFE bug 869296 which is being implemented right now

So, for the particular case I suggest checking the guest TZ configuration wrt what's set in the UI. The UI setting has no other significance so feel free to change it to anything what results in the desired offset

Comment 17 Martin Betak 2014-10-22 14:30:13 UTC
It seems there was incorrect mapping of exactly this timezone (US Eastern Standard Time) that disregarded the DST. Fix post upstream.

Comment 23 Nisim Simsolo 2014-11-13 12:35:53 UTC
Verified:
rhevm-3.5.0-0.19.beta.el6ev.noarch
libvirt-0.10.2-46.el6_6.1.x86_64
sanlock-2.8-1.el6.x86_64
qemu-kvm-rhev-0.12.1.2-2.448.el6.x86_64
vdsm-4.16.7.3-1.el6ev.x86_64


also, verified engine utc_diff is correct:

engine=# select vm_name, time_zone, utc_diff from vms;
 vm_name |        time_zone         | utc_diff 
---------+--------------------------+----------
 VM1     | Etc/GMT                  |        0
 win7    | US Eastern Standard Time |   -18000
 VM2     | Etc/GMT                  |        0
(3 rows)

Comment 25 errata-xmlrpc 2015-02-11 18:09:19 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2015-0158.html


Note You need to log in before you can comment on or make changes to this bug.