Add HTTP Server and Client duration Metrics in HTTP Node.js Instrumentation (#3149)

experimental/CHANGELOG.md

@@ -57,6 +57,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
 * fix(add-views-to-node-sdk): added the ability to define meter views in `NodeSDK` [#3066](https://github.com/open-telemetry/opentelemetry-js/pull/3124) @weyert
 * feature(add-console-metrics-exporter): add ConsoleMetricExporter [#3120](https://github.com/open-telemetry/opentelemetry-js/pull/3120) @weyert
 * 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

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

@@ -74,8 +74,10 @@
     "@opentelemetry/api": "^1.0.0"
   },
   "dependencies": {
+    "@opentelemetry/api-metrics": "0.32.0",
     "@opentelemetry/core": "1.6.0",
     "@opentelemetry/instrumentation": "0.32.0",
+    "@opentelemetry/sdk-metrics": "0.32.0",
     "@opentelemetry/semantic-conventions": "1.6.0",
     "semver": "^7.3.5"
   },

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,6 +60,8 @@ 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(
@@ -65,8 +69,26 @@ export class HttpInstrumentation extends InstrumentationBase<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, {
+        attributes: spanAttributes,
-          component: component,
-          serverName: instrumentation._getConfig().serverName,
-          hookAttributes: instrumentation._callStartSpanHook(
-            request,
-            instrumentation._getConfig().startIncomingSpanHook
-          ),
-        }),
       };
 
+      const startTime = hrTime();
+      let metricAttributes: MetricAttributes = utils.getIncomingRequestMetricAttributes(spanAttributes);
+
       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
@@ -299,7 +300,7 @@ export const extractHostnameAndPort = (
   requestOptions: Pick<ParsedRequestOptions, 'hostname' | 'host' | 'port' | 'protocol'>
 ): { hostname: string, port: number | string } => {
   if (requestOptions.hostname && requestOptions.port) {
-    return {hostname: requestOptions.hostname, port: requestOptions.port};
+    return { hostname: requestOptions.hostname, port: requestOptions.port };
   }
   const matches = requestOptions.host?.match(/^([^:/ ]+)(:\d{1,5})?/) || null;
   const hostname = requestOptions.hostname || (matches === null ? 'localhost' : matches[1]);
@@ -312,7 +313,7 @@ export const extractHostnameAndPort = (
       port = requestOptions.protocol === 'https:' ? '443' : '80';
     }
   }
-  return {hostname, port};
+  return { hostname, port };
 };
 
 /**
@@ -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];
+  //TODO: http.url attribute, it should susbtitute any parameters to avoid high cardinality.
+  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
@@ -422,6 +451,7 @@ export const getIncomingRequestAttributes = (
     [SemanticAttributes.HTTP_HOST]: host,
     [SemanticAttributes.NET_HOST_NAME]: hostname,
     [SemanticAttributes.HTTP_METHOD]: method,
+    [SemanticAttributes.HTTP_SCHEME]: options.component,
   };
 
   if (typeof ips === 'string') {
@@ -445,6 +475,23 @@ 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
+): MetricAttributes => {
+  const metricAttributes: MetricAttributes = {};
+  metricAttributes[SemanticAttributes.HTTP_SCHEME] = spanAttributes[SemanticAttributes.HTTP_SCHEME];
+  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];
+  //TODO: http.target attribute, it should susbtitute any parameters to avoid high cardinality.
+  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, '_')]));
 

experimental/packages/opentelemetry-instrumentation-http/test/functionals/http-metrics.test.ts

@@ -0,0 +1,103 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+import {
+  AggregationTemporality,
+  DataPointType,
+  InMemoryMetricExporter,
+  MeterProvider,
+  PeriodicExportingMetricReader,
+} from '@opentelemetry/sdk-metrics';
+import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node';
+import { SemanticAttributes } from '@opentelemetry/semantic-conventions';
+import * as assert from 'assert';
+import { HttpInstrumentation } from '../../src/http';
+import { httpRequest } from '../utils/httpRequest';
+
+const instrumentation = new HttpInstrumentation();
+instrumentation.enable();
+instrumentation.disable();
+
+import * as http from 'http';
+
+let server: http.Server;
+const serverPort = 22346;
+const protocol = 'http';
+const hostname = 'localhost';
+const pathname = '/test';
+const tracerProvider = new NodeTracerProvider();
+const meterProvider = new MeterProvider();
+const metricsMemoryExporter = new InMemoryMetricExporter(AggregationTemporality.DELTA);
+const metricReader = new PeriodicExportingMetricReader({ exporter: metricsMemoryExporter, exportIntervalMillis: 100 });
+meterProvider.addMetricReader(metricReader);
+instrumentation.setTracerProvider(tracerProvider);
+instrumentation.setMeterProvider(meterProvider);
+
+
+describe('metrics', () => {
+  beforeEach(() => {
+    metricsMemoryExporter.reset();
+  });
+
+  before(() => {
+    instrumentation.enable();
+    server = http.createServer((request, response) => {
+      response.end('Test Server Response');
+    });
+    server.listen(serverPort);
+  });
+
+  after(() => {
+    server.close();
+    instrumentation.disable();
+  });
+
+  it('should add server/client duration metrics', async () => {
+    const requestCount = 3;
+    for (let i = 0; i < requestCount; i++) {
+      await httpRequest.get(`${protocol}://${hostname}:${serverPort}${pathname}`);
+    }
+    await new Promise(resolve => setTimeout(resolve, 300));
+    const resourceMetrics = metricsMemoryExporter.getMetrics();
+    const scopeMetrics = resourceMetrics[0].scopeMetrics;
+    assert.strictEqual(scopeMetrics.length, 1, 'scopeMetrics count');
+    const metrics = scopeMetrics[0].metrics;
+    assert.strictEqual(metrics.length, 2, 'metrics count');
+    assert.strictEqual(metrics[0].dataPointType, DataPointType.HISTOGRAM);
+    assert.strictEqual(metrics[0].descriptor.description, 'measures the duration of the inbound HTTP requests');
+    assert.strictEqual(metrics[0].descriptor.name, 'http.server.duration');
+    assert.strictEqual(metrics[0].descriptor.unit, 'ms');
+    assert.strictEqual(metrics[0].dataPoints.length, 1);
+    assert.strictEqual((metrics[0].dataPoints[0].value as any).count, requestCount);
+    assert.strictEqual(metrics[0].dataPoints[0].attributes[SemanticAttributes.HTTP_SCHEME], 'http');
+    assert.strictEqual(metrics[0].dataPoints[0].attributes[SemanticAttributes.HTTP_METHOD], 'GET');
+    assert.strictEqual(metrics[0].dataPoints[0].attributes[SemanticAttributes.HTTP_FLAVOR], '1.1');
+    assert.strictEqual(metrics[0].dataPoints[0].attributes[SemanticAttributes.NET_HOST_NAME], 'localhost');
+    assert.strictEqual(metrics[0].dataPoints[0].attributes[SemanticAttributes.HTTP_STATUS_CODE], 200);
+    assert.strictEqual(metrics[0].dataPoints[0].attributes[SemanticAttributes.NET_HOST_PORT], 22346);
+
+    assert.strictEqual(metrics[1].dataPointType, DataPointType.HISTOGRAM);
+    assert.strictEqual(metrics[1].descriptor.description, 'measures the duration of the outbound HTTP requests');
+    assert.strictEqual(metrics[1].descriptor.name, 'http.client.duration');
+    assert.strictEqual(metrics[1].descriptor.unit, 'ms');
+    assert.strictEqual(metrics[1].dataPoints.length, 1);
+    assert.strictEqual((metrics[1].dataPoints[0].value as any).count, requestCount);
+    assert.strictEqual(metrics[1].dataPoints[0].attributes[SemanticAttributes.HTTP_METHOD], 'GET');
+    assert.strictEqual(metrics[1].dataPoints[0].attributes[SemanticAttributes.NET_PEER_NAME], 'localhost');
+    assert.strictEqual(metrics[1].dataPoints[0].attributes[SemanticAttributes.NET_PEER_PORT], 22346);
+    assert.strictEqual(metrics[1].dataPoints[0].attributes[SemanticAttributes.HTTP_STATUS_CODE], 200);
+    assert.strictEqual(metrics[1].dataPoints[0].attributes[SemanticAttributes.HTTP_FLAVOR], '1.1');
+  });
+});

experimental/packages/opentelemetry-instrumentation-http/test/utils/assertSpan.ts

@@ -125,7 +125,7 @@ export const assertSpan = (
       validations.hostname,
       'must be consistent (PEER_NAME and hostname)'
     );
-    if(!validations.noNetPeer) {
+    if (!validations.noNetPeer) {
       assert.ok(
         span.attributes[SemanticAttributes.NET_PEER_IP],
         'must have PEER_IP'
@@ -178,6 +178,11 @@ export const assertSpan = (
         'must have HOST_IP'
       );
     }
+    assert.strictEqual(
+      span.attributes[SemanticAttributes.HTTP_SCHEME],
+      validations.component,
+      ' must have http.scheme attribute'
+    );
     assert.ok(typeof span.parentSpanId === 'string');
     assert.ok(isValidSpanId(span.parentSpanId));
   } else if (validations.reqHeaders) {

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

@@ -24,8 +24,14 @@
     {
       "path": "../../../packages/opentelemetry-semantic-conventions"
     },
+    {
+      "path": "../opentelemetry-api-metrics"
+    },
     {
       "path": "../opentelemetry-instrumentation"
+    },
+    {
+      "path": "../opentelemetry-sdk-metrics"
     }
   ]
 }