A Brief Exercise in Profiling JavaScript

I recently had to track down a memory leak while reviewing a video course–a series of videos broken up into 8 sections consisting of 5 videos each–that demonstrated the development of a couple of games with HTML5 technologies.  This is a brief recap of how I approached uncovering the leak with the hope it can provide others with a hands-on exercise using Google Chrome’s profiling capabilities.

The course primarily involved JavaScript coding utilizing the EaselJS library to interface with the canvas element.  I had just completed the sixth in the series of videos provided at which point the code had placed the game into a loop.  That is, as soon as the hero in the game died, the game immediately started over again.  Letting the game loop through a few times I noticed the game started to get sluggish.  A natural assumption would be we have a memory leak.

Here is the code in exactly this state (view leak in browser and download archive of code).

Of course, thinking as any developer would, I figured it couldn’t be my fault.  The course must have instructed me to do something wrong and introduce the leak.  The course came with code representing where you should be after each video, so to test my assumption the course was at fault I ran the code the course provided, and it did not become sluggish.  So I was left pondering what I had done to get the game into this state.

At this point the code included 9 JavaScript files I had written consisting of about 400 lines of code.  There was also a dependency on the EaselJS library.  Naturally, I downloaded the latest and greatest version of EaselJS–0.7.1–while the course used an earlier version: 0.5.0.  Between the two versions some significant changes have been made to the library, and the minified file was 79 kb.  So this wasn’t going to be as simple as commenting out a few suspect lines here and there to narrow down the origin of the leak.

Enter the profiling tools in Google Chrome.  At this point you may want to open up my code in Google Chrome, open Chrome’s dev tools (F12 in Windows, Cmd+Opt+I on Mac), and click on the “Profiles” tab.  Make sure “Record Heap Allocations” is selected, and click “Start.”  This will give us an object allocation graph on a timeline (in gray) as well as indicating the time of events (in blue).  Do this for a while and then stop the profiling by clicking the red circle.

There are a few events that you will notice occur naturally.  Our hero, who at this stage in development is a green rectangle, can collide with a yellow rectangle (a “coin”) and collect it.  Our hero can also trigger a game restart in a couple of ways: by colliding with a red rectangle (an obstacle), or by falling off a black rectangle (a platform).  You can also trigger an event as a player by clicking on the canvas, which causes the hero to jump.

So back to our initial profiling.  Looking at the time line we took, you will notice the object allocation increasing over time in a saw tooth pattern, which confirms we have a leak.  You will also notice that at each jump in object allocation we have a blue line indicating an event occurred.  If you watched the game play in parallel with watching the timeline being recorded, you should have noticed that this jump in object allocation occurred immediately after our hero died, either by colliding with an object or falling off a platform.

 

Heap Timeline - notice sawtooth pattern with increasing object allocation being triggered by events (our hero dying)

Heap Timeline – notice sawtooth pattern with increasing object allocation being triggered by events (our hero dying)

So we’ve now confirmed we have a leak, as well as identified the event that is feeding the leak.  The next step is to identify the objects that are being created by the event.

Back to the “Profiles” tab in the dev tools.  But instead of selecting “Record Heap Allocations,” we instead are going to select “Take Heap Snapshot.”  The plan is we’re going to take a snapshot of the objects on the heap before the event occurs, and then a second snapshot after the event occurs.  We’ll then examine the difference between the two snapshots to see if we can identify any specific types of objects that increase in number.

So after starting your game, click the button to take a snapshot (it’s OK if you don’t take it before the first death of our hero, he will die plenty of times).  Now wait until our hero dies one or two or more times, and then take another snapshot by clicking the gray disc above the listing containing the first snapshot.  You should now have “Snapshot 1” and “Snapshot 2” listed.  Then from the “Summary” dropdown, select “Comparison” (see screenshot, immediately below).

After taking snapshots before and after the event, select "Comparison" from the dropdown.

After taking snapshots before and after the event, select “Comparison” from the dropdown.

To provide some context for what we’re about to see, here’s a little background on how some of the code is structured.  The game is made up of “GameObjects” whose constructor function’s prototype object is an instance of an EaselJS Container (createjs.Container).  If you look at the code for this, you will also notice that GameObject.prototype.initialize calls p.Container_initialize (which is a reference to the initialize method initially created when the prototype object was instantiated).

Derived from GameObject, using the same same prototypal inheritance pattern, are Coin, Obstacle, Platform, and MoveableGameObject.  Hero is then derived from MoveableGameObject.  When a new game is initialized, a single hero is instantiated, as are 10 Platforms.  Upon the first Platform a Coin in instantiated, and for the last 9 Platforms either a Coin or Obstacle is instantiated (via a 50% decision made via Math.random). These objects are all added to the game’s “camera” property as children, where the “camera” is an instance of an createjs.Container.  This camera is a child of the stage, which is the createjs wrapper object around the canvas the game is played on.

As mentioned earlier, the game ends and restarts (loops) when the hero either runs into an obstacle, or falls off a platform.

So, with this background, you should notice something quite interesting by looking at the comparison of the two snapshots taken with the profiler (see image, below).

Look at the Constructors list to see if we see any object numbers building up.  See anything interesting?

Look at the Constructors list to see if we see any object numbers building up. See anything interesting?

Between my snapshots, the hero died three times.  Given this, and what you know of the object model for this game, three items should stand out in the constructor list.

For starters, we see 30 new Platforms were created, and 0 deleted.  As mentioned above, with each game restart 10 Platforms are created, and with 3 restarts, we see the Platforms being created, but we’re not seeing the old ones being GC’d.  And we also see 16 Coins and 14 Obstacles created, but none are cleaned up.  So we now know when the game ends, we’re either not deleting the old objects, or more likely we’re maintaining a reference to them that is preventing them from being cleaned up by the garbage collector.

So the next step I would take is examining the code that is called after our hero dies, which presumably cleans up the game objects before starting over again.  Looking in rush-game.js, and specifically RushGame.prototype.resetGame, we see the call that should clean up these objects (ie, this.camera.removeAllChildren):


var p = RushGame.prototype;

p.resetGame = function() {
  this.camera.removeAllChildren();
  this.camera.x = 0;

  createjs.Ticker.removeAllEventListeners();
  createjs.Ticker.addEventListener('tick', (function() { this.tick(); }).bind(this));
};

And if we look at RushGame.prototype.initGame, we see that Platforms, Coins and Obstacles are added as children to the camera, so presumably we’re doing everything right.  So what’s going on with this.camera.removeAllChildren?

If you use the debugger and place a break point at the call of removeAllChildren, and then upon hitting it, examine what this method is in the console, you will see this:

leak-removeAllChildren

So we see it pops each child (Platform or Coin or Obstacle) off the camera’s children array, and then set’s the child’s parent property to null.  Presumably the parent is the camera, and these objects should be free to be cleaned up by the garbage collector.  So… More digging…  Let’s start with the Platform constructor function in rush-platform.js.


rush.Platform = (function() {
  function Platform(width) {
    this.initialize(width);
  }

  var p = Platform.prototype = new rush.GameObject();

  p.category = 'platform';

  p.GameObject_initialize = p.initialize;

  p.initialize = function(width) {
    this.width = width || 120;
    this.height = 12;

    var shape = rush.CommonShapes.rectangle({
      width: this.width,
      height: this.height
    });

    this.addChild(shape);
  };

  return Platform;
}());

We see it’s prototype object is an instance of a GameObject, and the constructor function itself calls initilialize, which is defined on the prototype object and adds a shape via a call to addChild, which it presumably accesses via the prototype chain.  But more interesting is what is happening just above the definition of initialize, we see GameObject_initialize being set to the prototype object’s initialize method, and then nothing further is done with it.

Now if you were to surmise at this point that GameObject_initialize should be called in initialize, and tried this and then repeated the profiling exercise, you will find you have discovered the issue in code causing the leak, as you would be seeing the Platform objects now being deleted in your snapshot diff.  And if you look at the code in rush-coin.js, and rush-obstacle.js, you would see the same mistake, which I introduced through copying and pasting the Platform code.  So at this point you could simply fix your code by calling GameObject_initialize in all three initialize definitions, and the leak is taken care of.

But for the sake of academic completeness, let’s dig into the code a little deeper and understand why this caused a leak.  Back to Platform, we know it’s prototype object is a GameObject, and we know we don’t call the GameObject’s initialize method.  So what do we see in rush-gameobject.js?


rush.GameObject = (function() {
  function GameObject() {
    this.initialize();
  }

  var p = GameObject.prototype = new createjs.Container();

  p.category = 'object';

  p.width = 0;
  p.height = 0;

  p.Container_initialize = p.initialize;

  p.initialize = function() {
    this.Container_initialize();
  }

  p.hitPoint = function(point) {
    if (point.x >= 0 && point.x <= this.width &&
        point.y >= 0 && point.y <= this.height) {
      return true;
    }
    return false;
  };
  return GameObject;
}());

So we see that GameObject’s prototype object is an instance of a createjs.Container, and that GameObject’s initialize method does call the Container’s initialize method.  But since the GameObject’s initialize method is not being called when the Platforms are being initialized, then the Container’s initialize method is not being called, either.  We can also note that addChild is not defined in GameObject, so the addChild being called in Platform.prototype.initialize is coming from further up the prototype chain.  And if we go up the prototype chain we also find addChild defined on createjs.Container.prototype.

Even though I only have the minified version of the EaselJS library, it is still apparent what is going on if we look a the code for the two attributes off the Container’s prototype object.

createjs.Container.prototype.initialize


function (){this.DisplayObject_initialize(),this.children=[]}

createjs.Container.prototype.addChild


function (a){
  if(null==a)return a;
  var b=arguments.length;
  if(b>1){for(var c=0;b>c;c++)this.addChild(arguments[c]);return arguments[b-1]}
  return a.parent&&a.parent.removeChild(a),a.parent=this,this.children.push(a),a
}

createjs.Container.prototype.initialize creates an array–children–in the this scope. However, remember that Platform (and Coin and Obstacle) don’t call GameObject.prototype.initialize, which is what calls this, so we don’t have a children array created on these objects. But all of the constructor functions for Platform, Coin and Obstacle have an instance of GameObject defined as their prototype object. So when we see this.children being referenced by addChild, it is Platform.prototype.children having an element being pushed on it (or Coin.prototype.children, or Obstacle.prototype.children), and since the constructor functions Platform, Coin and Obstacle never go out of scope, the elements of the children array off their prortype objects’ never go out of scope and don’t get GC’d.  And since these children elements reference the instances of Platform|Coin|Obstacle as their parent (this.parent, see addChild), those objects don’t get GC’d even though they are no longer elements in the camera.children array.

I realize there’s a lot in that last paragraph, and you may have to go back to the code (in the debugger, no less) to fit all the pieces together, but there you have it: the origin of the memory leak.  It even becomes more apparent if you do this: instead of calling this this.GameObject_initialize in the initialize method of the prototype object for Platfor|Coin|Obstacle, instead simply add the line “this.children = [];” in each initialize method, and the run and profile the code.  You will see the memory leak is gone.

All questions, comments and expressions of confusion welcome.

Advertisements