Skip to content

Instantly share code, notes, and snippets.

Show Gist options
  • Save pixelhandler/f01a1703721d31de0de1 to your computer and use it in GitHub Desktop.
Save pixelhandler/f01a1703721d31de0de1 to your computer and use it in GitHub Desktop.
Notes from talk at Ember-SC Feb '15 Meetup and EmberConf 2015 Minitalk: Measuring Performance with User Timing API

Measuring Performance with User Timing API

By Bill Heaton @pixelhandler

http://www.w3.org/TR/user-timing/#performancemark

See post: Measuring Performance with User Timing API, in an Ember Application

Measuring Performance with User Timing API

Bill Heaton | @pixelhandler

I help organize the Ember-SC Meetup. I blog at pixelhandler.com My experience developing Ember applications spans two years. I am employed by CrowdStrike, a cloud-based cybersecurity company with a focus on big data, threat intellegnce and incident response services. I work on their Falcon Host product.

Curiosity combined with a conviction that performance matters led me to experiment with measuring the speed of rendering templates in an Ember application.

Specifically, I wanted to capture the differences in template rendering speeds between Ember.js v1.8.1 with Handlebars v1.3 and Ember.js v1.10.0 with HTMLBars.

In case you missed it… HTMLBars is built on top of Handlebars; instead of compiling strings, HTMLBars creates document fragments with DOM constructors, e.g. the HTMLElement interface.

Where? And, when should I begin to measure the timings?

It seemed natural to use the [route's][routing] [renderTemplate] hook to mark the start time. [routing]: http://emberjs.com/guides/routing/ [renderTemplate]: http://emberjs.com/api/classes/Ember.Route.html#method_renderTemplate

What about capturing the measurment when the template is rendered?

In the same renderTemplate hook I can [schedule] capturing the final measurement in the [run loop's][run-loop] afterRender queue. [run-loop]: http://emberjs.com/guides/understanding-ember/run-loop/ [schedule]: http://emberjs.com/api/classes/Ember.run.html#method_schedule

Perhaps a simple mixin for routes can work for marking and measuring. Should I just use a timestamp or is there somthing better?

I found the [User Timing API][User Timing] (and a polyfill too). What is amazing about the [performance] measurements is that the API uses high-resolution timing with sub-millisecond resolution. (Sounds good to me Let's do this.) [User Timing]: http://www.w3.org/TR/user-timing [performance]: http://www.w3.org/standards/techs/performance#w3c_all [analyticsjs/user-timings]: https://developers.google.

Later I realized that Google Analytics can report on the [User Timings][analyticsjs/user-timings] in my app. [analyticsjs/user-timings]: https://developers.google.com/analytics/devguides/collection/analyticsjs/user-timings

To collect and measure the statistics for reporting on the render times in my Ember application, I created a mixin and used it in my routes, e.g. Index, Application, Post etc.

import Ember from 'ember';
import config from '../config/environment';
import { mark, measure, report } from '../utils/metrics';

export default Ember.Mixin.create({

  measurementName: Ember.required,

  reportUserTimings: true,

  renderTemplate(controller, model) {
    var beginName = 'mark_begin_rendering_' + this.measurementName;
    var endName = 'mark_end_rendering_' + this.measurementName;
    if (config.APP.REPORT_METRICS) {
      mark(beginName);
      Ember.run.scheduleOnce('afterRender', this, function() {
        mark(endName);
        measure(this.measurementName, beginName, endName);
        if (this.reportUserTimings) {
          report();
        }
      });
    }
    return this._super(controller, model);
  }

});

renderTemplate

  • The config can be set to report or not to report with
  • I can mark the beginning and the end of the rendering

renderTemplate

  • Optionally I can report the measurement after rendering or do that at some point later
  • Don't forget to call this._super()

I created the mark, measure, and report functions in a (utility) module that wraps the window.performance methods for [mark][performancemark] and [measure][performancemeasure] [performancemark]: http://www.w3.org/TR/user-timing/#performancemark [performancemeasure]: http://www.w3.org/TR/user-timing/#performancemeasure

Also I added functions for reporting the measurements; via an XHR request and also Google Analytics to report User Timings.

import Ember from 'ember';
import config from '../config/environment';

export function mark(name) {
  if (!window.performance || !window.performance.mark ) { return; }
  window.performance.mark(name);
}

export function measure(name, begin, end) {
  if (!window.performance || !window.performance.measure ) { return; }
  window.performance.measure(name, begin, end);
}

export function appReady() {
  return measureEntry('app_ready');
}

export function appUnload() {
  return measureEntry('app_unload');
}

export function pageView() {
  return measureEntry('page_view');
}

function measureEntry(name) {
  if (!window.performance || !window.performance.getEntriesByName ) { return; }
  var markName = name + '_now';
  mark(markName);
  if (window.performance.timing) {
    measure(name, 'navigationStart', markName);
  } else {
    measure(name, markName, markName);
  }
}

export function report() {
  if (!window.performance || !window.performance.getEntriesByType ) { return; }
  window.setTimeout(function() {
    send(window.performance.getEntriesByType('measure'));
    clear();
  }, 1000);
}

function send(measurements) {
  var measurement;
  for (var i = 0; i < measurements.length; ++i) {
    measurement = measurements[i];
    post(measurement);
    gaTrackTiming(measurement);
  }
}

export function post(measurement) {
  var payload = createMetric(measurement);
  return Ember.$.ajax({
    type: 'POST',
    url: endpointUri('metrics'),
    contentType: 'application/json; charset=utf-8',
    data: JSON.stringify({ metrics: payload }),
    dataType: 'json'
  });
}

function gaTrackTiming(measurement) {
  if (typeof window.ga !== 'function') { return; }
  window.ga('send', {
    'hitType': 'timing',
    'timingCategory': 'user_timing',
    'timingVar': measurement.name,
    'timingValue': measurement.duration,
    'timingLabel': measurement.emberVersion,
    'page': measurement.pathname
  });
}

function createMetric(measurement) {
  return {
    date: Date.now(),
    name: measurement.name,
    pathname: location.pathname,
    startTime: Math.round(measurement.startTime),
    duration: Number(Math.round(measurement.duration + 'e3') + 'e-3'), // round to thousandths
    visitor: window.localStorage.getItem('visitor'),
    screenWidth: window.screen.width,
    screenHeight: window.screen.height,
    screenColorDepth: window.screen.colorDepth,
    screenPixelDepth: window.screen.pixelDepth,
    screenOrientation: (window.screen.orientation) ? window.screen.orientation.type : null,
    blogVersion: config.APP.version,
    emberVersion: Ember.VERSION,
    adapterType: (config.APP.USE_SOCKET_ADAPTER) ? 'SOCKET' : 'JSONAPI'
  };
}

function endpointUri(resource) {
  var host = config.APP.API_HOST;
  var path = config.APP.API_PATH;
  var uri = (path) ? host + '/' + path : host;
  return uri + '/' + resource;
}

function clear() {
  window.performance.clearMarks();
  window.performance.clearMeasures();
}

User Timing API

Learn more about User Timing API to Measure Performance

In addition to collecting metrids on rendering templates, I captured durations for finding data. Names of the metics that interested me: app_ready, application_view, index_view, post_view, page_view, app_unload, archive_view, and find_posts.

// An Example Metric Resource
{
  adapterType: 'SOCKET',
  blogVersion: '3.3.8.fa3fbaf8',
  date: '2015-02-08T06:29:17.368Z',
  duration: 113.35,
  emberVersion: '1.10.0',
  id: '1a9864a2-4011-49d8-9233-fa76d26e9040',
  name: 'post_view',
  pathname: '/posts/refreshed-my-blog-with-express-and-emberjs',
  screenColorDepth: 24,
  screenHeight: 900,
  screenOrientation: 'landscape-primary',
  screenPixelDepth: 24,
  screenWidth: 1440,
  startTime: 391,
  userAgent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_2) .... Safari/537.36',
  visit: '22d5d2b0be4067ac3af57f4b14fcbb4b4d89fe34b1eeeaab910c259e7b9c55aa',
  visitor: 'c56f439e-646b-4f6a-b91b-5c119e21efba'
}

You might ask…
What did you find?

I was able to collect a good sized data set, I can search for duration values based on various facets of the metrics data, e.g. emberVersion and userAgent.

Since the timings are measured after data is fetched and the application is ready, I am pretty confident that the metrics captured do reflect the timings that actual users experience as the template is processed and presented.

I have not read How not to lie with statistics, The correct way to summarize benchmark results. So, the measurments I've taken at this point, or only an exploration of data set that is not normalized.

Kris Seldon mentioned to me that averages are meaningless and I'll need to calculate the geometric mean instead.

From jayconrod.com
"The geometric mean is intended for averaging ratios (normalized data)" … "Don't bother summarizing raw data without normalizing it.

Perhaps I can make some educated guesses?

A few comparisons
(Ember.js v1.10.0 and v1.8.1)

The measurements following highlight some gains and losses that may be result of an upgrade from Handlebars to HTMLbars in my application…

All userAgents, desktop
and mobile

Index (home) page in v1.8.1

/metrics/durations?name=index_view&emberVersion=1.8

// Index (home) page in v1.8.1
{
  average: 154.41764912280703,
  durations: 114,
  fastest: 5,
  pathname: "/",
  slowest: 914
}

Index (home) page in v1.10.0

/metrics/durations?name=index_view&emberVersion=1.10

// Index (home) page in v1.10.0
{
  average: 244.7352818181818,
  durations: 220,
  fastest: 5,
  pathname: "/",
  slowest: 1854.635
}

The most visited (post) page in v1.8.1

/metrics/durations?name=index_view&emberVersion=1.10

// The most visited (post) page in v1.8.1
{
  average: 251.42101618705053,
  durations: 1668,
  fastest: 8,
  pathname: "/posts/develop-a-restful-api-using-nodejs-with-express-and-mongoose",
  slowest: 3696
}

The most visited (post) page in v1.8.1

/metrics/durations?name=index_view&emberVersion=1.10

// The most visited (post) page in v1.10.0
{
  average: 232.02967880485514,
  durations: 2142,
  fastest: 8,
  pathname: "/posts/develop-a-restful-api-using-nodejs-with-express-and-mongoose",
  slowest: 5726
}

Long list (1,000 metrics) in v1.10.0, in Chrome

/api/metrics/durations?name=metrics_table&emberVersion=1.10&userAgent=Chrome

// Long list (1,000 metrics) in v1.10.0, in Chrome
{
  average: 690.5488399999999,
  durations: 25,
  fastest: 427.563,
  pathname: "/metrics",
  slowest: 1142.15
}

Long list (1,000 metrics) in v1.8.1, in Chrome

/metrics/durations?name=metrics_table&emberVersion=1.8&userAgent=Chrome

// Long list (1,000 metrics) in v1.8.1, in Chrome
{
  average: 682.4195625,
  durations: 16,
  fastest: 457.012,
  pathname: "/metrics",
  slowest: 991.684
}

Mobile userAgents

Index (home) page in v1.10.0, on Mobile

/metrics/durations?name=index_view&emberVersion=1.10&userAgent=Mobile

// Index (home) page in v1.10.0, on Mobile
{
  average: 580.4696976744186,
  durations: 43,
  fastest: 160,
  pathname: "/",
  slowest: 1490
}

Index (home) page in v1.8.1, on Mobile

/metrics/durations?name=index_view&emberVersion=1.8&userAgent=Mobile

// Index (home) page in v1.8.1, on Mobile
{
  average: 515.881875,
  durations: 8,
  fastest: 330,
  pathname: "/",
  slowest: 914
}

Long list (1,000 metrics) in v1.8.1, on Mobile

/metrics/durations?name=metrics_table&emberVersion=1.8&userAgent=Mobile

// Long list (1,000 metrics) in v1.8.1, on Mobile
{
  average: 2179.4,
  durations: 10,
  fastest: 871,
  pathname: "/metrics",
  slowest: 5380
}

Long list (1,000 metrics) in v1.10.0, on Mobile

/metrics/durations?name=metrics_table&emberVersion=1.10&userAgent=Mobile

// Long list (1,000 metrics) in v1.10.0, on Mobile
{
  average: 1617.4285714285713,
  durations: 7,
  fastest: 1014,
  pathname: "/metrics",
  slowest: 2285
}

What I've Observed About Performance in my Ember App

Handlebars to HTMLbars

  • Looking at the average speed of rendering the home page did not seem to show a performance gain, but the data set is not normalized
  • The same can be said for the speed of rendering the templates on my post pages
  • Though I don't believe that rendering a long list doesn't matter to my users, after experimenting with a long list I did notice notice any big gains in performance looking at the fastest rendering times in the data I collected
  • However what appears to be good news, is that the fastest speeds did improve, and even more so on mobile.

On Mobile

  • Perhaps I may expect a 25% - 50% gain in performance for the fastest time to render
  • The performance gains my users will benefit from may be limited to the users with newer mobile devices

Thanks to the hard work of the Ember.js contributors and core team its my expectation that users browsing my site should see a boost in performance.

Since I found these measurements valuable, I'll continue to collect them and review as I try out various beta versions of Ember.js. Recently another release of the 1.11.0 series was released, so I'll give it a try soon.

Once I discover how to normalize the metrics and calculate a proper geometric mean then I can draw some more definitive summaries about the measurements.

It is great have these metrics (prod build / server) in my own DB (from ~10,000 unique users & ~30,000 pageviews @ month). Currently, my data set provides some insights into identifying further investigation and encourages me to look into better reporting.

Thank You!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment