Clientcore - implement metrics support and report http request duration in instrumentation policy (Azure#43957)

* Add metrics

Author: Liudmila Molkova

sdk/clientcore/core/spotbugs-exclude.xml

@@ -226,7 +226,11 @@
   </Match>
   <Match>
     <Bug pattern="NP_NULL_PARAM_DEREF_ALL_TARGETS_DANGEROUS" />
-    <Class name="io.clientcore.core.serialization.json.contract.JsonWriterContractTests" />
+    <Or>
+      <Class name="io.clientcore.core.serialization.json.contract.JsonWriterContractTests" />
+      <Class name="io.clientcore.core.implementation.instrumentation.fallback.FallbackInstrumentationTests" />
+    </Or>
+
   </Match>
   <Match>
     <Bug pattern="NP_NULL_PARAM_DEREF_NONVIRTUAL" />

sdk/clientcore/core/src/main/java/io/clientcore/core/http/models/HttpInstrumentationOptions.java

@@ -250,6 +250,12 @@ public HttpInstrumentationOptions setTracingEnabled(boolean isTracingEnabled) {
         return this;
     }
 
+    @Override
+    public HttpInstrumentationOptions setMetricsEnabled(boolean isMetricsEnabled) {
+        super.setMetricsEnabled(isMetricsEnabled);
+        return this;
+    }
+
     @Override
     public HttpInstrumentationOptions setTelemetryProvider(Object telemetryProvider) {
         super.setTelemetryProvider(telemetryProvider);

sdk/clientcore/core/src/main/java/io/clientcore/core/http/pipeline/HttpInstrumentationPolicy.java

@@ -16,6 +16,8 @@
 import io.clientcore.core.instrumentation.Instrumentation;
 import io.clientcore.core.instrumentation.InstrumentationContext;
 import io.clientcore.core.instrumentation.LibraryInstrumentationOptions;
+import io.clientcore.core.instrumentation.metrics.DoubleHistogram;
+import io.clientcore.core.instrumentation.metrics.Meter;
 import io.clientcore.core.instrumentation.tracing.SpanBuilder;
 import io.clientcore.core.instrumentation.tracing.TracingScope;
 import io.clientcore.core.instrumentation.tracing.Span;
@@ -28,6 +30,7 @@
 import java.io.IOException;
 import java.io.InputStream;
 import java.util.Collections;
+import java.util.HashMap;
 import java.util.Locale;
 import java.util.Map;
 import java.util.Properties;
@@ -37,6 +40,7 @@
 import java.net.URI;
 
 import static io.clientcore.core.implementation.UrlRedactionUtil.getRedactedUri;
+import static io.clientcore.core.implementation.instrumentation.AttributeKeys.ERROR_TYPE_KEY;
 import static io.clientcore.core.implementation.instrumentation.AttributeKeys.HTTP_REQUEST_BODY_CONTENT_KEY;
 import static io.clientcore.core.implementation.instrumentation.AttributeKeys.HTTP_REQUEST_BODY_SIZE_KEY;
 import static io.clientcore.core.implementation.instrumentation.AttributeKeys.HTTP_REQUEST_DURATION_KEY;
@@ -76,7 +80,7 @@
  * so that it's executed in the scope of the span created by the {@link HttpInstrumentationPolicy}.
  *
  * <p><strong>Configure instrumentation policy:</strong></p>
- * <!-- src_embed io.clientcore.core.telemetry.tracing.instrumentationpolicy -->
+ * <!-- src_embed io.clientcore.core.instrumentation.instrumentationpolicy -->
  * <pre>
  *
  * HttpPipeline pipeline = new HttpPipelineBuilder&#40;&#41;
@@ -86,10 +90,10 @@
  *     .build&#40;&#41;;
  *
  * </pre>
- * <!-- end io.clientcore.core.telemetry.tracing.instrumentationpolicy -->
+ * <!-- end io.clientcore.core.instrumentation.instrumentationpolicy -->
  *
  * <p><strong>Customize instrumentation policy:</strong></p>
- * <!-- src_embed io.clientcore.core.telemetry.tracing.customizeinstrumentationpolicy -->
+ * <!-- src_embed io.clientcore.core.instrumentation.customizeinstrumentationpolicy -->
  * <pre>
  *
  * &#47;&#47; You can configure URL sanitization to include additional query parameters to preserve
@@ -104,10 +108,10 @@
  *     .build&#40;&#41;;
  *
  * </pre>
- * <!-- end io.clientcore.core.telemetry.tracing.customizeinstrumentationpolicy -->
+ * <!-- end io.clientcore.core.instrumentation.customizeinstrumentationpolicy -->
  *
  * <p><strong>Enrich HTTP spans with additional attributes:</strong></p>
- * <!-- src_embed io.clientcore.core.telemetry.tracing.enrichhttpspans -->
+ * <!-- src_embed io.clientcore.core.instrumentation.enrichhttpspans -->
  * <pre>
  *
  * HttpPipelinePolicy enrichingPolicy = &#40;request, next&#41; -&gt; &#123;
@@ -130,7 +134,7 @@
  *
  *
  * </pre>
- * <!-- end io.clientcore.core.telemetry.tracing.enrichhttpspans -->
+ * <!-- end io.clientcore.core.instrumentation.enrichhttpspans -->
  *
  */
 public final class HttpInstrumentationPolicy implements HttpPipelinePolicy {
@@ -160,13 +164,23 @@ public final class HttpInstrumentationPolicy implements HttpPipelinePolicy {
 
     private static final int MAX_BODY_LOG_SIZE = 1024 * 16;
     private static final String REDACTED_PLACEHOLDER = "REDACTED";
+    // HTTP request duration metric is formally defined in the OpenTelemetry Semantic Conventions:
+    // https://github.com/open-telemetry/semantic-conventions/blob/main/docs/http/http-metrics.md#metric-httpclientrequestduration
+    private static final String REQUEST_DURATION_METRIC_NAME = "http.client.request.duration";
+    private static final String REQUEST_DURATION_METRIC_DESCRIPTION = "Duration of HTTP client requests";
+    private static final String REQUEST_DURATION_METRIC_UNIT = "s";
 
     // request log level is low (verbose) since almost all request details are also
     // captured on the response log.
     private static final ClientLogger.LogLevel HTTP_REQUEST_LOG_LEVEL = ClientLogger.LogLevel.VERBOSE;
     private static final ClientLogger.LogLevel HTTP_RESPONSE_LOG_LEVEL = ClientLogger.LogLevel.INFORMATIONAL;
 
     private final Tracer tracer;
+    private final Meter meter;
+    private final boolean isTracingEnabled;
+    private final boolean isMetricsEnabled;
+    private final Instrumentation instrumentation;
+    private final DoubleHistogram httpRequestDuration;
     private final TraceContextPropagator traceContextPropagator;
     private final Set<String> allowedQueryParameterNames;
     private final Set<HttpHeaderName> allowedHeaderNames;
@@ -179,8 +193,11 @@ public final class HttpInstrumentationPolicy implements HttpPipelinePolicy {
      * @param instrumentationOptions Application telemetry options.
      */
     public HttpInstrumentationPolicy(HttpInstrumentationOptions instrumentationOptions) {
-        Instrumentation instrumentation = Instrumentation.create(instrumentationOptions, LIBRARY_OPTIONS);
-        this.tracer = instrumentation.getTracer();
+        this.instrumentation = Instrumentation.create(instrumentationOptions, LIBRARY_OPTIONS);
+        this.tracer = instrumentation.createTracer();
+        this.meter = instrumentation.createMeter();
+        this.httpRequestDuration = meter.createDoubleHistogram(REQUEST_DURATION_METRIC_NAME,
+            REQUEST_DURATION_METRIC_DESCRIPTION, REQUEST_DURATION_METRIC_UNIT);
         this.traceContextPropagator = instrumentation.getW3CTraceContextPropagator();
 
         HttpInstrumentationOptions optionsToUse
@@ -195,6 +212,9 @@ public HttpInstrumentationPolicy(HttpInstrumentationOptions instrumentationOptio
             .stream()
             .map(queryParamName -> queryParamName.toLowerCase(Locale.ROOT))
             .collect(Collectors.toSet());
+
+        this.isTracingEnabled = tracer.isEnabled();
+        this.isMetricsEnabled = meter.isEnabled();
     }
 
     /**
@@ -203,37 +223,38 @@ public HttpInstrumentationPolicy(HttpInstrumentationOptions instrumentationOptio
     @SuppressWarnings("try")
     @Override
     public Response<?> process(HttpRequest request, HttpPipelineNextPolicy next) {
-        boolean isTracingEnabled = tracer.isEnabled();
-        if (!isTracingEnabled && !isLoggingEnabled) {
+        if (!isTracingEnabled && !isLoggingEnabled && !isMetricsEnabled) {
             return next.process();
         }
 
         ClientLogger logger = getLogger(request);
         final long startNs = System.nanoTime();
-        String redactedUrl = getRedactedUri(request.getUri(), allowedQueryParameterNames);
-        int tryCount = HttpRequestAccessHelper.getTryCount(request);
+        final String redactedUrl = getRedactedUri(request.getUri(), allowedQueryParameterNames);
+        final int tryCount = HttpRequestAccessHelper.getTryCount(request);
         final long requestContentLength = getContentLength(logger, request.getBody(), request.getHeaders(), true);
 
-        InstrumentationContext instrumentationContext
-            = request.getRequestOptions() == null ? null : request.getRequestOptions().getInstrumentationContext();
-        Span span = Span.noop();
-        if (isTracingEnabled) {
-            if (request.getRequestOptions() == null || request.getRequestOptions() == RequestOptions.none()) {
-                request.setRequestOptions(new RequestOptions());
-            }
-
-            span = startHttpSpan(request, redactedUrl, instrumentationContext);
-            instrumentationContext = span.getInstrumentationContext();
-            request.getRequestOptions().setInstrumentationContext(instrumentationContext);
+        Map<String, Object> metricAttributes = isMetricsEnabled ? new HashMap<>(8) : null;
+        if (request.getRequestOptions() == null || request.getRequestOptions() == RequestOptions.none()) {
+            request.setRequestOptions(new RequestOptions());
         }
 
-        // even if tracing is disabled, we could have a valid context to propagate
-        // if it was provided by the application explicitly.
-        if (instrumentationContext != null && instrumentationContext.isValid()) {
-            traceContextPropagator.inject(instrumentationContext, request.getHeaders(), SETTER);
+        InstrumentationContext parentContext = request.getRequestOptions().getInstrumentationContext();
+
+        SpanBuilder spanBuilder = tracer.spanBuilder(request.getHttpMethod().toString(), CLIENT, parentContext);
+        setStartAttributes(request, redactedUrl, spanBuilder, metricAttributes);
+        Span span = spanBuilder.startSpan();
+
+        InstrumentationContext context
+            = span.getInstrumentationContext().isValid() ? span.getInstrumentationContext() : parentContext;
+
+        if (context != null && context.isValid()) {
+            request.getRequestOptions().setInstrumentationContext(context);
+            // even if tracing is disabled, we could have a valid context to propagate
+            // if it was provided by the application explicitly.
+            traceContextPropagator.inject(context, request.getHeaders(), SETTER);
         }
 
-        logRequest(logger, request, startNs, requestContentLength, redactedUrl, tryCount, instrumentationContext);
+        logRequest(logger, request, startNs, requestContentLength, redactedUrl, tryCount, context);
 
         try (TracingScope scope = span.makeCurrent()) {
             Response<?> response = next.process();
@@ -249,75 +270,114 @@ public Response<?> process(HttpRequest request, HttpPipelineNextPolicy next) {
                 return null;
             }
 
-            addDetails(request, response, tryCount, span);
-            response = logResponse(logger, response, startNs, requestContentLength, redactedUrl, tryCount,
-                instrumentationContext);
+            addDetails(request, response.getStatusCode(), tryCount, span, metricAttributes);
+            response = logResponse(logger, response, startNs, requestContentLength, redactedUrl, tryCount, context);
             span.end();
             return response;
         } catch (RuntimeException t) {
-            span.end(unwrap(t));
-            // TODO (limolkova) test otel scope still covers this
+            Throwable cause = unwrap(t);
+            if (metricAttributes != null) {
+                metricAttributes.put(ERROR_TYPE_KEY, cause.getClass().getCanonicalName());
+            }
+            span.end(cause);
             throw logException(logger, request, null, t, startNs, null, requestContentLength, redactedUrl, tryCount,
-                instrumentationContext);
+                context);
+        } finally {
+            if (isMetricsEnabled) {
+                httpRequestDuration.record((System.nanoTime() - startNs) / 1_000_000_000.0,
+                    instrumentation.createAttributes(metricAttributes), context);
+            }
         }
     }
 
-    private Span startHttpSpan(HttpRequest request, String sanitizedUrl, InstrumentationContext context) {
-        SpanBuilder spanBuilder = tracer.spanBuilder(request.getHttpMethod().toString(), CLIENT, context)
-            .setAttribute(HTTP_REQUEST_METHOD_KEY, request.getHttpMethod().toString())
-            .setAttribute(URL_FULL_KEY, sanitizedUrl)
-            .setAttribute(SERVER_ADDRESS_KEY, request.getUri().getHost());
-        maybeSetServerPort(spanBuilder, request.getUri());
-        return spanBuilder.startSpan();
+    private void setStartAttributes(HttpRequest request, String sanitizedUrl, SpanBuilder spanBuilder,
+        Map<String, Object> metricAttributes) {
+        if (!isTracingEnabled && !isMetricsEnabled) {
+            return;
+        }
+
+        int port = getServerPort(request.getUri());
+        if (isTracingEnabled) {
+            spanBuilder.setAttribute(HTTP_REQUEST_METHOD_KEY, request.getHttpMethod().toString())
+                .setAttribute(URL_FULL_KEY, sanitizedUrl)
+                .setAttribute(SERVER_ADDRESS_KEY, request.getUri().getHost());
+
+            if (port > 0) {
+                spanBuilder.setAttribute(SERVER_PORT_KEY, port);
+            }
+        }
+
+        if (isMetricsEnabled) {
+            metricAttributes.put(HTTP_REQUEST_METHOD_KEY, request.getHttpMethod().toString());
+            metricAttributes.put(SERVER_ADDRESS_KEY, request.getUri().getHost());
+            if (port > 0) {
+                metricAttributes.put(SERVER_PORT_KEY, port);
+            }
+        }
     }
 
     /**
      * Does the best effort to capture the server port with minimum perf overhead.
      * If port is not set, we check scheme for "http" and "https" (case-sensitive).
-     * If scheme is not one of those, we don't set the port.
+     * If scheme is not one of those, returns -1.
      *
-     * @param spanBuilder span builder
      * @param uri request URI
      */
-    private static void maybeSetServerPort(SpanBuilder spanBuilder, URI uri) {
+    private static int getServerPort(URI uri) {
         int port = uri.getPort();
-        if (port != -1) {
-            spanBuilder.setAttribute(SERVER_PORT_KEY, port);
-        } else {
+        if (port == -1) {
             switch (uri.getScheme()) {
                 case "http":
-                    spanBuilder.setAttribute(SERVER_PORT_KEY, 80);
-                    break;
+                    return 80;
 
                 case "https":
-                    spanBuilder.setAttribute(SERVER_PORT_KEY, 443);
-                    break;
+                    return 443;
 
                 default:
                     break;
             }
         }
+        return port;
     }
 
-    private void addDetails(HttpRequest request, Response<?> response, int tryCount, Span span) {
-        if (!span.isRecording()) {
+    private void addDetails(HttpRequest request, int statusCode, int tryCount, Span span,
+        Map<String, Object> metricAttributes) {
+        if (!span.isRecording() && !isMetricsEnabled) {
             return;
         }
 
-        span.setAttribute(HTTP_RESPONSE_STATUS_CODE_KEY, (long) response.getStatusCode());
-
-        if (tryCount > 0) {
-            span.setAttribute(HTTP_REQUEST_RESEND_COUNT_KEY, (long) tryCount);
+        String error = null;
+        if (statusCode >= 400) {
+            error = String.valueOf(statusCode);
         }
 
-        String userAgent = request.getHeaders().getValue(HttpHeaderName.USER_AGENT);
-        if (userAgent != null) {
-            span.setAttribute(USER_AGENT_ORIGINAL_KEY, userAgent);
+        if (span.isRecording()) {
+            span.setAttribute(HTTP_RESPONSE_STATUS_CODE_KEY, (long) statusCode);
+
+            if (tryCount > 0) {
+                span.setAttribute(HTTP_REQUEST_RESEND_COUNT_KEY, (long) tryCount);
+            }
+
+            String userAgent = request.getHeaders().getValue(HttpHeaderName.USER_AGENT);
+            if (userAgent != null) {
+                span.setAttribute(USER_AGENT_ORIGINAL_KEY, userAgent);
+            }
+
+            if (error != null) {
+                span.setError(error);
+            }
         }
 
-        if (response.getStatusCode() >= 400) {
-            span.setError(String.valueOf(response.getStatusCode()));
+        if (isMetricsEnabled) {
+            if (statusCode > 0) {
+                metricAttributes.put(HTTP_RESPONSE_STATUS_CODE_KEY, statusCode);
+            }
+
+            if (error != null) {
+                metricAttributes.put(ERROR_TYPE_KEY, error);
+            }
         }
+
         // TODO (lmolkova) url.template and experimental features
     }
 

sdk/clientcore/core/src/main/java/io/clientcore/core/implementation/instrumentation/NoopAttributes.java

@@ -0,0 +1,29 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+package io.clientcore.core.implementation.instrumentation;
+
+import io.clientcore.core.instrumentation.InstrumentationAttributes;
+
+import java.util.Objects;
+
+/**
+ * Noop implementation of {@link InstrumentationAttributes}.
+ */
+public final class NoopAttributes implements InstrumentationAttributes {
+    public static final NoopAttributes INSTANCE = new NoopAttributes();
+
+    /**
+     * {@inheritDoc}
+     */
+    @Override
+    public InstrumentationAttributes put(String key, Object value) {
+        Objects.requireNonNull(key, "'key' cannot be null.");
+        Objects.requireNonNull(value, "'value' cannot be null.");
+
+        return this;
+    }
+
+    private NoopAttributes() {
+    }
+}