| Re: [chrony-users] Time synchronisation over a high-latency packet radio network |
[ Thread Index |
Date Index
| More chrony.tuxfamily.org/chrony-users Archives
]
- To: chrony-users@xxxxxxxxxxxxxxxxxxxx
- Subject: Re: [chrony-users] Time synchronisation over a high-latency packet radio network
- From: Stuart Longland <stuartl@xxxxxxxxxxxxxxxxxx>
- Date: Sun, 12 May 2019 17:07:31 +1000
- Openpgp: id=77102FB21549FFDE5E13B83A0C7F53F4F359B8EF; url=https://stuartl.longlandclan.id.au/key.asc
On 7/5/19 6:11 pm, Miroslav Lichvar wrote:
> I'd suggest to set maxdistance to 5 or 10 to make sure it's not a
> problem with selecting the source. Try to reproduce the problem and
> post the output from the chronyc ntpdata, sources, sourcestats and
> tracking commands.
Okay, so testing at home… I've done the following:
1. I actually went through my code with a fine-toothed comb to pick up
some bugs. Notably, I have unit tests for the `aioax25` library being used.
2. I tweaked some settings in chrony.conf, notably:
server 127.0.0.1 port 3123 trust maxdelay 30 minpoll 3
maxjitter 30
maxdistance 30
minsamples 4
initstepslew 30 127.0.0.1
The `initstepslew` doesn't seem to quite work, not sure if it's possible
to set a port number on that or not.
maxjitter is no doubt huge, but I'm being conservative here. We're
going to experience a lot more jitter because it's a shared 1200 baud
link -- so if another station is transmitting, we must wait.
maxdistance was set to 30 here because again, a transmission may be
delayed for any number of reasons, especially if there are repeaters
involved, so I'm again being conservative.
3. I added some debugging statements in my code so I could verify that
the NTP traffic was being received and delivered.
The following shows the software doing a successful time sync from boot,
with `tshark` traces of the traffic.
> root@hackerlab:~# tail -n 0 -F /var/log/wicen-rfid.log /var/log/chrony/*.log /var/log/daemon.log & tshark -s0 -i lo -O ntp -d udp.port==3123,ntp -f 'udp port 3123'
> [1] 1252
> ==> /var/log/wicen-rfid.log <==
>
> ==> /var/log/chrony/measurements.log <==
>
> ==> /var/log/chrony/statistics.log <==
>
> ==> /var/log/chrony/tracking.log <==
>
> ==> /var/log/daemon.log <==
> Running as user "root" and group "root". This could be dangerous.
> tshark: Lua: Error during loading:
> /usr/share/wireshark/init.lua:32: dofile has been disabled due to running Wireshark as superuser. See https://wiki.wireshark.org/CaptureSetup/CapturePrivileges for help in running Wireshark as an unprivileged user.
> Nov 3 17:18:07 hackerlab systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
> Capturing on 'Loopback'
> Nov 3 17:18:07 hackerlab connmand[538]: lo {newlink} index 1 address 00:00:00:00:00:00 mtu 65536
> Nov 3 17:18:07 hackerlab connmand[538]: lo {newlink} index 1 operstate 0 <UNKNOWN>
> Nov 3 17:18:10 hackerlab dnsmasq-dhcp[1096]: DHCPREQUEST(usb0) 192.168.7.1 38:d2:69:4f:13:0a
> Nov 3 17:18:10 hackerlab dnsmasq-dhcp[1096]: DHCPACK(usb0) 192.168.7.1 38:d2:69:4f:13:0a rikishi
> Nov 3 17:18:12 hackerlab systemd[1]: Starting chrony, an NTP client/server...
> Nov 3 17:18:12 hackerlab chronyd[1294]: chronyd version 3.0 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SECHASH +SIGND +ASYNCDNS +IPV6 -DEBUG)
>
> ==> /var/log/chrony/tracking.log <==
> ==================================================================================================
> Date (UTC) Time IP Address St Freq ppm Skew ppm Offset L Co Offset sd Rem. corr.
> ==================================================================================================
> 2016-11-03 17:18:12 0.0.0.0 0 26.917 158.544 0.000e+00 ? 0 0.000e+00 -1.202e-15
>
> ==> /var/log/daemon.log <==
> Nov 3 17:18:12 hackerlab chronyd[1294]: Frequency 26.917 +/- 158.544 ppm read from /var/lib/chrony/chrony.drift
> Nov 3 17:18:18 hackerlab systemd[1]: serial-getty@xxxxxxxxxxxxxx: Service hold-off time over, scheduling restart.
> Nov 3 17:18:18 hackerlab systemd[1]: Stopped Serial Getty on ttyGS0.
> Nov 3 17:18:18 hackerlab systemd[1]: Started Serial Getty on ttyGS0.
> Nov 3 17:18:22 hackerlab chronyd[1294]: No suitable source for initstepslew
> Nov 3 17:18:24 hackerlab systemd[1]: Started chrony, an NTP client/server.
>
> ==> /var/log/wicen-rfid.log <==
> 2016-11-03 17:18:24,999 rfidterm.aprs[aprs.py: 137] DEBUG Setting default path for message to NTP
> 2016-11-03 17:18:25,001 rfidterm.aprs[aprs.py: 143] INFO Send one-shot to NTP: TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMnd0HwmN7yU
> 2016-11-03 17:18:25,003 rfidterm.aprs[aprs.py: 286] INFO Sending VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMnd0HwmN7yU'
> 2016-11-03 17:18:25,012 rfidterm.ax25[interface.py: 64] DEBUG Adding to queue: VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMnd0HwmN7yU'
> 2016-11-03 17:18:25,017 rfidterm.ax25[interface.py: 115] DEBUG Scheduling next transmission ASAP
> 2016-11-03 17:18:25,019 rfidterm.ntp[ntpproxy.py: 81] DEBUG Relaying NTP request from ('127.0.0.1', 55721): 23000320000000000000000000000000000000000000000000000000000000000000000000000000c9ddd07c2637bc94
> 2016-11-03 17:18:25,020 rfidterm.ax25[interface.py: 131] DEBUG Transmitting VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMnd0HwmN7yU'
> 2016-11-03 17:18:25,022 rfidterm.kiss.port0[kiss.py: 428] DEBUG XMIT AX.25 VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAMnd0HwmN7yU'
> 2016-11-03 17:18:25,030 rfidterm.kiss[kiss.py: 215] DEBUG XMIT FRAME '009ca8a040404060ac96689aa698e0ae92888a624062ae92888a64406303f03a4e54502020202020203a54533a49774144494141414141414141414141414141414141414141414141414141414141414141414141414141414141414141414141414d6e643048776d4e377955'
> 2016-11-03 17:18:25,035 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 113.19188865529328
> 2016-11-03 17:18:25,041 rfidterm.kiss[kiss.py: 308] DEBUG XMIT RAW 'c0009ca8a040404060ac96689aa698e0ae92888a624062ae92888a64406303f03a4e54502020202020203a54533a49774144494141414141414141414141414141414141414141414141414141414141414141414141414141414141414141414141
> Frame 1: 90 bytes on wire (720 bits), 90 bytes captured (720 bits) on interface 0
> Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: 00:00:00_00:00:00 (00:00:00:00:00:00)
> Internet Protocol Version 4, Src: 127.0.0.1, Dst: 127.0.0.1
> User Datagram Protocol, Src Port: 55721, Dst Port: 3123
> Network Time Protocol (NTP Version 4, client)
> Flags: 0x23, Leap Indicator: no warning, Version number: NTP Version 4, Mode: client
> 00.. .... = Leap Indicator: no warning (0)
> ..10 0... = Version number: NTP Version 4 (4)
> .... .011 = Mode: client (3)
> Peer Clock Stratum: unspecified or invalid (0)
> Peer Polling Interval: invalid (3)
> Peer Clock Precision: 4294967296.000000 sec
> Root Delay: 0 seconds
> Root Dispersion: 0 seconds
> Reference ID: NULL
> Reference Timestamp: Jan 1, 1970 00:00:00.000000000 UTC
> Origin Timestamp: Jan 1, 1970 00:00:00.000000000 UTC
> Receive Timestamp: Jan 1, 1970 00:00:00.000000000 UTC
> Transmit Timestamp: Apr 28, 2007 13:54:04.149287973 UTC
>
> 2016-11-03 17:18:28,957 rfidterm.rfid[rfid.py: 183] WARNING RFID reader has timed out
> 2016-11-03 17:18:28,958 rfidterm.aprs[aprs.py: 137] DEBUG Setting default path for message to VK4MSL-10
> 2016-11-03 17:18:28,964 rfidterm.aprs.message[message.py: 60] DEBUG Initialised handler for 1 state HandlerState.INIT
> 2016-11-03 17:18:28,965 rfidterm.aprs.message[message.py: 126] DEBUG Cancelling timer for 1
> 2016-11-03 17:18:28,973 rfidterm.aprs.message[message.py: 91] INFO Preparing to send 1 (state HandlerState.INIT)
> 2016-11-03 17:18:28,974 rfidterm.aprs[aprs.py: 286] INFO Sending VK4MSL>VK4MSL-10,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':VK4MSL-10:M:1 L:2 T:171828 C:RFID reader has timed out{1'
> 2016-11-03 17:18:28,983 rfidterm.ax25[interface.py: 64] DEBUG Adding to queue: VK4MSL>VK4MSL-10,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':VK4MSL-10:M:1 L:2 T:171828 C:RFID reader has timed out{1'
> 2016-11-03 17:18:28,988 rfidterm.ax25[interface.py: 115] DEBUG Scheduling next transmission ASAP
> 2016-11-03 17:18:28,993 rfidterm.aprs.message[message.py: 150] DEBUG 1 entering state HandlerState.SEND
> 2016-11-03 17:18:28,999 rfidterm.ax25[interface.py: 131] DEBUG Transmitting VK4MSL>VK4MSL-10,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':VK4MSL-10:M:1 L:2 T:171828 C:RFID reader has timed out{1'
> 2016-11-03 17:18:29,004 rfidterm.kiss.port0[kiss.py: 428] DEBUG XMIT AX.25 VK4MSL>VK4MSL-10,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':VK4MSL-10:M:1 L:2 T:171828 C:RFID reader has timed out{1'
> 2016-11-03 17:18:29,011 rfidterm.kiss[kiss.py: 215] DEBUG XMIT FRAME '00ac96689aa69874ac96689aa698e0ae92888a624062ae92888a64406303f03a564b344d534c2d31303a4d3a31204c3a3220543a31373138323820433a5246494420726561646572206861732074696d6564206f75747b31'
> 2016-11-03 17:18:29,016 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 117.0425119500675
> 2016-11-03 17:18:29,021 rfidterm.kiss[kiss.py: 308] DEBUG XMIT RAW 'c000ac96689aa69874ac96689aa698e0ae92888a624062ae92888a64406303f03a564b344d534c2d31303a4d3a31204c3a3220543a31373138323820433a5246494420726561646572206861732074696d6564206f75747b31c0'
> 2016-11-03 17:18:33,058 rfidterm.aprs[aprs.py: 137] DEBUG Setting default path for message to NTP
> 2016-11-03 17:18:33,060 rfidterm.aprs[aprs.py: 143] INFO Send one-shot to NTP: TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAhpxrakQDGN
> 2016-11-03 17:18:33,062 rfidterm.aprs[aprs.py: 286] INFO Sending VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAhpxrakQDGN'
> 2016-11-03 17:18:33,071 rfidterm.ax25[interface.py: 64] DEBUG Adding to queue: VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAhpxrakQDGN'
> 2016-11-03 17:18:33,076 rfidterm.ax25[interface.py: 115] DEBUG Scheduling next transmission ASAP
> 2016-11-03 17:18:33,081 rfidterm.ntp[ntpproxy.py: 81] DEBUG Relaying NTP request from ('127.0.0.1', 37132): 230003200000000000000000000000000000000000000000000000000000000000000000000000000869c6b6a440318d
> 2016-11-03 17:18:33,086 rfidterm.ax25[interface.py: 131] DEBUG Transmitting VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAhpxrakQDGN'
> 2016-11-03 17:18:33,091 rfidterm.kiss.port0[kiss.py: 428] DEBUG XMIT AX.25 VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAhpxrakQDGN'
> 2016-11-03 17:18:33,098 rfidterm.kiss[kiss.py: 215] DEBUG XMIT FRAME '009ca8a040404060ac96689aa698e0ae92888a624062ae92888a64406303f03a4e54502020202020203a54533a49774144494141414141414141414141414141414141414141414141414141414141414141414141414141414141414141414141414168707872616b5144474e'
> 2016-11-03 17:18:33,103 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 121.09111397034229
> 2016-11-03 17:18:33,109 rfidterm.kiss[kiss.py: 308] DEBUG XMIT RAW 'c0009ca8a040404060ac96689aa698e0ae92888a624062ae92888a64406303f03a4e54502020202020203a54533a49774144494141414141414141414141414141414141414141414141414141414141414141414141414141414141414141414141
> 414168707872616b5144474ec0'
> Frame 2: 90 bytes on wire (720 bits), 90 bytes captured (720 bits) on interface 0
> Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: 00:00:00_00:00:00 (00:00:00:00:00:00)
> Internet Protocol Version 4, Src: 127.0.0.1, Dst: 127.0.0.1
> User Datagram Protocol, Src Port: 37132, Dst Port: 3123
> Network Time Protocol (NTP Version 4, client)
> Flags: 0x23, Leap Indicator: no warning, Version number: NTP Version 4, Mode: client
> 00.. .... = Leap Indicator: no warning (0)
> ..10 0... = Version number: NTP Version 4 (4)
> .... .011 = Mode: client (3)
> Peer Clock Stratum: unspecified or invalid (0)
> Peer Polling Interval: invalid (3)
> Peer Clock Precision: 4294967296.000000 sec
> Root Delay: 0 seconds
> Root Dispersion: 0 seconds
> Reference ID: NULL
> Reference Timestamp: Jan 1, 1970 00:00:00.000000000 UTC
> Origin Timestamp: Jan 1, 1970 00:00:00.000000000 UTC
> Receive Timestamp: Jan 1, 1970 00:00:00.000000000 UTC
> Transmit Timestamp: Jun 22, 1904 16:17:58.641604515 UTC
>
> 2016-11-03 17:18:36,428 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW 'c000ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d4437514141453363414141656f'
> 2016-11-03 17:18:36,433 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:18:36,477 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW '473378392b7543434f71684b702b455343476e47747152414d593367676a394e685339596b4f4343503032464f506f76'
> 2016-11-03 17:18:36,483 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:18:36,488 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW 'c0'
> 2016-11-03 17:18:36,493 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:18:36,498 rfidterm.kiss[kiss.py: 252] DEBUG RECV FRAME end at 96
> 2016-11-03 17:18:36,502 rfidterm.kiss[kiss.py: 261] DEBUG RECEIVED FRAME 00ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a545
> 33a4a414d4437514141453363414141656f473378392b7543434f71684b702b455343476e47747152414d593367676a394e685339596b4f4343503032464f506f76, REMAINING c0
> 2016-11-03 17:18:36,508 rfidterm.kiss[kiss.py: 291] DEBUG RECV FRAME dispatch KISSCmdData{Port 0, Cmd 0x00, Payload ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d4437514141453363414141656f473378392b7543434f71684b702b455343476e47747152414d593367676a394e685339596b4f4343503032464f506f76}
> 2016-11-03 17:18:36,515 rfidterm.kiss.port0[kiss.py: 435] DEBUG Received frame KISSCmdData{Port 0, Cmd 0x00, Payload ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d4437514141453363414141656f473378392b7543434f71684b702b455343476e47747152414d593367676a394e685339596b4f4343503032464f506f76}
> 2016-11-03 17:18:36,520 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 124.67037597612293
> 2016-11-03 17:18:36,527 rfidterm.ax25[router.py: 98] DEBUG Handling incoming frame VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAeoG3x9+uCCOqhKp+ESCGnGtqRAMY3ggj9NhS9YkOCCP02FOPov'
> 2016-11-03 17:18:36,534 rfidterm.ax25[router.py: 136] DEBUG Dispatching frame to 1 receivers
> 2016-11-03 17:18:36,542 rfidterm.aprs[aprs.py: 246] DEBUG Processing incoming message VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAeoG3x9+uCCOqhKp+ESCGnGtqRAMY3ggj9NhS9YkOCCP02FOPov' (type APRSMessageFrame)
> 2016-11-03 17:18:36,548 rfidterm.aprs[router.py: 98] DEBUG Handling incoming frame VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAeoG3x9+uCCOqhKp+ESCGnGtqRAMY3ggj9NhS9YkOCCP02FOPov'
> 2016-11-03 17:18:36,553 rfidterm.aprs[router.py: 136] DEBUG Dispatching frame to 0 receivers
> 2016-11-03 17:18:36,558 rfidterm.ntp[ntpproxy.py: 84] DEBUG Received message: VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAeoG3x9+uCCOqhKp+ESCGnGtqRAMY3ggj9NhS9YkOCCP02FOPov'
>
> ==> /var/log/chrony/measurements.log <==
> ========================================================================================================================================
> Date (UTC) Time IP Address L St 123 567 ABCD LP RP Score Offset Peer del. Peer disp. Root del. Root disp. Refid MTxRx
> ========================================================================================================================================
> 2016-11-03 17:18:34 127.0.0.1 N 3 111 111 1111 3 3 0.00 7.945e+07 3.507e+00 7.017e-03 7.603e-02 2.991e-02 1B7C7DFA 4B D K
>
> ==> /var/log/wicen-rfid.log <==
> 2016-11-03 17:18:36,567 rfidterm.ntp[ntpproxy.py: 104] DEBUG Relayed NTP reply to ('127.0.0.1', 37132): 240303ed00001377000007a81b7c
> 7dfae0823aa84aa7e1120869c6b6a440318de0823f4d852f5890e0823f4d8538fa2f
> Frame 3: 90 bytes on wire (720 bits), 90 bytes captured (720 bits) on interface 0
> Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: 00:00:00_00:00:00 (00:00:00:00:00:00)
> Internet Protocol Version 4, Src: 127.0.0.1, Dst: 127.0.0.1
> User Datagram Protocol, Src Port: 3123, Dst Port: 37132
> Network Time Protocol (NTP Version 4, server)
> Flags: 0x24, Leap Indicator: no warning, Version number: NTP Version 4, Mode: server
> 00.. .... = Leap Indicator: no warning (0)
> ..10 0... = Version number: NTP Version 4 (4)
> .... .100 = Mode: server (4)
> Peer Clock Stratum: secondary reference (3)
> Peer Polling Interval: invalid (3)
> Peer Clock Precision: 0.000002 sec
> Root Delay: 0.0760345458984375 seconds
> Root Dispersion: 0.0299072265625 seconds
> Reference ID: 27.124.125.250
> Reference Timestamp: May 12, 2019 06:24:40.291624133 UTC
> Origin Timestamp: Jun 22, 1904 16:17:58.641604515 UTC
> Receive Timestamp: May 12, 2019 06:44:29.520253691 UTC
> Transmit Timestamp: May 12, 2019 06:44:29.520400654 UTC
>
> 2016-11-03 17:18:44,635 rfidterm.aprs[aprs.py: 137] DEBUG Setting default path for message to NTP
> 2016-11-03 17:18:44,637 rfidterm.aprs[aprs.py: 143] INFO Send one-shot to NTP: TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/TYU4+i9j255IOPB763qPfXGBqob9
> 2016-11-03 17:18:44,639 rfidterm.aprs[aprs.py: 286] INFO Sending VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/TYU4+i9j255IOPB763qPfXGBqob9'
> 2016-11-03 17:18:44,648 rfidterm.ax25[interface.py: 64] DEBUG Adding to queue: VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/TYU4+i9j255IOPB763qPfXGBqob9'
> 2016-11-03 17:18:44,653 rfidterm.ax25[interface.py: 115] DEBUG Scheduling next transmission ASAP
> 2016-11-03 17:18:44,658 rfidterm.ntp[ntpproxy.py: 81] DEBUG Relaying NTP request from ('127.0.0.1', 36587): 230003200000000000000000000000000000000000000000e0823f4d8538fa2f63db9e4838f07beb7a8f7d7181aa86fd
> 2016-11-03 17:18:44,660 rfidterm.ax25[interface.py: 131] DEBUG Transmitting VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/TYU4+i9j255IOPB763qPfXGBqob9'
> 2016-11-03 17:18:44,661 rfidterm.kiss.port0[kiss.py: 428] DEBUG XMIT AX.25 VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/TYU4+i9j255IOPB763qPfXGBqob9'
> 2016-11-03 17:18:44,668 rfidterm.kiss[kiss.py: 215] DEBUG XMIT FRAME '009ca8a040404060ac96689aa698e0ae92888a624062ae92888a64406303f03a4e54502020202020203a54533a49774144494141414141414141414141414141414141414141414141414141413449492f545955342b69396a323535494f5042373633715066584742716f6239'
> 2016-11-03 17:18:44,674 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 132.73307436825868
> 2016-11-03 17:18:44,679 rfidterm.kiss[kiss.py: 308] DEBUG XMIT RAW 'c0009ca8a040404060ac96689aa698e0ae92888a624062ae92888a64406303f03a4e54502020202020203a54533a49774144494141414141414141414141414141414141414141414141414141413449492f545955342b69396a323535494f5042373633715066584742716f6239c0'
> Frame 4: 90 bytes on wire (720 bits), 90 bytes captured (720 bits) on interface 0
> Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: 00:00:00_00:00:00 (00:00:00:00:00:00)
> Internet Protocol Version 4, Src: 127.0.0.1, Dst: 127.0.0.1
> User Datagram Protocol, Src Port: 36587, Dst Port: 3123
> Network Time Protocol (NTP Version 4, client)
> Flags: 0x23, Leap Indicator: no warning, Version number: NTP Version 4, Mode: client
> 00.. .... = Leap Indicator: no warning (0)
> ..10 0... = Version number: NTP Version 4 (4)
> .... .011 = Mode: client (3)
> Peer Clock Stratum: unspecified or invalid (0)
> Peer Polling Interval: invalid (3)
> Peer Clock Precision: 4294967296.000000 sec
> Root Delay: 0 seconds
> Root Dispersion: 0 seconds
> Reference ID: NULL
> Reference Timestamp: Jan 1, 1970 00:00:00.000000000 UTC
> Origin Timestamp: May 12, 2019 06:44:29.520400654 UTC
> Receive Timestamp: Feb 2, 1953 11:28:08.222419495 UTC
> Transmit Timestamp: Feb 27, 1965 21:21:53.506508290 UTC
>
> 2016-11-03 17:18:48,049 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW 'c000ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d44375141414533634141416579'
> 2016-11-03 17:18:48,054 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:18:48,059 rfidterm.kiss[kiss.py: 252] DEBUG RECV FRAME end at 1
> 2016-11-03 17:18:48,063 rfidterm.kiss[kiss.py: 261] DEBUG RECEIVED FRAME , REMAINING c000ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d44375141414533634141416579
> 2016-11-03 17:18:48,065 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:18:48,099 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW '473378392b7543434f71684b702b4553656f39396359477168763367676a395a45474979594f434350316b5161377741'
> 2016-11-03 17:18:48,105 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:18:48,110 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW 'c0'
> 2016-11-03 17:18:48,115 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:18:48,120 rfidterm.kiss[kiss.py: 252] DEBUG RECV FRAME end at 96
> 2016-11-03 17:18:48,125 rfidterm.kiss[kiss.py: 261] DEBUG RECEIVED FRAME 00ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d44375141414533634141416579473378392b7543434f71684b702b4553656f39396359477168763367676a395a45474979594f434350316b5161377741, REMAINING c0
> 2016-11-03 17:18:48,130 rfidterm.kiss[kiss.py: 291] DEBUG RECV FRAME dispatch KISSCmdData{Port 0, Cmd 0x00, Payload ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d44375141414533634141416579473378392b7543434f71684b702b4553656f39396359477168763367676a395a45474979594f434350316b5161377741}
> 2016-11-03 17:18:48,136 rfidterm.kiss.port0[kiss.py: 435] DEBUG Received frame KISSCmdData{Port 0, Cmd 0x00, Payload ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d44375141414533634141416579473378392b7543434f71684b702b4553656f39396359477168763367676a395a45474979594f434350316b5161377741}
> 2016-11-03 17:18:48,141 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 136.306199570241
> 2016-11-03 17:18:48,148 rfidterm.ax25[router.py: 98] DEBUG Handling incoming frame VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAeyG3x9+uCCOqhKp+ESeo99cYGqhv3ggj9ZEGIyYOCCP1kQa7wA'
> 2016-11-03 17:18:48,153 rfidterm.ax25[router.py: 136] DEBUG Dispatching frame to 1 receivers
> 2016-11-03 17:18:48,161 rfidterm.aprs[aprs.py: 246] DEBUG Processing incoming message VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAeyG3x9+uCCOqhKp+ESeo99cYGqhv3ggj9ZEGIyYOCCP1kQa7wA' (type APRSMessageFrame)
> 2016-11-03 17:18:48,167 rfidterm.aprs[router.py: 98] DEBUG Handling incoming frame VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL
> :TS:JAMD7QAAE3cAAAeyG3x9+uCCOqhKp+ESeo99cYGqhv3ggj9ZEGIyYOCCP1kQa7wA'
> 2016-11-03 17:18:48,172 rfidterm.aprs[router.py: 136] DEBUG Dispatching frame to 0 receivers
> 2016-11-03 17:18:48,177 rfidterm.ntp[ntpproxy.py: 84] DEBUG Received message: VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAeyG3x9+uCCOqhKp+ESeo99cYGqhv3ggj9ZEGIyYOCCP1kQa7wA'
> 2016-11-03 17:18:48,184 rfidterm.ntp[ntpproxy.py: 104] DEBUG Relayed NTP reply to ('127.0.0.1', 36587): 240303ed00001377000007b21b7c7dfae0823aa84aa7e1127a8f7d7181aa86fde0823f5910623260e0823f59106bbc00
>
> ==> /var/log/chrony/measurements.log <==
> 2016-11-03 17:18:46 127.0.0.1 N 3 111 111 1111 3 3 0.00 7.945e+07 3.549e+00 7.101e-03 7.603e-02 3.006e-02 1B7C7DFA 4B D K
> Frame 5: 90 bytes on wire (720 bits), 90 bytes captured (720 bits) on interface 0
> Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: 00:00:00_00:00:00 (00:00:00:00:00:00)
> Internet Protocol Version 4, Src: 127.0.0.1, Dst: 127.0.0.1
> User Datagram Protocol, Src Port: 3123, Dst Port: 36587
> Network Time Protocol (NTP Version 4, server)
> Flags: 0x24, Leap Indicator: no warning, Version number: NTP Version 4, Mode: server
> 00.. .... = Leap Indicator: no warning (0)
> ..10 0... = Version number: NTP Version 4 (4)
> .... .100 = Mode: server (4)
> Peer Clock Stratum: secondary reference (3)
> Peer Polling Interval: invalid (3)
> Peer Clock Precision: 0.000002 sec
> Root Delay: 0.0760345458984375 seconds
> Root Dispersion: 0.030059814453125 seconds
> Reference ID: 27.124.125.250
> Reference Timestamp: May 12, 2019 06:24:40.291624133 UTC
> Origin Timestamp: Feb 27, 1965 21:21:53.506508290 UTC
> Receive Timestamp: May 12, 2019 06:44:41.063998363 UTC
> Transmit Timestamp: May 12, 2019 06:44:41.064143896 UTC
>
> ==> /var/log/daemon.log <==
> Nov 3 17:18:51 hackerlab dnsmasq-dhcp[1096]: DHCPREQUEST(usb0) 192.168.7.1 38:d2:69:4f:13:0a
> Nov 3 17:18:51 hackerlab dnsmasq-dhcp[1096]: DHCPACK(usb0) 192.168.7.1 38:d2:69:4f:13:0a rikishi
>
> ==> /var/log/wicen-rfid.log <==
> 2016-11-03 17:18:56,322 rfidterm.aprs[aprs.py: 137] DEBUG Setting default path for message to NTP
> 2016-11-03 17:18:56,324 rfidterm.aprs[aprs.py: 143] INFO Send one-shot to NTP: TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/WRBrvABsRb0lOWOEh2+U/izAq+ol
> 2016-11-03 17:18:56,326 rfidterm.aprs[aprs.py: 286] INFO Sending VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/WRBrvABsRb0lOWOEh2+U/izAq+ol'
> 2016-11-03 17:18:56,332 rfidterm.ax25[interface.py: 64] DEBUG Adding to queue: VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/WRBrvABsRb0lOWOEh2+U/izAq+ol'
> 2016-11-03 17:18:56,337 rfidterm.ax25[interface.py: 115] DEBUG Scheduling next transmission ASAP
> 2016-11-03 17:18:56,341 rfidterm.ntp[ntpproxy.py: 81] DEBUG Relaying NTP request from ('127.0.0.1', 54903): 230003200000000000000000000000000000000000000000e0823f59106bbc006c45bd25396384876f94fe2cc0abea25
> 2016-11-03 17:18:56,346 rfidterm.ax25[interface.py: 131] DEBUG Transmitting VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/WRBrvABsRb0lOWOEh2+U/izAq+ol'
> 2016-11-03 17:18:56,352 rfidterm.kiss.port0[kiss.py: 428] DEBUG XMIT AX.25 VK4MSL>NTP,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':NTP :TS:IwADIAAAAAAAAAAAAAAAAAAAAAAAAAAA4II/WRBrvABsRb0lOWOEh2+U/izAq+ol'
> 2016-11-03 17:18:56,358 rfidterm.kiss[kiss.py: 215] DEBUG XMIT FRAME '009ca8a040404060ac96689aa698e0ae92888a624062ae92888a64406303f03a4e54502020202020203a54533a49774144494141414141414141414141414141414141414141414141414141413449492f57524272764142735262306c4f574f4568322b552f697a41712b6f6c'
> 2016-11-03 17:18:56,364 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 144.3553487613647
> 2016-11-03 17:18:56,369 rfidterm.kiss[kiss.py: 308] DEBUG XMIT RAW 'c0009ca8a040404060ac96689aa698e0ae92888a624062ae92888a64406303f03a4e54502020202020203a54533a49774144494141414141414141414141414141414141414141414141414141413449492f57524272764142735262306c4f574f4568322b552f697a41712b6f6cc0'
> Frame 6: 90 bytes on wire (720 bits), 90 bytes captured (720 bits) on interface 0
> Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: 00:00:00_00:00:00 (00:00:00:00:00:00)
> Internet Protocol Version 4, Src: 127.0.0.1, Dst: 127.0.0.1
> User Datagram Protocol, Src Port: 54903, Dst Port: 3123
> Network Time Protocol (NTP Version 4, client)
> Flags: 0x23, Leap Indicator: no warning, Version number: NTP Version 4, Mode: client
> 00.. .... = Leap Indicator: no warning (0)
> ..10 0... = Version number: NTP Version 4 (4)
> .... .011 = Mode: client (3)
> Peer Clock Stratum: unspecified or invalid (0)
> Peer Polling Interval: invalid (3)
> Peer Clock Precision: 4294967296.000000 sec
> Root Delay: 0 seconds
> Root Dispersion: 0 seconds
> Reference ID: NULL
> Reference Timestamp: Jan 1, 1970 00:00:00.000000000 UTC
> Origin Timestamp: May 12, 2019 06:44:41.064143896 UTC
> Receive Timestamp: Jul 25, 1957 10:02:13.224174769 UTC
> Transmit Timestamp: Apr 29, 1959 01:49:32.752623209 UTC
>
> 2016-11-03 17:19:00,069 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW 'c000ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d4437514141453363414141652b'
> 2016-11-03 17:19:00,074 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:19:00,079 rfidterm.kiss[kiss.py: 252] DEBUG RECV FRAME end at 1
> 2016-11-03 17:19:00,083 rfidterm.kiss[kiss.py: 261] DEBUG RECEIVED FRAME , REMAINING c000ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d4437514141453363414141652b
> 2016-11-03 17:19:00,088 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:19:00,119 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW '473378392b7543434f71684b702b45536235542b4c4d437236695867676a396b76364c516a2b43435032532f72416162'
> 2016-11-03 17:19:00,124 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:19:00,126 rfidterm.kiss[kiss.py: 204] DEBUG RECV RAW 'c0'
> 2016-11-03 17:19:00,127 rfidterm.kiss[kiss.py: 238] DEBUG RECV FRAME start at 0
> 2016-11-03 17:19:00,136 rfidterm.kiss[kiss.py: 252] DEBUG RECV FRAME end at 96
> 2016-11-03 17:19:00,140 rfidterm.kiss[kiss.py: 261] DEBUG RECEIVED FRAME 00ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d4437514141453363414141652b473378392b7543434f71684b702b45536235542b4c4d437236695867676a396b76364c516a2b43435032532f72416162, REMAINING c0
> 2016-11-03 17:19:00,146 rfidterm.kiss[kiss.py: 291] DEBUG RECV FRAME dispatch KISSCmdData{Port 0, Cmd 0x00, Payload ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d4437514141453363414141652b473378392b7543434f71684b702b45536235542b4c4d437236695867676a396b76364c516a2b43435032532f72416162}
> 2016-11-03 17:19:00,151 rfidterm.kiss.port0[kiss.py: 435] DEBUG Received frame KISSCmdData{Port 0, Cmd 0x00, Payload ac96689aa69860ac96689aa698f503f03a564b344d534c2020203a54533a4a414d4437514141453363414141652b473378392b7543434f71684b702b45536235542b4c4d437236695867676a396b76364c516a2b43435032532f72416162}
> 2016-11-03 17:19:00,157 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 148.21007610780103
> 2016-11-03 17:19:00,163 rfidterm.ax25[router.py: 98] DEBUG Handling incoming frame VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAe+G3x9+uCCOqhKp+ESb5T+LMCr6iXggj9kv6LQj+CCP2S/rAab'
> 2016-11-03 17:19:00,168 rfidterm.ax25[router.py: 136] DEBUG Dispatching frame to 1 receivers
> 2016-11-03 17:19:00,176 rfidterm.aprs[aprs.py: 246] DEBUG Processing incoming message VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAe+G3x9+uCCOqhKp+ESb5T+LMCr6iXggj9kv6LQj+CCP2S/rAab' (type APRSMessageFrame)
> 2016-11-03 17:19:00,182 rfidterm.aprs[router.py: 98] DEBUG Handling incoming frame VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAe+G3x9+uCCOqhKp+ESb5T+LMCr6iXggj9kv6LQj+CCP2S/rAab'
> 2016-11-03 17:19:00,187 rfidterm.aprs[router.py: 136] DEBUG Dispatching frame to 0 receivers
> 2016-11-03 17:19:00,192 rfidterm.ntp[ntpproxy.py: 84] DEBUG Received message: VK4MSL-10*>VK4MSL: PID=0xf0 Payload=b':VK4MSL :TS:JAMD7QAAE3cAAAe+G3x9+uCCOqhKp+ESb5T+LMCr6iXggj9kv6LQj+CCP2S/rAab'
>
> ==> /var/log/chrony/statistics.log <==
> ====================================================================================================================
> Date (UTC) Time IP Address Std dev'n Est offset Offset sd Diff freq Est skew Stress Ns Bs Nr Asym
> ====================================================================================================================
> 2016-11-03 17:18:58 127.0.0.1 3.212e-02 -7.945e+07 5.368e-02 6.628e-03 1.752e+00 3.3e+00 3 0 3 0.00
>
> ==> /var/log/daemon.log <==
> May 12 06:44:54 hackerlab chronyd[1294]: Selected source 127.0.0.1
>
> ==> /var/log/chrony/tracking.log <==
> 2016-11-03 17:19:00 127.0.0.1 4 26.917 158.544 -7.945e+07 N 1 5.368e-02 -3.783e-10
>
> ==> /var/log/chrony/measurements.log <==
> 2016-11-03 17:18:58 127.0.0.1 N 3 111 111 1111 3 3 0.00 7.945e+07 3.877e+00 7.756e-03 7.603e-02 3.024e-02 1B7C7DFA 4B
> ==> /var/log/chrony/measurements.log <==
> 2016-11-03 17:18:58 127.0.0.1 N 3 111 111 1111 3 3 0.00 7.945e+07 3.877e+00 7.756e-03 7.603e-02 3.024e-02 1B7C7DFA 4B D K
>
> ==> /var/log/wicen-rfid.log <==
> 2019-05-12 06:44:54,763 rfidterm.ntp[ntpproxy.py: 104] DEBUG Relayed NTP reply to ('127.0.0.1', 54903): 240303ed00001377000007be1b7c7dfae0823aa84aa7e1126f94fe2cc0abea25e0823f64bfa2d08fe0823f64bfac069b
>
> ==> /var/log/daemon.log <==
> May 12 06:44:54 hackerlab systemd[1213]: Time has been changed
> May 12 06:44:54 hackerlab chronyd[1294]: System clock wrong by 79449954.546492 seconds, adjustment started
> May 12 06:44:54 hackerlab systemd[1]: Time has been changed
>
> ==> /var/log/wicen-rfid.log <==
> 2019-05-12 06:44:54,777 rfidterm.ntp[ntpproxy.py: 113] INFO Time step of 919 days, 13:25:54.579836 took place
> 2019-05-12 06:44:54,795 rfidterm.rfid[rfid.py: 65] INFO Received time sync
>
> ==> /var/log/daemon.log <==
> May 12 06:44:54 hackerlab chronyd[1294]: System clock was stepped by 79449954.546492 seconds
> May 12 06:44:54 hackerlab systemd[1]: apt-daily.timer: Adding 10h 1min 40.755238s random time.
> May 12 06:44:54 hackerlab systemd[1]: apt-daily-upgrade.timer: Adding 12min 28.488847s random time.
>
> ==> /var/log/wicen-rfid.log <==
> 2019-05-12 06:44:54,805 rfidterm.aprs[aprs.py: 137] DEBUG Setting default path for message to VK4MSL-10
> 2019-05-12 06:44:54,824 rfidterm.aprs.message[message.py: 60] DEBUG Initialised handler for 2 state HandlerState.INIT
> 2019-05-12 06:44:54,828 rfidterm.aprs.message[message.py: 126] DEBUG Cancelling timer for 2
> 2019-05-12 06:44:54,833 rfidterm.aprs.message[message.py: 91] INFO Preparing to send 2 (state HandlerState.INIT)
> 2019-05-12 06:44:54,838 rfidterm.aprs[aprs.py: 286] INFO Sending VK4MSL>VK4MSL-10,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':VK4MSL-10:M:6 L:2 T:064454 C:Time synchronisation received{2'
> 2019-05-12 06:44:54,843 rfidterm.ax25[interface.py: 64] DEBUG Adding to queue: VK4MSL>VK4MSL-10,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':VK4MSL-10:M:6 L:2 T:064454 C:Time synchronisation received{2'
> 2019-05-12 06:44:54,849 rfidterm.ax25[interface.py: 112] DEBUG Scheduling next transmission in 0.22744106280103438
> 2019-05-12 06:44:54,854 rfidterm.aprs.message[message.py: 150] DEBUG 2 entering state HandlerState.SEND
> 2019-05-12 06:44:55,082 rfidterm.ax25[interface.py: 131] DEBUG Transmitting VK4MSL>VK4MSL-10,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':VK4MSL-10:M:6 L:2 T:064454 C:Time synchronisation received{2'
> 2019-05-12 06:44:55,087 rfidterm.kiss.port0[kiss.py: 428] DEBUG XMIT AX.25 VK4MSL>VK4MSL-10,WIDE1-1,WIDE2-1: PID=0xf0 Payload=b':VK4MSL-10:M:6 L:2 T:064454 C:Time synchronisation received{2'
> 2019-05-12 06:44:55,094 rfidterm.kiss[kiss.py: 215] DEBUG XMIT FRAME '00ac96689aa69874ac96689aa698e0ae92888a624062ae92888a64406303f03a564b344d534c2d31303a4d3a36204c3a3220543a30363434353420433a54696d652073796e6368726f6e69736174696f6e2072656365697665647b32'
> 2019-05-12 06:44:55,099 rfidterm.ax25[interface.py: 91] DEBUG Clear-to-send expiry at 148.55408098905156
I guess I should take this station for a ride up the road and see if it
still gets time sync when there's a few kilometres between my base and
the remote station.
With the time synchronised, I am seeing this:
> root@hackerlab:~# chronyc sources
> 210 Number of sources = 1
> MS Name/IP address Stratum Poll Reach LastRx Last sample
> ===============================================================================
> ^* localhost 3 6 174 238 +23ms[+2758us] +/- 1701ms
> root@hackerlab:~# chronyc sourcestats
> 210 Number of sources = 1
> Name/IP Address NP NR Span Frequency Freq Skew Offset Std Dev
> ==============================================================================
> localhost 24 11 871 -10.956 81.373 -2611us 31ms
> root@hackerlab:~# chronyc ntpdata
>
> Remote address : 127.0.0.1 (7F000001)
> Remote port : 3123
> Local address : 127.0.0.1 (7F000001)
> Leap status : Normal
> Version : 4
> Mode : Server
> Stratum : 3
> Poll interval : 6 (64 seconds)
> Precision : -19 (0.000001907 seconds)
> Root delay : 0.076035 seconds
> Root dispersion : 0.042969 seconds
> Reference ID : 1B7C7DFA ()
> Reference time : Sun May 12 06:24:40 2019
> Offset : -0.002757747 seconds
> Peer delay : 3.240200520 seconds
> Peer dispersion : 0.000206967 seconds
> Response time : 0.000172311 seconds
> Jitter asymmetry: +0.45
> NTP tests : 111 111 1111
> Interleaved : No
> Authenticated : No
> TX timestamping : Daemon
> RX timestamping : Kernel
> Total TX : 44
> Total RX : 29
> Total valid RX : 29
We'll see how it goes from here I guess. I'll have to do some more
testing, but I'll keep the above commands in mind.
Many thanks to all that replied. :-)
Regards,
--
Stuart Longland (aka Redhatter, VK4MSL)
I haven't lost my mind...
...it's backed up on a tape somewhere.
--
To unsubscribe email chrony-users-request@xxxxxxxxxxxxxxxxxxxx
with "unsubscribe" in the subject.
For help email chrony-users-request@xxxxxxxxxxxxxxxxxxxx
with "help" in the subject.
Trouble? Email listmaster@xxxxxxxxxxxxxxxxxxxx.