Add tls handshake duration metric field at MetricCollectingClient

line · May 6, 2024 · e2027e2 · e2027e2
1 parent 4c93a40
commit e2027e2
Show file tree

Hide file tree

Showing 3 changed files with 51 additions and 30 deletions.
diff --git a/core/src/main/java/com/linecorp/armeria/common/logging/ClientConnectionTimings.java b/core/src/main/java/com/linecorp/armeria/common/logging/ClientConnectionTimings.java
@@ -93,36 +93,6 @@ public long connectionAcquisitionDurationNanos() {
         return connectionAcquisitionDurationNanos;
     }
 
-    /**
-     * Returns the time when the client started to TLS handshake, in microseconds since the epoch.
-     *
-     * @return the start time, or {@code -1} if there was no action to TLS handshake.
-     */
-    public long tlsHandshakeStartTimeMicros() {
-        return tlsHandshakeStartTimeMicros;
-    }
-
-    /**
-     * Returns the time when the client started to TLS handshake, in milliseconds since the epoch.
-     *
-     * @return the start time, or {@code -1} if there was no action to TLS handshake.
-     */
-    public long tlsHandshakeStartTimeMillis() {
-        if (tlsHandshakeStartTimeMicros >= 0) {
-            return TimeUnit.MICROSECONDS.toMillis(tlsHandshakeStartTimeMicros);
-        }
-        return -1;
-    }
-
-    /**
-     * Returns the duration which was taken to TLS handshake, in nanoseconds.
-     *
-     * @return the duration, or {@code -1} if there was no action to TLS handshake.
-     */
-    public long tlsHandshakeDurationNanos() {
-        return tlsHandshakeDurationNanos;
-    }
-
     /**
      * Returns the time when the client started to resolve a domain name, in microseconds since the epoch.
      *
@@ -183,6 +153,36 @@ public long socketConnectDurationNanos() {
         return socketConnectDurationNanos;
     }
 
+    /**
+     * Returns the time when the client started to TLS handshake, in microseconds since the epoch.
+     *
+     * @return the start time, or {@code -1} if there was no action to TLS handshake.
+     */
+    public long tlsHandshakeStartTimeMicros() {
+        return tlsHandshakeStartTimeMicros;
+    }
+
+    /**
+     * Returns the time when the client started to TLS handshake, in milliseconds since the epoch.
+     *
+     * @return the start time, or {@code -1} if there was no action to TLS handshake.
+     */
+    public long tlsHandshakeStartTimeMillis() {
+        if (tlsHandshakeStartTimeMicros >= 0) {
+            return TimeUnit.MICROSECONDS.toMillis(tlsHandshakeStartTimeMicros);
+        }
+        return -1;
+    }
+
+    /**
+     * Returns the duration which was taken to TLS handshake, in nanoseconds.
+     *
+     * @return the duration, or {@code -1} if there was no action to TLS handshake.
+     */
+    public long tlsHandshakeDurationNanos() {
+        return tlsHandshakeDurationNanos;
+    }
+
     /**
      * Returns the time when the client started to wait for the completion of an existing connection attempt,
      * in microseconds since the epoch.

diff --git a/core/src/main/java/com/linecorp/armeria/internal/common/metric/RequestMetricSupport.java b/core/src/main/java/com/linecorp/armeria/internal/common/metric/RequestMetricSupport.java
@@ -126,6 +126,10 @@ private static void onResponse(
             if (socketConnectDurationNanos >= 0) {
                 metrics.socketConnectDuration().record(socketConnectDurationNanos, TimeUnit.NANOSECONDS);
             }
+            final long tlsHandshakeDurationNanos = timings.tlsHandshakeDurationNanos();
+            if (tlsHandshakeDurationNanos >= 0) {
+                metrics.tlsHandshakeDuration().record(tlsHandshakeDurationNanos, TimeUnit.NANOSECONDS);
+            }
             final long pendingAcquisitionDurationNanos = timings.pendingAcquisitionDurationNanos();
             if (pendingAcquisitionDurationNanos >= 0) {
                 metrics.pendingAcquisitionDuration().record(pendingAcquisitionDurationNanos,
@@ -204,6 +208,8 @@ private interface ClientRequestMetrics extends RequestMetrics {
 
         Timer socketConnectDuration();
 
+        Timer tlsHandshakeDuration();
+
         Timer pendingAcquisitionDuration();
 
         Counter writeTimeouts();
@@ -299,6 +305,7 @@ private static class DefaultClientRequestMetrics
         private final Timer connectionAcquisitionDuration;
         private final Timer dnsResolutionDuration;
         private final Timer socketConnectDuration;
+        private final Timer tlsHandshakeDuration;
         private final Timer pendingAcquisitionDuration;
 
         private final Counter writeTimeouts;
@@ -328,6 +335,9 @@ private static class DefaultClientRequestMetrics
             socketConnectDuration = newTimer(
                     parent, idPrefix.name("socket.connect.duration"), idPrefix.tags(),
                     distributionStatisticConfig);
+            tlsHandshakeDuration = newTimer(
+                    parent, idPrefix.name("tls.handshake.duration"), idPrefix.tags(),
+                    distributionStatisticConfig);
             pendingAcquisitionDuration = newTimer(
                     parent, idPrefix.name("pending.acquisition.duration"), idPrefix.tags(),
                     distributionStatisticConfig);
@@ -360,6 +370,11 @@ public Timer socketConnectDuration() {
             return socketConnectDuration;
         }
 
+        @Override
+        public Timer tlsHandshakeDuration() {
+            return tlsHandshakeDuration;
+        }
+
         @Override
         public Timer pendingAcquisitionDuration() {
             return pendingAcquisitionDuration;

diff --git a/core/src/test/java/com/linecorp/armeria/internal/common/metric/RequestMetricSupportTest.java b/core/src/test/java/com/linecorp/armeria/internal/common/metric/RequestMetricSupportTest.java
@@ -83,6 +83,8 @@ void httpSuccess() {
                                "service=FooService}", 1.0)
                 .containsEntry("foo.socket.connect.duration#count{http.status=200,method=POST," +
                                "service=FooService}", 1.0)
+                .containsEntry("foo.tls.handshake.duration#count{http.status=200,method=POST," +
+                               "service=FooService}", 1.0)
                 .containsEntry("foo.pending.acquisition.duration#count{http.status=200,method=POST," +
                                "service=FooService}", 1.0)
                 .containsEntry("foo.request.length#count{http.status=200,method=POST," +
@@ -107,6 +109,8 @@ private static ClientConnectionTimings newConnectionTimings() {
                                       .dnsResolutionEnd()
                                       .socketConnectStart()
                                       .socketConnectEnd()
+                                      .tlsHandshakeStart()
+                                      .tlsHandshakeEnd()
                                       .pendingAcquisitionStart()
                                       .pendingAcquisitionEnd()
                                       .build();
@@ -166,6 +170,8 @@ void actualRequestsIncreasedWhenRetrying() {
                                1.0)
                 .containsEntry("foo.socket.connect.duration#count{http.status=500,method=POST,service=none}",
                                1.0)
+                .containsEntry("foo.tls.handshake.duration#count{http.status=500,method=POST,service=none}",
+                               1.0)
                 .containsEntry("foo.pending.acquisition.duration#count{http.status=500,method=POST," +
                                "service=none}", 1.0)
                 .containsEntry("foo.request.length#count{http.status=500,method=POST,service=none}", 1.0)