diff --git a/plugins/node/opentelemetry-instrumentation-express/src/instrumentation.ts b/plugins/node/opentelemetry-instrumentation-express/src/instrumentation.ts index c476649750c..61d91b55e6f 100644 --- a/plugins/node/opentelemetry-instrumentation-express/src/instrumentation.ts +++ b/plugins/node/opentelemetry-instrumentation-express/src/instrumentation.ts @@ -15,12 +15,23 @@ */ import { getRPCMetadata, RPCType } from '@opentelemetry/core'; -import { trace, context, diag, SpanAttributes } from '@opentelemetry/api'; +import { + trace, + context, + diag, + SpanAttributes, + SpanStatusCode, +} from '@opentelemetry/api'; import type * as express from 'express'; import { ExpressInstrumentationConfig, ExpressRequestInfo } from './types'; import { ExpressLayerType } from './enums/ExpressLayerType'; import { AttributeNames } from './enums/AttributeNames'; -import { getLayerMetadata, storeLayerPath, isLayerIgnored } from './utils'; +import { + asErrorAndMessage, + getLayerMetadata, + isLayerIgnored, + storeLayerPath, +} from './utils'; import { VERSION } from './version'; import { InstrumentationBase, @@ -176,6 +187,7 @@ export class ExpressInstrumentation extends InstrumentationBase< layer[kLayerPatched] = true; this._wrap(layer, 'handle', (original: Function) => { + // TODO: instrument error handlers if (original.length === 4) return original; return function ( this: ExpressLayer, @@ -262,29 +274,55 @@ export class ExpressInstrumentation extends InstrumentationBase< const callbackIdx = args.findIndex(arg => typeof arg === 'function'); if (callbackIdx >= 0) { arguments[callbackIdx] = function () { + // express considers anything but an empty value, "route" or "router" + // passed to its callback to be an error + const maybeError = arguments[0]; + const isError = ![undefined, null, 'route', 'router'].includes( + maybeError + ); + if (isError) { + const [error, message] = asErrorAndMessage(maybeError); + span.recordException(error); + span.setStatus({ + code: SpanStatusCode.ERROR, + message, + }); + } + if (spanHasEnded === false) { spanHasEnded = true; req.res?.removeListener('finish', onResponseFinish); span.end(); } - if (!(req.route && arguments[0] instanceof Error)) { + if (!(req.route && isError)) { (req[_LAYERS_STORE_PROPERTY] as string[]).pop(); } const callback = args[callbackIdx] as Function; return callback.apply(this, arguments); }; } - const result = original.apply(this, arguments); - /** - * At this point if the callback wasn't called, that means either the - * layer is asynchronous (so it will call the callback later on) or that - * the layer directly end the http response, so we'll hook into the "finish" - * event to handle the later case. - */ - if (!spanHasEnded) { - res.once('finish', onResponseFinish); + + try { + return original.apply(this, arguments); + } catch (anyError) { + const [error, message] = asErrorAndMessage(anyError); + span.recordException(error); + span.setStatus({ + code: SpanStatusCode.ERROR, + message, + }); + throw anyError; + } finally { + /** + * At this point if the callback wasn't called, that means either the + * layer is asynchronous (so it will call the callback later on) or that + * the layer directly end the http response, so we'll hook into the "finish" + * event to handle the later case. + */ + if (!spanHasEnded) { + res.once('finish', onResponseFinish); + } } - return result; }; }); } diff --git a/plugins/node/opentelemetry-instrumentation-express/src/utils.ts b/plugins/node/opentelemetry-instrumentation-express/src/utils.ts index d272434422f..f543104e490 100644 --- a/plugins/node/opentelemetry-instrumentation-express/src/utils.ts +++ b/plugins/node/opentelemetry-instrumentation-express/src/utils.ts @@ -132,3 +132,16 @@ export const isLayerIgnored = ( return false; }; + +/** + * Converts a user-provided error value into an error and error message pair + * + * @param error - User-provided error value + * @returns Both an Error or string representation of the value and an error message + */ +export const asErrorAndMessage = ( + error: unknown +): [error: string | Error, message: string] => + error instanceof Error + ? [error, error.message] + : [String(error), String(error)]; diff --git a/plugins/node/opentelemetry-instrumentation-express/test/express.test.ts b/plugins/node/opentelemetry-instrumentation-express/test/express.test.ts index 64d6631409a..80c02518156 100644 --- a/plugins/node/opentelemetry-instrumentation-express/test/express.test.ts +++ b/plugins/node/opentelemetry-instrumentation-express/test/express.test.ts @@ -14,7 +14,7 @@ * limitations under the License. */ -import { context, trace } from '@opentelemetry/api'; +import { SpanStatusCode, context, trace } from '@opentelemetry/api'; import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node'; import { AsyncHooksContextManager } from '@opentelemetry/context-async-hooks'; import { @@ -255,6 +255,94 @@ describe('ExpressInstrumentation', () => { ); }); + it('captures sync middleware errors', async () => { + const rootSpan = tracer.startSpan('rootSpan'); + let finishListenerCount: number | undefined; + const httpServer = await serverWithMiddleware(tracer, rootSpan, app => { + app.use((req, res, next) => { + res.on('finish', () => { + finishListenerCount = res.listenerCount('finish'); + }); + next(); + }); + + const errorMiddleware: express.RequestHandler = (req, res, next) => { + throw new Error('message'); + }; + app.use(errorMiddleware); + }); + server = httpServer.server; + port = httpServer.port; + assert.strictEqual(memoryExporter.getFinishedSpans().length, 0); + + await context.with( + trace.setSpan(context.active(), rootSpan), + async () => { + await httpRequest.get(`http://localhost:${port}/toto/tata`); + rootSpan.end(); + assert.strictEqual(finishListenerCount, 3); + + const errorSpan = memoryExporter + .getFinishedSpans() + .find(span => span.name.includes('errorMiddleware')); + assert.notStrictEqual(errorSpan, undefined); + + assert.deepStrictEqual(errorSpan!.status, { + code: SpanStatusCode.ERROR, + message: 'message', + }); + assert.notStrictEqual( + errorSpan!.events.find(event => event.name === 'exception'), + undefined + ); + } + ); + }); + + it('captures async middleware errors', async () => { + const rootSpan = tracer.startSpan('rootSpan'); + let finishListenerCount: number | undefined; + const httpServer = await serverWithMiddleware(tracer, rootSpan, app => { + app.use((req, res, next) => { + res.on('finish', () => { + finishListenerCount = res.listenerCount('finish'); + }); + next(); + }); + + const errorMiddleware: express.RequestHandler = (req, res, next) => { + setTimeout(() => next(new Error('message')), 10); + }; + app.use(errorMiddleware); + }); + server = httpServer.server; + port = httpServer.port; + assert.strictEqual(memoryExporter.getFinishedSpans().length, 0); + + await context.with( + trace.setSpan(context.active(), rootSpan), + async () => { + await httpRequest.get(`http://localhost:${port}/toto/tata`); + rootSpan.end(); + assert.strictEqual(finishListenerCount, 2); + + const errorSpan = memoryExporter + .getFinishedSpans() + .find(span => span.name.includes('errorMiddleware')); + assert.notStrictEqual(errorSpan, undefined); + + assert.deepStrictEqual(errorSpan!.status, { + code: SpanStatusCode.ERROR, + message: 'message', + }); + assert.notStrictEqual( + errorSpan!.events.find(event => event.name === 'exception'), + undefined + ); + } + ); + }); + it('should not create span because there are no parent', async () => { const app = express(); app.use(express.json()); diff --git a/plugins/node/opentelemetry-instrumentation-express/test/utils.test.ts b/plugins/node/opentelemetry-instrumentation-express/test/utils.test.ts index e85a677af13..fc927a9b7fa 100644 --- a/plugins/node/opentelemetry-instrumentation-express/test/utils.test.ts +++ b/plugins/node/opentelemetry-instrumentation-express/test/utils.test.ts @@ -142,4 +142,27 @@ describe('Utils', () => { ); }); }); + + describe('asErrorAndMessage', () => { + it('should special case Error instances', () => { + const input = new Error('message'); + const [error, message] = utils.asErrorAndMessage(input); + assert.strictEqual(error, input); + assert.strictEqual(message, 'message'); + }); + + it('should pass strings as-is', () => { + const input = 'error'; + const [error, message] = utils.asErrorAndMessage(input); + assert.strictEqual(error, input); + assert.strictEqual(message, input); + }); + + it('should stringify other types', () => { + const input = 2; + const [error, message] = utils.asErrorAndMessage(input); + assert.strictEqual(error, '2'); + assert.strictEqual(message, '2'); + }); + }); });