Incorrect type passed to OTel API leads to the exported telemetry being dropped by the backend

[pichlermarc]

What would you like help with?

I think I found a bug

How are you running Renovate?

None

If you're self-hosting Renovate, tell us which platform (GitHub, GitLab, etc) and which version of Renovate.

No response

Please tell us more about your question or problem

Description

In this spot right here (L149, L165), a caught Error which, due to TypeScript settings, is of any type is passed to the OTel API as message, but message is expected to be a string:

renovate/lib/instrumentation/index.ts

Lines 141 to 165 in 5ca09ed

	return getTracer().startActiveSpan(name, options, context, (span: Span) => {
	try {
	const ret = fn();
	if (ret instanceof Promise) {
	return ret
	.catch((e) => {
	span.setStatus({
	code: SpanStatusCode.ERROR,
	message: e,
	});
	throw e;
	})
	.finally(() => span.end()) as ReturnType<F>;
	}
	span.end();
	return ret;
	} catch (e) {
	span.setStatus({
	code: SpanStatusCode.ERROR,
	message: e,
	});
	span.end();
	throw e;
	}
	});

This causes the exported message to be dropped by the OTel collector with an 400 Bad Request, including all the spans that were actually okay.

Minimal Reproduction Steps

• Create: a file config.yaml

receivers:
  otlp:
    protocols:
      http:
        endpoint: 0.0.0.0:4318
processors:
  batch:
exporters:
  debug:
service:
  pipelines:
    traces:
      receivers: [otlp]
      exporters: [debug]
      processors: [batch]

• docker run -v $(pwd)/config.yaml:/etc/otelcol/config.yaml --rm -it --network=host otel/opentelemetry-collector:latest
• docker run --rm --network=host --env OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318 renovate/renovate:latest (no config on purpose so that the config span gets it's status set to error)

Additional info

I'm a maintainer of OTel JS and we're aware that this may be a common issue to run into when using the OTel SDK. As such we're planning to add additional input validation to ensure that the OTLP export request is not dropped when such input is passed (open-telemetry/opentelemetry-js#4998).
However, us adding the additonal input validation would mean that we will drop the message that's passed when it is not a string, so you may still loose the message in the Span's status.

My recommendation therefore would be to update ./lib/instrumentation/index.ts like so:

diff --git a/lib/instrumentation/index.ts b/lib/instrumentation/index.ts
index 4f33813c9..ec97f1964 100644
--- a/lib/instrumentation/index.ts
+++ b/lib/instrumentation/index.ts
@@ -143,10 +143,10 @@ export function instrument<F extends () => ReturnType<F>>(
       const ret = fn();
       if (ret instanceof Promise) {
         return ret
-          .catch((e) => {
+          .catch((e: unknown) => {
             span.setStatus({
               code: SpanStatusCode.ERROR,
-              message: e,
+              message: e instanceof Error? e.message: undefined,
             });
             throw e;
           })
@@ -154,10 +154,10 @@ export function instrument<F extends () => ReturnType<F>>(
       }
       span.end();
       return ret;
-    } catch (e) {
+    } catch (e: unknown) {
       span.setStatus({
         code: SpanStatusCode.ERROR,
-        message: e,
+        message: e instanceof Error? e.message: undefined,
       });
       span.end();
       throw e;

This will fix the dropped OTLP message issue immediately, and once we, over at the OTel JS repo, have added the validation (open-telemetry/opentelemetry-js#4998), will ensure that the message will be on the exported telemetry 🙂

Logs (if relevant)

FATAL: You must configure a GitHub token
       "trace_id": "7fba3771a06b24a78f8a90a01b774c69",
       "span_id": "4b46b3788c704e02",
       "trace_flags": "01"
 INFO: Renovate was run at log level "info". Set LOG_LEVEL=debug in environment variables to see extended debug logs.
       "trace_id": "7fba3771a06b24a78f8a90a01b774c69",
       "span_id": "4b46b3788c704e02",
       "trace_flags": "01"
 INFO: Renovate is exiting with a non-zero code due to the following logged errors
       "loggerErrors": [
         {
           "name": "renovate",
           "level": 60,
           "logContext": "m_bSlGmusuNcW9uMm3uKv",
           "msg": "You must configure a GitHub token",
           "trace_id": "7fba3771a06b24a78f8a90a01b774c69",
           "span_id": "4b46b3788c704e02",
           "trace_flags": "01"
         }
       ],
       "trace_id": "7fba3771a06b24a78f8a90a01b774c69",
       "span_id": "4b46b3788c704e02",
       "trace_flags": "01"
ERROR: unhandledRejection
       "err": {
         "name": "OTLPExporterError",
         "code": 400,
         "message": "Bad Request",
         "stack": "OTLPExporterError: Bad Request\n    at IncomingMessage.<anonymous> (/usr/local/renovate/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/otlp-exporter-base/src/platform/node/http-transport-utils.ts:75:23)\n    at /usr/local/renovate/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/context-async-hooks/src/AbstractAsyncHooksContextManager.ts:75:49\n    at AsyncLocalStorage.run (node:async_hooks:335:14)\n    at AsyncLocalStorageContextManager.with (/usr/local/renovate/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/context-async-hooks/src/AsyncLocalStorageContextManager.ts:40:36)\n    at IncomingMessage.contextWrapper (/usr/local/renovate/node_modules/.pnpm/@[email protected]_@[email protected]/node_modules/@opentelemetry/context-async-hooks/src/AbstractAsyncHooksContextManager.ts:75:26)\n    at IncomingMessage.emit (node:events:531:35)\n    at IncomingMessage.emit (node:domain:488:12)\n    at endReadableNT (node:internal/streams/readable:1696:12)\n    at processTicksAndRejections (node:internal/process/task_queues:82:21)"
       }

[secustor]

Thanks for for the report.

Will the fix also work for the experimental api export?
https://github.com/open-telemetry/opentelemetry-js/blob/main/api/src/experimental/trace/SugaredTracer.ts#L68

This code has been added before that has been merged in the api package and planning on moving this over.

[pichlermarc]

yes that should also work with that - there we actually use Span#recordException() instead of setting a SpanStatus.message which is not affected by this problem. 🙂

[secustor]

Will be fixed with: #31481

[pichlermarc]

awesome, thanks 🙂 🎉