Merge pull request #6326 from vespa-engine/bjorncs/new-jdisc-metrics

Bjorncs/new jdisc metrics

7 files changed, 97 insertions, 38 deletions

diff --git a/config-model/src/main/java/com/yahoo/vespa/model/admin/monitoring/VespaMetricSet.java b/config-model/src/main/java/com/yahoo/vespa/model/admin/monitoring/VespaMetricSet.java
index fd295d7bf5c..b7c9116dc60 100644
--- a/config-model/src/main/java/com/yahoo/vespa/model/admin/monitoring/VespaMetricSet.java
+++ b/config-model/src/main/java/com/yahoo/vespa/model/admin/monitoring/VespaMetricSet.java
@@ -122,6 +122,14 @@ public class VespaMetricSet {
 
         metrics.add(new Metric("athenz-tenant-cert.expiry.seconds.last", "athenz-tenant-cert.expiry.seconds"));
 
+        metrics.add(new Metric("jdisc.http.request.prematurely_closed.rate"));
+
+        metrics.add(new Metric("http.status.1xx.rate"));
+        metrics.add(new Metric("http.status.2xx.rate"));
+        metrics.add(new Metric("http.status.3xx.rate"));
+        metrics.add(new Metric("http.status.4xx.rate"));
+        metrics.add(new Metric("http.status.5xx.rate"));
+
         return metrics;
     }
 
@@ -189,11 +197,6 @@ public class VespaMetricSet {
         metrics.add(new Metric("error.result_with_errors.rate","error.result_with_errors"));
         metrics.add(new Metric("error.unspecified.rate","error.unspecified"));
         metrics.add(new Metric("error.unhandled_exception.rate","error.unhandled_exception"));
-        metrics.add(new Metric("http.status.1xx.rate"));
-        metrics.add(new Metric("http.status.2xx.rate"));
-        metrics.add(new Metric("http.status.3xx.rate"));
-        metrics.add(new Metric("http.status.4xx.rate"));
-        metrics.add(new Metric("http.status.5xx.rate"));
 
         return metrics;
     }
diff --git a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/HttpRequestDispatch.java b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/HttpRequestDispatch.java
index 31268c823ba..b780243bd19 100644
--- a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/HttpRequestDispatch.java
+++ b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/HttpRequestDispatch.java
@@ -2,7 +2,6 @@
 package com.yahoo.jdisc.http.server.jetty;
 
 import com.yahoo.container.logging.AccessLogEntry;
-import com.yahoo.jdisc.Metric.Context;
 import com.yahoo.jdisc.References;
 import com.yahoo.jdisc.ResourceReference;
 import com.yahoo.jdisc.Response;
@@ -14,6 +13,7 @@ import com.yahoo.jdisc.http.HttpHeaders;
 import com.yahoo.jdisc.http.HttpRequest;
 import org.eclipse.jetty.io.EofException;
 import org.eclipse.jetty.server.HttpConnection;
+import org.eclipse.jetty.server.Request;
 
 import javax.servlet.AsyncContext;
 import javax.servlet.ServletInputStream;
@@ -21,6 +21,7 @@ import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
 import java.io.IOException;
 import java.nio.charset.StandardCharsets;
+import java.util.Map;
 import java.util.concurrent.CompletableFuture;
 import java.util.concurrent.CompletionException;
 import java.util.concurrent.atomic.AtomicBoolean;
@@ -45,7 +46,7 @@ class HttpRequestDispatch {
 
     private final JDiscContext jDiscContext;
     private final AsyncContext async;
-    private final HttpServletRequest servletRequest;
+    private final Request jettyRequest;
 
     private final ServletResponseController servletResponseController;
     private final RequestHandler requestHandler;
@@ -53,16 +54,15 @@ class HttpRequestDispatch {
 
     public HttpRequestDispatch(JDiscContext jDiscContext,
                                AccessLogEntry accessLogEntry,
-                               Context metricContext,
+                               Map<String, Object> requestMetricDimensions,
                                HttpServletRequest servletRequest,
                                HttpServletResponse servletResponse) throws IOException {
         this.jDiscContext = jDiscContext;
 
         requestHandler = newRequestHandler(jDiscContext, accessLogEntry, servletRequest);
 
-        this.metricReporter = new MetricReporter(jDiscContext.metric, metricContext,
-                ((org.eclipse.jetty.server.Request) servletRequest).getTimeStamp());
-        this.servletRequest = servletRequest;
+        this.jettyRequest = (Request) servletRequest;
+        this.metricReporter = new MetricReporter(jDiscContext.metric, requestMetricDimensions, jettyRequest.getTimeStamp());
         honourMaxKeepAliveRequests();
         this.servletResponseController = new ServletResponseController(
                 servletRequest,
@@ -73,6 +73,7 @@ class HttpRequestDispatch {
 
         this.async = servletRequest.startAsync();
         async.setTimeout(0);
+        metricReporter.uriLength(jettyRequest.getOriginalURI().length());
     }
 
     public void dispatch() throws IOException {
@@ -102,7 +103,7 @@ class HttpRequestDispatch {
 
     private void honourMaxKeepAliveRequests() {
         if (jDiscContext.serverConfig.maxKeepAliveRequests() > 0) {
-            HttpConnection connection = getConnection(servletRequest);
+            HttpConnection connection = getConnection(jettyRequest);
             if (connection.getMessagesIn() >= jDiscContext.serverConfig.maxKeepAliveRequests()) {
                 connection.getGenerator().setPersistent(false);
             }
@@ -123,14 +124,16 @@ class HttpRequestDispatch {
             }
 
             boolean reportedError = false;
+            parent.metricReporter.contentSize((int) parent.jettyRequest.getContentRead());
 
             if (error != null) {
                 if (error instanceof CompletionException && error.getCause() instanceof EofException) {
                     log.log(Level.FINE,
                             error,
-                            () -> "Network connection was unexpectedly terminated: " + parent.servletRequest.getRequestURI());
+                            () -> "Network connection was unexpectedly terminated: " + parent.jettyRequest.getRequestURI());
+                    parent.metricReporter.prematurelyClosed();
                 } else if (!(error instanceof OverloadException || error instanceof BindingNotFoundException)) {
-                    log.log(Level.WARNING, "Request failed: " + parent.servletRequest.getRequestURI(), error);
+                    log.log(Level.WARNING, "Request failed: " + parent.jettyRequest.getRequestURI(), error);
                 }
                 reportedError = true;
                 parent.metricReporter.failedResponse();
@@ -140,7 +143,7 @@ class HttpRequestDispatch {
 
             try {
                 parent.async.complete();
-                log.finest(() -> "Request completed successfully: " + parent.servletRequest.getRequestURI());
+                log.finest(() -> "Request completed successfully: " + parent.jettyRequest.getRequestURI());
             } catch (Throwable throwable) {
                 Level level = reportedError ? Level.FINE: Level.WARNING;
                 log.log(level, "async.complete failed", throwable);
@@ -150,15 +153,18 @@ class HttpRequestDispatch {
 
     @SuppressWarnings("try")
     private ServletRequestReader handleRequest() throws IOException {
-        HttpRequest jdiscRequest = HttpRequestFactory.newJDiscRequest(jDiscContext.container, servletRequest);
+        HttpRequest jdiscRequest = HttpRequestFactory.newJDiscRequest(jDiscContext.container, jettyRequest);
         ContentChannel requestContentChannel;
 
         try (ResourceReference ref = References.fromResource(jdiscRequest)) {
-            HttpRequestFactory.copyHeaders(servletRequest, jdiscRequest);
+            HttpRequestFactory.copyHeaders(jettyRequest, jdiscRequest);
             requestContentChannel = requestHandler.handleRequest(jdiscRequest, servletResponseController.responseHandler);
+            // Note: The matched binding is only available after FilteringRequestHandler has called resolveHandler() on the current Container instance.
+            //       resolveHandler() will assigned the matched binding on the Request object.
+            metricReporter.setBindingMatch(jdiscRequest.getBindingMatch());
         }
 
-        ServletInputStream servletInputStream = servletRequest.getInputStream();
+        ServletInputStream servletInputStream = jettyRequest.getInputStream();
 
         ServletRequestReader servletRequestReader =
                 new ServletRequestReader(
@@ -181,7 +187,7 @@ class HttpRequestDispatch {
 
     ContentChannel handleRequestFilterResponse(Response response) {
         try {
-            servletRequest.getInputStream().close();
+            jettyRequest.getInputStream().close();
             ContentChannel responseContentChannel = servletResponseController.responseHandler.handleResponse(response);
             servletResponseController.finishedFuture().whenComplete(completeRequestCallback);
             return responseContentChannel;
diff --git a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscFilterInvokerFilter.java b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscFilterInvokerFilter.java
index 7227d21e7a2..7b4bdc3fc8d 100644
--- a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscFilterInvokerFilter.java
+++ b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscFilterInvokerFilter.java
@@ -127,7 +127,7 @@ class JDiscFilterInvokerFilter implements Filter {
             final AccessLogEntry accessLogEntry = null; // Not used in this context.
             return new HttpRequestDispatch(jDiscContext,
                                            accessLogEntry,
-                                           getConnector(request).getMetricContext(),
+                                           getConnector(request).getRequestMetricDimensions(request),
                                            request, response);
         } catch (IOException e) {
             throw throwUnchecked(e);
diff --git a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscHttpServlet.java b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscHttpServlet.java
index 27f72c7b4bf..3b81dd94e11 100644
--- a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscHttpServlet.java
+++ b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscHttpServlet.java
@@ -6,7 +6,6 @@ import com.yahoo.jdisc.Metric;
 import com.yahoo.jdisc.handler.OverloadException;
 
 import javax.servlet.ServletException;
-import javax.servlet.ServletRequest;
 import javax.servlet.annotation.WebServlet;
 import javax.servlet.http.HttpServlet;
 import javax.servlet.http.HttpServletRequest;
@@ -15,6 +14,7 @@ import java.io.IOException;
 import java.util.Arrays;
 import java.util.Enumeration;
 import java.util.HashSet;
+import java.util.Map;
 import java.util.Set;
 import java.util.logging.Level;
 import java.util.logging.Logger;
@@ -91,7 +91,7 @@ class JDiscHttpServlet extends HttpServlet {
             throws ServletException, IOException {
         request.setAttribute(JDiscServerConnector.REQUEST_ATTRIBUTE, getConnector(request));
 
-        Metric.Context metricContext = getMetricContext(request);
+        Metric.Context metricContext = context.metric.createContext(getRequestMetricDimensions(request));
         context.metric.add(JettyHttpServer.Metrics.NUM_REQUESTS, 1, metricContext);
         context.metric.add(JettyHttpServer.Metrics.JDISC_HTTP_REQUESTS, 1, metricContext);
         context.metric.add(JettyHttpServer.Metrics.MANHATTAN_NUM_REQUESTS, 1, metricContext);
@@ -114,7 +114,7 @@ class JDiscHttpServlet extends HttpServlet {
         try {
             switch (request.getDispatcherType()) {
                 case REQUEST:
-                    new HttpRequestDispatch(context, accessLogEntry, getMetricContext(request), request, response)
+                    new HttpRequestDispatch(context, accessLogEntry, getRequestMetricDimensions(request), request, response)
                             .dispatch();
                     break;
                 default:
@@ -130,8 +130,8 @@ class JDiscHttpServlet extends HttpServlet {
         }
     }
 
-    private static Metric.Context getMetricContext(ServletRequest request) {
-        return JDiscServerConnector.fromRequest(request).getMetricContext();
+    private static Map<String, Object> getRequestMetricDimensions(HttpServletRequest request) {
+        return JDiscServerConnector.fromRequest(request).getRequestMetricDimensions(request);
     }
 
     private static String formatAttributes(final HttpServletRequest request) {
diff --git a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscServerConnector.java b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscServerConnector.java
index 8dd50074c32..118079a2fba 100644
--- a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscServerConnector.java
+++ b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JDiscServerConnector.java
@@ -9,11 +9,13 @@ import org.eclipse.jetty.server.ServerConnectionStatistics;
 import org.eclipse.jetty.server.ServerConnector;
 
 import javax.servlet.ServletRequest;
+import javax.servlet.http.HttpServletRequest;
 import java.io.IOException;
 import java.lang.reflect.Field;
 import java.net.Socket;
 import java.net.SocketException;
 import java.nio.channels.ServerSocketChannel;
+import java.util.HashMap;
 import java.util.Map;
 import java.util.TreeMap;
 import java.util.logging.Level;
@@ -30,6 +32,9 @@ class JDiscServerConnector extends ServerConnector {
     private final boolean tcpKeepAlive;
     private final boolean tcpNoDelay;
     private final ServerSocketChannel channelOpenedByActivator;
+    private final Metric metric;
+    private final String connectorName;
+    private final int listenPort;
 
     JDiscServerConnector(ConnectorConfig config, Metric metric, Server server,
                          ServerSocketChannel channelOpenedByActivator, ConnectionFactory... factories) {
@@ -38,6 +43,9 @@ class JDiscServerConnector extends ServerConnector {
         this.tcpKeepAlive = config.tcpKeepAliveEnabled();
         this.tcpNoDelay = config.tcpNoDelay();
         this.metricCtx = createMetricContext(config, metric);
+        this.metric = metric;
+        this.connectorName = config.name();
+        this.listenPort = config.listenPort();
 
         this.statistics = new ServerConnectionStatistics();
         addBean(statistics);
@@ -112,11 +120,20 @@ class JDiscServerConnector extends ServerConnector {
         return statistics;
     }
 
-    public Metric.Context getMetricContext() {
+    public Metric.Context getConnectorMetricContext() {
         return metricCtx;
     }
 
+    public Map<String, Object> getRequestMetricDimensions(HttpServletRequest request) {
+        Map<String, Object> props = new HashMap<>();
+        props.put(JettyHttpServer.Metrics.NAME_DIMENSION, connectorName);
+        props.put(JettyHttpServer.Metrics.PORT_DIMENSION, listenPort);
+        props.put(JettyHttpServer.Metrics.METHOD_DIMENSION, request.getMethod());
+        return props;
+    }
+
     public static JDiscServerConnector fromRequest(ServletRequest request) {
         return (JDiscServerConnector) request.getAttribute(REQUEST_ATTRIBUTE);
     }
+
 }
diff --git a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JettyHttpServer.java b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JettyHttpServer.java
index c85917c4c7e..24367863fbc 100644
--- a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JettyHttpServer.java
+++ b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/JettyHttpServer.java
@@ -66,12 +66,15 @@ public class JettyHttpServer extends AbstractServerProvider {
     public interface Metrics {
         String NAME_DIMENSION = "serverName";
         String PORT_DIMENSION = "serverPort";
+        String METHOD_DIMENSION = "httpMethod";
+        String HANDLER_DIMENSION = "handler";
 
         String NUM_OPEN_CONNECTIONS = "serverNumOpenConnections";
         String NUM_CONNECTIONS_OPEN_MAX = "serverConnectionsOpenMax";
         String CONNECTION_DURATION_MAX = "serverConnectionDurationMax";
         String CONNECTION_DURATION_MEAN = "serverConnectionDurationMean";
         String CONNECTION_DURATION_STD_DEV = "serverConnectionDurationStdDev";
+        String NUM_PREMATURELY_CLOSED_CONNECTIONS = "jdisc.http.request.prematurely_closed";
 
         String NUM_BYTES_RECEIVED = "serverBytesReceived";
         String NUM_BYTES_SENT     = "serverBytesSent";
@@ -104,6 +107,9 @@ public class JettyHttpServer extends AbstractServerProvider {
 
         String STARTED_MILLIS = "serverStartedMillis";
         @Deprecated String MANHATTAN_STARTED_MILLIS = "proc.uptime";
+
+        String URI_LENGTH = "jdisc.http.request.uri_length";
+        String CONTENT_SIZE = "jdisc.http.request.content_size";
     }
 
     private final static Logger log = Logger.getLogger(JettyHttpServer.class.getName());
@@ -346,12 +352,12 @@ public class JettyHttpServer extends AbstractServerProvider {
 
     private void setConnectorMetrics(JDiscServerConnector connector) {
         ServerConnectionStatistics statistics = connector.getStatistics();
-        metric.set(Metrics.NUM_CONNECTIONS, statistics.getConnectionsTotal(), connector.getMetricContext());
-        metric.set(Metrics.NUM_OPEN_CONNECTIONS, statistics.getConnections(), connector.getMetricContext());
-        metric.set(Metrics.NUM_CONNECTIONS_OPEN_MAX, statistics.getConnectionsMax(), connector.getMetricContext());
-        metric.set(Metrics.CONNECTION_DURATION_MAX, statistics.getConnectionDurationMax(), connector.getMetricContext());
-        metric.set(Metrics.CONNECTION_DURATION_MEAN, statistics.getConnectionDurationMean(), connector.getMetricContext());
-        metric.set(Metrics.CONNECTION_DURATION_STD_DEV, statistics.getConnectionDurationStdDev(), connector.getMetricContext());
+        metric.set(Metrics.NUM_CONNECTIONS, statistics.getConnectionsTotal(), connector.getConnectorMetricContext());
+        metric.set(Metrics.NUM_OPEN_CONNECTIONS, statistics.getConnections(), connector.getConnectorMetricContext());
+        metric.set(Metrics.NUM_CONNECTIONS_OPEN_MAX, statistics.getConnectionsMax(), connector.getConnectorMetricContext());
+        metric.set(Metrics.CONNECTION_DURATION_MAX, statistics.getConnectionDurationMax(), connector.getConnectorMetricContext());
+        metric.set(Metrics.CONNECTION_DURATION_MEAN, statistics.getConnectionDurationMean(), connector.getConnectorMetricContext());
+        metric.set(Metrics.CONNECTION_DURATION_STD_DEV, statistics.getConnectionDurationStdDev(), connector.getConnectorMetricContext());
     }
 
     private StatisticsHandler newStatisticsHandler() {
diff --git a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/MetricReporter.java b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/MetricReporter.java
index 2824ca66c29..00b8b262000 100644
--- a/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/MetricReporter.java
+++ b/jdisc_http_service/src/main/java/com/yahoo/jdisc/http/server/jetty/MetricReporter.java
@@ -3,20 +3,25 @@ package com.yahoo.jdisc.http.server.jetty;
 
 import com.yahoo.jdisc.Metric;
 import com.yahoo.jdisc.Metric.Context;
-
+import com.yahoo.jdisc.application.BindingMatch;
+import com.yahoo.jdisc.application.UriPattern;
+import com.yahoo.jdisc.handler.RequestHandler;
 import com.yahoo.jdisc.http.server.jetty.JettyHttpServer.Metrics;
-import org.jetbrains.annotations.Nullable;
 
+import java.util.HashMap;
+import java.util.Map;
 import java.util.concurrent.atomic.AtomicBoolean;
 
 
 /**
  * Responsible for metric reporting for JDisc http request handler support.
- * @author tonytv
+ *
+ * @author Tony Vaagenes
  */
 public class MetricReporter {
     private final Metric metric;
-    private final @Nullable Context context;
+    private volatile Context context;
+    private final Map<String, Object> requestDimensions;
 
     private final long requestStartTime;
 
@@ -24,12 +29,22 @@ public class MetricReporter {
     private final AtomicBoolean firstSetOfTimeToFirstByte = new AtomicBoolean(true);
 
 
-    public MetricReporter(Metric metric, @Nullable Context context, long requestStartTime) {
+    public MetricReporter(Metric metric, Map<String, Object> requestDimensions, long requestStartTime) {
         this.metric = metric;
-        this.context = context;
+        this.context = metric.createContext(requestDimensions);
+        this.requestDimensions = requestDimensions;
         this.requestStartTime = requestStartTime;
     }
 
+    public void setBindingMatch(BindingMatch<?> bindingMatch) {
+        if (bindingMatch == null) return;
+        UriPattern pattern = bindingMatch.matched();
+        if (pattern == null) return;
+        Map<String, Object> combinedDimensions = new HashMap<>(requestDimensions);
+        combinedDimensions.put(Metrics.HANDLER_DIMENSION, bindingMatch.toString());
+        this.context = metric.createContext(combinedDimensions);
+    }
+
     @SuppressWarnings("deprecation")
     public void successfulWrite(int numBytes) {
         setTimeToFirstByteFirstTime();
@@ -72,6 +87,10 @@ public class MetricReporter {
         metric.add(Metrics.NUM_FAILED_RESPONSES, 1, context);
     }
 
+    public void prematurelyClosed() {
+        metric.add(Metrics.NUM_PREMATURELY_CLOSED_CONNECTIONS, 1, context);
+    }
+
     @SuppressWarnings("deprecation")
     public void successfulRead(int bytes_received) {
         metric.set(JettyHttpServer.Metrics.NUM_BYTES_RECEIVED, bytes_received, context);
@@ -81,4 +100,12 @@ public class MetricReporter {
     private long getRequestLatency() {
         return System.currentTimeMillis() - requestStartTime;
     }
+
+    public void uriLength(int length) {
+        metric.set(Metrics.URI_LENGTH, length, context);
+    }
+
+    public void contentSize(int size) {
+        metric.set(Metrics.CONTENT_SIZE, size, context);
+    }
 }