On Tue, Feb 25, 2014 at 11:12:49AM +0100, Miroslav Lichvar wrote:
> On Sun, Feb 23, 2014 at 01:00:11PM -0700, Chris Murphy wrote:
>
> Are there any interesting messages in syslog near that jump? Both ntpd
> and chronyd in their default configuration log a message when they
> step the clock, but chronyd steps the clock only on start.
AFAIK both chronyd and ntpd are not supposed to force any significant
time jumps in a normal operation, except when forced on a startup to
perform an initial adjustment, and only vary slightly frequencies for a
gradual synchronization.
As a matter of fact I did not omit any log entries around both jumps
when I qouted what I found in initial messages.
> Also,
> chronyd will log a message if it detects that something else has
> stepped the clock backwards.
Searching through an output of journalctl when time was messed up
turns out to be not that obvious and I may missed some clues.
Apparently the first backjump may have happened about the same time.
Maybe. In any case these are timelines I managed to dig out.
On a machine with chronyd:
Feb 21 09:25:46 --- dbus-daemon reports failure for unit
'dbus-org.freedesktop.ModemManager1.service'
Jan 02 13:40:22 ---- systemd[750]: Time has been changed
The system clock has been changed to REALTIME microseconds after January
1st, 1970.
Jan 02 13:40:22 --- systemd[1]: Time has been changed ....
Jan 02 13:40:22 --- systemd[10804]: Time has been changed ....
Jan 02 13:41:57 --- dbus-daemon tries again and fails
'dbus-org.freedesktop.ModemManager1.service'
........ (more "Time has been changed" from various systemd processes
followed by some messages from chronyd at last)
Jan 02 14:15:07 --- chronyd[495]: Backward time jump detected! (correction
4302802.2 +- 1.0 seconds) Jan 02 14:16:22 --- chronyd[495]: Selected source
198.245.50.148 Jan 02 14:16:22 --- chronyd[495]: System clock wrong by
4302802.312517 seconds, adjustment started
Jan 02 14:16:22 --- smartd[502]: System clock time adjusted to the past.
Resetting next wakeup time.
198.245.50.148 is
vela.z0p.org but it is not selected explicitely but
one of pool time servers and this likely be something else on the next
startup. In any case chronyd detected a wrong clock but skewing that
amount will take a long while.
On the other machine with ntpd this looks like follows (with multiple
time gaps):
Feb 21 09:10:16 --- dbus-daemon reports failure for unit
'dbus-org.freedesktop.ModemManager1.service' Feb 20 23:22:01 --- systemd[1]:
Time has been changed Feb 20 23:22:01 --- systemd[12162]: Time has been
changed Feb 20 23:22:01 --- systemd[2717]: Time has been changed
............. (various unrelated activities)
Feb 20 00:01:02 --- systemd[2717]: Time has been changed !!!!!!
Feb 20 00:01:02 --- systemd[12162]: Time has been changed (and more of
similar) Feb 20 00:14:39 --- dbus[557]: [system] Activation via systemd failed
for unit 'dbus-org.freedesktop.ModemManager1.service' Feb 20 23:01:01 ---
systemd[12162]: Time has been changed
............ (followed by the first log entry from ntpd)
Feb 20 23:18:20 --- ntpd[602]: 0.0.0.0 0618 08 no_sys_peer
.....
Feb 21 01:05:55 --- ntpd[602]: 0.0.0.0 0617 07 panic_stop +36679 s; set clock
manually within 1000 s. Feb 21 01:05:55 --- systemd[1]: ntpd.service: main
process exited, code=exited, status=255/n/a Feb 21 01:05:55 --- systemd[1]:
Unit ntpd.service entered failed state.
Time was restored when I caught up and started ntpd manually
So far nothing like that happened again.
Michal
Don't know if it's related, but I just saw this:
Feb 25 12:06:18 nbecker7 kernel: [ 59.015938] Ebtables v2.0 registered
Feb 25 12:06:18 nbecker7 kernel: [ 59.601221] ip6_tables: (C) 2000-2006
Netfilter Core Team
Feb 25 12:06:18 nbecker7 kernel: [ 65.646938] Bridge firewalling registered
Feb 25 12:06:18 nbecker7 kernel: [ 65.671316] device virbr0-nic entered
promiscuous mode
Feb 25 12:06:18 nbecker7 kernel: [ 66.410670] virbr0: port 1(virbr0-nic)
entered listening state
Feb 25 12:06:18 nbecker7 kernel: [ 66.410678] virbr0: port 1(virbr0-nic)
entered listening state
Feb 25 12:06:18 nbecker7 kernel: [ 66.410724] IPv6: ADDRCONF(NETDEV_UP):
virbr0: link is not ready
Feb 25 12:06:18 nbecker7 kernel: [ 66.668588] virbr0: port 1(virbr0-nic)
entered disabled state
Feb 25 12:06:54 nbecker7 kernel: [ 109.855407] fuse init (API version 7.22)
Jan 8 10:48:32 nbecker7 systemd: Stopped target Graphical Interface.
Jan 8 10:48:32 nbecker7 systemd: Stopping Multi-User System.
Jan 8 10:48:32 nbecker7 systemd: Stopped target Multi-User System.
Jan 8 10:48:32 nbecker7 systemd: Stopping ABRT kernel log watcher...
Jan 8 10:48:32 nbecker7 systemd: Stopping Command Scheduler...
Jan 8 10:48:32 nbecker7 systemd: Stopping Install ABRT coredump hook...
Jan 8 10:48:32 nbecker7 systemd: Stopping ABRT Xorg log watcher...