[hooks_runner] Add TimelineEvents

pkgs/hooks_runner/CHANGELOG.md

@@ -1,3 +1,8 @@
+## 0.20.2
+
+* Add `dart:developer` `TimelineEvent`s to enable performance tracing for
+  hook invocations.
+
 ## 0.20.1
 
 * Bump the SDK constraint to at least the one from `package:hooks` to fix

pkgs/hooks_runner/lib/src/build_runner/build_planner.dart

@@ -3,6 +3,7 @@
 // BSD-style license that can be found in the LICENSE file.
 
 import 'dart:convert';
+import 'dart:developer';
 
 import 'package:file/file.dart';
 import 'package:graphs/graphs.dart' as graphs;
@@ -19,13 +20,16 @@ typedef BuildPlan = List<Package>;
 
 @internal
 class NativeAssetsBuildPlanner {
+  final TimelineTask task;
+
   final PackageGraph packageGraph;
   final Uri dartExecutable;
   final Logger logger;
   final PackageLayout packageLayout;
   final FileSystem fileSystem;
 
   NativeAssetsBuildPlanner._({
+    required this.task,
     required this.packageGraph,
     required this.dartExecutable,
     required this.logger,
@@ -39,11 +43,12 @@ class NativeAssetsBuildPlanner {
     required Logger logger,
     required PackageLayout packageLayout,
     required FileSystem fileSystem,
+    TimelineTask? task,
   }) async {
     final packageGraphJsonFile = fileSystem.file(
       packageConfigUri.resolve('package_graph.json'),
     );
-    assert(packageGraphJsonFile.existsSync());
+    assert(await packageGraphJsonFile.exists());
     final packageGraphJson = await packageGraphJsonFile.readAsString();
     final packageGraph = PackageGraph.fromPackageGraphJsonString(
       packageGraphJson,
@@ -57,17 +62,22 @@ class NativeAssetsBuildPlanner {
       logger: logger,
       packageLayout: packageLayout,
       fileSystem: fileSystem,
+      task: task ?? TimelineTask(),
     );
   }
 
   /// All packages in [PackageLayout.packageConfig] with native assets.
   ///
   /// Whether a package has native assets is defined by whether it contains
   /// a `hook/build.dart` or `hook/link.dart`.
-  Future<List<Package>> packagesWithHook(Hook hook) async => switch (hook) {
-    Hook.build => _packagesWithBuildHook ??= await _runPackagesWithHook(hook),
-    Hook.link => _packagesWithLinkHook ??= await _runPackagesWithHook(hook),
-  };
+  Future<List<Package>> packagesWithHook(Hook hook) async => _timeAsync(
+    'BuildPlanner.packagesWithHook',
+    arguments: {'hook': hook.toString()},
+    () async => switch (hook) {
+      Hook.build => _packagesWithBuildHook ??= await _runPackagesWithHook(hook),
+      Hook.link => _packagesWithLinkHook ??= await _runPackagesWithHook(hook),
+    },
+  );
 
   List<Package>? _packagesWithBuildHook;
   List<Package>? _packagesWithLinkHook;
@@ -113,38 +123,53 @@ class NativeAssetsBuildPlanner {
   /// a cyclic dependency is detected among packages with native asset build
   /// hooks, the [Result] is a [Failure] containing a
   /// [HooksRunnerFailure.projectConfig].
-  Future<Result<BuildPlan, HooksRunnerFailure>> makeBuildHookPlan() async {
-    if (_buildHookPlan != null) return Success(_buildHookPlan!);
-    final packagesWithNativeAssets = await packagesWithHook(Hook.build);
-    if (packagesWithNativeAssets.isEmpty) {
-      // Avoid calculating the package graph if there are no hooks.
-      return const Success([]);
-    }
-    final packageMap = {
-      for (final package in packagesWithNativeAssets) package.name: package,
-    };
-    final packagesToBuild = packageMap.keys.toSet();
-    final stronglyConnectedComponents = packageGraph.computeStrongComponents();
-    final result = <Package>[];
-    for (final stronglyConnectedComponent in stronglyConnectedComponents) {
-      final stronglyConnectedComponentWithNativeAssets = [
-        for (final packageName in stronglyConnectedComponent)
-          if (packagesToBuild.contains(packageName)) packageName,
-      ];
-      if (stronglyConnectedComponentWithNativeAssets.length > 1) {
-        logger.severe(
-          'Cyclic dependency for native asset builds in the following '
-          'packages: $stronglyConnectedComponentWithNativeAssets.',
-        );
-        return const Failure(HooksRunnerFailure.projectConfig);
-      } else if (stronglyConnectedComponentWithNativeAssets.length == 1) {
-        result.add(
-          packageMap[stronglyConnectedComponentWithNativeAssets.single]!,
-        );
-      }
+  Future<Result<BuildPlan, HooksRunnerFailure>> makeBuildHookPlan() async =>
+      _timeAsync('BuildPlanner.makeBuildHookPlan', () async {
+        if (_buildHookPlan != null) return Success(_buildHookPlan!);
+        final packagesWithNativeAssets = await packagesWithHook(Hook.build);
+        if (packagesWithNativeAssets.isEmpty) {
+          // Avoid calculating the package graph if there are no hooks.
+          return const Success([]);
+        }
+        final packageMap = {
+          for (final package in packagesWithNativeAssets) package.name: package,
+        };
+        final packagesToBuild = packageMap.keys.toSet();
+        final stronglyConnectedComponents = packageGraph
+            .computeStrongComponents();
+        final result = <Package>[];
+        for (final stronglyConnectedComponent in stronglyConnectedComponents) {
+          final stronglyConnectedComponentWithNativeAssets = [
+            for (final packageName in stronglyConnectedComponent)
+              if (packagesToBuild.contains(packageName)) packageName,
+          ];
+          if (stronglyConnectedComponentWithNativeAssets.length > 1) {
+            logger.severe(
+              'Cyclic dependency for native asset builds in the following '
+              'packages: $stronglyConnectedComponentWithNativeAssets.',
+            );
+            return const Failure(HooksRunnerFailure.projectConfig);
+          } else if (stronglyConnectedComponentWithNativeAssets.length == 1) {
+            result.add(
+              packageMap[stronglyConnectedComponentWithNativeAssets.single]!,
+            );
+          }
+        }
+        _buildHookPlan = result;
+        return Success(result);
+      });
+
+  Future<T> _timeAsync<T>(
+    String name,
+    Future<T> Function() function, {
+    Map<String, Object>? arguments,
+  }) async {
+    task.start(name, arguments: arguments);
+    try {
+      return await function();
+    } finally {
+      task.finish();
     }
-    _buildHookPlan = result;
-    return Success(result);
   }
 }