You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@trafficserver.apache.org by am...@apache.org on 2019/01/22 15:58:36 UTC

[trafficserver] branch master updated: Add Log fields that dump all MIME headers in a message.

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

amc 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 7e8a181  Add Log fields that dump all MIME headers in a message.
7e8a181 is described below

commit 7e8a181989ab9e27ddb86104f20065e877230210
Author: Walt Karas <wk...@yahoo-inc.com>
AuthorDate: Thu Sep 14 23:28:00 2017 +0000

    Add Log fields that dump all MIME headers in a message.
---
 .gitignore                                         |   1 +
 doc/admin-guide/logging/formatting.en.rst          |  32 ++++
 proxy/logging/Log.cc                               |  25 +++
 proxy/logging/LogAccess.cc                         |  52 +++++++
 proxy/logging/LogAccess.h                          |  81 +++++-----
 proxy/logging/LogUtils.cc                          | 171 +++++++++++++++++++++
 proxy/logging/LogUtils.h                           |  14 ++
 proxy/logging/Makefile.am                          |  27 +++-
 proxy/logging/test_LogUtils.cc                     |   9 ++
 proxy/logging/unit-tests/BufferWriterFormat.cc     |  24 +++
 proxy/logging/unit-tests/test_LogUtils.h           |  73 +++++++++
 proxy/logging/unit-tests/test_LogUtils2.cc         | 132 ++++++++++++++++
 src/traffic_server/Makefile.inc                    |   2 +-
 tests/gold_tests/logging/all_headers.test.py       | 112 ++++++++++++++
 tests/gold_tests/logging/all_headers_sanitizer.py  |  43 ++++++
 .../gold_tests/logging/gold/test_all_headers.gold  |   4 +
 16 files changed, 759 insertions(+), 43 deletions(-)

diff --git a/.gitignore b/.gitignore
index e56e2fe..361ce6d 100644
--- a/.gitignore
+++ b/.gitignore
@@ -103,6 +103,7 @@ proxy/http2/test_Http2DependencyTree
 proxy/http2/test_HPACK
 proxy/http2/hpack-tests/results
 proxy/logging/test_LogUtils
+proxy/logging/test_LogUtils2
 
 plugins/header_rewrite/header_rewrite_test
 plugins/experimental/esi/*_test
diff --git a/doc/admin-guide/logging/formatting.en.rst b/doc/admin-guide/logging/formatting.en.rst
index fce1edd..5295d6b 100644
--- a/doc/admin-guide/logging/formatting.en.rst
+++ b/doc/admin-guide/logging/formatting.en.rst
@@ -274,6 +274,11 @@ HTTP Headers
 .. _epsh:
 .. _essh:
 .. _ecssh:
+.. _cqah:
+.. _pqah:
+.. _psah:
+.. _ssah:
+.. _cssah:
 
 The following log tables provide access to the values of specified HTTP headers
 from each phase of the transaction lifecycle. Unlike many of the other log
@@ -320,6 +325,33 @@ ssh            essh
 cssh           ecssh
 ============== ===================
 
+It is also possible to log all of the headers in a transaction message with a
+single field.  For each original original field, there is a variant which ends in
+``ah`` rather than ``h``, as shown here:
+
+============== ===================
+Original Field All Headers Variant
+============== ===================
+cqh            cqah
+pqh            pqah
+psh            psah
+ssh            ssah
+cssh           cssah
+============== ===================
+
+No particular header is specified when using these variants, for example::
+
+    Format = '%<cqah>'
+
+The output generated by these fields has the pattern::
+
+    {{{tag1}:{value1}}{{tag2}:{value2}}...}
+
+(The size of some messages may exceed internal buffer capacity.  This may
+result in the value of the last header being truncated, in which case, the
+value will end with ``...}``.  This may also result in the ommission of
+entire tag/value pairs.)
+
 .. _admin-logging-fields-methods:
 
 HTTP Methods
diff --git a/proxy/logging/Log.cc b/proxy/logging/Log.cc
index 3d11a75..2e6d8fa 100644
--- a/proxy/logging/Log.cc
+++ b/proxy/logging/Log.cc
@@ -535,6 +535,11 @@ Log::init_fields()
   global_field_list.add(field, false);
   field_symbol_hash.emplace("ctec", field);
 
+  field = new LogField("client_request_all_header_fields", "cqah", LogField::STRING,
+                       &LogAccess::marshal_client_req_all_header_fields, &LogUtils::unmarshalMimeHdr);
+  global_field_list.add(field, false);
+  field_symbol_hash.emplace("cqah", field);
+
   // proxy -> client fields
   field = new LogField("proxy_resp_content_type", "psct", LogField::STRING, &LogAccess::marshal_proxy_resp_content_type,
                        (LogField::UnmarshalFunc)&LogAccess::unmarshal_str);
@@ -632,6 +637,11 @@ Log::init_fields()
   global_field_list.add(field, false);
   field_symbol_hash.emplace("chm", 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);
+  field_symbol_hash.emplace("psah", field);
+
   // proxy -> server fields
   field = new LogField("proxy_req_header_len", "pqhl", LogField::sINT, &LogAccess::marshal_proxy_req_header_len,
                        &LogAccess::unmarshal_int_to_str);
@@ -710,6 +720,11 @@ Log::init_fields()
   global_field_list.add(field, false);
   field_symbol_hash.emplace("pqssl", field);
 
+  field = new LogField("proxy_request_all_header_fields", "pqah", LogField::STRING, &LogAccess::marshal_proxy_req_all_header_fields,
+                       &LogUtils::unmarshalMimeHdr);
+  global_field_list.add(field, false);
+  field_symbol_hash.emplace("pqah", field);
+
   // server -> proxy fields
   field = new LogField("server_host_ip", "shi", LogField::IP, &LogAccess::marshal_server_host_ip, &LogAccess::unmarshal_ip_to_str);
 
@@ -776,6 +791,11 @@ Log::init_fields()
   global_field_list.add(field, false);
   field_symbol_hash.emplace("sca", field);
 
+  field = new LogField("origin_response_all_header_fields", "ssah", LogField::STRING,
+                       &LogAccess::marshal_server_resp_all_header_fields, &LogUtils::unmarshalMimeHdr);
+  global_field_list.add(field, false);
+  field_symbol_hash.emplace("ssah", field);
+
   field = new LogField("cached_resp_status_code", "csssc", LogField::sINT, &LogAccess::marshal_cache_resp_status_code,
                        &LogAccess::unmarshal_http_status);
   global_field_list.add(field, false);
@@ -801,6 +821,11 @@ Log::init_fields()
   global_field_list.add(field, false);
   field_symbol_hash.emplace("csshv", field);
 
+  field = new LogField("cache_origin_response_all_header_fields", "cssah", LogField::STRING,
+                       &LogAccess::marshal_cache_resp_all_header_fields, &LogUtils::unmarshalMimeHdr);
+  global_field_list.add(field, false);
+  field_symbol_hash.emplace("cssah", field);
+
   field = new LogField("client_retry_after_time", "crat", LogField::sINT, &LogAccess::marshal_client_retry_after_time,
                        &LogAccess::unmarshal_int_to_str);
   global_field_list.add(field, false);
diff --git a/proxy/logging/LogAccess.cc b/proxy/logging/LogAccess.cc
index 586676b..a9a6fe7 100644
--- a/proxy/logging/LogAccess.cc
+++ b/proxy/logging/LogAccess.cc
@@ -360,6 +360,15 @@ LogAccess::marshal_str(char *dest, const char *source, int padded_len)
 }
 
 /*-------------------------------------------------------------------------
+  -------------------------------------------------------------------------*/
+
+int
+LogAccess::marshal_client_req_all_header_fields(char *buf)
+{
+  return LogUtils::marshalMimeHdr(m_client_request, buf);
+}
+
+/*-------------------------------------------------------------------------
   LogAccess::marshal_mem
 
   This is a version of marshal_str that works with unterminated strings.
@@ -477,6 +486,18 @@ LogAccess::unmarshal_int(char **buf)
 }
 
 /*-------------------------------------------------------------------------
+  -------------------------------------------------------------------------*/
+
+int
+LogAccess::marshal_proxy_resp_all_header_fields(char *buf)
+{
+  return LogUtils::marshalMimeHdr(m_proxy_response, buf);
+}
+
+/*-------------------------------------------------------------------------
+  -------------------------------------------------------------------------*/
+
+/*-------------------------------------------------------------------------
   unmarshal_itoa
 
   This routine provides a fast conversion from a binary int to a string.
@@ -587,6 +608,18 @@ LogAccess::unmarshal_int_to_str_hex(char **buf, char *dest, int len)
 }
 
 /*-------------------------------------------------------------------------
+  -------------------------------------------------------------------------*/
+
+int
+LogAccess::marshal_proxy_req_all_header_fields(char *buf)
+{
+  return LogUtils::marshalMimeHdr(m_proxy_request, buf);
+}
+
+/*-------------------------------------------------------------------------
+  -------------------------------------------------------------------------*/
+
+/*-------------------------------------------------------------------------
   LogAccess::unmarshal_str
 
   Retrieve the string from the location pointed at by the buffer and
@@ -673,6 +706,18 @@ LogAccess::unmarshal_int_to_time_str(char **buf, char *dest, int len)
   return strlen;
 }
 
+/*-------------------------------------------------------------------------
+  -------------------------------------------------------------------------*/
+
+int
+LogAccess::marshal_server_resp_all_header_fields(char *buf)
+{
+  return LogUtils::marshalMimeHdr(m_server_response, buf);
+}
+
+/*-------------------------------------------------------------------------
+  -------------------------------------------------------------------------*/
+
 int
 LogAccess::unmarshal_int_to_netscape_str(char **buf, char *dest, int len)
 {
@@ -702,6 +747,13 @@ LogAccess::unmarshal_http_method (char **buf, char *dest, int len)
     return unmarshal_str (buf, dest, len);
 }
 */
+
+int
+LogAccess::marshal_cache_resp_all_header_fields(char *buf)
+{
+  return LogUtils::marshalMimeHdr(m_cache_response, buf);
+}
+
 /*-------------------------------------------------------------------------
   LogAccess::unmarshal_http_version
 
diff --git a/proxy/logging/LogAccess.h b/proxy/logging/LogAccess.h
index f402ad9..fa221ca 100644
--- a/proxy/logging/LogAccess.h
+++ b/proxy/logging/LogAccess.h
@@ -156,60 +156,65 @@ public:
   inkcoreapi int marshal_client_req_uuid(char *);               // STR
   inkcoreapi int marshal_client_rx_error_code(char *);          // STR
   inkcoreapi int marshal_client_tx_error_code(char *);          // STR
+  inkcoreapi int marshal_client_req_all_header_fields(char *);  // STR
 
   //
   // proxy -> client fields
   //
-  inkcoreapi int marshal_proxy_resp_content_type(char *);  // STR
-  inkcoreapi int marshal_proxy_resp_reason_phrase(char *); // STR
-  inkcoreapi int marshal_proxy_resp_squid_len(char *);     // INT
-  inkcoreapi int marshal_proxy_resp_content_len(char *);   // INT
-  inkcoreapi int marshal_proxy_resp_status_code(char *);   // INT
-  inkcoreapi int marshal_proxy_resp_header_len(char *);    // INT
-  inkcoreapi int marshal_proxy_finish_status_code(char *); // INT
-  inkcoreapi int marshal_cache_result_code(char *);        // INT
-  inkcoreapi int marshal_cache_result_subcode(char *);     // INT
-  inkcoreapi int marshal_proxy_host_port(char *);          // INT
-  inkcoreapi int marshal_cache_hit_miss(char *);           // INT
+  inkcoreapi int marshal_proxy_resp_content_type(char *);      // STR
+  inkcoreapi int marshal_proxy_resp_reason_phrase(char *);     // STR
+  inkcoreapi int marshal_proxy_resp_squid_len(char *);         // INT
+  inkcoreapi int marshal_proxy_resp_content_len(char *);       // INT
+  inkcoreapi int marshal_proxy_resp_status_code(char *);       // INT
+  inkcoreapi int marshal_proxy_resp_header_len(char *);        // INT
+  inkcoreapi int marshal_proxy_finish_status_code(char *);     // INT
+  inkcoreapi int marshal_cache_result_code(char *);            // INT
+  inkcoreapi int marshal_cache_result_subcode(char *);         // INT
+  inkcoreapi int marshal_proxy_host_port(char *);              // INT
+  inkcoreapi int marshal_cache_hit_miss(char *);               // INT
+  inkcoreapi int marshal_proxy_resp_all_header_fields(char *); // STR
 
   //
   // proxy -> server fields
   //
-  inkcoreapi int marshal_proxy_req_header_len(char *);  // INT
-  inkcoreapi int marshal_proxy_req_squid_len(char *);   // INT
-  inkcoreapi int marshal_proxy_req_content_len(char *); // INT
-  inkcoreapi int marshal_proxy_req_server_ip(char *);   // INT
-  inkcoreapi int marshal_proxy_req_server_port(char *); // INT
-  inkcoreapi int marshal_proxy_hierarchy_route(char *); // INT
-  inkcoreapi int marshal_next_hop_ip(char *);           // STR
-  inkcoreapi int marshal_next_hop_port(char *);         // INT
-  inkcoreapi int marshal_proxy_host_name(char *);       // STR
-  inkcoreapi int marshal_proxy_host_ip(char *);         // STR
-  inkcoreapi int marshal_proxy_req_is_ssl(char *);      // INT
+  inkcoreapi int marshal_proxy_req_header_len(char *);        // INT
+  inkcoreapi int marshal_proxy_req_squid_len(char *);         // INT
+  inkcoreapi int marshal_proxy_req_content_len(char *);       // INT
+  inkcoreapi int marshal_proxy_req_server_ip(char *);         // INT
+  inkcoreapi int marshal_proxy_req_server_port(char *);       // INT
+  inkcoreapi int marshal_proxy_hierarchy_route(char *);       // INT
+  inkcoreapi int marshal_next_hop_ip(char *);                 // STR
+  inkcoreapi int marshal_next_hop_port(char *);               // INT
+  inkcoreapi int marshal_proxy_host_name(char *);             // STR
+  inkcoreapi int marshal_proxy_host_ip(char *);               // STR
+  inkcoreapi int marshal_proxy_req_is_ssl(char *);            // INT
+  inkcoreapi int marshal_proxy_req_all_header_fields(char *); // STR
 
   //
   // server -> proxy fields
   //
-  inkcoreapi int marshal_server_host_ip(char *);           // INT
-  inkcoreapi int marshal_server_host_name(char *);         // STR
-  inkcoreapi int marshal_server_resp_status_code(char *);  // INT
-  inkcoreapi int marshal_server_resp_squid_len(char *);    // INT
-  inkcoreapi int marshal_server_resp_content_len(char *);  // INT
-  inkcoreapi int marshal_server_resp_header_len(char *);   // INT
-  inkcoreapi int marshal_server_resp_http_version(char *); // INT
-  inkcoreapi int marshal_server_resp_time_ms(char *);      // INT
-  inkcoreapi int marshal_server_resp_time_s(char *);       // INT
-  inkcoreapi int marshal_server_transact_count(char *);    // INT
-  inkcoreapi int marshal_server_connect_attempts(char *);  // INT
+  inkcoreapi int marshal_server_host_ip(char *);                // INT
+  inkcoreapi int marshal_server_host_name(char *);              // STR
+  inkcoreapi int marshal_server_resp_status_code(char *);       // INT
+  inkcoreapi int marshal_server_resp_squid_len(char *);         // INT
+  inkcoreapi int marshal_server_resp_content_len(char *);       // INT
+  inkcoreapi int marshal_server_resp_header_len(char *);        // INT
+  inkcoreapi int marshal_server_resp_http_version(char *);      // INT
+  inkcoreapi int marshal_server_resp_time_ms(char *);           // INT
+  inkcoreapi int marshal_server_resp_time_s(char *);            // INT
+  inkcoreapi int marshal_server_transact_count(char *);         // INT
+  inkcoreapi int marshal_server_connect_attempts(char *);       // INT
+  inkcoreapi int marshal_server_resp_all_header_fields(char *); // STR
 
   //
   // cache -> client fields
   //
-  inkcoreapi int marshal_cache_resp_status_code(char *);  // INT
-  inkcoreapi int marshal_cache_resp_squid_len(char *);    // INT
-  inkcoreapi int marshal_cache_resp_content_len(char *);  // INT
-  inkcoreapi int marshal_cache_resp_header_len(char *);   // INT
-  inkcoreapi int marshal_cache_resp_http_version(char *); // INT
+  inkcoreapi int marshal_cache_resp_status_code(char *);       // INT
+  inkcoreapi int marshal_cache_resp_squid_len(char *);         // INT
+  inkcoreapi int marshal_cache_resp_content_len(char *);       // INT
+  inkcoreapi int marshal_cache_resp_header_len(char *);        // INT
+  inkcoreapi int marshal_cache_resp_http_version(char *);      // INT
+  inkcoreapi int marshal_cache_resp_all_header_fields(char *); // STR
 
   inkcoreapi void set_client_req_url(char *, int);                // STR
   inkcoreapi void set_client_req_url_canon(char *, int);          // STR
diff --git a/proxy/logging/LogUtils.cc b/proxy/logging/LogUtils.cc
index 7b41463..22359eb 100644
--- a/proxy/logging/LogUtils.cc
+++ b/proxy/logging/LogUtils.cc
@@ -21,8 +21,22 @@
   See the License for the specific language governing permissions and
   limitations under the License.
  */
+
+#include <tscore/ink_align.h>
 #include "tscore/ink_config.h"
 #include "tscore/ink_string.h"
+#include <tscore/ink_assert.h>
+#include <tscore/BufferWriter.h>
+
+#ifdef TEST_LOG_UTILS
+
+#include "unit-tests/test_LogUtils.h"
+
+#else
+
+#include <MIME.h>
+
+#endif
 
 #include <cassert>
 #include <cstdio>
@@ -30,6 +44,8 @@
 #include <cstdarg>
 #include <cstring>
 #include <ctime>
+#include <string_view>
+#include <cstdint>
 
 #include <sys/time.h>
 #include <sys/types.h>
@@ -571,3 +587,158 @@ LogUtils::file_is_writeable(const char *full_filename, off_t *size_bytes, bool *
 
   return ret_val;
 }
+
+namespace
+{
+// Get a string out of a MIMEField using one of its member funcitions, and put it into a buffer writer, terminated with a nul.
+//
+void
+marshalStr(ts::FixedBufferWriter &bw, const MIMEField &mf, const char *(MIMEField::*get_func)(int *length) const)
+{
+  int length;
+  const char *data = (mf.*get_func)(&length);
+
+  if (!data or (*data == '\0')) {
+    // Empty string.  This is a problem, since it would result in two successive nul characters, which indicates the end of the
+    // marshaled hearer.  Change the string to a single blank character.
+
+    static const char Blank[] = " ";
+    data                      = Blank;
+    length                    = 1;
+  }
+
+  bw << std::string_view(data, length) << '\0';
+}
+
+void
+unmarshalStr(ts::FixedBufferWriter &bw, const char *&data)
+{
+  bw << '{';
+
+  while (*data) {
+    bw << *(data++);
+  }
+
+  // Skip over terminal nul.
+  ++data;
+
+  bw << '}';
+}
+
+} // end anonymous namespace
+
+namespace LogUtils
+{
+// Marshals header tags and values together, with a single terminating nul character.  Returns buffer space required.  'buf' points
+// to where to put the marshaled data.  If 'buf' is null, no data is marshaled, but the function returns the amount of space that
+// would have been used.
+//
+int
+marshalMimeHdr(MIMEHdr *hdr, char *buf)
+{
+  std::size_t bwSize = buf ? SIZE_MAX : 0;
+
+  ts::FixedBufferWriter bw(buf, bwSize);
+
+  if (hdr) {
+    MIMEFieldIter mfIter;
+    const MIMEField *mfp = hdr->iter_get_first(&mfIter);
+
+    while (mfp) {
+      marshalStr(bw, *mfp, &MIMEField::name_get);
+      marshalStr(bw, *mfp, &MIMEField::value_get);
+
+      mfp = hdr->iter_get_next(&mfIter);
+    }
+  }
+
+  bw << '\0';
+
+  return int(INK_ALIGN_DEFAULT(bw.extent()));
+}
+
+// Unmarshaled/printable format is {{{tag1}:{value1}}{{tag2}:{value2}} ... }
+//
+int
+unmarshalMimeHdr(char **buf, char *dest, int destLength)
+{
+  ink_assert(*buf != nullptr);
+
+  const char *data{*buf};
+
+  ink_assert(data != nullptr);
+
+  ts::FixedBufferWriter bw(dest, destLength);
+
+  bw << '{';
+
+  int pairEndFallback{0}, pairEndFallback2{0}, pairSeparatorFallback{0};
+
+  while (*data) {
+    if (!bw.error()) {
+      pairEndFallback2 = pairEndFallback;
+      pairEndFallback  = bw.size();
+    }
+
+    // Add open bracket of pair.
+    //
+    bw << '{';
+
+    // Unmarshal field name.
+    unmarshalStr(bw, data);
+
+    bw << ':';
+
+    if (!bw.error()) {
+      pairSeparatorFallback = bw.size();
+    }
+
+    // Unmarshal field value.
+    unmarshalStr(bw, data);
+
+    // Add close bracket of pair.
+    bw << '}';
+
+  } // end for loop
+
+  bw << '}';
+
+  if (bw.error()) {
+    // The output buffer wasn't big enough.
+
+    static std::string_view FULL_ELLIPSES("...}}}");
+
+    if ((pairSeparatorFallback > pairEndFallback) and ((pairSeparatorFallback + 7) <= destLength)) {
+      // In the report, we can show the existence of the last partial tag/value pair, and maybe part of the value.  If we only
+      // show part of the value, we want to end it with an elipsis, to make it clear it's not complete.
+
+      bw.reduce(destLength - FULL_ELLIPSES.size());
+      bw << FULL_ELLIPSES;
+
+    } else if (pairEndFallback and (pairEndFallback < destLength)) {
+      bw.reduce(pairEndFallback);
+      bw << '}';
+
+    } else if ((pairSeparatorFallback > pairEndFallback2) and ((pairSeparatorFallback + 7) <= destLength)) {
+      bw.reduce(destLength - FULL_ELLIPSES.size());
+      bw << FULL_ELLIPSES;
+
+    } else if (pairEndFallback2 and (pairEndFallback2 < destLength)) {
+      bw.reduce(pairEndFallback2);
+      bw << '}';
+
+    } else if (destLength > 1) {
+      bw.reduce(1);
+      bw << '}';
+
+    } else {
+      bw.reduce(0);
+    }
+  }
+
+  *buf += INK_ALIGN_DEFAULT(data - *buf + 1);
+
+  return bw.size();
+}
+
+} // end namespace LogUtils
diff --git a/proxy/logging/LogUtils.h b/proxy/logging/LogUtils.h
index 96cd051..2860db1 100644
--- a/proxy/logging/LogUtils.h
+++ b/proxy/logging/LogUtils.h
@@ -27,6 +27,8 @@
 #include "tscore/ink_platform.h"
 #include "tscore/Arena.h"
 
+class MIMEHdr;
+
 namespace LogUtils
 {
 enum AlarmType {
@@ -59,4 +61,16 @@ int timestamp_to_hex_str(unsigned timestamp, char *str, size_t len, size_t *n_ch
 int seconds_to_next_roll(time_t time_now, int rolling_offset, int rolling_interval);
 int file_is_writeable(const char *full_filename, off_t *size_bytes = nullptr, bool *has_size_limit = nullptr,
                       uint64_t *current_size_limit_bytes = nullptr);
+
+// Marshals header tags and values together, with a single terminating nul character.  Returns buffer space required.  'buf' points
+// to where to put the marshaled data.  If 'buf' is null, no data is marshaled, but the function returns the amount of space that
+// would have been used.
+int marshalMimeHdr(MIMEHdr *hdr, char *buf);
+
+// Unmarshelled/printable format is {{{tag1}:{value1}}{{tag2}:{value2}} ... }
+//
+// Returns -1 if data corruption is detected, otherwise the actual amount of data put into the 'dest' buffer.  '*buf' is advanced
+// to byte after the last byte consumed.
+int unmarshalMimeHdr(char **buf, char *dest, int destLength);
+
 }; // namespace LogUtils
diff --git a/proxy/logging/Makefile.am b/proxy/logging/Makefile.am
index cac0eb4..9f438ed 100644
--- a/proxy/logging/Makefile.am
+++ b/proxy/logging/Makefile.am
@@ -79,18 +79,37 @@ liblogcollation_a_SOURCES = \
 	LogCollationHostSM.h
 
 check_PROGRAMS = \
-	test_LogUtils
+	test_LogUtils \
+	test_LogUtils2
 
 TESTS = \
-	test_LogUtils
+	test_LogUtils \
+	test_LogUtils2
+
+test_LogUtils_CPPFLAGS =  $(AM_CPPFLAGS)\
+	-DTEST_LOG_UTILS
+
+test_LogUtils_SOURCES = \
+	test_LogUtils.cc
 
 test_LogUtils_LDADD = \
 	$(top_builddir)/src/tscore/libtscore.la \
 	$(top_builddir)/src/tscpp/util/libtscpputil.la \
 	$(top_builddir)/iocore/eventsystem/libinkevent.a
 
-test_LogUtils_SOURCES = \
-	test_LogUtils.cc
+test_LogUtils2_CPPFLAGS =  $(AM_CPPFLAGS)\
+	-DTEST_LOG_UTILS \
+	-I$(abs_top_srcdir)/tests/include
+
+test_LogUtils2_SOURCES = \
+	LogUtils.cc \
+	unit-tests/BufferWriterFormat.cc \
+	unit-tests/test_LogUtils2.cc
+
+test_LogUtils2_LDADD = \
+	$(top_builddir)/src/tscore/libtscore.la \
+	$(top_builddir)/src/tscpp/util/libtscpputil.la \
+	$(top_builddir)/iocore/eventsystem/libinkevent.a
 
 clang-tidy-local: $(liblogging_a_SOURCES) $(liblogcollation_a_SOURCES) $(EXTRA_DIST)
 	$(CXX_Clang_Tidy)
diff --git a/proxy/logging/test_LogUtils.cc b/proxy/logging/test_LogUtils.cc
index 0f39524..02b8cfe 100644
--- a/proxy/logging/test_LogUtils.cc
+++ b/proxy/logging/test_LogUtils.cc
@@ -25,6 +25,15 @@
 #include "LogUtils.cc"
 #include <string.h>
 
+#if 0
+// Stub
+EThread *
+this_ethread()
+{
+  return nullptr;
+}
+#endif
+
 REGRESSION_TEST(LogUtils_pure_escapify_url)(RegressionTest *t, int /* atype ATS_UNUSED */, int *pstatus)
 {
   TestBox box(t, pstatus);
diff --git a/proxy/logging/unit-tests/BufferWriterFormat.cc b/proxy/logging/unit-tests/BufferWriterFormat.cc
new file mode 100644
index 0000000..d2c3e39
--- /dev/null
+++ b/proxy/logging/unit-tests/BufferWriterFormat.cc
@@ -0,0 +1,24 @@
+/** @file
+
+  includes BufferWriterFormat.cc from TS utilities.
+
+  @section license License
+
+  Licensed to the Apache Software Foundation (ASF) under one
+  or more contributor license agreements.  See the NOTICE file
+  distributed with this work for additional information
+  regarding copyright ownership.  The ASF licenses this file
+  to you under the Apache License, Version 2.0 (the
+  "License"); you may not use this file except in compliance
+  with the License.  You may obtain a copy of the License at
+
+      http://www.apache.org/licenses/LICENSE-2.0
+
+  Unless required by applicable law or agreed to in writing, software
+  distributed under the License is distributed on an "AS IS" BASIS,
+  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+  See the License for the specific language governing permissions and
+  limitations under the License.
+ */
+
+#include "../../../src/tscore/BufferWriterFormat.cc"
diff --git a/proxy/logging/unit-tests/test_LogUtils.h b/proxy/logging/unit-tests/test_LogUtils.h
new file mode 100644
index 0000000..3c9ed22
--- /dev/null
+++ b/proxy/logging/unit-tests/test_LogUtils.h
@@ -0,0 +1,73 @@
+/** @file
+
+  Header file for shared declarations/definitions for test_LogUtils2.cc and LogUtils.h for unit testing.
+
+  @section license License
+
+  Licensed to the Apache Software Foundation (ASF) under one
+  or more contributor license agreements.  See the NOTICE file
+  distributed with this work for additional information
+  regarding copyright ownership.  The ASF licenses this file
+  to you under the Apache License, Version 2.0 (the
+  "License"); you may not use this file except in compliance
+  with the License.  You may obtain a copy of the License at
+
+      http://www.apache.org/licenses/LICENSE-2.0
+
+  Unless required by applicable law or agreed to in writing, software
+  distributed under the License is distributed on an "AS IS" BASIS,
+  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+  See the License for the specific language governing permissions and
+  limitations under the License.
+ */
+
+#pragma once
+
+struct MIMEField {
+  const char *tag, *value;
+
+  const char *
+  name_get(int *length) const
+  {
+    *length = strlen(tag);
+    return tag;
+  }
+  const char *
+  value_get(int *length) const
+  {
+    *length = strlen(value);
+    return value;
+  }
+};
+
+struct MIMEFieldIter {
+};
+
+class MIMEHdr
+{
+public:
+  MIMEHdr(const MIMEField *first, int count) : _first(first), _count(count), _idx(0) {}
+
+  const MIMEField *
+  iter_get_first(MIMEFieldIter *)
+  {
+    return _idx < _count ? _first + _idx : nullptr;
+  }
+  const MIMEField *
+  iter_get_next(MIMEFieldIter *)
+  {
+    ++_idx;
+    return iter_get_first(nullptr);
+  }
+
+  void
+  reset()
+  {
+    _idx = 0;
+  }
+
+private:
+  const MIMEField *const _first;
+  const int _count;
+  int _idx;
+};
diff --git a/proxy/logging/unit-tests/test_LogUtils2.cc b/proxy/logging/unit-tests/test_LogUtils2.cc
new file mode 100644
index 0000000..31376b3
--- /dev/null
+++ b/proxy/logging/unit-tests/test_LogUtils2.cc
@@ -0,0 +1,132 @@
+/** @file
+
+  Catch-based tests for LogUtils.h.
+
+  @section license License
+
+  Licensed to the Apache Software Foundation (ASF) under one
+  or more contributor license agreements.  See the NOTICE file
+  distributed with this work for additional information
+  regarding copyright ownership.  The ASF licenses this file
+  to you under the Apache License, Version 2.0 (the
+  "License"); you may not use this file except in compliance
+  with the License.  You may obtain a copy of the License at
+
+      http://www.apache.org/licenses/LICENSE-2.0
+
+  Unless required by applicable law or agreed to in writing, software
+  distributed under the License is distributed on an "AS IS" BASIS,
+  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+  See the License for the specific language governing permissions and
+  limitations under the License.
+ */
+
+#include <tscore/ink_assert.h>
+#include <tscore/ink_align.h>
+
+#include <LogUtils.h>
+
+#include "test_LogUtils.h"
+
+#define CATCH_CONFIG_MAIN
+#include "catch.hpp"
+
+#include <cstring>
+
+using namespace LogUtils;
+
+namespace
+{
+void
+test(const MIMEField *pairs, int numPairs, const char *asciiResult, int extraUnmarshalSpace = 0)
+{
+  char binBuf[1500], asciiBuf[1500];
+
+  MIMEHdr hdr{pairs, numPairs};
+
+  int binAlignSize = marshalMimeHdr(numPairs ? &hdr : nullptr, nullptr);
+
+  REQUIRE(binAlignSize < sizeof(binBuf));
+
+  hdr.reset();
+
+  REQUIRE(marshalMimeHdr(numPairs ? &hdr : nullptr, binBuf) == binAlignSize);
+
+  int binSize{1};
+
+  if (binBuf[0]) {
+    for (; binBuf[binSize] or binBuf[binSize + 1]; ++binSize) {
+    }
+
+    binSize += 2;
+
+  } else {
+    binSize = 1;
+  }
+
+  REQUIRE(INK_ALIGN_DEFAULT(binSize) == binAlignSize);
+
+  char *bp = binBuf;
+
+  int asciiSize = unmarshalMimeHdr(&bp, asciiBuf, std::strlen(asciiResult) + extraUnmarshalSpace);
+
+  REQUIRE(asciiSize == std::strlen(asciiResult));
+
+  REQUIRE((bp - binBuf) == binAlignSize);
+
+  REQUIRE(std::memcmp(asciiBuf, asciiResult, asciiSize) == 0);
+}
+
+} // namespace
+
+TEST_CASE("LogUtilsHttp", "[LUHP]")
+{
+#define X "12345678"
+#define X2 X X
+#define X3 X2 X2
+#define X4 X3 X3
+#define X5 X4 X4
+#define X6 X5 X5
+#define X7 X6 X6
+#define X8 X7 X7
+
+  const MIMEField pairs[] = {{"Argh", "Ugh"}, {"Argh2", "UghUgh"}, {"alltogethernow", X8}};
+
+  test(pairs, 1, "{{{Argh}:{Ugh}}}");
+  test(pairs, 2, "{{{Argh}:{Ugh}}{{Argh2}:{UghUgh}}}");
+  test(pairs, 2, "{{{Argh}:{Ugh}}{{Argh2}:{Ug...}}}");
+  test(pairs, 2, "{{{Argh}:{Ugh}}{{Argh2}:{U...}}}");
+  test(pairs, 2, "{{{Argh}:{Ugh}}{{Argh2}:{...}}}");
+  test(pairs, 2, "{{{Argh}:{Ugh}}}");
+  test(pairs, 2, "{{{Argh}:{Ugh}}}", 1);
+  test(pairs, 2, "{{{Argh}:{Ugh}}}", sizeof("{{Argh2}:{...}}") - 2);
+  test(pairs, 3, "{{{Argh}:{Ugh}}{{Argh2}:{UghUgh}}{{alltogethernow}:{" X8 "}}}");
+
+  test(pairs, 3, "{{{Argh}:{Ugh}}{{Argh2}:{UghUgh}}}");
+  test(pairs, 3, "{{{Argh}:{Ugh}}{{Argh2}:{Ug...}}}");
+  test(pairs, 3, "{{{Argh}:{Ugh}}{{Argh2}:{U...}}}");
+  test(pairs, 3, "{{{Argh}:{Ugh}}{{Argh2}:{...}}}");
+  test(pairs, 3, "{{{Argh}:{Ugh}}}");
+  test(pairs, 3, "{{{Argh}:{Ugh}}}", 1);
+  test(pairs, 3, "{{{Argh}:{Ugh}}}", sizeof("{{Argh2}:{...}}") - 2);
+
+  test(nullptr, 0, "{}");
+  test(nullptr, 0, "");
+  test(nullptr, 0, "", 1);
+}
+
+#include <cstdlib>
+#include <iostream>
+
+void
+_ink_assert(const char *a, const char *f, int line)
+{
+  std::cout << a << '\n' << f << '\n' << line << '\n';
+
+  std::exit(1);
+}
+
+void
+RecSignalManager(int, char const *, std::size_t)
+{
+}
diff --git a/src/traffic_server/Makefile.inc b/src/traffic_server/Makefile.inc
index 4657128..e828109 100644
--- a/src/traffic_server/Makefile.inc
+++ b/src/traffic_server/Makefile.inc
@@ -64,8 +64,8 @@ traffic_server_traffic_server_LDADD = \
 	$(top_builddir)/proxy/http/remap/libhttp_remap.a \
 	$(top_builddir)/proxy/http2/libhttp2.a \
 	$(top_builddir)/proxy/logging/liblogging.a \
-	$(top_builddir)/proxy/logging/liblogcollation.a \
 	$(top_builddir)/proxy/hdrs/libhdrs.a \
+	$(top_builddir)/proxy/logging/liblogcollation.a \
 	$(top_builddir)/proxy/shared/libdiagsconfig.a \
 	$(top_builddir)/mgmt/libmgmt_p.la \
 	$(top_builddir)/iocore/utils/libinkutils.a \
diff --git a/tests/gold_tests/logging/all_headers.test.py b/tests/gold_tests/logging/all_headers.test.py
new file mode 100644
index 0000000..8279ae3
--- /dev/null
+++ b/tests/gold_tests/logging/all_headers.test.py
@@ -0,0 +1,112 @@
+'''
+'''
+#  Licensed to the Apache Software Foundation (ASF) under one
+#  or more contributor license agreements.  See the NOTICE file
+#  distributed with this work for additional information
+#  regarding copyright ownership.  The ASF licenses this file
+#  to you under the Apache License, Version 2.0 (the
+#  "License"); you may not use this file except in compliance
+#  with the License.  You may obtain a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+#  Unless required by applicable law or agreed to in writing, software
+#  distributed under the License is distributed on an "AS IS" BASIS,
+#  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+#  See the License for the specific language governing permissions and
+#  limitations under the License.
+
+import os
+import subprocess
+
+Test.Summary = '''
+Test new "all headers" log fields
+'''
+# need Curl
+Test.SkipUnless(
+    Condition.HasProgram(
+        "curl", "Curl need to be installed on system for this test to work"),
+    # Condition.IsPlatform("linux"), Don't see the need for this.
+)
+
+# Define ATS.
+#
+ts = Test.MakeATSProcess("ts")
+
+# Define MicroServer.
+#
+server = Test.MakeOriginServer("server")
+
+request_header = {"headers": "GET / HTTP/1.1\r\nHost: does.not.matter\r\n\r\n", "timestamp": "1469733493.993", "body": ""}
+response_header = {"headers": "HTTP/1.1 200 OK\r\nConnection: close\r\nCache-control: max-age=85000\r\n\r\n",
+    "timestamp": "1469733493.993", "body": "xxx"}
+server.addResponse("sessionlog.json", request_header, response_header)
+
+ts.Disk.records_config.update({
+    'proxy.config.diags.debug.enabled': 0,
+    'proxy.config.diags.debug.tags': 'http|dns',
+})
+
+ts.Disk.remap_config.AddLine(
+    'map http://127.0.0.1:{0} http://127.0.0.1:{1}'.format(ts.Variables.port, server.Variables.Port)
+)
+
+# Mix in a numeric log field.  Hopefull this will detect any binary alignment problems.
+#
+ts.Disk.logging_yaml.AddLines(
+    '''
+formats:
+  - name: custom
+    format: " %<cqah> %<pssc> %<psah> %<ssah> %<pqah> %<cssah> " 
+logs:
+  - filename: test_all_headers
+    format: custom
+'''.split("\n")
+)
+
+# Configure comparison of "sanitized" log file with gold file at end of test.
+#
+Test.Disk.File(os.path.join(ts.Variables.LOGDIR, 'test_all_headers.log.san'),
+               exists=True, content='gold/test_all_headers.gold')
+
+# Ask the OS if the port is ready for connect()
+#
+def CheckPort(Port):
+    return lambda: 0 == subprocess.call('netstat --listen --tcp -n | grep -q :{}'.format(Port), shell=True)
+
+def reallyLong():
+    value = 'abcdefghijklmnop'
+    value = value + value
+    value = value + value
+    value = value + value
+    retval = ""
+    for i in range(3):
+        retval += ' -H "x-header{}: {}"'.format(i, value)
+    return retval
+
+tr = Test.AddTestRun()
+tr.Processes.Default.StartBefore(server, ready=CheckPort(server.Variables.Port))
+tr.Processes.Default.StartBefore(Test.Processes.ts, ready=CheckPort(ts.Variables.port))
+tr.Processes.Default.Command = (
+'curl "http://127.0.0.1:{0}" --user-agent "007" --verbose '.format(ts.Variables.port) + reallyLong()
+)
+tr.Processes.Default.ReturnCode = 0
+
+# Repeat same curl, will be answered from the ATS cache.
+#
+tr = Test.AddTestRun()
+tr.Processes.Default.Command = (
+'curl "http://127.0.0.1:{0}" --user-agent "007" --verbose '.format(ts.Variables.port) + reallyLong()
+)
+tr.Processes.Default.ReturnCode = 0
+
+# Delay to allow TS to flush report to disk, then "sanitize" generated log.
+#
+tr = Test.AddTestRun()
+tr.DelayStart = 10
+tr.Processes.Default.Command = 'python {0} {3} < {1} > {2}'.format(
+    os.path.join(Test.TestDirectory, 'all_headers_sanitizer.py'),
+    os.path.join(ts.Variables.LOGDIR, 'test_all_headers.log'),
+    os.path.join(ts.Variables.LOGDIR, 'test_all_headers.log.san'),
+    server.Variables.Port)
+tr.Processes.Default.ReturnCode = 0
diff --git a/tests/gold_tests/logging/all_headers_sanitizer.py b/tests/gold_tests/logging/all_headers_sanitizer.py
new file mode 100644
index 0000000..0e798df
--- /dev/null
+++ b/tests/gold_tests/logging/all_headers_sanitizer.py
@@ -0,0 +1,43 @@
+'''
+Sanitize the ATS-generated custom log file from the all_headers test.
+'''
+#  Licensed to the Apache Software Foundation (ASF) under one
+#  or more contributor license agreements.  See the NOTICE file
+#  distributed with this work for additional information
+#  regarding copyright ownership.  The ASF licenses this file
+#  to you under the Apache License, Version 2.0 (the
+#  "License"); you may not use this file except in compliance
+#  with the License.  You may obtain a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+#  Unless required by applicable law or agreed to in writing, software
+#  distributed under the License is distributed on an "AS IS" BASIS,
+#  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+#  See the License for the specific language governing permissions and
+#  limitations under the License.
+
+import sys
+import re
+
+rexl = []
+rexl.append((re.compile(r"\{\{Date\}\:\{[^}]*\}\}"), "__DATE__"))
+rexl.append((re.compile(r"\{\{Expires\}\:\{[^}]*\}\}"), "__EXPIRES__"))
+rexl.append((re.compile(r"\{\{Last-Modified\}\:\{[^}]*\}\}"), "__LAST_MODIFIED__"))
+rexl.append((re.compile(r"\{\{Server\}\:\{ATS/[0-9.]*\}\}"), "__ATS_SERVER__"))
+rexl.append((re.compile(r"\{\{Server\}\:\{ECS [^}]*\}\}"), "__ECS_SERVER__"))
+rexl.append((re.compile(r"\{\{Via\}\:\{[^}]*\}\}"), "__VIA__"))
+rexl.append((re.compile(r"\{\{Server\}\:\{ApacheTrafficServer/[0-9.]*\}\}"), "__ATS2_SERVER__"))
+rexl.append((re.compile(r"\{\{Age\}\:\{[0-9]*\}\}"), "__AGE__"))
+rexl.append((re.compile(r"\:" + sys.argv[1]), "__TS_PORT__")) # 1st and only argument is TS client port
+
+# Handle inconsistencies which I think are caused by different revisions of the standard Python http.server.HTTPServer class.
+
+rexl.append((re.compile(r'\{"359670651[^"]*"\}'), '{"359670651__WEIRD__"}'))
+rexl.append((re.compile(r'\{\{Accept-Ranges\}:\{bytes\}\}'), ''))
+
+for line in sys.stdin:
+    for rex, subStr in rexl:
+        line = rex.sub(subStr, line)
+
+    print(line)
diff --git a/tests/gold_tests/logging/gold/test_all_headers.gold b/tests/gold_tests/logging/gold/test_all_headers.gold
new file mode 100644
index 0000000..3cb54e5
--- /dev/null
+++ b/tests/gold_tests/logging/gold/test_all_headers.gold
@@ -0,0 +1,4 @@
+ {{{Host}:{127.0.0.1__TS_PORT__}}{{User-Agent}:{007}}{{Accept}:{*/*}}{{x-header0}:{abcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnop}}{{x-header1}:{abcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnop}}{{x-header2}:{abcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghi [...]
+
+ {{{Host}:{127.0.0.1__TS_PORT__}}{{User-Agent}:{007}}{{Accept}:{*/*}}{{x-header0}:{abcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnop}}{{x-header1}:{abcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnop}}{{x-header2}:{abcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghijklmnopabcdefghi [...]
+