fe: minor change to benchmarks to match what the runners expect

pkg/front_end/tool/perf.dart

 // Copyright (c) 2016, 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.
 
 /// An entrypoint used to run portions of front_end and measure its performance.
 library front_end.tool.perf;
 
 import 'dart:async';
 import 'dart:io' show exit;
 
@@ skipping 19 matching lines @@
 import 'package:front_end/src/scanner/token.dart';
 import 'package:kernel/kernel.dart';
 import 'package:package_config/discovery.dart';
 
 main(List<String> args) async {
   // TODO(sigmund): provide sdk folder as well.
   if (args.length < 2) {
     print('usage: perf.dart <bench-id> <entry.dart>');
     exit(1);
   }
-  var totalTimer = new Stopwatch()..start();
 
   var bench = args[0];
   var entryUri = Uri.base.resolve(args[1]);
 
   await setup(entryUri);
 
+  Set<Source> files = scanReachableFiles(entryUri);
   var handlers = {
-    'scan': () async {
-      Set<Source> files = scanReachableFiles(entryUri);
-      // TODO(sigmund): replace the warmup with instrumented snapshots.
-      for (int i = 0; i < 10; i++) scanFiles(files);
-    },
-    'parse': () async {
-      Set<Source> files = scanReachableFiles(entryUri);
-      // TODO(sigmund): replace the warmup with instrumented snapshots.
-      for (int i = 0; i < 10; i++) parseFiles(files);
-    },
+    'scan': () async => scanFiles(files),
+    'parse': () async => parseFiles(files),
     'kernel_gen_e2e': () async {
-      // TODO(sigmund): remove. This is used to compute the input size, we
-      // should extract input size from frontend instead.
-      scanReachableFiles(entryUri);
-      // TODO(sigmund): replace this warmup. Note that for very large programs,
-      // the GC pressure on the VM seems to make this worse with time (maybe we
-      // are leaking memory?). That's why we run it twice and not 10 times.
-      for (int i = 0; i < 2; i++) {
-        await generateKernel(entryUri, useSdkSummary: false);
-      }
+      await generateKernel(entryUri, useSdkSummary: false);
     },
     'kernel_gen_e2e_sum': () async {
-      // TODO(sigmund): remove. This is incorrect since it includes sizes for
-      // files that will not be loaded when using summaries. We need to extract
-      // input size from frontend instead.
-      scanReachableFiles(entryUri);
-      // TODO(sigmund): replace this warmup. Note that for very large programs,
-      // the GC pressure on the VM seems to make this worse with time (maybe we
-      // are leaking memory?). That's why we run it twice and not 10 times.
-      for (int i = 0; i < 2; i++) {
-        await generateKernel(entryUri, useSdkSummary: true, compileSdk: false);
-      }
+      await generateKernel(entryUri, useSdkSummary: true, compileSdk: false);
     },
-    'unlinked_summarize': () async {
-      Set<Source> files = scanReachableFiles(entryUri);
-      // TODO(sigmund): replace the warmup with instrumented snapshots.
-      for (int i = 0; i < 10; i++) unlinkedSummarizeFiles(files);
-    },
-    'prelinked_summarize': () async {
-      Set<Source> files = scanReachableFiles(entryUri);
-      // TODO(sigmund): replace the warmup with instrumented snapshots.
-      for (int i = 0; i < 10; i++) prelinkedSummarizeFiles(files);
-    },
-    'linked_summarize': () async {
-      Set<Source> files = scanReachableFiles(entryUri);
-      // TODO(sigmund): replace the warmup with instrumented snapshots.
-      for (int i = 0; i < 10; i++) linkedSummarizeFiles(files);
-    }
+    'unlinked_summarize': () async => summarize(files),
+    'prelinked_summarize': () async => summarize(files, prelink: true),
+    'linked_summarize': () async => summarize(files, link: true),
   };
 
   var handler = handlers[bench];
   if (handler == null) {
-    // TODO(sigmund): implement the remaining benchmarks.
     print('unsupported bench-id: $bench. Please specify one of the following: '
         '${handlers.keys.join(", ")}');
     exit(1);
   }
-  await handler();
 
-  totalTimer.stop();
-  report("total", totalTimer.elapsedMicroseconds);
+  // TODO(sigmund): replace the warmup with instrumented snapshots.
+  int iterations = bench.contains('kernel_gen') ? 2 : 10;
+  for (int i = 0; i < iterations; i++) {
+    var totalTimer = new Stopwatch()..start();
+    print('== iteration $i');
+    await handler();
+    totalTimer.stop();
+    report("total", totalTimer.elapsedMicroseconds);
+  }
+
 }
 
 /// Cumulative time spent parsing.
 Stopwatch parseTimer = new Stopwatch();
 
-/// Cumulative time spent prelinking summaries.
-Stopwatch prelinkSummaryTimer = new Stopwatch();
+/// Cumulative time spent building unlinked summaries.
+Stopwatch unlinkedSummarizeTimer = new Stopwatch();
 
 /// Cumulative time spent scanning.
 Stopwatch scanTimer = new Stopwatch();
 
-/// Cumulative total number of chars scanned.
-int scanTotalChars = 0;
+/// Size of all sources.
+int inputSize = 0;
 
 /// Factory to load and resolve app, packages, and sdk sources.
 SourceFactory sources;
 
-/// Cumulative time spent building unlinked summaries.
-Stopwatch unlinkedSummarizeTimer = new Stopwatch();
-
 /// Add to [files] all sources reachable from [start].
 void collectSources(Source start, Set<Source> files) {
   if (!files.add(start)) return;
   var unit = parseDirectives(start);
   for (var directive in unit.directives) {
     if (directive is UriBasedDirective) {
       var next = sources.resolveUri(start, directive.uri.stringValue);
       collectSources(next, files);
     }
   }
 }
 
 Future<Program> generateKernel(Uri entryUri,
     {bool useSdkSummary: false, bool compileSdk: true}) async {
+  // TODO(sigmund): this is here only to compute the input size,
+  // we should extract the input size from the frontend instead.
+  scanReachableFiles(entryUri);
+
   var dartkTimer = new Stopwatch()..start();
   // TODO(sigmund): add a constructor with named args to compiler options.
   var options = new CompilerOptions()
     ..strongMode = false
     ..compileSdk = compileSdk
     ..packagesFilePath = '.packages'
     ..onError = ((e) => print('${e.message}'));
   if (useSdkSummary) {
     // TODO(sigmund): adjust path based on the benchmark runner architecture.
     // Possibly let the runner make the file available at an architecture
     // independent location.
     options.sdkSummary = 'out/ReleaseX64/dart-sdk/lib/_internal/spec.sum';
   } else {
     options.sdkPath = 'sdk';
   }
   Program program = await kernelForProgram(entryUri, options);
   dartkTimer.stop();
   var suffix = useSdkSummary ? "_sum" : "";
   report("kernel_gen_e2e${suffix}", dartkTimer.elapsedMicroseconds);
   return program;
 }
 
 /// Generates unlinkmed summaries for all files in [files], and returns them in
-/// an [UnlinkedSummaries] container.
-UnlinkedSummaries generateUnlinkedSummaries(Set<Source> files) {
-  var unlinkedSummaries = new UnlinkedSummaries();
+/// an [_UnlinkedSummaries] container.
+_UnlinkedSummaries generateUnlinkedSummaries(Set<Source> files) {
+  var unlinkedSummaries = new _UnlinkedSummaries();
   for (var source in files) {
     unlinkedSummaries.summariesByUri[source.uri.toString()] =
         unlinkedSummarize(source);
   }
   return unlinkedSummaries;
 }
 
 /// Produces linked summaries for every file in [files] and reports the time

[Paul Berry, 2017/01/03 17:58:34]

Doc comment is no longer accurate.

[Siggi Cherem (dart-lang), 2017/01/04 00:01:04]

Done.

 /// spent doing so.
-void linkedSummarizeFiles(Set<Source> files) {
-  // The code below will record again how many chars are scanned and how long it
-  // takes to scan them, even though we already did so in [scanReachableFiles].
-  // Recording and reporting this twice is unnecessary, but we do so for now to
-  // validate that the results are consistent.
+void summarize(Set<Source> files, {bool prelink: false, bool link: false}) {
   scanTimer = new Stopwatch();
-  var old = scanTotalChars;
-  scanTotalChars = 0;
   parseTimer = new Stopwatch();
   unlinkedSummarizeTimer = new Stopwatch();
   var unlinkedSummaries = generateUnlinkedSummaries(files);
-  prelinkSummaryTimer = new Stopwatch();
-  Map<String, LinkedLibraryBuilder> prelinkedLibraries =
-      prelinkSummaries(files, unlinkedSummaries);
-  var linkTimer = new Stopwatch()..start();
-  LinkedLibrary getDependency(String uri) {
-    // getDependency should never be called because all dependencies are present
-    // in [prelinkedLibraries].
-    print('Warning: getDependency called for: $uri');
-    return null;
-  }
-
-  bool strong = true;
-  relink(prelinkedLibraries, getDependency, unlinkedSummaries.getUnit, strong);
-  linkTimer.stop();
-
-  if (old != scanTotalChars) print('input size changed? ${old} chars');
   report("scan", scanTimer.elapsedMicroseconds);
   report("parse", parseTimer.elapsedMicroseconds);
-  report('unlinked summarize', unlinkedSummarizeTimer.elapsedMicroseconds);
+  report('unlink extract', unlinkedSummarizeTimer.elapsedMicroseconds);

[Paul Berry, 2017/01/03 17:58:34]

I don't really have strong feelings about nomenclature here, but can you help me
understand why "extract" is a meaningful name for this benchmark?

[Siggi Cherem (dart-lang), 2017/01/04 00:01:04]

In all honestly, I'm not convinced about "extract" either. The main requirement
I have is that the runner relies on matching the benchmark name (which is an
argument to this script) and the name given to `report`. It's ok to report extra
data, and the runner will ignore it. I believe we will mostly use the data of
"unlinked summarize + parse" as a benchmark, which is why I made that be the one
with the benchmark name "unlinked_summarize" and gave this a different name.

Some ideas:
 (a) do not report the "extract" result at all
 (b) create 2 benchmarks:
    - unlinked_summarize: summarize alone (like you had before my change, aka
"extract")
    - unlinked_summarize_from_source: includes parse time (and maybe scan time
too?)
 (c) change the runner script to aggregate data itself. 

It is much easier to maintain things if we don't do (c). I'm totally fine with
either (a) or (b).

[Paul Berry, 2017/01/04 13:55:43]

In that case I'd prefer (b), on the theory that tracking more information is
better than less :)

   report(
-      'unlinked summarize + parse',
+      'unlinked_summarize',
       unlinkedSummarizeTimer.elapsedMicroseconds +
           parseTimer.elapsedMicroseconds);
-  report('prelink', prelinkSummaryTimer.elapsedMicroseconds);
-  report('link', linkTimer.elapsedMicroseconds);
+
+  if (prelink || link) {
+    var prelinkTimer = new Stopwatch()..start();
+    var prelinkedLibraries = prelinkSummaries(files, unlinkedSummaries);
+    prelinkTimer.stop();
+    report('prelinked_summarize', prelinkTimer.elapsedMicroseconds);
+
+    if (link) {
+      var linkTimer = new Stopwatch()..start();
+      LinkedLibrary getDependency(String uri) {
+        // getDependency should never be called because all dependencies are
+        // present in [prelinkedLibraries].
+        print('Warning: getDependency called for: $uri');
+        return null;
+      }
+
+      relink(prelinkedLibraries, getDependency, unlinkedSummaries.getUnit,
+          true /*strong*/);
+      linkTimer.stop();
+      report('linked_summarize', linkTimer.elapsedMicroseconds);
+    }
+  }
 }
 
 /// Uses the diet-parser to parse only directives in [source].
 CompilationUnit parseDirectives(Source source) {
   var token = tokenize(source);
   var parser = new Parser(source, AnalysisErrorListener.NULL_LISTENER);
   return parser.parseDirectives(token);
 }
 
 /// Parses every file in [files] and reports the time spent doing so.
 void parseFiles(Set<Source> files) {
-  // The code below will record again how many chars are scanned and how long it
-  // takes to scan them, even though we already did so in [scanReachableFiles].
-  // Recording and reporting this twice is unnecessary, but we do so for now to
-  // validate that the results are consistent.
   scanTimer = new Stopwatch();
-  var old = scanTotalChars;
-  scanTotalChars = 0;
   parseTimer = new Stopwatch();
   for (var source in files) {
     parseFull(source);
   }
 
-  // Report size and scanning time again. See discussion above.
-  if (old != scanTotalChars) print('input size changed? ${old} chars');
   report("scan", scanTimer.elapsedMicroseconds);
   report("parse", parseTimer.elapsedMicroseconds);
 }
 
 /// Parse the full body of [source] and return it's compilation unit.
 CompilationUnit parseFull(Source source) {
   var token = tokenize(source);
   parseTimer.start();
   var parser = new Parser(source, AnalysisErrorListener.NULL_LISTENER);
   var unit = parser.parseCompilationUnit(token);
   parseTimer.stop();
   return unit;
 }
 
-/// Produces prelinked summaries for every file in [files] and reports the time
-/// spent doing so.
-void prelinkedSummarizeFiles(Set<Source> files) {
-  // The code below will record again how many chars are scanned and how long it
-  // takes to scan them, even though we already did so in [scanReachableFiles].
-  // Recording and reporting this twice is unnecessary, but we do so for now to
-  // validate that the results are consistent.
-  scanTimer = new Stopwatch();
-  var old = scanTotalChars;
-  scanTotalChars = 0;
-  parseTimer = new Stopwatch();
-  unlinkedSummarizeTimer = new Stopwatch();
-  var unlinkedSummaries = generateUnlinkedSummaries(files);
-  prelinkSummaryTimer = new Stopwatch();
-  prelinkSummaries(files, unlinkedSummaries);
-
-  if (old != scanTotalChars) print('input size changed? ${old} chars');
-  report("scan", scanTimer.elapsedMicroseconds);
-  report("parse", parseTimer.elapsedMicroseconds);
-  report('unlinked summarize', unlinkedSummarizeTimer.elapsedMicroseconds);
-  report(
-      'unlinked summarize + parse',
-      unlinkedSummarizeTimer.elapsedMicroseconds +
-          parseTimer.elapsedMicroseconds);
-  report('prelink', prelinkSummaryTimer.elapsedMicroseconds);
-}
-
 /// Prelinks all the summaries for [files], using [unlinkedSummaries] to obtain
 /// their unlinked summaries.
 ///
 /// The return value is suitable for passing to the summary linker.
 Map<String, LinkedLibraryBuilder> prelinkSummaries(
-    Set<Source> files, UnlinkedSummaries unlinkedSummaries) {
-  prelinkSummaryTimer.start();
-  Set<String> libraryUris =
-      files.map((source) => source.uri.toString()).toSet();
+    Set<Source> files, _UnlinkedSummaries unlinkedSummaries) {
+  Set<String> libraryUris = files.map((source) => '${source.uri}').toSet();
 
   String getDeclaredVariable(String s) => null;
   var prelinkedLibraries =
       setupForLink(libraryUris, unlinkedSummaries.getUnit, getDeclaredVariable);
-  prelinkSummaryTimer.stop();
   return prelinkedLibraries;
 }
 
 /// Report that metric [name] took [time] micro-seconds to process
-/// [scanTotalChars] characters.
+/// [inputSize] characters.
 void report(String name, int time) {
   var sb = new StringBuffer();
-  sb.write('$name: $time us, ${time ~/ 1000} ms');
-  sb.write(', ${scanTotalChars * 1000 ~/ time} chars/ms');
+  var padding = " " * (20 - name.length);
+  sb.write('$name:$padding $time us, ${time ~/ 1000} ms');
+  sb.write(', ${time * 1000 ~/ inputSize} ns/char');
   print('$sb');
 }
 
 /// Scans every file in [files] and reports the time spent doing so.
 void scanFiles(Set<Source> files) {
-  // The code below will record again how many chars are scanned and how long it
-  // takes to scan them, even though we already did so in [scanReachableFiles].
-  // Recording and reporting this twice is unnecessary, but we do so for now to
-  // validate that the results are consistent.
+  // `tokenize` records how many chars are scanned and how long it takes to scan
+  // them. As this function is called repeatedly when running as a benchmark, we
+  // make sure to clear the data and compute it again every time.
   scanTimer = new Stopwatch();
-  var old = scanTotalChars;
-  scanTotalChars = 0;
   for (var source in files) {
     tokenize(source);
   }
 
-  // Report size and scanning time again. See discussion above.
-  if (old != scanTotalChars) print('input size changed? ${old} chars');
   report("scan", scanTimer.elapsedMicroseconds);
 }
 
 /// Load and scans all files we need to process: files reachable from the
 /// entrypoint and all core libraries automatically included by the VM.
 Set<Source> scanReachableFiles(Uri entryUri) {
   var files = new Set<Source>();
   var loadTimer = new Stopwatch()..start();
   collectSources(sources.forUri2(entryUri), files);
 
@@ skipping 10 matching lines @@
     "dart:typed_data",
     "dart:io"
   ];
 
   for (var lib in libs) {
     collectSources(sources.forUri(lib), files);
   }
 
   loadTimer.stop();
 
-  print('input size: ${scanTotalChars} chars');
+  for (var s in files) inputSize += s.contents.data.length;
+  print('input size: ${inputSize} chars');
   var loadTime = loadTimer.elapsedMicroseconds - scanTimer.elapsedMicroseconds;
   report("load", loadTime);
   report("scan", scanTimer.elapsedMicroseconds);
   return files;
 }
 
 /// Sets up analyzer to be able to load and resolve app, packages, and sdk
 /// sources.
 Future setup(Uri entryUri) async {
   var provider = PhysicalResourceProvider.INSTANCE;
   var packageMap = new ContextBuilder(provider, null, null)
       .convertPackagesToMap(await findPackages(entryUri));
   sources = new SourceFactory([
     new ResourceUriResolver(provider),
     new PackageMapUriResolver(provider, packageMap),
     new DartUriResolver(
         new FolderBasedDartSdk(provider, provider.getFolder("sdk"))),
   ]);
 }
 
 /// Scan [source] and return the first token produced by the scanner.
 Token tokenize(Source source) {
   scanTimer.start();
-  var contents = source.contents.data;
-  scanTotalChars += contents.length;
   // TODO(sigmund): is there a way to scan from a random-access-file without
   // first converting to String?
-  var scanner = new _Scanner(contents);
+  var scanner = new _Scanner(source.contents.data);
   var token = scanner.tokenize();
   scanTimer.stop();
   return token;
 }
 
 UnlinkedUnitBuilder unlinkedSummarize(Source source) {
   var unit = parseFull(source);
   unlinkedSummarizeTimer.start();
   var unlinkedUnit = serializeAstUnlinked(unit);
   unlinkedSummarizeTimer.stop();
   return unlinkedUnit;
 }
 
-/// Produces unlinked summaries for every file in [files] and reports the time
-/// spent doing so.
-void unlinkedSummarizeFiles(Set<Source> files) {
-  // The code below will record again how many chars are scanned and how long it
-  // takes to scan them, even though we already did so in [scanReachableFiles].
-  // Recording and reporting this twice is unnecessary, but we do so for now to
-  // validate that the results are consistent.
-  scanTimer = new Stopwatch();
-  var old = scanTotalChars;
-  scanTotalChars = 0;
-  parseTimer = new Stopwatch();
-  unlinkedSummarizeTimer = new Stopwatch();
-  generateUnlinkedSummaries(files);
-
-  if (old != scanTotalChars) print('input size changed? ${old} chars');
-  report("scan", scanTimer.elapsedMicroseconds);
-  report("parse", parseTimer.elapsedMicroseconds);
-  report('unlinked summarize', unlinkedSummarizeTimer.elapsedMicroseconds);
-  report(
-      'unlinked summarize + parse',
-      unlinkedSummarizeTimer.elapsedMicroseconds +
-          parseTimer.elapsedMicroseconds);
-}
-
 /// Simple container for a mapping from URI string to an unlinked summary.
-class UnlinkedSummaries {
+class _UnlinkedSummaries {
   final summariesByUri = <String, UnlinkedUnit>{};
 
   /// Get the unlinked summary for the given URI, and report a warning if it
   /// can't be found.
   UnlinkedUnit getUnit(String uri) {
     var result = summariesByUri[uri];
     if (result == null) {
       print('Warning: no summary found for: $uri');
     }
     return result;
   }
 }
 
 class _Scanner extends Scanner {
   _Scanner(String contents) : super(new CharSequenceReader(contents)) {
     preserveComments = false;
   }
 
   @override
   void reportError(errorCode, int offset, List<Object> arguments) {
     // ignore errors.
   }
 }