Merge pull request #31438 from vespa-engine/bjorncs/content-in-access-log

Bjorncs/content in access log

6 files changed, 126 insertions, 11 deletions

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..3b1db55defd 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,34 @@
 // 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.Random;
+import java.util.TreeMap;
+import java.util.concurrent.atomic.AtomicLong;
+import java.util.function.Function;
+import java.util.function.Predicate;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
+import java.util.stream.Collectors;
+import java.util.stream.IntStream;
+
+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 +39,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 +55,94 @@ 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 List<String> pathPrefixes;
+    private final List<Double> samplingRate;
+    private final Random rng = new Random();
 
     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.pathPrefixes = contentPathPrefixes.stream()
+                .map(s -> {
+                    var separatorIndex = s.lastIndexOf(':');
+                    return s.substring(0, separatorIndex == -1 ? s.length() : separatorIndex);
+                })
+                .toList();
+        this.samplingRate = contentPathPrefixes.stream()
+                .map(s -> {
+                    return Double.parseDouble(s.substring(s.lastIndexOf(':') + 1));
+                })
+                .toList();
     }
 
     @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 methodsWithEntity = List.of(HttpRequest.Method.POST, HttpRequest.Method.PUT, HttpRequest.Method.PATCH);
+        var originalContentChannel = delegateRequestHandler.handleRequest(request, handler);
+        var uriPath = request.getUri().getPath();
+        if (methodsWithEntity.contains(httpRequest.getMethod())) {
+            for (int i = 0; i < pathPrefixes.size(); i++) {
+                if (uriPath.startsWith(pathPrefixes.get(i))) {
+                    if (samplingRate.get(i) > rng.nextDouble()) {
+                        return new ContentLoggingContentChannel(originalContentChannel);
+                    }
+                }
+            }
+        }
+        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,