Improve NTP failure diagnostics and source transition coverage

This commit is contained in:
evgeny committed 2026-10-21 20:18:17 +02:00
1 parent d6eed66926
commit 6c84e680af
2 files changed
+53 -21

No files matched your search

+35 -20
View File
@@ -94,16 +94,29 @@ static void ntp_build_request(uint8_t* req, uint64_t* t1_ntp_out) {
/* возвращает 0 если ответ валиден; иначе -1 (пакет игнорируется, ждём timeout) */
static int ntp_parse_reply(const uint8_t* buf, size_t len, uint64_t t1_ntp,
int64_t* offset_us_out, int64_t* rtt_us_out, int* stratum_out) {
if (len < sizeof(struct ntp_packet)) return -1;
if (len < sizeof(struct ntp_packet)) {
DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "NTP: short reply: bytes=%zu required=%zu", len, sizeof(struct ntp_packet));
return -1;
}
const struct ntp_packet* reply = (const struct ntp_packet*)buf;
uint8_t mode = reply->li_vn_mode & 0x07;
if (mode != 4) return -1;
if (mode != 4) {
DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "NTP: invalid reply mode=%u", (unsigned)mode);
return -1;
}
int stratum = reply->stratum;
if (stratum == 0) return -1;
if (stratum == 0) {
DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "NTP: server returned stratum=0 (no time sample)");
return -1;
}
if (be64toh(reply->orig_ts) != t1_ntp) return -1;
if (be64toh(reply->orig_ts) != t1_ntp) {
DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "NTP: stale/unmatched reply: originate=%llu expected=%llu",
(unsigned long long)be64toh(reply->orig_ts), (unsigned long long)t1_ntp);
return -1;
}
struct timeval t4_tv;
#ifdef _WIN32
@@ -214,15 +227,16 @@ static int ntp_start_query(struct ntp_sync* ctx, const struct sockaddr_in* addr)
static int ntp_send_request(struct ntp_sync* ctx) {
struct UTUN_INSTANCE* inst = ctx->inst;
const char* name = ctx->query_idx >= 0 ? inst->ntp.servers[ctx->query_idx] : "test-server";
if (ctx->sock == SOCKET_INVALID) {
ctx->sock = socket_create_udp(AF_INET);
if (ctx->sock == SOCKET_INVALID) {
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: socket() failed: %s", socket_strerror(socket_get_error()));
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: socket() failed for %s: %s", name, socket_strerror(socket_get_error()));
return -1;
}
if (socket_set_nonblocking(ctx->sock) != 0) {
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: nonblocking mode failed: %s", socket_strerror(socket_get_error()));
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: nonblocking mode failed for %s: %s", name, socket_strerror(socket_get_error()));
return -1;
}
}
@@ -233,26 +247,26 @@ static int ntp_send_request(struct ntp_sync* ctx) {
ssize_t sent = socket_sendto(ctx->sock, ctx->req, sizeof(ctx->req),
(const struct sockaddr*)&ctx->qaddr, sizeof(ctx->qaddr));
if (sent != (ssize_t)sizeof(ctx->req)) {
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: sendto failed/short: sent=%lld error=%s",
(long long)sent, sent < 0 ? socket_strerror(socket_get_error()) : "short datagram");
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: sendto failed/short for %s: sent=%lld error=%s",
name, (long long)sent, sent < 0 ? socket_strerror(socket_get_error()) : "short datagram");
return -1;
}
if (!ctx->socket_id) {
ctx->socket_id = uasync_add_socket_t(inst->ua, ctx->sock, ntp_query_read_cb, NULL, NULL, "ntp_query", ctx);
if (!ctx->socket_id) {
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: uasync_add_socket_t failed");
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: uasync_add_socket_t failed for %s", name);
return -1;
}
}
ctx->timer = uasync_set_timeout(inst->ua, NTP_TIMEOUT_SEC * 10000, ctx, ntp_query_timeout_cb, "ntp_q");
if (!ctx->timer) {
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: uasync_set_timeout failed");
DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, "NTP: request timer failed for %s", name);
return -1;
}
DEBUG_DEBUG(DEBUG_CATEGORY_GENERAL, "NTP: sent request server=%d attempt=%d/%d timestamp=%llu",
ctx->query_idx, ctx->tries, NTP_MAX_TRIES, (unsigned long long)ctx->t1_ntp);
DEBUG_DEBUG(DEBUG_CATEGORY_GENERAL, "NTP: sent request server=%s attempt=%d/%d timestamp=%llu",
name, ctx->tries, NTP_MAX_TRIES, (unsigned long long)ctx->t1_ntp);
return 0;
}
@@ -263,15 +277,16 @@ static void ntp_query_read_cb(socket_t sock, void* arg) {
struct sockaddr_in from;
socklen_t from_len = sizeof(from);
ssize_t n = socket_recvfrom(ctx->sock, (void*)&reply, sizeof(reply), (struct sockaddr*)&from, &from_len);
if (n < 0) return; /* EAGAIN / ICMP (WSAECONNRESET) — ждём timeout */
if (n < 0) {
int error = socket_get_error();
if (error != ERR_AGAIN && error != ERR_WOULDBLOCK)
DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "NTP: recvfrom failed server=%d: %s", ctx->query_idx, socket_strerror(error));
return;
}
int64_t offset_us, rtt_us;
int stratum;
if (ntp_parse_reply((const uint8_t*)&reply, (size_t)n, ctx->t1_ntp, &offset_us, &rtt_us, &stratum) != 0) {
DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "NTP: ignoring invalid/stale reply: bytes=%lld server=%d",
(long long)n, ctx->query_idx);
return;
}
if (ntp_parse_reply((const uint8_t*)&reply, (size_t)n, ctx->t1_ntp, &offset_us, &rtt_us, &stratum) != 0) return;
struct NTP_TIME* ntp = &ctx->inst->ntp;
ntp->offset_us = offset_us;
@@ -290,8 +305,8 @@ static void ntp_query_read_cb(socket_t sock, void* arg) {
static void ntp_query_timeout_cb(void* arg) {
struct ntp_sync* ctx = (struct ntp_sync*)arg;
ctx->timer = NULL;
DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "NTP: response timeout server=%d attempt=%d/%d",
ctx->query_idx, ctx->tries, NTP_MAX_TRIES);
const char* name = ctx->query_idx >= 0 ? ctx->inst->ntp.servers[ctx->query_idx] : "test-server";
DEBUG_WARN(DEBUG_CATEGORY_GENERAL, "NTP: response timeout server=%s attempt=%d/%d", name, ctx->tries, NTP_MAX_TRIES);
if (ctx->tries < NTP_MAX_TRIES) {
if (ntp_send_request(ctx) == 0) return;
}
+18 -1
View File
@@ -364,6 +364,9 @@ static void test_init_failures(struct fixture* f) {
fail_alloc_at = 0;
assert(!f->inst.ntp.servers && !f->inst.ntp.timer && u_get_allocated_count() == baseline);
}
f->config.global.ntp_server_count = 3;
assert(ntp_time_init(&f->inst) == -1 && u_get_allocated_count() == baseline);
f->config.global.ntp_server_count = 2;
f->config.global.ntp_resync_interval = INT_MAX;
assert(ntp_time_init(&f->inst) == -1);
f->config.global.ntp_resync_interval = 3600;
@@ -421,6 +424,20 @@ static void test_peer_cache(struct fixture* f) {
assert(!f->inst.ntp_node.peer_count);
check_time(f, wall_us + 5000000);
}
static void test_sources(struct fixture* f) {
start(f, 1);
assert(!ntp_node_time_init(&f->inst));
receive_peer(f, &f->conns[0], 1, wall_us + 5000000);
check_time(f, wall_us + 5000000);
deliver_reply(request_stamp(), wall_us + 5000000);
check_time(f, wall_us + 5000000); // смена источника не меняет знак поправки
fire_timer(f->inst.ntp.timer);
for (int i = 0; i < 3; i++) fire_query_timer();
check_failed_cycle(f);
check_time(f, wall_us + 5000000); // отказ следующего цикла не уничтожает принятую поправку
receive_peer(f, &f->conns[0], 1, wall_us - 5000000);
check_time(f, wall_us + 5000000); // уже синхронизированный узел не принимает другую поправку пира
}
static int foreign_calls;
static void foreign_callback(struct ETCP_CONN* conn, int event, void* arg) {
(void)conn; (void)event; (void)arg;
@@ -469,7 +486,7 @@ int main(void) {
debug_set_category_level(DEBUG_CATEGORY_GENERAL, DEBUG_LEVEL_INFO);
void (*tests[])(struct fixture*) = {test_offsets, test_retry_timestamp, test_async_dns_failure,
test_immediate_dns_failure, test_udp_exhaustion, test_immediate_udp_failures, test_timer_failures,
test_cancel, test_init_failures, test_peer_cache, test_node_lifecycle};
test_cancel, test_init_failures, test_peer_cache, test_sources, test_node_lifecycle};
for (size_t i = 0; i < sizeof(tests) / sizeof(tests[0]); i++) {
size_t baseline = u_get_allocated_count();
struct fixture f;