dougwilson/nodejs-depd

deprecate.function's eval is slow

Closed this issue · 9 comments

I noticed that when I wrapped a function in deprecate.function() in my library, my benchmarks took a big hit, dropping ~62%. Changing my use to be an empty function with deprecate() inside brought my speed back to normal.

The important part: this slow down occured even without that function be executed. It simply existing slow things down.

Looking in the source, it looks like the goal is to keep the arity the same. Did you find changing the arity for a deprecated function caused programs to break? I'd vote for not worrying about it.

However, if it is a big deal, then I'd suggest instead having several wrapArity1(fn), wrapArity2(fn), and so forth, up to... 6? 10? It could be small as well.

Did you find changing the arity for a deprecated function caused programs to break?

There are dumb interfaces that depend on arity, for example expressjs-style middlewares need their arities.

However, if it is a big deal, then I'd suggest instead having several wrapArity1(fn), wrapArity2(fn), and so forth, up to... 6? 10? It could be small as well.

No, the code generation can handle that. I'll definitely look into the issue. Do you know what is causing the slow down? How would I make something that would implement an arity differently? Basically the wrap tries to make the deprecated function look as close as possible to the original: it keeps fn.length the same, keeps arguments.length the same within the original function, etc.

I would welcome a suggestion or PR that meets these requirements, though :)

P.S. I'm going to start looking through how you are using depd in https://github.com/seanmonstar/intel to see how I can add some more convenience methods that may be more useful. So far it does look like what you are doing with __deprecatedCallback may be better off using deprecate directly instead of wrapping an empty function, but I'm still looking at your use-case and thinking about it.

I've been toying with this in a fork:

function wrapfunction(fn, message) {
  if (typeof fn !== 'function') {
    throw new TypeError('argument fn must be a function')
  }

  var deprecate = this
  var stack = getStack()
  var site = callSiteLocation(stack[1])

  site.name = fn.name

  var wrapper = arityWrappers[fn.length] || arityWrappers[0];
  return wrapper(function() {
    log.call(deprecate, message, site);
    return fn.apply(this, arguments);
  });
}

var arityWrappers = {
  '0': function arity0(fn) {
    return function() {
      return fn.apply(this, arguments);
    }
  },
  '1': function arity1(fn) {
    return function(a) {
      return fn.apply(this, arguments);
    }
  }
  '2': function arity2(fn) {
    return function(a, b) {
      return fn.apply(this, arguments);
    }
  }
  '3': function arity3(fn) {
    return function(a, b, c) {
      return fn.apply(this, arguments);
    }
  }
  '4': function arity4(fn) {
    return function(a, b, c, d) {
      return fn.apply(this, arguments);
    }
  }
}

Of course, it could extend out to a sane number of arguments (someone has a function with more than 10 arity, they should be shot?).

So far it does look like what you are doing with __deprecatedCallback may be better off using deprecate directly instead of wrapping an empty function, but I'm still looking at your use-case and thinking about it.

I have switched to using deprecate directly.

this.__deprecatedCallback = function deprecated() {
  deprecate('Handler.emit callback argument has been removed');
};
// in handle()
this.emit(record, this.__deprecatedCallback);

I need to pass a function argument, so people don't end up with undefined(). I can't pass deprecate itself, cause when my users execute the callback, it would just be generating a function, instead of leaving a warning.

Oh, by "use deprecate directly" I meant using to what you changed it to for now :)

So from your examples, it looks like the one-time eval is making all future calls slow?

Hrm, trying again with a different computer saw now speed lost. Differences between computes: Slow: Ubuntu 14.04, node v0.10.20. Fast: Windows 7, node v0.10.26.

process.versions says that v8 is v3.14.5.9 in both, which I'd think would be the reason for eval behaving differently...

It could just be my one computer gone crazy, as I can't repro on others (though, it continues to show on the Ubuntu.). I'd recommend closing unless it repros anywhere else.

I'd recommend closing unless it repros anywhere else.

The fact that you took the time to report it makes me want to at least look into it myself as well, because there could be something to it :) I don't want to close it just yet because there may well be an issue and I just haven't had the time to dig in yet.

@seanmonstar sorry for the long delay :( So I was able to examine it and there is a slow down. Using the wrapper is much slower per call than just calling deprecate(msg) within your function. There is a v8 trick to make them the same, though, which I'm adding. I added a simple benchmark as well so I could see that it actually made the calls faster.