Can not execute the operation on ended Span opentelemetry-instrumentation-http

What version of OpenTelemetry are you using?

0.18.0

What version of Node are you using?

tested 12 and 14

Please provide the code you used to setup the OpenTelemetry SDK

export class SDK {
    static setup(): void {
        diag.setLogger(new DiagConsoleLogger(), logLevel[config.loggerLevel] || DEFAULT_LOG_LEVEL);

        const provider: NodeTracerProvider = new NodeTracerProvider();
        provider.register();

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

What did you do?

http request call

What did you expect to see?

Span created and closed with all data set

What did you see instead?

Can not execute the operation on ended Span

Additional context

That happens because request close event fired before the response end event.

socketCloseListener might emits close event before readable steam ended.

Due to it, http instrumentation going to close Span https://github.com/open-telemetry/opentelemetry-js/blob/357ec92e95e03b4d2309c65ffb17d06105985628/experimental/packages/opentelemetry-instrumentation-http/src/http.ts#L344

Response end event will set Span status, that will lead to ended span issue. https://github.com/open-telemetry/opentelemetry-js/blob/357ec92e95e03b4d2309c65ffb17d06105985628/experimental/packages/opentelemetry-instrumentation-http/src/http.ts#L317

It might be tricky to reproduce, as I see it relay on response content size. In most cases, request close event is fired after response end. I was lucky to reproduce it. There is some logic in a stream implementation.

Possible solution

Request end event might be changed with a close event. https://github.com/open-telemetry/opentelemetry-js/blob/357ec92e95e03b4d2309c65ffb17d06105985628/experimental/packages/opentelemetry-instrumentation-http/src/http.ts#L307

Response close event will be fired after request close by socketCloseListener implementation. Lines: 389 and 393

Related items

https://github.com/open-telemetry/opentelemetry-js/pull/2126