Improvements to the Activity API

Summary: Revised the Activity implementation - added flow annotations - fixed some lint warnings - added event `options`, specifically a `telemetric` option which indicates that events tagged in this manner are relevant for telemetry. The duration of these events is now highlighted in the Activity log Reviewed By: bestander, kentaromiura Differential Revision: D3770753 fbshipit-source-id: 6976535fd3bf5269c6263d825d657ab0805ecaad
facebook · Aug 25, 2016 · 11488d0 · 11488d0
1 parent 548ba83
commit 11488d0
Show file tree

Hide file tree

Showing 8 changed files with 174 additions and 70 deletions.
diff --git a/packager/react-packager/src/Activity/Types.js b/packager/react-packager/src/Activity/Types.js
@@ -0,0 +1,25 @@
+/**
+ * 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.
+ *
+ * @flow
+ *
+ */
+'use strict';
+
+export type EventOptions = {
+  telemetric: boolean,
+};
+
+export type Event = {
+  id: number,
+  startTimeStamp: number,
+  endTimeStamp?: number,
+  name: string,
+  data?: any,
+  options: EventOptions,
+};
diff --git a/packager/react-packager/src/Activity/__tests__/Activity-test.js b/packager/react-packager/src/Activity/__tests__/Activity-test.js
@@ -13,14 +13,17 @@ jest.disableAutomock();
 var Activity = require('../');
 
 describe('Activity', () => {
+  // eslint-disable-next-line no-console-disallow
   const origConsoleLog = console.log;
 
   beforeEach(() => {
+    // eslint-disable-next-line no-console-disallow
     console.log = jest.fn();
     jest.runOnlyPendingTimers();
   });
 
   afterEach(() => {
+    // eslint-disable-next-line no-console-disallow
     console.log = origConsoleLog;
   });
 
@@ -32,7 +35,9 @@ describe('Activity', () => {
       Activity.startEvent(EVENT_NAME, DATA);
       jest.runOnlyPendingTimers();
 
+      // eslint-disable-next-line no-console-disallow
       expect(console.log.mock.calls.length).toBe(1);
+      // eslint-disable-next-line no-console-disallow
       const consoleMsg = console.log.mock.calls[0][0];
       expect(consoleMsg).toContain('START');
       expect(consoleMsg).toContain(EVENT_NAME);
@@ -49,7 +54,9 @@ describe('Activity', () => {
       Activity.endEvent(eventID);
       jest.runOnlyPendingTimers();
 
+      // eslint-disable-next-line no-console-disallow
       expect(console.log.mock.calls.length).toBe(2);
+      // eslint-disable-next-line no-console-disallow
       const consoleMsg = console.log.mock.calls[1][0];
       expect(consoleMsg).toContain('END');
       expect(consoleMsg).toContain(EVENT_NAME);

diff --git a/packager/react-packager/src/Activity/index.js b/packager/react-packager/src/Activity/index.js
@@ -5,98 +5,122 @@
  * 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.
+ *
+ * @flow
+ *
  */
 'use strict';
 
+import type {EventOptions} from './Types';
+import type {Event} from './Types';
+
 const chalk = require('chalk');
 const events = require('events');
 
-const _eventStarts = Object.create(null);
-const _eventEmitter = new events.EventEmitter();
+let ENABLED = true;
+let UUID = 1;
 
-let _uuid = 1;
-let _enabled = true;
+const EVENT_INDEX: {[key: number]: Event} = Object.create(null);
+const EVENT_EMITTER = new events.EventEmitter();
 
-function endEvent(eventId) {
-  const eventEndTime = Date.now();
-  if (!_eventStarts[eventId]) {
-    throw new Error('event(' + eventId + ') either ended or never started');
+function startEvent(
+  name: string,
+  data: any = null,
+  options?: EventOptions = {telemetric: false},
+): number {
+  if (name == null) {
+    throw new Error('No event name specified!');
   }
 
-  _writeAction({
-    action: 'endEvent',
-    eventId: eventId,
-    tstamp: eventEndTime
-  });
+  const id = UUID++;
+  EVENT_INDEX[id] = {
+    id,
+    startTimeStamp: Date.now(),
+    name,
+    data,
+    options,
+  };
+  logEvent(id, 'startEvent');
+  return id;
 }
 
-function startEvent(eventName, data) {
-  const eventStartTime = Date.now();
-
-  if (eventName == null) {
-    throw new Error('No event name specified');
-  }
+function endEvent(id: number): void {
+  getEvent(id).endTimeStamp = Date.now();
+  logEvent(id, 'endEvent');
+}
 
-  if (data == null) {
-    data = null;
+function getEvent(id: number): Event {
+  if (!EVENT_INDEX[id]) {
+    throw new Error(`Event(${id}) either ended or never started`);
   }
 
-  const eventId = _uuid++;
-  const action = {
-    action: 'startEvent',
-    data: data,
-    eventId: eventId,
-    eventName: eventName,
-    tstamp: eventStartTime,
-  };
-  _eventStarts[eventId] = action;
-  _writeAction(action);
-
-  return eventId;
+  return EVENT_INDEX[id];
 }
 
-function disable() {
-  _enabled = false;
+function forgetEvent(id: number): void {
+  delete EVENT_INDEX[id];
 }
 
-function _writeAction(action) {
-  _eventEmitter.emit(action.action, action);
+function logEvent(id: number, phase: 'startEvent' | 'endEvent'): void {
+  const event = EVENT_INDEX[id];
+  EVENT_EMITTER.emit(phase, id);
 
-  if (!_enabled) {
+  if (!ENABLED) {
     return;
   }
 
-  const data = action.data ? ': ' + JSON.stringify(action.data) : '';
-  const fmtTime = new Date(action.tstamp).toLocaleTimeString();
+  const {
+    startTimeStamp,
+    endTimeStamp,
+    name,
+    data,
+    options,
+  } = event;
+
+  const duration = +endTimeStamp - startTimeStamp;
+  const dataString = data ? ': ' + JSON.stringify(data) : '';
+  const {telemetric} = options;
 
-  switch (action.action) {
+  switch (phase) {
     case 'startEvent':
-      console.log(chalk.dim(
-        '[' + fmtTime + '] ' +
-        '<START> ' + action.eventName +
-        data
-      ));
+      // eslint-disable-next-line no-console-disallow
+      console.log(
+        chalk.dim(
+          '[' + new Date(startTimeStamp).toLocaleString() + '] ' +
+          '<START> ' + name + dataString
+        )
+      );
       break;
 
     case 'endEvent':
-      const startAction = _eventStarts[action.eventId];
-      const startData = startAction.data ? ': ' + JSON.stringify(startAction.data) : '';
-      console.log(chalk.dim(
-        '[' + fmtTime + '] ' +
-        '<END>   ' + startAction.eventName +
-        ' (' + (action.tstamp - startAction.tstamp) + 'ms)' +
-        startData
-      ));
-      delete _eventStarts[action.eventId];
+      // eslint-disable-next-line no-console-disallow
+      console.log(
+        chalk.dim('[' + new Date(endTimeStamp).toLocaleString() + '] ' + '<END>   ' + name) +
+        chalk.dim(dataString) +
+        (telemetric ? chalk.reset.cyan(' (' + (duration) + 'ms)') : chalk.dim(' (' + (duration) + 'ms)'))
+      );
+      forgetEvent(id);
       break;
 
     default:
-      throw new Error('Unexpected scheduled action type: ' + action.action);
+      throw new Error('Unexpected scheduled event type: ' + name);
   }
 }
 
+function enable(): void {
+  ENABLED = true;
+}
+
+function disable(): void {
+  ENABLED = false;
+}
 
-exports.endEvent = endEvent;
-exports.startEvent = startEvent;
-exports.disable = disable;
-exports.eventEmitter = _eventEmitter;
+module.exports = {
+  startEvent,
+  endEvent,
+  getEvent,
+  forgetEvent,
+  enable,
+  disable,
+  eventEmitter: EVENT_EMITTER,
+};
diff --git a/packager/react-packager/src/Bundler/index.js b/packager/react-packager/src/Bundler/index.js
@@ -356,7 +356,13 @@ class Bundler {
     onModuleTransformed = noop,
     finalizeBundle = noop,
   }) {
-    const findEventId = Activity.startEvent('find dependencies');
+    const findEventId = Activity.startEvent(
+      'Finding dependencies',
+      null,
+      {
+        telemetric: true,
+      },
+    );
     const modulesByName = Object.create(null);
 
     if (!resolutionResponse) {

diff --git a/packager/react-packager/src/Server/index.js b/packager/react-packager/src/Server/index.js
@@ -485,7 +485,7 @@ class Server {
   _processAssetsRequest(req, res) {
     const urlObj = url.parse(req.url, true);
     const assetPath = urlObj.pathname.match(/^\/assets\/(.+)$/);
-    const assetEvent = Activity.startEvent(`processing asset request ${assetPath[1]}`);
+    const assetEvent = Activity.startEvent('Processing asset request', {asset: assetPath[1]});
     this._assetServer.get(assetPath[1], urlObj.query.platform)
       .then(
         data => res.end(this._rangeRequestMiddleware(req, res, data, assetPath)),
@@ -610,7 +610,15 @@ class Server {
       return;
     }
 
-    const startReqEventId = Activity.startEvent('request:' + req.url);
+    const startReqEventId = Activity.startEvent(
+      'Requesting bundle',
+      {
+        url: req.url,
+      },
+      {
+        telemetric: true,
+      },
+    );
     const options = this._getOptionsFromUrl(req.url);
     debug('Getting bundle for request');
     const building = this._useCachedOrUpdateOrCreateBundle(options);
@@ -661,7 +669,13 @@ class Server {
   }
 
   _symbolicate(req, res) {
-    const startReqEventId = Activity.startEvent('symbolicate');
+    const startReqEventId = Activity.startEvent(
+      'Symbolicating',
+      null,
+      {
+        telemetric: true,
+      },
+    );
     new Promise.resolve(req.rawBody).then(body => {
       const stack = JSON.parse(body).stack;
 

diff --git a/packager/react-packager/src/node-haste/DependencyGraph/DeprecatedAssetMap.js b/packager/react-packager/src/node-haste/DependencyGraph/DeprecatedAssetMap.js
@@ -1,4 +1,4 @@
- /**
+/**
  * Copyright (c) 2015-present, Facebook, Inc.
  * All rights reserved.
  *
@@ -60,6 +60,10 @@ class DeprecatedAssetMap {
         if (activity) {
           processAsset_DEPRECATEDActivity = activity.startEvent(
             'Building (deprecated) Asset Map',
+            null,
+            {
+              telemetric: true,
+            },
           );
         }
 

diff --git a/packager/react-packager/src/node-haste/fastfs.js b/packager/react-packager/src/node-haste/fastfs.js
@@ -46,7 +46,13 @@ class Fastfs extends EventEmitter {
       let fastfsActivity;
       const activity = this._activity;
       if (activity) {
-        fastfsActivity = activity.startEvent('Building in-memory fs for ' + this._name);
+        fastfsActivity = activity.startEvent(
+          'Building in-memory fs for ' + this._name,
+          null,
+          {
+            telemetric: true,
+          },
+        );
       }
       files.forEach(filePath => {
         const root = this._getRoot(filePath);

diff --git a/packager/react-packager/src/node-haste/index.js b/packager/react-packager/src/node-haste/index.js
@@ -1,4 +1,4 @@
- /**
+/**
  * Copyright (c) 2015-present, Facebook, Inc.
  * All rights reserved.
  *
@@ -91,8 +91,20 @@ class DependencyGraph {
     }
 
     const {activity} = this._opts;
-    const depGraphActivity = activity.startEvent('Building Dependency Graph');
-    const crawlActivity = activity.startEvent('Crawling File System');
+    const depGraphActivity = activity.startEvent(
+      'Building Dependency Graph',
+      null,
+      {
+        telemetric: true,
+      },
+    );
+    const crawlActivity = activity.startEvent(
+      'Crawling File System',
+      null,
+      {
+        telemetric: true,
+      },
+    );
     const allRoots = this._opts.roots.concat(this._opts.assetRoots_DEPRECATED);
     this._crawling = crawl(allRoots, {
       ignore: this._opts.ignoreFilePath,
@@ -148,7 +160,13 @@ class DependencyGraph {
     this._loading = Promise.all([
       this._fastfs.build()
         .then(() => {
-          const hasteActivity = activity.startEvent('Building Haste Map');
+          const hasteActivity = activity.startEvent(
+            'Building Haste Map',
+            null,
+            {
+              telemetric: true,
+            },
+          );
           return this._hasteMap.build().then(map => {
             activity.endEvent(hasteActivity);
             return map;