Context is lost when using async generators

[SoftMemes]

Please answer these questions before submitting a bug report.

What version of OpenTelemetry are you using?

Tested on 1.1.0, 1.1.1, 1.2.0 with 0.28 of contrib

What version of Node are you using?

v16.13.2

Please provide the code you used to setup the OpenTelemetry SDK

As per example on https://github.com/open-telemetry/opentelemetry-js with addition of registering a custom instrumentation.

What did you do?

I am attempting to use open telemetry together with a custom instrumentation for tracing (for nice-grpc). I have based my code very closely on the existing grpc instrumentation and can successfully record spans and see them appear on the console or in Zipkin when configured to use it.

However, I also want to capture trace id in my logs. I have tried the built in winston instrumentation, as well as custom code, all relying on trace.getSpan(context.active()) to get the current span (and from there the ids).

No matter where or how I call it however, trace.getSpan(context.active()) returns undefined. This is true also within my custom instrumentation just after having set a new context or created a new span.

I also get no information about the current span from the winston integration (which from the source code, relies on the same call).

What did you expect to see?

The current span being returned from trace.getSpan(context.active())

What did you see instead?

trace.getSpan(context.active()) always returns undefined.

[Flarna]

Please provide a reproducer showing how you setup otel and how you set the span as active on context.

Does trace.getSpan(context.active()) work for you e.g. withing an incoming HTTP request if you use the HttpInstrumentation?

[SoftMemes]

@Flarna thank you for your reply, I've now narrowed this issue down to specifically dealing with async generator functions.

I'm creating a middleware for nice-grpc which relies on async generators. While I've used context.with() on the invocation of the wrapped generator function, this is not by itself enough to automatically pass on the context as code is only run in response to a later call to "next". This appears to be a known limitation with async hooks / async local storage as the "next" call is strictly not related to the call that instantiated a generator.

I've been able to work around the problem with the following helper for running async generators within a context

async function* asyncGeneratorWithContext<T, TReturn, TNext>(
  operationContext: Context,
  operation: () => AsyncGenerator<T, TReturn, TNext>,
): AsyncGenerator<T, TReturn, TNext> {
  const generator = context.with(operationContext, operation)
  const next = context.bind(operationContext, generator.next.bind(generator))

  let result: IteratorResult<T, TReturn> = await next()

  while (!result.done) {
    const nextParam = yield result.value
    result = await next(nextParam)
  }

  // HACK, see https://github.com/microsoft/TypeScript/issues/48966
  return result.value as any
}

I've welcome any feedback on whether this looks like a reasonable fix / workaround.

[vmarchaud]

I might be wrong but i don't think the low level promise hook covers generators on the V8 side and i don't think its covered by async hooks itself in Node either. So i think the workaround is the only reasonable solution for now

[Flarna]

The corresponding issue in node repo: https://github.com/nodejs/node/issues/42237

[dyladan]

Since this is a bug in node itself and not OTel is there anything we can do here? Should we close this issue or keep it around? Or maybe create a new issue to document the shortcoming?

[aikoven]

I solved it in nice-grpc-opentelemetry by binding each method of an async iterator individually:

import {context, Context} from '@opentelemetry/api';

export function bindAsyncGenerator<T = unknown, TReturn = any, TNext = unknown>(
  ctx: Context,
  generator: AsyncGenerator<T, TReturn, TNext>,
): AsyncGenerator<T, TReturn, TNext> {
  return {
    next: context.bind(ctx, generator.next.bind(generator)),
    return: context.bind(ctx, generator.return.bind(generator)),
    throw: context.bind(ctx, generator.throw.bind(generator)),

    [Symbol.asyncIterator]() {
      return bindAsyncGenerator(ctx, generator[Symbol.asyncIterator]());
    },
  };
}

[dyladan]

We should probably document this somewhere

[github-actions[bot]]

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.

[github-actions[bot]]

This issue was closed because it has been stale for 14 days with no activity.