From a831e8b6cd44f98b50dbdb3d2c421c3d2f9ac7ad Mon Sep 17 00:00:00 2001 From: Felix Angelov Date: Wed, 17 Jul 2024 22:04:21 -0500 Subject: [PATCH] fix(mason_logger): progress overflow terminal spam (#1368) --- .github/workflows/mason_logger.yaml | 34 ++++-- .../mason_logger/lib/src/mason_logger.dart | 1 + packages/mason_logger/lib/src/progress.dart | 37 +++++- packages/mason_logger/test/fixtures/ci.txt | 2 +- .../test/src/mason_logger_test.dart | 1 + .../mason_logger/test/src/progress_test.dart | 110 +++++++++++++----- 6 files changed, 139 insertions(+), 46 deletions(-) diff --git a/.github/workflows/mason_logger.yaml b/.github/workflows/mason_logger.yaml index fdb681b7d..52fba0b21 100644 --- 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 index bfb21f307..8d8b7d0f6 100644 --- 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 index bf747f3b4..ac80baff5 100644 --- 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 index 8bb00d2c0..b2e36e1b4 100644 --- a/packages/mason_logger/test/fixtures/ci.txt +++ b/packages/mason_logger/test/fixtures/ci.txt @@ -1 +1 @@ -⠋ Calculating... ⠙ This is taking longer than expected... (1.0s) ⠹ Almost done... (2.0s) ✓ 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 index d6cd6d58e..c1d901609 100644 --- 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 index 40baaf99c..414fd655d 100644 --- 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.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.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( - '''\r✓ test message (0.1s)\n''', + any(that: matches(RegExp(r'✓.*test message.*\(0.1s\)'))), ); }, ).called(1); @@ -261,17 +327,10 @@ void main() { await Future.delayed(const Duration(milliseconds: 100)); progress.update(update); await Future.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); @@ -279,13 +338,7 @@ void main() { 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.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( - '''\u000D✗ $message $time\n''', + any(that: matches(RegExp(r'✗.*test message.*\(0\.1s\)'))), ); }, ).called(1);