AbstractAsyncHooksContextManager breaks .removeListener for handlers which was added with .once

[ghisguth]

What version of OpenTelemetry are you using?

latest

@opentelemetry/context-async-hooks 1.2.0

What version of Node are you using?

v16.14.0

Please provide the code you used to setup the OpenTelemetry SDK

Code uses req.once("abort", handler) and after successful processing it calls req.removeListener("abort", handler). Code works without OTEL. With OTEL removeListener is not removing handler and application crashes with unhandled error.

What did you do?

I have created unit tests which reproduces the problem: #2970

Once bug is fixed, it should pass the test.

Code

      it('should remove event handler enabled by .once using removeAllListener (when enabled)', () => {
        const ee = new EventEmitter();
        const context = ROOT_CONTEXT.setValue(key1, 1);
        const patchedEE = contextManager.bind(context, ee);
        const handler = () => { };
        patchedEE.once('test', handler);
        assert.strictEqual(patchedEE.listeners('test').length, 1);
        patchedEE.removeListener('test', handler);
        assert.strictEqual(patchedEE.listeners('test').length, 0);
      });

What did you expect to see?

Test should pass. Handler should be removed if we call once, and then removeListener.

What did you see instead?

Handler is not removed from listeners.

Additional context

#2970

[dyladan]

I have been looking into this and I think this might be an issue within the events standard library module itself. I have come up with a very minimal reproduction for this and I'm at a complete loss for what we can do aside from simply not supporting once

Minimal repro:

const { EventEmitter } = require("events");
const assert = require("assert")

// global map because who cares for the example
const map = {};

function wrapFunction(target) {
    return function (...args) {
        target.apply(this, args);
    };
}

function patchAddListener(original) {
    return function (event, listener) {
        let listeners = map[event];
        if (listeners === undefined) {
            listeners = {}
            map[event] = listeners;
        }
        const patchedListener = wrapFunction(listener);
        listeners[listener] = patchedListener;
        return original.call(this, event, patchedListener);
    }
}

function patchOff(original) {
    return function (event, listener) {
        const listeners = map[event];
        if (listeners === undefined) {
            return original.call(this, event, listener);
        }
        const patchedListener = listeners[listener];
        return original.call(this, event, patchedListener || listener);
    }
}

ee = new EventEmitter();

// Comment this line to fix the assertions
ee.on = patchAddListener(ee.on);
ee.once = patchAddListener(ee.once);
ee.removeListener = patchOff(ee.removeListener);

const handler = () => { console.log('handler') };
ee.once('test', handler);
assert.strictEqual(ee.listeners('test').length, 1);
ee.removeListener('test', handler);
assert.strictEqual(ee.listeners('test').length, 0);

The only way around this I can think of is for us to completely reimplement once on our own instead of relying on the default once behavior, but I am extremely hesitant to do that as I think it is likely quite error prone.

[dyladan]

/cc @Flarna since you're probably our best expert on node internals

[dyladan]

I think I may have discovered the issue.

1. user calls once
2. we wrap their function (wrapper1) and call the original once
3. original once wraps (onceWrapper) and calls on (which is ours)
4. we wrap the function again (wrapper2) and call the original on
5. user calls removeListener
6. we look up our wrapper (wrapper1) by a map and call the original removeListener with wrapper1
7. the original removeListener attempts to check if the function passed matches any function in the list of listeners or if any function in the list of listeners is a onceWrapper but it isn't because we've wrapped it again wrapper2

Proof of the theory:

const { EventEmitter } = require("events");
const assert = require("assert")

const patchedFnSymbol = Symbol('OpenTelemetry patched function');

function wrapFunction(target) {
    if (typeof target !== 'function') {
        return target;
    }

    if (target[patchedFnSymbol]) {
        // this line is never called because when `on` is called, it is called with the `onceWrapper` not with our wrapper
        console.log('this is already wrapped')
        return target[patchedFnSymbol];
    }

    console.log('wrapping', target)

    const patchedFn = function patchedFunction(...args) {
        console.log('this function is wrapped');
        target.apply(this, args);
    };

    target[patchedFnSymbol] = patchedFn;
    return patchedFn
}

function getWrapper(target) {
    if (typeof target !== 'function' || typeof target[patchedFnSymbol] !== 'function') {
        return target;
    }

    return getWrapper(target[patchedFnSymbol]);
}

function patchAddListener(ee, name) {
    const original = ee[name]
    const wrapper = function (event, listener) {
        if (listener && typeof listener == 'object') {
            if (typeof listener.listener == 'function') {
                listener = listener.listener;
            }
        }

        const patchedListener = wrapFunction(listener);
        console.log(`calling original ${name} with`, patchedListener);
        return original.call(this, event, patchedListener);
    }

    ee[name] = wrapper;
}

function patchRemoveListener(original) {
    return function (event, listener) {
        const wrapper = getWrapper(listener);
        console.log('calling original removeListener with', wrapper);
        return original.call(this, event, wrapper);
    }
}

ee = new EventEmitter();

// Comment this line to fix the assertions
patchAddListener(ee, 'on');
patchAddListener(ee, 'once');
ee.removeListener = patchRemoveListener(ee.removeListener);

const handler = () => { console.log('handler') };
ee.once('test', handler);
assert.strictEqual(ee.listeners('test').length, 1);
ee.removeListener('test', handler);
assert.strictEqual(ee.listeners('test').length, 0);

Console output:

➜  testbed node event_repro.js
wrapping [Function: handler]
calling original once with [Function: patchedFunction]
wrapping [Function: bound onceWrapper] { listener: [Function: patchedFunction] }
calling original on with [Function: patchedFunction]
calling original removeListener with [Function: patchedFunction]
assert.js:118
  throw new AssertionError(obj);
  ^

[dyladan]

in wrapFunction we can check if the input target is a onceWrapper by checking if the name is "bound onceWrapper"

const { EventEmitter } = require("events");
const assert = require("assert")

const patchedFnSymbol = Symbol('OpenTelemetry patched function');

function wrapFunction(target) {
    if (typeof target !== 'function') {
        return target;
    }

    // IMPORTANT LINE HERE
    if (target.name === 'bound onceWrapper') {
        return target;
    }

    if (target[patchedFnSymbol]) {
        // this line is never called because when `on` is called, it is called with the `onceWrapper` not with our wrapper
        console.log('this is already wrapped')
        return target[patchedFnSymbol];
    }

    console.log('wrapping', target)

    const patchedFn = function patchedFunction(...args) {
        console.log('this function is wrapped');
        target.apply(this, args);
    };

    target[patchedFnSymbol] = patchedFn;
    return patchedFn
}

function getWrapper(target) {
    if (typeof target !== 'function' || typeof target[patchedFnSymbol] !== 'function') {
        return target;
    }

    return getWrapper(target[patchedFnSymbol]);
}

function patchAddListener(ee, name) {
    const original = ee[name]
    const wrapper = function (event, listener) {
        if (listener && typeof listener == 'object') {
            if (typeof listener.listener == 'function') {
                listener = listener.listener;
            }
        }

        const patchedListener = wrapFunction(listener);
        console.log(`calling original ${name} with`, patchedListener);
        return original.call(this, event, patchedListener);
    }

    ee[name] = wrapper;
}

function patchRemoveListener(original) {
    return function (event, listener) {
        const wrapper = getWrapper(listener);
        console.log('calling original removeListener with', wrapper);
        return original.call(this, event, wrapper);
    }
}

ee = new EventEmitter();

// Comment this line to fix the assertions
patchAddListener(ee, 'on');
patchAddListener(ee, 'once');
ee.removeListener = patchRemoveListener(ee.removeListener);

const handler = () => { console.log('handler') };
ee.once('test', handler);
assert.strictEqual(ee.listeners('test').length, 1);
ee.removeListener('test', handler);
assert.strictEqual(ee.listeners('test').length, 0);

console output:

wrapping [Function: handler]
calling original once with [Function: patchedFunction]
calling original on with [Function: bound onceWrapper] { listener: [Function: patchedFunction] }
calling original removeListener with [Function: patchedFunction]

[dyladan]

If anybody knows a better way to check if the function is a bound onceWrapper please tell me

[dyladan]

Here is the original implementation for once:

function onceWrapper() {
  if (!this.fired) {
    this.target.removeListener(this.type, this.wrapFn);
    this.fired = true;
    if (arguments.length === 0)
      return this.listener.call(this.target);
    return this.listener.apply(this.target, arguments);
  }
}

function _onceWrap(target, type, listener) {
  const state = { fired: false, wrapFn: undefined, target, type, listener };
  const wrapped = onceWrapper.bind(state);
  wrapped.listener = listener;
  state.wrapFn = wrapped;
  return wrapped;
}

/**
 * Adds a one-time `listener` function to the event emitter.
 * @param {string | symbol} type
 * @param {Function} listener
 * @returns {EventEmitter}
 */
EventEmitter.prototype.once = function once(type, listener) {
  checkListener(listener);

  this.on(type, _onceWrap(this, type, listener));
  return this;
};

[dyladan]

Created #3122 and #3123 to fix this problem. Each of them solves the problem on its own it is just a matter of what do we think would be more robust (or merge both)

[Flarna]

/cc @Flarna since you're probably our best expert on node internals

Sorry for the late answer, was on vacation.

I think special handling of once is needed somewhere. One option is to detect on calls coming from once another option is maybe to implement once wrapper in way that it bypasses our on wrapper.

The really hard task is implement it in a way that it still works (and doesn't break others) if there are other context managers (e.g. APM tools,...) used at the same time which also patch once and on and apply their own logic.

Note that besides removeListener there might be other APIs where side effects are visible: listeners and rawListeners. But I doubt that it is possible to implement a context manager which is "invisible" if one looks in detail.