Context Propagation doesn't work with NestJS & fetch

[Lp-Francois]

What happened?

Tracing with NestJS seems to work nicely for each micro-service. But when trying to propagate a trace ID to trace several micro-services communicating between each other, the propagation seems not to be working as the traceID from the micro-service A is nowhere to be found in micro-service B.

To reproduce, I crafted a simple example repository.

Steps to Reproduce

I created a simple NestJS application with tracing in tracing.ts. When querying GET /hello, the hello endpoint sends a request to /world, and return the result from the world endpoint.

Repository: https://github.com/Lp-Francois/bug-report-otel-nestjs

To run it follow the next step:

In 1 terminal, run the following commands.

git clone https://github.com/Lp-Francois/bug-report-otel-nestjs

cd bug-report-otel-nestjs

npm install

npm run start:dev
# or `npm run start`

in another terminal, or from postman/other fetch this endpoint: http://localhost:3002/hello, and notice 2 things:

1. How headers are missing any traceparent/traceId on the response
2. How the fetch request from nest is not passing the traceId to the request (similar to this on-going issues? Add instrumentation for fetch API #4333 & Cannot get HTTP Context Propagation to work #4247)

Example: run curl -v http://localhost:3002/hello

Expected Result

I would expect the traceID to be propagated to my endpoints:
According to https://www.w3.org/TR/trace-context/ I was expecting at least a traceparent header.

Expected steps:

When I pass a traceparent in the headers of my GET request to /hello

1. The application is picking up the traceID from the traceparent header is use it for the current request ✅
2. when doing a query to another micro-service/endpoint, pass this traceID in the headers ❌
3. return the traceID in the response ❌

Actual Result

In the postman/curl response (curl -v http://localhost:3002/hello) I don't have trace info.

And in the 2nd request the traceID from the /hello is not used

Additional Details

OpenTelemetry Setup Code

// code available at https://github.com/Lp-Francois/bug-report-otel-nestjs/blob/main/src/tracing.ts

/* eslint-disable @typescript-eslint/no-unused-vars */
/* eslint-disable no-console */
import { BatchSpanProcessor } from '@opentelemetry/sdk-trace-base';
import { Resource } from '@opentelemetry/resources';
import { ExpressInstrumentation } from '@opentelemetry/instrumentation-express';
import { NestInstrumentation } from '@opentelemetry/instrumentation-nestjs-core';
import { NodeSDK } from '@opentelemetry/sdk-node';
import { AsyncLocalStorageContextManager } from '@opentelemetry/context-async-hooks';
import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-http';
import {
  CompositePropagator,
  W3CTraceContextPropagator,
  W3CBaggagePropagator,
} from '@opentelemetry/core';
import { PinoInstrumentation } from '@opentelemetry/instrumentation-pino'
import { B3InjectEncoding, B3Propagator } from '@opentelemetry/propagator-b3';
import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node';
import { SemanticResourceAttributes } from '@opentelemetry/semantic-conventions';
import { HttpInstrumentation } from '@opentelemetry/instrumentation-http';
import { AWSXRayPropagator } from '@opentelemetry/propagator-aws-xray';
import { diag, DiagConsoleLogger, DiagLogLevel } from '@opentelemetry/api';

// For troubleshooting, set the log level to DiagLogLevel.DEBUG
// diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.DEBUG);

const otelSDK = new NodeSDK({
  spanProcessor: new BatchSpanProcessor(
    new OTLPTraceExporter({
      url: 'http://localhost:4318/v1/traces',
    }),
  ),
  resource: new Resource({
    [SemanticResourceAttributes.SERVICE_NAME]: 'hello-world',
  }),
  instrumentations: [
    // new HttpInstrumentation(),
    // new ExpressInstrumentation(),
    // new NestInstrumentation(),
    new PinoInstrumentation({
      // Log span context under custom keys
      // This is optional, and will default to "trace_id", "span_id" and "trace_flags" as the keys
      logKeys: {
        traceId: 'traceId',
        spanId: 'spanId',
        traceFlags: 'traceFlags',
      },
    }),
    getNodeAutoInstrumentations({
      '@opentelemetry/instrumentation-fs': { enabled: false },
      '@opentelemetry/instrumentation-aws-lambda': { enabled: false },
      '@opentelemetry/instrumentation-net': { enabled: false },
    }),
  ],
  // pass a ton of propagators, hopping to get at least one working
  textMapPropagator: new CompositePropagator({
    propagators: [
      new W3CTraceContextPropagator(),
      new W3CBaggagePropagator(),
      new B3Propagator(),
      new B3Propagator({
        injectEncoding: B3InjectEncoding.MULTI_HEADER,
      }),
      new AWSXRayPropagator(),
    ],
  }),
});

export default otelSDK;

package.json

{
  "name": "project-name",
  "version": "0.0.1",
  "description": "",
  "author": "",
  "private": true,
  "license": "UNLICENSED",
  "scripts": {
    "build": "nest build",
    "format": "prettier --write \"src/**/*.ts\" \"test/**/*.ts\"",
    "start": "nest start",
    "start:dev": "nest start --watch",
    "start:debug": "nest start --debug --watch",
    "start:prod": "node dist/main",
    "lint": "eslint \"{src,apps,libs,test}/**/*.ts\" --fix"
  },
  "dependencies": {
    "@nestjs/axios": "^3.0.2",
    "@nestjs/common": "^10.0.0",
    "@nestjs/core": "^10.0.0",
    "@nestjs/platform-express": "^10.0.0",
    "@opentelemetry/api": "^1.7.0",
    "@opentelemetry/auto-instrumentations-node": "^0.41.0",
    "@opentelemetry/context-async-hooks": "^1.21.0",
    "@opentelemetry/core": "^1.21.0",
    "@opentelemetry/exporter-jaeger": "^1.21.0",
    "@opentelemetry/exporter-prometheus": "^0.48.0",
    "@opentelemetry/exporter-trace-otlp-http": "^0.48.0",
    "@opentelemetry/instrumentation-express": "^0.35.0",
    "@opentelemetry/instrumentation-http": "^0.48.0",
    "@opentelemetry/instrumentation-nestjs-core": "^0.34.0",
    "@opentelemetry/instrumentation-pino": "^0.35.0",
    "@opentelemetry/propagator-aws-xray": "^1.3.1",
    "@opentelemetry/propagator-b3": "^1.21.0",
    "@opentelemetry/resources": "^1.21.0",
    "@opentelemetry/sdk-metrics": "^1.18.0",
    "@opentelemetry/sdk-node": "^0.48.0",
    "@opentelemetry/sdk-trace-base": "^1.21.0",
    "@opentelemetry/semantic-conventions": "^1.21.0",
    "axios": "^1.6.7",
    "nestjs-pino": "^4.0.0",
    "pino-http": "^9.0.0",
    "pino-pretty": "^10.3.1",
    "reflect-metadata": "^0.1.13",
    "rxjs": "^7.8.1"
  },
  "devDependencies": {
    "@nestjs/cli": "^10.0.0",
    "@nestjs/schematics": "^10.0.0",
    "@nestjs/testing": "^10.0.0",
    "@types/express": "^4.17.17",
    "@types/jest": "^29.5.2",
    "@types/node": "^20.3.1",
    "@types/supertest": "^6.0.0",
    "@typescript-eslint/eslint-plugin": "^6.0.0",
    "@typescript-eslint/parser": "^6.0.0",
    "eslint": "^8.42.0",
    "eslint-config-prettier": "^9.0.0",
    "eslint-plugin-prettier": "^5.0.0",
    "jest": "^29.5.0",
    "prettier": "^3.0.0",
    "source-map-support": "^0.5.21",
    "supertest": "^6.3.3",
    "ts-jest": "^29.1.0",
    "ts-loader": "^9.4.3",
    "ts-node": "^10.9.1",
    "tsconfig-paths": "^4.2.0",
    "typescript": "^5.1.3"
  },
  "jest": {
    "moduleFileExtensions": [
      "js",
      "json",
      "ts"
    ],
    "rootDir": "src",
    "testRegex": ".*\\.spec\\.ts$",
    "transform": {
      "^.+\\.(t|j)s$": "ts-jest"
    },
    "collectCoverageFrom": [
      "**/*.(t|j)s"
    ],
    "coverageDirectory": "../coverage",
    "testEnvironment": "node"
  }
}

Relevant log output

Nest] 75265  - 02/09/2024, 3:25:49 PM     LOG [NestFactory] Starting Nest application...
[Nest] 75265  - 02/09/2024, 3:25:49 PM     LOG [InstanceLoader] AppModule dependencies initialized +8ms
[Nest] 75265  - 02/09/2024, 3:25:49 PM     LOG [InstanceLoader] LoggerModule dependencies initialized +0ms
[Nest] [RoutesResolver] AppController {/}:
[Nest] [RouterExplorer] Mapped {/, GET} route
[Nest] [RouterExplorer] Mapped {/hello, GET} route
[Nest] [RouterExplorer] Mapped {/world, GET} route
[Nest] [NestApplication] Nest application successfully started
[Nest] Application is running on: http://localhost:3002
[Nest] 
[Nest] Access: http://localhost:3002/
[Nest] Access: http://localhost:3002/hello
[Nest] Access: http://localhost:3002/world
[Nest] 
[Nest] [trace=4bf92f3577b34da6a3ce929d0e0e4736][AppController] [+] endpoint /hello - getHello()
[Nest] [trace=4bf92f3577b34da6a3ce929d0e0e4736][AppController] headers received are:
[Nest] [trace=7d30776891932e3bf935c22b3be120a6][AppController] [+] /getWorld - getWorld()
[Nest] [trace=7d30776891932e3bf935c22b3be120a6][AppController] headers received are:
[Nest] [trace=7d30776891932e3bf935c22b3be120a6] request completed
[Nest] [trace=4bf92f3577b34da6a3ce929d0e0e4736] request completed

[pichlermarc]

We currently don't have a node-based fetch instrumentation, so that's why there's no propagation.
Re-categorizing this as a feature-request.

[Lp-Francois]

oki good to know! I would be eager to contribute :)

[Lp-Francois]

for reference:

open-telemetry/opentelemetry-js-contrib#1951

[github-actions]

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.

[pichlermarc]

Closing this as the new undici instrumentation is now available: https://www.npmjs.com/package/@opentelemetry/instrumentation-undici

node-fetch uses undici under the hood so using this one should also enable you to propagate context using node-fetch 🙂