Wednesday, June 5, 2013

Improving Backbone App Performance

At CSSConf and JSConf, one of the big themes was performance. I saw talks from Chrome engineers on Jank-busting, a talk from Adobe engineer Peter Flynn on performance tuning in Brackets, and had a lengthy lunch discussion about API performance and caching. Eventually, I couldn't stand all that talking with no action, and I broke down and spent my night in the bar investigating a part of Coursera that is noticeably slow: the course catalog. We looked into the backend API performance a few weeks ago, but I figured, hey, maybe there were frontend improvements that we could make too. Here's what I did and what I learnt.

Step 1. Identify Problem Areas in Timeline

In order to show our course catalog to users, the browser goes through many steps: loading the JS and CSS files, parsing them, finding the right Backbone route, creating the view, sending off an AJAX request to get courses, and rendering everything to the DOM. We could have performance issues in each of those steps (and there's ways to improve the performance of all of them), but I wanted to identify if there were big problem areas with obvious room for improvement.

To start off with, I loaded the catalog with the Chrome timeline view open and recording, and looked for big blocks. I quickly found two of them that looked ripe for the fixing:

  • The callback function for the courses AJAX request that turned the JSON into Backbone collections and models. This one was all "Scripting" blocks (JS execution).
  • The function that rendered the tags and courses to the catalog. This showed up as staggered "Rendering" blocks (DOM operations).

Here's what that looked like in the timeline:



Step 2. Break them down in Profiler

The timeline view will give you a good rough idea of where the browser is spending its time, but the profiler can give you exact statistics on what functions are taking the most amount of time. After reloading the catalog while recording a Javascript CPU profile, I identified a few functions taking a suspicious amount of time, both from external libraries:

  • Backbone.Relational took up the majority of the time with constructor and add operations
  • moment.js took up a significant amount of time with date processing functions.

Here's what the profiler looked like in tree view with relevant nodes expanded:



Step 3. Remove, reload, record

I immediately started thinking of ways to reduce our usage of those external libraries (as I wasn't interested in trying to understand why they were so time-intensive), but before I tried those, I wanted to make sure I was scientific about seeing what changes had the greatest effect on performance. To the measuring machine!

I inserted console.time("Backbonify") and console.timeEnd("Backbonify") statements at the start and end of our AJAX callback, so that I could immediately see that time duration in the console on every reload. I discovered that the time varied between loads (by 20-80ms) and determined I would need to record a range, not a single number. Before making any changes, the Backbonify time was about 750-850ms.

Now that I had a starting number to gauge my progress, I created a table of code-changes and time-ranges, and started changing code, reloading, and recording the new time spent. At first, I didn't worry about whether the code actually still worked - I just wanted to see if theoretically, I was able to remove some bit of code, how great of an improvement would I see? I didn't want to go through the effort of rewriting code until I understood how much I would gain.

Here's a screenshot of that table:



Step 4. Rewrite away the slowness

After my rapid-fire removal-and-reload session, I had a very good idea of what I could do to improve our performance while still retaining our functionality. Thankfully, we already had a number of tests for the code, so I had some confidence that I would know if I broke existing functionality.

Here's a run-down of the main changes that I made:

  • Removed Backbone.Relational
    Time saved: ~400ms
    We were using the library so that we could turn our JSON into nested collections of different models, and have a nice simple API for doing that, but I discovered that I could do the conversion myself and not take nearly as much time. Here's a basic conversion from the Topic.initialize() method:
    if (!this.get('courses') || !(this.get('courses') instanceof Courses)) {
      this.set('courses',
        new Courses(this.get('courses')), {silent: true});
    }
    

  • Deferred and cached moment.js functionality
    Time saved: 100ms
    We were using moment.js to set quite a few computed attributes on our Course models (related to start dates), and we were doing that upon initialization of the model, so that the computed attributes were always available just like normal attributes. So I turned them instead into explicit function calls (course.getStartStatus() vs. course.get('start_status')) and rewrote the code that called them, so that we we don't call the expensive moment functions until absolutely necessary. I also wrote a cache for moment.js so that I'd only call the .format() method if I'd never formatted that date before, for example. That improves performance both in calling the methods multiple time on the same model but also in calling them across different models with the same start dates. Here's a snippet of that cache:
      var MomentCache = {
        moments: {},
        formats: {},
        getMomentFor: function(arr) {
          var key = arr.join('/');
          if (!MomentCache.moments[key]) {
            var momentFor = moment(arr);
            if (momentFor.isValid()) {
              MomentCache.moments[key] = momentFor;
            }
          }
          return MomentCache.moments[key];
        },
        getFormatted: function(momentObj, formatString) {
          var key = momentObj.valueOf() + '|' + formatString;
          if (!MomentCache.formats[key]) {
            MomentCache.formats[key] = momentObj.format(formatString);
          }
          return MomentCache.formats[key];
        }
      };
    

  • Stopped listening to Collection "add" for renders
    Time saved: ~60ms
    For the second problem area that I identified, the one that was DOM-render-heavy, I realized the problem was that we were doing many separate calls to our templating functions and jQuery append, and it would obviously be more efficient to reduce them to one template and append call. This was actually due to the way we were using Backbone events - we were listening to "add" on a collection, and despite the fact that we were adding all of our models at once to the collection, the "add" event triggers *for each model*, passing in the added model. To speed it up, I triggered a custom event for that batch add, and rendered all the non-rendered models at once in the callback. The callback looked something like:
        addTopics: function() {
          var self = this;
          var topicsToAdd = [];
          this.model.get('collection').each(function(topic) {
            // If we already rendered it, we don't render it again
            if (self.$('.coursera-catalog-course-listing-box[data-topic-id=' + topic.get('id') + ']').length) {
              return;
            }
            topicsToAdd.push(topic);
          });
          this.$('.coursera-catalog-listings').append(
            listingTemplate({topicsInfo: topicsToAdd}));
        }
    

  • Removed "comparator" on Collections
    Time saved: 50ms
    We had a comparator function defined on some of our collections, which is a function that Backbone optionally looks for to create a default sort order for the models in a collection. As it turns out, we weren't ever relying on that default sort order, because we always use utility functions to sort our collections in different orders depending on the view and user interactions. I removed the comparators on the collections, and from now on, I will recommend that we never use them and always use explicit sorting functions.


Step 5. Profit!

After all those changes, my final Backbonify time went down to 90-110ms. If my measurements are as highly scientific as I hope they are, that means that I shaved off ~700ms in JS execution time. That was all locally measured times, but they're similar savings in production.

Here's what the profile view looks like now:

A part of me is tempted to put in an artificial delay back into the catalog, and do an A/B test to see if the performance changes actually do affect signups. But another part of me thinks that's a horrible thing to do to users. Maybe one day.

The Chrome profiling tools are a bit intimidating at first, but I encourage you to open them up, do some poking around, and see what your app's up to. I sure learnt a lot about ours — and I know I'll keep learning. There's still so much to improve!

No comments: