From 1b18f2eebb48fd7da69d33c0d332936d47bf7f22 Mon Sep 17 00:00:00 2001 From: Elliott Brooks <21270878+elliette@users.noreply.github.com> Date: Tue, 9 Jan 2024 11:16:41 -0800 Subject: [PATCH 1/8] wip --- dwds/lib/src/services/chrome_proxy_service.dart | 1 + 1 file changed, 1 insertion(+) diff --git a/dwds/lib/src/services/chrome_proxy_service.dart b/dwds/lib/src/services/chrome_proxy_service.dart index 913db0f5b..29c3dbe88 100644 --- a/dwds/lib/src/services/chrome_proxy_service.dart +++ b/dwds/lib/src/services/chrome_proxy_service.dart @@ -1265,6 +1265,7 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. final isolateRef = inspector.isolateRef; if (!filter(e)) return; final args = e.params?['args'] as List?; + print('ARGS ARE $args'); final item = args?[0] as Map?; final value = '${item?["value"]}\n'; controller.add( From 41148ee863d57b45b67c0f03fb39fa10334ed02a Mon Sep 17 00:00:00 2001 From: Elliott Brooks <21270878+elliette@users.noreply.github.com> Date: Tue, 9 Jan 2024 14:50:33 -0800 Subject: [PATCH 2/8] Always fetch full developer log messages --- .../src/services/chrome_proxy_service.dart | 44 +++++++++++++++---- 1 file changed, 36 insertions(+), 8 deletions(-) diff --git a/dwds/lib/src/services/chrome_proxy_service.dart b/dwds/lib/src/services/chrome_proxy_service.dart index 29c3dbe88..3f210f569 100644 --- a/dwds/lib/src/services/chrome_proxy_service.dart +++ b/dwds/lib/src/services/chrome_proxy_service.dart @@ -1265,7 +1265,6 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. final isolateRef = inspector.isolateRef; if (!filter(e)) return; final args = e.params?['args'] as List?; - print('ARGS ARE $args'); final item = args?[0] as Map?; final value = '${item?["value"]}\n'; controller.add( @@ -1384,7 +1383,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; @@ -1403,12 +1408,13 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. ConsoleAPIEvent event, ) async { final logObject = event.params?['args'][1] as Map?; - final logParams = {}; - for (dynamic obj in logObject?['preview']?['properties'] ?? {}) { - if (obj['name'] != null && obj is Map) { - logParams[obj['name'] as String] = RemoteObject(obj); - } - } + final objectId = logObject?["objectId"]; + // Always attempt to fetch the full properties instead of `RemoteObject` + // abbreviated properties (this prevents the message from being truncated): + // https://chromedevtools.github.io/devtools-protocol/tot/Runtime/#type-RemoteObject + final logParams = objectId != null + ? await _fetchFullLogParams(objectId) + : _fetchAbbreviatedLogParams(logObject); final logRecord = LogRecord( message: await _instanceRef(logParams['message']), @@ -1437,6 +1443,28 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. ); } + Future> _fetchFullLogParams(String objectId) async { + final logParams = {}; + for (final property in await inspector.getProperties(objectId)) { + final name = property.name; + final value = property.value; + if (name != null && value != null) { + logParams[name] = value; + } + } + return logParams; + } + + Map _fetchAbbreviatedLogParams(Map? logObject) { + final logParams = {}; + for (dynamic obj in logObject?['preview']?['properties'] ?? []) { + if (obj is Map && obj['name'] != null) { + logParams[obj['name'] as String] = RemoteObject(obj); + } + } + return logParams; + } + @override Future getVMTimelineMicros() { return _rpcNotSupportedFuture('getVMTimelineMicros'); From 4d944f74f2ea84370d9b415ba53cdcacdddc8d03 Mon Sep 17 00:00:00 2001 From: Elliott Brooks <21270878+elliette@users.noreply.github.com> Date: Tue, 9 Jan 2024 16:11:14 -0800 Subject: [PATCH 3/8] Respond to PR comments, clean up --- dwds/lib/src/services/chrome_proxy_service.dart | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/dwds/lib/src/services/chrome_proxy_service.dart b/dwds/lib/src/services/chrome_proxy_service.dart index 3f210f569..a2ef15e90 100644 --- a/dwds/lib/src/services/chrome_proxy_service.dart +++ b/dwds/lib/src/services/chrome_proxy_service.dart @@ -1363,9 +1363,9 @@ ${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) { + // TODO(https://github.com/dart-lang/webdev/issues/2335): Make sure that + // inspect properties are not being truncated. case 'dart.developer.inspect': // All inspected objects should be real objects. if (event.args[1].type != 'object') break; @@ -1408,9 +1408,9 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. ConsoleAPIEvent event, ) async { final logObject = event.params?['args'][1] as Map?; - final objectId = logObject?["objectId"]; - // Always attempt to fetch the full properties instead of `RemoteObject` - // abbreviated properties (this prevents the message from being truncated): + 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) @@ -1457,9 +1457,9 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. Map _fetchAbbreviatedLogParams(Map? logObject) { final logParams = {}; - for (dynamic obj in logObject?['preview']?['properties'] ?? []) { - if (obj is Map && obj['name'] != null) { - logParams[obj['name'] as String] = RemoteObject(obj); + for (dynamic property in logObject?['preview']?['properties'] ?? []) { + if (property is Map && property['name'] != null) { + logParams[property['name'] as String] = RemoteObject(property); } } return logParams; From f61056be1501ab157e2eace11bf9478299c0015a Mon Sep 17 00:00:00 2001 From: Elliott Brooks <21270878+elliette@users.noreply.github.com> Date: Tue, 9 Jan 2024 16:11:24 -0800 Subject: [PATCH 4/8] Add a test --- dwds/test/chrome_proxy_service_test.dart | 50 ++++++++++++++++-------- 1 file changed, 34 insertions(+), 16 deletions(-) diff --git a/dwds/test/chrome_proxy_service_test.dart b/dwds/test/chrome_proxy_service_test.dart index 43e84d46b..20de12344 100644 --- a/dwds/test/chrome_proxy_service_test.dart +++ b/dwds/test/chrome_proxy_service_test.dart @@ -2370,25 +2370,43 @@ 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); + }); }); }); } From 5bf79766b268fe7170deacc3eb6965e0f2bf11f4 Mon Sep 17 00:00:00 2001 From: Elliott Brooks <21270878+elliette@users.noreply.github.com> Date: Tue, 9 Jan 2024 16:13:53 -0800 Subject: [PATCH 5/8] Typo --- dwds/test/chrome_proxy_service_test.dart | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/dwds/test/chrome_proxy_service_test.dart b/dwds/test/chrome_proxy_service_test.dart index 20de12344..58e047cbb 100644 --- a/dwds/test/chrome_proxy_service_test.dart +++ b/dwds/test/chrome_proxy_service_test.dart @@ -2379,7 +2379,7 @@ void main() { ); }); - test('dart.developer logs are correctly converted to log records', + test('dart:developer logs are correctly converted to log records', () async { final logStream = context.service.onEvent(EventStreams.kLogging); final message = 'myMessage'; @@ -2396,7 +2396,7 @@ void main() { expect(logRecord.loggerName!.valueAsString, 'testLogCategory'); }); - test('long dart.developer log messages are not truncated', () async { + 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.'; From f196c2e91b9174e1e4605b900107297263930766 Mon Sep 17 00:00:00 2001 From: Elliott Brooks <21270878+elliette@users.noreply.github.com> Date: Wed, 10 Jan 2024 10:28:23 -0800 Subject: [PATCH 6/8] Update CHANGELOG --- dwds/CHANGELOG.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/dwds/CHANGELOG.md b/dwds/CHANGELOG.md index f72d51610..bedef0c93 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) From 739a19b3c4be5a7fc4ed0542c136c76fa4149fec Mon Sep 17 00:00:00 2001 From: Elliott Brooks <21270878+elliette@users.noreply.github.com> Date: Wed, 10 Jan 2024 11:14:22 -0800 Subject: [PATCH 7/8] Remove TODO --- dwds/lib/src/services/chrome_proxy_service.dart | 2 -- 1 file changed, 2 deletions(-) diff --git a/dwds/lib/src/services/chrome_proxy_service.dart b/dwds/lib/src/services/chrome_proxy_service.dart index a2ef15e90..94a293de3 100644 --- a/dwds/lib/src/services/chrome_proxy_service.dart +++ b/dwds/lib/src/services/chrome_proxy_service.dart @@ -1364,8 +1364,6 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. final args = event.args; final firstArgValue = (args.isNotEmpty ? args[0].value : null) as String?; switch (firstArgValue) { - // TODO(https://github.com/dart-lang/webdev/issues/2335): Make sure that - // inspect properties are not being truncated. case 'dart.developer.inspect': // All inspected objects should be real objects. if (event.args[1].type != 'object') break; From d24c09bc5eae0d0a1e26c760108d1d7bb37bbf3f Mon Sep 17 00:00:00 2001 From: Elliott Brooks <21270878+elliette@users.noreply.github.com> Date: Wed, 10 Jan 2024 14:27:33 -0800 Subject: [PATCH 8/8] Respond to PR comments --- dwds/lib/src/services/chrome_proxy_service.dart | 13 +++++++++++-- dwds/test/chrome_proxy_service_test.dart | 3 ++- 2 files changed, 13 insertions(+), 3 deletions(-) diff --git a/dwds/lib/src/services/chrome_proxy_service.dart b/dwds/lib/src/services/chrome_proxy_service.dart index 94a293de3..3f9f45807 100644 --- a/dwds/lib/src/services/chrome_proxy_service.dart +++ b/dwds/lib/src/services/chrome_proxy_service.dart @@ -1411,7 +1411,7 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. // `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) + ? await _fetchFullLogParams(objectId, logObject: logObject) : _fetchAbbreviatedLogParams(logObject); final logRecord = LogRecord( @@ -1441,7 +1441,10 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. ); } - Future> _fetchFullLogParams(String objectId) async { + Future> _fetchFullLogParams( + String objectId, { + required Map? logObject, + }) async { final logParams = {}; for (final property in await inspector.getProperties(objectId)) { final name = property.name; @@ -1450,6 +1453,12 @@ ${globalToolConfiguration.loadStrategy.loadModuleSnippet}("dart_sdk").developer. 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; } diff --git a/dwds/test/chrome_proxy_service_test.dart b/dwds/test/chrome_proxy_service_test.dart index 58e047cbb..c2d757868 100644 --- a/dwds/test/chrome_proxy_service_test.dart +++ b/dwds/test/chrome_proxy_service_test.dart @@ -2399,7 +2399,8 @@ void main() { 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.'; + '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');"), );