fix(mason_logger): progress overflow terminal spam (#1368)

felangel · Jul 18, 2024 · a831e8b · a831e8b
1 parent 7090628
commit a831e8b
Show file tree

Hide file tree

Showing 6 changed files with 139 additions and 46 deletions.
diff --git a/.github/workflows/mason_logger.yaml b/.github/workflows/mason_logger.yaml
@@ -40,6 +40,30 @@ jobs:
       - name: Analyze
         run: dart analyze --fatal-infos --fatal-warnings .
 
+      - name: Run Tests
+        run: |
+          dart pub global activate coverage 1.2.0
+          dart test --coverage=coverage && dart pub global run coverage:format_coverage --lcov --in=coverage --out=coverage/lcov.info --packages=.dart_tool/package_config.json --report-on=lib --check-ignore
+
+      - name: Check Code Coverage
+        uses: VeryGoodOpenSource/very_good_coverage@v3
+        with:
+          path: packages/mason_logger/coverage/lcov.info
+
+  e2e:
+    defaults:
+      run:
+        working-directory: packages/mason_logger
+
+    runs-on: macos-latest
+
+    steps:
+      - uses: actions/checkout@v4.1.7
+      - uses: dart-lang/setup-dart@v1
+
+      - name: Install Dependencies
+        run: dart pub get
+
       - name: Verify CI Behavior
         run: |
           dart test/ci.dart >> ci.txt
@@ -52,16 +76,6 @@ jobs:
               exit 1
           fi
 
-      - name: Run Tests
-        run: |
-          dart pub global activate coverage 1.2.0
-          dart test --coverage=coverage && dart pub global run coverage:format_coverage --lcov --in=coverage --out=coverage/lcov.info --packages=.dart_tool/package_config.json --report-on=lib --check-ignore
-
-      - name: Check Code Coverage
-        uses: VeryGoodOpenSource/very_good_coverage@v3
-        with:
-          path: packages/mason_logger/coverage/lcov.info
-
   pana:
     defaults:
       run:

diff --git a/packages/mason_logger/lib/src/mason_logger.dart b/packages/mason_logger/lib/src/mason_logger.dart
@@ -1,6 +1,7 @@
 import 'dart:async';
 import 'dart:convert';
 import 'dart:io' as io;
+import 'dart:math';
 
 import 'package:mason_logger/mason_logger.dart';
 import 'package:mason_logger/src/ffi/terminal.dart';

diff --git a/packages/mason_logger/lib/src/progress.dart b/packages/mason_logger/lib/src/progress.dart
@@ -72,6 +72,10 @@ class Progress {
     _timer = Timer.periodic(const Duration(milliseconds: 80), _onTick);
   }
 
+  static const _padding = 15;
+  static const _disableLineWrap = '\x1b[?7l';
+  static const _enableLineWrap = '\x1b[?7h';
+
   final ProgressOptions _options;
 
   final io.Stdout _stdout;
@@ -95,7 +99,7 @@ class Progress {
   void complete([String? update]) {
     _stopwatch.stop();
     _write(
-      '''$_clearLine${lightGreen.wrap('✓')} ${update ?? _message} $_time\n''',
+      '''$_enableWrap$_clearLine${lightGreen.wrap('✓')} ${update ?? _message} $_time\n''',
     );
     _timer?.cancel();
   }
@@ -108,7 +112,9 @@ class Progress {
   /// * [cancel], to cancel the progress entirely and remove the written line.
   void fail([String? update]) {
     _timer?.cancel();
-    _write('$_clearLine${red.wrap('✗')} ${update ?? _message} $_time\n');
+    _write(
+      '$_enableWrap$_clearLine${red.wrap('✗')} ${update ?? _message} $_time\n',
+    );
     _stopwatch.stop();
   }
 
@@ -126,18 +132,41 @@ class Progress {
     _stopwatch.stop();
   }
 
+  int get _terminalColumns {
+    if (!_stdout.hasTerminal) return 80;
+    return _stdout.terminalColumns;
+  }
+
+  String get _clampedMessage {
+    final width = max(_terminalColumns - _padding, _padding);
+    if (_message.length > width) return _message.substring(0, width);
+    return _message;
+  }
+
   String get _clearLine {
+    if (!_stdout.hasTerminal) return '\r';
     return '\u001b[2K' // clear current line
         '\r'; // bring cursor to the start of the current line
   }
 
+  String get _disableWrap {
+    if (!_stdout.hasTerminal) return '';
+    return _disableLineWrap;
+  }
+
+  String get _enableWrap {
+    if (!_stdout.hasTerminal) return '';
+    return _enableLineWrap;
+  }
+
   void _onTick(Timer? _) {
     _index++;
     final frames = _options.animation.frames;
     final char = frames.isEmpty ? '' : frames[_index % frames.length];
     final prefix = char.isEmpty ? char : '${lightGreen.wrap(char)} ';
-
-    _write('$_clearLine$prefix$_message${_options.trailing} $_time');
+    _write(
+      '''$_disableWrap$_clearLine$prefix$_clampedMessage${_options.trailing} $_time''',
+    );
   }
 
   void _write(String object) {

diff --git a/packages/mason_logger/test/fixtures/ci.txt b/packages/mason_logger/test/fixtures/ci.txt
@@ -1 +1 @@
-⠋ Calculating...[2K⠙ This is taking longer than expected... (1.0s)[2K⠹ Almost done... (2.0s)[2K✓ Done (3.0s)
+⠋ Calculating...⠙ This is taking longer than expected... (1.0s)⠹ Almost done... (2.0s)✓ Done (3.0s)

diff --git a/packages/mason_logger/test/src/mason_logger_test.dart b/packages/mason_logger/test/src/mason_logger_test.dart
@@ -24,6 +24,7 @@ void main() {
 
       when(() => stdout.supportsAnsiEscapes).thenReturn(true);
       when(() => stdout.hasTerminal).thenReturn(true);
+      when(() => stdout.terminalColumns).thenReturn(80);
     });
 
     group('theme', () {

diff --git a/packages/mason_logger/test/src/progress_test.dart b/packages/mason_logger/test/src/progress_test.dart
@@ -15,6 +15,7 @@ void main() {
       stdout = _MockStdout();
       when(() => stdout.supportsAnsiEscapes).thenReturn(true);
       when(() => stdout.hasTerminal).thenReturn(true);
+      when(() => stdout.terminalColumns).thenReturn(80);
     });
 
     test('writes ms when elapsed time is less than 0.1s', () async {
@@ -33,6 +34,76 @@ void main() {
       );
     });
 
+    test('truncates message when length exceeds terminal columns', () async {
+      await _runZoned(
+        () async {
+          const message = 'this is a very long message that will be truncated.';
+          when(() => stdout.terminalColumns).thenReturn(36);
+          final progress = Logger().progress(message);
+          await Future<void>.delayed(const Duration(milliseconds: 400));
+          progress.complete();
+          verifyInOrder([
+            () {
+              stdout.write(
+                any(
+                  that: matches(
+                    RegExp(r'this is a very long m\.\.\..*\(0.2s\)'),
+                  ),
+                ),
+              );
+            },
+            () {
+              stdout.write(
+                any(
+                  that: matches(
+                    RegExp(r'this is a very long m\.\.\..*\(0.3s\)'),
+                  ),
+                ),
+              );
+            },
+            () {
+              stdout.write(
+                any(
+                  that: matches(
+                    RegExp(
+                      r'this is a very long message that will be truncated\..*\(0.4s\)',
+                    ),
+                  ),
+                ),
+              );
+            },
+          ]);
+        },
+        stdout: () => stdout,
+        zoneValues: {AnsiCode: true},
+      );
+    });
+
+    test('writes full message when stdout does not have a terminal', () async {
+      await _runZoned(
+        () async {
+          const message = 'this is a very long message that will be truncated.';
+          when(() => stdout.hasTerminal).thenReturn(false);
+          final progress = Logger().progress(message);
+          await Future<void>.delayed(const Duration(milliseconds: 400));
+          progress.complete();
+          verify(() {
+            stdout.write(
+              any(
+                that: matches(
+                  RegExp(
+                    r'this is a very long message that will be truncated\..*\(0.4s\)',
+                  ),
+                ),
+              ),
+            );
+          }).called(1);
+        },
+        stdout: () => stdout,
+        zoneValues: {AnsiCode: true},
+      );
+    });
+
     test('writes static message when stdioType is not terminal', () async {
       when(() => stdout.hasTerminal).thenReturn(false);
       await _runZoned(
@@ -45,7 +116,7 @@ void main() {
             () => stdout.write('${lightGreen.wrap('⠋')} $message...'),
             () {
               stdout.write(
-                '''\u001b[2K\r${lightGreen.wrap('✓')} $message ${darkGray.wrap('(0.4s)')}\n''',
+                '''\r${lightGreen.wrap('✓')} $message ${darkGray.wrap('(0.4s)')}\n''',
               );
             },
           ]);
@@ -72,7 +143,7 @@ void main() {
             () => stdout.write('${lightGreen.wrap('⠋')} $message!!!'),
             () {
               stdout.write(
-                '''\u001b[2K\r${lightGreen.wrap('✓')} $message ${darkGray.wrap('(0.4s)')}\n''',
+                '''\r${lightGreen.wrap('✓')} $message ${darkGray.wrap('(0.4s)')}\n''',
               );
             },
           ]);
@@ -213,20 +284,15 @@ void main() {
               () {
                 stdout.write(
                   any(
-                    that: matches(
-                      RegExp(
-                        r'\[2K\u000D\[92m⠙\[0m test message... \[90m\(8\dms\)\[0m',
-                      ),
-                    ),
+                    that: matches(RegExp(r'⠙.*test message\.\.\..*\(8\dms\)')),
                   ),
                 );
               },
             ).called(1);
-
             verify(
               () {
                 stdout.write(
-                  '''[2K\r[92m✓[0m test message [90m(0.1s)[0m\n''',
+                  any(that: matches(RegExp(r'✓.*test message.*\(0.1s\)'))),
                 );
               },
             ).called(1);
@@ -261,31 +327,18 @@ void main() {
             await Future<void>.delayed(const Duration(milliseconds: 100));
             progress.update(update);
             await Future<void>.delayed(const Duration(milliseconds: 100));
-
             verify(
               () {
                 stdout.write(
-                  any(
-                    that: matches(
-                      RegExp(
-                        r'\[2K\u000D\[92m⠙\[0m message... \[90m\(8\dms\)\[0m',
-                      ),
-                    ),
-                  ),
+                  any(that: matches(RegExp(r'⠙.*message\.\.\..*\(8\dms\)'))),
                 );
               },
             ).called(1);
 
             verify(
               () {
                 stdout.write(
-                  any(
-                    that: matches(
-                      RegExp(
-                        r'\[2K\u000D\[92m⠹\[0m update... \[90m\(0\.1s\)\[0m',
-                      ),
-                    ),
-                  ),
+                  any(that: matches(RegExp(r'⠹.*update\.\.\..*\(0\.1s\)'))),
                 );
               },
             ).called(1);
@@ -316,7 +369,6 @@ void main() {
       test('writes lines to stdout', () async {
         await _runZoned(
           () async {
-            const time = '(0.1s)';
             const message = 'test message';
             final progress = Logger().progress(message);
             await Future<void>.delayed(const Duration(milliseconds: 100));
@@ -326,11 +378,7 @@ void main() {
               () {
                 stdout.write(
                   any(
-                    that: matches(
-                      RegExp(
-                        r'\[2K\u000D\[92m⠙\[0m test message... \[90m\(8\dms\)\[0m',
-                      ),
-                    ),
+                    that: matches(RegExp(r'⠙.*test message\.\.\..*\(8\dms\)')),
                   ),
                 );
               },
@@ -339,7 +387,7 @@ void main() {
             verify(
               () {
                 stdout.write(
-                  '''[2K\u000D[31m✗[0m $message [90m$time[0m\n''',
+                  any(that: matches(RegExp(r'✗.*test message.*\(0\.1s\)'))),
                 );
               },
             ).called(1);
Original file line number	Diff line number	Diff line change
		@@ -1 +1 @@
		⠋ Calculating...[2K⠙ This is taking longer than expected... (1.0s)[2K⠹ Almost done... (2.0s)[2K✓ Done (3.0s)
		⠋ Calculating...⠙ This is taking longer than expected... (1.0s)⠹ Almost done... (2.0s)✓ Done (3.0s)
Expand Down