Add what changed and what is built to verbose logging. (#3937)

* Add what changed and what is built to verbose logging.

* Address review comments.

Author: davidmorgan

build_runner/CHANGELOG.md

@@ -11,6 +11,7 @@
 - Remove `OnDeleteWriter`, add functionality to `ReaderWriter`.
 - Add `NodeType` to `AssetNode`, remove subtypes. Make mutations explicit.
 - Use `built_value` for `AssetNode` and related types.
+- Add details of what changed and what is built to `--verbose` logging.
 
 ## 2.4.15
 

build_runner/lib/src/logging/std_io_logging.dart

@@ -26,7 +26,7 @@ StringBuffer colorLog(LogRecord record, {required bool verbose}) {
   final level = color.wrap('[${record.level}]');
   final eraseLine = ansiOutputEnabled && !verbose ? '\x1b[2K\r' : '';
   var lines = <Object>[
-    '$eraseLine$level ${_recordHeader(record, verbose)}${record.message}',
+    '$eraseLine$level ${_recordHeader(record)}${record.message}',
   ];
 
   if (record.error != null) {
@@ -64,9 +64,9 @@ void _stdIOLogListener(LogRecord record, {required bool verbose}) =>
 
 /// Filter out the Logger names which aren't coming from specific builders and
 /// splits the header for levels >= WARNING.
-String _recordHeader(LogRecord record, bool verbose) {
+String _recordHeader(LogRecord record) {
   var maybeSplit = record.level >= Level.WARNING ? '\n' : '';
-  return verbose || record.loggerName.contains(' ')
+  return record.loggerName.contains(' ')
       ? '${record.loggerName}:$maybeSplit'
       : '';
 }

build_runner_core/CHANGELOG.md

@@ -20,6 +20,7 @@
   `AssetWriterSpy` functionality.
 - Add `NodeType` to `AssetNode`, remove subtypes. Make mutations explicit.
 - Use `built_value` for `AssetNode` and related types, and for serialization.
+- Add details of what changed and what is built to `--verbose` logging.
 
 ## 8.0.0
 

build_runner_core/lib/src/changes/asset_updates.dart

@@ -0,0 +1,68 @@
+// Copyright (c) 2025, 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.
+
+import 'package:build/build.dart';
+import 'package:built_collection/built_collection.dart';
+import 'package:watcher/watcher.dart';
+
+import '../logging/log_renderer.dart';
+
+/// Asset updates for an incremental build.
+class AssetUpdates {
+  final BuiltSet<AssetId> added;
+  final BuiltSet<AssetId> modified;
+  final BuiltSet<AssetId> removed;
+
+  AssetUpdates({
+    required this.added,
+    required this.modified,
+    required this.removed,
+  });
+
+  factory AssetUpdates.from(Map<AssetId, ChangeType> updates) {
+    final added = <AssetId>[];
+    final modified = <AssetId>[];
+    final removed = <AssetId>[];
+    for (final update in updates.entries) {
+      switch (update.value) {
+        case ChangeType.ADD:
+          added.add(update.key);
+          break;
+        case ChangeType.MODIFY:
+          modified.add(update.key);
+          break;
+        case ChangeType.REMOVE:
+          removed.add(update.key);
+          break;
+      }
+    }
+    return AssetUpdates(
+      added: (added..sort()).toBuiltSet(),
+      modified: (modified..sort()).toBuiltSet(),
+      removed: (removed..sort()).toBuiltSet(),
+    );
+  }
+
+  bool get isEmpty => added.isEmpty && modified.isEmpty && removed.isEmpty;
+
+  /// Explain what was updated, for logging.
+  String render(LogRenderer renderer) {
+    if (isEmpty) {
+      return 'Updates: none.';
+    }
+
+    final result = <String>[];
+    if (added.isNotEmpty) {
+      result.add('added ${renderer.trimmedIds(added)}');
+    }
+    if (modified.isNotEmpty) {
+      result.add('modified ${renderer.trimmedIds(modified)}');
+    }
+    if (removed.isNotEmpty) {
+      result.add('removed ${renderer.trimmedIds(removed)}');
+    }
+
+    return 'Updates: ${result.join('; ')}.';
+  }
+}

build_runner_core/lib/src/generate/build.dart

@@ -20,10 +20,12 @@ import '../asset/writer.dart';
 import '../asset_graph/graph.dart';
 import '../asset_graph/node.dart';
 import '../asset_graph/optional_output_tracker.dart';
+import '../changes/asset_updates.dart';
 import '../environment/build_environment.dart';
 import '../logging/build_for_input_logger.dart';
 import '../logging/failure_reporter.dart';
 import '../logging/human_readable_duration.dart';
+import '../logging/log_renderer.dart';
 import '../logging/logging.dart';
 import '../performance_tracking/performance_tracking_resolvers.dart';
 import '../util/build_dirs.dart';
@@ -56,8 +58,10 @@ class Build {
   final RunnerAssetWriter deleteWriter;
 
   // Logging.
-  final BuildPerformanceTracker _performanceTracker;
+  final LogRenderer renderer;
+  final BuildPerformanceTracker performanceTracker;
   late final HungActionsHeartbeat hungActionsHeartbeat;
+  final bool logFine;
 
   // State.
   final AssetGraph assetGraph;
@@ -78,10 +82,12 @@ class Build {
     required this.deleteWriter,
     required this.resourceManager,
     required this.assetGraph,
-  }) : _performanceTracker =
+  }) : renderer = LogRenderer(rootPackageName: options.packageGraph.root.name),
+       performanceTracker =
            options.trackPerformance
                ? BuildPerformanceTracker()
-               : BuildPerformanceTracker.noOp() {
+               : BuildPerformanceTracker.noOp(),
+       logFine = _logger.level <= Level.FINE {
     hungActionsHeartbeat = HungActionsHeartbeat(() {
       final message = StringBuffer();
       const actionsToLogMax = 5;
@@ -101,6 +107,10 @@ class Build {
   }
 
   Future<BuildResult> run(Map<AssetId, ChangeType> updates) async {
+    if (logFine) {
+      _logger.fine(AssetUpdates.from(updates).render(renderer));
+    }
+
     var watch = Stopwatch()..start();
     var result = await _safeBuild(updates);
     var optionalOutputTracker = OptionalOutputTracker(
@@ -164,7 +174,6 @@ class Build {
   /// capturing.
   Future<BuildResult> _safeBuild(Map<AssetId, ChangeType> updates) {
     var done = Completer<BuildResult>();
-
     var heartbeat = HeartbeatLogger(
       transformLog: (original) => '$original, ${_buildProgress()}',
       waitDuration: const Duration(seconds: 1),
@@ -238,13 +247,13 @@ class Build {
   /// Runs the actions in [buildPhases] and returns a future which completes
   /// to the [BuildResult] once all [BuildPhase]s are done.
   Future<BuildResult> _runPhases() {
-    return _performanceTracker.track(() async {
+    return performanceTracker.track(() async {
       final outputs = <AssetId>[];
       for (var phaseNum = 0; phaseNum < buildPhases.length; phaseNum++) {
         var phase = buildPhases[phaseNum];
         if (phase.isOptional) continue;
         outputs.addAll(
-          await _performanceTracker.trackBuildPhase(phase, () async {
+          await performanceTracker.trackBuildPhase(phase, () async {
             if (phase is InBuildPhase) {
               var primaryInputs = await _matchingPrimaryInputs(
                 phase.package,
@@ -268,7 +277,7 @@ class Build {
       return BuildResult(
         BuildStatus.success,
         outputs,
-        performance: _performanceTracker,
+        performance: performanceTracker,
       );
     });
   }
@@ -392,7 +401,7 @@ class Build {
     AssetId input,
   ) async {
     final builder = phase.builder;
-    var tracker = _performanceTracker.addBuilderAction(
+    var tracker = performanceTracker.addBuilderAction(
       input,
       phase.builderLabel,
     );
@@ -433,7 +442,7 @@ class Build {
 
       if (!await tracker.trackStage(
         'Setup',
-        () => _buildShouldRun(builderOutputs, readerWriter),
+        () => _buildShouldRun(input, builderOutputs, readerWriter),
       )) {
         return <AssetId>[];
       }
@@ -667,6 +676,7 @@ class Build {
 
   /// Checks and returns whether any [outputs] need to be updated.
   Future<bool> _buildShouldRun(
+    AssetId input,
     Iterable<AssetId> outputs,
     AssetReader reader,
   ) async {
@@ -682,6 +692,12 @@ class Build {
     for (var output in outputs.skip(1)) {
       if (assetGraph.get(output)!.generatedNodeState!.pendingBuildAction ==
           PendingBuildAction.build) {
+        if (logFine) {
+          _logger.fine(
+            'Build ${renderer.build(input, outputs)} because '
+            '${renderer.id(output)} was marked for build.',
+          );
+        }
         return true;
       }
     }
@@ -713,19 +729,48 @@ class Build {
 
     // Early bail out condition, this is a forced update.
     if (firstNodeState.pendingBuildAction == PendingBuildAction.build) {
+      if (logFine) {
+        _logger.fine(
+          'Build ${renderer.build(input, outputs)} because '
+          '${renderer.id(firstNode.id)} was marked for build.',
+        );
+      }
       return true;
     }
     // This is a fresh build or the first time we've seen this output.
-    if (firstNodeState.previousInputsDigest == null) return true;
+    if (firstNodeState.previousInputsDigest == null) {
+      if (logFine) {
+        _logger.fine(
+          'Build ${renderer.build(input, outputs)} because '
+          '${renderer.id(firstNode.id)} has no previousInputsDigest.',
+        );
+      }
+      return true;
+    }
 
     var digest = await _computeCombinedDigest(
       firstNodeState.inputs,
       firstNode.generatedNodeConfiguration!.builderOptionsId,
       reader,
     );
     if (digest != firstNodeState.previousInputsDigest) {
+      if (logFine) {
+        _logger.fine(
+          'Build ${renderer.build(input, outputs)} because '
+          'inputs digest changed '
+          'from ${renderer.digest(firstNodeState.previousInputsDigest)} '
+          'to ${renderer.digest(digest)}.',
+        );
+      }
       return true;
     } else {
+      if (logFine) {
+        _logger.fine(
+          'Skip bulding ${renderer.build(input, outputs)} because '
+          'inputs digest is still '
+          '${renderer.digest(firstNodeState.previousInputsDigest)}.',
+        );
+      }
       // Make sure to update the `state` field for all outputs.
       for (var id in outputs) {
         assetGraph.updateNode(id, (nodeBuilder) {

build_runner_core/lib/src/logging/log_renderer.dart

@@ -0,0 +1,83 @@
+// Copyright (c) 2025, 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.
+
+import 'package:build/build.dart';
+import 'package:crypto/crypto.dart';
+
+/// Renders objects to strings for display in logs.
+class LogRenderer {
+  final String rootPackageName;
+
+  LogRenderer({required this.rootPackageName});
+
+  /// Renders [id].
+  ///
+  /// Like `AssetId.toString`, except the package name is omitted if it matches
+  /// [rootPackageName].
+  String id(AssetId id) {
+    if (id.package == rootPackageName) {
+      return id.path;
+    } else {
+      return id.toString();
+    }
+  }
+
+  /// Renders a build action with [input] and [outputs].
+  ///
+  /// Output names that mostly match [input] are shortened to remove the
+  /// duplication.
+  ///
+  /// Examples: `foo.dart->.g.dart`, `foo.dart->(.g.dart, .other.dart)`
+  String build(AssetId input, Iterable<AssetId> outputs) {
+    final displayedInput = id(input);
+    // If the input ends in `.dart`, take the base name and trim it from all
+    // outputs. So for example `foo.dart->foo.g.dart` is shortened to
+    // `foo.dart->.g.dart`.
+    final trimPrefix =
+        displayedInput.endsWith('.dart')
+            ? displayedInput.substring(0, displayedInput.length - 5)
+            : null;
+    final displayedOutputs =
+        outputs.length == 1
+            ? _trim(id(outputs.first), trimPrefix: trimPrefix)
+            : '(${trimmedIds(outputs, trimPrefix: trimPrefix)})';
+    return '$displayedInput->$displayedOutputs';
+  }
+
+  /// Returns [ids] converted to `String` as a comma-separated list,
+  /// with all ids beyond the third replaced by "(# more)".
+  ///
+  /// If [trimPrefix] is passed, trim the specified prefix from all items where
+  /// it matches.
+  String trimmedIds(Iterable<AssetId> ids, {String? trimPrefix}) {
+    final firstThree = ids
+        .map(id)
+        .take(3)
+        .map((s) => _trim(s, trimPrefix: trimPrefix));
+    if (firstThree.length == ids.length) {
+      return firstThree.join(', ');
+    } else {
+      return [...firstThree, '(${ids.length - 3} more)'].join(', ');
+    }
+  }
+
+  /// Renders [digest].
+  ///
+  /// Returns `none` for null, or the first seven characters of the digest.
+  String digest(Digest? digest) {
+    if (digest == null) return 'none';
+    var result = digest.toString();
+    if (result.length > 7) result = result.substring(0, 7);
+    return result;
+  }
+
+  /// Returns [string] with [trimPrefix] removed if it matches.
+  static String _trim(String string, {String? trimPrefix}) {
+    if (trimPrefix == null) return string;
+    if (string.startsWith(trimPrefix)) {
+      return string.substring(trimPrefix.length);
+    }
+    return string;
+  }
+}