Cache output of dart2js compilations that went wrong on disk.

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 74 matching lines @@
   }
 
   bool _equal(Command other) {
     return hashCode == other.hashCode &&
         commandLine == other.commandLine &&
         displayName == other.displayName;
   }
 
   String toString() => reproductionCommand;
 
-  Future<bool> get outputIsUpToDate => new Future.value(false);
+  Future<CachedState> get outputIsUpToDate => 
+      new Future.value(const CachedState(false, false));

[kustermann, 2014/04/29 21:20:44]

It's not so nice that the Command class itself has a property of type
CacheState, which contains compilation logic (compilation logic should only live
in the CompilationCommand subclass).

The only reason why you need this CachedState class at the moment, is because
you only write the output files if the 'exitCode' was nonzero. You could write
stdout/stderr/extitCode/... always out to a file (even for successful
compilations) eliminating this problem. The cost would be one more file, with a
bit of content, but looking at what dart2js compilation currently outputs for
some tests (e.g. a polymer test):
-rw-r----- ... 1.1M ...  /tmp/foobar.js
-rw-r----- ... 23K   ...  /tmp/foobar.js.deps
-rw-r----- ... 367K ...  /tmp/foobar.js.map
-rw-r----- ... 1.6M ...  /tmp/foobar.precompiled.js

I don't think < 1k of stdout/stderr would matter much (just the deps file would
usually be 5-10x bigger than stdout/stderr).

Additional benefit: If a test fails at runtime and the compilation was skipped,
we could still show stdout/stderr from dart2js in the failure output (which we
currently don't have).

[ricow1, 2014/04/30 06:51:01]

This is actually no different then the fact that it already had a
outputIsUpToDate function which is only relevant for compilation commands!
There is a tradeoff here, do you want to to split using is XCommand in specific
code or do you want additional stuff in your main interface. Look below why this
is no longer a problem.
This is probably not the general case, I would expect simple tests to have a
much lower difference. That said, I am not concerned about disk space here.
I actually started out by doing this, but decided against it  since it
complicated the general logic in the RunningProcess class. It just occurred to
me now that there is no reason whatsoever that I should still be looking at the
timestamp of the dart2js generated file - I should just be looking at the cached
CommandOutput file - I don't know why I had in my mind that I needed to look at
both.

I changed now the logic to only look at the new file, much better and smaller
code - removed CachedState

+  
+  Future<String> get cachedOutput => new Future.value(null);
+  Future writeCachedOutput(CommandOutput output) => new Future.value(null);
 }
 
+class CachedState {
+  const CachedState(this.upToDateCompilation,
+                 this.upToDateCommandOutput);
+  final bool upToDateCompilation;
+  final bool upToDateCommandOutput;
+}
+
+
 class ProcessCommand extends Command {
   /** Path to the executable of this command. */
   String executable;
 
   /** Command line arguments to the executable. */
   List<String> arguments;
 
   /** Environment for the command */
   Map<String, String> environmentOverrides;
 
@@ skipping 49 matching lines @@
 
   String get reproductionCommand {
     var command = ([executable]..addAll(arguments))
         .map(escapeCommandLineArgument).join(' ');
     if (workingDirectory != null) {
       command = "$command (working directory: $workingDirectory)";
     }
     return command;
   }
 
-  Future<bool> get outputIsUpToDate => new Future.value(false);
+  Future<CachedState> get outputIsUpToDate => 
+      new Future.value(const CachedState(false, false));
 }
 
 class CompilationCommand extends ProcessCommand {
   String _outputFile;
   bool _neverSkipCompilation;
   List<Uri> _bootstrapDependencies;
 
+  Future writeCachedOutput(CommandOutput output) {
+    var file = new io.File(TestUtils.cachedOutputFile(_outputFile));
+    return file.writeAsString(output.json);
+  }
+
+  Future<CommandOutput> get cachedOutput {
+    var file = new io.File(TestUtils.cachedOutputFile(_outputFile));
+    return file.exists().then((exists) {
+      if (exists) return file.readAsString().then((content) {
+        return new CompilationCommandOutputImpl.fromJson(this, content);
+      });;
+    });
+  }
+
   CompilationCommand._(String displayName,
                        this._outputFile,
                        this._neverSkipCompilation,
                        List<Uri> bootstrapDependencies,
                        String executable,
                        List<String> arguments,
                        Map<String, String> environmentOverrides)
       : super._(displayName, executable, arguments, environmentOverrides) {
     // We sort here, so we can do a fast hashCode/operator==
     _bootstrapDependencies = new List.from(bootstrapDependencies);
     _bootstrapDependencies.sort();
   }
 
-  Future<bool> get outputIsUpToDate {
+  Future<CachedState> get outputIsUpToDate {
     if (_neverSkipCompilation) return new Future.value(false);

[Bill Hesse, 2014/04/29 17:51:55]

Shouldn't these return CachedState objects?

[kustermann, 2014/04/29 21:20:44]

BTW: I hope we did not disable '--checked' mode when running test.dart :)

[ricow1, 2014/04/30 06:51:01]

We did not

[ricow1, 2014/04/30 06:51:01]

Done.

-
     Future<List<Uri>> readDepsFile(String path) {
       var file = new io.File(new Path(path).toNativePath());
       if (!file.existsSync()) {
         return new Future.value(null);
       }
       return file.readAsLines().then((List<String> lines) {
         var dependencies = new List<Uri>();
         for (var line in lines) {
           line = line.trim();
           if (line.length > 0) {
             dependencies.add(Uri.parse(line));
           }
         }
         return dependencies;
       });
     }
 
+    bool isUpToDate(lastModified, dependencies) {
+      if (lastModified == null) return false;
+      for (var dependency in dependencies) {
+        var dependencyLastModified =
+          TestUtils.lastModifiedCache.getLastModified(dependency);
+        if (dependencyLastModified == null ||
+            dependencyLastModified.isAfter(lastModified)) {
+          return false;
+        }
+      }
+      return true;
+    }
+
     return readDepsFile("$_outputFile.deps").then((dependencies) {
       if (dependencies != null) {
         dependencies.addAll(_bootstrapDependencies);
-        var jsOutputLastModified = TestUtils.lastModifiedCache.getLastModified(
+        var lastModified = TestUtils.lastModifiedCache.getLastModified(
             new Uri(scheme: 'file', path: _outputFile));
-        if (jsOutputLastModified != null) {
-          for (var dependency in dependencies) {
-            var dependencyLastModified =
-                TestUtils.lastModifiedCache.getLastModified(dependency);
-            if (dependencyLastModified == null ||
-                dependencyLastModified.isAfter(jsOutputLastModified)) {
-              return false;
-            }
+        if (isUpToDate(lastModified, dependencies)) {
+          return const CachedState(true, false);

[Bill Hesse, 2014/04/29 17:51:55]

Is CachedState(true, false) really meaning CachedState(true, ignored), since
having the right compiled output means we don't need the output?  If so, the
class should document that.  Why is true, true not a better choice here?

[ricow1, 2014/04/30 06:51:01]

Because it would not be true - if we have up to date compilation output it means
that compilation succeeded, i.e., we would not have saved the command output -
it is not up to date.
That said, I removed CachedState class again

+        } else {
+          // We did not have real output, check if we have stored the 
+          // output of running the compiler on this test for a failed run.
+          var cachedOutputFile = TestUtils.cachedOutputFile(_outputFile);
+          var cachedOutputUri = new Uri(scheme: 'file', path: cachedOutputFile);
+          var cachedOutputLastModified = 
+              TestUtils.lastModifiedCache.getLastModified(cachedOutputUri);
+          if (isUpToDate(cachedOutputLastModified, dependencies)) {
+            return const CachedState(false, true);
           }
-          return true;
         }
       }
-      return false;
+      return const CachedState(false, false);
     });
   }
 
   void _buildHashCode(HashCodeBuilder builder) {
     super._buildHashCode(builder);
     builder.add(_outputFile);
     builder.add(_neverSkipCompilation);
     for (var uri in _bootstrapDependencies) builder.add(uri);
   }
 
@@ skipping 676 matching lines @@
 
   int get pid;
 
   List<int> get stdout;
 
   List<int> get stderr;
 
   List<String> get diagnostics;
 
   bool get compilationSkipped;
+
+  String get json;
 }
 
 class CommandOutputImpl extends UniqueObject implements CommandOutput {
   Command command;
   int exitCode;
 
   bool timedOut;
   List<int> stdout;
   List<int> stderr;
   Duration time;
@@ skipping 69 matching lines @@
 
   Expectation _negateOutcomeIfNegativeTest(Expectation outcome,
                                            bool isNegative) {
     if (!isNegative) return outcome;
 
     if (outcome.canBeOutcomeOf(Expectation.FAIL)) {
       return Expectation.PASS;
     }
     return Expectation.FAIL;
   }
+
+  String get json => null;
+
 }
 
 class BrowserCommandOutputImpl extends CommandOutputImpl {
   // Although tests are reported as passing, content shell sometimes exits with
   // a nonzero exitcode which makes our dartium builders extremely falky.
   // See: http://dartbug.com/15139.
   static int WHITELISTED_CONTENTSHELL_EXITCODE = -1073740022;
   static bool isWindows = io.Platform.operatingSystem == 'windows';
 
   bool _failedBecauseOfMissingXDisplay;
@@ skipping 577 matching lines @@
       // We expected to run the test, but we got an compile time error.
       // If the compilation succeeded, we wouldn't be in here!
       assert(exitCode != 0);
       return Expectation.COMPILETIME_ERROR;
     }
 
     Expectation outcome =
         exitCode == 0 ? Expectation.PASS : Expectation.COMPILETIME_ERROR;
     return _negateOutcomeIfNegativeTest(outcome, testCase.isNegative);
   }
+
+  String get json {
+    var map = {
+    'stdout': stdout,
+    'stderr': stderr,
+    'exitCode': exitCode,
+    'timedOut': timedOut,

[kustermann, 2014/04/29 21:20:44]

It may make sense to also add 'time' here, not sure though.

[ricow1, 2014/04/30 06:51:01]

I did so at first, but removed it, since it would give counter intuitive numbers
in the reporting (with the --time flag). I would be surprised to see compilation
taking the top 20 spots when I did not do any compilations :-)

+    };
+    return JSON.encode(map);
+  }
+
+  factory CompilationCommandOutputImpl.fromJson(Command command,
+                                                String json) {
+    var obj = JSON.decode(json);
+    for (var v in ['stdout', 'stderr', 'exitCode', 'timedOut']) {
+      assert(obj.containsKey(v));
+    }
+    return new CompilationCommandOutputImpl(command,
+                                            obj['exitCode'],
+                                            obj['timedOut'],
+                                            obj['stdout'],
+                                            obj['stderr'],
+                                            const Duration(seconds: 0),
+                                            true);
+                                            
+  }
 }
 
 class JsCommandlineOutputImpl extends CommandOutputImpl
                               with UnittestSuiteMessagesMixin {
   JsCommandlineOutputImpl(Command command, int exitCode, bool timedOut,
       List<int> stdout, List<int> stderr, Duration time)
       : super(command, exitCode, timedOut, stdout, stderr, time, false, 0);
 
   Expectation result(TestCase testCase) {
     // Handle crashes and timeouts first
@@ skipping 177 matching lines @@
   RunningProcess(this.command, this.timeout);
 
   Future<CommandOutput> run() {
     completer = new Completer<CommandOutput>();
     startTime = new DateTime.now();
     _runCommand();
     return completer.future;
   }
 
   void _runCommand() {
-    command.outputIsUpToDate.then((bool isUpToDate) {
-      if (isUpToDate) {
+    command.outputIsUpToDate.then((CachedState cachedState) {
+      if (cachedState.upToDateCompilation) {
         compilationSkipped = true;
         _commandComplete(0);
+      } else if (cachedState.upToDateCommandOutput) {
+        compilationSkipped = true;
+        command.cachedOutput.then((cached) {
+          _commandComplete(cached.exitCode, cachedOutput: cached);
+        });
       } else {
         var processEnvironment = _createProcessEnvironment();
         Future processFuture =
             io.Process.start(command.executable,
                              command.arguments,
                              environment: processEnvironment,
                              workingDirectory: command.workingDirectory);
         processFuture.then((io.Process process) {
           StreamSubscription stdoutSubscription =
               _drainStream(process.stdout, stdout);
@@ skipping 72 matching lines @@
           print("Process error:");
           print("  Command: $command");
           print("  Error: $e");
           _commandComplete(-1);
           return true;
         });
       }
     });
   }
 
-  void _commandComplete(int exitCode) {
+  void _commandComplete(int exitCode, {cachedOutput: null}) {
     if (timeoutTimer != null) {
       timeoutTimer.cancel();
     }
-    var commandOutput = _createCommandOutput(command, exitCode);
-    completer.complete(commandOutput);
+    if (cachedOutput != null) {
+      completer.complete(cachedOutput);
+    } else {
+      var commandOutput = _createCommandOutput(command, exitCode);
+      if (exitCode != 0) {
+        command.writeCachedOutput(commandOutput);
+      }

[Bill Hesse, 2014/04/29 17:51:55]

Should we put a try-catch around this?  Or make writeCachedOutput never throw? 
Or do we want to crash in this case?

[ricow1, 2014/04/30 06:51:01]

Changed writeCachedOutput to not ever throw

+      completer.complete(commandOutput);
+    }
   }
 
   CommandOutput _createCommandOutput(ProcessCommand command, int exitCode) {
     var commandOutput = createCommandOutput(
         command,
         exitCode,
         timedOut,
         stdout.toList(),
         stderr.toList(),
         new DateTime.now().difference(startTime),
@@ skipping 1053 matching lines @@
     }
   }
 
   void eventAllTestsDone() {
     for (var listener in _eventListener) {
       listener.allDone();
     }
     _allDone();
   }
 }