Log requests and request failures in build daemon asset server

_test/test/serve_integration_test.dart

@@ -4,7 +4,13 @@
 
 @TestOn('vm')
 import 'dart:convert';
-import 'dart:io' show HttpClient, HttpHeaders, HttpStatus;
+import 'dart:io'
+    show
+        HttpClient,
+        HttpClientRequest,
+        HttpClientResponse,
+        HttpHeaders,
+        HttpStatus;
 
 import 'package:path/path.dart' as p;
 import 'package:test/test.dart';
@@ -15,7 +21,13 @@ void main() {
   late HttpClient httpClient;
 
   setUpAll(() {
-    httpClient = HttpClient();
+    // Configure the client so it is possible to download a large number
+    // of files simultaneously. This prevents getting SocketException on
+    // too many connections.
+    httpClient = HttpClient()
+      ..maxConnectionsPerHost = 200
+      ..idleTimeout = Duration(seconds: 30)
+      ..connectionTimeout = Duration(seconds: 30);
   });
 
   tearDownAll(() {
@@ -157,4 +169,51 @@ void main() {
             .close();
     expect(await utf8.decodeStream(ddcFileResponse), contains('"goodbye"'));
   });
+
+  test('should serve files in parallel', () async {
+    await startServer(buildArgs: [
+      'web',
+      '--build-filter',
+      'web/sub/main.dart.js',
+      '--verbose',
+      '--define',
+      'build_web_compilers|ddc=generate-full-dill=true',
+    ]);
+
+    addTearDown(() async {
+      await stopServer();
+    });
+
+    Future<void> read(String path) async {
+      HttpClientRequest? request;
+      HttpClientResponse? response;
+      try {
+        request = await httpClient.get('localhost', 8080, path);
+        response = await request.close();
+        expect(
+          response.statusCode,
+          HttpStatus.ok,
+          reason: '$path ${response.reasonPhrase}',
+        );
+      } catch (e, s) {
+        fail('Error reading $path: $e:$s');
+      } finally {
+        request?.abort();
+        await response?.drain().catchError((_) {});
+      }
+    }
+
+    const n = 1000;
+    var futures = [
+      for (var i = 0; i < n; i++) read('main.sound.ddc.js'),
+      for (var i = 0; i < n; i++) read('main.sound.ddc.js.map'),
+      for (var i = 0; i < n; i++) read('main.sound.ddc.dill'),
+      for (var i = 0; i < n; i++) read('main.sound.ddc.full.dill'),
+      for (var i = 0; i < n; i++) read('sub/message.sound.ddc.js'),
+      for (var i = 0; i < n; i++) read('sub/message.sound.ddc.js.map'),
+      for (var i = 0; i < n; i++) read('sub/message.sound.ddc.dill'),
+      for (var i = 0; i < n; i++) read('sub/message.sound.ddc.full.dill'),
+    ];
+    await Future.wait(futures);
+  });
 }

build_runner/CHANGELOG.md

@@ -1,4 +1,7 @@
-## 2.0.7-dev
+## 2.1.0-dev
+
+- Add `--log-requests` flag to build daemon.
+- Log failed asset requests in build_runner server.
 
 ## 2.0.6
 

build_runner/lib/src/daemon/asset_server.dart

@@ -5,13 +5,17 @@
 import 'dart:async';
 import 'dart:io';
 
+import 'package:build_runner/src/entrypoint/options.dart';
 import 'package:http_multi_server/http_multi_server.dart';
+import 'package:logging/logging.dart';
 import 'package:shelf/shelf.dart';
 import 'package:shelf/shelf_io.dart' as shelf_io;
 
 import '../server/server.dart';
 import 'daemon_builder.dart';
 
+final _logger = Logger('AssetServer');
+
 class AssetServer {
   final HttpServer _server;
 
@@ -22,6 +26,7 @@ class AssetServer {
   Future<void> stop() => _server.close(force: true);
 
   static Future<AssetServer> run(
+    DaemonOptions options,
     BuildRunnerDaemonBuilder builder,
     String rootPackage,
   ) async {
@@ -30,7 +35,14 @@ class AssetServer {
       await builder.building;
       return Response.notFound('');
     }).add(AssetHandler(builder.reader, rootPackage).handle);
-    shelf_io.serveRequests(server, cascade.handler);
+
+    var pipeline = Pipeline();
+    if (options.logRequests) {
+      pipeline = pipeline.addMiddleware(
+          logRequests(logger: (message, isError) => _logger.finest(message)));
+    }
+
+    shelf_io.serveRequests(server, pipeline.addHandler(cascade.handler));
     return AssetServer._(server);
   }
 }

build_runner/lib/src/entrypoint/daemon.dart

@@ -31,9 +31,14 @@ class DaemonCommand extends WatchCommand {
   String get name => 'daemon';
 
   DaemonCommand() {
-    argParser.addOption(buildModeFlag,
-        help: 'Specify the build mode of the daemon, e.g. auto or manual.',
-        defaultsTo: 'BuildMode.Auto');
+    argParser
+      ..addOption(buildModeFlag,
+          help: 'Specify the build mode of the daemon, e.g. auto or manual.',
+          defaultsTo: 'BuildMode.Auto')
+      ..addFlag(logRequestsOption,
+          defaultsTo: false,
+          negatable: false,
+          help: 'Enables logging for each request to the server.');
   }
 
   @override
@@ -98,7 +103,8 @@ $logEndMarker'''));
           stdout.writeln(log.message);
         }
       });
-      var server = await AssetServer.run(builder, packageGraph.root.name);
+      var server =
+          await AssetServer.run(options, builder, packageGraph.root.name);
       File(assetServerPortFilePath(workingDirectory))
           .writeAsStringSync('${server.port}');
       unawaited(builder.buildScriptUpdated.then((_) async {

build_runner/lib/src/entrypoint/options.dart

@@ -128,10 +128,12 @@ class SharedOptions {
 /// Options specific to the `daemon` command.
 class DaemonOptions extends WatchOptions {
   BuildMode buildMode;
+  bool logRequests;
 
   DaemonOptions._({
     required Set<BuildFilter> buildFilters,
     required this.buildMode,
+    required this.logRequests,
     required bool deleteFilesByDefault,
     required bool enableLowResourcesMode,
     required String? configKey,
@@ -185,6 +187,7 @@ class DaemonOptions extends WatchOptions {
     return DaemonOptions._(
       buildFilters: buildFilters,
       buildMode: buildMode,
+      logRequests: argResults[logRequestsOption] as bool,
       deleteFilesByDefault: argResults[deleteFilesByDefaultOption] as bool,
       enableLowResourcesMode: argResults[lowResourcesModeOption] as bool,
       configKey: argResults[configOption] as String?,

build_runner/lib/src/server/server.dart

@@ -317,53 +317,60 @@ class AssetHandler {
   Future<shelf.Response> _handle(shelf.Request request, AssetId assetId,
       {bool fallbackToDirectoryList = false}) async {
     try {
-      if (!await _reader.canRead(assetId)) {
-        var reason = await _reader.unreadableReason(assetId);
-        switch (reason) {
-          case UnreadableReason.failed:
-            return shelf.Response.internalServerError(
-                body: 'Build failed for $assetId');
-          case UnreadableReason.notOutput:
-            return shelf.Response.notFound('$assetId was not output');
-          case UnreadableReason.notFound:
-            if (fallbackToDirectoryList) {
-              return shelf.Response.notFound(await _findDirectoryList(assetId));
-            }
-            return shelf.Response.notFound('Not Found');
-          default:
-            return shelf.Response.notFound('Not Found');
+      try {
+        if (!await _reader.canRead(assetId)) {
+          var reason = await _reader.unreadableReason(assetId);
+          switch (reason) {
+            case UnreadableReason.failed:
+              return shelf.Response.internalServerError(
+                  body: 'Build failed for $assetId');
+            case UnreadableReason.notOutput:
+              return shelf.Response.notFound('$assetId was not output');
+            case UnreadableReason.notFound:
+              if (fallbackToDirectoryList) {
+                return shelf.Response.notFound(
+                    await _findDirectoryList(assetId));
+              }
+              return shelf.Response.notFound('Not Found');
+            default:
+              return shelf.Response.notFound('Not Found');
+          }
         }
+      } on ArgumentError catch (_) {
+        return shelf.Response.notFound('Not Found');
       }
-    } on ArgumentError catch (_) {
-      return shelf.Response.notFound('Not Found');
-    }
 
-    var etag = base64.encode((await _reader.digest(assetId)).bytes);
-    var contentType = _typeResolver.lookup(assetId.path);
-    if (contentType == 'text/x-dart') {
-      contentType = '$contentType; charset=utf-8';
-    }
-    var headers = <String, Object>{
-      if (contentType != null) HttpHeaders.contentTypeHeader: contentType,
-      HttpHeaders.etagHeader: etag,
-      // We always want this revalidated, which requires specifying both
-      // max-age=0 and must-revalidate.
-      //
-      // See spec https://goo.gl/Lhvttg for more info about this header.
-      HttpHeaders.cacheControlHeader: 'max-age=0, must-revalidate',
-    };
+      var etag = base64.encode((await _reader.digest(assetId)).bytes);
+      var contentType = _typeResolver.lookup(assetId.path);
+      if (contentType == 'text/x-dart') {
+        contentType = '$contentType; charset=utf-8';
+      }
+      var headers = <String, Object>{
+        if (contentType != null) HttpHeaders.contentTypeHeader: contentType,
+        HttpHeaders.etagHeader: etag,
+        // We always want this revalidated, which requires specifying both
+        // max-age=0 and must-revalidate.
+        //
+        // See spec https://goo.gl/Lhvttg for more info about this header.
+        HttpHeaders.cacheControlHeader: 'max-age=0, must-revalidate',
+      };
 
-    if (request.headers[HttpHeaders.ifNoneMatchHeader] == etag) {
-      // This behavior is still useful for cases where a file is hit
-      // without a cache-busting query string.
-      return shelf.Response.notModified(headers: headers);
-    }
-    List<int>? body;
-    if (request.method != 'HEAD') {
-      body = await _reader.readAsBytes(assetId);
-      headers[HttpHeaders.contentLengthHeader] = '${body.length}';
+      if (request.headers[HttpHeaders.ifNoneMatchHeader] == etag) {
+        // This behavior is still useful for cases where a file is hit
+        // without a cache-busting query string.
+        return shelf.Response.notModified(headers: headers);
+      }
+      List<int>? body;
+      if (request.method != 'HEAD') {
+        body = await _reader.readAsBytes(assetId);
+        headers[HttpHeaders.contentLengthHeader] = '${body.length}';
+      }
+      return shelf.Response.ok(body, headers: headers);
+    } catch (e, s) {
+      _logger.finest(
+          'Error on request ${request.method} ${request.requestedUri}', e, s);
+      rethrow;
     }
-    return shelf.Response.ok(body, headers: headers);
   }
 
   Future<String> _findDirectoryList(AssetId from) async {

build_runner/test/server/serve_integration_test.dart

@@ -33,6 +33,8 @@ void main() {
     reader = InMemoryRunnerAssetReader.shareAssetCache(writer.assets,
         rootPackage: 'example')
       ..cacheStringAsset(AssetId('example', 'web/initial.txt'), 'initial')
+      ..cacheStringAsset(AssetId('example', 'web/large.txt'),
+          List.filled(10000, 'large').join(''))
       ..cacheStringAsset(
           AssetId('example', '.packages'),
           '# Fake packages file\n'
@@ -56,12 +58,14 @@ void main() {
       packageGraph: graph,
       reader: reader,
       writer: writer,
-      logLevel: Level.OFF,
+      logLevel: Level.ALL,
+      onLog: (record) => printOnFailure('[${record.level}] '
+          '${record.loggerName}: ${record.message}'),
       directoryWatcherFactory: (path) => FakeWatcher(path),
       terminateEventStream: terminateController.stream,
       skipBuildScriptCheck: true,
     );
-    handler = server.handlerFor('web');
+    handler = server.handlerFor('web', logRequests: true);
 
     nextBuild = Completer<BuildResult>();
     subscription = server.buildResults.listen((result) {
@@ -83,6 +87,18 @@ void main() {
     expect(await response.readAsString(), 'initial');
   });
 
+  test('should serve original files in parallel', () async {
+    final getHello = Uri.parse('http://localhost/large.txt');
+    final futures = [
+      for (var i = 0; i < 512; i++)
+        (() async => await handler(Request('GET', getHello)))(),
+    ];
+    var responses = await Future.wait(futures);
+    for (var response in responses) {
+      expect(await response.readAsString(), startsWith('large'));
+    }
+  });
+
   test('should serve built files', () async {
     final getHello = Uri.parse('http://localhost/initial.g.txt');
     reader.cacheStringAsset(AssetId('example', 'web/initial.g.txt'), 'INITIAL');