fix(logging): combine newline-split stdout messages into one log entry (#9757)
* fix(logging): combine newline-split stdout messages into one log entry
* Refactor StdoutEventHandler buffering logic and null handling
* formatting
* Update packages/devtools_app/release_notes/NEXT_RELEASE_NOTES.md
Co-authored-by: Kenzie Davisson <43759233+kenzieschmoll@users.noreply.github.com>
---------
Co-authored-by: Kenzie Davisson <43759233+kenzieschmoll@users.noreply.github.com>
diff --git a/packages/devtools_app/lib/src/screens/logging/logging_controller.dart b/packages/devtools_app/lib/src/screens/logging/logging_controller.dart
index fa93986..da6f1ce 100644
--- a/packages/devtools_app/lib/src/screens/logging/logging_controller.dart
+++ b/packages/devtools_app/lib/src/screens/logging/logging_controller.dart
@@ -293,13 +293,13 @@
void _handleConnectionStart(VmServiceWrapper service) {
// Log stdout events.
- final stdoutHandler = _StdoutEventHandler(this, 'stdout');
+ final stdoutHandler = StdoutEventHandler(this, 'stdout');
autoDisposeStreamSubscription(
service.onStdoutEventWithHistorySafe.listen(stdoutHandler.handle),
);
// Log stderr events.
- final stderrHandler = _StdoutEventHandler(this, 'stderr', isError: true);
+ final stderrHandler = StdoutEventHandler(this, 'stderr', isError: true);
autoDisposeStreamSubscription(
service.onStderrEventWithHistorySafe.listen(stderrHandler.handle),
);
@@ -841,44 +841,21 @@
/// stdout message and its newline. Currently, `foo\n` is sent as two VM events;
/// we wait for up to 1ms when we get the `foo` event, to see if the next event
/// is a single newline. If so, we add the newline to the previous log message.
-class _StdoutEventHandler {
- _StdoutEventHandler(
- this.loggingController,
- this.name, {
- this.isError = false,
- });
+@visibleForTesting
+class StdoutEventHandler {
+ StdoutEventHandler(this.loggingController, this.name, {this.isError = false});
final LoggingController loggingController;
final String name;
final bool isError;
- LogData? buffer;
- Timer? timer;
+ LogData? _buffer;
+ Timer? _timer;
void handle(Event e) {
final message = decodeBase64(e.bytes!);
- if (buffer != null) {
- timer?.cancel();
-
- if (message == '\n') {
- loggingController.log(
- LogData(
- buffer!.kind,
- buffer!.details! + message,
- buffer!.timestamp,
- summary: buffer!.summary! + message,
- isError: buffer!.isError,
- isolateRef: e.isolateRef,
- ),
- );
- buffer = null;
- return;
- }
-
- loggingController.log(buffer!);
- buffer = null;
- }
+ if (_handleBufferedMessage(message, e)) return;
const maxLength = 200;
@@ -899,13 +876,70 @@
if (message == '\n') {
loggingController.log(data);
} else {
- buffer = data;
- timer = Timer(const Duration(milliseconds: 1), () {
- loggingController.log(buffer!);
- buffer = null;
- });
+ _setBuffer(data);
}
}
+
+ bool _handleBufferedMessage(String message, Event e) {
+ if (_buffer case final currentBuffer?) {
+ _timer?.cancel();
+
+ if (message == '\n') {
+ loggingController.log(
+ LogData(
+ currentBuffer.kind,
+ currentBuffer.details! + message,
+ currentBuffer.timestamp,
+ summary: currentBuffer.summary! + message,
+ isError: currentBuffer.isError,
+ isolateRef: e.isolateRef,
+ ),
+ );
+ _buffer = null;
+ return true;
+ }
+
+ // If the buffered message ends with a newline, the next message is a
+ // continuation of the same print statement (e.g. debugPrint('line1\nline2')
+ // is sent by the VM as two events: 'line1\n' and 'line2'). Combine them
+ // into a single log entry.
+ // See: https://github.com/flutter/devtools/issues/9557
+ if (currentBuffer.details!.endsWith('\n')) {
+ _setBuffer(
+ LogData(
+ currentBuffer.kind,
+ currentBuffer.details! + message,
+ currentBuffer.timestamp,
+ summary: currentBuffer.summary,
+ isError: currentBuffer.isError,
+ isolateRef: e.isolateRef,
+ ),
+ );
+ return true;
+ }
+
+ loggingController.log(currentBuffer);
+ _buffer = null;
+ }
+ return false;
+ }
+
+ void _setBuffer(LogData data) {
+ _buffer = data;
+ _timer?.cancel();
+ _timer = Timer(const Duration(milliseconds: 1), () {
+ if (_buffer case final currentBuffer?) {
+ loggingController.log(currentBuffer);
+ _buffer = null;
+ }
+ });
+ }
+
+ @visibleForTesting
+ LogData? get buffer => _buffer;
+
+ @visibleForTesting
+ Timer? get timer => _timer;
}
bool _isNotNull(InstanceRef? serviceRef) {
diff --git a/packages/devtools_app/release_notes/NEXT_RELEASE_NOTES.md b/packages/devtools_app/release_notes/NEXT_RELEASE_NOTES.md
index d729c95..d4e8482 100644
--- a/packages/devtools_app/release_notes/NEXT_RELEASE_NOTES.md
+++ b/packages/devtools_app/release_notes/NEXT_RELEASE_NOTES.md
@@ -43,7 +43,7 @@
## Logging updates
-TODO: Remove this section if there are not any updates.
+- Fixed an issue where log messages containing newline characters were incorrectly split into multiple separate entries in the Logging screen. [#9757](https://github.com/flutter/devtools/pull/9757)
## App size tool updates
diff --git a/packages/devtools_app/test/screens/logging/logging_controller_test.dart b/packages/devtools_app/test/screens/logging/logging_controller_test.dart
index 4362b58..85b534e 100644
--- a/packages/devtools_app/test/screens/logging/logging_controller_test.dart
+++ b/packages/devtools_app/test/screens/logging/logging_controller_test.dart
@@ -381,4 +381,55 @@
},
);
});
+
+ group('StdoutEventHandler', () {
+ late LoggingController controller;
+ late StdoutEventHandler stdoutHandler;
+
+ Event stdoutEvent(String message, {int? timestamp}) {
+ return Event(
+ bytes: base64Encode(utf8.encode(message)),
+ timestamp: timestamp ?? ++timestampCounter,
+ );
+ }
+
+ setUp(() {
+ setGlobal(ServiceConnectionManager, FakeServiceConnectionManager());
+ setGlobal(MessageBus, MessageBus());
+ setGlobal(PreferencesController, PreferencesController());
+
+ controller = LoggingController()..init();
+ stdoutHandler = StdoutEventHandler(controller, 'stdout');
+ });
+
+ test('combines newline-terminated continuation into one log', () async {
+ stdoutHandler.handle(stdoutEvent('line1\n'));
+ stdoutHandler.handle(stdoutEvent('line2'));
+
+ await Future<void>.delayed(const Duration(milliseconds: 10));
+
+ expect(controller.data, hasLength(1));
+ expect(controller.data.single.kind, 'stdout');
+ expect(controller.data.single.details, 'line1\nline2');
+ });
+
+ test('still combines message followed by lone newline', () {
+ stdoutHandler.handle(stdoutEvent('line1'));
+ stdoutHandler.handle(stdoutEvent('\n'));
+
+ expect(controller.data, hasLength(1));
+ expect(controller.data.single.details, 'line1\n');
+ });
+
+ test('keeps separate entries for distinct non-newline chunks', () async {
+ stdoutHandler.handle(stdoutEvent('line1'));
+ stdoutHandler.handle(stdoutEvent('line2'));
+
+ await Future<void>.delayed(const Duration(milliseconds: 10));
+
+ expect(controller.data, hasLength(2));
+ expect(controller.data[0].details, 'line1');
+ expect(controller.data[1].details, 'line2');
+ });
+ });
}
