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

[trafficserver] branch master updated: Allow for long Http* error.log lines (#8855)

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

bneradt 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 d274b8f9f Allow for long Http* error.log lines (#8855)
d274b8f9f is described below

commit d274b8f9f066bfd0bd743b9a73e2323b505a8cfc
Author: Brian Neradt <br...@gmail.com>
AuthorDate: Tue Jun 7 15:01:11 2022 -0500

    Allow for long Http* error.log lines (#8855)
    
    Many URLs and log paths are long enough that the previous 256 byte
    error.log limit for HttpSM and HttpTransact made it so that the logs got
    truncated. Some of those logs had meaningful strings at the end which
    made them hard to interpret unless you had the source code in front of
    you to figure out what was truncated. This utilizes bwprint and local
    std::string buffers for arbitrarily long log lines.
---
 proxy/http/HttpSM.cc       | 36 +++++++++++++-----------------------
 proxy/http/HttpTransact.cc | 43 ++++++++++++++++++-------------------------
 2 files changed, 31 insertions(+), 48 deletions(-)

diff --git a/proxy/http/HttpSM.cc b/proxy/http/HttpSM.cc
index a023ea8e0..eb2d62ac1 100644
--- a/proxy/http/HttpSM.cc
+++ b/proxy/http/HttpSM.cc
@@ -101,6 +101,9 @@ namespace
 // Unique state machine identifier
 std::atomic<int64_t> next_sm_id(0);
 
+/// Buffer for some error logs.
+thread_local std::string error_bw_buffer;
+
 /**
    Outbound PROXY Protocol
 
@@ -4168,27 +4171,18 @@ HttpSM::check_sni_host()
             Warning("No SNI for TLS request with hostname %.*s action=%s", host_len, host_name, action_value);
             SMDebug("ssl_sni", "No SNI for TLS request with hostname %.*s action=%s", host_len, host_name, action_value);
             if (host_sni_policy == 2) {
-              Log::error("%s", lbw()
-                                 .clip(1)
-                                 .print("No SNI for TLS request: connecting to {} for host='{}', returning a 403",
-                                        t_state.client_info.dst_addr, std::string_view{host_name, static_cast<size_t>(host_len)})
-                                 .extend(1)
-                                 .write('\0')
-                                 .data());
+              ts::bwprint(error_bw_buffer, "No SNI for TLS request: connecting to {} for host='{}', returning a 403",
+                          t_state.client_info.dst_addr, std::string_view{host_name, static_cast<size_t>(host_len)});
+              Log::error("%s", error_bw_buffer.c_str());
               this->t_state.client_connection_enabled = false;
             }
           } else if (strncasecmp(host_name, sni_value, host_len) != 0) { // Name mismatch
             Warning("SNI/hostname mismatch sni=%s host=%.*s action=%s", sni_value, host_len, host_name, action_value);
             SMDebug("ssl_sni", "SNI/hostname mismatch sni=%s host=%.*s action=%s", sni_value, host_len, host_name, action_value);
             if (host_sni_policy == 2) {
-              Log::error("%s", lbw()
-                                 .clip(1)
-                                 .print("SNI/hostname mismatch: connecting to {} for host='{}' sni='{}', returning a 403",
-                                        t_state.client_info.dst_addr, std::string_view{host_name, static_cast<size_t>(host_len)},
-                                        sni_value)
-                                 .extend(1)
-                                 .write('\0')
-                                 .data());
+              ts::bwprint(error_bw_buffer, "SNI/hostname mismatch: connecting to {} for host='{}' sni='{}', returning a 403",
+                          t_state.client_info.dst_addr, std::string_view{host_name, static_cast<size_t>(host_len)}, sni_value);
+              Log::error("%s", error_bw_buffer.c_str());
               this->t_state.client_connection_enabled = false;
             }
           } else {
@@ -5556,14 +5550,10 @@ HttpSM::mark_host_failure(HostDBInfo *info, time_t time_down)
         int host_len;
         const char *host_name_ptr = t_state.unmapped_url.host_get(&host_len);
         std::string_view host_name{host_name_ptr, size_t(host_len)};
-        Log::error("%s", lbw()
-                           .clip(1)
-                           .print("CONNECT: {::s} connecting to {} for host='{}' url='{}' marking down",
-                                  ts::bwf::Errno(t_state.current.server->connect_result), t_state.current.server->dst_addr,
-                                  host_name, ts::bwf::FirstOf(url_str, "<none>"))
-                           .extend(1)
-                           .write('\0')
-                           .data());
+        ts::bwprint(error_bw_buffer, "CONNECT: {::s} connecting to {} for host='{}' url='{}' marking down",
+                    ts::bwf::Errno(t_state.current.server->connect_result), t_state.current.server->dst_addr, host_name,
+                    ts::bwf::FirstOf(url_str, "<none>"));
+        Log::error("%s", error_bw_buffer.c_str());
 
         if (url_str) {
           t_state.arena.str_free(url_str);
diff --git a/proxy/http/HttpTransact.cc b/proxy/http/HttpTransact.cc
index fbedf96dc..3dc23eddf 100644
--- a/proxy/http/HttpTransact.cc
+++ b/proxy/http/HttpTransact.cc
@@ -51,7 +51,10 @@
 namespace
 {
 char const Dns_error_body[] = "connect#dns_failed";
-}
+
+/// Buffer for some error logs.
+thread_local std::string error_bw_buffer;
+} // namespace
 
 // Support ip_resolve override.
 const MgmtConverter HttpTransact::HOST_RES_CONV{[](const void *data) -> std::string_view {
@@ -95,9 +98,6 @@ static char range_type[] = "multipart/byteranges; boundary=RANGE_SEPARATOR";
 
 extern HttpBodyFactory *body_factory;
 
-// Handy typedef for short (single line) message generation.
-using lbw = ts::LocalBufferWriter<256>;
-
 // wrapper to choose between a remap next hop strategy or use parent.config
 // remap next hop strategy is preferred
 inline static bool
@@ -908,13 +908,9 @@ HttpTransact::OriginDead(State *s)
   int host_len;
   const char *host_name_ptr = s->unmapped_url.host_get(&host_len);
   std::string_view host_name{host_name_ptr, size_t(host_len)};
-  Log::error("%s", lbw()
-                     .clip(1)
-                     .print("CONNECT: dead server no request to {} for host='{}' url='{}'", s->current.server->dst_addr, host_name,
-                            ts::bwf::FirstOf(url_str, "<none>"))
-                     .extend(1)
-                     .write('\0')
-                     .data());
+  ts::bwprint(error_bw_buffer, "CONNECT: dead server no request to {} for host='{}' url='{}'", s->current.server->dst_addr,
+              host_name, ts::bwf::FirstOf(url_str, "<none>"));
+  Log::error("%s", error_bw_buffer.c_str());
   s->arena.str_free(url_str);
 
   TRANSACT_RETURN(SM_ACTION_SEND_ERROR_CACHE_NOOP, nullptr);
@@ -1891,8 +1887,8 @@ HttpTransact::ReDNSRoundRobin(State *s)
     s->next_action       = SM_ACTION_SEND_ERROR_CACHE_NOOP;
     //  s->next_action = PROXY_INTERNAL_CACHE_NOOP;
     char *url_str = s->hdr_info.client_request.url_string_get(&s->arena, nullptr);
-    Log::error("%s",
-               lbw().clip(1).print("DNS Error: looking up {}", ts::bwf::FirstOf(url_str, "<none>")).extend(1).write('\0').data());
+    ts::bwprint(error_bw_buffer, "DNS Error: looking up {}", ts::bwf::FirstOf(url_str, "<none>"));
+    Log::error("%s", error_bw_buffer.c_str());
   }
 
   return;
@@ -1963,8 +1959,8 @@ HttpTransact::OSDNSLookup(State *s)
       // Set to internal server error so later logging will pick up SQUID_LOG_ERR_DNS_FAIL
       build_error_response(s, HTTP_STATUS_INTERNAL_SERVER_ERROR, "Cannot find server.", "connect#dns_failed");
       char *url_str = s->hdr_info.client_request.url_string_get(&s->arena, nullptr);
-      Log::error("%s",
-                 lbw().clip(1).print("DNS Error: looking up {}", ts::bwf::FirstOf(url_str, "<none>")).extend(1).write('\0').data());
+      ts::bwprint(error_bw_buffer, "DNS Error: looking up {}", ts::bwf::FirstOf(url_str, "<none>"));
+      Log::error("%s", error_bw_buffer.c_str());
       // s->cache_info.action = CACHE_DO_NO_ACTION;
       TRANSACT_RETURN(SM_ACTION_SEND_ERROR_CACHE_NOOP, nullptr);
     }
@@ -3911,16 +3907,13 @@ HttpTransact::error_log_connection_failure(State *s, ServerState_t conn_state)
       host_name_ptr = s->unmapped_url.host_get(&host_len);
     }
     std::string_view host_name{host_name_ptr, size_t(host_len)};
-    Log::error("%s", lbw()
-                       .clip(1)
-                       .print("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>"))
-                       .extend(1)
-                       .write('\0')
-                       .data());
+    ts::bwprint(error_bw_buffer,
+                "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>"));
+    Log::error("%s", error_bw_buffer.c_str());
 
     s->arena.str_free(url_str);
   }