diff --git a/experimental/CHANGELOG.md b/experimental/CHANGELOG.md index a489427839..377e37c9fa 100644 --- a/experimental/CHANGELOG.md +++ b/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 diff --git a/experimental/packages/opentelemetry-instrumentation-http/package.json b/experimental/packages/opentelemetry-instrumentation-http/package.json index a248b031ea..754414cf9f 100644 --- a/experimental/packages/opentelemetry-instrumentation-http/package.json +++ b/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" }, diff --git a/experimental/packages/opentelemetry-instrumentation-http/src/http.ts b/experimental/packages/opentelemetry-instrumentation-http/src/http.ts index 5459e1d26f..a0e07a1e9f 100644 --- a/experimental/packages/opentelemetry-instrumentation-http/src/http.ts +++ b/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 { private readonly _spanNotEnded: WeakSet = new WeakSet(); 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 { 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 { * @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 { 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 { 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 { 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); + const ctx = propagation.extract(ROOT_CONTEXT, headers); const span = instrumentation._startHttpSpan( `${component.toLocaleUpperCase()} ${method}`, @@ -456,7 +489,7 @@ export class HttpInstrumentation extends InstrumentationBase { 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 { 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 { request, response ), - () => {}, + () => { }, true ); } - instrumentation._closeHttpSpan(span); + instrumentation._closeHttpSpan(span, SpanKind.SERVER, startTime, metricAttributes); return returned; }; @@ -495,7 +529,7 @@ export class HttpInstrumentation extends InstrumentationBase { 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 { } 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 { ), }); + 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 { 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 { return instrumentation._traceClientRequest( request, hostname, - span + span, + startTime, + metricAttributes ); }); }; @@ -646,13 +685,21 @@ export class HttpInstrumentation extends InstrumentationBase { 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 { ) { safeExecuteInTheMiddle( () => this._getConfig().responseHook!(span, response), - () => {}, + () => { }, true ); } @@ -672,7 +719,7 @@ export class HttpInstrumentation extends InstrumentationBase { ) { safeExecuteInTheMiddle( () => this._getConfig().requestHook!(span, request), - () => {}, + () => { }, true ); } @@ -681,7 +728,7 @@ export class HttpInstrumentation extends InstrumentationBase { request: http.IncomingMessage | http.RequestOptions, hookFunc: Function | undefined, ) { - if(typeof hookFunc === 'function'){ + if (typeof hookFunc === 'function') { return safeExecuteInTheMiddle( () => hookFunc(request), () => { }, diff --git a/experimental/packages/opentelemetry-instrumentation-http/src/utils.ts b/experimental/packages/opentelemetry-instrumentation-http/src/utils.ts index f42f9955b3..e9e9b45468 100644 --- a/experimental/packages/opentelemetry-instrumentation-http/src/utils.ts +++ b/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 ): { 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, '_')])); diff --git a/experimental/packages/opentelemetry-instrumentation-http/test/functionals/http-metrics.test.ts b/experimental/packages/opentelemetry-instrumentation-http/test/functionals/http-metrics.test.ts new file mode 100644 index 0000000000..5ab046b45f --- /dev/null +++ b/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'); + }); +}); diff --git a/experimental/packages/opentelemetry-instrumentation-http/test/utils/assertSpan.ts b/experimental/packages/opentelemetry-instrumentation-http/test/utils/assertSpan.ts index db0d0d1ea0..3b9b1a402d 100644 --- a/experimental/packages/opentelemetry-instrumentation-http/test/utils/assertSpan.ts +++ b/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) { diff --git a/experimental/packages/opentelemetry-instrumentation-http/tsconfig.json b/experimental/packages/opentelemetry-instrumentation-http/tsconfig.json index b883031b0f..034c613b3e 100644 --- a/experimental/packages/opentelemetry-instrumentation-http/tsconfig.json +++ b/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" } ] }