clientlog: undo clock adjustments in updated TX timestamps

When the server clock was updated between saving of the RX timestamp and
updating the TX timestamp, a client using interleaved mode with the four
timestamps which minimize error in measured delay (e.g. chrony) had the
server clock adjustment included in the measured delay, which could
disrupt the sample filtering and weighting.

Add a handler to track the slew epoch and remember the last offset. Undo
the adjustment in TX timestamps which have their RX timestamp in the
previous epoch to fix the delay observed by the clients.

If an unknown clock step is detected, drop all timestamps.

diff --git a/clientlog.c b/clientlog.c
index 2a18a97f6a6a707e455d882c24f19f1860b2933e..79d643f42bbc32b69f183d31660f6311b84392ad 100644 (file)
--- a/clientlog.c
+++ b/clientlog.c
@@ -38,6 +38,7 @@
 #include "array.h"
 #include "clientlog.h"
 #include "conf.h"
+#include "local.h"
 #include "memory.h"
 #include "ntp.h"
 #include "reports.h"
@@ -125,7 +126,8 @@ static int active;
 /* RX and TX timestamp saved for clients using interleaved mode */
 typedef struct {
   uint64_t rx_ts;
-  uint32_t flags;
+  uint16_t flags;
+  uint16_t slew_epoch;
   int32_t tx_ts_offset;
 } NtpTimestamps;
 
@@ -141,6 +143,8 @@ typedef struct {
   uint32_t max_size;
   uint32_t cached_index;
   uint64_t cached_rx_ts;
+  uint16_t slew_epoch;
+  double slew_offset;
 } NtpTimestampMap;
 
 static NtpTimestampMap ntp_ts_map;
@@ -163,6 +167,8 @@ static uint32_t total_record_drops;
 /* ================================================== */
 
 static int expand_hashtable(void);
+static void handle_slew(struct timespec *raw, struct timespec *cooked, double dfreq,
+                        double doffset, LCL_ChangeType change_type, void *anything);
 
 /* ================================================== */
 
@@ -407,6 +413,10 @@ CLG_Initialise(void)
   ntp_ts_map.max_size = 1U << (slots2 + SLOT_BITS);
   ntp_ts_map.cached_index = 0;
   ntp_ts_map.cached_rx_ts = 0ULL;
+  ntp_ts_map.slew_epoch = 0;
+  ntp_ts_map.slew_offset = 0.0;
+
+  LCL_AddParameterChangeHandler(handle_slew, NULL);
 }
 
 /* ================================================== */
@@ -420,6 +430,8 @@ CLG_Finalise(void)
   ARR_DestroyInstance(records);
   if (ntp_ts_map.timestamps)
     ARR_DestroyInstance(ntp_ts_map.timestamps);
+
+  LCL_RemoveParameterChangeHandler(handle_slew, NULL);
 }
 
 /* ================================================== */
@@ -864,6 +876,7 @@ CLG_SaveNtpTimestamps(NTP_int64 *rx_ts, struct timespec *tx_ts)
   tss = get_ntp_tss(index);
   tss->rx_ts = rx;
   tss->flags = 0;
+  tss->slew_epoch = ntp_ts_map.slew_epoch;
   set_ntp_tx_offset(tss, rx_ts, tx_ts);
 
   DEBUG_LOG("Saved RX+TX index=%"PRIu32" first=%"PRIu32" size=%"PRIu32,
@@ -872,6 +885,41 @@ CLG_SaveNtpTimestamps(NTP_int64 *rx_ts, struct timespec *tx_ts)
 
 /* ================================================== */
 
+static void
+handle_slew(struct timespec *raw, struct timespec *cooked, double dfreq,
+            double doffset, LCL_ChangeType change_type, void *anything)
+{
+  /* Drop all timestamps on unknown step */
+  if (change_type == LCL_ChangeUnknownStep) {
+    ntp_ts_map.size = 0;
+    ntp_ts_map.cached_rx_ts = 0ULL;
+  }
+
+  ntp_ts_map.slew_epoch++;
+  ntp_ts_map.slew_offset = doffset;
+}
+
+/* ================================================== */
+
+void
+CLG_UndoNtpTxTimestampSlew(NTP_int64 *rx_ts, struct timespec *tx_ts)
+{
+  uint32_t index;
+
+  if (!ntp_ts_map.timestamps)
+    return;
+
+  if (!find_ntp_rx_ts(ntp64_to_int64(rx_ts), &index))
+    return;
+
+  /* If the RX timestamp was captured before the last correction of the clock,
+     remove the adjustment from the TX timestamp */
+  if ((uint16_t)(get_ntp_tss(index)->slew_epoch + 1U) == ntp_ts_map.slew_epoch)
+    UTI_AddDoubleToTimespec(tx_ts, ntp_ts_map.slew_offset, tx_ts);
+}
+
+/* ================================================== */
+
 void
 CLG_UpdateNtpTxTimestamp(NTP_int64 *rx_ts, struct timespec *tx_ts)
 {

diff --git a/clientlog.h b/clientlog.h
index a4001025126bcb35bad9072f30895d564f5e08bb..2a5565e02d99ba97291a9e5ff07c1c6461f787a7 100644 (file)
--- a/clientlog.h
+++ b/clientlog.h
@@ -47,6 +47,7 @@ extern int CLG_GetNtpMinPoll(void);
 
 /* Functions to save and retrieve timestamps for server interleaved mode */
 extern void CLG_SaveNtpTimestamps(NTP_int64 *rx_ts, struct timespec *tx_ts);
+extern void CLG_UndoNtpTxTimestampSlew(NTP_int64 *rx_ts, struct timespec *tx_ts);
 extern void CLG_UpdateNtpTxTimestamp(NTP_int64 *rx_ts, struct timespec *tx_ts);
 extern int CLG_GetNtpTxTimestamp(NTP_int64 *rx_ts, struct timespec *tx_ts);
 extern void CLG_DisableNtpTimestamps(NTP_int64 *rx_ts);

diff --git a/ntp_core.c b/ntp_core.c
index 40a1f3aded56e4de50ac045c183dbf0a521f06c0..f7c955d2ddc7418ca8903aea0cc833024cc2352a 100644 (file)
--- a/ntp_core.c
+++ b/ntp_core.c
@@ -2215,7 +2215,7 @@ void
 NCR_ProcessTxUnknown(NTP_Remote_Address *remote_addr, NTP_Local_Address *local_addr,
                      NTP_Local_Timestamp *tx_ts, NTP_Packet *message, int length)
 {
-  NTP_Local_Timestamp local_tx;
+  NTP_Local_Timestamp old_tx, new_tx;
   NTP_int64 *local_ntp_rx;
   NTP_PacketInfo info;
 
@@ -2229,13 +2229,18 @@ NCR_ProcessTxUnknown(NTP_Remote_Address *remote_addr, NTP_Local_Address *local_a
     UTI_AddDoubleToTimespec(&tx_ts->ts, SMT_GetOffset(&tx_ts->ts), &tx_ts->ts);
 
   local_ntp_rx = &message->receive_ts;
+  new_tx = *tx_ts;
 
-  if (!CLG_GetNtpTxTimestamp(local_ntp_rx, &local_tx.ts))
+  if (!CLG_GetNtpTxTimestamp(local_ntp_rx, &old_tx.ts))
     return;
 
-  update_tx_timestamp(&local_tx, tx_ts, local_ntp_rx, NULL, message);
+  /* Undo a clock adjustment between the RX and TX timestamps to minimise error
+     in the delay measured by the client */
+  CLG_UndoNtpTxTimestampSlew(local_ntp_rx, &new_tx.ts);
+
+  update_tx_timestamp(&old_tx, &new_tx, local_ntp_rx, NULL, message);
 
-  CLG_UpdateNtpTxTimestamp(local_ntp_rx, &local_tx.ts);
+  CLG_UpdateNtpTxTimestamp(local_ntp_rx, &new_tx.ts);
 }
 
 /* ================================================== */

diff --git a/test/unit/clientlog.c b/test/unit/clientlog.c
index b7aed365c9555843f73017ab58714850a968b283..2a9a58896f2bf5780e87d909e48a83924a72f823 100644 (file)
--- a/test/unit/clientlog.c
+++ b/test/unit/clientlog.c
@@ -52,6 +52,7 @@ test_unit(void)
   for (i = 0; i < sizeof conf / sizeof conf[0]; i++)
     CNF_ParseLine(NULL, i + 1, conf[i]);
 
+  LCL_Initialise();
   CLG_Initialise();
 
   TEST_CHECK(ARR_GetSize(records) == 16);
@@ -115,6 +116,7 @@ test_unit(void)
     ntp_ts_map.first = i % ntp_ts_map.max_size;
     ntp_ts_map.size = 0;
     ntp_ts_map.cached_rx_ts = 0ULL;
+    ntp_ts_map.slew_epoch = i * 400;
 
     for (j = 0; j < 500; j++) {
       do {
@@ -140,21 +142,41 @@ test_unit(void)
         TEST_CHECK(ntp_ts_map.size == ntp_ts_map.max_size);
         TEST_CHECK(ntp_ts_map.first == (i + j + ntp_ts_map.size + 1) % ntp_ts_map.max_size);
       }
+      TEST_CHECK(ntp_ts_map.cached_index == ntp_ts_map.size - 1);
+      TEST_CHECK(get_ntp_tss(ntp_ts_map.size - 1)->slew_epoch == ntp_ts_map.slew_epoch);
       TEST_CHECK(CLG_GetNtpTxTimestamp(&ntp_ts, &ts2));
       TEST_CHECK(UTI_CompareTimespecs(&ts, &ts2) == 0);
 
       for (k = random() % 4; k > 0; k--) {
-        int64_to_ntp64(get_ntp_tss(random() % ntp_ts_map.size)->rx_ts, &ntp_ts);
+        index2 = random() % ntp_ts_map.size;
+        int64_to_ntp64(get_ntp_tss(index2)->rx_ts, &ntp_ts);
         if (random() % 2)
           TEST_CHECK(CLG_GetNtpTxTimestamp(&ntp_ts, &ts));
 
         UTI_Ntp64ToTimespec(&ntp_ts, &ts);
         UTI_AddDoubleToTimespec(&ts, TST_GetRandomDouble(-1.999, 1.999), &ts);
+
+        ts2 = ts;
+        CLG_UndoNtpTxTimestampSlew(&ntp_ts, &ts);
+        if ((get_ntp_tss(index2)->slew_epoch + 1) % (1U << 16) != ntp_ts_map.slew_epoch) {
+          TEST_CHECK(UTI_CompareTimespecs(&ts, &ts2) == 0);
+        } else {
+          TEST_CHECK(fabs(UTI_DiffTimespecsToDouble(&ts, &ts2) - ntp_ts_map.slew_offset) <
+                     1.0e-9);
+        }
+
         CLG_UpdateNtpTxTimestamp(&ntp_ts, &ts);
 
         TEST_CHECK(CLG_GetNtpTxTimestamp(&ntp_ts, &ts2));
         TEST_CHECK(UTI_CompareTimespecs(&ts, &ts2) == 0);
 
+        if (random() % 2) {
+          uint16_t prev_epoch = ntp_ts_map.slew_epoch;
+          handle_slew(NULL, NULL, 0.0, TST_GetRandomDouble(-1.0e-5, 1.0e-5),
+                      LCL_ChangeAdjust, NULL);
+          TEST_CHECK((prev_epoch + 1) % (1U << 16) == ntp_ts_map.slew_epoch);
+        }
+
         if (ntp_ts_map.size > 1) {
           index = random() % (ntp_ts_map.size - 1);
           if (get_ntp_tss(index)->rx_ts + 1 != get_ntp_tss(index + 1)->rx_ts) {
@@ -163,6 +185,7 @@ test_unit(void)
             int64_to_ntp64(get_ntp_tss(index + 1)->rx_ts - 1, &ntp_ts);
             TEST_CHECK(!CLG_GetNtpTxTimestamp(&ntp_ts, &ts));
             CLG_UpdateNtpTxTimestamp(&ntp_ts, &ts);
+            CLG_UndoNtpTxTimestampSlew(&ntp_ts, &ts);
           }
         }
 
@@ -172,6 +195,7 @@ test_unit(void)
           int64_to_ntp64(get_ntp_tss(ntp_ts_map.size - 1)->rx_ts + 1, &ntp_ts);
           TEST_CHECK(!CLG_GetNtpTxTimestamp(&ntp_ts, &ts));
           CLG_UpdateNtpTxTimestamp(&ntp_ts, &ts);
+          CLG_UndoNtpTxTimestampSlew(&ntp_ts, &ts);
         }
       }
     }
@@ -244,9 +268,19 @@ test_unit(void)
         CLG_GetNtpTxTimestamp(&ntp_ts, &ts);
       }
     }
+
+    if (random() % 2) {
+      handle_slew(NULL, NULL, 0.0, TST_GetRandomDouble(-1.0e9, 1.0e9),
+                  LCL_ChangeUnknownStep, NULL);
+      TEST_CHECK(ntp_ts_map.size == 0);
+      TEST_CHECK(ntp_ts_map.cached_rx_ts == 0ULL);
+      TEST_CHECK(!CLG_GetNtpTxTimestamp(&ntp_ts, &ts));
+      CLG_UpdateNtpTxTimestamp(&ntp_ts, &ts);
+    }
   }
 
   CLG_Finalise();
+  LCL_Finalise();
   CNF_Finalise();
 }
 #else