OMV keeps previous date & time after update to 3.0.88

    • OMV 3.x

    This site uses cookies. By continuing to browse this site, you are agreeing to our Cookie Policy.

    • OMV keeps previous date & time after update to 3.0.88

      After an update of OMV pumping up to version 3.0.88, I realised that the date of the OS stays all time to "Wed 2017-09-20". I'm using a Raspbian Jessie as the underlying OS for the Raspberry Pi.

      Checking under the Web GUI "System -> Date & Time", I see the same date being set to: Wed 20 Sep 2017 18:30:35 CEST

      Even after a reboot, I always see the date above starting with "Wed 2017-09-20".

      Only when I untick the "Use NTP Server" check-box, and manually set the date towards today's date in the Web GUI, everything seems to be OK then.

      Can anybody enlighten me where I can look further to resolve the issue?

      The post was edited 1 time, last by carriba ().

    • I've shut down the NAS box completely yesterday evening, and powered it on again this morning. And see there, I'm now getting yesterday's date and time when I powered on the box (today is the 28 september). See the output when looging in:

      login as: admin
      admin@nasbox.local's password:
      Last login: Wed Sep 27 19:32:57 2017
      admin@nasbox:~ $ timedatectl
      Local time: Wed 2017-09-27 19:34:13 CEST
      Universal time: Wed 2017-09-27 17:34:13 UTC
      RTC time: n/a
      Time zone: ... (CEST, +0200)
      NTP enabled: no
      NTP synchronized: yes
      RTC in local TZ: no
      DST active: yes
      Last DST change: DST began at
      Sun 2017-03-26 01:59:59 CET
      Sun 2017-03-26 03:00:00 CEST
      Next DST change: DST ends (the clock jumps one hour backwards) at
      Sun 2017-10-29 02:59:59 CEST
      Sun 2017-10-29 02:00:00 CET

      Checking the "dmesg" output, I do not see any entries pointing out how the date & time is being set.

      Checking the "/var/log/syslog" file, I do find the following entries:

      Sep 27 19:32:52 nasbox ntpd[891]: ntpd 4.2.6p5@1.2349-o Mon Jul 25 22:35:28 UTC 2016 (1)
      Sep 27 19:32:52 nasbox ntp[837]: Starting NTP server: ntpd.
      Sep 27 19:32:52 nasbox systemd[1]: Started LSB: Start NTP daemon.
      Sep 27 19:32:52 nasbox ntpd[906]: proto: precision = 0.677 usec
      Sep 27 19:32:52 nasbox ntpd[906]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
      Sep 27 19:32:52 nasbox ntpd[906]: Listen normally on 1 lo 127.0.0.1 UDP 123
      Sep 27 19:32:52 nasbox ntpd[906]: Listen normally on 2 eth0 192.168.0.49 UDP 123
      Sep 27 19:32:52 nasbox ntpd[906]: peers refreshed
      Sep 27 19:32:52 nasbox ntpd[906]: Listening on routing socket on fd #19 for interface updates
      Sep 27 19:32:52 nasbox ntpd[906]: restrict: error in address '::' on line 20. Ignoring...
      Sep 27 19:32:52 nasbox ntpd[906]: restrict: error in address '::1' on line 23. Ignoring...
      ...
      Sep 27 19:34:13 nasbox systemd[1]: Starting Time & Date Service...
      Sep 27 19:34:13 nasbox dbus[746]: [system] Successfully activated service 'org.freedesktop.timedate1'
      Sep 27 19:34:13 nasbox systemd-timedated[1273]: /etc/localtime should be a symbolic link to a time zone data file in /usr/share/zoneinfo/.
      Sep 27 19:34:13 nasbox systemd[1]: Started Time & Date Service.
      ...
      Sep 27 19:38:37 nasbox systemd[1]: Starting Time & Date Service...
      Sep 27 19:38:38 nasbox dbus[746]: [system] Successfully activated service 'org.freedesktop.timedate1'
      Sep 27 19:38:38 nasbox systemd[1]: Started Time & Date Service.

      The entries above seem to be fine to me, and for sure I did not alter any NTP configuration settings whatsoever.

      Only when I log into the OMV Web GUI, and go to "System -> Date & Time", and then toggle the "Use NTP Server" check box, and manually set the date & time to the actual one, and get back to the shell prompt, I'm getting the following output:

      admin@nasbox:~$ timedatectl
      Local time: Thu 2017-09-28 12:07:56 CEST
      Universal time: Thu 2017-09-28 10:07:56 UTC
      RTC time: n/a
      Time zone: ... (CEST, +0200)
      NTP enabled: no
      NTP synchronized: no
      RTC in local TZ: no
      DST active: yes
      Last DST change: DST began at
      Sun 2017-03-26 01:59:59 CET
      Sun 2017-03-26 03:00:00 CEST
      Next DST change: DST ends (the clock jumps one hour backwards) at
      Sun 2017-10-29 02:59:59 CEST
      Sun 2017-10-29 02:00:00 CET

      From above output, I see that NTP is no longer synchronised. It writes "no", instead of "yes" in the previous output of the "timedatectl" command.

      Not sure where to look further now, however I will keep digging...

      Again: this seems to be reproducable after each boot, and it happened after the latest updated of OMV towards 3.0.88.

      The post was edited 2 times, last by carriba ().

    • I've shut down the NAS box yesterday afternoon, and powered it on again after today's lunch.

      I logged in immediately onto the box, and queried with the commands "date ; ntpq -p ; ntpdc -l ; ps -aux | grep ntp" the current date and time, and where appropriate I also fired the "timedatectl" command to obtain further details about the NTP syncronisation status.

      Here the oputput of all my exercises after booting up the box:

      ------------------------------------------------------------------------------------------------------------------------------------
      login as: admin
      admin@nasbox.local's password:
      Last login: Thu Sep 28 15:31:21 2017
      admin@nasbox:~ $ date ; ntpq -p ; ntpdc -l ; ps -aux | grep ntp
      Thu 28 Sep 15:31:45 CEST 2017
      remote refid st t when poll reach delay offset jitter
      ==============================================================================
      *LOCAL(0) .LOCL. 12 l 31 64 1 0.000 0.000 0.001
      ntp.ipreso.com 145.238.203.14 2 u 20 64 1 103.613 7946114 8.172
      client LOCAL(0)
      client ntp.ipreso.com
      ntp 940 0.0 0.3 5684 3144 ? Ss 15:31 0:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 106:111
      admin 1164 0.0 0.2 4276 2020 pts/0 S+ 15:31 0:00 grep --color=auto ntp

      admin@nasbox:~ $ date ; ntpq -p ; ntpdc -l ; ps -aux | grep ntp ; timedatectl
      Thu 28 Sep 15:50:51 CEST 2017
      remote refid st t when poll reach delay offset jitter
      ==============================================================================
      LOCAL(0) .LOCL. 12 l 1113 64 0 0.000 0.000 0.000
      *ntp.ipreso.com 145.238.203.14 2 u 37 64 377 98.233 7946114 10.016
      client LOCAL(0)
      client ntp.ipreso.com
      ntp 940 0.0 0.3 5684 3144 ? Ss 15:31 0:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 106:111
      Local time: Thu 2017-09-28 15:50:51 CEST
      Universal time: Thu 2017-09-28 13:50:51 UTC
      RTC time: n/a
      Time zone: ... (CEST, +0200)
      NTP enabled: no
      NTP synchronized: yes
      RTC in local TZ: no
      DST active: yes
      Last DST change: DST began at
      Sun 2017-03-26 01:59:59 CET
      Sun 2017-03-26 03:00:00 CEST
      Next DST change: DST ends (the clock jumps one hour backwards) at
      Sun 2017-10-29 02:59:59 CEST

      admin@nasbox:~ $ uptime
      15:50:53 up 20 min, 2 users, load average: 0.15, 0.09, 0.09

      admin@nasbox:~ $ date ; ntpq -p ; ntpdc -l ; ps -aux | grep ntp
      Fri 29 Sep 13:56:30 CEST 2017
      remote refid st t when poll reach delay offset jitter
      ==============================================================================
      LOCAL(0) .LOCL. 12 l 49 64 1 0.000 0.000 0.001
      *ntp.ipreso.com 145.238.203.14 2 u 29 64 1 104.949 3.859 2.424
      client LOCAL(0)
      client ntp.ipreso.com
      ntp 940 0.0 0.3 5684 3144 ? Ss 13:35 0:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 106:111
      admin 2761 0.0 0.2 4276 1916 pts/0 S+ 13:56 0:00 grep --color=auto ntp

      admin@nasbox:~ $ uptime
      13:56:43 up 21 min, 2 users, load average: 0.07, 0.08, 0.09

      admin@nasbox:~ $ date ; ntpq -p ; ntpdc -l ; ps -aux | grep ntp ; timedatectl
      Fri 29 Sep 13:57:30 CEST 2017
      remote refid st t when poll reach delay offset jitter
      ==============================================================================
      LOCAL(0) .LOCL. 12 l 108 64 2 0.000 0.000 0.001
      *ntp.ipreso.com 145.238.203.14 2 u 26 64 1 97.983 0.491 2.006
      client LOCAL(0)
      client ntp.ipreso.com
      ntp 940 0.0 0.3 5684 3144 ? Ss 13:35 0:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 106:111
      admin 2801 0.0 0.2 4276 2016 pts/0 S+ 13:57 0:00 grep --color=auto ntp
      Local time: Fri 2017-09-29 13:57:31 CEST
      Universal time: Fri 2017-09-29 11:57:31 UTC
      RTC time: n/a
      Time zone: ... (CEST, +0200)
      NTP enabled: no
      NTP synchronized: no
      RTC in local TZ: no
      DST active: yes
      Last DST change: DST began at
      Sun 2017-03-26 01:59:59 CET
      Sun 2017-03-26 03:00:00 CEST
      Next DST change: DST ends (the clock jumps one hour backwards) at
      Sun 2017-10-29 02:59:59 CEST
      Sun 2017-10-29 02:00:00 CET
      ------------------------------------------------------------------------------------------------------------------------------------

      In the "/var/log/syslog" file, I find multiple of the same entries:

      ------------------------------------------------------------------------------------------------------------------------------------
      Sep 29 13:55:41 nasbox systemd[1019]: Time has been changed
      Sep 29 13:55:41 nasbox systemd[1074]: Time has been changed
      Sep 29 13:55:41 nasbox systemd[967]: Time has been changed
      Sep 29 13:55:41 nasbox systemd[1]: Time has been changed
      ------------------------------------------------------------------------------------------------------------------------------------

      So concluding: after booting up the OS, it keeps the previous date & time. Only after about 21 minutes of OS uptime, the system's clock indeed changes towards the current date and time.

      Using the timedatectl command, I see that NTP synchonisation is set to "yes", however it still shows the previous day's clock.

      Using the same command after the date and time has synchronised, I see that NTP synchonisation is set to "no".

      So the question arises to me, why does it take more than 21 minutes to get the system's clock synchronised with the correct NTP clock source. Why does the timedatectl command provides misleading(?) information about the platform's current system time.

      The post was edited 4 times, last by carriba ().

    • OK, I left the NAS box shutdown (to be precise, on 29 september) for a couple of days, and then powered it on again . Here the output of the "/var/log/syslog" file:

      Sep 29 14:39:19 nasbox rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="700" x-info="http://www.rsyslog.com"] rsyslogd was HUPed
      Sep 29 14:41:24 nasbox rsyslogd0: action 'action 21' resumed (module 'builtin:ompipe') [try rsyslog.com/e/0 ]
      Sep 29 14:41:24 nasbox rsyslogd-2359: action 'action 21' resumed (module 'builtin:ompipe') [try rsyslog.com/e/2359 ]
      Sep 29 14:41:24 nasbox systemd[1]: Starting Session c5 of user admin.
      Sep 29 14:41:24 nasbox systemd[1]: Started Session c5 of user admin.
      Sep 29 14:45:01 nasbox CRON[1468]: (root) CMD (/usr/sbin/omv-mkgraph >/dev/null 2>&1)
      Sep 29 14:47:37 nasbox systemd[1]: Starting Cleanup of Temporary Directories...
      Sep 29 14:47:37 nasbox systemd[1]: Started Cleanup of Temporary Directories.
      Oct 3 09:12:05 nasbox systemd[1009]: Time has been changed
      Oct 3 09:12:05 nasbox systemd[1]: Time has been changed
      Oct 3 09:12:05 nasbox systemd[1000]: Time has been changed
      Oct 3 09:12:07 nasbox dbus[703]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service'
      Oct 3 09:12:07 nasbox systemd[1]: Starting Time & Date Service...
      Oct 3 09:12:07 nasbox dbus[703]: [system] Successfully activated service 'org.freedesktop.timedate1'
      Oct 3 09:12:07 nasbox systemd-timedated[1589]: /etc/localtime should be a symbolic link to a time zone data file in /usr/share/zoneinfo/.
      Oct 3 09:12:07 nasbox systemd[1]: Started Time & Date Service.
      Oct 3 09:15:01 nasbox CRON[1656]: (root) CMD (/usr/sbin/omv-mkgraph >/dev/null 2>&1)

      The post was edited 1 time, last by carriba ().

    • From these entries, I can see several "systemd" lines showing that time has changed a couple of times.

      Now, what is changing the time that much is unclear to me as I do not seem to find any other hint in other log files. No particular entries in the "/var/log/messages" file.

      Not sure yet what is triggering the date & time update...

      The post was edited 1 time, last by carriba ().