Somehow callbacks are being multiply-wrapped

[kentonv]

I'm trying to debug a problem we're observing where we see a sudden explosion of fibers. The fibers are being created by meteor-promise. This problem is causing production outages on roughly an hourly basis.

What I've observed so far is that when the storm happens, the monkey-patched Promise.then() is being called and given inputs which are already wrapped by wrapCallback() from promise_server.js. I determined this by instrumenting wrapCallback() to console.log() the callback. This printed:

function (arg) {
  return fiberPool.run({
    callback: callback,
    args: [arg], // Avoid dealing with arguments objects.
    dynamics: dynamics,
    stackError: stackError,
  }, Promise);
};

That code is, of course, the function that wrapCallback() returns! This confused me for a while because initially I assumed I had done my instrumentation wrong and printed the wrong thing. But, no -- wrapCallback() is in fact receiving as input a callback that it itself created.

How could this happen? My first thought was that somehow makeCompatible() had been called multiple times, repeatedly re-patching the same Promise definition. Hence, each patch would call the next's .then(), adding additional redundant wrappers. However, when I put a console.log() at the top of this function, I only saw it printed once.

I tried sampling stack traces when wrapCallback() is called in this redundant way, and AFAICT they all look like this:

 at wrapCallback (/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:117:20)
 at Promise.then (/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:25:9)
 at process._tickCallback (node.js:369:9)

Unfortunately, I do not know why _tickCallback is directly calling Promise.then. Presumably this means someone registered Promise.then.bind(this, cb) as a next-tick callback?

My current theory is that this monkey-patching is exhibiting a variation of "fragile base class syndrome": I suspect the V8 promise implementation itself sometimes calls .then() internally, and is unexpectedly getting the monkey-patched version, and then going into some sort of loop.

I'm still working on this. Filing bug in case anyone knows anything.

[kentonv]

I added some instrumentation to detect when wrapCallback() receives as input a callback it created and it turns out this happens all the time.

But I can't figure out why. Stack traces indicate in all cases that Promise.then is either being called by process._tickCallback or is the top of the stack (I guess meaning it was called directly from C++ code).

It seems likely that somewhere in the node promise implementation it recursively calls this.then(), but I have yet to find where.

[kentonv]

I adjusted wrapCallback() to add a boolean flag alreadyWrapped to the function after wrapping, and so that when it is asked to wrap a callback that already has this flag, it simply returns the callback verbatim. This seems to have fixed the problem.

I still don't know why the callbacks are passing through .then() multiple times.