open-telemetry / opentelemetry-js-contrib

OpenTelemetry instrumentation for JavaScript modules
https://opentelemetry.io
Apache License 2.0
637 stars 473 forks source link

Defensive `decodeURIComponent` express error? #1691

Open daniel-white opened 9 months ago

daniel-white commented 9 months ago

What version of OpenTelemetry are you using?

@opentelemetry/instrumentation-express@0.32.3

What version of Node are you using?

16

What did you do?

we've been receiving requests to our express server that include invalid URLs that fail decodeURIComponent. we are seeing errors logged out that include otel in the stack so I'm not sure if its express or the instrumentation's middleware needing to handle this more gracefully.

URIError: Failed to decode param '%C0'
--
at decodeURIComponent (<anonymous>)
at decode_param (/home/node/node_modules/express/lib/router/layer.js:172:12)
at Layer.match (/home/node/node_modules/express/lib/router/layer.js:148:15)
at matchLayer (/home/node/node_modules/express/lib/router/index.js:585:18)
at next (/home/node/node_modules/express/lib/router/index.js:226:15)
at /home/node/node_modules/@opentelemetry/context-async-hooks/build/src/AbstractAsyncHooksContextManager.js:50:55
at AsyncLocalStorage.run (node:async_hooks:330:14)
at AsyncLocalStorageContextManager.with (/home/node/node_modules/@opentelemetry/context-async-hooks/build/src/AsyncLocalStorageContextManager.js:33:40)
at contextWrapper (/home/node/node_modules/@opentelemetry/context-async-hooks/build/src/AbstractAsyncHooksContextManager.js:50:32)
at arguments.<computed> (/home/node/node_modules/@opentelemetry/instrumentation-express/build/src/instrumentation.js:208:73)

What did you expect to see?

no errors

What did you see instead?

the above stack trace

Additional context

express@4.18.2

Flarna commented 9 months ago

The way how most OTel node.js instrumentations work is to wrap functions. Once called these wrappers do something (e.g. extract some data from arguments, start a span,...), then call the original and once the original function returns they do again something (e.g. end a span, check return value,...).

That said it's quite clear that OTel instrumentations are often on a call stack and not automatically responsible for any problem which might happen later.

Are you sure that OTel is actually the cause for the invalid urls received by your server?

daniel-white commented 9 months ago

@Flarna its not responsible for the urls. i did not know if there was some sort of logging or other behavior in the instrumentation that could cause this error to leak to stderr unintentionally

Flarna commented 9 months ago

Ah ok, it's about the log not about the error. I see no place in the express instrumentation where logging to stderr is done. In general OTel doesn't log to stderr, there is an diag api which is noop on default and user can configure it as needed.

trentm commented 9 months ago

FWIW, there are many issues on express discussing a similar (the same?) thing: https://github.com/expressjs/express/issues?q=is%3Aissue+decodeURIComponent

Do you get the same error printed if the OTel instrumentation is removed/disabled?