Fetch full developer.log messages (#2333)

Author: elliette

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)

dwds/lib/src/services/chrome_proxy_service.dart

@@ -1363,8 +1363,6 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer.
 
       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 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer.
           );
           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 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer.
     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 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer.
     );
   }
 
+  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');

dwds/test/chrome_proxy_service_test.dart

@@ -2370,25 +2370,44 @@ void main() {
       });
     });
 
-    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';
+
+        safeUnawaited(
+          context.tabConnection.runtime.evaluate("sendLog('$message');"),
+        );
+
+        final event = await logStream.first;
+        expect(event.kind, EventKind.kLogging);
 
-      final event = await stream.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 logRecord = event.logRecord!;
-      expect(logRecord.message!.valueAsString, message);
-      expect(logRecord.loggerName!.valueAsString, 'testLogCategory');
+        final event = await logStream.first;
+        expect(event.logRecord!.message!.valueAsString, longMessage);
+      });
     });
   });
 }