Add HTTP Server and Client duration Metrics in HTTP Node.js Instrumentation

experimental/CHANGELOG.md

@@ -8,6 +8,7 @@ All notable changes to experimental packages in this project will be documented
 
 ### :rocket: (Enhancement)
 
+* feature(instrumentation-http): Add HTTP Server and Client duration Metrics in HTTP Node.js Instrumentation [#3149](https://github.com/open-telemetry/opentelemetry-js/pull/3149) @hectorhdzg
 * feature(prometheus-serialiser): export the unit block when unit is set in metric descriptor [#3066](https://github.com/open-telemetry/opentelemetry-js/pull/3041) @weyert
 
 ### :bug: (Bug Fix)

experimental/packages/opentelemetry-instrumentation-http/package.json

@@ -47,6 +47,7 @@
   "devDependencies": {
     "@opentelemetry/api": "^1.0.0",
     "@opentelemetry/context-async-hooks": "1.5.0",
+    "@opentelemetry/sdk-metrics-base": "0.31.0",
     "@opentelemetry/sdk-trace-base": "1.5.0",
     "@opentelemetry/sdk-trace-node": "1.5.0",
     "@types/got": "9.6.12",
@@ -74,6 +75,7 @@
     "@opentelemetry/api": "^1.0.0"
   },
   "dependencies": {
+    "@opentelemetry/api-metrics": "0.31.0",
     "@opentelemetry/core": "1.5.0",
     "@opentelemetry/instrumentation": "0.31.0",
     "@opentelemetry/semantic-conventions": "1.5.0",

experimental/packages/opentelemetry-instrumentation-http/src/http.ts

@@ -15,6 +15,7 @@
  */
 import {
   context,
+  HrTime,
   INVALID_SPAN_CONTEXT,
   propagation,
   ROOT_CONTEXT,
@@ -25,7 +26,8 @@ import {
   SpanStatusCode,
   trace,
 } from '@opentelemetry/api';
-import { suppressTracing } from '@opentelemetry/core';
+import { Histogram, MeterProvider, MetricAttributes, ValueType } from '@opentelemetry/api-metrics';
+import { hrTime, hrTimeDuration, hrTimeToMilliseconds, suppressTracing } from '@opentelemetry/core';
 import type * as http from 'http';
 import type * as https from 'https';
 import { Socket } from 'net';
@@ -58,15 +60,35 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
   private readonly _spanNotEnded: WeakSet<Span> = new WeakSet<Span>();
   private readonly _version = process.versions.node;
   private _headerCapture;
+  private _httpServerDurationHistogram!: Histogram;
+  private _httpClientDurationHistogram!: Histogram;
 
   constructor(config?: HttpInstrumentationConfig) {
     super(
       '@opentelemetry/instrumentation-http',
       VERSION,
       config
     );
-
     this._headerCapture = this._createHeaderCapture();
+    this._updateMetricInstruments();
+  }
+
+  override setMeterProvider(meterProvider: MeterProvider) {
+    super.setMeterProvider(meterProvider);
+    this._updateMetricInstruments();
+  }
+
+  private _updateMetricInstruments() {
+    this._httpServerDurationHistogram = this.meter.createHistogram('http.server.duration', {
+      description: 'measures the duration of the inbound HTTP requests',
+      unit: 'ms',
+      valueType: ValueType.DOUBLE
+    });
+    this._httpClientDurationHistogram = this.meter.createHistogram('http.client.duration', {
+      description: 'measures the duration of the outbound HTTP requests',
+      unit: 'ms',
+      valueType: ValueType.DOUBLE
+    });
   }
 
   private _getConfig(): HttpInstrumentationConfig {
@@ -272,11 +294,15 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
    * @param request The original request object.
    * @param options The arguments to the original function.
    * @param span representing the current operation
+   * @param startTime representing the start time of the request to calculate duration in Metric
+   * @param metricAttributes metric attributes
    */
   private _traceClientRequest(
     request: http.ClientRequest,
     hostname: string,
-    span: Span
+    span: Span,
+    startTime: HrTime,
+    metricAttributes: MetricAttributes
   ): http.ClientRequest {
     if (this._getConfig().requestHook) {
       this._callRequestHook(span, request);
@@ -294,6 +320,8 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
           response,
         );
         span.setAttributes(responseAttributes);
+        metricAttributes = Object.assign(metricAttributes, utils.getOutgoingRequestMetricAttributesOnResponse(responseAttributes));
+
         if (this._getConfig().responseHook) {
           this._callResponseHook(span, response);
         }
@@ -323,32 +351,32 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
                   request,
                   response
                 ),
-              () => {},
+              () => { },
               true
             );
           }
 
-          this._closeHttpSpan(span);
+          this._closeHttpSpan(span, SpanKind.CLIENT, startTime, metricAttributes);
         });
         response.on('error', (error: Err) => {
           this._diag.debug('outgoingRequest on error()', error);
           utils.setSpanWithError(span, error);
           const code = utils.parseResponseStatus(SpanKind.CLIENT, response.statusCode);
           span.setStatus({ code, message: error.message });
-          this._closeHttpSpan(span);
+          this._closeHttpSpan(span, SpanKind.CLIENT, startTime, metricAttributes);
         });
       }
     );
     request.on('close', () => {
       this._diag.debug('outgoingRequest on request close()');
       if (!request.aborted) {
-        this._closeHttpSpan(span);
+        this._closeHttpSpan(span, SpanKind.CLIENT, startTime, metricAttributes);
       }
     });
     request.on('error', (error: Err) => {
       this._diag.debug('outgoingRequest on request error()', error);
       utils.setSpanWithError(span, error);
-      this._closeHttpSpan(span);
+      this._closeHttpSpan(span, SpanKind.CLIENT, startTime, metricAttributes);
     });
 
     this._diag.debug('http.ClientRequest return request');
@@ -404,18 +432,23 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
 
       const headers = request.headers;
 
+      const spanAttributes = utils.getIncomingRequestAttributes(request, {
+        component: component,
+        serverName: instrumentation._getConfig().serverName,
+        hookAttributes: instrumentation._callStartSpanHook(
+          request,
+          instrumentation._getConfig().startIncomingSpanHook
+        ),
+      });
+
       const spanOptions: SpanOptions = {
         kind: SpanKind.SERVER,
-        attributes: utils.getIncomingRequestAttributes(request, {
-          component: component,
-          serverName: instrumentation._getConfig().serverName,
-          hookAttributes: instrumentation._callStartSpanHook(
-            request,
-            instrumentation._getConfig().startIncomingSpanHook
-          ),
-        }),
+        attributes: spanAttributes,
       };
 
+      const startTime = hrTime();
+      let metricAttributes: MetricAttributes = utils.getIncomingRequestMetricAttributes(spanAttributes, { component: component });
+
       const ctx = propagation.extract(ROOT_CONTEXT, headers);
       const span = instrumentation._startHttpSpan(
         `${component.toLocaleUpperCase()} ${method}`,
@@ -456,7 +489,7 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
               error => {
                 if (error) {
                   utils.setSpanWithError(span, error);
-                  instrumentation._closeHttpSpan(span);
+                  instrumentation._closeHttpSpan(span, SpanKind.SERVER, startTime, metricAttributes);
                   throw error;
                 }
               }
@@ -466,6 +499,7 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
               request,
               response
             );
+            metricAttributes = Object.assign(metricAttributes, utils.getIncomingRequestMetricAttributesOnResponse(attributes));
 
             instrumentation._headerCapture.server.captureResponseHeaders(span, header => response.getHeader(header));
 
@@ -481,12 +515,12 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
                     request,
                     response
                   ),
-                () => {},
+                () => { },
                 true
               );
             }
 
-            instrumentation._closeHttpSpan(span);
+            instrumentation._closeHttpSpan(span, SpanKind.SERVER, startTime, metricAttributes);
             return returned;
           };
 
@@ -495,7 +529,7 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
             error => {
               if (error) {
                 utils.setSpanWithError(span, error);
-                instrumentation._closeHttpSpan(span);
+                instrumentation._closeHttpSpan(span, SpanKind.SERVER, startTime, metricAttributes);
                 throw error;
               }
             }
@@ -520,7 +554,7 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
       }
       const extraOptions =
         typeof args[0] === 'object' &&
-        (typeof options === 'string' || options instanceof url.URL)
+          (typeof options === 'string' || options instanceof url.URL)
           ? (args.shift() as http.RequestOptions)
           : undefined;
       const { origin, pathname, method, optionsParsed } = utils.getRequestInfo(
@@ -572,6 +606,9 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
         ),
       });
 
+      const startTime = hrTime();
+      const metricAttributes: MetricAttributes = utils.getOutgoingRequestMetricAttributes(attributes);
+
       const spanOptions: SpanOptions = {
         kind: SpanKind.CLIENT,
         attributes,
@@ -601,7 +638,7 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
           error => {
             if (error) {
               utils.setSpanWithError(span, error);
-              instrumentation._closeHttpSpan(span);
+              instrumentation._closeHttpSpan(span, SpanKind.CLIENT, startTime, metricAttributes);
               throw error;
             }
           }
@@ -612,7 +649,9 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
         return instrumentation._traceClientRequest(
           request,
           hostname,
-          span
+          span,
+          startTime,
+          metricAttributes
         );
       });
     };
@@ -646,13 +685,21 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
     return span;
   }
 
-  private _closeHttpSpan(span: Span) {
+  private _closeHttpSpan(span: Span, spanKind: SpanKind, startTime: HrTime, metricAttributes: MetricAttributes) {
     if (!this._spanNotEnded.has(span)) {
       return;
     }
 
     span.end();
     this._spanNotEnded.delete(span);
+
+    // Record metrics
+    const duration = hrTimeToMilliseconds(hrTimeDuration(startTime, hrTime()));
+    if (spanKind === SpanKind.SERVER) {
+      this._httpServerDurationHistogram.record(duration, metricAttributes);
+    } else if (spanKind === SpanKind.CLIENT) {
+      this._httpClientDurationHistogram.record(duration, metricAttributes);
+    }
   }
 
   private _callResponseHook(
@@ -661,7 +708,7 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
   ) {
     safeExecuteInTheMiddle(
       () => this._getConfig().responseHook!(span, response),
-      () => {},
+      () => { },
       true
     );
   }
@@ -672,7 +719,7 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
   ) {
     safeExecuteInTheMiddle(
       () => this._getConfig().requestHook!(span, request),
-      () => {},
+      () => { },
       true
     );
   }
@@ -681,7 +728,7 @@ export class HttpInstrumentation extends InstrumentationBase<Http> {
     request: http.IncomingMessage | http.RequestOptions,
     hookFunc: Function | undefined,
   ) {
-    if(typeof hookFunc === 'function'){
+    if (typeof hookFunc === 'function') {
       return safeExecuteInTheMiddle(
         () => hookFunc(request),
         () => { },

experimental/packages/opentelemetry-instrumentation-http/src/utils.ts

@@ -35,6 +35,7 @@ import { getRPCMetadata, RPCType } from '@opentelemetry/core';
 import * as url from 'url';
 import { AttributeNames } from './enums/AttributeNames';
 import { Err, IgnoreMatcher, ParsedRequestOptions } from './types';
+import { MetricAttributes } from '@opentelemetry/api-metrics';
 
 /**
  * Get an absolute url
@@ -348,6 +349,20 @@ export const getOutgoingRequestAttributes = (
   return Object.assign(attributes, options.hookAttributes);
 };
 
+/**
+ * Returns outgoing request Metric attributes scoped to the request data
+ * @param {SpanAttributes} spanAttributes the span attributes
+ */
+export const getOutgoingRequestMetricAttributes = (
+  spanAttributes: SpanAttributes
+): MetricAttributes => {
+  const metricAttributes: MetricAttributes = {};
+  metricAttributes[SemanticAttributes.HTTP_METHOD] = spanAttributes[SemanticAttributes.HTTP_METHOD];
+  metricAttributes[SemanticAttributes.NET_PEER_NAME] = spanAttributes[SemanticAttributes.NET_PEER_NAME];
+  metricAttributes[SemanticAttributes.HTTP_URL] = spanAttributes[SemanticAttributes.HTTP_URL];
+  return metricAttributes;
+};
+
 /**
  * Returns attributes related to the kind of HTTP protocol used
  * @param {string} [kind] Kind of HTTP protocol used: "1.0", "1.1", "2", "SPDY" or "QUIC".
@@ -392,6 +407,20 @@ export const getOutgoingRequestAttributesOnResponse = (
   return Object.assign(attributes, httpKindAttributes);
 };
 
+/**
+ * Returns outgoing request Metric attributes scoped to the response data
+ * @param {SpanAttributes} spanAttributes the span attributes
+ */
+export const getOutgoingRequestMetricAttributesOnResponse = (
+  spanAttributes: SpanAttributes
+): MetricAttributes => {
+  const metricAttributes: MetricAttributes = {};
+  metricAttributes[SemanticAttributes.NET_PEER_PORT] = spanAttributes[SemanticAttributes.NET_PEER_PORT];
+  metricAttributes[SemanticAttributes.HTTP_STATUS_CODE] = spanAttributes[SemanticAttributes.HTTP_STATUS_CODE];
+  metricAttributes[SemanticAttributes.HTTP_FLAVOR] = spanAttributes[SemanticAttributes.HTTP_FLAVOR];
+  return metricAttributes;
+};
+
 /**
  * Returns incoming request attributes scoped to the request data
  * @param {IncomingMessage} request the request object
@@ -445,6 +474,24 @@ export const getIncomingRequestAttributes = (
   return Object.assign(attributes, httpKindAttributes, options.hookAttributes);
 };
 
+/**
+ * Returns incoming request Metric attributes scoped to the request data
+ * @param {SpanAttributes} spanAttributes the span attributes
+ * @param {{ component: string }} options used to pass data needed to create attributes
+ */
+export const getIncomingRequestMetricAttributes = (
+  spanAttributes: SpanAttributes,
+  options: { component: string }
+): MetricAttributes => {
+  const metricAttributes: MetricAttributes = {};
+  metricAttributes[SemanticAttributes.HTTP_SCHEME] = options.component;
+  metricAttributes[SemanticAttributes.HTTP_METHOD] = spanAttributes[SemanticAttributes.HTTP_METHOD];
+  metricAttributes[SemanticAttributes.NET_HOST_NAME] = spanAttributes[SemanticAttributes.NET_HOST_NAME];
+  metricAttributes[SemanticAttributes.HTTP_FLAVOR] = spanAttributes[SemanticAttributes.HTTP_FLAVOR];
+  metricAttributes[SemanticAttributes.HTTP_TARGET] = spanAttributes[SemanticAttributes.HTTP_TARGET];
+  return metricAttributes;
+};
+
 /**
  * Returns incoming request attributes scoped to the response data
  * @param {(ServerResponse & { socket: Socket; })} response the response object
@@ -475,6 +522,19 @@ export const getIncomingRequestAttributesOnResponse = (
   return attributes;
 };
 
+/**
+ * Returns incoming request Metric attributes scoped to the request data
+ * @param {SpanAttributes} spanAttributes the span attributes
+ */
+export const getIncomingRequestMetricAttributesOnResponse = (
+  spanAttributes: SpanAttributes
+): MetricAttributes => {
+  const metricAttributes: MetricAttributes = {};
+  metricAttributes[SemanticAttributes.HTTP_STATUS_CODE] = spanAttributes[SemanticAttributes.HTTP_STATUS_CODE];
+  metricAttributes[SemanticAttributes.NET_HOST_PORT] = spanAttributes[SemanticAttributes.NET_HOST_PORT];
+  return metricAttributes;
+};
+
 export function headerCapture(type: 'request' | 'response', headers: string[]) {
   const normalizedHeaders = new Map(headers.map(header => [header.toLowerCase(), header.toLowerCase().replace(/-/g, '_')]));