time_callbacks.js

/**
 * Searches the functions defined in the `fns` param and replaces any arguments
 * that have the name 'callback' or 'cb' with a wrapped callback that will
 * record how long it took for the callback to be invoked and how many times
 * it was called. To view the information recorded call window.timeDump`name`();
 *
 *
 * @param {string} name Unique name for the stats.
 * @param {Object} fns All the functions that will have callbacks wrapped.
 * @return {Object} An object with the same keys as the `fns` object, but with
 *                  wrapped callbacks.
 */
function timeCallbacks(name, fns) {
  var STRIP_COMMENTS = /((\/\/.*$)|(\/\*[\s\S]*?\*\/))/mg;
  var ARGUMENT_NAMES = /([^\s,]+)/g;
  function getParamNames(func) {
    var fnStr = func.toString().replace(STRIP_COMMENTS, '')
    var result = fnStr.slice(fnStr.indexOf('(')+1, fnStr.indexOf(')')).match(ARGUMENT_NAMES)
    if(result === null)
       result = []
    return result
  }

  var STR_PAD_LEFT = 1;
  var STR_PAD_RIGHT = 2;
  var STR_PAD_BOTH = 3;
  function pad(str, len, pad, dir) {
    if (typeof(len) == "undefined") { var len = 0; }
    if (typeof(pad) == "undefined") { var pad = ' '; }
    if (typeof(dir) == "undefined") { var dir = STR_PAD_RIGHT; }
    if (len + 1 >= str.length) {
      switch (dir) {
      case STR_PAD_LEFT:
          str = Array(len + 1 - str.length).join(pad) + str;
      break;
      case STR_PAD_BOTH:
          var right = Math.ceil((padlen = len - str.length) / 2);
          var left = padlen - right;
          str = Array(left+1).join(pad) + str + Array(right+1).join(pad);
      break;
      default:
          str = str + Array(len + 1 - str.length).join(pad);
      break;
      } // switch
    }
    return str;
  }

  var time = {};
  var padKey = 0;
  var ret = {};

  window['timeDump' + name] = function() {
    var totalTime = 0;
    console.log(name + ' timing:')
    for (var key in time) {
      console.log(pad(key, padKey) +
        ' time: ' + pad(Math.round(time[key].time) + '', 4, ' ', STR_PAD_LEFT) +
        ' calls: ' + pad(time[key].calls + '', 4, ' ', STR_PAD_LEFT) +
        ' longest: ' + pad(Math.round(time[key].longest) + '', 4, ' ', STR_PAD_LEFT));
      totalTime += time[key].time;
    }
    console.log('Total time in ' + name + ':' + Math.round(totalTime));
  };

  for (var key in fns) {
    ret[key] = fns[key];
    var params = getParamNames(ret[key]);
    var cbIndex = params.indexOf('cb');
    if (cbIndex === -1) {
      var cbIndex = params.indexOf('callback');
      if (cbIndex === -1) {
        continue;
      }
    }
    time[key] = {
      time: 0,
      calls: 0,
      longest: 0
    };
    padKey = Math.max(key.length, padKey);
    console.log('Logging time for ' + name + ' ' + key + '()');
    ret[key] =
      (function(fn, key, cbIndex) {
        return function() {
          var start = window.performance.now();
          // Store the original callback.
          var cb = arguments[cbIndex];
          if (!cb) {
            return;
          }
          // Replace the callback with our own.
          arguments[cbIndex] = function() {
            var end = window.performance.now();
            time[key].time += end - start;
            time[key].calls++;
            time[key].longest = Math.max(time[key].longest, end - start);
            cb.apply(null, arguments);
          };
          // Invoke the original function.
          fn.apply(null, arguments);
        }
      })(ret[key], key, cbIndex);
  }
  return ret;
}