play-co / timestep

GNU General Public License v3.0
16 stars 27 forks source link

Optimization of BaseBacking class #123

Closed bchevalier closed 7 years ago

bchevalier commented 7 years ago

Why

The goal of this optimization was to speed up the updateGlobalTransformViewBacking.

I was investigating why the ViewBacking.updateGlobalTransform method was slower than expected. JavaScript profiling on Everwing was showing around 5.7% of the total execution time was taken by updateGlobalTransform while I would expect less than 2% for what it does (profiled with main gameplay feature).

How

I realized that the ViewBacking instances might not be very well optimized due to properties being attached to the prototype instead of being added as regular properties of the instances. Therefore the optimization consisted solely in rewriting the definition of the BaseBacking class.

Result

CPU

Overall, it looks like the CPU usage of updateGlobalTransform went down to ~2.7%. Which would indicate a 3% boost for the total but it seems that the refactoring benefits other methods as profiling suggest a 9% reduction of CPU usage: out of 5 run per configuration (before and after refactoring), I get a 16.82% non-idle time before and 15.28% after, which corresponds to a 9% reduction.

Screen shot of JS profile before:

screen shot 2017-06-09 at 2 30 28 pm

Screen shot of JS profile after:

screen shot 2017-06-09 at 2 27 05 pm

The above screenshots are characteristic of the behavior that can be noticed across all 10 runs. It is interesting to note that the anonymous function, located in util/setProperty, went down from 2.4% to ~1%. This method was called indirectly whenever accessing or setting a property with custom getters and setters generated in util/setProperty. A few, frequently accessed, properties of BaseBacking were set up this way but are not anymore with this refactoring; This explains why this anonymous method is now using less resources.

Memory

It appears that the amount of memory used by instances of the class is now smaller but the amount is very negligible. Screen shot of memory profile before:

screen shot 2017-06-09 at 12 13 58 pm

Screen shot of memory profile after:

screen shot 2017-06-09 at 12 12 07 pm

Notes

bchevalier commented 7 years ago

Updated to keep the behavior of copy and update methods unchanged.

By the way, something crazy is happening, or may be I am becoming crazy because I cannot seem to be able to create a copy the following way:

    var copy = {
      x: this.x,
      y: this.y,
      offsetX: this.offsetX,
      offsetY: this.offsetX,
      anchorX: this.anchorX,
      anchorY: this.anchorY,
      centerAnchor: this.centerAnchor,
      width: this._width,
      height: this._height,
      r: this.r,
      opacity: this.opacity,
      zIndex: this._zIndex,
      scale: this.scale,
      scaleX: this.scaleX,
      scaleY: this.scaleY,
      flipX: this.flipX,
      flipY: this.flipY,
      visible: this.visible,
      clip: this.clip,
      backgroundColor: this.backgroundColor,
      compositeOperation: this.compositeOperation
    };

Animations are messed up if I instantiate a copy as shown in the code above. That's why I needed to keep BASE_STYLE_PROPS around. I also get unintended and different behavior if I set up the copy object by looping through a list of keys that would look like the following:

var BASE_STYLE_PROPS = [
  'x',
  'y',
  'offsetX',
  'offsetY',
  'anchorX',
  'anchorY',
  'centerAnchor',
  'width',
  'height',
  'r',
  'opacity',
  'zIndex',
  'scale',
  'scaleX',
  'scaleY',
  'flipX',
  'flipY',
  'visible',
  'clip',
  'backgroundColor',
  'compositeOperation'
];

I really do not understand what is going on, any idea?

rogueSkib commented 7 years ago

@bchevalier that's a tricky one, I had to use a diff checker to find it. You have offsetY: this.offsetX

bchevalier commented 7 years ago

thanks! Fixed it

fairfieldt commented 7 years ago

Hey Brice, this is awesome! Thanks for the thorough writeup.

It's probably worth looking at the optimization/deoptimization/bailout logging on the commandline - I find it's often more informative than what is surfaced to the profiler:

"/Applications/Google Chrome.app/Contents/MacOS/Google Chrome" \ --no-sandbox --js-flags="--trace-deopt --trace-opt-verbose --trace-bailout"

I took a quick look and updateGlobalTransform itself seems to be nicely optimized. Unrelated to this specific PR, but some methods the logging points to:

[not yet optimizing onTick, not enough type info: 2/13 (15%)]
[not yet optimizing tick, not enough type info: 9/129 (6%)]
[not yet optimizing renderFilter, not enough type info: 14/81 (17%)]
[not yet optimizing render, not enough type info: 13/56 (23%)]
[not yet optimizing get, not enough type info: 2/3 (66%)]

These get called a lot; might be worth trying to fix that. It'd also be nice to see the profile on mobile safari (you can attach the safari dev tools to a phone over the usb connection).

bchevalier commented 7 years ago

Hi Tom, thanks for your input!

My current strategy is to optimize the methods that are the most resource consuming in our use cases first (Everwing being the priority but also Cats and Bubble-blitz). It's true that de-opt or lack of optimization are usually a good hint when trying to speed-up those methods.

Here is the result of profiling safari on an iPhone 7: Before

no-optim

After

safari-after

We see that the updateGlobalTransform, wrapRender and _renderSubviews methods are using less resources than before. It looks like some other methods are now consuming more (optimizing one method make other methods look relatively heavier). The problem is that the % is relative to the total resource consumption, not a % of total available resources which makes it more difficult to measure the global performance impact of a change.

Does anyone know if there is a way to get the result of the profiling in a javascript object without having the save the CPU profile? (<- I just want to skip this intermediary step)

Also tested on an Xperia Z3, the FPS seems to go up from ~40 to ~45.

bjornstar commented 7 years ago

You might find https://github.com/paulirish/automated-chrome-profiling useful.

bchevalier commented 7 years ago

thanks @bjornstar, will have a look!