How to know during system start when system time becomes correct from NTP

Question

I have a Raspberry Pi running Raspbian (Debian derivative) that is recording real-time temperatures. As part of this, I need a clock that is accurate to within a few seconds. In normal operation when the server is up, I understand that the Raspberry Pi regularly connects over the network to an NTP server to make sure it's local clock is reasonably close to the correct time. That level of accuracy is fine for my application. The Raspberry Pi does not have a battery powered clock to keep time when the server is shutdown or depowered so when it first boots up the system time is not correct until it establishes an internet connection and gets the correct time via NTP.

Where I have found a problem is when there is a power outage and the Raspberry Pi is off for some period of time without power, then powers back up sometime later (say 30 minutes). The Pi boots, my app starts up and starts recording temperatures again, but the clock on the Pi is not correct so it records temperatures with the wrong timestamp. It appears to somehow have saved the last known time and picks up from there (it does not reset to epoch time when it restarts). Eventually, when the LAN that the Pi is on recovers and regains internet connectivity, the Pi will correct its time (via NTP), but before that happens, I have inaccurate timestamps that get recorded.

I'm trying to figure out what the best course of action is to solve this issue?

For maintenance reasons, I'd rather not add a battery backed add-on clock (don't want anyone to have to replace a battery as this is essentially an embedded device, not easily user accessible).

I'm willing to have my app postpone recording temperatures until I know the time has been accurately retrieved from the network, but I don't even know how to detect that state. Anyone know how to know when the time has now been updated from an NTP server and is now correct?

My app is started by running a script at startup.

Any other ideas for how to solve this issue?

Answer 1

Every time you reboot your Pi (which takes more than a few seconds), your clock is going to be off for more than what ntp can compensate for by stretching/shortening time (ie. slewing, which only good for correcting a clock that is only slightly off, such as caused by a real time clock being slow or fast by a second or so a day), ntp has to set the clock.

So what might be the easiest is to have a script that starts your temperature measuring program first call ntpdate or equivalent, which sets the date or slews according to how far of the retrieved value is. ntpdate therefore doesn't disrupt things if the clock is already set close to correct by ntp e.g. if you restart via this script without having had a reboot.

Answer 2

Check out the ntp-wait program that comes with NTP. You run it, it waits until your clock is synchronized, and exits. (Or it eventually gives up, and exits with an error.) You can use it to prevent your script from starting until the clock is synchronized.

You can also run something like ntpq -p or ntpq -c rv and parse the output to check your clock's status. Indeed, ntp-wait is a short Perl script doing exactly that.

Answer 3

Another option may be to parse the output of ntpq -c peers to watch for the stratum to move away from 16.

Answer 4

Provided you are using ntpd (from the ntpd package) to keep your clock in sync, it can be configured to step the clock on boot regardless of the time offset. If you're using some other package please advise in your Question.

By default ntpd would only jump the clock if it was less than 1000 seconds, but Debian's implementation provides the -g flag to override the limitation and allow stepping from any offset. (This is good.)

Also, the -x flag will force slewing of the time rather than stepping for intervals of up to 600 seconds; you do not want this set. (The Debian default does not set this flag, which is good.)

Check /etc/default/ntp, which should have just this line setting the flags:

NTPD_OPTS='-g'

---

Your question has been updated to explain that the logging process starts before time has synchronised, so I would suggest you use ntpstat to identify when the synchronisation is complete.

Unsynchronised

ntpstat; printf "\nexit status %s\n" $?
unsynchronised
   polling server every 8 s

exit status 1

Synchronised

ntpstat; printf "\nexit status %s\n" $?
synchronised to NTP server (203.0.113.22) at stratum 3
   time correct to within 93 ms
   polling server every 1024 s

exit status 0

Busy loop example

until ntpstat; do echo waiting; sleep 30; done; date

---

If you don't have ntpstat and can't install it, you could probably get some information from ntpq -c sysinfo

ntpq -c sysinfo
associd=0 status=0615 leap_none, sync_ntp, 1 event, clock_sync,
system peer:        server2.contoso.com:123
system peer mode:   client
leap indicator:     00
stratum:            3
log2 precision:     -20
root delay:         26.453
root dispersion:    28.756
reference ID:       203.0.113.22
reference time:     e08863a7.fb7d83bf  Thu, May 16 2019 23:33:11.982
system jitter:      3.227792
clock jitter:       1.178
clock wander:       0.012
broadcast delay:    -50.000
symm. auth. delay:  0.000

Answer 5

Your NTP client is also an NTP server, and it can report its current status to its clients.

I'm actually using chrony rather than ntpd on my boxes, and when I ask it for its current status it says this:

[axa@enyo ~]$ chronyc tracking
Reference ID    : p.q.s.t (xxx.yyy.zzz)
Stratum         : 4
Ref time (UTC)  : Sun May 31 22:35:34 2015
System time     : 0.000630264 seconds slow of NTP time
Last offset     : +0.000047504 seconds
RMS offset      : 0.023269517 seconds
Frequency       : 6.462 ppm slow
Residual freq   : -0.023 ppm
Skew            : 0.225 ppm
Root delay      : 0.031594 seconds
Root dispersion : 0.025155 seconds
Update interval : 1035.3 seconds
Leap status     : Normal

From the "System time" field, your process can work out whether the clock is sufficiently accurate. I'm pretty sure you could read these values directly without having to parse the output of a command intended for human use, but I don't know the details.

Answer 6

You haven't really analysed the problem, and while what you are suggesting would work if you can detect when ntp runs, it is unnecessarily complex.

You don't say how often you log, or how you set the logging time.

Your system saves the time (in /etc/fake-hwclock.data) which should be updated hourly by a cron task. The result of this is that the time recorded will always be before the actual time (by the time of outage plus 0-1 hour).

The end result of this is that you will have a log file with regular times and a possible "gap" during power outage. When ntp kicks in it will correct the time, so you will have "gap" for the correction.

It is possible that after an outage the time may appear to go backwards (if there are log entries after cron saves the time).

All you have to do is post process the log file, detect the gaps/time changes and correct the file. To make the taks easier I would log a distinct message in the log on process startup.

Having said all that, I would just get a RTC (only a few dollars on eBay) which will keep the time for years using a $1 battery, which is what I use on my Pi.

Answer 7

This is an extremely useful thread, highlighting a real existing problem (that is often not solved or solved terribly, not in a robust way) effecting the usability and maintenance cost of millions of "IOT" systems (soon billions). Several nice ntp hints above, NTP is useful, but sometimes comes late to the party:

DX=`date +%s.%4N`
DB=`awk -v DX=$DX '{printf "%.0f",DX-$1}' /proc/uptime`
c=$(( $c+1 ))
echo "${DX} DB=$DB $$ $c $MSG"

Marcell's method: subtracting uptime (first field of /proc/uptime) from unix date ($DX) = is the (DB) boot time (might theoretically change by 1 because of rounding, never seen that though). Some recently recorded example filename=date...$DB.$$.$c.myapp.gpg:

2019-05-16.200713.1558037061.1207.6.myapp.gpg
2019-05-16.201348.1558037061.1207.7.myapp.gpg

Even if NTP manages to sync after days of datalogging (network problem), the logged data is safe, and easy to recover timestamp automatically during data presentation/analyzis, by detecting $DB jump because (at the time) of NTP sync. Even if NTP never syncs for some reason, data will be logged, and consistent (though exact time offset cannot always be recovered in that case; time-sync can often be established from the logged data - eg. light sensors, or events/sounds also recorded by other systems).

Note: the $$ will likely be different after boot, and $DB will be different as well, $c counter confirms continuity.

It is our task to implement robust systems that work reasonably (baby baby it's a wild world) in as many situations as possible (consider that more and more systems are mobile, and network may or may not be immediately available when booting in a tunnel, or elsewhere).

It's unprofessional to implement fragile systems, or let issues escalate instead of containing them (1 subsystem does not work well, eg. network or NTP => other subsystems also freeze => such practices applied in large systems make the right recipe for circular dependencies, unreliable systems, or total system collapse at the worst time we can imagine). It's unprofessional to add unnecessary dependencies (=let someone else, eg. administrators solve it, we are programmers and just don't care). Eg. requiring that network and gateway and time servers are always up and reachable right after boot, and RTC installed and maintained (replacing batteries possibly in dozens or hundreds of devices). Yes, of course reliable network and NTP systems are welcome. Battery RTC in every gadget is usually more pain than gain.

In general, data should be logged (instead of freezing the system unnecessarily) in some usable way if at all possible.

Further improvements are possible (also, porting /bin/sh to .py or .c or ... ), of course. Usually logging in UTC, display in TZ localized form is a good idea (local-time can jump back, which can sometimes cause problems). Bash is awesome, but it is kind to avoid bash syntax, if it's easy to make it work well with /bin/sh dash or busybox shell... avoid the bash "function" noiseword.

Answer 8

What I decided I wanted in my solution was a function that would return a promise that resolved when the system time was accurate. I could then call that function upon startup and use its feedback to know when to start recording temperatures again. To do that, I decided to use an ntpClient to get the accurate time myself and compare it to the local system time. When the two are within a desired precision, then I can resolve the promise. When they are not, I set a timer and recheck the time, continuing until eventually the local system time becomes accurate enough. So, far this has worked just fine through several power outages (which is where the problem with inaccurate time was initially discovered).

Here's the code I used:

const Promise = require('bluebird');
const ntpClient = Promise.promisifyAll(require('ntp-client'));
const log = require('./log');

function Decay(startT, maxT, decayAmount, decayTimes) {
    // startT is initial delay (e.g. 5 seconds)
    // maxT is the max delay this ever returns (e.g. 5 minutes)
    // decayAmount is how much to decay when a threshold is crossed (e.g. increase by 0.5)
    // decayTimes is how many invocations should trigger a decayAmount (e.g. every 5 times)

    // example: var d = new Decay(5000, 5*60*1000, .5, 5);
    // each 5 seconds, to a max of 5 minutes, getting 50% longer every 5 invocations

    // make sure decayTimes is at least 1 and not negative
    decayTimes = Math.max(decayTimes, 1);
    var num = 0;
    var currentDelay = startT;
    var start = Date.now();

    this.val = function() {
        var elapsed = Date.now() - start;
        // if evenly divisible by decayTimes, then bump the increment
        if (num !== 0 && num % decayTimes === 0) {
            currentDelay = Math.min(Math.round((1 + decayAmount) * currentDelay), maxT);
        }
        ++num;
        return currentDelay;
    };
}

function checkSystemTime(precision) {
    precision = precision || 5000;
    return ntpClient.getNetworkTimeAsync("pool.ntp.org", 123).then(function(ntpTime) {
        return Math.abs(ntpTime.getTime() - Date.now()) <= precision;
    });
}

function waitForAccurateSystemTime(precision, howLong) {
    var start = Date.now();
    // retry starts every 5 seconds, repeats 5 times, then increases by 50% 
    //   up until longest retry time of once every 15 minutes
    var decay = new Decay(5000, 15*60*1000, .5, 5);
    var errCntr = 0;
    var inaccurateCntr = 0;

    function logRetries() {
        // only log anything if there were more than five consecutive errors
        if (errCntr > 5 || inaccurateCntr > 0) {
            log(7, "Time synchronization issue, errCntr = " + errCntr + ", inaccurateCntr = " + inaccurateCntr);
        }
    }

    return new Promise(function(resolve, reject) {

        function check() {
            checkSystemTime(precision).then(function(accurate) {
                if (accurate) {
                    resolve(true);
                } else {
                    ++inaccurateCntr;
                    again();
                }
            }, again);
        }

        function again() {
            ++errCntr;
            if (errCntr == 10) {
                // only log once here that we're in a retry loop on 10th retry
                // final logging will be done later
                log(7, "In retry loop waiting for system time to agree with ntp server time");
            }
            // if we're only supposed to go for a certain amount of time, then check to see
            // if we exceeded that amount of time.  If not, set timer for next decay() value.
            if (!howLong || Date.now() - start <= howLong) {
                setTimeout(check, decay.val());
            } else {
                var err = "timeout waiting for accurate system time";
                log(7, err);
                reject(err);
            }
        }

        check();
    }).then(function(result) {
        logRetries();
        return result;
    }).catch(function(err) {
        logRetries();
        throw err;
    });
}

module.exports = {
    checkSystemTime: checkSystemTime,
    waitForAccurateSystemTime: waitForAccurateSystemTime,
    Decay: Decay
};

And, I use this like this:

const validTime = require("./valid-time");
validTime.waitForAccurateSystemTime(2 * 60 * 1000, 0).then({
    // start operation here that requires accurate system time
}).catch({
    // abort process, no accurate system time could be found
});