Debugging React Native Performance: Snoopy and the MessageQueue

This post is part of a series about React Native Performance, and the upcoming Programming React Native Vol 2.

In my previous Debugging React Native article I mentioned the MessageQueue, the SPY_MODE flag, and how I submitted a pull request that changed it effectively into a spy() function anyone can try using. I also mentioned Snoopy, a tool I built that uses spy() and creates a high-level tool that helps you with debugging MessageQueue performance problems. Today, we'll take a look at how that came to be, and how you can use Snoopy to figure out your performance problems.

The React Native MessageQueue is the facility through which both native and Javascript parts communicate. As we adopt new libraries and components, they'll be using the same facility to communicate, implicitly. Each library we add, in addition to each new piece of code we add, use the same pipe to send and receive messages to, and from, the native part.

Inevitably, some of the components we'll adopt will make heavy use of the MessageQueue, but actually we'll never know or have the time to notice. We perceive the MessageQueue as an internal thing and (for a good reason) and to be honest we tend to treat libraries as black boxes that frees our time and let us work on solving other, more interesting, problems.

But here’s the deal. I had to realize the MessageQueue existed, I mean, I knew it existed — but I didn’t realize I should be looking there for answers. I found that bits of images were passing back and forth as base64 serialized values that were too heavy to go on the same channel that keeps the Javascript and native realms in sync. 

For that, I had to also realize how I would pry the MessageQueue open and see it overflowing with big messages and needless communication, due to the way I was using libraries at the time.

The Need for a Message Queue

If you imagined you had to build React Native from scratch, how would that be? Let's use the simplest module I could think of for illustration: Alert.

First, ergonomically, it looks like a plain Javascript module:

Alert.alert(
  'Title',
  'msg'
)

Behind the scenes, translating that to iOS would have to mean something along the lines of this:

let alertController = UIAlertController(title: "Title", message: "msg", preferredStyle: .Alert)
let defaultAction = UIAlertAction(title: "OK", style: .Default, handler: nil)
alertController.addAction(defaultAction)

This kind of translation, or wrapping, is one hint at the massive amount of work needed to create a framework like React Native. It means wrapping native code and exposing it as Javascript. It would also mean we need a Javascript engine embedded inside our native platform.

And so, we stated that we have a native part and a Javascript part for every running React Native process. It sounds obvious, but when you factor in a scalable architecture, extensible design, sandboxed code, smart rendering pipelines, you'll realize these would have to be two separate living organisms and that they need a form of efficient message passing to communicate.

This kind of architecture exists everywhere around us, for example, we've had postMessage on the Web. I had to hand-wave a lot of detail to keep focus, but be sure that in React Native, you have these two parts and the architecture is much detailed than what I described.

When we work on performance issues, we're looking for bottlenecks. For example, high CPU usage would probably mean one or two hot areas or functions, which you can find with profiling tools. Once fixed, you can be sure a couple more hot areas will pop up, but on average performance would improve.

The MessageQueue presents an interesting variant of a bottleneck. One that introduces congestion. It's implicit, like the internet connection we use, or the roads we use to commute. To take the internet connection analogy, if there's a too high rate of traffic, you'll experience slowness, and similarly, if we have a too high volume of traffic. So we have small messages with high rate, and big messages with low rate and some times the combination of the two.

Prying Open the Message Queue

Ultimately we want to have the following:

  1. Have better visibility, move MessageQueue away from the implicit zone and into our comfort zone.
  2. Have a good way to analyze what we see, so we can make informed decisions.

Better Visibility

To tackle the first item, I had a plan: find a flag I can switch on, or suffer and build tracing into the MessageQueue myself. I bumped onto a flag React Native core contributors used for their own debugging purposes called SPY_MODE. But, you had to switch it on by editing the MessageQueue code. Actually, that's how the spy() function came to be.

The spy() function adds a convenient way to, well, spy on the MessageQueue from your own user-land code. This means you can try it on any React Native app right now, and it doesn't matter where you drop these couple lines of code:

import Snoopy from 'rn-snoopy'
import MessageQueue from 'react-native/Libraries/Utilities/MessageQueue'
MessageQueue.spy((info)=>console.log("event!", info))

You'll get this:

2016-10-10 19:56:44.089 [info][tid:com.facebook.react.JavaScript] 'event!', { type: 1,
  module: 'UIManager',
  method: 'updateView',
  args: [ [Getter/Setter], [Getter/Setter], [Getter/Setter] ] }
2016-10-10 19:56:44.090 [info][tid:com.facebook.react.JavaScript] 'event!', { type: 1,
  module: 'UIManager',
  method: 'updateView',
  args: [ [Getter/Setter], [Getter/Setter], [Getter/Setter] ] }

The reason that it's not nice to look at so far, is because you're getting the raw info event, which has the following shape:

{
  type: int (0=N->JS | 1=JS->N)
  method: string,
  module: string,
  args: object,
}

A moment before we see how this shape is good for us, let's try the default way to spy on events:

MessageQueue.spy((info)=>console.log("event!", info))

Which give us:

2016-10-10 20:03:53.954 [info][tid:com.facebook.react.JavaScript] JS->N : UIManager.updateView([85,"RCTView",{"opacity":1,"transform":[1,0,0,0,0,1,0,0,0,0,1,0,15,0,0,1]}])
2016-10-10 20:03:53.954 [info][tid:com.facebook.react.JavaScript] JS->N : UIManager.updateView([93,"RCTView",{"opacity":0,"transform":[1,0,0,0,0,1,0,0,0,0,1,0,20,0,0,1]}])
2016-10-10 20:03:53.968 [info][tid:com.facebook.react.JavaScript] N->JS : JSTimersExecution.callTimers([[73]])
2016-10-10 20:03:53.969 [info][tid:com.facebook.react.JavaScript] JS->N : UIManager.updateView([97,"RCTView",{"opacity":1}])

With that, we're done with the first issue.

Better Analysis

If you're running this side by side with me, you'll notice that your logs are streaming events constantly. Arguably, the best way to tame a stream of events is with a reactive framework like rxjs (or Kefir, or most, or flyd).

So if we stream these into a pipe that aggregates and shapes the data, we can come to conclusions efficiently, come up with numbers that signify "good" or "bad", and automate this whole process to create our own alerts. Sounds familiar? Well, not by chance, this is the same process you'd use to tame network traffic, and, for all intents and purposes the communication through the MessageQueue is another form of traffic.

Let's see how we can do the above using a tool I've built called Snoopy which was, in fact, the reason I added the spy() function in the first place :).

Within your app, or a new app you create, or even the Snoopy demo app, find a place to add the following:

import EventEmitter from 'react-native/Libraries/EventEmitter/EventEmitter'
const emitter = new EventEmitter()
const events = Snoopy.stream(emitter)

You now have events, and we're hooked into the MessageQueue. It's a fully primed stream, onto which you can tack Rx constructs as you see fit.

Filter is one of these constructs. With the Snoopy filter helper, let's see how we can start analyzing this stream:

import filter from 'rn-snoopy/stream/filter'

// Show calls going from Javascript to Native: create an info shape
// with Snoopy.TO_NATIVE. Use true to log filter results.

filter({ type: Snoopy.TO_NATIVE }, true)(events).subscribe()

// Filter based on method: show calls dealing with 'createView'.

filter({ method:'createView' }, true)(events).subscribe()

// Filter based on arguments: using nested matching.

filter({ method:'createView', {args: {foo: {bar:1}}}}, true)(events).subscribe()

// Filter based on a predicate: use a function.

filter((info)=>info.method == 'createView', true)(events).subscribe()

These should get you started when the stream is overwhelming. For example, filtering on createView is a great way to verify that a ListView does not create new cells, when you were expecting it the least.

To surface trends, we can use the built-in graphing and aggregation helpers that ships with Snoopy called bars, and buffer.

import bars from 'rn-snoopy/stream/bars'
import buffer from 'rn-snoopy/stream/buffer'

And here are a couple patterns you can use with these:

// Visualize the rate of messages per second which go over the MessageQueue:
bars()(
  buffer()(
    events
  )
).subscribe()

// Visualize how big are messages over the MessageQueue:
// Note: we turn messages into a JSON string, and then measure
// the length of that string. Previously, the bars method had
// no argument, and here it gets a "measurement" function.
bars(info=>JSON.stringify(info.args).length)(
  events
).subscribe()

Here's how it should look live:

One last thing

Although we defined two goals, it's trivial to build an alerting system that would trigger when we mistakenly abuse the MessageQueue:

// Trigger a yellobox (true) once the rate
// is more than 100 messages per second.
bars(infoAry=>infoAry.length, 100, true).length)(
  events
).subscribe()

This is how it should look like:

Freestyle it

I picked rxjs, and not other, perhaps more pure and better performing reactive libraries out there although I did use those initially (namely: most). The main reason was that rxjs comes with rich operators out of the box, and extensive educational material.

Go ahead and try Snoopy and think up new and interesting ways to shape and look the stream of messages that go through the MessageQueue. Let me know what you think. It should be dead easy now.