Introduce --report-timings flag for flutter build aot command. (#30032)

This flag makes flutter build aot report timings for substeps (e.g.
frontend compilation and gen_snapshot) in a machine readable form.

packages/flutter_tools/lib/src/base/build.dart

@@ -70,6 +70,13 @@ class GenSnapshot {
 }
 
 class AOTSnapshotter {
+  AOTSnapshotter({this.reportTimings = false});
+
+  /// If true then AOTSnapshotter would report timings for individual building
+  /// steps (Dart front-end parsing and snapshot generation) in a stable
+  /// machine readable form. See [AOTSnapshotter._timedStep].
+  final bool reportTimings;
+
   /// Builds an architecture-specific ahead-of-time compiled snapshot of the specified script.
   Future<int> build({
     @required TargetPlatform platform,
@@ -197,11 +204,11 @@ class AOTSnapshotter {
     }
 
     final SnapshotType snapshotType = SnapshotType(platform, buildMode);
-    final int genSnapshotExitCode = await genSnapshot.run(
+    final int genSnapshotExitCode = await _timedStep('gen_snapshot', () => genSnapshot.run(
       snapshotType: snapshotType,
       additionalArgs: genSnapshotArgs,
       iosArch: iosArch,
-    );
+    ));
     if (genSnapshotExitCode != 0) {
       printError('Dart snapshot generator failed with exit code $genSnapshotExitCode');
       return genSnapshotExitCode;
@@ -309,7 +316,7 @@ class AOTSnapshotter {
 
     final String depfilePath = fs.path.join(outputPath, 'kernel_compile.d');
     final KernelCompiler kernelCompiler = await kernelCompilerFactory.create(flutterProject);
-    final CompilerOutput compilerOutput = await kernelCompiler.compile(
+    final CompilerOutput compilerOutput = await _timedStep('frontend', () => kernelCompiler.compile(
       sdkRoot: artifacts.getArtifactPath(Artifact.flutterPatchedSdkPath),
       mainPath: mainPath,
       packagesPath: packagesPath,
@@ -323,7 +330,7 @@ class AOTSnapshotter {
       aot: true,
       trackWidgetCreation: trackWidgetCreation,
       targetProductVm: buildMode == BuildMode.release,
-    );
+    ));
 
     // Write path to frontend_server, since things need to be re-generated when that changes.
     final String frontendPath = artifacts.getArtifactPath(Artifact.frontendServerSnapshotForEngineDartSdk);
@@ -345,6 +352,20 @@ class AOTSnapshotter {
   String _getPackagePath(PackageMap packageMap, String package) {
     return fs.path.dirname(fs.path.fromUri(packageMap.map[package]));
   }
+
+  /// This method is used to measure duration of an action and emit it into
+  /// verbose output from flutter_tool for other tools (e.g. benchmark runner)
+  /// to find.
+  /// Important: external performance tracking tools expect format of this
+  /// output to be stable.
+  Future<T> _timedStep<T>(String marker, FutureOr<T> Function() action) async {
+    final Stopwatch sw = Stopwatch()..start();
+    final T value = await action();
+    if (reportTimings) {
+      printStatus('$marker(RunTime): ${sw.elapsedMilliseconds} ms.');
+    }
+    return value;
+  }
 }
 
 class JITSnapshotter {

packages/flutter_tools/lib/src/commands/build_aot.dart

@@ -33,6 +33,11 @@ class BuildAotCommand extends BuildSubCommand {
         defaultsTo: false,
         help: 'Compile to a *.so file (requires NDK when building for Android).',
       )
+      ..addFlag('report-timings',
+        negatable: false,
+        defaultsTo: false,
+        help: 'Report timing information about build steps in machine readable form,',
+      )
       ..addMultiOption('ios-arch',
         splitCommas: true,
         defaultsTo: defaultIOSArchs.map<String>(getNameForIOSArch),
@@ -73,9 +78,10 @@ class BuildAotCommand extends BuildSubCommand {
       );
     }
     final String outputPath = argResults['output-dir'] ?? getAotBuildDirectory();
+    final bool reportTimings = argResults['report-timings'];
     try {
       String mainPath = findMainDartFile(targetFile);
-      final AOTSnapshotter snapshotter = AOTSnapshotter();
+      final AOTSnapshotter snapshotter = AOTSnapshotter(reportTimings: reportTimings);
 
       // Compile to kernel.
       mainPath = await snapshotter.compileKernel(

packages/flutter_tools/test/base/build_test.dart

@@ -13,6 +13,7 @@ import 'package:flutter_tools/src/base/build.dart';
 import 'package:flutter_tools/src/base/context.dart';
 import 'package:flutter_tools/src/base/file_system.dart';
 import 'package:flutter_tools/src/base/io.dart';
+import 'package:flutter_tools/src/base/logger.dart';
 import 'package:flutter_tools/src/base/process.dart';
 import 'package:flutter_tools/src/ios/mac.dart';
 import 'package:flutter_tools/src/version.dart';
@@ -87,9 +88,11 @@ void main() {
     _FakeGenSnapshot genSnapshot;
     MemoryFileSystem fs;
     AOTSnapshotter snapshotter;
+    AOTSnapshotter snapshotterWithTimings;
     MockAndroidSdk mockAndroidSdk;
     MockArtifacts mockArtifacts;
     MockXcode mockXcode;
+    BufferLogger bufferLogger;
 
     setUp(() async {
       fs = MemoryFileSystem();
@@ -105,9 +108,11 @@ void main() {
 
       genSnapshot = _FakeGenSnapshot();
       snapshotter = AOTSnapshotter();
+      snapshotterWithTimings = AOTSnapshotter(reportTimings: true);
       mockAndroidSdk = MockAndroidSdk();
       mockArtifacts = MockArtifacts();
       mockXcode = MockXcode();
+      bufferLogger = BufferLogger();
       for (BuildMode mode in BuildMode.values) {
         when(mockArtifacts.getArtifactPath(Artifact.snapshotDart, any, mode)).thenReturn(kSnapshotDart);
       }
@@ -119,6 +124,7 @@ void main() {
       FileSystem: () => fs,
       GenSnapshot: () => genSnapshot,
       Xcode: () => mockXcode,
+      Logger: () => bufferLogger,
     };
 
     testUsingContext('iOS debug AOT snapshot is invalid', () async {
@@ -491,6 +497,36 @@ void main() {
       ]);
     }, overrides: contextOverrides);
 
+    testUsingContext('reports timing', () async {
+      fs.file('main.dill').writeAsStringSync('binary magic');
+
+      final String outputPath = fs.path.join('build', 'foo');
+      fs.directory(outputPath).createSync(recursive: true);
+
+      genSnapshot.outputs = <String, String>{
+        fs.path.join(outputPath, 'vm_snapshot_data'): '',
+        fs.path.join(outputPath, 'isolate_snapshot_data'): '',
+        fs.path.join(outputPath, 'vm_snapshot_instr'): '',
+        fs.path.join(outputPath, 'isolate_snapshot_instr'): '',
+      };
+
+      final RunResult successResult = RunResult(ProcessResult(1, 0, '', ''), <String>['command name', 'arguments...']);
+      when(xcode.cc(any)).thenAnswer((_) => Future<RunResult>.value(successResult));
+      when(xcode.clang(any)).thenAnswer((_) => Future<RunResult>.value(successResult));
+
+      final int genSnapshotExitCode = await snapshotterWithTimings.build(
+        platform: TargetPlatform.android_arm,
+        buildMode: BuildMode.release,
+        mainPath: 'main.dill',
+        packagesPath: '.packages',
+        outputPath: outputPath,
+        buildSharedLibrary: false,
+      );
+
+      expect(genSnapshotExitCode, 0);
+      expect(genSnapshot.callCount, 1);
+      expect(bufferLogger.statusText, matches(RegExp(r'gen_snapshot\(RunTime\): \d+ ms.')));
+    }, overrides: contextOverrides);
   });
 
   group('Snapshotter - JIT', () {