I have a lot of "Time has been changed" in the journal of my linux boxes

Question

_{Thursday, March 16, 2017 12:20 PM}

Hi Support!

I have some linux boxes on Azure with CoreOS(just installed)/Debian/Ubuntu, and I notice that on the journal log there are a log of message like this:

Mar 16 11:34:12 msnc1-1-zwe systemd[1]: Time has been changed
Mar 16 11:34:17 msnc1-1-zwe systemd[1]: Time has been changed
Mar 16 11:34:17 msnc1-1-zwe systemd[12525]: Time has been changed
Mar 16 11:34:22 msnc1-1-zwe systemd[12525]: Time has been changed
Mar 16 11:34:22 msnc1-1-zwe systemd[1]: Time has been changed
Mar 16 11:34:27 msnc1-1-zwe systemd[1]: Time has been changed
Mar 16 11:34:27 msnc1-1-zwe systemd[12525]: Time has been changed

Mar 16 12:17:31 monitor1-0-zwe[3879]: Time has been changed
Mar 16 12:17:36 monitor1-0-zwe[3879]: Time has been changed
Mar 16 12:17:36 monitor1-0-zwe[1]: Time has been changed
Mar 16 12:17:36 monitor1-0-zwe[1]: apt-daily.timer: Adding 9h 39min 34.170890s random time.
Mar 16 12:17:36 monitor1-0-zwe[1]: snapd.refresh.timer: Adding 1h 26min 11.804266s random time.
Mar 16 12:17:41 monitor1-0-zwe[1]: Time has been changed
Mar 16 12:17:41 monitor1-0-zwe[1]: apt-daily.timer: Adding 4h 28min 37.134577s random time.
Mar 16 12:17:41 monitor1-0-zwe[1]: snapd.refresh.timer: Adding 1h 39min 56.995064s random time.
Mar 16 12:17:41 monitor1-0-zwe[3879]: Time has been changed
Mar 16 12:17:46 monitor1-0-zwe[3879]: Time has been changed

As I understand on internet, this is caused by a conflict of HyperV Time Sync Service and the Linux Kernel.
This cause that at some point in date of the system is not coherent.
It there a solution?

Thanks,
Domenico

All replies (6)

_{Thursday, March 16, 2017 8:27 PM | 2 votes}

Newer versions of Linux have our improved support for the TimeSync integration service which  enhances the precision of time synchronization with the host. On Linux installations with systemd this can produce a large number of “systemd: Time has been changed” messages in /var/log/messages.

If TimeSync is desired, but the message is not, create a config file in rsyslog.d to filter out the messages:

1. Create a file in /etc/rsyslog.d, for example

    # vi /etc/rsyslog.d/time_msgs.conf

2. Add this line:

   :msg, contains, "Time has been changed" ~

3. Restart rsyslog to enable the change

   # systemctl restart rsyslog.service

Josh Poulson Program Manager, Linux Integration Services, Enterprise Open Source Group Microsoft

_{Monday, March 20, 2017 10:47 AM}

Hi Josh,
 thank you for your response.

I would like to know more about this since if I hide the message of syslog, I feel like sweeping the dust under the carpet :)

After some research, I think that the message came from a difference of the two time, CLOCK_MONOTONIC and CLOCK_REALTIME.
I have 12 machines in Azure and I check the RTC time of each. I found that they are very different among them:

[dometec@precision7510 ansible-prod]$ ansible all -a "timedatectl" | grep "RTC time"
        RTC time: Sat 2017-04-22 04:23:19
        RTC time: Sat 2017-04-22 04:23:00
        RTC time: Sat 2017-04-01 09:21:19
        RTC time: Wed 2017-04-19 20:18:29
        RTC time: Mon 2017-04-24 04:31:19
        RTC time: Wed 2017-04-19 22:37:00
        RTC time: Mon 2017-04-24 03:44:18
        RTC time: Fri 2017-03-24 10:20:14
        RTC time: Wed 2017-04-19 00:18:28
        RTC time: Wed 2017-04-26 12:58:57
        RTC time: Wed 2017-04-26 12:14:19
        RTC time: Sat 2017-07-08 07:17:57

In a virtualized environment, is the HyperV responsible for providing the RTC clock function?

Thank you,
Domenico

_{Friday, March 24, 2017 12:41 AM}

Hi Domenico,

To answer your first post, the "Time has been changed" messages are a result of TimeSync integration service constantly updating the system clock on the Linux machine.

Josh's response provides a way to avoid getting spammed with these messages.

If you prefer to use another mechanism to sync the system clock (e.g. NTP), you can disable TimeSync using following steps:

sudo -I
wget https://raw.githubusercontent.com/torvalds/linux/master/tools/hv/lsvmbus
chmod u+x lsvmbus
python ./lsvmbus –vvvv

You will see output like this:

* VMBUS ID 11: Class_ID = {9527e630-d0ae-497b-adce-e80ab0175caf} - [Time Synchronization]*
*        Device_ID = {2dd1ce17-079e-403c-b352-a1921ee207ee}*
*        Sysfs path: /sys/bus/vmbus/devices/vmbus_13*
*        Rel_ID=11, target_cpu=0*

From the output of lsvmbus, use the vmbus_XX id that corresponds to the sysfs path in the “Time Synchronization” device. Pass it to the following command to disable it.

echo vmbus_13 > /sys/bus/vmbus/drivers/hv_util/unbind

Regarding the RTC clock, you may need to run a command such as "hwclock --systohc" to ensure that the RTC is in sync with the system time.

Do you still see this variance if you run this command on all the machines?

_{Thursday, March 30, 2017 9:49 AM}

Hi Alex,

 when a try the echo command Ubuntu and Debian machines, I get this error:

# echo vmbus_11 > /sys/bus/vmbus/drivers/hv_util/unbind
-bash: echo: write error: No such device

In dmesg and syslog I do not see something interesting.

It works on CentOS 7.

Thanks

Domenico

_{Tuesday, May 2, 2017 3:30 PM}

On debian/ubuntu use the VMBUS uuid :

echo 2dd1ce17-079e-403c-b352-a1921ee207ee > /sys/bus/vmbus/drivers/hv_util/unbind

_{Monday, June 26, 2017 8:40 PM | 1 vote}

If you put it in rc.local its executed automatical every start. Works fine for me.