From ee5c584c943eb8a3de0566843a42784f16c0f31f Mon Sep 17 00:00:00 2001 From: Onur Temizkan Date: Wed, 18 Sep 2024 01:10:28 +0300 Subject: [PATCH] feat(instrumentation-express): Use router path in router span names (#2319) This PR adds a new utility (getRouterPath) to recursively search the (possibly nested) parameterised router path when getting the layer metadata. This only affects the span name, not the http.route attribute of the span. http.route is still showing the mount path. (Active discussion on this: Express instrumentation does not properly handle router usage #1993 (comment)) Uses route primarily to assign the requestHandler span name instead of layerPath. layerPath does not represent the full path, only the path of the last matching router when nested routers are used. Co-authored-by: Abhijeet Prasad Co-authored-by: Jamie Danielson Co-authored-by: Jamie Danielson --- .../src/instrumentation.ts | 2 +- .../src/internal-types.ts | 1 + .../src/utils.ts | 44 ++++++++-- .../test/express.test.ts | 80 ++++++++++++++++++ .../fixtures/use-express-nested-router.mjs | 81 +++++++++++++++++++ .../test/fixtures/use-express-router.mjs | 72 +++++++++++++++++ .../test/utils.test.ts | 49 ++++++++++- 7 files changed, 320 insertions(+), 9 deletions(-) create mode 100644 plugins/node/opentelemetry-instrumentation-express/test/fixtures/use-express-nested-router.mjs create mode 100644 plugins/node/opentelemetry-instrumentation-express/test/fixtures/use-express-router.mjs diff --git a/plugins/node/opentelemetry-instrumentation-express/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-express/src/instrumentation.ts index bcff7a52e2..155b63f494 100644 --- a/plugins/node/opentelemetry-instrumentation-express/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-express/src/instrumentation.ts @@ -180,7 +180,7 @@ export class ExpressInstrumentation extends InstrumentationBase 0 ? route : '/', }; - const metadata = getLayerMetadata(layer, layerPath); + const metadata = getLayerMetadata(route, layer, layerPath); const type = metadata.attributes[ AttributeNames.EXPRESS_TYPE ] as ExpressLayerType; diff --git a/plugins/node/opentelemetry-instrumentation-express/src/internal-types.ts b/plugins/node/opentelemetry-instrumentation-express/src/internal-types.ts index a661bf9de4..ebdc260bc3 100644 --- a/plugins/node/opentelemetry-instrumentation-express/src/internal-types.ts +++ b/plugins/node/opentelemetry-instrumentation-express/src/internal-types.ts @@ -64,6 +64,7 @@ export type ExpressLayer = { params: { [key: string]: string }; path: string; regexp: RegExp; + route?: ExpressLayer; }; export type LayerMetadata = { diff --git a/plugins/node/opentelemetry-instrumentation-express/src/utils.ts b/plugins/node/opentelemetry-instrumentation-express/src/utils.ts index fa7b0ee9a0..fdc8f3728c 100644 --- a/plugins/node/opentelemetry-instrumentation-express/src/utils.ts +++ b/plugins/node/opentelemetry-instrumentation-express/src/utils.ts @@ -44,12 +44,34 @@ export const storeLayerPath = (request: PatchedRequest, value?: string) => { (request[_LAYERS_STORE_PROPERTY] as string[]).push(value); }; +/** + * Recursively search the router path from layer stack + * @param path The path to reconstruct + * @param layer The layer to reconstruct from + * @returns The reconstructed path + */ +export const getRouterPath = (path: string, layer: ExpressLayer): string => { + const stackLayer = layer.handle?.stack?.[0]; + + if (stackLayer?.route?.path) { + return `${path}${stackLayer.route.path}`; + } + + if (stackLayer?.handle?.stack) { + return getRouterPath(path, stackLayer); + } + + return path; +}; + /** * Parse express layer context to retrieve a name and attributes. + * @param route The route of the layer * @param layer Express layer * @param [layerPath] if present, the path on which the layer has been mounted */ export const getLayerMetadata = ( + route: string, layer: ExpressLayer, layerPath?: string ): { @@ -57,20 +79,26 @@ export const getLayerMetadata = ( name: string; } => { if (layer.name === 'router') { + const maybeRouterPath = getRouterPath('', layer); + const extractedRouterPath = maybeRouterPath + ? maybeRouterPath + : layerPath || route || '/'; + return { attributes: { - [AttributeNames.EXPRESS_NAME]: layerPath, + [AttributeNames.EXPRESS_NAME]: extractedRouterPath, [AttributeNames.EXPRESS_TYPE]: ExpressLayerType.ROUTER, }, - name: `router - ${layerPath}`, + name: `router - ${extractedRouterPath}`, }; } else if (layer.name === 'bound dispatch') { return { attributes: { - [AttributeNames.EXPRESS_NAME]: layerPath ?? 'request handler', + [AttributeNames.EXPRESS_NAME]: + (route || layerPath) ?? 'request handler', [AttributeNames.EXPRESS_TYPE]: ExpressLayerType.REQUEST_HANDLER, }, - name: `request handler${layer.path ? ` - ${layerPath}` : ''}`, + name: `request handler${layer.path ? ` - ${route || layerPath}` : ''}`, }; } else { return { @@ -159,11 +187,13 @@ export const asErrorAndMessage = ( export const getLayerPath = ( args: [LayerPathSegment | LayerPathSegment[], ...unknown[]] ): string | undefined => { - if (Array.isArray(args[0])) { - return args[0].map(arg => extractLayerPathSegment(arg) || '').join(','); + const firstArg = args[0]; + + if (Array.isArray(firstArg)) { + return firstArg.map(arg => extractLayerPathSegment(arg) || '').join(','); } - return extractLayerPathSegment(args[0]); + return extractLayerPathSegment(firstArg); }; const extractLayerPathSegment = (arg: LayerPathSegment) => { diff --git a/plugins/node/opentelemetry-instrumentation-express/test/express.test.ts b/plugins/node/opentelemetry-instrumentation-express/test/express.test.ts index 7f52e90e35..5991688ffd 100644 --- a/plugins/node/opentelemetry-instrumentation-express/test/express.test.ts +++ b/plugins/node/opentelemetry-instrumentation-express/test/express.test.ts @@ -641,6 +641,86 @@ describe('ExpressInstrumentation', () => { }); }); + it('should work with Express routers', async () => { + await testUtils.runTestFixture({ + cwd: __dirname, + argv: ['fixtures/use-express-router.mjs'], + env: { + NODE_OPTIONS: + '--experimental-loader=@opentelemetry/instrumentation/hook.mjs', + NODE_NO_WARNINGS: '1', + }, + checkResult: (err, stdout, stderr) => { + assert.ifError(err); + }, + checkCollector: (collector: testUtils.TestCollector) => { + const spans = collector.sortedSpans; + + assert.strictEqual(spans[0].name, 'GET'); + assert.strictEqual(spans[0].kind, testUtils.OtlpSpanKind.CLIENT); + assert.strictEqual(spans[1].name, 'GET /api/user/:id'); + assert.strictEqual(spans[1].kind, testUtils.OtlpSpanKind.SERVER); + assert.strictEqual(spans[1].parentSpanId, spans[0].spanId); + assert.strictEqual(spans[2].name, 'middleware - query'); + assert.strictEqual(spans[3].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[3].parentSpanId, spans[1].spanId); + assert.strictEqual(spans[4].name, 'middleware - simpleMiddleware'); + assert.strictEqual(spans[4].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[4].parentSpanId, spans[1].spanId); + assert.strictEqual(spans[5].name, 'router - /api/user/:id'); + assert.strictEqual(spans[5].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[5].parentSpanId, spans[1].spanId); + assert.strictEqual(spans[6].name, 'request handler - /api/user/:id'); + assert.strictEqual(spans[6].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[6].parentSpanId, spans[1].spanId); + }, + }); + }); + + it('should work with nested Express routers', async () => { + await testUtils.runTestFixture({ + cwd: __dirname, + argv: ['fixtures/use-express-nested-router.mjs'], + env: { + NODE_OPTIONS: + '--experimental-loader=@opentelemetry/instrumentation/hook.mjs', + NODE_NO_WARNINGS: '1', + }, + checkResult: (err, stdout, stderr) => { + assert.ifError(err); + }, + checkCollector: (collector: testUtils.TestCollector) => { + const spans = collector.sortedSpans; + + assert.strictEqual(spans[0].name, 'GET'); + assert.strictEqual(spans[0].kind, testUtils.OtlpSpanKind.CLIENT); + assert.strictEqual(spans[1].name, 'GET /api/user/:id/posts/:postId'); + assert.strictEqual(spans[1].kind, testUtils.OtlpSpanKind.SERVER); + assert.strictEqual(spans[2].name, 'middleware - query'); + assert.strictEqual(spans[2].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[2].parentSpanId, spans[1].spanId); + assert.strictEqual(spans[3].name, 'middleware - expressInit'); + assert.strictEqual(spans[3].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[3].parentSpanId, spans[1].spanId); + assert.strictEqual(spans[4].name, 'middleware - simpleMiddleware'); + assert.strictEqual(spans[4].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[4].parentSpanId, spans[1].spanId); + assert.strictEqual(spans[5].name, 'router - /api/user/:id'); + assert.strictEqual(spans[5].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[5].parentSpanId, spans[1].spanId); + assert.strictEqual(spans[6].name, 'router - /:postId'); + assert.strictEqual(spans[6].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[6].parentSpanId, spans[1].spanId); + assert.strictEqual( + spans[7].name, + 'request handler - /api/user/:id/posts/:postId' + ); + assert.strictEqual(spans[7].kind, testUtils.OtlpSpanKind.INTERNAL); + assert.strictEqual(spans[7].parentSpanId, spans[1].spanId); + }, + }); + }); + it('should set a correct transaction name for routes specified in RegEx', async () => { await testUtils.runTestFixture({ cwd: __dirname, diff --git a/plugins/node/opentelemetry-instrumentation-express/test/fixtures/use-express-nested-router.mjs b/plugins/node/opentelemetry-instrumentation-express/test/fixtures/use-express-nested-router.mjs new file mode 100644 index 0000000000..98ba0bf236 --- /dev/null +++ b/plugins/node/opentelemetry-instrumentation-express/test/fixtures/use-express-nested-router.mjs @@ -0,0 +1,81 @@ +/* + * 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 { promisify } from 'util'; +import { createTestNodeSdk } from '@opentelemetry/contrib-test-utils'; + +import { HttpInstrumentation } from '@opentelemetry/instrumentation-http'; +import { ExpressInstrumentation } from '../../build/src/index.js'; + +const sdk = createTestNodeSdk({ + serviceName: 'use-express-nested', + instrumentations: [ + new HttpInstrumentation(), + new ExpressInstrumentation() + ] +}) + +sdk.start(); + +import express from 'express'; +import * as http from 'http'; + +const app = express(); + +app.use(async function simpleMiddleware(req, res, next) { + // Wait a short delay to ensure this "middleware - ..." span clearly starts + // before the "router - ..." span. The test rely on a start-time-based sort + // of the produced spans. If they start in the same millisecond, then tests + // can be flaky. + await promisify(setTimeout)(10); + next(); +}); + +const userRouter = express.Router(); +const postsRouter = express.Router(); + +postsRouter.get('/:postId', (req, res, next) => { + res.json({ hello: 'yes' }); + res.end(); + next(); +}); + +userRouter.get('/api/user/:id', (req, res, next) => { + res.json({ hello: 'yes' }); + res.end(); + next(); +}); + +userRouter.use('/api/user/:id/posts', postsRouter); + +app.use(userRouter); + +const server = http.createServer(app); +await new Promise(resolve => server.listen(0, resolve)); +const port = server.address().port; + + +await new Promise(resolve => { + http.get(`http://localhost:${port}/api/user/123/posts/321`, (res) => { + res.resume(); + res.on('end', data => { + resolve(data); + }); + }) +}); + +await new Promise(resolve => server.close(resolve)); +await sdk.shutdown(); diff --git a/plugins/node/opentelemetry-instrumentation-express/test/fixtures/use-express-router.mjs b/plugins/node/opentelemetry-instrumentation-express/test/fixtures/use-express-router.mjs new file mode 100644 index 0000000000..5846da88ae --- /dev/null +++ b/plugins/node/opentelemetry-instrumentation-express/test/fixtures/use-express-router.mjs @@ -0,0 +1,72 @@ +/* + * 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 { promisify } from 'util'; +import { createTestNodeSdk } from '@opentelemetry/contrib-test-utils'; + +import { HttpInstrumentation } from '@opentelemetry/instrumentation-http'; +import { ExpressInstrumentation } from '../../build/src/index.js'; + +const sdk = createTestNodeSdk({ + serviceName: 'use-express-nested', + instrumentations: [ + new HttpInstrumentation(), + new ExpressInstrumentation() + ] +}) + +sdk.start(); + +import express from 'express'; +import * as http from 'http'; + +const app = express(); + +app.use(async function simpleMiddleware(req, res, next) { + // Wait a short delay to ensure this "middleware - ..." span clearly starts + // before the "router - ..." span. The test rely on a start-time-based sort + // of the produced spans. If they start in the same millisecond, then tests + // can be flaky. + await promisify(setTimeout)(10); + next(); +}); + +const router = express.Router(); + +router.get('/api/user/:id', (req, res, next) => { + res.json({ hello: 'yes' }); + res.end(); + next(); +}); + +app.use(router); + +const server = http.createServer(app); +await new Promise(resolve => server.listen(0, resolve)); +const port = server.address().port; + + +await new Promise(resolve => { + http.get(`http://localhost:${port}/api/user/123`, (res) => { + res.resume(); + res.on('end', data => { + resolve(data); + }); + }) +}); + +await new Promise(resolve => server.close(resolve)); +await sdk.shutdown(); diff --git a/plugins/node/opentelemetry-instrumentation-express/test/utils.test.ts b/plugins/node/opentelemetry-instrumentation-express/test/utils.test.ts index 098bab4e8c..f8dac5035b 100644 --- a/plugins/node/opentelemetry-instrumentation-express/test/utils.test.ts +++ b/plugins/node/opentelemetry-instrumentation-express/test/utils.test.ts @@ -94,6 +94,7 @@ describe('Utils', () => { it('should return router metadata', () => { assert.deepEqual( utils.getLayerMetadata( + '/test', { name: 'router', } as ExpressLayer, @@ -112,6 +113,7 @@ describe('Utils', () => { it('should return request handler metadata', () => { assert.deepEqual( utils.getLayerMetadata( + '/:id', { name: 'bound dispatch', } as ExpressLayer, @@ -129,7 +131,7 @@ describe('Utils', () => { it('should return middleware metadata', () => { assert.deepEqual( - utils.getLayerMetadata({ + utils.getLayerMetadata('', { name: 'bodyParser', } as ExpressLayer), { @@ -143,6 +145,51 @@ describe('Utils', () => { }); }); + describe('reconstructRouterPath()', () => { + it('should reconstruct a simple router path', () => { + const layer = { + handle: { + stack: [ + { + route: { + path: '/test', + }, + }, + ], + }, + }; + + assert.strictEqual( + utils.getRouterPath('', layer as unknown as ExpressLayer), + '/test' + ); + }); + + it('should reconstruct a parameterized router path', () => { + const layer = { + handle: { + stack: [ + { + handle: { + stack: [ + { + route: { + path: '/:id', + }, + }, + ], + }, + }, + ], + }, + }; + + assert.strictEqual( + utils.getRouterPath('', layer as unknown as ExpressLayer), + '/:id' + ); + }); + }); describe('asErrorAndMessage', () => { it('should special case Error instances', () => { const input = new Error('message');