9.2.x: Make sure that the thread local time is updated timely (#10163)

doc/admin-guide/files/records.config.en.rst

@@ -4865,6 +4865,13 @@ Sockets
    ``2`` Tracks IO Buffer Memory and OpenSSL Memory allocations and releases
    ===== ======================================================================
 
+.. ts:cv:: CONFIG proxy.config.system_clock INT 0
+
+   *For advanced users only*. This allows to specify the underlying system clock
+   used by ATS. The default is ``CLOCK_REALTIME`` (``0``), but a higher performance
+   option could be ``CLOCK_REALTIME_COARSE`` (``5``). See ``clock_gettime(2)`` for
+   more details. On Linux, these definitions can be found in ``<linux/time.h>``.
+
 .. ts:cv:: CONFIG proxy.config.allocator.dontdump_iobuffers INT 1
 
    Enable (1) the exclusion of IO buffers from core files when ATS crashes on supported

include/tscore/ink_hrtime.h

@@ -224,12 +224,14 @@ ink_hrtime_to_timeval(ink_hrtime t)
    which translates to (365 + 0.25)369*24*60*60 seconds   */
 #define NT_TIMEBASE_DIFFERENCE_100NSECS 116444736000000000i64
 
+extern int gSystemClock; // 0 == CLOCK_REALTIME, the default
+
 static inline ink_hrtime
-ink_get_hrtime_internal()
+ink_get_hrtime()
 {
 #if defined(freebsd) || HAVE_CLOCK_GETTIME
   timespec ts;
-  clock_gettime(CLOCK_REALTIME, &ts);
+  clock_gettime(static_cast<clockid_t>(gSystemClock), &ts);
   return ink_hrtime_from_timespec(&ts);
 #else
   timeval tv;
@@ -241,13 +243,13 @@ ink_get_hrtime_internal()
 static inline struct timeval
 ink_gettimeofday()
 {
-  return ink_hrtime_to_timeval(ink_get_hrtime_internal());
+  return ink_hrtime_to_timeval(ink_get_hrtime());
 }
 
 static inline int
 ink_time()
 {
-  return (int)ink_hrtime_to_sec(ink_get_hrtime_internal());
+  return (int)ink_hrtime_to_sec(ink_get_hrtime());
 }
 
 static inline int

iocore/aio/AIO.cc

@@ -73,7 +73,7 @@ aio_stats_cb(const char * /* name ATS_UNUSED */, RecDataT data_type, RecData *da
   int64_t new_val = 0;
   int64_t diff    = 0;
   int64_t count, sum;
-  ink_hrtime now = Thread::get_hrtime();
+  ink_hrtime now = ink_get_hrtime();
   // The RecGetGlobalXXX stat functions are cheaper than the
   // RecGetXXX functions. The Global ones are expensive
   // for increments and decrements. But for AIO stats we
@@ -118,7 +118,7 @@ static AIOTestData *data;
 int
 AIOTestData::ink_aio_stats(int event, void *d)
 {
-  ink_hrtime now   = Thread::get_hrtime();
+  ink_hrtime now   = ink_get_hrtime();
   double time_msec = (double)(now - start) / (double)HRTIME_MSECOND;
   int i            = (aio_reqs[0] == nullptr) ? 1 : 0;
   for (; i < num_filedes; ++i)
@@ -487,7 +487,7 @@ aio_thread_main(void *arg)
       }
       ink_mutex_acquire(&my_aio_req->aio_mutex);
     } while (true);
-    timespec timedwait_msec = ink_hrtime_to_timespec(Thread::get_hrtime_updated() + HRTIME_MSECONDS(net_config_poll_timeout));
+    timespec timedwait_msec = ink_hrtime_to_timespec(ink_get_hrtime() + HRTIME_MSECONDS(net_config_poll_timeout));
     ink_cond_timedwait(&my_aio_req->aio_cond, &my_aio_req->aio_mutex, &timedwait_msec);
   }
   return nullptr;

iocore/aio/test_AIO.cc

@@ -253,11 +253,11 @@ int
 AIO_Device::do_fd(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
 {
   if (!time_start) {
-    time_start = Thread::get_hrtime();
+    time_start = ink_get_hrtime();
     fprintf(stderr, "Starting the aio_testing \n");
   }
-  if ((Thread::get_hrtime() - time_start) > (run_time * HRTIME_SECOND)) {
-    time_end = Thread::get_hrtime();
+  if ((ink_get_hrtime() - time_start) > (run_time * HRTIME_SECOND)) {
+    time_end = ink_get_hrtime();
     ink_atomic_increment(&n_accessors, -1);
     if (n_accessors <= 0) {
       dump_summary();

iocore/cache/CacheDir.cc

@@ -1104,7 +1104,7 @@ CacheSync::mainEvent(int event, Event *e)
     }
 
     if (!vol->dir_sync_in_progress) {
-      start_time = Thread::get_hrtime();
+      start_time = ink_get_hrtime();
     }
 
     // recompute hit_evacuate_window
@@ -1186,7 +1186,7 @@ CacheSync::mainEvent(int event, Event *e)
     } else {
       vol->dir_sync_in_progress = false;
       CACHE_INCREMENT_DYN_STAT(cache_directory_sync_count_stat);
-      CACHE_SUM_DYN_STAT(cache_directory_sync_time_stat, Thread::get_hrtime() - start_time);
+      CACHE_SUM_DYN_STAT(cache_directory_sync_time_stat, ink_get_hrtime() - start_time);
       start_time = 0;
       goto Ldone;
     }
@@ -1500,27 +1500,27 @@ EXCLUSIVE_REGRESSION_TEST(Cache_dir)(RegressionTest *t, int /* atype ATS_UNUSED
   // test insert-delete
   rprintf(t, "insert-delete test\n");
   regress_rand_init(13);
-  ttime = Thread::get_hrtime_updated();
+  ttime = ink_get_hrtime();
   for (i = 0; i < newfree; i++) {
     regress_rand_CacheKey(&key);
     dir_insert(&key, d, &dir);
   }
-  uint64_t us = (Thread::get_hrtime_updated() - ttime) / HRTIME_USECOND;
+  uint64_t us = (ink_get_hrtime() - ttime) / HRTIME_USECOND;
   // On windows us is sometimes 0. I don't know why.
   // printout the insert rate only if its not 0
   if (us) {
     rprintf(t, "insert rate = %d / second\n", static_cast<int>((newfree * static_cast<uint64_t>(1000000)) / us));
   }
   regress_rand_init(13);
-  ttime = Thread::get_hrtime_updated();
+  ttime = ink_get_hrtime();
   for (i = 0; i < newfree; i++) {
     Dir *last_collision = nullptr;
     regress_rand_CacheKey(&key);
     if (!dir_probe(&key, d, &dir, &last_collision)) {
       ret = REGRESSION_TEST_FAILED;
     }
   }
-  us = (Thread::get_hrtime_updated() - ttime) / HRTIME_USECOND;
+  us = (ink_get_hrtime() - ttime) / HRTIME_USECOND;
   // On windows us is sometimes 0. I don't know why.
   // printout the probe rate only if its not 0
   if (us) {

iocore/cache/CacheRead.cc

@@ -307,7 +307,7 @@ CacheVC::openReadFromWriter(int event, Event *e)
     // before the open_write, but the reader could not get the volume
     // lock. If we don't reset the clock here, we won't choose any writer
     // and hence fail the read request.
-    start_time                = Thread::get_hrtime();
+    start_time                = ink_get_hrtime();
     f.read_from_writer_called = 1;
   }
   cancel_trigger();

iocore/cache/CacheWrite.cc

@@ -207,7 +207,7 @@ CacheVC::updateVector(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
    - total_len. The total number of bytes for the document so far.
      Doc->total_len and alternate's total len is set to this value.
    - first_key. Doc's first_key is set to this value.
-   - pin_in_cache. Doc's pinned value is set to this + Thread::get_hrtime().
+   - pin_in_cache. Doc's pinned value is set to this + ink_get_hrtime().
    - earliest_key. If f.use_first_key, Doc's key is set to this value.
    - key. If !f.use_first_key, Doc's key is set to this value.
    - blocks. Used only if write_len is set. Data to be written
@@ -680,7 +680,7 @@ Vol::evacuateDocReadDone(int event, Event *e)
   if (!b) {
     goto Ldone;
   }
-  if ((b->f.pinned && !b->readers) && doc->pinned < static_cast<uint32_t>(Thread::get_hrtime() / HRTIME_SECOND)) {
+  if ((b->f.pinned && !b->readers) && doc->pinned < static_cast<uint32_t>(ink_get_hrtime() / HRTIME_SECOND)) {
     goto Ldone;
   }
 
@@ -817,7 +817,7 @@ agg_copy(char *p, CacheVC *vc)
     doc->checksum                        = DOC_NO_CHECKSUM;
     if (vc->pin_in_cache) {
       dir_set_pinned(&vc->dir, 1);
-      doc->pinned = static_cast<uint32_t>(Thread::get_hrtime() / HRTIME_SECOND) + vc->pin_in_cache;
+      doc->pinned = static_cast<uint32_t>(ink_get_hrtime() / HRTIME_SECOND) + vc->pin_in_cache;
     } else {
       dir_set_pinned(&vc->dir, 0);
       doc->pinned = 0;

iocore/cache/P_CacheInternal.h

@@ -562,7 +562,7 @@ new_CacheVC(Continuation *cont)
   c->vector.data.data = &c->vector.data.fast_data[0];
   c->_action          = cont;
   c->mutex            = cont->mutex;
-  c->start_time       = Thread::get_hrtime();
+  c->start_time       = ink_get_hrtime();
   c->setThreadAffinity(t);
   ink_assert(c->trigger == nullptr);
   Debug("cache_new", "new %p", c);

iocore/cache/P_CacheTest.h

@@ -95,7 +95,7 @@ struct CacheTestSM : public RegressionSM {
   void
   make_request()
   {
-    start_time = Thread::get_hrtime();
+    start_time = ink_get_hrtime();
     make_request_internal();
   }
   virtual void make_request_internal() = 0;

iocore/dns/DNS.cc

@@ -412,7 +412,7 @@ DNSEntry::init(DNSQueryData target, int qtype_arg, Continuation *acont, DNSProce
       qtype = T_AAAA;
     }
   }
-  submit_time   = Thread::get_hrtime();
+  submit_time   = ink_get_hrtime();
   action        = acont;
   submit_thread = acont->mutex->thread_holding;
 
@@ -688,7 +688,7 @@ DNSHandler::retry_named(int ndx, ink_hrtime t, bool reopen)
 void
 DNSHandler::try_primary_named(bool reopen)
 {
-  ink_hrtime t = Thread::get_hrtime();
+  ink_hrtime t = ink_get_hrtime();
   if (reopen && ((t - last_primary_reopen) > DNS_PRIMARY_REOPEN_PERIOD)) {
     Debug("dns", "try_primary_named: reopening primary DNS connection");
     last_primary_reopen = t;
@@ -990,7 +990,7 @@ DNSHandler::mainEvent(int event, Event *e)
     if (DNS_CONN_MODE::TCP_RETRY == dns_conn_mode) {
       check_and_reset_tcp_conn();
     }
-    ink_hrtime t = Thread::get_hrtime();
+    ink_hrtime t = ink_get_hrtime();
     if (t - last_primary_retry > DNS_PRIMARY_RETRY_PERIOD) {
       for (int i = 0; i < n_con; i++) {
         if (ns_down[i]) {
@@ -1218,7 +1218,7 @@ write_dns_event(DNSHandler *h, DNSEntry *e, bool over_tcp)
   ++h->in_flight;
   DNS_INCREMENT_DYN_STAT(dns_in_flight_stat);
 
-  e->send_time = Thread::get_hrtime();
+  e->send_time = ink_get_hrtime();
 
   if (e->timeout) {
     e->timeout->cancel();
@@ -1393,9 +1393,9 @@ dns_result(DNSHandler *h, DNSEntry *e, HostEnt *ent, bool retry, bool tcp_retry)
   }
   if (!cancelled) {
     if (!ent || !ent->good) {
-      DNS_SUM_DYN_STAT(dns_fail_time_stat, Thread::get_hrtime() - e->submit_time);
+      DNS_SUM_DYN_STAT(dns_fail_time_stat, ink_get_hrtime() - e->submit_time);
     } else {
-      DNS_SUM_DYN_STAT(dns_success_time_stat, Thread::get_hrtime() - e->submit_time);
+      DNS_SUM_DYN_STAT(dns_success_time_stat, ink_get_hrtime() - e->submit_time);
     }
   }
 
@@ -1543,7 +1543,7 @@ dns_process(DNSHandler *handler, HostEnt *buf, int len)
   --(handler->in_flight);
   DNS_DECREMENT_DYN_STAT(dns_in_flight_stat);
 
-  DNS_SUM_DYN_STAT(dns_response_time_stat, Thread::get_hrtime() - e->send_time);
+  DNS_SUM_DYN_STAT(dns_response_time_stat, ink_get_hrtime() - e->send_time);
 
   // retrying over TCP when truncated is set
   if (dns_conn_mode == DNS_CONN_MODE::TCP_RETRY && h->tc == 1) {

iocore/dns/P_DNSProcessor.h

@@ -203,7 +203,7 @@ struct DNSHandler : public Continuation {
     ++failover_number[name_server];
     Debug("dns", "sent_one: failover_number for resolver %d is %d", name_server, failover_number[name_server]);
     if (failover_number[name_server] >= dns_failover_number && !crossed_failover_number[name_server])
-      crossed_failover_number[name_server] = Thread::get_hrtime();
+      crossed_failover_number[name_server] = ink_get_hrtime();
   }
 
   bool
@@ -212,17 +212,17 @@ struct DNSHandler : public Continuation {
     if (is_debug_tag_set("dns")) {
       Debug("dns", "failover_now: Considering immediate failover, target time is %" PRId64 "",
             (ink_hrtime)HRTIME_SECONDS(dns_failover_period));
-      Debug("dns", "\tdelta time is %" PRId64 "", (Thread::get_hrtime() - crossed_failover_number[i]));
+      Debug("dns", "\tdelta time is %" PRId64 "", (ink_get_hrtime() - crossed_failover_number[i]));
     }
-    return ns_down[i] || (crossed_failover_number[i] &&
-                          ((Thread::get_hrtime() - crossed_failover_number[i]) > HRTIME_SECONDS(dns_failover_period)));
+    return ns_down[i] ||
+           (crossed_failover_number[i] && ((ink_get_hrtime() - crossed_failover_number[i]) > HRTIME_SECONDS(dns_failover_period)));
   }
 
   bool
   failover_soon(int i)
   {
     return ns_down[i] || (crossed_failover_number[i] &&
-                          ((Thread::get_hrtime() - crossed_failover_number[i]) >
+                          ((ink_get_hrtime() - crossed_failover_number[i]) >
                            (HRTIME_SECONDS(dns_failover_try_period + failover_soon_number[i] * FAILOVER_SOON_RETRY))));
   }
 

iocore/eventsystem/I_EThread.h

@@ -291,7 +291,7 @@ class EThread : public Thread
 
   Event *schedule_local(Event *e);
 
-  InkRand generator = static_cast<uint64_t>(Thread::get_hrtime_updated() ^ reinterpret_cast<uintptr_t>(this));
+  InkRand generator = static_cast<uint64_t>(ink_get_hrtime() ^ reinterpret_cast<uintptr_t>(this));
 
   /*-------------------------------------------------------*\
   |  UNIX Interface                                         |
@@ -366,7 +366,7 @@ class EThread : public Thread
     int
     waitForActivity(ink_hrtime timeout) override
     {
-      _q.wait(Thread::get_hrtime() + timeout);
+      _q.wait(ink_get_hrtime() + timeout);
       return 0;
     }
     void

iocore/eventsystem/I_Lock.h

@@ -277,7 +277,7 @@ Mutex_trylock(
 #ifdef DEBUG
     m->srcloc    = location;
     m->handler   = ahandler;
-    m->hold_time = Thread::get_hrtime();
+    m->hold_time = ink_get_hrtime();
 #ifdef MAX_LOCK_TAKEN
     m->taken++;
 #endif // MAX_LOCK_TAKEN
@@ -324,7 +324,7 @@ Mutex_lock(
 #ifdef DEBUG
     m->srcloc    = location;
     m->handler   = ahandler;
-    m->hold_time = Thread::get_hrtime();
+    m->hold_time = ink_get_hrtime();
 #ifdef MAX_LOCK_TAKEN
     m->taken++;
 #endif // MAX_LOCK_TAKEN
@@ -363,7 +363,7 @@ Mutex_unlock(ProxyMutex *m, EThread *t)
     m->nthread_holding--;
     if (!m->nthread_holding) {
 #ifdef DEBUG
-      if (Thread::get_hrtime() - m->hold_time > MAX_LOCK_TIME)
+      if (ink_get_hrtime() - m->hold_time > MAX_LOCK_TIME)
         lock_holding(m->srcloc, m->handler);
 #ifdef MAX_LOCK_TAKEN
       if (m->taken > MAX_LOCK_TAKEN)

iocore/eventsystem/I_Thread.h

@@ -159,37 +159,13 @@ class Thread
 
       @note The cached copy is thread local which means each thread need to update the cached copy by itself.
   */
-  static ink_hrtime get_hrtime();
-
-  /** Get the operating system high resolution time.
-
-      Get the current time at high resolution from the operating system.  This is more expensive
-      than @c get_hrtime and should be used only where very precise timing is required.
-
-      @note This also updates the cached time.
-  */
-  static ink_hrtime get_hrtime_updated();
 
   Thread(const Thread &) = delete;
   Thread &operator=(const Thread &) = delete;
   virtual ~Thread();
 
 protected:
   Thread();
-
-  static thread_local ink_hrtime cur_time;
 };
 
 extern Thread *this_thread();
-
-TS_INLINE ink_hrtime
-Thread::get_hrtime()
-{
-  return cur_time;
-}
-
-TS_INLINE ink_hrtime
-Thread::get_hrtime_updated()
-{
-  return cur_time = ink_get_hrtime_internal();
-}

iocore/eventsystem/PQ-List.cc

@@ -25,7 +25,7 @@
 
 PriorityEventQueue::PriorityEventQueue()
 {
-  last_check_time    = Thread::get_hrtime_updated();
+  last_check_time    = ink_get_hrtime();
   last_check_buckets = last_check_time / PQ_BUCKET_TIME(0);
 }