Improve logging; add doc about logging

helidon-io · Nov 27, 2024 · ed81654 · ed81654
1 parent c4ababf
commit ed81654
Show file tree

Hide file tree

Showing 2 changed files with 47 additions and 11 deletions.
diff --git a/docs/src/main/asciidoc/mp/restclient/restclientmetrics.adoc b/docs/src/main/asciidoc/mp/restclient/restclientmetrics.adoc
@@ -82,6 +82,13 @@ Helidon _does not_ provide a `/metrics` endpoint for standalone clients, nor doe
 
 In contrast, when REST clients run inside Helidon servers the REST client metrics for REST clients known to Helidon appear in the `/metrics` output.
 
+=== Turning on Logging
+Set `io.helidon.microprofile.restclientmetrics.level=DEBUG` in your logging settings to see some of the inner workings of the REST client metrics implementation.
+
+During start-up the logging reports analysis of candidate REST client interfaces and the creation of metric registration entries, including the metric annotation and where Helidon found each.
+
+When a REST client is made known to Helidon the logging reports the actual registration of the metrics derived from that REST client interface.
+
 == API
 Use the following annotations from  `org.eclipse.microprofile.metrics.annotation`  listed in the following table to trigger REST client metrics.
 [cols="1,2"]

diff --git a/...rc/main/java/io/helidon/microprofile/restclientmetrics/RestClientMetricsCdiExtension.java b/...rc/main/java/io/helidon/microprofile/restclientmetrics/RestClientMetricsCdiExtension.java
@@ -19,12 +19,14 @@
 import java.lang.reflect.Method;
 import java.time.Duration;
 import java.util.ArrayList;
+import java.util.Arrays;
 import java.util.HashMap;
 import java.util.HashSet;
 import java.util.List;
 import java.util.Map;
 import java.util.Objects;
 import java.util.Set;
+import java.util.StringJoiner;
 import java.util.function.Consumer;
 import java.util.function.Function;
 import java.util.stream.Collectors;
@@ -160,7 +162,7 @@ void prepareMetricRegistrations(@Observes AfterBeanDiscovery abd) {
                                                     "Examining type " + annotatedTypeInClosure.getJavaClass()
                                                             .getCanonicalName());
 
-                                          annotatedTypeInClosure.getMethods().stream()
+                                         annotatedTypeInClosure.getMethods().stream()
                                                  .filter(RestClientMetricsCdiExtension::hasRestAnnotation)
                                                  .forEach(annotatedMethod -> {
                                                      // Record registrations needed for this method based on
@@ -225,9 +227,10 @@ void registerMetricsForRestClient(Class<?> restClient) {
                 Metric metric = registration.registrationOp.apply(metricRegistry);
                 if (LOGGER.isLoggable(DEBUG)) {
                     metricsRegisteredForRestClient.add(metric);
-                    LOGGER.log(DEBUG, String.format("For REST client method %s#%s registered metric %s",
+                    LOGGER.log(DEBUG, String.format("For REST client method %s#%s registering metric using %s",
                                                     restClient.getCanonicalName(),
                                                     method.getName(),
+                                                    registration,
                                                     metric));
                 }
                 metricsUpdateWorkByMethod.computeIfAbsent(method, k -> new ArrayList<>())
@@ -259,6 +262,14 @@ Map<Method, List<MetricsUpdateWork>> metricsUpdateWorkByMethod() {
         return metricsUpdateWorkByMethod;
     }
 
+    private static Tag[] tags(Annotation metricAnnotation) {
+        return switch (metricAnnotation) {
+            case Counted counted -> tags(counted.tags());
+            case Timed timed -> tags(timed.tags());
+            default -> null;
+        };
+    }
+
     /**
      * Converts tag expressions in a metrics annotation to an array of {@link org.eclipse.microprofile.metrics.Tag} for use
      * during metric registration.
@@ -342,11 +353,11 @@ static MetricsUpdateWork create(Metric metric) {
             return switch (metric) {
                 case Timer timer -> MetricsUpdateWork.create(cctx -> cctx.setProperty(SAVED_START_TIME_PROPERTY_NAME,
                                                                                       System.nanoTime()),
-                                                      cctx -> {
-                                                          long startTime =
-                                                                  (Long) cctx.getProperty(SAVED_START_TIME_PROPERTY_NAME);
-                                                          timer.update(Duration.ofNanos(System.nanoTime() - startTime));
-                                                      });
+                                                             cctx -> {
+                                                                 long startTime =
+                                                                         (Long) cctx.getProperty(SAVED_START_TIME_PROPERTY_NAME);
+                                                                 timer.update(Duration.ofNanos(System.nanoTime() - startTime));
+                                                             });
                 case Counter counter -> MetricsUpdateWork.create(cctx -> counter.inc());
                 default -> null;
             };
@@ -381,6 +392,8 @@ private static MetricsUpdateWork create(Consumer<ClientRequestContext> preWork)
      * @param registrationOp   function to register the new metric in a metric registry
      */
     private record Registration(String metricName,
+                                Tag[] tags,
+                                Metadata metadata,
                                 Annotation metricAnnotation,
                                 Function<MetricRegistry, ? extends Metric> registrationOp) {
 
@@ -400,13 +413,29 @@ static Registration create(Class<?> declaringType,
                                              + method.getJavaMember().getName())
                     .build();
 
+            Tag[] tagsFromAnnotation = RestClientMetricsCdiExtension.tags(metricAnnotation);
             return switch (metricAnnotation) {
-                case Timed timed ->
-                        new Registration(metadata.getName(), metricAnnotation, mr -> mr.timer(metadata, tags(timed.tags())));
-                case Counted counted ->
-                        new Registration(metadata.getName(), metricAnnotation, mr -> mr.counter(metadata, tags(counted.tags())));
+                case Timed timed -> new Registration(metadata.getName(),
+                                                      tagsFromAnnotation,
+                                                      metadata,
+                                                      timed,
+                                                      mr -> mr.timer(metadata, tagsFromAnnotation));
+                case Counted counted -> new Registration(metadata.getName(),
+                                                        tagsFromAnnotation,
+                                                        metadata,
+                                                        counted,
+                                                        mr -> mr.counter(metadata, tagsFromAnnotation));
                 default -> null;
             };
         }
+
+        @Override
+        public String toString() {
+            return new StringJoiner(", ", Registration.class.getSimpleName() + "[", "]")
+                    .add("metadata=" + metadata)
+                    .add("tags=" + Arrays.toString(tags))
+                    .add("metricAnnotation=" + metricAnnotation)
+                    .toString();
+        }
     }
 }