Logging: add freshness_limit (cfl) and current_age (cca) log fields

doc/admin-guide/logging/formatting.en.rst

@@ -156,6 +156,8 @@ Cache Details
 .. _crra:
 .. _cwra:
 .. _cccs:
+.. _cfl:
+.. _cca:
 
 These log fields reveal details of the |TS| proxy interaction with its own
 cache while attempting to service incoming client requests.
@@ -186,6 +188,15 @@ cccs  Proxy Cache    Cache collapsed connection success;
                      -1: collapsing was attempted but failed, request went upstream
                      0: collapsing was unnecessary
                      1: attempted to collapse and got a cache hit on subsequent read attempts
+
+cfl   Proxy Cache    Freshness limit (in seconds) for the cached object.
+                     Written when an object is served from or written to
+                     cache. Value is ``-1`` if not applicable.
+
+cca   Proxy Cache    Current age (in seconds) of the cached object at serve
+                     time. Computed from internal state without reading
+                     response headers. Value is ``-1`` if not applicable.
+
 ===== ============== ==========================================================
 
 .. _admin-logging-fields-txn:

include/proxy/http/HttpTransact.h

@@ -490,6 +490,8 @@ class HttpTransact
     HTTPInfo         transform_store;
     CacheDirectives  directives;
     HTTPInfo        *object_read          = nullptr;
+    int              freshness_limit      = -1;  // seconds; -1 = not yet set
+    ink_time_t       current_age          = -1;              // seconds; -1 = not yet set
     HTTPInfo        *stale_fallback       = nullptr; // Saved stale object for action 6 fallback during retry
     CacheWriteLock_t write_lock_state     = CacheWriteLock_t::INIT;
     int              lookup_count         = 0;

include/proxy/logging/LogAccess.h

@@ -190,6 +190,8 @@ class LogAccess
   int marshal_cache_result_subcode(char *);         // INT
   int marshal_proxy_host_port(char *);              // INT
   int marshal_cache_hit_miss(char *);               // INT
+  int marshal_cache_freshness_limit(char *);        // INT
+  int marshal_cache_current_age(char *);            // INT
   int marshal_proxy_resp_all_header_fields(char *); // STR
 
   //

include/proxy/logging/TransactionLogData.h

@@ -163,6 +163,8 @@ class TransactionLogData
   int get_cache_transform_write_code() const;
   int get_cache_open_read_tries() const;
   int get_cache_open_write_tries() const;
+  int get_freshness_limit() const;
+  int64_t get_current_age() const;
   int get_max_cache_open_write_retries() const;
 
   // ===== Retry attempts =====

src/proxy/http/HttpTransact.cc

@@ -7583,10 +7583,13 @@ HttpTransact::what_is_document_freshness(State *s, HTTPHdr *client_request, HTTP
 
   response_date = cached_obj_response->get_date();
   fresh_limit   = calculate_document_freshness_limit(s, cached_obj_response, response_date, &heuristic);
+  s->cache_info.freshness_limit = fresh_limit;  // save for logging
   ink_assert(fresh_limit >= 0);
 
   current_age = HttpTransactCache::calculate_document_age(s->request_sent_time, s->response_received_time, cached_obj_response,
                                                           response_date, s->current.now);
+
+  s->cache_info.current_age = current_age;
 
   // First check overflow status
   // Second if current_age is under the max, use the smaller value

src/proxy/logging/Log.cc

@@ -722,6 +722,16 @@ Log::init_fields()
   global_field_list.add(field, false);
   field_symbol_hash.emplace("chm", field);
 
+  field = new LogField("cache_freshness_limit", "cfl", LogField::sINT, &LogAccess::marshal_cache_freshness_limit, 
+                      &LogAccess::unmarshal_int_to_str);
+  global_field_list.add(field, false);
+  field_symbol_hash.emplace("cfl", field);
+
+  field = new LogField("cache_current_age", "cca", LogField::sINT, &LogAccess::marshal_cache_current_age,
+                       &LogAccess::unmarshal_int_to_str);
+  global_field_list.add(field, false);
+  field_symbol_hash.emplace("cca", field);
+
   field = new LogField("proxy_response_all_header_fields", "psah", LogField::STRING,
                        &LogAccess::marshal_proxy_resp_all_header_fields, &LogUtils::unmarshalMimeHdr);
   global_field_list.add(field, false);

src/proxy/logging/LogAccess.cc

@@ -2610,6 +2610,25 @@ LogAccess::marshal_cache_hit_miss(char *buf)
   return INK_MIN_ALIGN;
 }
 
+
+int
+LogAccess::marshal_cache_freshness_limit(char *buf)
+{
+  if (buf) {
+    marshal_int(buf, static_cast<int64_t>(m_data->get_freshness_limit()));
+  }
+  return INK_MIN_ALIGN;
+}
+
+int
+LogAccess::marshal_cache_current_age(char *buf)
+{
+  if (buf) {
+    marshal_int(buf, m_data->get_current_age());
+  }
+  return INK_MIN_ALIGN;
+}
+
 /*-------------------------------------------------------------------------
   -------------------------------------------------------------------------*/
 

src/proxy/logging/TransactionLogData.cc

@@ -949,6 +949,26 @@ TransactionLogData::get_max_cache_open_write_retries() const
   return -1;
 }
 
+int
+TransactionLogData::get_freshness_limit() const
+{
+  if (likely(m_http_sm != nullptr)) {
+    return m_http_sm->t_state.cache_info.freshness_limit;
+  }
+  return -1;
+}
+
+int64_t
+TransactionLogData::get_current_age() const
+{
+  if (likely(m_http_sm != nullptr)) {
+    return static_cast<int64_t>(m_http_sm->t_state.cache_info.current_age);
+  }
+  return -1;
+}
+
+// ===== Retry attempts =====
+
 // ===== Retry attempts =====
 
 int64_t