From bc33e1cda11c93097dfa726d7dd7870dec172158 Mon Sep 17 00:00:00 2001 From: Miroslav Lichvar Date: Mon, 25 Oct 2021 17:00:28 +0200 Subject: [PATCH] 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. --- clientlog.c | 50 ++++++++++++++++++++++++++++++++++++++++++- clientlog.h | 1 + ntp_core.c | 13 +++++++---- test/unit/clientlog.c | 36 ++++++++++++++++++++++++++++++- 4 files changed, 94 insertions(+), 6 deletions(-) diff --git a/clientlog.c b/clientlog.c index 2a18a97..79d643f 100644 --- 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 a400102..2a5565e 100644 --- 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 40a1f3a..f7c955d 100644 --- 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); - CLG_UpdateNtpTxTimestamp(local_ntp_rx, &local_tx.ts); + update_tx_timestamp(&old_tx, &new_tx, local_ntp_rx, NULL, message); + + CLG_UpdateNtpTxTimestamp(local_ntp_rx, &new_tx.ts); } /* ================================================== */ diff --git a/test/unit/clientlog.c b/test/unit/clientlog.c index b7aed36..2a9a588 100644 --- 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