Transfer-Encoding:chunked log field fix

When an origin server returns Transfer-Encoding:chunked, ATS removes
this header during response processing to handle dechunking. This
prevented the original header value from being logged via
%<{Transfer-Encoding}ssh>. This fix stores the original
Transfer-Encoding value before deletion and uses the stored value if
requested via the ssh field.

Fixes: #6261

Author: bneradt

include/proxy/http/HttpTransact.h

@@ -635,6 +635,7 @@ class HttpTransact
     bool            trust_response_cl          = false;
     ResponseError_t response_error             = ResponseError_t::NO_RESPONSE_HEADER_ERROR;
     bool            extension_method           = false;
+    std::string     server_response_transfer_encoding; ///< Storage for logging.
 
     _HeaderInfo() {}
   };

src/proxy/http/HttpTransact.cc

@@ -5850,6 +5850,9 @@ HttpTransact::initialize_state_variables_from_response(State *s, HTTPHdr *incomi
           new_enc_val = new_enc_iter.get_next(&new_enc_len);
         }
 
+        // Store the original Transfer-Encoding value for logging before we delete it.
+        s->hdr_info.server_response_transfer_encoding.assign(field->value_get().data(), field->value_get().length());
+
         // We're done with the old field since we copied out everything
         //   we needed
         incoming_response->field_delete(field);

src/proxy/logging/LogAccess.cc

@@ -3246,6 +3246,34 @@ LogAccess::marshal_http_header_field(LogField::Container container, char *field,
     }
   }
 
+  // The Transfer-Encoding:chunked value may have been removed from the header
+  // during processing, but we store it for logging purposes.
+  if (valid_field == false && container == LogField::SSH && strcmp(field, "Transfer-Encoding") == 0) {
+    const std::string &stored_te = m_http_sm->t_state.hdr_info.server_response_transfer_encoding;
+    if (!stored_te.empty()) {
+      valid_field = true;
+      actual_len  = stored_te.length();
+      str         = const_cast<char *>(stored_te.data());
+
+      int running_len = actual_len + 1; // +1 for null terminator
+      padded_len      = padded_length(running_len);
+
+      if (buf) {
+        memcpy(buf, str, actual_len);
+        buf[actual_len]  = '\0';
+        buf             += running_len;
+
+#ifdef DEBUG
+        int pad_len = padded_len - running_len;
+        for (int i = 0; i < pad_len; i++) {
+          *buf = '$';
+          buf++;
+        }
+#endif
+      }
+    }
+  }
+
   if (valid_field == false) {
     padded_len = INK_MIN_ALIGN;
     if (buf) {

tests/gold_tests/logging/gold/field-test.gold

@@ -1,3 +1,3 @@
-application/json,%20application/json
-application/jason,%20application/json
-application/json
+Transfer-Encoding:chunked Content-Type:application/json,%20application/json
+Transfer-Encoding:- Content-Type:application/jason,%20application/json
+Transfer-Encoding:- Content-Type:application/json

tests/gold_tests/logging/log-field.test.py

@@ -29,7 +29,7 @@
 response_header = {
     'timestamp': 100,
     "headers":
-        "HTTP/1.1 200 OK\r\nTest: 1\r\nContent-Type: application/json\r\nConnection: close\r\nContent-Type: application/json\r\n\r\n",
+        "HTTP/1.1 200 OK\r\nTest: 1\r\nContent-Type: application/json\r\nConnection: close\r\nContent-Type: application/json\r\nTransfer-Encoding: chunked\r\n\r\n",
     "body": "Test 1"
 }
 server.addResponse("sessionlog.json", request_header, response_header)
@@ -59,6 +59,8 @@
 
 ts.Disk.records_config.update(
     {
+        'proxy.config.diags.debug.enabled': 1,
+        'proxy.config.diags.debug.tags': 'http|log',
         'proxy.config.net.connections_throttle': 100,
         'proxy.config.dns.nameservers': f"127.0.0.1:{nameserver.Variables.Port}",
         'proxy.config.dns.resolv_conf': 'NULL'
@@ -71,7 +73,7 @@
 logging:
   formats:
     - name: custom
-      format: '%<{Content-Type}essh>'
+      format: 'Transfer-Encoding:%<{Transfer-Encoding}ssh> Content-Type:%<{Content-Type}essh>'
   logs:
     - filename: field-test
       format: custom
@@ -81,6 +83,8 @@
 # at the end of the different test run a custom log file should exist
 # Because of this we expect the testruns to pass the real test is if the
 # customlog file exists and passes the format check
+# Note that the gold file expects Chunked, not chunked, because microserver
+# converts to Chunked. This is not an ATS issue, but a microserver issue.
 Test.Disk.File(os.path.join(ts.Variables.LOGDIR, 'field-test.log'), exists=True, content='gold/field-test.gold')
 
 # first test is a miss for default