Capture and report stdout/stderr of the browser while running a test

tools/testing/dart/browser_controller.dart

 // Copyright (c) 2013, the Dart project authors.  Please see the AUTHORS file
 // for details. All rights reserved. Use of this source code is governed by a
 // BSD-style license that can be found in the LICENSE file.
 library browser;
 
 import "dart:async";
 import "dart:convert" show LineSplitter, UTF8;
 import "dart:core";
 import "dart:io";
 
 import 'android.dart';
 import 'utils.dart';
 
+class BrowserOutput {
+  final StringBuffer stdout = new StringBuffer();
+  final StringBuffer stderr = new StringBuffer();
+  final StringBuffer eventLog = new StringBuffer();
+}
+
 /** Class describing the interface for communicating with browsers. */
 abstract class Browser {
-  StringBuffer _stdout = new StringBuffer();
-  StringBuffer _stderr = new StringBuffer();
-  StringBuffer _usageLog = new StringBuffer();
+  BrowserOutput _allBrowserOutput = new BrowserOutput();
+  BrowserOutput _testBrowserOutput = new BrowserOutput();
+
   // This is called after the process is closed, before the done future
   // is completed.
   // Subclasses can use this to cleanup any browser specific resources
   // (temp directories, profiles, etc). The function is expected to do
   // it's work synchronously.
   Function _cleanup;
 
   /** The version of the browser - normally set when starting a browser */
   String version = "";
   /**
@@ skipping 43 matching lines @@
 
   // TODO(kustermann): add standard support for chrome on android
   static bool supportedBrowser(String name) {
     return SUPPORTED_BROWSERS.contains(name);
   }
 
   void _logEvent(String event) {
     String toLog = "$this ($id) - $event \n";
     if (debugPrint) print("usageLog: $toLog");
     if (logger != null) logger(toLog);
-    _usageLog.write(toLog);
+
+    _allBrowserOutput.eventLog.write(toLog);
+    _testBrowserOutput.eventLog.write(toLog);
   }
 
   void _addStdout(String output) {
     if (debugPrint) print("stdout: $output");
-    _stdout.write(output);
+
+    _allBrowserOutput.stdout.write(output);
+    _testBrowserOutput.stdout.write(output);
   }
 
   void _addStderr(String output) {
     if (debugPrint) print("stderr: $output");
-    _stderr.write(output);
+
+    _allBrowserOutput.stderr.write(output);
+    _testBrowserOutput.stderr.write(output);
   }
 
   Future close() {
     _logEvent("Close called on browser");
     if (process != null) {
       if (process.kill(ProcessSignal.SIGKILL)) {
         _logEvent("Successfully sent kill signal to process.");
       } else {
         _logEvent("Sending kill signal failed.");
       }
@@ skipping 54 matching lines @@
         }).whenComplete(() => doneCompleter.complete(true));
       });
       return true;
     }).catchError((error) {
       _logEvent("Running $command $arguments failed with $error");
       return false;
     });
   }
 
   /**
-   * Get any stdout that the browser wrote during execution.
+   * Get the output that was written so far to stdout/stderr/eventLog.
    */
-  String get stdout => _stdout.toString();
-  String get stderr => _stderr.toString();
-  String get usageLog => _usageLog.toString();

[kustermann, 2013/10/18 12:02:25]

I couldn't find any uses of these. I hope it's okay to replace them by
allBrowserOutput/testBrowserOutput.

+  BrowserOutput get allBrowserOutput => _allBrowserOutput;
+  BrowserOutput get testBrowserOutput => _testBrowserOutput;
+
+  void resetTestBrowserOutput() {
+    _testBrowserOutput = new BrowserOutput();
+  }
 
   String toString();
+
   /** Starts the browser loading the given url */
   Future<bool> start(String url);
 }
 
 class Safari extends Browser {
   /**
    * The binary used to run safari - changing this can be nececcary for
    * testing or using non standard safari installation.
    */
   static const String binary = "/Applications/Safari.app/Contents/MacOS/Safari";
@@ skipping 429 matching lines @@
   // Used for debugging, this is simply a unique identifier assigned to each
   // test.
   int id;
   static int _idCounter = 0;
 
   BrowserTest(this.url, this.doneCallback, this.timeout) {
     id = _idCounter++;
   }
 }
 
+/* Describes the output of running the test in a browser */
+class BrowserTestOutput {
+  final bool didTimeout;
+  final Duration delayUntilTestStarted;
+  final Duration duration;
+  final BrowserOutput browserOutput;
+  final String dom;
+
+  BrowserTestOutput(
+      this.delayUntilTestStarted, this.duration, this.dom,
+      this.browserOutput, {this.didTimeout: false});
+}
 
 /**
  * Encapsulates all the functionality for running tests in browsers.
  * The interface is rather simple. After starting the runner tests
  * are simply added to the queue and a the supplied callbacks are called
  * whenever a test completes.
  */
 class BrowserTestRunner {
   final Map globalConfiguration;
 
@@ skipping 110 matching lines @@
       if (status.currentTest.id != testId) {
         print("Expected test id ${status.currentTest.id} for"
               "${status.currentTest.url}");
         print("Got test id ${testId}");
         print("Last test id was ${status.lastTest.id} for "
               "${status.currentTest.url}");
         throw("This should never happen, wrong test id");
       }
       testCache[testId] = status.currentTest.url;
       Stopwatch watch = new Stopwatch()..start();
-      status.currentTest.doneCallback(output,
-                                      status.currentTest.delayUntilTestStarted,
-                                      status.currentTest.stopwatch.elapsed);
+
+      // Report that the test is finished now
+      var browserTestOutput = new BrowserTestOutput(
+          status.currentTest.delayUntilTestStarted,
+          status.currentTest.stopwatch.elapsed,
+          output,
+          status.browser.testBrowserOutput);
+      status.currentTest.doneCallback(browserTestOutput);
+
       watch.stop();
       status.lastTest = status.currentTest;
       status.currentTest = null;
     } else {
       print("\nThis is bad, should never happen, handleResult no test");
       print("URL: ${status.lastTest.url}");
       print(output);
       terminate().then((_) {
         exit(1);
       });
@@ skipping 12 matching lines @@
     }
   }
 
   void handleTimeout(BrowserTestingStatus status) {
     // We simply kill the browser and starts up a new one!
     // We could be smarter here, but it does not seems like it is worth it.
     status.timeout = true;
     timedOut.add(status.currentTest.url);
     var id = status.browser.id;
     status.browser.close().then((_) {
+      // Wait until the browser is closed before reporting the test as timeout.
+      // This will enable us to capture stdout/stderr from the browser
+      // (which might provide us with information about what went wrong).
+      var browserTestOutput = new BrowserTestOutput(
+          status.currentTest.delayUntilTestStarted,
+          status.currentTest.stopwatch.elapsed,
+          'Dom could not be fetched, since the test timed out.',
+          status.browser.testBrowserOutput,
+          didTimeout: true);
+      status.currentTest.stopwatch.stop();
+      status.currentTest.doneCallback(browserTestOutput);
+      status.currentTest = null;
+
       // We don't want to start a new browser if we are terminating.
       if (underTermination) return;
       var browser;
       var new_id = id;
       if (browserName == 'chromeOnAndroid') {
         browser = new AndroidChrome(adbDeviceMapping[id]);
       } else {
         browserStatus.remove(id);
         browser = getInstance();
         new_id = "BROWSER$browserIdCount";
@@ skipping 14 matching lines @@
         }
         if (success) {
           browserStatus[browser.id] = new BrowserTestingStatus(browser);
         } else {
           // TODO(ricow): Handle this better.
           print("This is bad, should never happen, could not start browser");
           exit(1);
         }
       });
     });
-    status.currentTest.stopwatch.stop();
-    status.currentTest.doneCallback("TIMEOUT",
-                                    status.currentTest.delayUntilTestStarted,
-                                    status.currentTest.stopwatch.elapsed);
-    status.currentTest = null;
   }
 
   BrowserTest getNextTest(String browserId) {
     if (testQueue.isEmpty) return null;
     var status = browserStatus[browserId];
     if (status == null) return null;
 
     // We are currently terminating this browser, don't start a new test.
     if (status.timeout) return null;
+
     BrowserTest test = testQueue.removeLast();
     if (status.currentTest == null) {
       status.currentTest = test;
     } else {
       // TODO(ricow): Handle this better.
       print("This is bad, should never happen, getNextTest all full");
       print("This happened for browser $browserId");
       print("Old test was: ${status.currentTest.url}");
       print("Timed out tests:");
       for (var v in timedOut) {
         print("  $v");
       }
       exit(1);
     }
 
     status.currentTest.timeoutTimer = createTimeoutTimer(test, status);
     status.currentTest.stopwatch = new Stopwatch()..start();
+
+    // Reset the test specific output information (stdout, stderr) on the
+    // browser since a new test is begin started.
+    status.browser.resetTestBrowserOutput();
+
     return test;
   }
 
   Timer createTimeoutTimer(BrowserTest test, BrowserTestingStatus status) {
     return new Timer(
         new Duration(seconds: test.timeout), () { handleTimeout(status); });
   }
 
   void queueTest(BrowserTest test) {
     testQueue.add(test);
@@ skipping 354 matching lines @@
     Dart test driver, number of tests: <div id="number"></div><br>
     Currently executing: <div id="currently_executing"></div><br>
     Unhandled error: <div id="unhandled_error"></div>
     <iframe id="embedded_iframe"></iframe>
   </body>
 </html>
 """;
     return driverContent;
   }
 }