time jumping back

Miroslav Lichvar mlichvar at redhat.com
Wed Feb 26 09:39:34 UTC 2014


On Tue, Feb 25, 2014 at 10:27:56AM -0700, Michal Jaegermann wrote:
> 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.

Ok, it looks like something else than ntpd or chronyd is indeed
setting the clock on your system. From the systemd code it seems the
"Time has been changed" message is generated by timer with the
TFD_TIMER_CANCEL_ON_SET flag, which I think can be triggered by
settimeofday(), clock_settime() and adjtimex() system calls, and other
events like system resume, etc.

As a quick check, does the following command print anything beside
systemd and chronyd/ntpd?

# for i in /proc/*/exe; do readelf -s $i 2>/dev/null | grep -q 'clock_settime\|settimeofday\|adjtimex' && readlink $i; done

If that doesn't print anything interesting, you might want to consider
running a systemtap script to see what processes are making the calls.
This looks useful:

https://sourceware.org/systemtap/examples/process/syscalltimes

> 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.

-- 
Miroslav Lichvar


More information about the test mailing list