On 19/1/17 1:19 pm, Peter Brady wrote:
Hi All,
Just noticed a funny time jump on a testing CentOS 7 VM. Specifically the system time jumps around by a few hours during system boot. The below is a selection from /var/log/messages during boot:
Jan 19 12:49:57 arr-data-dev chronyd[716]: Frequency -0.829 +/- 0.007 ppm read from /var/lib/chrony/drift Jan 19 12:49:57 arr-data-dev polkitd[720]: Started polkitd version 0.112 Jan 19 12:49:57 arr-data-dev systemd: Starting D-Bus System Message Bus... Jan 19 12:49:57 arr-data-dev systemd: Starting GSSAPI Proxy Daemon... Jan 19 12:49:57 arr-data-dev systemd: Started Dump dmesg to /var/log/dmesg. Jan 19 12:49:57 arr-data-dev kernel: NET: Registered protocol family 40 Jan 19 12:49:57 arr-data-dev sssd: Starting up Jan 19 12:49:57 arr-data-dev systemd: Started GSSAPI Proxy Daemon. Jan 19 12:49:57 arr-data-dev systemd: Reached target NFS client services. Jan 19 12:49:57 arr-data-dev systemd: Starting NFS client services. Jan 19 12:49:57 arr-data-dev systemd: Reached target Remote File Systems (Pre). Jan 19 12:49:57 arr-data-dev systemd: Starting Remote File Systems (Pre). Jan 19 12:49:57 arr-data-dev systemd: Started Authorization Manager. Jan 19 12:49:57 arr-data-dev systemd: Starting firewalld - dynamic firewall daemon... Jan 19 20:47:57 arr-data-dev systemd: Time has been changed Jan 19 20:47:57 arr-data-dev chronyd[716]: Forward time jump detected! Jan 19 20:47:57 arr-data-dev sssd[be[default]]: Starting up
<snip>
Jan 19 20:48:05 arr-data-dev systemd: Starting Multi-User System. Jan 19 20:48:05 arr-data-dev systemd: Starting Update UTMP about System Runlevel Changes... Jan 19 20:48:05 arr-data-dev systemd: Started Update UTMP about System Runlevel Changes. Jan 19 12:50:09 arr-data-dev chronyd[716]: Selected source IP-CHANGED Jan 19 12:50:09 arr-data-dev chronyd[716]: System clock wrong by -28676.126423 seconds, adjustment started Jan 19 12:50:09 arr-data-dev chronyd[716]: System clock was stepped by -28676.126423 seconds Jan 19 12:50:09 arr-data-dev systemd: Time has been changed Jan 19 12:50:09 arr-data-dev chronyd[716]: Selected source IP-CHANGED Jan 19 12:50:10 arr-data-dev chronyd[716]: Selected source IP-CHANGED Jan 19 12:50:11 arr-data-dev chronyd[716]: Selected source IP-CHANGED
For reference the 12:49 -> 12:50 is the correct local time, I'm in the Australian Eastern Daylight Saving time zone and my hardware clock (from hwclock) is close to that time.
The plus eight hours jump has me curious though as I think this is causing some trouble for SSSD and Network Manager that are starting up in interval when the time is stepped forward. Given I'm at +11 from UTC the system clock does not appear to be jumping to UTC.
I'm running 3.10.0-514.2.2.el7.x86_64 with yum reporting no patches. This is a VM running on ESXi 5.6.
According to /var/log/boot.log everything started up OK.
Has anyone seen anything similar?
Thanks in advance, -pete
OK,
Answering my own question here in case it helps elsewhere. The main problem existed between the keyboard and chair.
When the VMware host was installed some time ago it was neglected to configure NTP on the host itself, hence the time had drifted quite significantly. So when open-vm-tools came up, it synced off the VMware host system time and over-rode the VM's hardware clock. Then when chrony came up later in the boot process it pushed the time back correctly.
Now with NTP running on the VMware host the boot is clean with SSSD and Network Manager are functioning as expected
Frustrating.
Thanks, -pete