From 9c138f9c76c1cc49388e73591e643128a24149fd Mon Sep 17 00:00:00 2001 From: Christopher Fujino Date: Mon, 28 Mar 2022 14:13:28 -0700 Subject: [PATCH] [flutter_tools] warn when doctor takes long (#100805) * warn when doctor takes long --- .../lib/src/android/android_workflow.dart | 4 ++ .../flutter_tools/lib/src/base/logger.dart | 57 ++++++++++++++++--- packages/flutter_tools/lib/src/doctor.dart | 5 +- .../commands.shard/hermetic/attach_test.dart | 6 +- .../test/general.shard/base/logger_test.dart | 31 +++++++++- 5 files changed, 93 insertions(+), 10 deletions(-) diff --git a/packages/flutter_tools/lib/src/android/android_workflow.dart b/packages/flutter_tools/lib/src/android/android_workflow.dart index b511a168373..7d6de454f74 100644 --- a/packages/flutter_tools/lib/src/android/android_workflow.dart +++ b/packages/flutter_tools/lib/src/android/android_workflow.dart @@ -186,11 +186,13 @@ class AndroidValidator extends DoctorValidator { messages.add(ValidationMessage(_userMessages.androidSdkLocation(androidSdk.directory.path))); + _task = 'Validating Android SDK command line tools are available'; if (!androidSdk.cmdlineToolsAvailable) { messages.add(ValidationMessage.error(_userMessages.androidMissingCmdTools)); return ValidationResult(ValidationType.missing, messages); } + _task = 'Validating Android SDK licenses'; if (androidSdk.licensesAvailable && !androidSdk.platformToolsAvailable) { messages.add(ValidationMessage.hint(_userMessages.androidSdkLicenseOnly(kAndroidHome))); return ValidationResult(ValidationType.partial, messages); @@ -227,6 +229,7 @@ class AndroidValidator extends DoctorValidator { messages.add(ValidationMessage('$kAndroidSdkRoot = $androidSdkRoot')); } + _task = 'Validating Android SDK'; final List validationResult = androidSdk.validateSdkWellFormed(); if (validationResult.isNotEmpty) { @@ -238,6 +241,7 @@ class AndroidValidator extends DoctorValidator { return ValidationResult(ValidationType.partial, messages, statusInfo: sdkVersionText); } + _task = 'Finding Java binary'; // Now check for the JDK. final String? javaBinary = AndroidSdk.findJavaBinary( androidStudio: _androidStudio, diff --git a/packages/flutter_tools/lib/src/base/logger.dart b/packages/flutter_tools/lib/src/base/logger.dart index 3de53cc212b..5047e165768 100644 --- a/packages/flutter_tools/lib/src/base/logger.dart +++ b/packages/flutter_tools/lib/src/base/logger.dart @@ -212,7 +212,11 @@ abstract class Logger { /// A [SilentStatus] or an [AnonymousSpinnerStatus] (depending on whether the /// terminal is fancy enough), already started. - Status startSpinner({ VoidCallback? onFinish }); + Status startSpinner({ + VoidCallback? onFinish, + Duration? timeout, + SlowWarningCallback? slowWarningCallback, + }); /// Send an event to be emitted. /// @@ -368,8 +372,16 @@ class DelegatingLogger implements Logger { } @override - Status startSpinner({VoidCallback? onFinish}) { - return _delegate.startSpinner(onFinish: onFinish); + Status startSpinner({ + VoidCallback? onFinish, + Duration? timeout, + SlowWarningCallback? slowWarningCallback, + }) { + return _delegate.startSpinner( + onFinish: onFinish, + timeout: timeout, + slowWarningCallback: slowWarningCallback, + ); } @override @@ -571,7 +583,11 @@ class StdoutLogger extends Logger { } @override - Status startSpinner({ VoidCallback? onFinish }) { + Status startSpinner({ + VoidCallback? onFinish, + Duration? timeout, + SlowWarningCallback? slowWarningCallback, + }) { if (_status != null || !supportsColor) { return SilentStatus( onFinish: onFinish, @@ -588,6 +604,8 @@ class StdoutLogger extends Logger { stdio: _stdio, stopwatch: _stopwatchFactory.createStopwatch(), terminal: terminal, + timeout: timeout, + slowWarningCallback: slowWarningCallback, )..start(); return _status!; } @@ -859,7 +877,11 @@ class BufferLogger extends Logger { } @override - Status startSpinner({VoidCallback? onFinish}) { + Status startSpinner({ + VoidCallback? onFinish, + Duration? timeout, + SlowWarningCallback? slowWarningCallback, + }) { return SilentStatus( stopwatch: _stopwatchFactory.createStopwatch(), onFinish: onFinish, @@ -1111,9 +1133,11 @@ abstract class Status { Status({ this.onFinish, required Stopwatch stopwatch, + this.timeout, }) : _stopwatch = stopwatch; final VoidCallback? onFinish; + final Duration? timeout; @protected final Stopwatch _stopwatch; @@ -1126,6 +1150,9 @@ abstract class Status { return getElapsedAsMilliseconds(_stopwatch.elapsed); } + @visibleForTesting + bool get seemsSlow => timeout != null && _stopwatch.elapsed > timeout!; + /// Call to start spinning. void start() { assert(!_stopwatch.isRunning); @@ -1247,16 +1274,21 @@ class AnonymousSpinnerStatus extends Status { required Stopwatch stopwatch, required Stdio stdio, required Terminal terminal, + this.slowWarningCallback, + Duration? timeout, }) : _stdio = stdio, _terminal = terminal, _animation = _selectAnimation(terminal), super( onFinish: onFinish, stopwatch: stopwatch, - ); + timeout: timeout, + ); final Stdio _stdio; final Terminal _terminal; + String _slowWarning = ''; + final SlowWarningCallback? slowWarningCallback; static const String _backspaceChar = '\b'; static const String _clearChar = ' '; @@ -1300,9 +1332,10 @@ class AnonymousSpinnerStatus extends Status { Timer? timer; int ticks = 0; int _lastAnimationFrameLength = 0; + bool timedOut = false; String get _currentAnimationFrame => _animation[ticks % _animation.length]; - int get _currentLineLength => _lastAnimationFrameLength; + int get _currentLineLength => _lastAnimationFrameLength + _slowWarning.length; void _writeToStdOut(String message) => _stdio.stdoutWrite(message); @@ -1332,6 +1365,16 @@ class AnonymousSpinnerStatus extends Status { assert(timer.isActive); _writeToStdOut(_backspaceChar * _lastAnimationFrameLength); ticks += 1; + if (seemsSlow) { + if (!timedOut) { + timedOut = true; + _clear(_currentLineLength); + } + if (_slowWarning == '' && slowWarningCallback != null) { + _slowWarning = slowWarningCallback!(); + _writeToStdOut(_slowWarning); + } + } final String newFrame = _currentAnimationFrame; _lastAnimationFrameLength = newFrame.runes.length; _writeToStdOut(newFrame); diff --git a/packages/flutter_tools/lib/src/doctor.dart b/packages/flutter_tools/lib/src/doctor.dart index 5a4efd77718..72fbd73de8a 100644 --- a/packages/flutter_tools/lib/src/doctor.dart +++ b/packages/flutter_tools/lib/src/doctor.dart @@ -315,7 +315,10 @@ class Doctor { for (final ValidatorTask validatorTask in startedValidatorTasks ?? startValidatorTasks()) { final DoctorValidator validator = validatorTask.validator; - final Status status = _logger.startSpinner(); + final Status status = _logger.startSpinner( + timeout: const Duration(seconds: 2), + slowWarningCallback: () => validator.slowWarning, + ); ValidationResult result; try { result = await validatorTask.result; diff --git a/packages/flutter_tools/test/commands.shard/hermetic/attach_test.dart b/packages/flutter_tools/test/commands.shard/hermetic/attach_test.dart index 6277f3f216c..20bc230a440 100644 --- a/packages/flutter_tools/test/commands.shard/hermetic/attach_test.dart +++ b/packages/flutter_tools/test/commands.shard/hermetic/attach_test.dart @@ -631,7 +631,11 @@ class StreamLogger extends Logger { } @override - Status startSpinner({ VoidCallback onFinish }) { + Status startSpinner({ + VoidCallback onFinish, + Duration timeout, + SlowWarningCallback slowWarningCallback, + }) { return SilentStatus( stopwatch: Stopwatch(), onFinish: onFinish, diff --git a/packages/flutter_tools/test/general.shard/base/logger_test.dart b/packages/flutter_tools/test/general.shard/base/logger_test.dart index 58d377a2ba3..df6082bc595 100644 --- a/packages/flutter_tools/test/general.shard/base/logger_test.dart +++ b/packages/flutter_tools/test/general.shard/base/logger_test.dart @@ -451,7 +451,7 @@ void main() { FakeAsync().run((FakeAsync time) { final AnonymousSpinnerStatus spinner = AnonymousSpinnerStatus( stdio: mockStdio, - stopwatch: stopwatchFactory.createStopwatch(), + stopwatch: mockStopwatch, terminal: terminal, )..start(); doWhileAsync(time, () => spinner.ticks < 10); @@ -479,6 +479,35 @@ void main() { expect(done, isTrue); }); + testWithoutContext('AnonymousSpinnerStatus logs warning after timeout', () async { + mockStopwatch = FakeStopwatch(); + const String warningMessage = 'a warning message.'; + final bool done = FakeAsync().run((FakeAsync time) { + final AnonymousSpinnerStatus spinner = AnonymousSpinnerStatus( + stdio: mockStdio, + stopwatch: mockStopwatch, + terminal: terminal, + slowWarningCallback: () => warningMessage, + timeout: const Duration(milliseconds: 100), + )..start(); + // must be greater than the spinner timer duration + const Duration timeLapse = Duration(milliseconds: 101); + mockStopwatch.elapsed += timeLapse; + time.elapse(timeLapse); + + List lines = outputStdout(); + expect( + lines.join(), + contains(warningMessage), + ); + + spinner.stop(); + lines = outputStdout(); + return true; + }); + expect(done, isTrue); + }); + testWithoutContext('Stdout startProgress on colored terminal', () async { final Logger logger = StdoutLogger( terminal: coloredTerminal,