[ReactNative] Add PerformanceLogger to measure TTI

Summary:
@public

Add PerformanceLogger to keep track of JS download, initial script execution and
full TTI.

Test Plan:
The Native side currently calls `addTimespans` when it's finish initializing
with the six values (start and end for the three events), so I just checked it
with a `PerformanceLogger.logTimespans()` at the end of the function.

```
2015-06-18 16:47:19.096 [info][tid:com.facebook.React.JavaScript] "ScriptDownload: 48ms"
2015-06-18 16:47:19.096 [info][tid:com.facebook.React.JavaScript] "ScriptExecution: 106ms"
2015-06-18 16:47:19.096 [info][tid:com.facebook.React.JavaScript] "TTI: 293ms"
```

Libraries/JavaScriptAppEngine/Initialization/InitializeJavaScriptAppEngine.js

@@ -24,6 +24,7 @@
 
 // Just to make sure the JS gets packaged up.
 require('RCTDeviceEventEmitter');
+require('PerformanceLogger');
 
 if (typeof GLOBAL === 'undefined') {
   GLOBAL = this;

Libraries/Utilities/PerformanceLogger.js

@@ -0,0 +1,96 @@
+/**
+ * Copyright (c) 2015-present, Facebook, Inc.
+ * All rights reserved.
+ *
+ * This source code is licensed under the BSD-style license found in the
+ * LICENSE file in the root directory of this source tree. An additional grant
+ * of patent rights can be found in the PATENTS file in the same directory.
+ *
+ * @providesModule PerformanceLogger
+ */
+'use strict';
+
+
+var performanceNow = require('performanceNow');
+
+var timespans = {};
+
+/**
+ * This is meant to collect and log performance data in production, which means
+ * it needs to have minimal overhead.
+ */
+var PerformanceLogger = {
+  addTimespan(key, lengthInMs, description) {
+    if (timespans[key]) {
+      if (__DEV__) {
+        console.log(
+          'PerformanceLogger: Attempting to add a timespan that already exists'
+        );
+      }
+      return;
+    }
+
+    timespans[key] = {
+      description: description,
+      totalTime: lengthInMs,
+    };
+  },
+
+  startTimespan(key, description) {
+    if (timespans[key]) {
+      if (__DEV__) {
+        console.log(
+          'PerformanceLogger: Attempting to start a timespan that already exists'
+        );
+      }
+      return;
+    }
+
+    timespans[key] = {
+      description: description,
+      startTime: performanceNow(),
+    };
+  },
+
+  stopTimespan(key) {
+    if (!timespans[key] || !timespans[key].startTime) {
+      if (__DEV__) {
+        console.log(
+          'PerformanceLogger: Attempting to end a timespan that has not started'
+        );
+      }
+      return;
+    }
+
+    timespans[key].endTime = performanceNow();
+    timespans[key].totalTime =
+      timespans[key].endTime - timespans[key].startTime;
+  },
+
+  clearTimespans() {
+    timespans = {};
+  },
+
+  getTimespans() {
+    return timespans;
+  },
+
+  logTimespans() {
+    for (var key in timespans) {
+      console.log(key + ': ' + timespans[key].totalTime + 'ms');
+    }
+  },
+
+  addTimespans(newTimespans, labels) {
+    for (var i = 0, l = newTimespans.length; i < l; i += 2) {
+      var label = labels[i / 2];
+      PerformanceLogger.addTimespan(
+        label,
+        (newTimespans[i + 1] - newTimespans[i]),
+        label
+      );
+    }
+  }
+};
+
+module.exports = PerformanceLogger;

React/Base/RCTBridge.m

@@ -20,6 +20,7 @@
 #import "RCTKeyCommands.h"
 #import "RCTLog.h"
 #import "RCTPerfStats.h"
+#import "RCTPerformanceLogger.h"
 #import "RCTProfile.h"
 #import "RCTRedBox.h"
 #import "RCTRootView.h"
@@ -612,6 +613,8 @@ dispatch_queue_t RCTJSThread;
   RCTAssertMainThread();
 
   if ((self = [super init])) {
+    RCTPerformanceLoggerStart(RCTPLTTI);
+
     _bundleURL = bundleURL;
     _moduleProvider = block;
     _launchOptions = [launchOptions copy];
@@ -981,8 +984,10 @@ RCT_INNER_BRIDGE_ONLY(_invokeAndProcessModule:(__unused NSString *)module
   } else {
 
     RCTProfileBeginEvent();
+    RCTPerformanceLoggerStart(RCTPLScriptDownload);
     RCTJavaScriptLoader *loader = [[RCTJavaScriptLoader alloc] initWithBridge:self];
     [loader loadBundleAtURL:bundleURL onComplete:^(NSError *error, NSString *script) {
+      RCTPerformanceLoggerEnd(RCTPLScriptDownload);
       RCTProfileEndEvent(@"JavaScript dowload", @"init,download", @[]);
 
       _loading = NO;

React/Base/RCTPerformanceLogger.h

@@ -0,0 +1,24 @@
+/**
+ * Copyright (c) 2015-present, Facebook, Inc.
+ * All rights reserved.
+ *
+ * This source code is licensed under the BSD-style license found in the
+ * LICENSE file in the root directory of this source tree. An additional grant
+ * of patent rights can be found in the PATENTS file in the same directory.
+ */
+
+#import <Foundation/Foundation.h>
+
+#import "RCTDefines.h"
+#import "RCTBridgeModule.h"
+
+typedef NS_ENUM(NSUInteger, RCTPLTag) {
+  RCTPLScriptDownload = 0,
+  RCTPLAppScriptExecution,
+  RCTPLTTI,
+  RCTPLSize
+};
+
+void RCTPerformanceLoggerStart(RCTPLTag tag);
+void RCTPerformanceLoggerEnd(RCTPLTag tag);
+NSArray *RCTPerformanceLoggerOutput(void);

React/Base/RCTPerformanceLogger.m

@@ -0,0 +1,77 @@
+/**
+ * Copyright (c) 2015-present, Facebook, Inc.
+ * All rights reserved.
+ *
+ * This source code is licensed under the BSD-style license found in the
+ * LICENSE file in the root directory of this source tree. An additional grant
+ * of patent rights can be found in the PATENTS file in the same directory.
+ */
+
+#import <QuartzCore/QuartzCore.h>
+
+#import "RCTPerformanceLogger.h"
+#import "RCTRootView.h"
+
+static int64_t RCTPLData[RCTPLSize][2] = {};
+
+void RCTPerformanceLoggerStart(RCTPLTag tag)
+{
+  RCTPLData[tag][0] = CACurrentMediaTime() * 1000;
+}
+
+void RCTPerformanceLoggerEnd(RCTPLTag tag)
+{
+  RCTPLData[tag][1] = CACurrentMediaTime() * 1000;
+}
+
+NSArray *RCTPerformanceLoggerOutput(void)
+{
+  return @[
+    @(RCTPLData[0][0]),
+    @(RCTPLData[0][1]),
+    @(RCTPLData[1][0]),
+    @(RCTPLData[1][1]),
+    @(RCTPLData[2][0]),
+    @(RCTPLData[2][1]),
+  ];
+}
+
+@interface RCTPerformanceLogger : NSObject <RCTBridgeModule>
+
+@end
+
+@implementation RCTPerformanceLogger
+
+RCT_EXPORT_MODULE()
+
+@synthesize bridge = _bridge;
+
+- (instancetype)init
+{
+  if ((self = [super init])) {
+    [[NSNotificationCenter defaultCenter] addObserver:self
+                                             selector:@selector(sendTimespans)
+                                                 name:RCTContentDidAppearNotification
+                                               object:nil];
+  }
+  return self;
+}
+
+- (void)dealloc
+{
+  [[NSNotificationCenter defaultCenter] removeObserver:self];
+}
+
+- (void)sendTimespans
+{
+  [_bridge enqueueJSCall:@"PerformanceLogger.addTimespans" args:@[
+    RCTPerformanceLoggerOutput(),
+    @[
+      @"ScriptDownload",
+      @"ScriptExecution",
+      @"TTI",
+    ],
+  ]];
+}
+
+@end

React/Base/RCTRootView.m

@@ -17,6 +17,7 @@
 #import "RCTEventDispatcher.h"
 #import "RCTKeyCommands.h"
 #import "RCTLog.h"
+#import "RCTPerformanceLogger.h"
 #import "RCTSourceCode.h"
 #import "RCTTouchHandler.h"
 #import "RCTUIManager.h"
@@ -247,6 +248,7 @@ RCT_NOT_IMPLEMENTED(-initWithCoder:(NSCoder *)aDecoder)
 - (void)insertReactSubview:(id<RCTViewNodeProtocol>)subview atIndex:(NSInteger)atIndex
 {
   [super insertReactSubview:subview atIndex:atIndex];
+  RCTPerformanceLoggerEnd(RCTPLTTI);
   dispatch_async(dispatch_get_main_queue(), ^{
     if (!_contentHasAppeared) {
       _contentHasAppeared = YES;

React/Executors/RCTContextExecutor.m

@@ -17,6 +17,7 @@
 #import "RCTDefines.h"
 #import "RCTLog.h"
 #import "RCTProfile.h"
+#import "RCTPerformanceLogger.h"
 #import "RCTUtils.h"
 
 @interface RCTJavaScriptContext : NSObject <RCTInvalidating>
@@ -446,12 +447,14 @@ static NSError *RCTNSErrorFromJSError(JSContextRef context, JSValueRef jsError)
     if (!strongSelf || !strongSelf.isValid) {
       return;
     }
+    RCTPerformanceLoggerStart(RCTPLAppScriptExecution);
     JSValueRef jsError = NULL;
     JSStringRef execJSString = JSStringCreateWithCFString((__bridge CFStringRef)script);
     JSStringRef jsURL = JSStringCreateWithCFString((__bridge CFStringRef)sourceURL.absoluteString);
     JSValueRef result = JSEvaluateScript(strongSelf->_context.ctx, execJSString, NULL, jsURL, 0, &jsError);
     JSStringRelease(jsURL);
     JSStringRelease(execJSString);
+    RCTPerformanceLoggerEnd(RCTPLAppScriptExecution);
 
     if (onComplete) {
       NSError *error;

React/React.xcodeproj/project.pbxproj

@@ -48,6 +48,7 @@
 		13E067591A70F44B002CDEE1 /* UIView+React.m in Sources */ = {isa = PBXBuildFile; fileRef = 13E067541A70F44B002CDEE1 /* UIView+React.m */; };
 		1403F2B31B0AE60700C2A9A4 /* RCTPerfStats.m in Sources */ = {isa = PBXBuildFile; fileRef = 1403F2B21B0AE60700C2A9A4 /* RCTPerfStats.m */; };
 		14200DAA1AC179B3008EE6BA /* RCTJavaScriptLoader.m in Sources */ = {isa = PBXBuildFile; fileRef = 14200DA91AC179B3008EE6BA /* RCTJavaScriptLoader.m */; };
+		142014191B32094000CC17BA /* RCTPerformanceLogger.m in Sources */ = {isa = PBXBuildFile; fileRef = 142014171B32094000CC17BA /* RCTPerformanceLogger.m */; };
 		14435CE51AAC4AE100FC20F4 /* RCTMap.m in Sources */ = {isa = PBXBuildFile; fileRef = 14435CE21AAC4AE100FC20F4 /* RCTMap.m */; };
 		14435CE61AAC4AE100FC20F4 /* RCTMapManager.m in Sources */ = {isa = PBXBuildFile; fileRef = 14435CE41AAC4AE100FC20F4 /* RCTMapManager.m */; };
 		146459261B06C49500B389AA /* RCTFPSGraph.m in Sources */ = {isa = PBXBuildFile; fileRef = 146459251B06C49500B389AA /* RCTFPSGraph.m */; };
@@ -177,6 +178,8 @@
 		1403F2B21B0AE60700C2A9A4 /* RCTPerfStats.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = RCTPerfStats.m; sourceTree = "<group>"; };
 		14200DA81AC179B3008EE6BA /* RCTJavaScriptLoader.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = RCTJavaScriptLoader.h; sourceTree = "<group>"; };
 		14200DA91AC179B3008EE6BA /* RCTJavaScriptLoader.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = RCTJavaScriptLoader.m; sourceTree = "<group>"; };
+		142014171B32094000CC17BA /* RCTPerformanceLogger.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = RCTPerformanceLogger.m; sourceTree = "<group>"; };
+		142014181B32094000CC17BA /* RCTPerformanceLogger.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = RCTPerformanceLogger.h; sourceTree = "<group>"; };
 		1436DD071ADE7AA000A5ED7D /* RCTFrameUpdate.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; path = RCTFrameUpdate.h; sourceTree = "<group>"; };
 		14435CE11AAC4AE100FC20F4 /* RCTMap.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = RCTMap.h; sourceTree = "<group>"; };
 		14435CE21AAC4AE100FC20F4 /* RCTMap.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = RCTMap.m; sourceTree = "<group>"; };
@@ -439,6 +442,8 @@
 				146459251B06C49500B389AA /* RCTFPSGraph.m */,
 				1403F2B11B0AE60700C2A9A4 /* RCTPerfStats.h */,
 				1403F2B21B0AE60700C2A9A4 /* RCTPerfStats.m */,
+				142014171B32094000CC17BA /* RCTPerformanceLogger.m */,
+				142014181B32094000CC17BA /* RCTPerformanceLogger.h */,
 			);
 			path = Base;
 			sourceTree = "<group>";
@@ -551,6 +556,7 @@
 				134FCB3D1A6E7F0800051CC8 /* RCTContextExecutor.m in Sources */,
 				13E067591A70F44B002CDEE1 /* UIView+React.m in Sources */,
 				14F484561AABFCE100FDF6B9 /* RCTSliderManager.m in Sources */,
+				142014191B32094000CC17BA /* RCTPerformanceLogger.m in Sources */,
 				83CBBA981A6020BB00E9B192 /* RCTTouchHandler.m in Sources */,
 				83CBBA521A601E3B00E9B192 /* RCTLog.m in Sources */,
 				13B0801D1A69489C00A75B9A /* RCTNavItemManager.m in Sources */,