context-async-hooks throws unhandled exception with follow-redirects 1.13.3 dependency

[AKWolff037]

Please answer these questions before submitting a bug report.

What version of OpenTelemetry are you using?

0.18.2

What version of Node are you using?

12.18.4

Please provide the code you used to setup the OpenTelemetry SDK

const otelNode = require('@opentelemetry/node')
const registerInstrumentations = require('@opentelemetry/instrumentation').registerInstrumentations

const tracer = new otelNode.NodeTracerProvider()
registerInstrumentations({
    tracerProvider: tracer
})
tracer.register()
const axios = require('axios')
const makeTheCall = async () => {
    const axiosConfig = {
        url: 'http://www.google.com',
        method: 'GET',
        timeout: '10'
    }
    const result = await axios(axiosConfig).catch((e) => {
        console.log('got an error in the call', e.code)
        return null
    })
    console.log('Result: ', result)
}
makeTheCall().then(() => {
    setTimeout(() => {
        console.log('Call finished successfully!')
    }, 1000)    
}).catch((e) => {
    console.log('Call failed completely', e)
})

/*
$ node .
got an error in the call ECONNABORTED
Result:  null
events.js:292
      throw er; // Unhandled 'error' event
      ^

Error: socket hang up
    at connResetException (internal/errors.js:610:14)
    at Socket.socketCloseListener (_http_client.js:400:25)
    at Socket.emit (events.js:327:22)
    at TCP.<anonymous> (net.js:674:12)
    at TCP.callbackTrampoline (internal/async_hooks.js:120:14)
Emitted 'error' event on Writable instance at:
    at ClientRequest.eventHandlers.<computed> (D:\Git\test-for-bugs\node_modules\follow-redirects\index.js:13:24)
    at D:\Git\test-for-bugs\node_modules\@opentelemetry\context-async-hooks\build\src\AbstractAsyncHooksContextManager.js:43:55
    at AsyncHooksContextManager.with (D:\Git\test-for-bugs\node_modules\@opentelemetry\context-async-hooks\build\src\AsyncHooksContextManager.js:42:23)
    at ClientRequest.contextWrapper (D:\Git\test-for-bugs\node_modules\@opentelemetry\context-async-hooks\build\src\AbstractAsyncHooksContextManager.js:43:32)
    at ClientRequest.emit (events.js:327:22)
    at Socket.socketCloseListener (_http_client.js:400:11)
    at Socket.emit (events.js:327:22)
    at TCP.<anonymous> (net.js:674:12)
    at TCP.callbackTrampoline (internal/async_hooks.js:120:14) {
  code: 'ECONNRESET'
}
*/

The same result with everything commented out before const axios

$ node .
got an error in the call ECONNABORTED
Result:  null
Call finished successfully!

What did you do?

If possible, provide a recipe for reproducing the error.

Update dependency graph to use follow-redirects version 1.13.3 instead of earlier versions.

What did you expect to see?

The same behavior as when follow-redirects version 1.13.1 was installed.

What did you see instead?

The tracer threw an uncaught exception.

Additional context

events.js:292
      throw er; // Unhandled 'error' event
      ^

Error: socket hang up
    at connResetException (internal/errors.js:610:14)
    at Socket.socketCloseListener (_http_client.js:400:25)
    at Socket.emit (events.js:327:22)
    at TCP.<anonymous> (net.js:674:12)
    at TCP.callbackTrampoline (internal/async_hooks.js:120:14)
Emitted 'error' event on Writable instance at:
    at ClientRequest.eventHandlers.<computed> (D:\Git\test-for-bugs\node_modules\follow-redirects\index.js:13:24)
    at D:\Git\test-for-bugs\node_modules\@opentelemetry\context-async-hooks\build\src\AbstractAsyncHooksContextManager.js:43:55
    at AsyncHooksContextManager.with (D:\Git\test-for-bugs\node_modules\@opentelemetry\context-async-hooks\build\src\AsyncHooksContextManager.js:42:23)
    at ClientRequest.contextWrapper (D:\Git\test-for-bugs\node_modules\@opentelemetry\context-async-hooks\build\src\AbstractAsyncHooksContextManager.js:43:32)
    at ClientRequest.emit (events.js:327:22)
    at Socket.socketCloseListener (_http_client.js:400:11)
    at Socket.emit (events.js:327:22)
    at TCP.<anonymous> (net.js:674:12)
    at TCP.callbackTrampoline (internal/async_hooks.js:120:14) {
  code: 'ECONNRESET'
}

Add any other context about the problem here.

It appears it was caused by this change, which was made to the follow-redirects module in order stop potential memory leaks with failed calls. follow-redirects/follow-redirects#152

All dependencies installed for above test/reproduction script:

  "dependencies": {
    "@opentelemetry/api": "^1.0.0-rc.0",
    "@opentelemetry/core": "^0.18.2",
    "@opentelemetry/instrumentation": "^0.18.2",
    "@opentelemetry/node": "^0.18.2",
    "@opentelemetry/plugin-http": "^0.18.2",
    "@opentelemetry/plugin-https": "^0.18.2",
    "axios": "^0.21.1"
  }

[Flarna]

Not sure if this changes anything but looking into your dependencies it seems you mix incompatible versions of API and SDK/Instrumentations (see compatibility matrix).

Update: It doesn't change anything.

[Flarna]

I think this is a problem in follow-redirects. I created follow-redirects/follow-redirects#159.
I'm curious which feedback we get there.

[dyladan]

Not much feedback so far. Is there a way we can work around it for now?

[dyladan]

@AKWolff037 what makes you think this is an issue with the context-async-hooks package? Is it just because you see it in the stack traces? I think this is more likely an issue with the http instrumentation.

[AKWolff037]

@AKWolff037 what makes you think this is an issue with the context-async-hooks package? Is it just because you see it in the stack traces? I think this is more likely an issue with the http instrumentation.

The issue is almost certainly caused by the follow-redirects update, but it's also causing an unhandled exception to be thrown from opentelemetry which crashes the application - and goes against the spec.

The best fix is for follow-redirects to get updated again, but if a dependency update can cause opentelemetry to crash the application then that's a major concern that should probably be handled on the opentelemetry side - imo.

[dyladan]

@AKWolff037 what makes you think this is an issue with the context-async-hooks package? Is it just because you see it in the stack traces? I think this is more likely an issue with the http instrumentation.

The issue is almost certainly caused by the follow-redirects update, but it's also causing an unhandled exception to be thrown from opentelemetry which crashes the application - and goes against the spec.

The best fix is for follow-redirects to get updated again, but if a dependency update can cause opentelemetry to crash the application then that's a major concern that should probably be handled on the opentelemetry side - imo.

I wasn't arguing that it was an issue with opentelemetry. I was wondering what pointed you specifically at the context async hooks package rather than a different opentelemetry package.

[AKWolff037]

Ah. Yeah basically only the stack trace :)

[Flarna]

I think the problem is in AbstractAsyncHooksContextManager#_patchRemoveAllListeners.

Actual there are two problems:

• If removeAllListeners() is called without arguments event is undefined and as a result nothing is removed here instead everything
• calling the original here results in arguments.length === 1 there and as a result again nothing is removed.

A fix should be simple and I can create a PR later. If someone else is faster feel free to start.

Please note that this will only fix the crash here which is caused by not removing the "error" event. But it will uncover another issue that span is never ended - because this happens in close event which will be removed then by follow-redirects.

[dyladan]

Never ending span is not ideal, but is better than crash. I think non-ending spans will not leak memory so we should be ok there too.