web application profiling using code snippets

Dr. Gleb Bahmutov PhD

Kensho, Boston / NYC

 

 

Kensho app

User: Page is slow to load

Dev: How long does it take to load thE page?

solution 1:

Observe the Network panel

hint: use throttling

Solution 2: use chrome stats object

(function timeFirstPaint() {
  var fp = chrome.loadTimes().firstPaintTime - 
    chrome.loadTimes().startLoadTime;
  console.log('first paint: ' + fp);
}());

Copy / paste this code into the Chrome browser console

Pasting and running the same code over and over

there has got to be a better way

Chrome > DevTools > Sources > Snippets

How long does the page load?

Code Snippets

find Expensive images

Include missing styles

<h1>
    <i class="fa fa-flag"></i> Include missing styles 
    <i class="fa fa-heart"></i>
</h1>
(function addFontAwesomeCssLink() {
  var ss = document.createElement('link');
  ss.type = 'text/css';
  ss.rel = 'stylesheet';
  ss.href = '//maxcdn.bootstrapcdn.com/font-awesome/4.3.0/css/font-awesome.min.css';
  document.getElementsByTagName("head")[0].appendChild(ss);
}());

user: The app is slow

qa: Why is this action slow?

dev: how long does this javascript function run?

profiling javascript

// "app" code
function add(a, b) {
  return a + b;
}

// "user" code
function onClick() {
  console.log(add(2, 3));
}
// click!
// 5

within 0.1 second ?

time add function

// "app" code
function add(a, b) {
  var started = Number(new Date());
  var sum = a + b;
  var finished = Number(new Date());
  console.log('add took', 
    finished - started, 'ms');
  return sum;
}


// "user" code
function onClick() {
  console.log(add(2, 3));
}
// click!
// add took 10ms
// 5

time a function call via external overwrite

// "app" code
function add(a, b) {
  return a + b;
}


// "user" code
function onClick() {
  var started = Number(new Date());
  console.log(add(2, 3));
  var finished = Number(new Date());
  console.log('add took', 
    finished - started, 'ms');
}
// click!
// 5
// add took 10ms

wrap add from snippet

// "app" code
function add(a, b) {
  return a + b;
}

// "user" code
function onClick() {
  console.log(add(2, 3));
}
// code snippet
function profileAdd() {
  var _add = add;
  add = function profiledAdd(a, b) {
    var started = Number(new Date());
    var sum = _add(a, b);
    var finished = Number(new Date());
    console.log('add took', finished - started, 'ms');  
    return sum;
  };
}

wrap add from snippet might not work

// "app" code
function add(a, b) {
  return a + b;
}

// "user" code
function onClick() {
  var todo = add.bind(null, 2, 3);
  console.log(todo();
}
// code snippet
function profileAdd() {
  var _add = add;
  add = function profiledAdd(a, b) {
    ...
  };
}

Prefer wrapping methods

// "app" code
function add(a, b) {
  return a + b;
}
var calc = {
  add: add
};
// "user code"
function click(calc) {
  console.log(calc.add(2, 3));
}
// code snippet
var _add = calc.add;
calc.add = function () {
  console.log('adding', arguments);
  return _add.apply(calc, arguments);
}
// adding { '0': 2, '1': 3 }
// 5

Works in Angular

var selector = 'load';
var methodName = 'load';
var el = angular.element(document.getElementById(selector));
var scope = el.scope() || el.isolateScope();
var fn = scope[methodName];
var $timeout = el.injector().get('$timeout');
var $q = el.injector().get('$q');

scope[methodName] = function () {
  console.profile(name);
  console.time(name);

  // method can return a value or a promise
  var returned = fn();
  $q.when(returned).finally(function finishedMethod() {
    console.timeStamp('finished', methodName);

    $timeout(function afterDOMUpdate() {
      console.timeStamp('dom updated after', methodName);
      console.timeEnd(name);
      console.profileEnd();
    
      scope[methodName] = fn;
    }, 0);
  });
};

Works with prototypes

// tough cases like jQuery plugins
new Photostack(document.getElementById('photostack-3');
function profile(proto, methodName) {
    var originalMethod = proto[methodName];
    function restoreMethod() {
        console.timeEnd(methodName);
        proto[methodName] = originalMethod;
    } 
    proto[methodName] = function () {
        console.time(methodName);
        originalMethod.apply(this, arguments);
        restoreMethod();
    };
}
// where we want to profile Photostack.prototype._rotate
profile(Photostack.prototype, '_rotate');

js profiling example

my profiling rules

  • Profile in a "clean" browser

  • profile the actual application

  • optimize the top bottleneck first

Warning signs

  • try - catch blocks
  • modifying arguments
    • arguments = arguments || []
  • deleting / adding properties
    • delete foo.bar
  • calling function with different argument types
function add(a, b) {
    return a + b;
}
add(2, 3);
add('foo', 'bar');

Will not be optimized

  • eval
  • debug
  • long functions!

iojs 1.8.1 has more than 300 switches. A lot related to performance tuning

 

            iojs --v8-options
        

bad flame chart

good flame chart

time web worker

var worker = new Worker('worker.js');
function renderPrimes(primes) {
    var html = primes.map(primeToRow).join('\n');
    document.querySelector('#results').innerHTML = html;
}
worker.onmessage = function (e) {
    console.log('worker has finished');
    renderPrimes(e.data);
};
var primesApp = {
    worker: worker,
    findFirstPrimes: function (n) {
        console.log('finding first', n, 'primes');
        worker.postMessage({ cmd: 'primes', n: n });
    }
};
document.querySelector('#find').addEventListener('click', function () {
    var n = Number(document.querySelector('#n').value);
    primesApp.findFirstPrimes(n);
});

Need to time separate actions

var m1 = obj1[methodName1];
var m2 = obj2[methodName2];

obj1[methodName1] = function () {
    console.profile('separate');
    console.time('separate');
    m1.apply(obj1, arguments);
};

obj2[methodName2] = function () {
    console.timeEnd('separate');
    console.profileEnd('separate');
    m2.apply(obj2, arguments);
};

// call with
// obj1 = primesApp.worker, methodName1 = 'postMessage'
// obj2 = primesApp.worker, methodName2 = 'onmessage'  

Solution: wrap 2 steps into a single promise

// "user" code
webWorker.computePrimes(10000)
    .then(render);
// can be wrapped easily in a code snippet
var started = Number(new Date());
var result = webWorker.computePrimes(1000);
if (isPromise(result)) {
  return result.tap(function () {
    var finished = Number(new Date());
  });
} else {
  ... // time normally
}

What about timeline?

Layout profiler

Paint profiler

Weird behavior when trying to start from a code snippet (or browser console)

Observe paint

Can code snippets be updated?

YES, inception-style

Related

MUST watch: "DevTools: State of the Union" by @addyosmani

Q: How much to optimize?

A: Set a budget

  • page load time (text)

  • images appear

  • each click has visual action

  • browser is never locked

Q: How much to optimize?

A: Set a budget

  • page load time (text)

  • images appear

  • each click has visual action

  • browser is never locked

500ms

1000ms

100ms

30FPS

Q: how to stick to the performance budget as web app grows?

still searching for an answer

web application profiling using code snippets