Commit 8e0902b7 authored by Evan Hunt's avatar Evan Hunt
Browse files

Merge branch '2592-dig-clock-realtime' into 'main'

Resolve "dig -u is extremely inaccurate, especially on machines with the kernel timer tick set at 100Hz"

Closes #2592

See merge request !4826
parents bee4ee93 1933bcf1
5604. [bug] "dig -u" now uses CLOCK_REALTIME for more accurate
time reporting. [GL #2592]
5603. [experimental] A "filter-a.so" plugin, which is similar to the 5603. [experimental] A "filter-a.so" plugin, which is similar to the
"filter-aaaa.so" plugin but which omits A records "filter-aaaa.so" plugin but which omits A records
instead of AAAA records, has been added. Thanks to instead of AAAA records, has been added. Thanks to
......
...@@ -2866,7 +2866,11 @@ send_udp(dig_query_t *query) { ...@@ -2866,7 +2866,11 @@ send_udp(dig_query_t *query) {
isc_buffer_usedregion(&query->sendbuf, &r); isc_buffer_usedregion(&query->sendbuf, &r);
debug("sending a request"); 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);
}
isc_nmhandle_attach(query->handle, &query->sendhandle); isc_nmhandle_attach(query->handle, &query->sendhandle);
...@@ -3172,7 +3176,12 @@ launch_next_query(dig_query_t *query) { ...@@ -3172,7 +3176,12 @@ launch_next_query(dig_query_t *query) {
if (!query->first_soa_rcvd) { if (!query->first_soa_rcvd) {
dig_query_t *sendquery = NULL; dig_query_t *sendquery = NULL;
debug("sending a request in launch_next_query"); 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_attach(query, &sendquery); query_attach(query, &sendquery);
isc_buffer_usedregion(&query->sendbuf, &r); isc_buffer_usedregion(&query->sendbuf, &r);
if (keep != NULL) { if (keep != NULL) {
...@@ -3584,7 +3593,11 @@ recv_done(isc_nmhandle_t *handle, isc_result_t eresult, isc_region_t *region, ...@@ -3584,7 +3593,11 @@ recv_done(isc_nmhandle_t *handle, isc_result_t eresult, isc_region_t *region,
goto detach_query; goto detach_query;
} }
TIME_NOW(&query->time_recv); if (query->lookup->use_usec) {
TIME_NOW_HIRES(&query->time_recv);
} else {
TIME_NOW(&query->time_recv);
}
if (eresult == ISC_R_TIMEDOUT && !l->tcp_mode && l->retries > 1) { if (eresult == ISC_R_TIMEDOUT && !l->tcp_mode && l->retries > 1) {
dig_query_t *newq = NULL; dig_query_t *newq = NULL;
......
...@@ -151,7 +151,11 @@ received(unsigned int bytes, isc_sockaddr_t *from, dig_query_t *query) { ...@@ -151,7 +151,11 @@ received(unsigned int bytes, isc_sockaddr_t *from, dig_query_t *query) {
if (!short_form) { if (!short_form) {
char fromtext[ISC_SOCKADDR_FORMATSIZE]; char fromtext[ISC_SOCKADDR_FORMATSIZE];
isc_sockaddr_format(from, fromtext, sizeof(fromtext)); 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); diff = (int)isc_time_microdiff(&now, &query->time_sent);
printf("Received %u bytes from %s in %d ms\n", bytes, fromtext, printf("Received %u bytes from %s in %d ms\n", bytes, fromtext,
diff / 1000); diff / 1000);
......
...@@ -340,6 +340,8 @@ mock_assert(const int result, const char *const expression, ...@@ -340,6 +340,8 @@ mock_assert(const int result, const char *const expression,
* Time * Time
*/ */
#define TIME_NOW(tp) RUNTIME_CHECK(isc_time_now((tp)) == ISC_R_SUCCESS) #define TIME_NOW(tp) RUNTIME_CHECK(isc_time_now((tp)) == ISC_R_SUCCESS)
#define TIME_NOW_HIRES(tp) \
RUNTIME_CHECK(isc_time_now_hires((tp)) == ISC_R_SUCCESS)
/*% /*%
* Alignment * Alignment
......
...@@ -128,7 +128,7 @@ isc_time_formatISO8601us_test(void **state) { ...@@ -128,7 +128,7 @@ isc_time_formatISO8601us_test(void **state) {
UNUSED(state); UNUSED(state);
setenv("TZ", "America/Los_Angeles", 1); setenv("TZ", "America/Los_Angeles", 1);
result = isc_time_now(&t); result = isc_time_now_hires(&t);
assert_int_equal(result, ISC_R_SUCCESS); assert_int_equal(result, ISC_R_SUCCESS);
/* check formatting: yyyy-mm-ddThh:mm:ss.ssssssZ */ /* check formatting: yyyy-mm-ddThh:mm:ss.ssssssZ */
...@@ -236,7 +236,7 @@ isc_time_formatISO8601Lus_test(void **state) { ...@@ -236,7 +236,7 @@ isc_time_formatISO8601Lus_test(void **state) {
UNUSED(state); UNUSED(state);
setenv("TZ", "America/Los_Angeles", 1); setenv("TZ", "America/Los_Angeles", 1);
result = isc_time_now(&t); result = isc_time_now_hires(&t);
assert_int_equal(result, ISC_R_SUCCESS); assert_int_equal(result, ISC_R_SUCCESS);
/* check formatting: yyyy-mm-ddThh:mm:ss.ssssss */ /* check formatting: yyyy-mm-ddThh:mm:ss.ssssss */
......
...@@ -150,6 +150,26 @@ isc_time_now(isc_time_t *t); ...@@ -150,6 +150,26 @@ isc_time_now(isc_time_t *t);
* in the current definition of isc_time_t. * in the current definition of isc_time_t.
*/ */
isc_result_t
isc_time_now_hires(isc_time_t *t);
/*%<
* Set 't' to the current absolute time. Uses higher resolution clocks
* recommended when microsecond accuracy is required.
*
* Requires:
*
*\li 't' is a valid pointer.
*
* Returns:
*
*\li Success
*\li Unexpected error
* Getting the time from the system failed.
*\li Out of range
* The time from the system is too large to be represented
* in the current definition of isc_time_t.
*/
isc_result_t isc_result_t
isc_time_nowplusinterval(isc_time_t *t, const isc_interval_t *i); isc_time_nowplusinterval(isc_time_t *t, const isc_interval_t *i);
/*%< /*%<
......
...@@ -33,6 +33,10 @@ ...@@ -33,6 +33,10 @@
#define NS_PER_US 1000 /*%< Nanoseconds per microsecond. */ #define NS_PER_US 1000 /*%< Nanoseconds per microsecond. */
#define NS_PER_MS 1000000 /*%< Nanoseconds per millisecond. */ #define NS_PER_MS 1000000 /*%< Nanoseconds per millisecond. */
#if defined(CLOCK_REALTIME)
#define CLOCKSOURCE_HIRES CLOCK_REALTIME
#endif /* #if defined(CLOCK_REALTIME) */
#if defined(CLOCK_REALTIME_COARSE) #if defined(CLOCK_REALTIME_COARSE)
#define CLOCKSOURCE CLOCK_REALTIME_COARSE #define CLOCKSOURCE CLOCK_REALTIME_COARSE
#elif defined(CLOCK_REALTIME_FAST) #elif defined(CLOCK_REALTIME_FAST)
...@@ -41,6 +45,10 @@ ...@@ -41,6 +45,10 @@
#define CLOCKSOURCE CLOCK_REALTIME #define CLOCKSOURCE CLOCK_REALTIME
#endif /* if defined(CLOCK_REALTIME_COARSE) */ #endif /* if defined(CLOCK_REALTIME_COARSE) */
#if !defined(CLOCKSOURCE_HIRES)
#define CLOCKSOURCE_HIRES CLOCKSOURCE
#endif /* #ifndef CLOCKSOURCE_HIRES */
/*% /*%
*** Intervals *** Intervals
***/ ***/
...@@ -106,14 +114,14 @@ isc_time_isepoch(const isc_time_t *t) { ...@@ -106,14 +114,14 @@ isc_time_isepoch(const isc_time_t *t) {
return (false); return (false);
} }
isc_result_t static inline isc_result_t
isc_time_now(isc_time_t *t) { time_now(isc_time_t *t, clockid_t clock) {
struct timespec ts; struct timespec ts;
char strbuf[ISC_STRERRORSIZE]; char strbuf[ISC_STRERRORSIZE];
REQUIRE(t != NULL); REQUIRE(t != NULL);
if (clock_gettime(CLOCKSOURCE, &ts) == -1) { if (clock_gettime(clock, &ts) == -1) {
strerror_r(errno, strbuf, sizeof(strbuf)); strerror_r(errno, strbuf, sizeof(strbuf));
UNEXPECTED_ERROR(__FILE__, __LINE__, "%s", strbuf); UNEXPECTED_ERROR(__FILE__, __LINE__, "%s", strbuf);
return (ISC_R_UNEXPECTED); return (ISC_R_UNEXPECTED);
...@@ -138,6 +146,16 @@ isc_time_now(isc_time_t *t) { ...@@ -138,6 +146,16 @@ isc_time_now(isc_time_t *t) {
return (ISC_R_SUCCESS); return (ISC_R_SUCCESS);
} }
isc_result_t
isc_time_now_hires(isc_time_t *t) {
return time_now(t, CLOCKSOURCE_HIRES);
}
isc_result_t
isc_time_now(isc_time_t *t) {
return time_now(t, CLOCKSOURCE);
}
isc_result_t isc_result_t
isc_time_nowplusinterval(isc_time_t *t, const isc_interval_t *i) { isc_time_nowplusinterval(isc_time_t *t, const isc_interval_t *i) {
struct timespec ts; struct timespec ts;
......
...@@ -164,6 +164,26 @@ isc_time_now(isc_time_t *t); ...@@ -164,6 +164,26 @@ isc_time_now(isc_time_t *t);
* in the current definition of isc_time_t. * in the current definition of isc_time_t.
*/ */
isc_result_t
isc_time_now_hires(isc_time_t *t);
/*%<
* Set 't' to the current absolute time. Uses higher resolution clocks
* recommended when microsecond accuracy is required.
*
* Requires:
*
*\li 't' is a valid pointer.
*
* Returns:
*
*\li Success
*\li Unexpected error
* Getting the time from the system failed.
*\li Out of range
* The time from the system is too large to be represented
* in the current definition of isc_time_t.
*/
isc_result_t isc_result_t
isc_time_nowplusinterval(isc_time_t *t, const isc_interval_t *i); isc_time_nowplusinterval(isc_time_t *t, const isc_interval_t *i);
/* /*
......
...@@ -691,6 +691,7 @@ isc_time_isepoch ...@@ -691,6 +691,7 @@ isc_time_isepoch
isc_time_microdiff isc_time_microdiff
isc_time_nanoseconds isc_time_nanoseconds
isc_time_now isc_time_now
isc_time_now_hires
isc_time_nowplusinterval isc_time_nowplusinterval
isc_time_parsehttptimestamp isc_time_parsehttptimestamp
isc_time_secondsastimet isc_time_secondsastimet
......
...@@ -124,6 +124,15 @@ isc_time_now(isc_time_t *t) { ...@@ -124,6 +124,15 @@ isc_time_now(isc_time_t *t) {
return (ISC_R_SUCCESS); return (ISC_R_SUCCESS);
} }
isc_result_t
isc_time_now_hires(isc_time_t *t) {
REQUIRE(t != NULL);
GetSystemTimePreciseAsFileTime(&t->absolute);
return (ISC_R_SUCCESS);
}
isc_result_t isc_result_t
isc_time_nowplusinterval(isc_time_t *t, const isc_interval_t *i) { isc_time_nowplusinterval(isc_time_t *t, const isc_interval_t *i) {
ULARGE_INTEGER i1; ULARGE_INTEGER i1;
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment