Use Zone to correctly measure async operations.

pkg/compiler/lib/src/apiimpl.dart

Index: pkg/compiler/lib/src/apiimpl.dart
diff --git a/pkg/compiler/lib/src/apiimpl.dart b/pkg/compiler/lib/src/apiimpl.dart
index 3fe63b6a34d04449cf97a2d77f51a41881cf9fe9..7539fe77b9be95c80c32d03ec7529d72f9f4638a 100644
--- a/pkg/compiler/lib/src/apiimpl.dart
+++ b/pkg/compiler/lib/src/apiimpl.dart
@@ -14,7 +14,7 @@ import 'package:package_config/src/packages_impl.dart'
 import 'package:package_config/src/util.dart' show checkValidPackageUri;
 
 import '../compiler_new.dart' as api;
-import 'common/tasks.dart' show GenericTask;
+import 'common/tasks.dart' show GenericTask, Measurer;
 import 'common.dart';
 import 'compiler.dart';
 import 'diagnostics/messages.dart' show Message;
@@ -159,14 +159,14 @@ class CompilerImpl extends Compiler {
 
   Future<elements.LibraryElement> analyzeUri(Uri uri,
       {bool skipLibraryWithPartOfTag: true}) {
-    List<Future> setupFutures = new List<Future>();
+    Future setupFuture = new Future.value();
     if (resolvedUriTranslator.isNotSet) {
-      setupFutures.add(setupSdk());
+      setupFuture = setupFuture.then((_) => setupSdk());
     }
     if (packages == null) {
-      setupFutures.add(setupPackages(uri));
+      setupFuture = setupFuture.then((_) => setupPackages(uri));
     }
-    return Future.wait(setupFutures).then((_) {
+    return setupFuture.then((_) {
       return super
           .analyzeUri(uri, skipLibraryWithPartOfTag: skipLibraryWithPartOfTag);
     });
@@ -224,33 +224,59 @@ class CompilerImpl extends Compiler {
   }
 
   Future<bool> run(Uri uri) {
-    log('Using platform configuration at ${options.platformConfigUri}');
-
-    return Future.wait([setupSdk(), setupPackages(uri)]).then((_) {
-      assert(resolvedUriTranslator.isSet);
-      assert(packages != null);
-
-      return super.run(uri).then((bool success) {
-        int cumulated = 0;
-        for (final task in tasks) {
-          int elapsed = task.timing;
-          if (elapsed != 0) {
-            cumulated += elapsed;
-            log('${task.name} took ${elapsed}msec');
-            for (String subtask in task.subtasks) {
-              int subtime = task.getSubtaskTime(subtask);
-              log('${task.name} > $subtask took ${subtime}msec');
-            }
-          }
+    Duration setupDuration = measurer.wallClock.elapsed;
+    return selfTask.measureSubtask("CompilerImpl.run", () {
+      log('Using platform configuration at ${options.platformConfigUri}');
+
+      return setupSdk().then((_) => setupPackages(uri)).then((_) {
+        assert(resolvedUriTranslator.isSet);
+        assert(packages != null);
+
+        return super.run(uri);
+      }).then((bool success) {
+        if (options.verbose) {
+          StringBuffer timings = new StringBuffer();
+          computeTimings(setupDuration, timings);
+          log("$timings");
         }
-        int total = totalCompileTime.elapsedMilliseconds;
-        log('Total compile-time ${total}msec;'
-            ' unaccounted ${total - cumulated}msec');
         return success;
       });
     });
   }
 
+  void computeTimings(Duration setupDuration, StringBuffer timings) {
+    timings.writeln("Timings:");
+    Duration totalDuration = measurer.wallClock.elapsed;
+    Duration asyncDuration = measurer.asyncWallClock.elapsed;
+    Duration cumulatedDuration = Duration.ZERO;
+    for (final task in tasks) {
+      String running = task.isRunning ? "*" : "";
+      Duration duration = task.duration;
+      if (duration != Duration.ZERO) {
+        cumulatedDuration += duration;
+        timings.writeln(
+            '    $running${task.name} took'
+            ' ${duration.inMilliseconds}msec');
+        for (String subtask in task.subtasks) {
+          int subtime = task.getSubtaskTime(subtask);
+          String running = task.getSubtaskIsRunning(subtask) ? "*" : "";
+          timings.writeln(
+              '    $running${task.name} > $subtask took ${subtime}msec');
+        }
+      }
+    }
+    Duration unaccountedDuration =
+        totalDuration - cumulatedDuration - setupDuration - asyncDuration;
+    double percent = unaccountedDuration.inMilliseconds * 100
+        / totalDuration.inMilliseconds;
+    timings.write(
+        '    Total compile-time ${totalDuration.inMilliseconds}msec;'
+        ' setup ${setupDuration.inMilliseconds}msec;'
+        ' async ${asyncDuration.inMilliseconds}msec;'
+        ' unaccounted ${unaccountedDuration.inMilliseconds}msec'
+        ' (${percent.toStringAsFixed(2)}%)');
+  }
+
   void reportDiagnostic(DiagnosticMessage message,
       List<DiagnosticMessage> infos, api.Diagnostic kind) {
     _reportDiagnosticMessage(message, kind);
@@ -284,12 +310,12 @@ class CompilerImpl extends Compiler {
   }
 
   Future callUserProvider(Uri uri) {
-    return userProviderTask.measure(() => provider.readFromUri(uri));
+    return userProviderTask.measureIo(() => provider.readFromUri(uri));
   }
 
   Future<Packages> callUserPackagesDiscovery(Uri uri) {
     return userPackagesDiscoveryTask
-        .measure(() => options.packagesDiscoveryProvider(uri));
+        .measureIo(() => options.packagesDiscoveryProvider(uri));
   }
 
   Uri resolvePatchUri(String libraryName) {