Will Snook.com

NTP and Raspberry Pi data logging

29 Aug 2017

Update 10 Sep 2017: To use ntpq, you may need to do sudo apt-get install ntp because Raspbian Stretch Lite uses systemd-timesyncd while Jessie Lite uses ntpd. I originally wrote this for Jessie.

----

To run a Raspberry Pi as a data logger, you need to pay special attention to the system time because the clock doesn't have a battery. It's possible to add an RTC module with battery backup, but Raspbian defaults to using NTP because it's cheaper. NTP usually works great, but network or power problems can cause timekeeping problems. To avoid incorrect time after power outages, you can have your data logging service monitor NTP's status and wait to record measurements until the time is stable.

In my experience with Raspberry Pi data logging on a home network, NTP works fine as long as the power stays on. But, after power outages, my Raspberry Pi, WiFi router, and DSL modem have a race. Normally, the Raspberry Pi boots before the DSL link comes back up. So, during that interval, the Pi's system clock is wrong because NTP can't talk to any time servers. By using the ntpq command, you can monitor NTP's confidence about whether it knows the current time.

Glossary

NTP stands for Network Time Protocol, and its purpose is to let networked computers synchronize their clocks to official standard time sources. [1]

ntpd is a service that runs as part of Raspbian and other operating systems for the purpose of implementing NTP. [2]

ntpq is a command line tool that can query ntpd about its status. [2]

NTP peer means a computer running ntpd that is involved in synchronizing its system clock with other computers running ntpd. Technically, the Raspberry Pi is an NTP peer. But, in this context, the interesting peers are servers with a close connection to a highly accurate time source like an atomic clock or a GPS receiver. I use time server to mean an NTP peer with a low-latency link to an accurate time source.

System clock means the operating system kernel's mechanism for tracking clock time. In this context, it means a clock that will lose track of time during a reboot or shutdown.

RTC stands for Real Time Clock. Desktop computers and laptops usually have an RTC module with a backup battery that keeps a clock running when the rest of the computer is turned off. Raspberry Pi computers do not include RTC modules because the Raspberry Pi Foundation wanted to avoid using expensive components.

WAN stands for Wide Area Network. In this case, it means a DSL link from my home network to the Internet.

LAN stands for Local Area Network. In this case, it means the WiFi network that I use to ssh from my laptop to my Raspberry Pi.

Understanding ntpq's output

To monitor ntpd's status as it tries to keep the Raspberry Pi system clock synchronized with standard time, I use ntpq. Here's an example of the output from running "ntpq -np" when the network is up and the system clock is set accurately:

remote refid st t when poll reach delay offset jitter ============================================================================== 37.187.104.44 193.190.230.66 2 u 4 64 1 155.415 -0.792 0.565 85.199.213.50 85.199.214.101 2 u 16 64 0 0.000 0.000 0.001 2003:a:47f:abe4 192.168.100.15 2 u 16 64 0 0.000 0.000 0.001 *129.6.15.30 .NIST. 1 u 9 64 1 84.992 -1.525 1.717

Approximately speaking, if you see a peer line with a * in the first column, it means that NTP is happy and your clock is probably set correctly. In this case, the last line starts with *, so NTP is happy.

In more technical language, the first column of a peer status line is a character code representing the value of the select field of the peer status word [3, 4, 5].

What happens if the DSL link is down?

Here's what happened when I ran an experiment to simulate my DSL modem and Raspberry Pi booting up simultaneously after a power outage. To test ntpd, I just needed to make the Raspberry Pi reboot without a WAN link, then reconnect the WAN after a delay. This was my procedure:

  1. Unplug my DSL modem's Ethernet cable from the WiFi router
  2. Reboot the Raspberry Pi
  3. SSH into the Raspberry Pi and prepare to run the script shown below
  4. Simultaneously plug the DSL modem's Ethernet cable back into the Wifi router and start my script for monitoring the system clock and ntpq

This is my script for watching the system clock and the output of ntpq:

#!/bin/bash # Append the output of date and ntpq to a log file once a second for 80 seconds for i in `seq 1 80`; do date | tee --append /home/pi/ntpq.log echo '%%' | tee --append /home/pi/ntpq.log ntpq -np | tee --append /home/pi/ntpq.log echo '%%' | tee --append /home/pi/ntpq.log sleep 1 done

The script ran for 80 seconds. Initially, ntpq was mad because ntpd couldn't talk to its time servers. It took ntpd 61 seconds to realize the WAN link was back up and to make initial contact with the servers. About 6 seconds after that, ntpd made its first adjustment to the system clock. After 6 more seconds, ntpd selected the NIST peer.

The actual log output was long and boring, but here's an edited version:

Tue Aug 29 13:07:42 CDT 2017 %% No association ID's returned %% Tue Aug 29 13:07:43 CDT 2017 %% No association ID's returned %%

[skipping more "No association ID's returned"]

Tue Aug 29 13:08:42 CDT 2017 %% No association ID's returned %% Tue Aug 29 13:08:43 CDT 2017 %% remote refid st t when poll reach delay offset jitter ============================================================================== 37.187.104.44 .INIT. 16 u - 64 0 0.000 0.000 0.000 85.199.213.50 .INIT. 16 u - 64 0 0.000 0.000 0.000 2003:a:47f:abe4 .INIT. 16 u - 64 0 0.000 0.000 0.000 129.6.15.30 .INIT. 16 u - 64 0 0.000 0.000 0.000 %% Tue Aug 29 13:08:45 CDT 2017 %% remote refid st t when poll reach delay offset jitter ============================================================================== 37.187.104.44 .INIT. 16 u - 64 0 0.000 0.000 0.000 85.199.213.50 85.199.214.101 2 u 1 64 1 158.662 902353. 0.001 2003:a:47f:abe4 192.168.100.15 2 u 1 64 1 243.053 902361. 0.001 129.6.15.30 .NIST. 1 u 1 64 1 91.500 902353. 0.001 %%

Several cues here tell us that NTP does not yet know the correct time: the select fields are all " ", the refid fields still have ".INIT.", when is "-", etc.

[skipping more of ntpd's initial exchange with its NTP peers]

Tue Aug 29 13:08:49 CDT 2017 %% remote refid st t when poll reach delay offset jitter ============================================================================== 37.187.104.44 .INIT. 16 u - 64 0 0.000 0.000 0.000 85.199.213.50 85.199.214.101 2 u 1 64 1 157.448 902353. 0.108 2003:a:47f:abe4 192.168.100.15 2 u 1 64 1 236.481 902360. 0.861 129.6.15.30 .NIST. 1 u 1 64 1 87.738 902352. 0.927 %% Tue Aug 29 13:23:52 CDT 2017 %% remote refid st t when poll reach delay offset jitter ============================================================================== 37.187.104.44 .STEP. 16 u - 64 0 0.000 0.000 0.001 85.199.213.50 85.199.214.101 2 u 1 64 0 0.000 0.000 0.001 2003:a:47f:abe4 192.168.100.15 2 u 1 64 0 0.000 0.000 0.001 129.6.15.30 .STEP. 16 u 89 64 0 0.000 0.000 0.001 %%

Note the switch from ".NIST." to ".STEP." that corresponded with a system clock jump from "13:08:49" to "13:23:52". The system clock step adjustment happened 68 seconds after I connected the DSL modem.

[skipping more of ntpd's exchange with its NTP peers]

Tue Aug 29 13:23:58 CDT 2017 %% remote refid st t when poll reach delay offset jitter ============================================================================== 37.187.104.44 193.190.230.66 2 u - 64 1 155.727 -0.785 0.752 85.199.213.50 85.199.214.101 2 u 6 64 0 0.000 0.000 0.001 2003:a:47f:abe4 192.168.100.15 2 u 6 64 0 0.000 0.000 0.001 129.6.15.30 .NIST. 1 u 1 64 1 85.445 -1.498 2.108 %% Tue Aug 29 13:23:59 CDT 2017 %% remote refid st t when poll reach delay offset jitter ============================================================================== 37.187.104.44 193.190.230.66 2 u 1 64 1 155.727 -0.785 0.752 85.199.213.50 85.199.214.101 2 u 7 64 0 0.000 0.000 0.001 2003:a:47f:abe4 192.168.100.15 2 u 7 64 0 0.000 0.000 0.001 *129.6.15.30 .NIST. 1 u - 64 1 84.992 -1.525 1.717 %%

About 7 seconds after the first clock adjustment, the select field on the bottom line switched from " " to "*" as ntpd picked the NIST server as its selected peer. The rest of the log looked similar to the last output from ntpq above.

At this point, ntpd is happy and the system clock should be set accurately, so it would be okay for a data logger service to start recording measurements.

Code examples

Here are examples of ways to test whether NTP has selected a peer and synchronized the system clock.

If you're feeling impatient, try this from a bash prompt:

if ntpq -np | grep '^\*'; then echo NTP is happy; else echo not sure; fi

Or, if you want to try a bash script, you can do this:

#!/bin/bash ntpq -np | grep --quiet '^\*' if [ $? == 0 ]; then # Do this stuff if the time is ready (maybe start your data logger?) echo NTP is happy else # Do this stuff if the time is not ready (maybe keep waiting?) echo not sure fi

Or, if you want to use Python, try this:

#!/usr/bin/env python2.7 import os if os.system("ntpq -np | grep --quiet '^\*'") == 0: # Do this stuff if the time is ready (maybe start your data logger?) print "NTP is happy" else: # Do this stuff if the time is not ready (maybe keep waiting?) print "not sure"

The output "NTP is happy" means your clock is probably set accurately. But, if you see "not sure", there's a fair chance that your clock is wrong.

These examples all work by grepping the output of ntpq for a peer status line that starts with "*".

References

  1. Sections four, five, and six of the ntp.org NTP FAQ and Howto.
  2. Raspbian's NTP documentation: man ntpd, man ntpq, and the README files in /usr/share/doc/ntp
  3. https://www.eecis.udel.edu/~mills/ntp/html/ntpq.html: in the Control Message Commands section, the table for peers explains the fields for ntpq -p
  4. https://www.eecis.udel.edu/~mills/ntp/html/decode.html#peer explains the peer status word
  5. Aron Toponce's Real Life NTP post gives a quick overview of NTP and how to understand ntpq's output
  6. My experiments on a Raspberry Pi 3 Model B and Raspberry Pi Zero W running the April 10, 2017 version of Raspbian Jessie Lite