Provides better React debug stats + React verbose mode

Summary:
Release notes: Adds React verbose mode

Adds React verbose mode for better debugging.
Closes https://github.com/facebook/prepack/pull/1592

Differential Revision: D7280813

Pulled By: trueadm

fbshipit-source-id: b777848ac8e006574b59cccb343764067d146a1d

package.json

@@ -55,7 +55,7 @@
     "depcheck": "babel-node scripts/detect_bad_deps.js",
     "prettier": "node ./scripts/prettier.js write-changed",
     "prettier-all": "node ./scripts/prettier.js write",
-    "debug-fb-www": "node ./scripts/debug-fb-www.js"
+    "debug-fb-www": "node --stack_trace_limit=200 --stack_size=10000 ./scripts/debug-fb-www.js"
   },
   "dependencies": {
     "babel-core": "^6.26.0",

scripts/debug-fb-www.js

@@ -15,17 +15,22 @@
 
 let prepackSources = require("../lib/prepack-node.js").prepackSources;
 let path = require("path");
-let { readFile, writeFile } = require("fs");
+let { readFile, writeFile, existsSync } = require("fs");
 let { promisify } = require("util");
 let readFileAsync = promisify(readFile);
 let writeFileAsync = promisify(writeFile);
+let chalk = require("chalk");
 
 let errorsCaptured = [];
 
 let prepackOptions = {
   errorHandler: diag => {
     errorsCaptured.push(diag);
-    if (diag.severity !== "Warning" && diag.severity !== "Information") {
+    if (diag.severity === "Information") {
+      console.log(diag.message);
+      return "Recover";
+    }
+    if (diag.severity !== "Warning") {
       return "Fail";
     }
     return "Recover";
@@ -37,6 +42,7 @@ let prepackOptions = {
   maxStackDepth: 100,
   reactEnabled: true,
   reactOutput: "jsx",
+  reactVerbose: true,
   inlineExpressions: true,
   omitInvariants: true,
   abstractEffectsInAdditionalFunctions: true,
@@ -44,6 +50,10 @@ let prepackOptions = {
 };
 let inputPath = path.resolve("fb-www/input.js");
 let outputPath = path.resolve("fb-www/output.js");
+let componentsListPath = path.resolve("fb-www/components.txt");
+let components = new Map();
+let startTime = Date.now();
+let uniqueEvaluatedComponents = 0;
 
 function compileSource(source) {
   let serialized;
@@ -62,6 +72,17 @@ function compileSource(source) {
   };
 }
 
+async function readComponentsList() {
+  if (existsSync(componentsListPath)) {
+    let componentsList = await readFileAsync(componentsListPath, "utf8");
+    let componentNames = componentsList.split("\n");
+
+    for (let componentName of componentNames) {
+      components.set(componentName, "missing");
+    }
+  }
+}
+
 async function compileFile() {
   let source = await readFileAsync(inputPath, "utf8");
   let { stats, code } = await compileSource(source);
@@ -77,20 +98,59 @@ function printReactEvaluationGraph(evaluatedRootNode, depth) {
   } else {
     let status = evaluatedRootNode.status.toLowerCase();
     let message = evaluatedRootNode.message !== "" ? `: ${evaluatedRootNode.message}` : "";
-    let line = `- ${evaluatedRootNode.name} (${status}${message})`;
+    let name = evaluatedRootNode.name;
+    let line;
+    if (status === "inlined") {
+      line = `${chalk.gray(`-`)} ${chalk.green(name)} ${chalk.gray(`(${status + message})`)}`;
+    } else if (status === "unsupported_completion" || status === "unknown_type" || status === "bail-out") {
+      line = `${chalk.gray(`-`)} ${chalk.red(name)} ${chalk.gray(`(${status + message})`)}`;
+    } else {
+      line = `${chalk.gray(`-`)} ${chalk.yellow(name)} ${chalk.gray(`(${status + message})`)}`;
+    }
+    if (components.has(name)) {
+      let currentStatus = components.get(name);
+
+      if (currentStatus === "missing") {
+        uniqueEvaluatedComponents++;
+        currentStatus = [currentStatus];
+        components.set(name, currentStatus);
+      } else if (Array.isArray(currentStatus)) {
+        currentStatus.push(status);
+      }
+    }
     console.log(line.padStart(line.length + depth));
     printReactEvaluationGraph(evaluatedRootNode.children, depth + 2);
   }
 }
 
-compileFile()
+readComponentsList()
+  .then(compileFile)
   .then(result => {
-    console.log("\nCompilation complete!");
-    console.log(`Evaluated Components: ${result.componentsEvaluated}`);
-    console.log(`Optimized Trees: ${result.optimizedTrees}`);
-    console.log(`Inlined Components: ${result.inlinedComponents}\n`);
-    console.log(`Evaluated Tree:`);
+    console.log(`\n${chalk.inverse(`=== Compilation Complete ===`)}\n`);
+    console.log(chalk.bold(`Evaluated Tree:`));
     printReactEvaluationGraph(result.evaluatedRootNodes, 0);
+
+    if (components.size > 0) {
+      console.log(`\n${chalk.inverse(`=== Status ===`)}\n`);
+      for (let [componentName, status] of components) {
+        if (status === "missing") {
+          console.log(`${chalk.red(`✖`)} ${componentName}`);
+        } else {
+          console.log(`${chalk.green(`✔`)} ${componentName}`);
+        }
+      }
+    }
+
+    console.log(`\n${chalk.inverse(`=== Summary ===`)}\n`);
+    if (components.size > 0) {
+      console.log(`${chalk.gray(`Optimized Components`)}: ${uniqueEvaluatedComponents}/${components.size}`);
+    }
+    console.log(`${chalk.gray(`Optimized Nodes`)}: ${result.componentsEvaluated}`);
+    console.log(`${chalk.gray(`Inlined Nodes`)}: ${result.inlinedComponents}`);
+    console.log(`${chalk.gray(`Optimized Trees`)}: ${result.optimizedTrees}`);
+
+    let timeTaken = Math.floor((Date.now() - startTime) / 1000);
+    console.log(`${chalk.gray(`Compile time`)}: ${timeTaken}s\n`);
   })
   .catch(e => {
     console.error(e.natickStack || e.stack);

src/options.js

@@ -48,6 +48,7 @@ export type RealmOptions = {
   maxStackDepth?: number,
   reactEnabled?: boolean,
   reactOutput?: ReactOutputTypes,
+  reactVerbose?: boolean,
   stripFlow?: boolean,
   abstractEffectsInAdditionalFunctions?: boolean,
 };

src/prepack-options.js

@@ -38,6 +38,7 @@ export type PrepackOptions = {|
   profile?: boolean,
   reactEnabled?: boolean,
   reactOutput?: ReactOutputTypes,
+  reactVerbose?: boolean,
   residual?: boolean,
   serialize?: boolean,
   check?: Array<number>,
@@ -67,6 +68,7 @@ export function getRealmOptions({
   uniqueSuffix,
   reactEnabled,
   reactOutput,
+  reactVerbose,
   residual,
   serialize = !residual,
   check,
@@ -86,6 +88,7 @@ export function getRealmOptions({
     uniqueSuffix,
     reactEnabled,
     reactOutput,
+    reactVerbose,
     residual,
     serialize,
     check,

src/realm.js

@@ -196,6 +196,7 @@ export class Realm {
       hoistableReactElements: new WeakMap(),
       reactElements: new WeakSet(),
       symbols: new Map(),
+      verbose: opts.reactVerbose || false,
     };
 
     this.stripFlow = opts.stripFlow || false;
@@ -264,6 +265,7 @@ export class Realm {
     output?: ReactOutputTypes,
     reactElements: WeakSet<ObjectValue>,
     symbols: Map<ReactSymbolTypes, SymbolValue>,
+    verbose: boolean,
   };
   stripFlow: boolean;
 

src/serializer/functions.js

@@ -228,8 +228,12 @@ export class Functions {
   }
 
   checkRootReactComponentTrees(statistics: ReactStatistics, react: ReactSerializerState): void {
+    let logger = this.moduleTracer.modules.logger;
     let recordedReactRootValues = this.__generateAdditionalFunctionsMap("__reactComponentTrees");
     // Get write effects of the components
+    if (this.realm.react.verbose) {
+      logger.logInformation(`Evaluating ${recordedReactRootValues.size} React component tree roots...`);
+    }
     for (let [componentRoot, { config }] of recordedReactRootValues) {
       invariant(config);
       let reconciler = new Reconciler(this.realm, this.moduleTracer, statistics, react, config);
@@ -238,6 +242,7 @@ export class Functions {
         continue;
       }
       let evaluatedRootNode = createReactEvaluatedNode("ROOT", getComponentName(this.realm, componentType));
+      logger.logInformation(`- ${evaluatedRootNode.name} (root)...`);
       statistics.evaluatedRootNodes.push(evaluatedRootNode);
       if (reconciler.hasEvaluatedRootNode(componentType, evaluatedRootNode)) {
         continue;
@@ -260,6 +265,7 @@ export class Functions {
             return;
           }
           reconciler.clearComponentTreeState();
+          logger.logInformation(`  - ${evaluatedNode.name} (branch)...`);
           let branchEffects = reconciler.render(branchComponentType, null, null, false, evaluatedNode);
           let branchComponentTreeState = reconciler.componentTreeState;
           this._generateWriteEffectsForReactComponentTree(

src/serializer/serializer.js

@@ -105,6 +105,9 @@ export class Serializer {
       timingStats.totalTime = Date.now();
       timingStats.globalCodeTime = Date.now();
     }
+    if (this.realm.react.verbose) {
+      this.logger.logInformation(`Evaluating initialization path...`);
+    }
     let code = this._execute(sources);
     let environmentRecordIdAfterGlobalCode = EnvironmentRecord.nextId;
     if (timingStats !== undefined) timingStats.globalCodeTime = Date.now() - timingStats.globalCodeTime;
@@ -138,6 +141,9 @@ export class Serializer {
       preludeGenerator.createNameGenerator("$"),
       this.statistics
     );
+    if (this.realm.react.verbose) {
+      this.logger.logInformation(`Visiting evaluated nodes...`);
+    }
     let residualHeapVisitor = new ResidualHeapVisitor(
       this.realm,
       this.logger,
@@ -150,6 +156,9 @@ export class Serializer {
     if (this.logger.hasErrors()) return undefined;
     if (timingStats !== undefined) timingStats.deepTraversalTime = Date.now() - timingStats.deepTraversalTime;
 
+    if (this.realm.react.verbose) {
+      this.logger.logInformation(`Serializing evaluated nodes...`);
+    }
     const realmPreludeGenerator = this.realm.preludeGenerator;
     invariant(realmPreludeGenerator);
     const residualHeapValueIdentifiers = new ResidualHeapValueIdentifiers(

src/utils/logger.js

@@ -124,6 +124,10 @@ export class Logger {
     this._log(value, message, "Warning");
   }
 
+  logInformation(message: string) {
+    this._log(this.realm.intrinsics.undefined, message, "Information");
+  }
+
   _log(value: Value, message: string, severity: Severity) {
     let loc = value.expressionLocation;
     if (value.intrinsicName) {