diff --git a/dwds/lib/src/debugging/inspector.dart b/dwds/lib/src/debugging/inspector.dart index fc883a223..a6c80ebb0 100644 --- a/dwds/lib/src/debugging/inspector.dart +++ b/dwds/lib/src/debugging/inspector.dart @@ -371,7 +371,7 @@ function($argsString) { return instance; } } catch (e, s) { - _logger.log(Level.FINE, 'getObject failed with exception: $e:$s'); + _logger.fine('getObject $objectId failed', e, s); rethrow; } throw UnsupportedError('Only libraries, instances, classes, and scripts ' diff --git a/dwds/lib/src/handlers/dev_handler.dart b/dwds/lib/src/handlers/dev_handler.dart index 664f93169..2a036ee18 100644 --- a/dwds/lib/src/handlers/dev_handler.dart +++ b/dwds/lib/src/handlers/dev_handler.dart @@ -39,6 +39,8 @@ import 'injector.dart'; /// Note: this should not be checked in enabled. const _enableLogging = false; +final _logger = Logger('DevHandler'); + /// SSE handler to enable development features like hot reload and /// opening DevTools. class DevHandler { @@ -53,7 +55,6 @@ class DevHandler { final _servicesByAppId = {}; final _appConnectionByAppId = {}; final Stream buildResults; - final _logger = Logger('DevHandler'); final Future Function() _chromeConnection; final ExtensionBackend _extensionBackend; final StreamController extensionDebugConnections = diff --git a/dwds/lib/src/services/expression_compiler_service.dart b/dwds/lib/src/services/expression_compiler_service.dart index 1ffb4fb69..2411ad49a 100644 --- a/dwds/lib/src/services/expression_compiler_service.dart +++ b/dwds/lib/src/services/expression_compiler_service.dart @@ -351,7 +351,7 @@ class ExpressionCompilerService implements ExpressionCompiler { return await _assetHandler(request); } catch (e, s) { - _logger.severe('Error loading $uri: $e:$s'); + _logger.severe('Error loading $uri', e, s); rethrow; } } diff --git a/dwds/test/build_daemon_evaluate_test.dart b/dwds/test/build_daemon_evaluate_test.dart index 335b2ef51..b64bb30cb 100644 --- a/dwds/test/build_daemon_evaluate_test.dart +++ b/dwds/test/build_daemon_evaluate_test.dart @@ -39,23 +39,19 @@ class TestSetup { ChromeProxyService get service => fetchChromeProxyService(context.debugConnection); WipConnection get tabConnection => context.tabConnection; - - /// Redirect the logs for the current zone to emit on failure. - /// - /// All messages are stored and reported on test failure. - /// Needs to be called in both setUpAll() and setUp() to store - /// the logs in the current zone. - /// - /// Note: change 'printOnFailure' to 'print' for debug printing. - static void setCurrentLogWriter() { - configureLogWriter( - customLogWriter: (level, message, - {loggerName, error, stackTrace, verbose}) => - printOnFailure('[$level] $loggerName: $message')); - } } void main() async { + // Enable verbose logging for debugging. + var debug = false; + + // Change to 'true' to print expression compiler messages to console. + // + // Note: expression compiler runs in an isolate, so its output is not + // currently redirected to a logger. As a result, it will be printed + // regardless of the logger settings. + var verboseCompiler = false; + for (var soundNullSafety in [false, true]) { var setup = soundNullSafety ? TestSetup.sound() : TestSetup.unsound(); var context = setup.context; @@ -79,10 +75,10 @@ void main() async { group('shared context with evaluation', () { setUpAll(() async { - TestSetup.setCurrentLogWriter(); + setCurrentLogWriter(debug: debug); await context.setUp( enableExpressionEvaluation: true, - verbose: false, + verboseCompiler: verboseCompiler, ); }); @@ -90,9 +86,7 @@ void main() async { await context.tearDown(); }); - setUp(() async { - TestSetup.setCurrentLogWriter(); - }); + setUp(() => setCurrentLogWriter(debug: debug)); group('evaluateInFrame', () { VM vm; @@ -105,6 +99,7 @@ void main() async { Stream stream; setUp(() async { + setCurrentLogWriter(debug: debug); vm = await setup.service.getVM(); isolate = await setup.service.getIsolate(vm.isolates.first.id); scripts = await setup.service.getScripts(isolate.id); @@ -136,7 +131,7 @@ void main() async { var param = object as InstanceRef; - expect( + await expectLater( () => setup.service.evaluateInFrame( isolate.id, event.topFrame.index, @@ -520,8 +515,8 @@ void main() async { var event = await stream.firstWhere( (event) => event.kind == EventKind.kPauseBreakpoint); - expect( - () => setup.service + await expectLater( + setup.service .evaluateInFrame('bad', event.topFrame.index, 'local'), throwsRPCError); }); @@ -533,6 +528,7 @@ void main() async { Isolate isolate; setUp(() async { + setCurrentLogWriter(debug: debug); vm = await setup.service.getVM(); isolate = await setup.service.getIsolate(vm.isolates.first.id); @@ -602,10 +598,10 @@ void main() async { group('shared context with no evaluation', () { setUpAll(() async { - TestSetup.setCurrentLogWriter(); + setCurrentLogWriter(debug: debug); await context.setUp( enableExpressionEvaluation: false, - verbose: false, + verboseCompiler: verboseCompiler, ); }); @@ -613,9 +609,7 @@ void main() async { await context.tearDown(); }); - setUp(() async { - TestSetup.setCurrentLogWriter(); - }); + setUp(() => setCurrentLogWriter(debug: debug)); group('evaluateInFrame', () { VM vm; @@ -645,8 +639,8 @@ void main() async { var event = await stream.firstWhere( (event) => event.kind == EventKind.kPauseBreakpoint); - expect( - () => setup.service.evaluateInFrame( + await expectLater( + setup.service.evaluateInFrame( isolate.id, event.topFrame.index, 'local'), throwsRPCError); }); diff --git a/dwds/test/chrome_proxy_service_test.dart b/dwds/test/chrome_proxy_service_test.dart index ee160d2c9..4ed7f3a0e 100644 --- a/dwds/test/chrome_proxy_service_test.dart +++ b/dwds/test/chrome_proxy_service_test.dart @@ -33,11 +33,8 @@ WipConnection get tabConnection => context.tabConnection; void main() { group('shared context', () { setUpAll(() async { - configureLogWriter( - customLogWriter: (level, message, - {loggerName, error, stackTrace, verbose}) => - printOnFailure('[$level] $loggerName: $message')); - await context.setUp(verbose: false); + setCurrentLogWriter(); + await context.setUp(verboseCompiler: false); }); tearDownAll(() async { @@ -52,6 +49,7 @@ void main() { ScriptRef mainScript; setUp(() async { + setCurrentLogWriter(); vm = await fetchChromeProxyService(context.debugConnection).getVM(); isolate = await fetchChromeProxyService(context.debugConnection) .getIsolate(vm.isolates.first.id); @@ -160,6 +158,8 @@ void main() { }); group('callServiceExtension', () { + setUp(setCurrentLogWriter); + test('success', () async { var serviceMethod = 'ext.test.callServiceExtension'; await tabConnection.runtime @@ -208,6 +208,8 @@ void main() { }); group('VMTimeline', () { + setUp(setCurrentLogWriter); + test('clearVMTimeline', () async { await expectLater(service.clearVMTimeline(), throwsRPCError); }); @@ -246,12 +248,15 @@ void main() { LibraryRef bootstrap; setUpAll(() async { + setCurrentLogWriter(); var vm = await service.getVM(); isolate = await service.getIsolate(vm.isolates.first.id); bootstrap = isolate.rootLib; }); group('top level methods', () { + setUp(setCurrentLogWriter); + test('can return strings', () async { expect( await service.evaluate( @@ -304,6 +309,8 @@ void main() { }); group('with provided scope', () { + setUp(setCurrentLogWriter); + Future createRemoteObject(String message) async { return await service.evaluate( isolate.id, bootstrap.id, 'createObject("$message")') @@ -362,6 +369,8 @@ void main() { }); group('getIsolate', () { + setUp(setCurrentLogWriter); + test('works for existing isolates', () async { var vm = await service.getVM(); var result = await service.getIsolate(vm.isolates.first.id); @@ -393,6 +402,7 @@ void main() { Library rootLibrary; setUpAll(() async { + setCurrentLogWriter(); var vm = await service.getVM(); isolate = await service.getIsolate(vm.isolates.first.id); bootstrap = isolate.rootLib; @@ -400,6 +410,8 @@ void main() { await service.getObject(isolate.id, bootstrap.id) as Library; }); + setUp(setCurrentLogWriter); + test('Libraries', () async { expect(rootLibrary, isNotNull); // TODO: library names change with kernel dart-lang/sdk#36736 @@ -654,6 +666,8 @@ void main() { }); group('getSourceReport', () { + setUp(setCurrentLogWriter); + test('Coverage report', () async { var vm = await service.getVM(); var isolateId = vm.isolates.first.id; @@ -698,6 +712,7 @@ void main() { ScriptRef mainScript; setUp(() async { + setCurrentLogWriter(); var vm = await service.getVM(); isolateId = vm.isolates.first.id; scripts = await service.getScripts(isolateId); @@ -732,6 +747,7 @@ void main() { ScriptRef mainScript; setUp(() async { + setCurrentLogWriter(); var vm = await service.getVM(); isolateId = vm.isolates.first.id; scripts = await service.getScripts(isolateId); @@ -800,6 +816,7 @@ void main() { ScriptRef mainScript; setUp(() async { + setCurrentLogWriter(); var vm = await service.getVM(); isolateId = vm.isolates.first.id; scripts = await service.getScripts(isolateId); @@ -954,6 +971,7 @@ void main() { InstanceRef testInstance; setUp(() async { + setCurrentLogWriter(); vm = await service.getVM(); isolate = await service.getIsolate(vm.isolates.first.id); bootstrap = isolate.rootLib; @@ -1156,6 +1174,7 @@ void main() { Stream eventStream; setUp(() async { + setCurrentLogWriter(); expect(await service.streamListen('Debug'), const TypeMatcher()); eventStream = service.onEvent('Debug'); diff --git a/dwds/test/events_test.dart b/dwds/test/events_test.dart index 6fe3c1e60..f206cc0bf 100644 --- a/dwds/test/events_test.dart +++ b/dwds/test/events_test.dart @@ -24,20 +24,6 @@ WipConnection get tabConnection => context.tabConnection; final context = TestContext(); -/// Redirect the logs for the current zone to emit on failure. -/// -/// All messages are stored and reported on test failure. -/// Needs to be called in both setUpAll() and setUp() to store -/// the logs in the current zone. -/// -/// Note: change 'printOnFailure' to 'print' for debug printing. -void setCurrentLogWriter() { - configureLogWriter( - customLogWriter: (level, message, - {loggerName, error, stackTrace, verbose}) => - printOnFailure('[$level] $loggerName: $message')); -} - void main() { setUpAll(() async { setCurrentLogWriter(); diff --git a/dwds/test/expression_compiler_service_test.dart b/dwds/test/expression_compiler_service_test.dart index 2bba32f36..665bcdbc1 100644 --- a/dwds/test/expression_compiler_service_test.dart +++ b/dwds/test/expression_compiler_service_test.dart @@ -50,8 +50,7 @@ void main() async { output.stream.listen(printOnFailure); configureLogWriter( - customLogWriter: (level, message, - {loggerName, error, stackTrace, verbose}) => + customLogWriter: (level, message, {error, loggerName, stackTrace}) => output.add('[$level] $loggerName: $message')); // start expression compilation service diff --git a/dwds/test/fixtures/context.dart b/dwds/test/fixtures/context.dart index 2ca1d04e4..67fb96394 100644 --- a/dwds/test/fixtures/context.dart +++ b/dwds/test/fixtures/context.dart @@ -11,7 +11,6 @@ import 'dart:io'; import 'package:build_daemon/client.dart'; import 'package:build_daemon/data/build_status.dart'; import 'package:build_daemon/data/build_target.dart'; -import 'package:build_daemon/data/server_log.dart'; import 'package:dwds/dwds.dart'; import 'package:dwds/src/debugging/webkit_debugger.dart'; import 'package:dwds/src/utilities/dart_uri.dart'; @@ -74,7 +73,7 @@ class TestContext { /// this value from the ddc debug metadata and pass it to the /// expression compiler worker initialiation API. bool soundNullSafety; - final _logger = logging.Logger('TestContext'); + final _logger = logging.Logger('Context'); /// Top level directory in which we run the test server.. String workingDirectory; @@ -121,7 +120,7 @@ class TestContext { bool restoreBreakpoints, CompilationMode compilationMode, bool enableExpressionEvaluation, - bool verbose}) async { + bool verboseCompiler}) async { reloadConfiguration ??= ReloadConfiguration.none; serveDevTools ??= false; enableDebugExtension ??= false; @@ -131,7 +130,7 @@ class TestContext { compilationMode ??= CompilationMode.buildDaemon; enableExpressionEvaluation ??= false; spawnDds ??= true; - verbose ??= false; + verboseCompiler ??= false; try { configureLogWriter(); @@ -190,10 +189,16 @@ class TestContext { '--define', 'build_web_compilers|ddc=generate-full-dill=true', ], - if (verbose) '--verbose', + '--verbose', ]; - daemonClient = await connectClient(workingDirectory, options, - (log) => _logger.log(toLoggingLevel(log.level), log.message)); + daemonClient = + await connectClient(workingDirectory, options, (log) { + var record = log.toLogRecord(); + var name = + record.loggerName == '' ? '' : '${record.loggerName}: '; + _logger.log(record.level, '$name${record.message}', record.error, + record.stackTrace); + }); daemonClient.registerBuildTarget( DefaultBuildTarget((b) => b..target = pathToServe)); daemonClient.startBuild(); @@ -215,7 +220,7 @@ class TestContext { 'localhost', port, assetHandler, - verbose, + verboseCompiler, ); expressionCompiler = ddcService; } @@ -243,7 +248,7 @@ class TestContext { [fileSystemRoot], 'org-dartlang-app', _outputDir.path, - verbose); + verboseCompiler); var assetServerPort = await findUnusedPort(); await webRunner.run(hostname, assetServerPort, pathToServe); diff --git a/dwds/test/fixtures/logging.dart b/dwds/test/fixtures/logging.dart index b6fb66feb..1d8092d23 100644 --- a/dwds/test/fixtures/logging.dart +++ b/dwds/test/fixtures/logging.dart @@ -14,48 +14,50 @@ typedef LogWriter = void Function(Level level, String message, StreamSubscription _loggerSub; -/// Configure test log writer. +/// Redirect the logs for the current zone to emit on failure. /// -/// Tests and groups of tests can use this to configure individual -/// log writers on setup. +/// If [debug] is false, messages are stored and reported on test failure. +/// If [debug] is true, messages are always printed to the console. /// -/// Note that the logwriter needs to be set in both `setUpAll` and -/// `setUp` to store messages for the same zone as the failure in -/// order to report all stored messages on that failure. +/// Note that the logwriter uses [printOnFailure] that stores the messages +/// on the current zone. As a result, [setCurrentLogWriter] needs to be set +/// in both `setUpAll` and `setUp` to store messages for the same zone as the +/// failure in order to report all stored messages on that failure. /// -/// For example, to enable verbose printing during debugging: +/// For example: /// -/// void setCurrentLogWriter() { -/// // Note: change 'printOnFailure' to 'print' for debug printing. -/// configureLogWriter( -/// customLogWriter: (level, message, -/// {loggerName, error, stackTrace, verbose}) => -/// printOnFailure('[$level] $loggerName: $message')); -/// } +/// // Enable verbose logging for debugging. +/// bool debug = true; /// /// group('shared context', () { /// setUpAll(() async { /// // Set the logger for the current group. -/// setCurrentLogWriter(); -/// await context.setUp(); +/// setCurrentLogWriter(debug: debug); +/// ... /// }); -/// /// setUp(() async { /// // Reset the logger for the current test. -/// setCurrentLogWriter(); +/// setCurrentLogWriter(debug: debug); +/// ... /// }); -/// /// ... /// }); +void setCurrentLogWriter({bool debug = false}) => + configureLogWriter(customLogWriter: createLogWriter(debug: debug)); + +/// Configure test log writer. +/// +/// Tests and groups of tests can use this to configure individual +/// log writers on setup. void configureLogWriter({LogWriter customLogWriter}) { _logWriter = customLogWriter ?? _logWriter; Logger.root.level = Level.ALL; _loggerSub?.cancel(); _loggerSub = Logger.root.onRecord.listen((event) { logWriter(event.level, event.message, - error: '${event.error}', + error: event.error?.toString(), loggerName: event.loggerName, - stackTrace: '${event.stackTrace}'); + stackTrace: event.stackTrace?.toString()); }); } @@ -64,8 +66,16 @@ void stopLogWriter() { _loggerSub = null; } -LogWriter _logWriter = (level, message, - {String error, String loggerName, String stackTrace}) => - printOnFailure('[$level] $loggerName: $message'); +LogWriter _logWriter = createLogWriter(); + +LogWriter createLogWriter({bool debug = false}) => + (level, message, {String error, String loggerName, String stackTrace}) { + var printFn = debug ? print : printOnFailure; + var errorMessage = error == null ? '' : ':\n$error'; + var stackMessage = stackTrace == null ? '' : ':\n$stackTrace'; + printFn('[$level] $loggerName: $message' + '$errorMessage' + '$stackMessage'); + }; LogWriter get logWriter => _logWriter; diff --git a/dwds/test/fixtures/server.dart b/dwds/test/fixtures/server.dart index 894fa302a..c65022b27 100644 --- a/dwds/test/fixtures/server.dart +++ b/dwds/test/fixtures/server.dart @@ -11,10 +11,13 @@ import 'package:devtools_server/devtools_server.dart' as devtools_lancher; import 'package:dwds/data/build_result.dart'; import 'package:dwds/dwds.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 'package:webkit_inspection_protocol/webkit_inspection_protocol.dart'; +Logger _logger = Logger('TestServer'); + Handler _interceptFavicon(Handler handler) { return (request) async { if (request.url.pathSegments.isNotEmpty && @@ -124,8 +127,12 @@ class TestServer { cascade = cascade.add(ddcService.handler); } - shelf_io.serveRequests(server, - pipeline.addMiddleware(dwds.middleware).addHandler(cascade.handler)); + shelf_io.serveRequests( + server, + pipeline + .addMiddleware(_logRequests) + .addMiddleware(dwds.middleware) + .addHandler(cascade.handler)); return TestServer._( target, @@ -136,4 +143,37 @@ class TestServer { assetReader, ); } + + /// [Middleware] that logs all requests, inspired by [logRequests]. + static Handler _logRequests(Handler innerHandler) { + return (Request request) async { + var watch = Stopwatch()..start(); + try { + var response = await innerHandler(request); + var logFn = + response.statusCode >= 500 ? _logger.warning : _logger.finest; + var msg = _requestLabel(response.statusCode, request.requestedUri, + request.method, watch.elapsed); + logFn(msg); + return response; + } catch (error, stackTrace) { + if (error is HijackException) rethrow; + var msg = _requestLabel( + 500, request.requestedUri, request.method, watch.elapsed); + _logger.severe(msg, error, stackTrace); + rethrow; + } + }; + } + + static String _requestLabel( + int statusCode, Uri requestedUri, String method, Duration elapsedTime) { + return '$elapsedTime ' + '$method [$statusCode] ' + '${requestedUri.path}${_formatQuery(requestedUri.query)}'; + } + + static String _formatQuery(String query) { + return query == '' ? '' : '?$query'; + } } diff --git a/dwds/test/frontend_server_evaluate_test.dart b/dwds/test/frontend_server_evaluate_test.dart index a4e3683b2..3efc1039b 100644 --- a/dwds/test/frontend_server_evaluate_test.dart +++ b/dwds/test/frontend_server_evaluate_test.dart @@ -31,17 +31,15 @@ class TestSetup { ChromeProxyService get service => fetchChromeProxyService(context.debugConnection); WipConnection get tabConnection => context.tabConnection; - - static void setCurrentLogWriter() { - // Note: change 'printOnFailure' to 'print' for debug printing - configureLogWriter( - customLogWriter: (level, message, - {loggerName, error, stackTrace, verbose}) => - printOnFailure('[$level] $loggerName: $message')); - } } void main() async { + // Enable verbose logging for debugging. + var debug = false; + + // Change to 'false' to silence frontend server messages. + var verboseCompiler = true; + var setup = TestSetup.unsound(); var context = setup.context; @@ -64,11 +62,11 @@ void main() async { group('shared context with evaluation', () { setUpAll(() async { - TestSetup.setCurrentLogWriter(); + setCurrentLogWriter(debug: debug); await context.setUp( enableExpressionEvaluation: true, compilationMode: CompilationMode.frontendServer, - verbose: false); + verboseCompiler: verboseCompiler); }); tearDownAll(() async { @@ -76,7 +74,7 @@ void main() async { }); setUp(() async { - TestSetup.setCurrentLogWriter(); + setCurrentLogWriter(debug: debug); }); group('evaluateInFrame', () { @@ -469,11 +467,11 @@ void main() async { group('shared context with no evaluation', () { setUpAll(() async { - TestSetup.setCurrentLogWriter(); + setCurrentLogWriter(debug: debug); await context.setUp( enableExpressionEvaluation: false, compilationMode: CompilationMode.frontendServer, - verbose: false); + verboseCompiler: verboseCompiler); }); tearDownAll(() async { @@ -481,7 +479,7 @@ void main() async { }); setUp(() async { - TestSetup.setCurrentLogWriter(); + setCurrentLogWriter(debug: debug); }); group('evaluateInFrame', () { @@ -512,8 +510,8 @@ void main() async { var event = await stream.firstWhere( (Event event) => event.kind == EventKind.kPauseBreakpoint); - expect( - () => setup.service + await expectLater( + setup.service .evaluateInFrame(isolate.id, event.topFrame.index, 'local'), throwsRPCError); }); diff --git a/dwds/test/handlers/asset_handler_test.dart b/dwds/test/handlers/asset_handler_test.dart index df18c3a1b..d3bad888d 100644 --- a/dwds/test/handlers/asset_handler_test.dart +++ b/dwds/test/handlers/asset_handler_test.dart @@ -16,13 +16,6 @@ import '../fixtures/context.dart'; import '../fixtures/logging.dart'; import '../fixtures/utilities.dart'; -void setCurrentLogWriter() { - configureLogWriter( - customLogWriter: (level, message, - {loggerName, error, stackTrace, verbose}) => - printOnFailure('[$level] $loggerName: $message')); -} - void main() { group('Asset handler', () { final context = TestContext(); @@ -31,7 +24,10 @@ void main() { setUpAll(() async { setCurrentLogWriter(); - await context.setUp(enableExpressionEvaluation: true, verbose: true); + await context.setUp( + enableExpressionEvaluation: true, + verboseCompiler: false, + ); client = IOClient(HttpClient() ..maxConnectionsPerHost = 200 diff --git a/dwds/test/restore_breakpoints_test.dart b/dwds/test/restore_breakpoints_test.dart index f1cc9d514..3761bf4e3 100644 --- a/dwds/test/restore_breakpoints_test.dart +++ b/dwds/test/restore_breakpoints_test.dart @@ -21,17 +21,12 @@ ChromeProxyService get service => fetchChromeProxyService(context.debugConnection); WipConnection get tabConnection => context.tabConnection; -void setCurrentLogWriter() { - configureLogWriter( - customLogWriter: (level, message, - {loggerName, error, stackTrace, verbose}) => - printOnFailure('[$level] $loggerName: $message')); -} - void main() { setUpAll(() async { setCurrentLogWriter(); - await context.setUp(restoreBreakpoints: true, verbose: true); + await context.setUp( + restoreBreakpoints: true, + ); }); tearDownAll(() async { diff --git a/frontend_server_common/lib/src/asset_server.dart b/frontend_server_common/lib/src/asset_server.dart index d790d7c53..756d489f7 100644 --- a/frontend_server_common/lib/src/asset_server.dart +++ b/frontend_server_common/lib/src/asset_server.dart @@ -21,6 +21,8 @@ import 'package:shelf/shelf.dart' as shelf; import 'utilities.dart'; +Logger _logger = Logger('TestAssetServer'); + class TestAssetServer implements AssetReader { TestAssetServer( this._root, @@ -35,10 +37,6 @@ class TestAssetServer implements AssetReader { static const String _defaultMimeType = 'application/octet-stream'; final FileSystem _fileSystem; - void _printTrace(String message) { - Logger.root.info(message); - } - /// Start the web asset server on a [hostname] and [port]. /// /// Unhandled exceptions will throw a exception with the error and stack @@ -160,7 +158,7 @@ class TestAssetServer implements AssetReader { castStringKeyedMap(json.decode(manifestFile.readAsStringSync())); for (var filePath in manifest.keys) { if (filePath == null) { - _printTrace('Invalid manfiest file: $filePath'); + _logger.severe('Invalid manfiest file: $filePath'); continue; } var offsets = castStringKeyedMap(manifest[filePath]); @@ -171,14 +169,14 @@ class TestAssetServer implements AssetReader { if (codeOffsets.length != 2 || sourcemapOffsets.length != 2 || metadataOffsets.length != 2) { - _printTrace('Invalid manifest byte offsets: $offsets'); + _logger.severe('Invalid manifest byte offsets: $offsets'); continue; } var codeStart = codeOffsets[0]; var codeEnd = codeOffsets[1]; if (codeStart < 0 || codeEnd > codeBytes.lengthInBytes) { - _printTrace('Invalid byte index: [$codeStart, $codeEnd]'); + _logger.severe('Invalid byte index: [$codeStart, $codeEnd]'); continue; } var byteView = Uint8List.view( @@ -191,7 +189,7 @@ class TestAssetServer implements AssetReader { var sourcemapStart = sourcemapOffsets[0]; var sourcemapEnd = sourcemapOffsets[1]; if (sourcemapStart < 0 || sourcemapEnd > sourcemapBytes.lengthInBytes) { - _printTrace('Invalid byte index: [$sourcemapStart, $sourcemapEnd]'); + _logger.severe('Invalid byte index: [$sourcemapStart, $sourcemapEnd]'); continue; } var sourcemapView = Uint8List.view( @@ -204,7 +202,7 @@ class TestAssetServer implements AssetReader { var metadataStart = metadataOffsets[0]; var metadataEnd = metadataOffsets[1]; if (metadataStart < 0 || metadataEnd > metadataBytes.lengthInBytes) { - _printTrace('Invalid byte index: [$metadataStart, $metadataEnd]'); + _logger.severe('Invalid byte index: [$metadataStart, $metadataEnd]'); continue; } var metadataView = Uint8List.view( diff --git a/frontend_server_common/lib/src/devfs.dart b/frontend_server_common/lib/src/devfs.dart index ff1eb2203..568d1fad1 100644 --- a/frontend_server_common/lib/src/devfs.dart +++ b/frontend_server_common/lib/src/devfs.dart @@ -10,6 +10,7 @@ import 'dart:io'; import 'package:dwds/dwds.dart'; import 'package:file/file.dart'; +import 'package:logging/logging.dart'; import 'package:meta/meta.dart'; import 'package:path/path.dart' as p; @@ -22,6 +23,8 @@ import 'utilities.dart'; final String dartWebSdkPath = p.join(dartSdkPath, 'lib', 'dev_compiler'); +Logger _logger = Logger('WebDevFs'); + class WebDevFS { WebDevFS({ this.fileSystem, @@ -183,9 +186,12 @@ Future writeBundle( if (bundleDir.existsSync()) { try { bundleDir.deleteSync(recursive: true); - } on FileSystemException catch (err) { - printError('Failed to clean up asset directory ${bundleDir.path}: $err\n' - 'To clean build artifacts, use the command "flutter clean".'); + } on FileSystemException catch (e, s) { + _logger.warning( + 'Failed to clean up asset directory ${bundleDir.path}.\n' + 'To clean build artifacts, use the command "flutter clean".', + e, + s); } } bundleDir.createSync(recursive: true); diff --git a/frontend_server_common/lib/src/devfs_content.dart b/frontend_server_common/lib/src/devfs_content.dart index 0fb642e97..3b09c15c7 100644 --- a/frontend_server_common/lib/src/devfs_content.dart +++ b/frontend_server_common/lib/src/devfs_content.dart @@ -10,9 +10,12 @@ import 'dart:async'; import 'dart:convert'; import 'package:file/file.dart'; +import 'package:logging/logging.dart'; import 'utilities.dart'; +Logger _logger = Logger('DevFsContent'); + /// Common superclass for content copied to the device. abstract class DevFSContent { /// Return true if this is the first time this method is called @@ -79,7 +82,7 @@ class DevFSFileContent extends DevFSContent { } } if (_fileStat == null) { - printError( + _logger.severe( 'Unable to get status of file "${file.path}": file not found.'); } } diff --git a/frontend_server_common/lib/src/frontend_server_client.dart b/frontend_server_common/lib/src/frontend_server_client.dart index 6d7138d22..2b4d5c10c 100644 --- a/frontend_server_common/lib/src/frontend_server_client.dart +++ b/frontend_server_common/lib/src/frontend_server_client.dart @@ -20,6 +20,14 @@ import 'package:usage/uuid/uuid.dart'; import 'utilities.dart'; +Logger _logger = Logger('FrontendServerClient'); +Logger _serverLogger = Logger('FrontendServer'); + +void defaultConsumer(String message, {StackTrace stackTrace}) => + stackTrace == null + ? _serverLogger.info(message) + : _serverLogger.severe(message, null, stackTrace); + String get frontendServerExecutable => p.join(dartSdkPath, 'bin', 'snapshots', 'frontend_server.dart.snapshot'); @@ -38,11 +46,7 @@ enum StdoutState { collectDiagnostic, collectDependencies } /// Handles stdin/stdout communication with the frontend server. class StdoutHandler { - void _printTrace(String message) { - Logger.root.info(message); - } - - StdoutHandler({this.consumer = printError}) { + StdoutHandler({@required this.consumer}) { reset(); } @@ -137,7 +141,7 @@ class StdoutHandler { sources.remove(Uri.parse(message.substring(1))); break; default: - _printTrace('Unexpected prefix for $message uri - ignoring'); + _logger.warning('Unexpected prefix for $message uri - ignoring'); } } } @@ -389,7 +393,7 @@ class DefaultResidentCompiler implements ResidentCompiler { this.fileSystemScheme, this.platformDill, this.verbose, - CompilerMessageConsumer compilerMessageConsumer = printError, + CompilerMessageConsumer compilerMessageConsumer = defaultConsumer, }) : assert(sdkRoot != null), _stdoutHandler = StdoutHandler(consumer: compilerMessageConsumer), // This is a URI, not a file path, so the forward slash is correct even on Windows. @@ -401,10 +405,6 @@ class DefaultResidentCompiler implements ResidentCompiler { final String platformDill; final bool verbose; - void _printTrace(String message) { - Logger.root.info(message); - } - @override void addFileSystemRoot(String root) { fileSystemRoots.add(root); @@ -461,14 +461,14 @@ class DefaultResidentCompiler implements ResidentCompiler { ? '${_mapFilename(request.mainPath, packageUriMapper)} ' : ''; _server.stdin.writeln('recompile $mainUri$inputKey'); - _printTrace('<- recompile $mainUri$inputKey'); + _logger.info('<- recompile $mainUri$inputKey'); for (var fileUri in request.invalidatedFiles) { var message = _mapFileUri(fileUri.toString(), packageUriMapper); _server.stdin.writeln(message); - _printTrace(message); + _logger.info(message); } _server.stdin.writeln(inputKey); - _printTrace('<- $inputKey'); + _logger.info('<- $inputKey'); return _stdoutHandler.compilerOutput.future; } @@ -527,7 +527,7 @@ class DefaultResidentCompiler implements ResidentCompiler { if (verbose) '--verbose' ]; - _printTrace(args.join(' ')); + _logger.info(args.join(' ')); _server = await Process.start(Platform.resolvedExecutable, args, workingDirectory: packagesPath); _server.stdout @@ -545,7 +545,7 @@ class DefaultResidentCompiler implements ResidentCompiler { _server.stderr .transform(utf8.decoder) .transform(const LineSplitter()) - .listen(printError); + .listen(_logger.info); unawaited(_server.exitCode.then((int code) { if (code != 0) { @@ -554,7 +554,7 @@ class DefaultResidentCompiler implements ResidentCompiler { })); _server.stdin.writeln('compile $scriptUri'); - _printTrace('<- compile $scriptUri'); + _logger.info('<- compile $scriptUri'); return _stdoutHandler.compilerOutput.future; } @@ -655,7 +655,7 @@ class DefaultResidentCompiler implements ResidentCompiler { void accept() { if (_compileRequestNeedsConfirmation) { _server.stdin.writeln('accept'); - _printTrace('<- accept'); + _logger.info('<- accept'); } _compileRequestNeedsConfirmation = false; } @@ -677,7 +677,7 @@ class DefaultResidentCompiler implements ResidentCompiler { } _stdoutHandler.reset(expectSources: false); _server.stdin.writeln('reject'); - _printTrace('<- reject'); + _logger.info('<- reject'); _compileRequestNeedsConfirmation = false; return _stdoutHandler.compilerOutput.future; } @@ -685,12 +685,12 @@ class DefaultResidentCompiler implements ResidentCompiler { @override void reset() { _server?.stdin?.writeln('reset'); - _printTrace('<- reset'); + _logger.info('<- reset'); } Future quit() async { _server.stdin.writeln('quit'); - _printTrace('<- quit'); + _logger.info('<- quit'); return _server.exitCode; } @@ -749,7 +749,7 @@ class DefaultResidentCompiler implements ResidentCompiler { return 0; } - _printTrace('killing pid ${_server.pid}'); + _logger.info('killing pid ${_server.pid}'); _server.kill(); return _server.exitCode; } diff --git a/frontend_server_common/lib/src/resident_runner.dart b/frontend_server_common/lib/src/resident_runner.dart index 4850b746e..9f14f8704 100644 --- a/frontend_server_common/lib/src/resident_runner.dart +++ b/frontend_server_common/lib/src/resident_runner.dart @@ -10,6 +10,7 @@ import 'dart:async'; import 'package:dwds/dwds.dart'; +import 'package:logging/logging.dart'; import 'package:path/path.dart' as p; import 'asset.dart'; @@ -21,6 +22,8 @@ import 'utilities.dart'; final Uri platformDill = Uri.file(p.join(dartSdkPath, 'lib', '_internal', 'ddc_sdk.dill')); +Logger _logger = Logger('ResidentWebRunner'); + class ResidentWebRunner { ResidentWebRunner( this.mainPath, @@ -73,7 +76,7 @@ class ResidentWebRunner { var report = await _updateDevFS(); if (!report.success) { - printError('Failed to compile application.'); + _logger.severe('Failed to compile application.'); return 1; } diff --git a/frontend_server_common/lib/src/utilities.dart b/frontend_server_common/lib/src/utilities.dart index baac68cb9..9e89da85c 100644 --- a/frontend_server_common/lib/src/utilities.dart +++ b/frontend_server_common/lib/src/utilities.dart @@ -27,10 +27,3 @@ final String pubPath = p.join(_sdkDir, 'bin', Platform.isWindows ? 'pub.bat' : 'pub'); const fs.FileSystem fileSystem = LocalFileSystem(); - -void printError(String message, {StackTrace stackTrace}) { - if (stackTrace != null) { - print('$message: $stackTrace'); - } - print(message); -}