Logging

_test_common/lib/test_environment.dart

@@ -6,7 +6,6 @@ import 'dart:async';
 
 import 'package:build/build.dart';
 import 'package:build_runner_core/build_runner_core.dart';
-import 'package:logging/logging.dart';
 
 import 'common.dart';
 
@@ -32,8 +31,6 @@ class TestBuildEnvironment implements BuildEnvironment {
   /// [prompt].
   final bool throwOnPrompt;
 
-  final logRecords = <LogRecord>[];
-
   /// The next response for calls to [prompt]. Must be set before calling
   /// [prompt].
   set nextPromptResponse(int next) {
@@ -48,9 +45,6 @@ class TestBuildEnvironment implements BuildEnvironment {
     this.throwOnPrompt = false,
   }) : _readerWriter = readerWriter ?? TestReaderWriter();
 
-  @override
-  void onLog(LogRecord record) => logRecords.add(record);
-
   /// Prompt the user for input.
   ///
   /// The message and choices are displayed to the user and the index of the
@@ -67,17 +61,14 @@ class TestBuildEnvironment implements BuildEnvironment {
   }
 
   @override
-  BuildEnvironment copyWith({
-    void Function(LogRecord)? onLogOverride,
-    RunnerAssetWriter? writer,
-    AssetReader? reader,
-  }) => TestBuildEnvironment(
-    readerWriter:
-        (writer as TestReaderWriter?) ??
-        (reader as TestReaderWriter?) ??
-        _readerWriter,
-    throwOnPrompt: throwOnPrompt,
-  );
+  BuildEnvironment copyWith({RunnerAssetWriter? writer, AssetReader? reader}) =>
+      TestBuildEnvironment(
+        readerWriter:
+            (writer as TestReaderWriter?) ??
+            (reader as TestReaderWriter?) ??
+            _readerWriter,
+        throwOnPrompt: throwOnPrompt,
+      );
 
   @override
   Future<BuildResult> finalizeBuild(

_test_common/lib/test_phases.dart

@@ -141,15 +141,9 @@ Future<TestBuildersResult> testPhases(
     packageGraph,
     reader: readerWriter,
     writer: readerWriter,
-    onLogOverride: onLog,
-  );
-  var logSubscription = LogSubscription(
-    environment,
-    verbose: verbose,
-    logLevel: logLevel,
   );
+  BuildLog().configure(verbose: verbose, logLevel: logLevel, onLog: onLog);
   var options = await BuildOptions.create(
-    logSubscription,
     deleteFilesByDefault: deleteFilesByDefault,
     packageGraph: packageGraph,
     skipBuildScriptCheck: true,
@@ -172,7 +166,6 @@ Future<TestBuildersResult> testPhases(
     buildFilters: buildFilters,
   );
   await build.beforeExit();
-  await options.logListener.cancel();
 
   if (checkBuildStatus) {
     checkBuild(

build/lib/src/builder/logging.dart

@@ -21,6 +21,7 @@ Logger get log => Zone.current[logKey] as Logger? ?? _default;
 /// be logged with `log.severe`.
 ///
 /// Completes with the first error or result of `fn`, whichever comes first.
+/// TODO move to BuildLog.
 Future<T> scopeLogAsync<T>(Future<T> Function() fn, Logger log) {
   var done = Completer<T>();
   runZonedGuarded(
@@ -42,3 +43,23 @@ Future<T> scopeLogAsync<T>(Future<T> Function() fn, Logger log) {
   });
   return done.future;
 }
+
+/// Runs [fn] in an error handling [Zone].
+///
+/// Any calls to [print] will be logged with `log.info`, and any errors will be
+/// logged with `log.severe`.
+/// TODO move to BuildLog.
+T? scopeLogSync<T>(T Function() fn, Logger log) {
+  return runZonedGuarded(
+    fn,
+    (e, st) {
+      log.severe('', e, st);
+    },
+    zoneSpecification: ZoneSpecification(
+      print: (self, parent, zone, message) {
+        log.info(message);
+      },
+    ),
+    zoneValues: {logKey: log},
+  );
+}

build/lib/src/state/filesystem_cache.dart

@@ -6,10 +6,15 @@ import 'dart:async';
 import 'dart:convert';
 import 'dart:typed_data';
 
+// ignore: implementation_imports
+import 'package:build_runner_core/src/logging/build_log.dart';
+
 import '../../build.dart';
 import '../asset/id.dart';
 import 'lru_cache.dart';
 
+final BuildLog _log = BuildLog();
+
 /// Cache for file existence and contents.
 ///
 /// TODO(davidmorgan): benchmark, optimize the caching strategy.
@@ -154,10 +159,12 @@ class InMemoryFilesystemCache implements FilesystemCache {
 
   @override
   void flush() {
-    for (final write in _pendingWrites.values) {
-      write.writer();
-    }
-    _pendingWrites.clear();
+    _log.attribute(Attribution.write, () {
+      for (final write in _pendingWrites.values) {
+        write.writer();
+      }
+      _pendingWrites.clear();
+    });
   }
 
   @override

build_resolvers/lib/src/analysis_driver_model.dart

@@ -11,9 +11,13 @@ import 'package:build/build.dart';
 import 'package:build/src/internal.dart';
 // ignore: implementation_imports
 import 'package:build_runner_core/src/generate/build_step_impl.dart';
+// ignore: implementation_imports
+import 'package:build_runner_core/src/logging/build_log.dart';
 
 import 'analysis_driver_filesystem.dart';
 
+final _log = BuildLog();
+
 /// Manages analysis driver and related build state.
 ///
 /// - Tracks the import graph of all sources needed for analysis.
@@ -115,13 +119,16 @@ class AnalysisDriverModel {
 
     // If requested, find transitive imports.
     if (transitive) {
-      // Note: `transitiveDepsOf` can cause loads that cause builds that cause a
-      // recursive `_performResolve` on this same `AnalysisDriver` instance.
-      final nodeLoader = AssetDepsLoader(buildStep.phasedReader);
-      buildStep.inputTracker.addResolverEntrypoint(entrypoint);
-      idsToSyncOntoFilesystem = await _graphLoader.transitiveDepsOf(
-        nodeLoader,
-        entrypoint,
+      idsToSyncOntoFilesystem = await _log.attributeAsync(
+        Attribution.track,
+        () async {
+          // Note: `transitiveDepsOf` can cause loads that cause builds that
+          // cause a recursive `_performResolve` on this same `AnalysisDriver`
+          // instance.
+          final nodeLoader = AssetDepsLoader(buildStep.phasedReader);
+          buildStep.inputTracker.addResolverEntrypoint(entrypoint);
+          return await _graphLoader.transitiveDepsOf(nodeLoader, entrypoint);
+        },
       );
     } else {
       // Notify [buildStep] of its inputs.

build_resolvers/lib/src/resolver.dart

@@ -21,6 +21,8 @@ import 'package:analyzer/src/clients/build_resolvers/build_resolvers.dart';
 import 'package:async/async.dart';
 import 'package:build/build.dart';
 import 'package:build/experiments.dart';
+// ignore: implementation_imports
+import 'package:build_runner_core/src/logging/build_log.dart';
 import 'package:collection/collection.dart' show IterableExtension;
 import 'package:package_config/package_config.dart';
 import 'package:path/path.dart' as p;
@@ -197,22 +199,22 @@ class PerActionResolver implements ReleasableResolver {
 class AnalyzerResolver implements ReleasableResolver {
   final AnalysisDriverModel _analysisDriverModel;
   final AnalysisDriverForPackageBuild _driver;
-  final Pool _driverPool;
+  final AttributingPool _driverPool;
   final SharedResourcePool _readAndWritePool;
 
   Future<List<LibraryElement>>? _sdkLibraries;
 
   AnalyzerResolver(
     this._driver,
-    this._driverPool,
+    Pool driverPool,
     this._readAndWritePool,
     this._analysisDriverModel,
-  );
+  ) : _driverPool = AttributingPool(driverPool);
 
   @override
   Future<bool> isLibrary(AssetId assetId) async {
     if (assetId.extension != '.dart') return false;
-    return _driverPool.withResource(() {
+    return _driverPool.withResource(() async {
       if (!_driver.isUriOfExistingFile(assetId.uri)) return false;
       var result =
           _driver.currentSession.getFile(
@@ -655,3 +657,18 @@ Future<String> packagePath(String package) async {
   var libRoot = await Isolate.resolvePackageUri(Uri.parse('package:$package/'));
   return p.dirname(p.fromUri(libRoot));
 }
+
+final _log = BuildLog();
+
+/// Wraps [pool] so accesses are attributed as [Attribution.analyze].
+class AttributingPool {
+  final Pool pool;
+
+  AttributingPool(this.pool);
+
+  Future<T> withResource<T>(Future<T> Function() function) async {
+    return pool.withResource(
+      () => _log.attributeAsync(Attribution.analyze, function),
+    );
+  }
+}

build_resolvers/lib/src/sdk_summary.dart

@@ -7,13 +7,13 @@ import 'dart:io';
 
 import 'package:analyzer/dart/sdk/build_sdk_summary.dart';
 import 'package:analyzer/file_system/physical_file_system.dart';
-import 'package:logging/logging.dart';
+import 'package:build_runner_core/build_runner_core.dart';
 import 'package:path/path.dart' as p;
 
 import 'human_readable_duration.dart';
 import 'resolver.dart' show packagePath;
 
-final _logger = Logger('build_resolvers');
+final _log = BuildLog();
 
 /// `true` if the currently running dart was provided by the Flutter SDK.
 final isFlutter =
@@ -63,7 +63,7 @@ Future<String> defaultSdkSummaryGenerator() async {
   // Generate the summary and version files if necessary.
   if (needsRebuild) {
     var watch = Stopwatch()..start();
-    _logger.info('Generating SDK summary...');
+    _log.info('Generating SDK summary...');
     await Directory(cacheDir).create(recursive: true);
     final tempDir = await Directory(cacheDir).createTemp();
     final tempFile = File(p.join(tempDir.path, p.basename(summaryPath)));
@@ -82,7 +82,7 @@ Future<String> defaultSdkSummaryGenerator() async {
     await _createDepsFile(depsFile, currentDeps);
     await tempDir.delete();
     watch.stop();
-    _logger.info(
+    _log.info(
       'Generating SDK summary completed, took '
       '${humanReadable(watch.elapsed)}\n',
     );

build_runner/bin/build_runner.dart

@@ -10,15 +10,15 @@ import 'package:args/command_runner.dart';
 import 'package:build_runner/src/build_script_generate/bootstrap.dart';
 import 'package:build_runner/src/entrypoint/options.dart';
 import 'package:build_runner/src/entrypoint/runner.dart';
-import 'package:build_runner/src/logging/std_io_logging.dart';
 import 'package:build_runner_core/build_runner_core.dart';
 import 'package:io/ansi.dart';
 import 'package:io/io.dart';
-import 'package:logging/logging.dart';
 
 import 'src/commands/clean.dart';
 import 'src/commands/generate_build_script.dart';
 
+final _log = BuildLog();
+
 Future<void> main(List<String> args) async {
   // Use the actual command runner to parse the args and immediately print the
   // usage information if there is no command provided or the help command was
@@ -77,26 +77,11 @@ Future<void> main(List<String> args) async {
     return;
   }
 
-  StreamSubscription logListener;
   if (commandName == 'daemon') {
-    // Simple logs only in daemon mode. These get converted into info or
-    // severe logs by the client.
-    logListener = Logger.root.onRecord.listen((record) {
-      if (record.level >= Level.SEVERE) {
-        var buffer = StringBuffer(record.message);
-        if (record.error != null) buffer.writeln(record.error);
-        if (record.stackTrace != null) buffer.writeln(record.stackTrace);
-        stderr.writeln(buffer);
-      } else {
-        stdout.writeln(record.message);
-      }
-    });
+    _log.configure(mode: BuildLogMode.daemon);
   } else {
     var verbose = parsedArgs.command!['verbose'] as bool? ?? false;
-    if (verbose) Logger.root.level = Level.ALL;
-    logListener = Logger.root.onRecord.listen(
-      stdIOLogListener(verbose: verbose),
-    );
+    _log.configure(verbose: verbose);
   }
   if (localCommandNames.contains(commandName)) {
     exitCode = await commandRunner.runCommand(parsedArgs) ?? 1;
@@ -105,5 +90,4 @@ Future<void> main(List<String> args) async {
     while ((exitCode = await generateAndRun(args, experiments: experiments)) ==
         ExitCode.tempFail.code) {}
   }
-  await logListener.cancel();
 }

build_runner/bin/src/commands/clean.dart

@@ -27,7 +27,7 @@ class CleanCommand extends Command<int> {
 
   @override
   Future<int> run() async {
-    await cleanFor(assetGraphPathFor(scriptLocation), logger);
+    await cleanFor(assetGraphPathFor(scriptLocation));
     return 0;
   }
 }