test.dart sometimes associates the wrong stderr with a task.

tools/testing/dart/test_runner.dart

 // Copyright (c) 2012, 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.
 
 /**
  * Classes and methods for executing tests.
  *
  * This module includes:
  * - Managing parallel execution of tests, including timeout checks.
  * - Evaluating the output of each test as pass/fail/crash/timeout.
@@ skipping 148 matching lines @@
 }
 
 
 /**
  * TestOutput records the output of a completed test: the process's exit code,
  * the standard output and standard error, whether the process timed out, and
  * the time the process took to run.  It also contains a pointer to the
  * [TestCase] this is the output of.
  */
 class TestOutput {
-  TestCase testCase;
-  int exitCode;
-  bool timedOut;
+  final TestCase testCase;
+  final int exitCode;
+  final bool timedOut;
+  final List<String> stdout;
+  final List<String> stderr;
+  final Duration time;
   bool failed = false;
-  List<String> stdout;
-  List<String> stderr;
-  Duration time;
   /**
    * Set to true if we encounter a condition in the output that indicates we
    * need to rerun this test.
    */
-  bool requestRetry;
+  bool requestRetry = false;
 
   TestOutput(this.testCase, this.exitCode, this.timedOut, this.stdout,
              this.stderr, this.time) {
     testCase.output = this;
-    requestRetry = false;
   }
 
   String get result() =>
       hasCrashed ? CRASH : (hasTimedOut ? TIMEOUT : (hasFailed ? FAIL : PASS));
 
   bool get unexpectedOutput() => !testCase.expectedOutcomes.contains(result);
 
   bool get hasCrashed() {
     if (new Platform().operatingSystem() == 'windows') {
       // The VM uses std::abort to terminate on asserts.
@@ skipping 69 matching lines @@
   List<Function> handlers;
   bool allowRetries = false;
 
   /** Which command of [testCase.commands] is currently being executed. */
   int currentStep;
 
   RunningProcess(TestCase this.testCase,
       [this.allowRetries, this.processQueue]);
 
   /**
-   * Called when all commands are executed. [exitCode] is 0 if all command
+   * Called when all commands are executed. [exitCode] is 0 if all commands
    * succeded, otherwise it will have the exit code of the first failing
    * command.
    */
   void testComplete(int exitCode) {
     new TestOutput(testCase, exitCode, timedOut, stdout,
                    stderr, new Date.now().difference(startTime));
     timeoutTimer.cancel();
     if (testCase.output.unexpectedOutput && testCase.configuration['verbose']) {
       print(testCase.displayName);
       for (var line in testCase.output.stderr) print(line);
@@ skipping 52 matching lines @@
       var line = source.readLine();
       while (null != line) {
         destination.add(line);
         line = source.readLine();
       }
     };
   }
 
   void start() {
     Expect.isFalse(testCase.expectedOutcomes.contains(SKIP));
-    stdout = new List<String>();
-    stderr = new List<String>();
+    stdout = [];
+    stderr = [];
     currentStep = 0;
     runCommand(testCase.commands[currentStep++], stepExitHandler);
   }
 
   void runCommand(Command command,
                   void exitHandler(int exitCode)) {
     if (new Platform().operatingSystem() == 'windows') {
       // Windows can't handle the first command if it is a .bat file or the like
       // with the slashes going the other direction.
       // TODO(efortuna): Remove this when fixed (Issue 1306).
@@ skipping 85 matching lines @@
         bool shutdownMillisecs = 30000;
         new Timer((e) { if (!closed) _process.kill(); }, shutdownMillisecs);
       } else {
         _process.kill();
       }
     }
   }
 
   void doStartTest(TestCase testCase) {
     _startTime = new Date.now();
-    _testStdout = new List<String>();
-    _testStderr = new List<String>();
-    _stdoutStream.lineHandler = _readOutput(_stdoutStream, _testStdout);
-    _stderrStream.lineHandler = _readOutput(_stderrStream, _testStderr);
+    _testStdout = [];
+    _testStderr = [];
+    _stdoutStream.lineHandler = _readStdout(_stdoutStream, _testStdout);
+    _stderrStream.lineHandler = _readStderr(_stderrStream, _testStderr);
     _timer = new Timer(_timeoutHandler, testCase.timeout * 1000);
     var line = _createArgumentsLine(testCase.batchTestArguments);
     _process.stdin.write(line.charCodes());
   }
 
   String _createArgumentsLine(List<String> arguments) {
     return Strings.join(arguments, ' ') + '\n';
   }
 
+  // This removes the line handler from stderr and  reads all 
+  // remaining bytes from it.
+  // TODO(zundel): This is pretty bad - streams need flush()

[Emily Fortuna, 2012/02/29 19:59:03]

Add issue id # (1407) in comment
(also possibly let sgjesse (owner of 1407) know about this in test dart -- it
may raise the priority of flush getting implemented in streams sooner)

[zundel, 2012/02/29 20:19:08]

Done.

+  _drainStderr() {
+    _stderrStream.lineHandler = null;
+    while(true) {
+      var available = 0;
+      try {
+        available = _process.stderr.available();
+      } catch (SocketIOException ex) {
+        break;
+      }
+      if (available <= 0) break;
+      String result = _stderrStream.readLine();
+      if (result == null) {
+        // This is intended to catch the last line, but might foul up
+        // if more bytes immediately come available after read() and before
+        // the test for available()
+        result = _stderrStream.read();

[Emily Fortuna, 2012/02/29 19:59:03]

Perhaps I'm misunderstanding the API, but would the case actually occur that
_stderrStream.read() does not return null but there are still more lines to be
read using readLine or read? Shouldn't the call to read() be the end?

[zundel, 2012/02/29 20:19:08]

(see next comment).

+        if (result == null) {
+          var buf = new List<int>(available);
+          _process.stderr.readInto(buf, 0, available);;

[Siggi Cherem (dart-lang), 2012/02/29 19:13:32]

extra ;

[Emily Fortuna, 2012/02/29 19:59:03]

_stderrStream was instantiated from new StringInputStream(_process.stderr), so
shouldn't _process.stderr be empty already?

[zundel, 2012/02/29 20:19:08]

I didn't know about 1407 and filed this bug to try to explain why I felt the
need to work around this way.

http://code.google.com/p/dart/issues/detail?id=1926

You'd think you could never get to this point, but it remains that
_process.stderr.available() returns a positive number after the call to both
read() and readLine().  In fact, a call to StringInputStream.read() or
.readLine() does not actually read from the underlying stream at all.  It just
delivers up data that's already be read in and processes it through the decoder
to turn it into a string.

Its great that this means there's no chance this call will block, but then your
call to read() is possibly leaving unread data waiting to be read.  Seems like a
possible inefficiency.

+          result = new String.fromCharCodes(buf);
+          _testStderr.add(result);
+          break;
+        }
+      }
+      _testStderr.add(result);
+    }
+  }
+  
   int _reportResult(String output) {
+    _drainStderr();
     var test = _currentTest;
     _currentTest = null;
 
     // output = '>>> TEST {PASS, FAIL, OK, CRASH, FAIL, TIMEOUT}'
     var outcome = output.split(" ")[2];
     var exitCode = 0;
     if (outcome == "CRASH") exitCode = -10;
     if (outcome == "FAIL" || outcome == "TIMEOUT") exitCode = 1;
     new TestOutput(test, exitCode, outcome == "TIMEOUT", _testStdout,
                    _testStderr, new Date.now().difference(_startTime));
     test.completed();
   }
 
-  Function _readOutput(StringInputStream stream, List<String> buffer) {
+  Function _readStdout(StringInputStream stream, List<String> buffer) {
     return () {
       var status;
       var line = stream.readLine();
       // Drain the input stream to get the error output.
       while (line != null) {
         if (line.startsWith('>>> TEST')) {
           status = line;
         } else if (line.startsWith('>>> BATCH START')) {
           // ignore
         } else if (line.startsWith('>>> ')) {
           throw new Exception('Unexpected command from dartc batch runner.');
         } else {
           buffer.add(line);
         }
         line = stream.readLine();
       }
       if (status != null) {
         _timer.cancel();
         // For crashing processes, let the exit handler deal with it.
         if (!status.contains("CRASH")) {
           _reportResult(status);
         }
       }
     };
   }
+  
+  Function _readStderr(StringInputStream stream, List<String> buffer) {
+    return () {

[Emily Fortuna, 2012/02/29 19:59:03]

Check out makeReadHandler on line 334. 
whesse also has the line: 
if (source.closed) return;  // TODO(whesse): Remove when bug is fixed.
I don't know what the particular bug is, but you may want to have a similar test
in this function, too. Or, better yet, share code between makeReadHandler and
this method (and maybe _readStdout).

[zundel, 2012/02/29 20:19:08]

I just got rid of _readStdout() and replaced it with _makeReadHandler() and put
the  if stream.closed() logic
in _readStdout()

+      var line;
+      while ((line = stream.readLine()) != null) {
+        buffer.add(line);
+      }
+    };
+  }
 
   void _exitHandler(exitCode) {
     if (_timer != null) _timer.cancel();
+    _reportResult(">>> TEST CRASH");
     _process.close();
-    _startProcess(() {
-      _reportResult(">>> TEST CRASH");
-    });
+    _startProcess();
   }
 
   void _timeoutHandler(ignore) {
-    _process.exitHandler = (exitCode) {
+    _process.exitHandler = (exitCode) {_
+      reportResult(">>> TEST TIMEOUT");
       _process.close();
-      _startProcess(() {
-        _reportResult(">>> TEST TIMEOUT");
-      });
+      _startProcess();
     };
     _process.kill();
   }
 
-  void _startProcess(then) {
+  void _startProcess([Function then = null]) {
     _process = new Process.start(_executable, _batchArguments);
     _stdoutStream = new StringInputStream(_process.stdout);
     _stderrStream = new StringInputStream(_process.stderr);
-    _testStdout = new List<String>();
-    _testStderr = new List<String>();
-    _stdoutStream.lineHandler = _readOutput(_stdoutStream, _testStdout);
-    _stderrStream.lineHandler = _readOutput(_stderrStream, _testStderr);
+    _testStdout = [];
+    _testStderr = [];
+    _stdoutStream.lineHandler = _readStdout(_stdoutStream, _testStdout);
+    _stderrStream.lineHandler = _readStderr(_stderrStream, _testStderr);
     _process.exitHandler = _exitHandler;
     _process.startHandler = then;
   }
 }
 
 /**
  * ProcessQueue is the master control class, responsible for running all
  * the tests in all the TestSuites that have been registered.  It includes
  * a rate-limited queue to run a limited number of tests in parallel,
  * a ProgressIndicator which prints output when tests are started and
@@ skipping 230 matching lines @@
         // the developer doesn't waste his or her time trying to fix a bunch of
         // tests that appear to be broken but were actually just flakes that
         // didn't get retried because there had already been one failure.
         bool allowRetry = _MAX_FAILED_NO_RETRY > _progress.numFailedTests;
         new RunningProcess(test, allowRetry, this).start();
       }
       _numProcesses++;
     }
   }
 }