Fetch full `developer.log` messages (#2333)
diff --git a/dwds/CHANGELOG.md b/dwds/CHANGELOG.md index f72d516..bedef0c 100644 --- a/dwds/CHANGELOG.md +++ b/dwds/CHANGELOG.md
@@ -1,5 +1,7 @@ ## 23.2.0-wip +- Send untruncated `dart:developer` logs to debugging clients. - [#2333](https://github.com/dart-lang/webdev/pull/2333) + ## 23.1.1 - Loosen `package:vm_service` constraints to allow `>=13.0.0 <15.0.0`. - [#2329](https://github.com/dart-lang/webdev/pull/2329)
diff --git a/dwds/lib/src/services/chrome_proxy_service.dart b/dwds/lib/src/services/chrome_proxy_service.dart index 913db0f..3f9f458 100644 --- a/dwds/lib/src/services/chrome_proxy_service.dart +++ b/dwds/lib/src/services/chrome_proxy_service.dart
@@ -1363,8 +1363,6 @@ final args = event.args; final firstArgValue = (args.isNotEmpty ? args[0].value : null) as String?; - // TODO(nshahan) - Migrate 'inspect' and 'log' events to the injected - // client communication approach as well? switch (firstArgValue) { case 'dart.developer.inspect': // All inspected objects should be real objects. @@ -1383,7 +1381,13 @@ ); break; case 'dart.developer.log': - await _handleDeveloperLog(isolateRef, event); + await _handleDeveloperLog(isolateRef, event).catchError( + (error, stackTrace) => _logger.warning( + 'Error handling developer log:', + error, + stackTrace, + ), + ); break; default: break; @@ -1402,12 +1406,13 @@ ConsoleAPIEvent event, ) async { final logObject = event.params?['args'][1] as Map?; - final logParams = <String, RemoteObject>{}; - for (dynamic obj in logObject?['preview']?['properties'] ?? {}) { - if (obj['name'] != null && obj is Map<String, dynamic>) { - logParams[obj['name'] as String] = RemoteObject(obj); - } - } + final objectId = logObject?['objectId']; + // Always attempt to fetch the full properties instead of relying on + // `RemoteObject.preview` which only has truncated log messages: + // https://chromedevtools.github.io/devtools-protocol/tot/Runtime/#type-RemoteObject + final logParams = objectId != null + ? await _fetchFullLogParams(objectId, logObject: logObject) + : _fetchAbbreviatedLogParams(logObject); final logRecord = LogRecord( message: await _instanceRef(logParams['message']), @@ -1436,6 +1441,37 @@ ); } + Future<Map<String, RemoteObject>> _fetchFullLogParams( + String objectId, { + required Map? logObject, + }) async { + final logParams = <String, RemoteObject>{}; + for (final property in await inspector.getProperties(objectId)) { + final name = property.name; + final value = property.value; + if (name != null && value != null) { + logParams[name] = value; + } + } + + // If for some reason we don't get the full log params, then return the + // abbreviated version instead: + if (logParams.isEmpty) { + return _fetchAbbreviatedLogParams(logObject); + } + return logParams; + } + + Map<String, RemoteObject> _fetchAbbreviatedLogParams(Map? logObject) { + final logParams = <String, RemoteObject>{}; + for (dynamic property in logObject?['preview']?['properties'] ?? []) { + if (property is Map<String, dynamic> && property['name'] != null) { + logParams[property['name'] as String] = RemoteObject(property); + } + } + return logParams; + } + @override Future<Timestamp> getVMTimelineMicros() { return _rpcNotSupportedFuture('getVMTimelineMicros');
diff --git a/dwds/test/chrome_proxy_service_test.dart b/dwds/test/chrome_proxy_service_test.dart index 43e84d4..c2d7578 100644 --- a/dwds/test/chrome_proxy_service_test.dart +++ b/dwds/test/chrome_proxy_service_test.dart
@@ -2370,25 +2370,44 @@ }); }); - test('Logging', () async { - final service = context.service; - expect( - service.streamListen(EventStreams.kLogging), - completion(_isSuccess), - ); - final stream = service.onEvent(EventStreams.kLogging); - final message = 'myMessage'; + group('Logging |', () { + test('logging stream is registered', () { + final service = context.service; + expect( + service.streamListen(EventStreams.kLogging), + completion(_isSuccess), + ); + }); - safeUnawaited( - context.tabConnection.runtime.evaluate("sendLog('$message');"), - ); + test('dart:developer logs are correctly converted to log records', + () async { + final logStream = context.service.onEvent(EventStreams.kLogging); + final message = 'myMessage'; - final event = await stream.first; - expect(event.kind, EventKind.kLogging); + safeUnawaited( + context.tabConnection.runtime.evaluate("sendLog('$message');"), + ); - final logRecord = event.logRecord!; - expect(logRecord.message!.valueAsString, message); - expect(logRecord.loggerName!.valueAsString, 'testLogCategory'); + final event = await logStream.first; + expect(event.kind, EventKind.kLogging); + + final logRecord = event.logRecord!; + expect(logRecord.message!.valueAsString, message); + expect(logRecord.loggerName!.valueAsString, 'testLogCategory'); + }); + + test('long dart:developer log messages are not truncated', () async { + final logStream = context.service.onEvent(EventStreams.kLogging); + final longMessage = + 'A very long log message that Chrome truncates by default and ' + 'requires users to expand in order to see the entire message.'; + safeUnawaited( + context.tabConnection.runtime.evaluate("sendLog('$longMessage');"), + ); + + final event = await logStream.first; + expect(event.logRecord!.message!.valueAsString, longMessage); + }); }); }); }