Allow logging of request content

9 files changed, 132 insertions, 18 deletions

diff --git a/container-core/abi-spec.json b/container-core/abi-spec.json
index e1ffda5649c..bf9a177c28e 100644
--- a/container-core/abi-spec.json
+++ b/container-core/abi-spec.json
@@ -1047,11 +1047,14 @@
       "public com.yahoo.jdisc.http.ConnectorConfig$AccessLog$Builder remoteAddressHeaders(java.util.Collection)",
       "public com.yahoo.jdisc.http.ConnectorConfig$AccessLog$Builder remotePortHeaders(java.lang.String)",
       "public com.yahoo.jdisc.http.ConnectorConfig$AccessLog$Builder remotePortHeaders(java.util.Collection)",
+      "public com.yahoo.jdisc.http.ConnectorConfig$AccessLog$Builder contentPathPrefixes(java.lang.String)",
+      "public com.yahoo.jdisc.http.ConnectorConfig$AccessLog$Builder contentPathPrefixes(java.util.Collection)",
       "public com.yahoo.jdisc.http.ConnectorConfig$AccessLog build()"
     ],
     "fields" : [
       "public java.util.List remoteAddressHeaders",
-      "public java.util.List remotePortHeaders"
+      "public java.util.List remotePortHeaders",
+      "public java.util.List contentPathPrefixes"
     ]
   },
   "com.yahoo.jdisc.http.ConnectorConfig$AccessLog" : {
@@ -1066,7 +1069,9 @@
       "public java.util.List remoteAddressHeaders()",
       "public java.lang.String remoteAddressHeaders(int)",
       "public java.util.List remotePortHeaders()",
-      "public java.lang.String remotePortHeaders(int)"
+      "public java.lang.String remotePortHeaders(int)",
+      "public java.util.List contentPathPrefixes()",
+      "public java.lang.String contentPathPrefixes(int)"
     ],
     "fields" : [ ]
   },
diff --git a/container-core/src/main/java/com/yahoo/container/logging/AccessLogEntry.java b/container-core/src/main/java/com/yahoo/container/logging/AccessLogEntry.java
index e4af680726a..0eb4485936d 100644
--- a/container-core/src/main/java/com/yahoo/container/logging/AccessLogEntry.java
+++ b/container-core/src/main/java/com/yahoo/container/logging/AccessLogEntry.java
@@ -8,6 +8,7 @@ import java.util.ArrayList;
 import java.util.Collections;
 import java.util.List;
 import java.util.Map;
+import java.util.Optional;
 import java.util.Set;
 import java.util.function.Function;
 
@@ -31,11 +32,23 @@ import static java.util.stream.Collectors.toMap;
  */
 public class AccessLogEntry {
 
+    public record Content(String type, long length, byte[] body) {}
+
     private final Object monitor = new Object();
 
     private HitCounts hitCounts;
     private TraceNode traceNode;
     private ListMap<String,String> keyValues=null;
+    private Content content;
+
+    public void setContent(Content entity) {
+        synchronized (monitor) {
+            requireNull(this.content);
+            this.content = entity;
+        }
+    }
+
+    public Optional<Content> getContent() { synchronized (monitor) { return Optional.ofNullable(content); } }
 
     public void setHitCounts(final HitCounts hitCounts) {
         synchronized (monitor) {
diff --git a/container-core/src/main/java/com/yahoo/container/logging/JSONFormatter.java b/container-core/src/main/java/com/yahoo/container/logging/JSONFormatter.java
index f1e865cd596..1f42f8ded97 100644
--- a/container-core/src/main/java/com/yahoo/container/logging/JSONFormatter.java
+++ b/container-core/src/main/java/com/yahoo/container/logging/JSONFormatter.java
@@ -1,15 +1,16 @@
 // Copyright Vespa.ai. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 package com.yahoo.container.logging;
 
-import com.yahoo.json.Jackson;
 import com.fasterxml.jackson.core.JsonEncoding;
 import com.fasterxml.jackson.core.JsonFactory;
 import com.fasterxml.jackson.core.JsonGenerator;
+import com.yahoo.json.Jackson;
 import com.yahoo.yolean.trace.TraceNode;
 
 import java.io.IOException;
 import java.io.OutputStream;
 import java.security.Principal;
+import java.util.Base64;
 import java.util.Collection;
 import java.util.Objects;
 import java.util.logging.Level;
@@ -102,6 +103,15 @@ public class JSONFormatter implements LogWriter<RequestLogEntry> {
                 trace.accept(new TraceRenderer(generator, timestamp));
             }
 
+            var content = entry.content().orElse(null);
+            if (content != null) {
+                generator.writeObjectFieldStart("content");
+                generator.writeStringField("type", content.type());
+                generator.writeNumberField("length", content.length());
+                generator.writeStringField("body", Base64.getEncoder().encodeToString(content.body()));
+                generator.writeEndObject();
+            }
+
             // Only add search sub block of this is a search request
             if (isSearchRequest(entry)) {
                 HitCounts hitCounts = entry.hitCounts().get();
diff --git a/container-core/src/main/java/com/yahoo/container/logging/RequestLogEntry.java b/container-core/src/main/java/com/yahoo/container/logging/RequestLogEntry.java
index 0092d67b0fa..a5f82a8b637 100644
--- a/container-core/src/main/java/com/yahoo/container/logging/RequestLogEntry.java
+++ b/container-core/src/main/java/com/yahoo/container/logging/RequestLogEntry.java
@@ -1,6 +1,7 @@
 // Copyright Vespa.ai. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 package com.yahoo.container.logging;
 
+import com.yahoo.container.logging.AccessLogEntry.Content;
 import com.yahoo.yolean.trace.TraceNode;
 
 import java.security.Principal;
@@ -50,6 +51,7 @@ public class RequestLogEntry {
     private final Principal sslPrincipal;
     private final HitCounts hitCounts;
     private final TraceNode traceNode;
+    private final Content content;
     private final SortedMap<String, Collection<String>> extraAttributes;
 
     private RequestLogEntry(Builder builder) {
@@ -76,6 +78,7 @@ public class RequestLogEntry {
         this.sslPrincipal = builder.sslPrincipal;
         this.hitCounts = builder.hitCounts;
         this.traceNode = builder.traceNode;
+        this.content = builder.content;
         this.extraAttributes = copyExtraAttributes(builder.extraAttributes);
     }
 
@@ -102,6 +105,7 @@ public class RequestLogEntry {
     public Optional<Principal> sslPrincipal() { return Optional.ofNullable(sslPrincipal); }
     public Optional<HitCounts> hitCounts() { return Optional.ofNullable(hitCounts); }
     public Optional<TraceNode> traceNode() { return Optional.ofNullable(traceNode); }
+    public Optional<Content> content() { return Optional.ofNullable(content); }
     public SortedSet<String> extraAttributeKeys() { return Collections.unmodifiableSortedSet((SortedSet<String>)extraAttributes.keySet()); }
     public Collection<String> extraAttributeValues(String key) { return Collections.unmodifiableCollection(extraAttributes.get(key)); }
 
@@ -145,6 +149,7 @@ public class RequestLogEntry {
         private Principal userPrincipal;
         private HitCounts hitCounts;
         private TraceNode traceNode;
+        private Content content;
         private Principal sslPrincipal;
         private final Map<String, Collection<String>> extraAttributes = new HashMap<>();
 
@@ -171,6 +176,7 @@ public class RequestLogEntry {
         public Builder sslPrincipal(Principal sslPrincipal) { this.sslPrincipal = requireNonNull(sslPrincipal); return this; }
         public Builder hitCounts(HitCounts hitCounts) { this.hitCounts = requireNonNull(hitCounts); return this; }
         public Builder traceNode(TraceNode traceNode) { this.traceNode = requireNonNull(traceNode); return this; }
+        public Builder content(Content content) { this.content = requireNonNull(content); return this; }
         public Builder addExtraAttribute(String key, String value) {
             this.extraAttributes.computeIfAbsent(requireNonNull(key), __ -> new ArrayList<>()).add(requireNonNull(value));
             return this;
diff --git a/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/AccessLogRequestLog.java b/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/AccessLogRequestLog.java
index af1179fadba..6c071a162d1 100644
--- a/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/AccessLogRequestLog.java
+++ b/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/AccessLogRequestLog.java
@@ -117,6 +117,7 @@ class AccessLogRequestLog extends AbstractLifeCycle implements org.eclipse.jetty
                 }
                 addNonNullValue(builder, accessLogEntry.getHitCounts(), RequestLogEntry.Builder::hitCounts);
                 addNonNullValue(builder, accessLogEntry.getTrace(), RequestLogEntry.Builder::traceNode);
+                accessLogEntry.getContent().ifPresent(builder::content);
             }
             http2StreamId(request).ifPresent(streamId -> builder.addExtraAttribute("http2-stream-id", Integer.toString(streamId)));
 
diff --git a/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/AccessLoggingRequestHandler.java b/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/AccessLoggingRequestHandler.java
index 2c9cffa6786..dbf9138275b 100644
--- a/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/AccessLoggingRequestHandler.java
+++ b/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/AccessLoggingRequestHandler.java
@@ -1,18 +1,29 @@
 // Copyright Vespa.ai. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 package com.yahoo.jdisc.http.server.jetty;
 
-import com.google.common.base.Preconditions;
 import com.yahoo.container.logging.AccessLogEntry;
 import com.yahoo.jdisc.Request;
 import com.yahoo.jdisc.handler.AbstractRequestHandler;
+import com.yahoo.jdisc.handler.CompletionHandler;
 import com.yahoo.jdisc.handler.ContentChannel;
 import com.yahoo.jdisc.handler.DelegatedRequestHandler;
 import com.yahoo.jdisc.handler.RequestHandler;
 import com.yahoo.jdisc.handler.ResponseHandler;
+import com.yahoo.jdisc.http.HttpHeaders;
 import com.yahoo.jdisc.http.HttpRequest;
 
+import java.io.ByteArrayOutputStream;
+import java.nio.ByteBuffer;
+import java.util.List;
 import java.util.Map;
+import java.util.Objects;
 import java.util.Optional;
+import java.util.concurrent.atomic.AtomicLong;
+import java.util.function.Predicate;
+import java.util.regex.Pattern;
+import java.util.stream.Collectors;
+
+import static com.yahoo.jdisc.http.server.jetty.RequestUtils.getConnector;
 
 /**
  * A wrapper RequestHandler that enables access logging. By wrapping the request handler, we are able to wrap the
@@ -23,6 +34,7 @@ import java.util.Optional;
  * Does not otherwise interfere with the request processing of the delegate request handler.
  *
  * @author bakksjo
+ * @author bjorncs
  */
 public class AccessLoggingRequestHandler extends AbstractRequestHandler implements DelegatedRequestHandler {
     public static final String CONTEXT_KEY_ACCESS_LOG_ENTRY
@@ -38,27 +50,84 @@ public class AccessLoggingRequestHandler extends AbstractRequestHandler implemen
                 (AccessLogEntry) requestContextMap.get(CONTEXT_KEY_ACCESS_LOG_ENTRY));
     }
 
-    private final RequestHandler delegate;
+    private final org.eclipse.jetty.server.Request jettyRequest;
+    private final RequestHandler delegateRequestHandler;
     private final AccessLogEntry accessLogEntry;
+    private final Predicate<String> contentLoggingEnabledMatcher;
 
     public AccessLoggingRequestHandler(
-            final RequestHandler delegateRequestHandler,
-            final AccessLogEntry accessLogEntry) {
-        this.delegate = delegateRequestHandler;
+            org.eclipse.jetty.server.Request jettyRequest,
+            RequestHandler delegateRequestHandler,
+            AccessLogEntry accessLogEntry) {
+        this.jettyRequest = jettyRequest;
+        this.delegateRequestHandler = delegateRequestHandler;
         this.accessLogEntry = accessLogEntry;
+        var contentPathPrefixes = getConnector(jettyRequest).connectorConfig().accessLog().contentPathPrefixes();
+        this.contentLoggingEnabledMatcher = contentPathPrefixes.isEmpty()
+                ? __ -> false
+                : Pattern.compile(
+                        contentPathPrefixes.stream()
+                                .map(Pattern::quote)
+                                .collect(Collectors.joining("|", "^(", ")")))
+                .asMatchPredicate();
+
     }
 
     @Override
     public ContentChannel handleRequest(final Request request, final ResponseHandler handler) {
-        Preconditions.checkArgument(request instanceof HttpRequest, "Expected HttpRequest, got " + request);
         final HttpRequest httpRequest = (HttpRequest) request;
         httpRequest.context().put(CONTEXT_KEY_ACCESS_LOG_ENTRY, accessLogEntry);
-        return delegate.handleRequest(request, handler);
+        var acceptedMethods = List.of(HttpRequest.Method.POST, HttpRequest.Method.PUT, HttpRequest.Method.PATCH);
+        var originalContentChannel = delegateRequestHandler.handleRequest(request, handler);
+        if (acceptedMethods.contains(httpRequest.getMethod())
+                && contentLoggingEnabledMatcher.test(request.getUri().getPath())) {
+            return new ContentLoggingContentChannel(originalContentChannel);
+        } else {
+            return originalContentChannel;
+        }
     }
 
-
     @Override
     public RequestHandler getDelegate() {
-        return delegate;
+        return delegateRequestHandler;
+    }
+
+    private class ContentLoggingContentChannel implements ContentChannel {
+        private static final int CONTENT_LOGGING_MAX_SIZE = 16 * 1024 * 1024;
+
+        final AtomicLong length = new AtomicLong();
+        final ByteArrayOutputStream accumulatedRequestContent;
+        final ContentChannel originalContentChannel;
+
+        public ContentLoggingContentChannel(ContentChannel originalContentChannel) {
+            this.originalContentChannel = originalContentChannel;
+            var contentLength = jettyRequest.getContentLength();
+            this.accumulatedRequestContent = new ByteArrayOutputStream(contentLength == -1 ? 128 : contentLength);
+        }
+
+        @Override
+        public void write(ByteBuffer buf, CompletionHandler handler) {
+            length.addAndGet(buf.remaining());
+            var bytesToLog = Math.min(buf.remaining(), CONTENT_LOGGING_MAX_SIZE - accumulatedRequestContent.size());
+            if (bytesToLog > 0) accumulatedRequestContent.write(buf.array(), buf.arrayOffset() + buf.position(), bytesToLog);
+            if (originalContentChannel != null) originalContentChannel.write(buf, handler);
+        }
+
+        @Override
+        public void close(CompletionHandler handler) {
+            var bytes = accumulatedRequestContent.toByteArray();
+            accessLogEntry.setContent(new AccessLogEntry.Content(
+                    Objects.requireNonNullElse(jettyRequest.getHeader(HttpHeaders.Names.CONTENT_TYPE), ""),
+                    length.get(),
+                    bytes));
+            accumulatedRequestContent.reset();
+            length.set(0);
+            if (originalContentChannel != null) originalContentChannel.close(handler);
+        }
+
+        @Override
+        public void onError(Throwable error) {
+            if (originalContentChannel != null) originalContentChannel.onError(error);
+        }
     }
 }
diff --git a/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/HttpRequestDispatch.java b/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/HttpRequestDispatch.java
index 0b021ec8bcd..9d873f75516 100644
--- a/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/HttpRequestDispatch.java
+++ b/container-core/src/main/java/com/yahoo/jdisc/http/server/jetty/HttpRequestDispatch.java
@@ -214,7 +214,8 @@ class HttpRequestDispatch {
                 new FilteringRequestHandler(context.filterResolver(), (Request)servletRequest),
                 servletRequest, context.removeRawPostBodyForWwwUrlEncodedPost());
 
-        return new AccessLoggingRequestHandler(requestHandler, accessLogEntry);
+        return new AccessLoggingRequestHandler(
+                (Request) servletRequest, requestHandler, accessLogEntry);
     }
 
     private static RequestHandler wrapHandlerIfFormPost(RequestHandler requestHandler,
diff --git a/container-core/src/main/resources/configdefinitions/jdisc.http.jdisc.http.connector.def b/container-core/src/main/resources/configdefinitions/jdisc.http.jdisc.http.connector.def
index 2906f75a1f5..b11081cad92 100644
--- a/container-core/src/main/resources/configdefinitions/jdisc.http.jdisc.http.connector.def
+++ b/container-core/src/main/resources/configdefinitions/jdisc.http.jdisc.http.connector.def
@@ -154,3 +154,6 @@ accessLog.remoteAddressHeaders[]      string
 
 # HTTP request headers that contain remote port
 accessLog.remotePortHeaders[]         string
+
+# Path prefixes for which content should be logged
+accessLog.contentPathPrefixes[]  string
diff --git a/container-core/src/test/java/com/yahoo/jdisc/http/server/jetty/HttpServerTest.java b/container-core/src/test/java/com/yahoo/jdisc/http/server/jetty/HttpServerTest.java
index 73dfb85519c..ef1576b1ae8 100644
--- a/container-core/src/test/java/com/yahoo/jdisc/http/server/jetty/HttpServerTest.java
+++ b/container-core/src/test/java/com/yahoo/jdisc/http/server/jetty/HttpServerTest.java
@@ -82,6 +82,7 @@ import static com.yahoo.jdisc.http.server.jetty.SimpleHttpClient.ResponseValidat
 import static com.yahoo.jdisc.http.server.jetty.Utils.createHttp2Client;
 import static com.yahoo.jdisc.http.server.jetty.Utils.createSslTestDriver;
 import static com.yahoo.jdisc.http.server.jetty.Utils.generatePrivateKeyAndCertificate;
+import static java.nio.charset.StandardCharsets.UTF_8;
 import static org.hamcrest.CoreMatchers.containsString;
 import static org.hamcrest.CoreMatchers.is;
 import static org.hamcrest.CoreMatchers.startsWith;
@@ -742,12 +743,17 @@ public class HttpServerTest {
         JettyTestDriver driver = JettyTestDriver.newConfiguredInstance(
                 new EchoRequestHandler(),
                 new ServerConfig.Builder(),
-                new ConnectorConfig.Builder(),
+                new ConnectorConfig.Builder().accessLog(
+                        new ConnectorConfig.AccessLog.Builder()
+                                .contentPathPrefixes("/status.html")),
                 binder -> binder.bind(RequestLog.class).toInstance(requestLogMock));
         driver.client().newPost("/status.html").setContent("abcdef").execute().expectStatusCode(is(OK));
         RequestLogEntry entry = requestLogMock.poll(Duration.ofSeconds(5));
         assertEquals(200, entry.statusCode().getAsInt());
         assertEquals(6, entry.requestSize().getAsLong());
+        assertEquals("text/plain; charset=UTF-8", entry.content().get().type());
+        assertEquals(6, entry.content().get().length());
+        assertEquals("abcdef", new String(entry.content().get().body(), UTF_8));
         assertTrue(driver.close());
     }
 
@@ -894,7 +900,7 @@ public class HttpServerTest {
             final HttpRequest httpRequest = (HttpRequest)request;
             final String connectedAt = String.valueOf(httpRequest.getConnectedAt(TimeUnit.MILLISECONDS));
             final ContentChannel ch = handler.handleResponse(new Response(OK));
-            ch.write(ByteBuffer.wrap(connectedAt.getBytes(StandardCharsets.UTF_8)), null);
+            ch.write(ByteBuffer.wrap(connectedAt.getBytes(UTF_8)), null);
             ch.close(null);
             return null;
         }
@@ -924,7 +930,7 @@ public class HttpServerTest {
             List<Cookie> cookies = new ArrayList<>(((HttpRequest)request).decodeCookieHeader());
             cookies.sort(new CookieComparator());
             final ContentChannel out = ResponseDispatch.newInstance(Response.Status.OK).connect(handler);
-            out.write(StandardCharsets.UTF_8.encode(cookies.toString()), null);
+            out.write(UTF_8.encode(cookies.toString()), null);
             out.close(null);
             return null;
         }
@@ -938,7 +944,7 @@ public class HttpServerTest {
         public ContentChannel handleRequest(Request request, ResponseHandler handler) {
             Map<String, List<String>> parameters = new TreeMap<>(((HttpRequest)request).parameters());
             ContentChannel responseContentChannel = ResponseDispatch.newInstance(Response.Status.OK).connect(handler);
-            responseContentChannel.write(ByteBuffer.wrap(parameters.toString().getBytes(StandardCharsets.UTF_8)),
+            responseContentChannel.write(ByteBuffer.wrap(parameters.toString().getBytes(UTF_8)),
                                          NULL_COMPLETION_HANDLER);
 
             // Have the request content written back to the response.
@@ -1012,7 +1018,7 @@ public class HttpServerTest {
         @Override
         public ContentChannel handleRequest(Request req, ResponseHandler handler) {
             final ContentChannel ch = handler.handleResponse(new Response(OK));
-            ch.write(ByteBuffer.wrap(req.getUri().toString().getBytes(StandardCharsets.UTF_8)), null);
+            ch.write(ByteBuffer.wrap(req.getUri().toString().getBytes(UTF_8)), null);
             ch.close(null);
             return null;
         }