Axios HTTP backend call generates Opentelemetry span that is not correlated with the parent span

Question

I'm trying to perform manual instrumentation in NodeJs (v18.16.1) using opentelemetry. The scenario is very simple, I'm making an axios HTTP call to a dummy JSON API and I want to collect the generated trace.

Dependencies:

  "@opentelemetry/api": "^1.3.0",
  "@opentelemetry/auto-instrumentations-node": "^0.38.0",
  "@opentelemetry/context-async-hooks": "^1.15.0",
  "@opentelemetry/instrumentation": "^0.41.0",
  "@opentelemetry/instrumentation-http": "^0.35.1",
  "@opentelemetry/resources": "^1.9.1",
  "@opentelemetry/sdk-metrics": "^1.9.1",
  "@opentelemetry/sdk-node": "^0.35.1",
  "@opentelemetry/sdk-trace-base": "^1.9.1",
  "@opentelemetry/sdk-trace-node": "^1.9.1",
  "@opentelemetry/semantic-conventions": "^1.9.1",
  "axios": "^1.4.0"

The setup is the following:

otel/tracing.js file:

const opentelemetry = require('@opentelemetry/api')
const { Resource } = require("@opentelemetry/resources");
const { SemanticResourceAttributes } = require("@opentelemetry/semantic-conventions");
const { NodeTracerProvider } = require("@opentelemetry/sdk-trace-node");
const { registerInstrumentations } = require("@opentelemetry/instrumentation");
const { ConsoleSpanExporter, SimpleSpanProcessor} = require("@opentelemetry/sdk-trace-base");
const { AsyncHooksContextManager } = require('@opentelemetry/context-async-hooks');
const {
    HttpInstrumentation,
} = require("@opentelemetry/instrumentation-http");


const contextManager = new AsyncHooksContextManager();

contextManager.enable()

opentelemetry.context.setGlobalContextManager(contextManager)


registerInstrumentations({
    instrumentations: [new HttpInstrumentation()],
});

const resource =
    Resource.default().merge(
        new Resource({
            [SemanticResourceAttributes.SERVICE_NAME]: 'poc-otel-tracing',
            [SemanticResourceAttributes.SERVICE_VERSION]: "0.1.0",
        })
    );

const provider = new NodeTracerProvider({
    resource: resource
});

const exporter = new ConsoleSpanExporter();
const processor = new SimpleSpanProcessor(exporter);


provider.addSpanProcessor(processor);

provider.register();

// process.on('exit', function() {
//     void exporter.shutdown()
// });

src/index.ts file

import axios from "axios";

import opentelemetry, {Span} from "@opentelemetry/api";
const tracer = opentelemetry.trace.getTracer('poc-otel-tracing');

const API_BASE_URL = 'https://jsonplaceholder.typicode.com/posts';

const func = async() => {

    const rootSpan = tracer.startSpan('root-span')
    await apiCall(rootSpan)
    rootSpan.end()
}

const apiCall = async (parentSpan: Span) => {

    const ctx = opentelemetry.trace.setSpan(opentelemetry.context.active(), parentSpan)

    const childSpan = tracer.startSpan('api-call', undefined, ctx)

    try {
        await axios.get(API_BASE_URL);
    } catch (e) {
        childSpan.recordException(e);
    }

    childSpan.end()
}

void func()

Note that I'm using typescript, and I'm using npm run build && node --require "./otel/tracing.js" dist/index.js to run the compiled JS and to require the otel/tracing.js script.

The console output is the following:

{
  traceId: '15b261f7332feb1fdc79cff5a280529b',
  parentId: undefined,
  traceState: undefined,
  name: 'HTTPS GET',
  id: '477643c3a9536749',
  kind: 2,
  timestamp: 1690206903281000,
  duration: 128485,
  attributes: {
    'http.url': 'https://jsonplaceholder.typicode.com/posts',
    'http.method': 'GET',
    'http.target': '/posts',
    'net.peer.name': 'jsonplaceholder.typicode.com',
    'http.host': 'jsonplaceholder.typicode.com:443',
    'net.peer.ip': '172.64.162.6',
    'net.peer.port': 443,
    'http.status_code': 200,
    'http.status_text': 'OK',
    'http.flavor': '1.1',
    'net.transport': 'ip_tcp'
  },
  status: { code: 0 },
  events: [],
  links: []
}
{
  traceId: 'ba35dbc454728c2bbc5b30a435dec3bb',
  parentId: 'a3897743fb82276c',
  traceState: undefined,
  name: 'api-call',
  id: 'ec3d00cb4ad95d26',
  kind: 0,
  timestamp: 1690206903278000,
  duration: 136158,
  attributes: {},
  status: { code: 0 },
  events: [],
  links: []
}
{
  traceId: 'ba35dbc454728c2bbc5b30a435dec3bb',
  parentId: undefined,
  traceState: undefined,
  name: 'root-span',
  id: 'a3897743fb82276c',
  kind: 0,
  timestamp: 1690206903278000,
  duration: 136633,
  attributes: {},
  status: { code: 0 },
  events: [],
  links: []
}

I don't understand why the span created for the axios http call is not correlated with the 'api-call' span (i.e. the span generated by axios should have 'api-call' as parent span) and should be part of the same trace.

Here's the output I would expect:

{
  traceId: 'ba35dbc454728c2bbc5b30a435dec3bb',
  parentId: 'a3897743fb82276c',
  traceState: undefined,
  name: 'HTTPS GET',
  id: '477643c3a9536749',
  kind: 2,
  timestamp: 1690206903281000,
  duration: 128485,
  attributes: {
    'http.url': 'https://jsonplaceholder.typicode.com/posts',
    'http.method': 'GET',
    'http.target': '/posts',
    'net.peer.name': 'jsonplaceholder.typicode.com',
    'http.host': 'jsonplaceholder.typicode.com:443',
    'net.peer.ip': '172.64.162.6',
    'net.peer.port': 443,
    'http.status_code': 200,
    'http.status_text': 'OK',
    'http.flavor': '1.1',
    'net.transport': 'ip_tcp'
  },
  status: { code: 0 },
  events: [],
  links: []
}
{
  traceId: 'ba35dbc454728c2bbc5b30a435dec3bb',
  parentId: 'a3897743fb82276c',
  traceState: undefined,
  name: 'api-call',
  id: 'ec3d00cb4ad95d26',
  kind: 0,
  timestamp: 1690206903278000,
  duration: 136158,
  attributes: {},
  status: { code: 0 },
  events: [],
  links: []
}
{
  traceId: 'ba35dbc454728c2bbc5b30a435dec3bb',
  parentId: undefined,
  traceState: undefined,
  name: 'root-span',
  id: 'a3897743fb82276c',
  kind: 0,
  timestamp: 1690206903278000,
  duration: 136633,
  attributes: {},
  status: { code: 0 },
  events: [],
  links: []
}

Could someone help me understand what I'm doing wrong? Thanks in advance!

score 0 · Answer 1 · answered Aug 16 '23 at 12:44

The cause: The trace information is not propagated to the request (via axios in your case)

The fix: extract trace info from the context, and inject it to request headers

const traceHeaders = {};
// inject context to trace headers for propagtion to the next service
propagation.inject(context.active(), traceHeaders);
// pass the trace headers to your request
const config = {
  headers: traceHeaders
};
await axios.get(API_BASE_URL, config);

Hope it works for you. In case you need, I have the detailed setup documented here, with a link to a complete source

Axios HTTP backend call generates Opentelemetry span that is not correlated with the parent span

1 Answers1