Re: [ntp:questions] implementing a simple ntp server: offset jumps

[Brian Inglis]

On 2016-11-26 16:26, folkert wrote:

For fun I'm implementing a simple ntp-server which gets its time from
a gps with pps.
Now this works somewhat: most of the time the offset is pretty low
compared to a system with a real ntp implementation but sometimes
the offset is almost a second, as if something wraps.
I've been staring for hours at the code and can't find the bug.
Maybe you guys want to look?


Only thing that comes to mind is that by the time you receive the GPS
message and process it, time is nearly at the next second, and your
timestamps make that obvious.
All you're showing us are the symptoms and results of the timing error,
not the data which causes it.

What you think is happening probably isn't what's happening, or when,
and you may need timing info around your function calls to see where
that is occurring e.g. if you have WiFi or USB or combined, something
sometimes may take hundreds of ms instead of ms away from your thread
e.g. a syscall which sometimes blocks, rescheduling your thread.

Change your process(es) based on the NTP *V4* reference implementation:
https://tools.ietf.org/html/rfc5905
and dump out your real local system hardware time stamp, showing all
the incoming packet NTP time stamps with the changes in the state
variables and the results of the calculations on them, the same with
the outgoing packet, GPS PPS, and GPS messages.

Preferably these should be queued to an output thread, and the source
of the timing error should become obvious.

--
Take care. Thanks, Brian Inglis, Calgary, Alberta, Canada
___
questions mailing list
questions@lists.ntp.org
http://lists.ntp.org/listinfo/questions

[ntp:questions] implementing a simple ntp server: offset jumps

[folkert]

Hi,

For fun I'm implementing a simple ntp-server which gets its time from a
gps with pps.
Now this works somewhat: most of the time the offset is pretty low
compared to a system with a real ntp implementation but sometimes the
offset is almost a second, as if something wraps.
I've been staring for hours at the code and can't find the bug. Maybe
you guys want to look?

void processNtpPackets(word targetPort, byte opponentIp[4], uint16_t 
opponentPort, const uint8_t *data, word len) {

  // timestamp from when the packet was received
  uint64_t requestReceiveAtServer = get_ntp_ts();

  uint8_t ntp_send_buffer[48];
  memcpy(ntp_send_buffer, data, sizeof ntp_send_buffer);

  // https://tools.ietf.org/html/rfc958

  // several flags
  ntp_send_buffer[0] = ((hasFix ? 0 : 3) << 6) | (4 << 3) | (4 << 0);
  // type
  // 1 = primary reference (e.g. radio clock)
  ntp_send_buffer[1] = 1;
  // poll
  ntp_send_buffer[2] = 1;
  // precision
  ntp_send_buffer[3] = -17; // 8us

  // root delay
  ntp_send_buffer[4] = ntp_send_buffer[5] = ntp_send_buffer[6] = 
ntp_send_buffer[7] = 0;

  // root dispersion
  ntp_send_buffer[8] = ntp_send_buffer[9] = ntp_send_buffer[10] = 
ntp_send_buffer[11] = 0;

  // reference clock identifier
  memcpy(_send_buffer[12], "aGPS", 4);

  // 16:8 reference
  // last timestamp received from gps
  // ** if I use the real value for that (which can be almost a
  // ** second old), then ntpdate complains that the server is
  // ** not suitable for sync
  put_uint64_t(_send_buffer[16], get_ntp_ts());

  // 24:8 originate: copy of transmit from client
  // copy from received packet
  memcpy(_send_buffer[24], [40], 8);

  // 32:8 receive
  // when the request was received
  put_uint64_t(_send_buffer[32], requestReceiveAtServer);

  // 40:8 transmit
  // when we send the reply
  put_uint64_t(_send_buffer[40], get_ntp_ts());

  sendPacket(ntp_send_buffer);
}

What I see is:

server 10.42.46.45, stratum 1, offset -0.005966, delay 0.02910
server 10.42.46.45, stratum 1, offset -0.006345, delay 0.02829
server 10.42.46.45, stratum 1, offset -0.006417, delay 0.02852
server 10.42.46.45, stratum 1, offset 0.993544, delay 0.02864
server 10.42.46.45, stratum 1, offset 0.993544, delay 0.02859
server 10.42.46.45, stratum 1, offset 0.993360, delay 0.02901
server 10.42.46.45, stratum 1, offset -0.006317, delay 0.02835
server 10.42.46.45, stratum 1, offset -0.006236, delay 0.02826
server 10.42.46.45, stratum 1, offset -0.005912, delay 0.02901
server 10.42.46.45, stratum 1, offset -0.006384, delay 0.02855
server 10.42.46.45, stratum 1, offset 0.993440, delay 0.02892
server 10.42.46.45, stratum 1, offset 0.993831, delay 0.02933
...
and so on

and ntpdate with debug:

folkert@voga:~/Projects/fampler/trunk$ /usr/sbin/ntpdate -dv -q
10.42.46.45 
27 Nov 00:25:49 ntpdate[27205]: ntpdate 4.2.8p8@1.3265-o Tue Oct 18
19:47:01 UTC 2016 (1)
transmit(10.42.46.45)
receive(10.42.46.45)
transmit(10.42.46.45)
receive(10.42.46.45)
transmit(10.42.46.45)
receive(10.42.46.45)
transmit(10.42.46.45)
receive(10.42.46.45)
server 10.42.46.45, port 123
stratum 1, precision -17, leap 00, trust 000
refid [aGPS], delay 0.02905, dispersion 0.02252
transmitted 4, in filter 4
reference time:dbe49883.7854c6a8  Sun, Nov 27 2016  0:25:55.470
originate timestamp: dbe49883.785626fb  Sun, Nov 27 2016  0:25:55.470
transmit timestamp:  dbe49883.656c48ed  Sun, Nov 27 2016  0:25:55.396
filter delay:  0.02905  0.11633  0.05977  0.10786 
 0.0  0.0  0.0  0.0 
filter offset: -0.00580 0.037552 0.009143 0.032719
 0.00 0.00 0.00 0.00
delay 0.02905, dispersion 0.02252
offset -0.005805

27 Nov 00:25:55 ntpdate[27205]: adjust time server 10.42.46.45 offset
-0.005805 sec
folkert@voga:~/Projects/fampler/trunk$ /usr/sbin/ntpdate -dv -q
10.42.46.45 
27 Nov 00:25:56 ntpdate[27224]: ntpdate 4.2.8p8@1.3265-o Tue Oct 18
19:47:01 UTC 2016 (1)
transmit(10.42.46.45)
receive(10.42.46.45)
transmit(10.42.46.45)
receive(10.42.46.45)
transmit(10.42.46.45)
receive(10.42.46.45)
transmit(10.42.46.45)
receive(10.42.46.45)
server 10.42.46.45, port 123
stratum 1, precision -17, leap 00, trust 000
refid [aGPS], delay 0.02940, dispersion 0.01137
transmitted 4, in filter 4
reference time:dbe4988b.d7f3d68a  Sun, Nov 27 2016  0:26:03.843
originate timestamp: dbe4988b.d7f536dd  Sun, Nov 27 2016  0:26:03.843
transmit timestamp:  dbe4988a.cbd9a868  Sun, Nov 27 2016  0:26:02.796
filter delay:  0.02940  0.08627  0.04507  0.08044 
 0.0  0.0  0.0  0.0 
filter offset: 0.994249 1.022678 0.991374 1.019840
 0.00 0.00 0.00 0.00
delay 0.02940, dispersion 0.01137
offset 0.994249

27 Nov 00:26:02 ntpdate[27224]: step time server 10.42.46.45 offset
0.994249 sec


Folkert van Heusden

-- 
--
Phone: +31-6-41278122, PGP-key: 1F28D8AE, www.vanheusden.com
___
questions mailing list