CHR initial time wrong

sid5632 · Thu May 18, 2017 12:10 pm

Where does CHR get its initial time from? It's completely wrong on mine (running under Virtualbox on Ubuntu) and it gets worse every boot as the following log extracts show:

may/21 08:37:40 system,info router rebooted 
may/21 08:37:40 interface,info ether1 link up 
may/21 08:37:40 system,info item added 
may/21 08:37:40 dhcp,info dhcp-client on ether1 got IP address ...
may/21 08:37:45 system,info,account user admin logged in from ...
may/21 08:39:08 system,info SNTP client configuration changed by admin 
may/10 22:49:28 system,info sntp change time May/21/2017 08:39:08 => May/10/2017 22:49:28 

jun/05 06:52:51 system,info router rebooted 
jun/05 06:52:51 interface,info ether1 link up 
jun/05 06:52:51 system,info item added 
jun/05 06:52:51 dhcp,info dhcp-client on ether1 got IP address ...
jun/05 06:54:49 system,info,account user admin logged in from ...
jun/05 06:55:26 system,info SNTP client configuration changed by admin 
09:59:00 system,info sntp change time Jun/05/2017 06:56:15 => May/18/2017 09:59:00 

jun/05 07:03:36 system,info router rebooted 
jun/05 07:03:36 interface,info ether1 link up 
jun/05 07:03:37 system,info item added 
jun/05 07:03:37 dhcp,info dhcp-client on ether1 got IP address ...
jun/05 07:04:27 system,info,account user admin logged in from ...
10:02:31 system,info sntp change time Jun/05/2017 07:05:08 => May/18/2017 10:02:31

The time should be picked up from the host (which is of course correct) - all other VMs work this way, so what can be the cause of this?

Currently running 6.40rc5 but it does the same thing on 6.39

If the Dude is running on the CHR - why is primarily what I'm using it for - this huge backwards step in time causes all sorts of weird problems.

romeoma2004 · Thu Jul 20, 2017 11:47 am

Dear

just remove the ntp package if you installed and use only sntp client then it will work fine , ntp package you can use it in case if you want to make your CHR router as ntp server

sid5632 · Thu Jul 20, 2017 4:28 pm

I don't have the ntp package. I never said I did.
Did you even read and understand my original post properly before posting your pointless, utterly inconsequential and completely irrelevant reply?

IntrusDave · Thu Jul 20, 2017 6:56 pm

No need to be rude. Clearly he doesn't understand, which is easily explained by his post count (that was his 1st post).

Anyway - The CHR doesn't have any of the VM tools installed, so it is unable to communicate directly with the host to get the date and time. Unfortunately, you only real choice is to have the CHR pull the time from an NTP server (time1.google.com and time2.google.com are very good). Most of the routerOS divides do not have an internal clock, so RouterOS normally stores the current time in the config when it is shutdown - but that is ONLY when you use the internal "/system shutdown" function. shutdown down from the host, a power cycle doesn't store it. But the NTP client should pull the current date and time pretty quickly once the WAN comes online.

sid5632 · Fri Jul 21, 2017 10:24 am

Anyway - The CHR doesn't have any of the VM tools installed, so it is unable to communicate directly with the host to get the date and time.

OK, I could understand that if the time was 1/1/70 every boot, but it isn't:

22:49:28 system,info sntp change time May/21/2017 08:39:08 => May/10/2017 22:49:28
09:59:00 system,info sntp change time Jun/05/2017 06:56:15 => May/18/2017 09:59:00
10:02:31 system,info sntp change time Jun/05/2017 07:05:08 => May/18/2017 10:02:31

So where does it get these future dates from? And why do they get further into the future (by more than the elapsed time) every time you restart?

Most of the routerOS divides do not have an internal clock, so RouterOS normally stores the current time in the config when it is shutdown

If it reads this you may expect time at startup to be behind current time, not in front of it.

But the NTP client should pull the current date and time pretty quickly once the WAN comes online.

It does, but it takes roughly 20 seconds which is long enough for the Dude component to have become completely messed up by time going backwards.

pe1chl · Fri Jul 21, 2017 11:45 am

It is something specific to your system (setup of the host system or the CHR).
I have a CHR running under ESXi with no particular settings other than sntp and also Dude installed, and it reboots to the correct time.
Sometimes I see that sntp makes a 1-second adjustment after boot, but usually nothing.

sid5632 · Fri Jul 21, 2017 2:10 pm

It is something specific to your system (setup of the host system or the CHR).
I have a CHR running under ESXi with no particular settings other than sntp and also Dude installed, and it reboots to the correct time.
Sometimes I see that sntp makes a 1-second adjustment after boot, but usually nothing.

Thanks, that is useful info.

The config. is pretty simple so that can't be the cause:

# jul/21/2017 12:02:43 by RouterOS 6.40rc32
# software id = 
#
#
#
/ip dhcp-client add disabled=no interface=ether1
/ip firewall filter add action=reject chain=output dst-address=169.254.169.254 protocol=tcp reject-with=tcp-reset
/snmp set enabled=yes
/system clock set time-zone-name=Europe/London
/system ntp client set enabled=yes server-dns-names=uk.pool.ntp.org
/system package update set channel=release-candidate

The only thing time related in Virtualbox config. is "Hardware clock in UTC time" which was enabled (the way you have it for every other Linux based VM).
I disabled it just to see what happened:

[admin@MikroTik] > log pr
12:01:33 system,info router rebooted 
12:01:33 interface,info ether1 link up 
12:01:36 system,info,account user admin logged in via local 
12:01:43 system,info item added 
12:01:44 dhcp,info dhcp-client on ether1 got IP address 192.168.x.y
12:02:07 system,info sntp change time Jul/21/2017 12:02:10 => Jul/21/2017 12:02:07

and it's now working properly. Weird.

Thanks again for the useful feedback.

sid5632 · Fri Aug 04, 2017 3:05 pm

Actually, this was not the cure and the problem came back at the next reboot. The shutdown to edit the VM Settings confused the situation...

It turns out that the clock in RouterOS starts up with the incorrect time if the router has been rebooted (using /system reboot).
It is in advance of where it should be by the same amount of time that the router has been running since the last cold start.
e.g.
I last cold started the CHR on 2nd Aug at 14:29
I rebooted it on 4th Aug at 11:49
Time is currently showing as 6th Aug. 09:13
Here is the log extract:
aug/06 09:13:30 system,info router rebooted
aug/06 09:13:30 interface,info ether1 link up
aug/06 09:13:40 system,info item added
11:51:13 system,info sntp change time Aug/06/2017 09:15:24 => Aug/04/2017 11:51:13

If you do a cold start (using /system shutdown) and then manually start the VM again, it starts up with the correct time from the host.
It is nothing to do with having "Hardware Clock in UTC Time" or not.
It is rather inconvenient not to be able to use "reboot" though.

pe1chl · Fri Aug 04, 2017 3:40 pm

Did you try a different hypervisor to ascertain that it is a RouterOS problem instead of a hypervisor problem?

sid5632 · Sat Aug 05, 2017 2:41 am

Did you try a different hypervisor to ascertain that it is a RouterOS problem instead of a hypervisor problem?

No I didn't. What would you suggest?
I don't really see how it can be a hypervisor bug though.

pe1chl · Sat Aug 05, 2017 11:32 am

Well, as I already mentioned, I have never seen this problem on VMware ESXi.
It could be some bug or some incompatibility between CHR and the hypervisor, I don't know.
There also usually are options in the hypervisor for timekeeping:
- time is synced by the hypervisor or left free running (and possibly synced by the VM)
- clock is running in UTC or in local time, with or without DST.

sid5632 · Sat Aug 12, 2017 3:28 pm

It could be some bug or some incompatibility between CHR and the hypervisor

It turns out during further testing that it's the "Paravirtualization interface" setting on Virtualbox that's the cause of the problem.
"None", "Minimal", "Legacy" and "Hyper-V" do not exhibit the problem.
"Default" and "KVM" do exhibit the problem.
As all new VMs get created with a default of "Default" for this parameter, this is a bit of a problem.

Anyway, finally, I was able to get Support to reproduce the bug, which is good news, and they are looking at fixing it.

pe1chl · Sat Aug 12, 2017 6:22 pm

Well I have used virtualbox to run Windows under Linux for a while, and I should say I had loads of problems
that I never had in VMware ESX(i). Not this problem, of course. But I have read from others who had issues
with hypervisors when trying to sync the time from the VM (e.g. when running NTP).

Good to hear that at least the issue has been narrowed down and reproduced, such things can often be
very difficult to locate but are usually quite easy to fix.

CHR initial time wrong

CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Re: CHR initial time wrong

Who is online