From 702edde73a0a18b75ed9ba2b59580bd6c021e17f Mon Sep 17 00:00:00 2001 From: Patrick McLean Date: Fri, 19 Mar 2021 22:50:51 -0700 Subject: [PATCH] dig: Use high resolution clocks when microsecond accuracy is requested The TIME_NOW macro calls isc_time_now which uses CLOCK_REALTIME_COARSE for getting the current time. This is perfectly fine for millisecond, however when the user request microsecond resolutiuon, they are going to get very inaccurate results. This is especially true on a server class machine where the clock ticks may be set to 100HZ. This changes dig to use the new TIME_NOW_HIRES macro that uses the CLOCK_MONOTONIC_RAW that is more expensive, but gets the *actual* current time rather than the at the last kernel time tick. (cherry picked from commit 56cef1495f2b72100996fc042277dc52c3328aef) --- bin/dig/dighost.c | 18 +++++++++++++++--- bin/dig/host.c | 6 +++++- 2 files changed, 20 insertions(+), 4 deletions(-) diff --git a/bin/dig/dighost.c b/bin/dig/dighost.c index f3a8cbc619..6d04e68689 100644 --- a/bin/dig/dighost.c +++ b/bin/dig/dighost.c @@ -2935,7 +2935,11 @@ send_udp(dig_query_t *query) { } isc_buffer_usedregion(&query->sendbuf, &r); debug("sending a request"); - TIME_NOW(&query->time_sent); + if (query->lookup->use_usec) { + TIME_NOW_HIRES(&query->time_sent); + } else { + TIME_NOW(&query->time_sent); + } INSIST(query->sock != NULL); query->waiting_senddone = true; sevent = isc_socket_socketevent( @@ -3217,7 +3221,11 @@ launch_next_query(dig_query_t *query, bool include_question) { debug("recvcount=%d", recvcount); if (!query->first_soa_rcvd) { debug("sending a request in launch_next_query"); - TIME_NOW(&query->time_sent); + if (query->lookup->use_usec) { + TIME_NOW_HIRES(&query->time_sent); + } else { + TIME_NOW(&query->time_sent); + } query->waiting_senddone = true; isc_buffer_clear(&query->tmpsendbuf); isc_buffer_putuint16(&query->tmpsendbuf, @@ -3623,7 +3631,11 @@ recv_done(isc_task_t *task, isc_event_t *event) { INSIST(recvcount >= 0); query = event->ev_arg; - TIME_NOW(&query->time_recv); + if (query->lookup->use_usec) { + TIME_NOW_HIRES(&query->time_recv); + } else { + TIME_NOW(&query->time_recv); + } l = query->lookup; diff --git a/bin/dig/host.c b/bin/dig/host.c index 1bcb75bde9..0490e0e4a7 100644 --- a/bin/dig/host.c +++ b/bin/dig/host.c @@ -148,7 +148,11 @@ received(unsigned int bytes, isc_sockaddr_t *from, dig_query_t *query) { if (!short_form) { char fromtext[ISC_SOCKADDR_FORMATSIZE]; isc_sockaddr_format(from, fromtext, sizeof(fromtext)); - TIME_NOW(&now); + if (query->lookup->use_usec) { + TIME_NOW_HIRES(&now); + } else { + TIME_NOW(&now); + } diff = (int)isc_time_microdiff(&now, &query->time_sent); printf("Received %u bytes from %s in %d ms\n", bytes, fromtext, diff / 1000);