You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@trafficserver.apache.org by wk...@apache.org on 2022/08/16 21:05:01 UTC

[trafficserver] branch master updated: Fix incrementation and logging of server connection attempts. (#8776)

This is an automated email from the ASF dual-hosted git repository.

wkaras pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/trafficserver.git


The following commit(s) were added to refs/heads/master by this push:
     new eb250b52f Fix incrementation and logging of server connection attempts. (#8776)
eb250b52f is described below

commit eb250b52f5d0991117d58b36eea44870a8592d70
Author: Walt Karas <wk...@verizonmedia.com>
AuthorDate: Tue Aug 16 16:04:55 2022 -0500

    Fix incrementation and logging of server connection attempts. (#8776)
    
    * Fix incrementation and logging of server connection attempts for transaction.
    
    * Changes to PR 8776 required by code review.
    
    Co-authored-by: Walt Karas <wk...@yahooinc.com>
---
 proxy/http/HttpSM.cc       |  6 ++---
 proxy/http/HttpTransact.cc | 50 ++++++++++++++++++-----------------
 proxy/http/HttpTransact.h  | 66 ++++++++++++++++++++++++++++++++++++++++++----
 proxy/logging/LogAccess.cc |  2 +-
 4 files changed, 91 insertions(+), 33 deletions(-)

diff --git a/proxy/http/HttpSM.cc b/proxy/http/HttpSM.cc
index 7ffbf4cc6..ed810af9d 100644
--- a/proxy/http/HttpSM.cc
+++ b/proxy/http/HttpSM.cc
@@ -4840,7 +4840,7 @@ HttpSM::send_origin_throttled_response()
   // t_state.current.attempts so that another parent or
   // NextHop may be tried.
   if (t_state.dns_info.looking_up != ResolveInfo::PARENT_PROXY) {
-    t_state.current.attempts = t_state.txn_conf->connect_attempts_max_retries;
+    t_state.current.attempts.maximize(t_state.configured_connect_attempts_max_retries());
   }
   t_state.current.state = HttpTransact::OUTBOUND_CONGESTION;
   call_transact_and_set_next_state(HttpTransact::HandleResponse);
@@ -5021,7 +5021,7 @@ HttpSM::do_http_server_open(bool raw)
         SMDebug("ip_allow", "Line %d denial for '%.*s' from %s", acl.source_line(), method_str_len, method_str,
                 ats_ip_ntop(server_ip, ipb, sizeof(ipb)));
       }
-      t_state.current.attempts = t_state.txn_conf->connect_attempts_max_retries; // prevent any more retries with this IP
+      t_state.current.attempts.maximize(t_state.configured_connect_attempts_max_retries()); // prevent any more retries with this IP
       call_transact_and_set_next_state(HttpTransact::Forbidden);
       return;
     }
@@ -5285,7 +5285,7 @@ HttpSM::do_http_server_open(bool raw)
 
           SMDebug("http_ss", "using pre-warmed tunnel netvc=%p", netvc);
 
-          t_state.current.attempts = 0;
+          t_state.current.attempts.clear();
 
           ink_release_assert(default_handler == HttpSM::default_handler);
           handleEvent(NET_EVENT_OPEN, netvc);
diff --git a/proxy/http/HttpTransact.cc b/proxy/http/HttpTransact.cc
index e1d79f40a..83a0f0692 100644
--- a/proxy/http/HttpTransact.cc
+++ b/proxy/http/HttpTransact.cc
@@ -509,11 +509,13 @@ HttpTransact::is_server_negative_cached(State *s)
 
 inline static void
 update_current_info(HttpTransact::CurrentInfo *into, HttpTransact::ConnectionAttributes *from,
-                    ResolveInfo::UpstreamResolveStyle who, int attempts)
+                    ResolveInfo::UpstreamResolveStyle who, bool clear_attempts)
 {
   into->request_to = who;
   into->server     = from;
-  into->attempts   = attempts;
+  if (clear_attempts) {
+    into->attempts.clear();
+  }
 }
 
 inline static void
@@ -640,7 +642,7 @@ find_server_and_update_current_info(HttpTransact::State *s)
   switch (s->parent_result.result) {
   case PARENT_SPECIFIED:
     s->parent_info.name = s->arena.str_store(s->parent_result.hostname, strlen(s->parent_result.hostname));
-    update_current_info(&s->current, &s->parent_info, ResolveInfo::PARENT_PROXY, (s->current.attempts)++);
+    update_current_info(&s->current, &s->parent_info, ResolveInfo::PARENT_PROXY, false);
     update_dns_info(&s->dns_info, &s->current);
     ink_assert(s->dns_info.looking_up == ResolveInfo::PARENT_PROXY);
     s->next_hop_scheme = URL_WKSIDX_HTTP;
@@ -661,7 +663,7 @@ find_server_and_update_current_info(HttpTransact::State *s)
     }
   /* fall through */
   default:
-    update_current_info(&s->current, &s->server_info, ResolveInfo::ORIGIN_SERVER, (s->current.attempts)++);
+    update_current_info(&s->current, &s->server_info, ResolveInfo::ORIGIN_SERVER, false);
     update_dns_info(&s->dns_info, &s->current);
     ink_assert(s->dns_info.looking_up == ResolveInfo::ORIGIN_SERVER);
     s->next_hop_scheme = s->scheme;
@@ -1676,7 +1678,7 @@ HttpTransact::setup_plugin_request_intercept(State *s)
   s->scheme = s->next_hop_scheme = URL_WKSIDX_HTTP;
 
   // Set up a "fake" server entry
-  update_current_info(&s->current, &s->server_info, ResolveInfo::ORIGIN_SERVER, 0);
+  update_current_info(&s->current, &s->server_info, ResolveInfo::ORIGIN_SERVER, true);
 
   // Also "fake" the info we'd normally get from
   //   hostDB
@@ -2846,7 +2848,7 @@ HttpTransact::HandleCacheOpenReadHit(State *s)
     if (s->current.request_to == ResolveInfo::ORIGIN_SERVER && is_server_negative_cached(s) && response_returnable == true &&
         is_stale_cache_response_returnable(s) == true) {
       server_up = false;
-      update_current_info(&s->current, nullptr, ResolveInfo::UNDEFINED_LOOKUP, 0);
+      update_current_info(&s->current, nullptr, ResolveInfo::UNDEFINED_LOOKUP, true);
       TxnDebug("http_trans", "CacheOpenReadHit - server_down, returning stale document");
     }
     // a parent lookup could come back as PARENT_FAIL if in parent.config, go_direct == false and
@@ -2854,7 +2856,7 @@ HttpTransact::HandleCacheOpenReadHit(State *s)
     else if (s->current.request_to == ResolveInfo::HOST_NONE && s->parent_result.result == PARENT_FAIL) {
       if (response_returnable == true && is_stale_cache_response_returnable(s) == true) {
         server_up = false;
-        update_current_info(&s->current, nullptr, ResolveInfo::UNDEFINED_LOOKUP, 0);
+        update_current_info(&s->current, nullptr, ResolveInfo::UNDEFINED_LOOKUP, true);
         TxnDebug("http_trans", "CacheOpenReadHit - server_down, returning stale document");
       } else {
         handle_parent_died(s);
@@ -3316,8 +3318,8 @@ HttpTransact::HandleCacheOpenReadMiss(State *s)
       }
     }
     build_request(s, &s->hdr_info.client_request, &s->hdr_info.server_request, s->current.server->http_version);
-    s->current.attempts = 0;
-    s->next_action      = how_to_open_connection(s);
+    s->current.attempts.clear();
+    s->next_action = how_to_open_connection(s);
     if (s->current.server == &s->server_info && s->next_hop_scheme == URL_WKSIDX_HTTP) {
       HttpTransactHeaders::remove_host_name_from_url(&s->hdr_info.server_request);
     }
@@ -3621,7 +3623,7 @@ HttpTransact::handle_response_from_parent(State *s)
     }
 
     char addrbuf[INET6_ADDRSTRLEN];
-    TxnDebug("http_trans", "[%d] failed to connect to parent %s", s->current.attempts,
+    TxnDebug("http_trans", "[%d] failed to connect to parent %s", s->current.attempts.get(),
              ats_ip_ntop(&s->current.server->dst_addr.sa, addrbuf, sizeof(addrbuf)));
 
     // If the request is not retryable, just give up!
@@ -3634,20 +3636,20 @@ HttpTransact::handle_response_from_parent(State *s)
       return;
     }
 
-    if (s->current.attempts < s->txn_conf->parent_connect_attempts) {
+    if (s->current.attempts.get() < s->txn_conf->parent_connect_attempts) {
       HTTP_INCREMENT_DYN_STAT(http_total_parent_retries_stat);
-      s->current.attempts++;
+      s->current.attempts.increment(s->configured_connect_attempts_max_retries());
 
       // Are we done with this particular parent?
-      if ((s->current.attempts - 1) % s->txn_conf->per_parent_connect_attempts != 0) {
+      if ((s->current.attempts.get() - 1) % s->txn_conf->per_parent_connect_attempts != 0) {
         // No we are not done with this parent so retry
         HTTP_INCREMENT_DYN_STAT(http_total_parent_switches_stat);
         s->next_action = how_to_open_connection(s);
         TxnDebug("http_trans", "%s Retrying parent for attempt %d, max %" PRId64, "[handle_response_from_parent]",
-                 s->current.attempts, s->txn_conf->per_parent_connect_attempts);
+                 s->current.attempts.get(), s->txn_conf->per_parent_connect_attempts);
         return;
       } else {
-        TxnDebug("http_trans", "%s %d per parent attempts exhausted", "[handle_response_from_parent]", s->current.attempts);
+        TxnDebug("http_trans", "%s %d per parent attempts exhausted", "[handle_response_from_parent]", s->current.attempts.get());
         HTTP_INCREMENT_DYN_STAT(http_total_parent_retries_exhausted_stat);
 
         // Only mark the parent down if we failed to connect
@@ -3755,9 +3757,9 @@ HttpTransact::handle_response_from_server(State *s)
       max_connect_retries = s->txn_conf->connect_attempts_max_retries;
     }
 
-    TxnDebug("http_trans", "max_connect_retries: %d s->current.attempts: %d", max_connect_retries, s->current.attempts);
+    TxnDebug("http_trans", "max_connect_retries: %d s->current.attempts: %d", max_connect_retries, s->current.attempts.get());
 
-    if (is_request_retryable(s) && s->current.attempts < max_connect_retries) {
+    if (is_request_retryable(s) && s->current.attempts.get() < max_connect_retries) {
       // If this is a round robin DNS entry & we're tried configured
       //    number of times, we should try another node
       if (ResolveInfo::OS_Addr::TRY_CLIENT == s->dns_info.os_addr_style) {
@@ -3773,7 +3775,7 @@ HttpTransact::handle_response_from_server(State *s)
         return CallOSDNSLookup(s);
       } else {
         if ((s->txn_conf->connect_attempts_rr_retries > 0) &&
-            ((s->current.attempts + 1) % s->txn_conf->connect_attempts_rr_retries == 0)) {
+            ((s->current.attempts.get() + 1) % s->txn_conf->connect_attempts_rr_retries == 0)) {
           s->dns_info.select_next_rr();
         }
         retry_server_connection_not_open(s, s->current.state, max_connect_retries);
@@ -3805,7 +3807,7 @@ void
 HttpTransact::error_log_connection_failure(State *s, ServerState_t conn_state)
 {
   char addrbuf[INET6_ADDRSTRLEN];
-  TxnDebug("http_trans", "[%d] failed to connect [%d] to %s", s->current.attempts, conn_state,
+  TxnDebug("http_trans", "[%d] failed to connect [%d] to %s", s->current.attempts.get(), conn_state,
            ats_ip_ntop(&s->current.server->dst_addr.sa, addrbuf, sizeof(addrbuf)));
 
   if (s->current.server->had_connect_fail()) {
@@ -3820,8 +3822,8 @@ HttpTransact::error_log_connection_failure(State *s, ServerState_t conn_state)
                 "CONNECT: attempt fail [{}] to {} for host='{}' "
                 "connection_result={::s} error={::s} attempts={} url='{}'",
                 HttpDebugNames::get_server_state_name(conn_state), s->current.server->dst_addr, host_name,
-                ts::bwf::Errno(s->current.server->connect_result), ts::bwf::Errno(s->cause_of_death_errno), s->current.attempts,
-                ts::bwf::FirstOf(url_str, "<none>"));
+                ts::bwf::Errno(s->current.server->connect_result), ts::bwf::Errno(s->cause_of_death_errno),
+                s->current.attempts.get(), ts::bwf::FirstOf(url_str, "<none>"));
     Log::error("%s", error_bw_buffer.c_str());
 
     s->arena.str_free(url_str);
@@ -3845,7 +3847,7 @@ HttpTransact::retry_server_connection_not_open(State *s, ServerState_t conn_stat
 {
   ink_assert(s->current.state != CONNECTION_ALIVE);
   ink_assert(s->current.state != ACTIVE_TIMEOUT);
-  ink_assert(s->current.attempts <= max_retries);
+  ink_assert(s->current.attempts.get() <= max_retries);
   ink_assert(s->cause_of_death_errno != -UNKNOWN_INTERNAL_ERROR);
 
   error_log_connection_failure(s, conn_state);
@@ -3854,9 +3856,9 @@ HttpTransact::retry_server_connection_not_open(State *s, ServerState_t conn_stat
   // disable keep-alive for request and retry //
   //////////////////////////////////////////////
   s->current.server->keep_alive = HTTP_NO_KEEPALIVE;
-  s->current.attempts++;
+  s->current.attempts.increment(s->configured_connect_attempts_max_retries());
 
-  TxnDebug("http_trans", "attempts now: %d, max: %d", s->current.attempts, max_retries);
+  TxnDebug("http_trans", "attempts now: %d, max: %d", s->current.attempts.get(), max_retries);
 
   return;
 }
diff --git a/proxy/http/HttpTransact.h b/proxy/http/HttpTransact.h
index 03752ebf6..6fbe0f365 100644
--- a/proxy/http/HttpTransact.h
+++ b/proxy/http/HttpTransact.h
@@ -23,6 +23,8 @@
 
 #pragma once
 
+#include <cstddef>
+
 #include "tscore/ink_assert.h"
 #include "tscore/ink_platform.h"
 #include "I_HostDB.h"
@@ -570,12 +572,60 @@ public:
     ConnectionAttributes *server                 = nullptr;
     ink_time_t now                               = 0;
     ServerState_t state                          = STATE_UNDEFINED;
-    unsigned attempts                            = 0;
-    unsigned simple_retry_attempts               = 0;
-    unsigned unavailable_server_retry_attempts   = 0;
-    ParentRetry_t retry_type                     = PARENT_RETRY_NONE;
+    class Attempts
+    {
+    public:
+      Attempts()                 = default;
+      Attempts(Attempts const &) = delete;
+
+      unsigned
+      get() const
+      {
+        return _v;
+      }
+
+      void
+      maximize(MgmtInt configured_connect_attempts_max_retries)
+      {
+        ink_assert(_v <= configured_connect_attempts_max_retries);
+        if (_v < configured_connect_attempts_max_retries) {
+          ink_assert(0 == _saved_v);
+          _saved_v = _v;
+          _v       = configured_connect_attempts_max_retries;
+        }
+      }
+
+      void
+      clear()
+      {
+        _v       = 0;
+        _saved_v = 0;
+      }
+
+      void
+      increment(MgmtInt configured_connect_attempts_max_retries)
+      {
+        ++_v;
+        ink_assert(_v <= configured_connect_attempts_max_retries);
+      }
+
+      unsigned
+      saved() const
+      {
+        return _saved_v ? _saved_v : _v;
+      }
+
+    private:
+      unsigned _v{0}, _saved_v{0};
+    };
+    Attempts attempts;
+    unsigned simple_retry_attempts             = 0;
+    unsigned unavailable_server_retry_attempts = 0;
+    ParentRetry_t retry_type                   = PARENT_RETRY_NONE;
+
+    _CurrentInfo()                     = default;
+    _CurrentInfo(_CurrentInfo const &) = delete;
 
-    _CurrentInfo() {}
   } CurrentInfo;
 
   // Conversion handling for DNS host resolution type.
@@ -877,6 +927,12 @@ public:
       Debug("http", "Setting upstream connection failure %d to %d", e, this->current.server->connect_result);
     }
 
+    MgmtInt
+    configured_connect_attempts_max_retries() const
+    {
+      return txn_conf->connect_attempts_max_retries;
+    }
+
   private:
     // Make this a raw byte array, so it will be accessed through the my_txn_conf() member function.
     alignas(OverridableHttpConfigParams) char _my_txn_conf[sizeof(OverridableHttpConfigParams)];
diff --git a/proxy/logging/LogAccess.cc b/proxy/logging/LogAccess.cc
index 6116688b3..a726a35c4 100644
--- a/proxy/logging/LogAccess.cc
+++ b/proxy/logging/LogAccess.cc
@@ -2633,7 +2633,7 @@ int
 LogAccess::marshal_server_connect_attempts(char *buf)
 {
   if (buf) {
-    int64_t attempts = m_http_sm->t_state.current.attempts;
+    int64_t attempts = m_http_sm->t_state.current.attempts.saved();
     marshal_int(buf, attempts);
   }
   return INK_MIN_ALIGN;