Timing fix for HostDB restructure (#34)

bneradt · bneradt · SolidWallOfCode · commit fd79ca63ea89 · 2022-07-01T15:56:29.000-05:00
The default duration of time_since_epoch() is
std::chrono::high_resolution_clock::duration, which will not generally
be seconds. hostDB.refcountcache-&gt;put expects the epoch count to be a
number of seconds. This explicitly casts to seconds so we get that
expected value.

This also makes some other std::chrono time updates.

Co-authored-by: bneradt &lt;bneradt@yahooinc.com&gt;
diff --git a/include/tscore/ink_time.h b/include/tscore/ink_time.h
@@ -53,6 +53,7 @@ using ts_hr_time  = ts_hr_clock::time_point;
 
 using ts_seconds      = std::chrono::seconds;
 using ts_milliseconds = std::chrono::milliseconds;
+using ts_nanoseconds  = std::chrono::nanoseconds;
 
 /// Equivalent of 0 for @c ts_time. This should be used as the default initializer.
 static constexpr ts_time TS_TIME_ZERO;
diff --git a/iocore/hostdb/HostDB.cc b/iocore/hostdb/HostDB.cc
@@ -38,6 +38,7 @@
 #include <http/HttpConfig.h>
 
 using ts::TextView;
+using std::chrono::duration_cast;
 
 HostDBProcessor hostDBProcessor;
 int HostDBProcessor::hostdb_strict_round_robin = 0;
@@ -54,11 +55,12 @@ unsigned int hostdb_ip_stale_interval          = HOST_DB_IP_STALE;
 unsigned int hostdb_ip_timeout_interval        = HOST_DB_IP_TIMEOUT;
 unsigned int hostdb_ip_fail_timeout_interval   = HOST_DB_IP_FAIL_TIMEOUT;
 unsigned int hostdb_serve_stale_but_revalidate = 0;
-ts_seconds hostdb_hostfile_check_interval{std::chrono::hours(24)};
-// Epoch timestamp of the current hosts file check.
-ts_time hostdb_current_interval{TS_TIME_ZERO};
+static ts_seconds hostdb_hostfile_check_interval{std::chrono::hours(24)};
+// Epoch timestamp of the current hosts file check. This also functions as a
+// cached version of ts_clock::now().
+ts_time hostdb_current_timestamp{TS_TIME_ZERO};
 // Epoch timestamp of the last time we actually checked for a hosts file update.
-static ts_time hostdb_last_interval{TS_TIME_ZERO};
+static ts_time hostdb_last_timestamp{TS_TIME_ZERO};
 // Epoch timestamp when we updated the hosts file last.
 static ts_time hostdb_hostfile_update_timestamp{TS_TIME_ZERO};
 static char hostdb_filename[PATH_NAME_MAX] = DEFAULT_HOST_DB_FILENAME;
@@ -420,7 +422,7 @@ HostDBBackgroundTask::wait_event(int, void *)
 
   SET_HANDLER(&HostDBBackgroundTask::sync_event);
   if (next_sync > ts_milliseconds{100}) {
-    eventProcessor.schedule_in(this, std::chrono::duration_cast<std::chrono::nanoseconds>(next_sync).count(), ET_TASK);
+    eventProcessor.schedule_in(this, duration_cast<ts_nanoseconds>(next_sync).count(), ET_TASK);
   } else {
     eventProcessor.schedule_imm(this, ET_TASK);
   }
@@ -552,9 +554,10 @@ HostDBProcessor::start(int, size_t)
   REC_EstablishStaticConfigInt32U(hostdb_round_robin_max_count, "proxy.config.hostdb.round_robin_max_count");
 
   //
-  // Set up hostdb_current_interval
+  // Initialize hostdb_current_timestamp which is our cached version of
+  // ts_clock::now().
   //
-  hostdb_current_interval = ts_clock::now();
+  hostdb_current_timestamp = ts_clock::now();
 
   HostDBContinuation *b = hostDBContAllocator.alloc();
   SET_CONTINUATION_HANDLER(b, (HostDBContHandler)&HostDBContinuation::backgroundEvent);
@@ -693,19 +696,19 @@ probe(const Ptr<ProxyMutex> &mutex, HostDBHash const &hash, bool ignore_timeout)
   }
 
   // If the record is stale, but we want to revalidate-- lets start that up
-  if ((!ignore_timeout && record->is_ip_stale() && record->record_type != HostDBType::HOST) ||
+  if ((!ignore_timeout && record->is_ip_configured_stale() && record->record_type != HostDBType::HOST) ||
       (record->is_ip_timeout() && record->serve_stale_but_revalidate())) {
     HOSTDB_INCREMENT_DYN_STAT(hostdb_total_serve_stale_stat);
     if (hostDB.is_pending_dns_for_hash(hash.hash)) {
       Debug("hostdb", "%s",
-            ts::bwprint(ts::bw_dbg, "stale {} {} {}, using with pending refresh", record->ip_interval(),
+            ts::bwprint(ts::bw_dbg, "stale {} {} {}, using with pending refresh", record->ip_age(),
                         record->ip_timestamp.time_since_epoch(), record->ip_timeout_interval)
               .c_str());
       return record;
     }
     Debug("hostdb", "%s",
-          ts::bwprint(ts::bw_dbg, "stale {} {} {}, using while refresh", record->ip_interval(),
-                      record->ip_timestamp.time_since_epoch(), record->ip_timeout_interval)
+          ts::bwprint(ts::bw_dbg, "stale {} {} {}, using while refresh", record->ip_age(), record->ip_timestamp.time_since_epoch(),
+                      record->ip_timeout_interval)
             .c_str());
     HostDBContinuation *c = hostDBContAllocator.alloc();
     HostDBContinuation::Options copt;
@@ -962,7 +965,7 @@ HostDBContinuation::lookup_done(TextView query_name, ts_seconds answer_ttl, SRVH
       ip_text_buffer b;
       Debug("hostdb", "failed for %s", hash.ip.toString(b, sizeof b));
     }
-    record->ip_timestamp        = hostdb_current_interval;
+    record->ip_timestamp        = hostdb_current_timestamp;
     record->ip_timeout_interval = ts_seconds(std::clamp(hostdb_ip_fail_timeout_interval, 1u, HOST_DB_MAX_TTL));
 
     if (is_srv()) {
@@ -997,7 +1000,7 @@ HostDBContinuation::lookup_done(TextView query_name, ts_seconds answer_ttl, SRVH
     HOSTDB_SUM_DYN_STAT(hostdb_ttl_stat, answer_ttl.count());
 
     // update the TTL
-    record->ip_timestamp        = hostdb_current_interval;
+    record->ip_timestamp        = hostdb_current_timestamp;
     record->ip_timeout_interval = std::clamp(answer_ttl, ts_seconds(1), ts_seconds(HOST_DB_MAX_TTL));
 
     if (is_byname()) {
@@ -1206,9 +1209,9 @@ HostDBContinuation::dnsEvent(int event, HostEnt *e)
     }
 
     if (!serve_stale) { // implies r != old_r
-      hostDB.refcountcache->put(
-        r->key, r.get(), r->_record_size,
-        (r->ip_timestamp + r->ip_timeout_interval + ts_seconds(hostdb_serve_stale_but_revalidate)).time_since_epoch().count());
+      auto const duration_till_revalidate = r->expiry_time().time_since_epoch();
+      auto const seconds_till_revalidate  = duration_cast<ts_seconds>(duration_till_revalidate).count();
+      hostDB.refcountcache->put(r->key, r.get(), r->_record_size, seconds_till_revalidate);
     } else {
       Warning("Fallback to serving stale record, skip re-update of hostdb for %.*s", int(query_name.size()), query_name.data());
     }
@@ -1511,22 +1514,22 @@ HostDBContinuation::do_dns()
 
 //
 // Background event
-// Just increment the current_interval.  Might do other stuff
-// here, like move records to the current position in the cluster.
-//
+// Increment the hostdb_current_timestamp which funcions as our cached version
+// of ts_clock::now().  Might do other stuff here, like move records to the
+// current position in the cluster.
 int
 HostDBContinuation::backgroundEvent(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
 {
   std::string dbg;
 
-  // No nothing if hosts file checking is not enabled.
+  hostdb_current_timestamp = ts_clock::now();
+
+  // Do nothing if hosts file checking is not enabled.
   if (hostdb_hostfile_check_interval.count() == 0) {
     return EVENT_CONT;
   }
 
-  hostdb_current_interval = ts_clock::now();
-
-  if ((hostdb_current_interval - hostdb_last_interval) > hostdb_hostfile_check_interval) {
+  if ((hostdb_current_timestamp - hostdb_last_timestamp) > hostdb_hostfile_check_interval) {
     bool update_p = false; // do we need to reparse the file and update?
     char path[PATH_NAME_MAX];
 
@@ -1539,7 +1542,7 @@ HostDBContinuation::backgroundEvent(int /* event ATS_UNUSED */, Event * /* e ATS
       hostdb_hostfile_path             = path;
       update_p                         = true;
     } else if (!hostdb_hostfile_path.empty()) {
-      hostdb_last_interval = hostdb_current_interval;
+      hostdb_last_timestamp = hostdb_current_timestamp;
       std::error_code ec;
       auto stat{ts::file::status(hostdb_hostfile_path, ec)};
       if (!ec) {
@@ -1688,7 +1691,7 @@ struct ShowHostDB : public ShowCont {
           CHECK_SHOW(show("<table border=1>\n"));
           CHECK_SHOW(show("<tr><td>%s</td><td>%d</td></tr>\n", "Total", r->rr_count));
           CHECK_SHOW(show("<tr><td>%s</td><td>%d</td></tr>\n", "Current", r->_rr_idx.load()));
-          CHECK_SHOW(show("<tr><td>%s</td><td>%s</td></tr>\n", "Stale", r->is_ip_stale() ? "Yes" : "No"));
+          CHECK_SHOW(show("<tr><td>%s</td><td>%s</td></tr>\n", "Stale", r->is_ip_configured_stale() ? "Yes" : "No"));
           CHECK_SHOW(show("<tr><td>%s</td><td>%s</td></tr>\n", "Timed-Out", r->is_ip_timeout() ? "Yes" : "No"));
           CHECK_SHOW(show("</table>\n"));
         } else {
@@ -2112,7 +2115,7 @@ ParseHostFile(ts::file::path const &path, ts_seconds hostdb_hostfile_check_inter
         }
       }
 
-      hostdb_hostfile_update_timestamp = hostdb_current_interval;
+      hostdb_hostfile_update_timestamp = hostdb_current_timestamp;
     }
   }
 
@@ -2280,10 +2283,10 @@ HostDBRecord::serve_stale_but_revalidate() const
 
   // ip_timeout_interval == DNS TTL
   // hostdb_serve_stale_but_revalidate == number of seconds
-  // ip_interval() is the number of seconds between now() and when the entry was inserted
-  if ((ip_timeout_interval + ts_seconds(hostdb_serve_stale_but_revalidate)) > ip_interval()) {
-    Debug_bw("hostdb", "serving stale entry {} | {} | {} as requested by config", ip_timeout_interval,
-             hostdb_serve_stale_but_revalidate, ip_interval());
+  // ip_age() is the number of seconds between now() and when the entry was inserted
+  if ((ip_timeout_interval + ts_seconds(hostdb_serve_stale_but_revalidate)) > ip_age()) {
+    Debug_bw("hostdb", "serving stale entry for {}, TTL: {}, serve_stale_for: {}, age: {} as requested by config", name(),
+             ip_timeout_interval, hostdb_serve_stale_but_revalidate, ip_age());
     return true;
   }
 
diff --git a/iocore/hostdb/I_HostDBProcessor.h b/iocore/hostdb/I_HostDBProcessor.h
@@ -61,7 +61,17 @@ struct ResolveInfo;
 // disk representation to decrease # of seeks.
 //
 extern int hostdb_enable;
-extern ts_time hostdb_current_interval;
+/** Epoch timestamp of the current hosts file check.
+ *
+ * This also functions as a cached version of ts_clock::now(). Since it is
+ * updated in backgroundEvent which runs every second, it should be
+ * approximately accurate to a second.
+ */
+extern ts_time hostdb_current_timestamp;
+
+/** How long before any DNS response is consided stale, regardless of DNS TTL.
+ * This corresponds to proxy.config.hostdb.verify_after.
+ */
 extern unsigned int hostdb_ip_stale_interval;
 extern unsigned int hostdb_ip_timeout_interval;
 extern unsigned int hostdb_ip_fail_timeout_interval;
@@ -325,10 +335,13 @@ class HostDBRecord : public RefCountObj
   /// Hash key.
   uint64_t key{0};
 
-  /// When the data was received.
+  /// When the DNS response was received.
   ts_time ip_timestamp;
 
-  /// Valid duration of the data.
+  /// Valid duration of the DNS response data.
+  /// In the code this functions as the TTL in HostDB calcuations, but may not
+  /// be the response's TTL based upon configuration such as
+  /// proxy.config.hostdb.ttl_mode.
   ts_seconds ip_timeout_interval;
 
   /** Atomically advance the round robin index.
@@ -414,18 +427,33 @@ class HostDBRecord : public RefCountObj
   /// @return The time point when the item expires.
   ts_time expiry_time() const;
 
-  ts_seconds ip_interval() const;
+  /// @return The age of the DNS response.
+  ts_seconds ip_age() const;
 
+  /// @return How long before the DNS response becomes stale (i.e., exceeds @a
+  /// ip_timeout_interval from the time of the response).
   ts_seconds ip_time_remaining() const;
 
-  bool is_ip_stale() const;
+  /// @return Whether the age of the DNS response exceeds @a the user's
+  /// configured proxy.config.hostdb.verify_after value.
+  bool is_ip_configured_stale() const;
 
+  /** Whether we have exceeded the DNS response's TTL (i.e., whether the DNS
+   * response is stale). */
   bool is_ip_timeout() const;
 
   bool is_ip_fail_timeout() const;
 
   void refresh_ip();
 
+  /** Whether the DNS response can still be used per
+   * proxy.config.hostdb.serve_stale_for configuration.
+   *
+   * @return False if serve_stale_for is not configured or if the DNS
+   * response's age is less than TTL + the serve_stale_for value. Note that
+   * this function will return true for DNS responses whose age is less than
+   * TTL (i.e., for responses that are not yet stale).
+   */
   bool serve_stale_but_revalidate() const;
 
   /// Deallocate @a this.
@@ -722,41 +750,44 @@ HostDBRecord::expiry_time() const
 }
 
 inline ts_seconds
-HostDBRecord::ip_interval() const
+HostDBRecord::ip_age() const
 {
   static constexpr ts_seconds ZERO{0};
   static constexpr ts_seconds MAX{0x7FFFFFFF};
-  return std::clamp(std::chrono::duration_cast<ts_seconds>((hostdb_current_interval - ip_timestamp)), ZERO, MAX);
+  return std::clamp(std::chrono::duration_cast<ts_seconds>(hostdb_current_timestamp - ip_timestamp), ZERO, MAX);
 }
 
 inline ts_seconds
 HostDBRecord::ip_time_remaining() const
 {
-  return ip_timeout_interval - this->ip_interval();
+  static constexpr ts_seconds ZERO{0};
+  static constexpr ts_seconds MAX{0x7FFFFFFF};
+  return std::clamp(std::chrono::duration_cast<ts_seconds>(ip_timeout_interval - this->ip_age()), ZERO, MAX);
 }
 
 inline bool
-HostDBRecord::is_ip_stale() const
+HostDBRecord::is_ip_configured_stale() const
 {
-  return ip_timeout_interval >= ts_seconds(2 * hostdb_ip_stale_interval) && ip_interval() >= ts_seconds(hostdb_ip_stale_interval);
+  return (
+    ((ip_timeout_interval >= ts_seconds(2 * hostdb_ip_stale_interval)) && (ip_age() >= ts_seconds(hostdb_ip_stale_interval))));
 }
 
 inline bool
 HostDBRecord::is_ip_timeout() const
 {
-  return ip_interval() >= ip_timeout_interval;
+  return ip_age() >= ip_timeout_interval;
 }
 
 inline bool
 HostDBRecord::is_ip_fail_timeout() const
 {
-  return ip_interval() >= ts_seconds(hostdb_ip_fail_timeout_interval);
+  return ip_age() >= ts_seconds(hostdb_ip_fail_timeout_interval);
 }
 
 inline void
 HostDBRecord::refresh_ip()
 {
-  ip_timestamp = hostdb_current_interval;
+  ip_timestamp = hostdb_current_timestamp;
 }
 
 inline ts::MemSpan<HostDBInfo>
