Add proxy.config.cache.log.alternate.eviction

configs/records.config.default.in

@@ -129,6 +129,8 @@ CONFIG proxy.config.cache.ram_cache.size INT -1
 CONFIG proxy.config.cache.ram_cache_cutoff INT 4194304
     # https://docs.trafficserver.apache.org/records.config#proxy-config-cache-limits-http-max-alts
 CONFIG proxy.config.cache.limits.http.max_alts INT 5
+    # https://docs.trafficserver.apache.org/records.config#proxy-config-cache-log-alternate-eviction
+CONFIG proxy.config.cache.log.alternate.eviction INT 0
     # https://docs.trafficserver.apache.org/records.config#proxy-config-cache-max-doc-size
 CONFIG proxy.config.cache.max_doc_size INT 0
 CONFIG proxy.config.cache.min_average_object_size INT 8000

doc/admin-guide/configuration/cache-basics.en.rst

@@ -583,6 +583,9 @@ To force document caching:
 
 #. Run the command :option:`traffic_ctl config reload` to apply the configuration changes.
 
+
+.. _CachingHttpAlternates:
+
 Caching HTTP Alternates
 =======================
 

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

@@ -2242,6 +2242,22 @@ Cache Control
    The maximum number of alternates that are allowed for any given URL.
    Disable by setting to 0.
 
+.. ts:cv:: CONFIG proxy.config.cache.log.alternate.eviction INT 0
+
+   When enabled (``1``), |TS| will emit a Status level log entry every time an
+   alternate for an object is evicted due to the number of its alternates
+   exceeding the value of :ts:cv:`proxy.config.cache.limits.http.max_alts`. The
+   URI for the evicted alternate is included in the log. This logging may be
+   useful to determine whether :ts:cv:`proxy.config.cache.limits.http.max_alts`
+   is tuned correctly for a given environment. It also provides visibility into
+   alternate eviction for individual objects, which can be helpful for
+   diagnosing unexpected `Vary:` header behavior from particular origins.
+
+   For further details concerning the caching of alternates, see :ref:`Caching
+   HTTP Alternates <CachingHttpAlternates>`.
+
+   By default, alternate eviction logging is disabled (set to ``0``).
+
 .. ts:cv:: CONFIG proxy.config.cache.target_fragment_size INT 1048576
 
    Sets the target size of a contiguous fragment of a file in the disk cache.

iocore/cache/Cache.cc

@@ -64,6 +64,7 @@ int cache_config_ram_cache_compress            = 0;
 int cache_config_ram_cache_compress_percent    = 90;
 int cache_config_ram_cache_use_seen_filter     = 1;
 int cache_config_http_max_alts                 = 3;
+int cache_config_log_alternate_eviction        = 0;
 int cache_config_dir_sync_frequency            = 60;
 int cache_config_permit_pinning                = 0;
 int cache_config_select_alternate              = 1;
@@ -3165,6 +3166,9 @@ ink_cache_init(ts::ModuleVersion v)
   REC_EstablishStaticConfigInt32(cache_config_http_max_alts, "proxy.config.cache.limits.http.max_alts");
   Debug("cache_init", "proxy.config.cache.limits.http.max_alts = %d", cache_config_http_max_alts);
 
+  REC_EstablishStaticConfigInt32(cache_config_log_alternate_eviction, "proxy.config.cache.log.alternate.eviction");
+  Debug("cache_init", "proxy.config.cache.log.alternate.eviction = %d", cache_config_log_alternate_eviction);
+
   REC_EstablishStaticConfigInteger(cache_config_ram_cache_cutoff, "proxy.config.cache.ram_cache_cutoff");
   Debug("cache_init", "cache_config_ram_cache_cutoff = %" PRId64 " = %" PRId64 "Mb", cache_config_ram_cache_cutoff,
         cache_config_ram_cache_cutoff / (1024 * 1024));

iocore/cache/CacheWrite.cc

@@ -98,6 +98,30 @@ CacheVC::updateVector(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
       if (od->move_resident_alt && get_alternate_index(write_vector, od->single_doc_key) == 0) {
         od->move_resident_alt = false;
       }
+      if (cache_config_log_alternate_eviction) {
+        CacheHTTPInfo *info = write_vector->get(0);
+        HTTPHdr *request    = info->request_get();
+        if (request->valid()) {
+          // In contrast to url_string_get, this url_print interface doesn't
+          // use HTTPHdr's m_heap which is not valid at this point because the
+          // HttpSM is most likely gone.
+          int url_length = request->url_printed_length();
+          ats_scoped_mem<char> url_text;
+          url_text   = static_cast<char *>(ats_malloc(url_length + 1));
+          int index  = 0;
+          int offset = 0;
+          // url_print does not NULL terminate, so url_length instead of url_length + 1.
+          int ret                    = request->url_print(url_text.get(), url_length, &index, &offset);
+          url_text.get()[url_length] = '\0';
+          if (ret == 0) {
+            Note("Could not print URL of evicted alternate.");
+          } else {
+            Status("The maximum number of alternates was exceeded for a resource. "
+                   "An alternate was evicted for URL: %.*s",
+                   url_length, url_text.get());
+          }
+        }
+      }
       write_vector->remove(0, true);
     }
     if (vec) {

iocore/cache/P_CacheInternal.h

@@ -207,6 +207,7 @@ extern RecRawStatBlock *cache_rsb;
 // Configuration
 extern int cache_config_dir_sync_frequency;
 extern int cache_config_http_max_alts;
+extern int cache_config_log_alternate_eviction;
 extern int cache_config_permit_pinning;
 extern int cache_config_select_alternate;
 extern int cache_config_max_doc_size;

lib/perl/lib/Apache/TS/AdminClient.pm

@@ -341,6 +341,7 @@ The Apache Traffic Server Administration Manual will explain what these strings
  proxy.config.cache.hosting_filename
  proxy.config.cache.ip_allow.filename
  proxy.config.cache.limits.http.max_alts
+ proxy.config.cache.log.alternate.eviction
  proxy.config.cache.max_disk_errors
  proxy.config.cache.max_doc_size
  proxy.config.cache.min_average_object_size

mgmt/RecordsConfig.cc

@@ -838,6 +838,8 @@ static const RecordElement RecordsConfig[] =
   //  # (0 disables the maximum number of alts check)
   {RECT_CONFIG, "proxy.config.cache.limits.http.max_alts", RECD_INT, "5", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL}
   ,
+  {RECT_CONFIG, "proxy.config.cache.log.alternate.eviction", RECD_INT, "0", RECU_DYNAMIC, RR_NULL, RECC_INT, "[0-1]", RECA_NULL}
+  ,
   {RECT_CONFIG, "proxy.config.cache.force_sector_size", RECD_INT, "0", RECU_DYNAMIC, RR_NULL, RECC_NULL, nullptr, RECA_NULL}
   ,
   {RECT_CONFIG, "proxy.config.cache.target_fragment_size", RECD_INT, "1048576", RECU_DYNAMIC, RR_NULL, RECC_NULL, nullptr, RECA_NULL}

tests/gold_tests/cache/gold/two_alternates_evicted.gold

@@ -0,0 +1,3 @@
+``
+``STATUS: The maximum number of alternates was exceeded for a resource. An alternate was evicted for URL: http://127.0.0.1:``/same/path/for/all/requests
+``STATUS: The maximum number of alternates was exceeded for a resource. An alternate was evicted for URL: http://127.0.0.1:``/same/path/for/all/requests