Skip to content

F
Front-End
Unverified Commit dac2ebf0 authored by Ian Hickson's avatar Ian Hickson Committed by GitHub
Browse files
Options

More flexible timeout logic in flutter_test (#18256) 

This should reduce the number of flakes without actually increasing
the timeout, so we'll still find out quickly if a test is hanging.

The numbers here might need tweaking. Maybe the default two seconds is
too short for CI bots.
parent 6c56bb24
Hide whitespace changes
Inline Side-by-side
Showing with 277 additions and 120 deletions
dev/automated_tests/test_smoke_test/timeout_fail_test.dart 0 → 100644
View file @ dac2ebf0
// Copyright 2018 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'package:flutter_test/flutter_test.dart';
void main() {
testWidgets('flutter_test timeout logic - addTime - negative', (WidgetTester tester) async {
await tester.runAsync(() async {
await new Future<void>.delayed(const Duration(milliseconds: 3500));
}, additionalTime: const Duration(milliseconds: 200));
});
}
dev/automated_tests/test_smoke_test/timeout_pass_test.dart 0 → 100644
View file @ dac2ebf0
// Copyright 2018 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'package:flutter_test/flutter_test.dart';
void main() {
testWidgets('flutter_test timeout logic - addTime - positive', (WidgetTester tester) async {
await tester.runAsync(() async {
await new Future<void>.delayed(const Duration(milliseconds: 3500));
}, additionalTime: const Duration(milliseconds: 2000));
});
}
dev/bots/test.dart
View file @ dac2ebf0
......@@ -50,8 +50,11 @@ Future<Null> main(List<String> args) async {
final String shard = Platform.environment['SHARD'];
if (shard != null) {
if (!_kShards.containsKey(shard))
throw new ArgumentError('Invalid shard: $shard');
if (!_kShards.containsKey(shard)) {
print('Invalid shard: $shard');
print('The available shards are: ${_kShards.keys.join(", ")}');
exit(1);
}
print('${bold}SHARD=$shard$reset');
await _kShards[shard]();
} else {
......@@ -132,55 +135,79 @@ Future<Null> _analyzeRepo() async {
}
Future<Null> _runTests() async {
// Verify that the tests actually return failure on failure and success on success.
// Verify that the tests actually return failure on failure and success on
// success.
final String automatedTests = path.join(flutterRoot, 'dev', 'automated_tests');
await _runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'fail_test.dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
);
// We run the "pass" and "fail" smoke tests first, and alone, because those
// are particularly critical and sensitive. If one of these fails, there's no
// point even trying the others.
await _runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'pass_test.dart'),
printOutput: false,
timeout: _kShortTimeout,
);
await _runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'crash1_test.dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
);
await _runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'crash2_test.dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
);
await _runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'syntax_error_test.broken_dart'),
script: path.join('test_smoke_test', 'fail_test.dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
);
// We run the timeout tests individually because they are timing-sensitive.
await _runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'missing_import_test.broken_dart'),
expectFailure: true,
script: path.join('test_smoke_test', 'timeout_pass_test.dart'),
expectFailure: false,
printOutput: false,
timeout: _kShortTimeout,
);
await _runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'disallow_error_reporter_modification_test.dart'),
script: path.join('test_smoke_test', 'timeout_fail_test.dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
);
await _runCommand(flutter,
<String>['drive', '--use-existing-app', '-t', path.join('test_driver', 'failure.dart')],
workingDirectory: path.join(flutterRoot, 'packages', 'flutter_driver'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
// We run the remaining smoketests in parallel, because they each take some
// time to run (e.g. compiling), so we don't want to run them in series,
// especially on 20-core machines...
await Future.wait<void>(
<Future<void>>[
_runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'crash1_test.dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
),
_runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'crash2_test.dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
),
_runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'syntax_error_test.broken_dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
),
_runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'missing_import_test.broken_dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
),
_runFlutterTest(automatedTests,
script: path.join('test_smoke_test', 'disallow_error_reporter_modification_test.dart'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
),
_runCommand(flutter,
<String>['drive', '--use-existing-app', '-t', path.join('test_driver', 'failure.dart')],
workingDirectory: path.join(flutterRoot, 'packages', 'flutter_driver'),
expectFailure: true,
printOutput: false,
timeout: _kShortTimeout,
),
],
);
// Verify that we correctly generated the version file.
......@@ -369,8 +396,20 @@ Future<Null> _runFlutterTest(String workingDirectory, {
final List<String> args = <String>['test']..addAll(options);
if (flutterTestArgs != null && flutterTestArgs.isNotEmpty)
args.addAll(flutterTestArgs);
if (script != null)
if (script != null) {
final String fullScriptPath = path.join(workingDirectory, script);
if (!FileSystemEntity.isFileSync(fullScriptPath)) {
print('Could not find test: $fullScriptPath');
print('Working directory: $workingDirectory');
print('Script: $script');
if (!printOutput)
print('This is one of the tests that does not normally print output.');
if (skip)
print('This is one of the tests that is normally skipped in this configuration.');
exit(1);
}
args.add(script);
}
return _runCommand(flutter, args,
workingDirectory: workingDirectory,
expectFailure: expectFailure,
......
packages/flutter_test/lib/src/binding.dart
View file @ dac2ebf0
......@@ -169,6 +169,10 @@ abstract class TestWidgetsFlutterBinding extends BindingBase
int get microtaskCount;
/// The default test timeout for tests when using this binding.
///
/// The [AutomatedTestWidgetsFlutterBinding] layers in an additional timeout
/// mechanism beyond this, with much more aggressive timeouts. See
/// [AutomatedTestWidgetsFlutterBinding.addTime].
test_package.Timeout get defaultTestTimeout;
/// The current time.
......@@ -194,16 +198,16 @@ abstract class TestWidgetsFlutterBinding extends BindingBase
/// this method works when the test is run with `flutter run`.
Future<Null> pump([ Duration duration, EnginePhase newPhase = EnginePhase.sendSemanticsUpdate ]);
/// Runs a [callback] that performs real asynchronous work.
/// Runs a `callback` that performs real asynchronous work.
///
/// This is intended for callers who need to call asynchronous methods where
/// the methods spawn isolates or OS threads and thus cannot be executed
/// synchronously by calling [pump].
///
/// If [callback] completes successfully, this will return the future
/// returned by [callback].
/// If `callback` completes successfully, this will return the future
/// returned by `callback`.
///
/// If [callback] completes with an error, the error will be caught by the
/// If `callback` completes with an error, the error will be caught by the
/// Flutter framework and made available via [takeException], and this method
/// will return a future that completes will `null`.
///
......@@ -211,7 +215,14 @@ abstract class TestWidgetsFlutterBinding extends BindingBase
/// are required to wait for the returned future to complete before calling
/// this method again. Attempts to do otherwise will result in a
/// [TestFailure] error being thrown.
Future<T> runAsync<T>(Future<T> callback());
///
/// The `additionalTime` argument is used by the
/// [AutomatedTestWidgetsFlutterBinding] implementation to increase the
/// current timeout. See [AutomatedTestWidgetsFlutterBinding.addTime] for
/// details. The value is ignored by the [LiveTestWidgetsFlutterBinding].
Future<T> runAsync<T>(Future<T> callback(), {
Duration additionalTime = const Duration(milliseconds: 250),
});
/// Artificially calls dispatchLocaleChanged on the Widget binding,
/// then flushes microtasks.
......@@ -377,7 +388,9 @@ abstract class TestWidgetsFlutterBinding extends BindingBase
// The LiveTestWidgetsFlutterBinding overrides this to report the exception to the console.
}
Future<Null> _runTest(Future<Null> testBody(), VoidCallback invariantTester, String description) {
Future<Null> _runTest(Future<Null> testBody(), VoidCallback invariantTester, String description, {
Future<Null> timeout,
}) {
assert(description != null);
assert(inTest);
_oldExceptionHandler = FlutterError.onError;
......@@ -403,88 +416,92 @@ abstract class TestWidgetsFlutterBinding extends BindingBase
};
final Completer<Null> testCompleter = new Completer<Null>();
final VoidCallback testCompletionHandler = _createTestCompletionHandler(description, testCompleter);
final ZoneSpecification errorHandlingZoneSpecification = new ZoneSpecification(
handleUncaughtError: (Zone self, ZoneDelegate parent, Zone zone, dynamic exception, StackTrace stack) {
if (testCompleter.isCompleted) {
// Well this is not a good sign.
// Ideally, once the test has failed we would stop getting errors from the test.
// However, if someone tries hard enough they could get in a state where this happens.
// If we silently dropped these errors on the ground, nobody would ever know. So instead
// we report them to the console. They don't cause test failures, but hopefully someone
// will see them in the logs at some point.
debugPrint = debugPrintOverride; // just in case the test overrides it -- otherwise we won't see the error!
FlutterError.dumpErrorToConsole(new FlutterErrorDetails(
exception: exception,
stack: _unmangle(stack),
context: 'running a test (but after the test had completed)',
library: 'Flutter test framework'
), forceReport: true);
return;
}
// This is where test failures, e.g. those in expect(), will end up.
// Specifically, runUnaryGuarded() will call this synchronously and
// return our return value if _runTestBody fails synchronously (which it
// won't, so this never happens), and Future will call this when the
// Future completes with an error and it would otherwise call listeners
// if the listener is in a different zone (which it would be for the
// `whenComplete` handler below), or if the Future completes with an
// error and the future has no listeners at all.
//
// This handler further calls the onError handler above, which sets
// _pendingExceptionDetails. Nothing gets printed as a result of that
// call unless we already had an exception pending, because in general
// we want people to be able to cause the framework to report exceptions
// and then use takeException to verify that they were really caught.
// Now, if we actually get here, this isn't going to be one of those
// cases. We only get here if the test has actually failed. So, once
// we've carefully reported it, we then immediately end the test by
// calling the testCompletionHandler in the _parentZone.
//
// We have to manually call testCompletionHandler because if the Future
// library calls us, it is maybe _instead_ of calling a registered
// listener from a different zone. In our case, that would be instead of
// calling the whenComplete() listener below.
//
// We have to call it in the parent zone because if we called it in
// _this_ zone, the test framework would find this zone was the current
// zone and helpfully throw the error in this zone, causing us to be
// directly called again.
String treeDump;
try {
treeDump = renderViewElement?.toStringDeep() ?? '<no tree>';
} catch (exception) {
treeDump = '<additional error caught while dumping tree: $exception>';
}
final StringBuffer expectLine = new StringBuffer();
final int stackLinesToOmit = reportExpectCall(stack, expectLine);
FlutterError.reportError(new FlutterErrorDetails(
void handleUncaughtError(dynamic exception, StackTrace stack) {
if (testCompleter.isCompleted) {
// Well this is not a good sign.
// Ideally, once the test has failed we would stop getting errors from the test.
// However, if someone tries hard enough they could get in a state where this happens.
// If we silently dropped these errors on the ground, nobody would ever know. So instead
// we report them to the console. They don't cause test failures, but hopefully someone
// will see them in the logs at some point.
debugPrint = debugPrintOverride; // just in case the test overrides it -- otherwise we won't see the error!
FlutterError.dumpErrorToConsole(new FlutterErrorDetails(
exception: exception,
stack: _unmangle(stack),
context: 'running a test',
library: 'Flutter test framework',
stackFilter: (Iterable<String> frames) {
return FlutterError.defaultStackFilter(frames.skip(stackLinesToOmit));
},
informationCollector: (StringBuffer information) {
if (stackLinesToOmit > 0)
information.writeln(expectLine.toString());
if (showAppDumpInErrors) {
information.writeln('At the time of the failure, the widget tree looked as follows:');
information.writeln('# ${treeDump.split("\n").takeWhile((String s) => s != "").join("\n# ")}');
}
if (description.isNotEmpty)
information.writeln('The test description was:\n$description');
context: 'running a test (but after the test had completed)',
library: 'Flutter test framework'
), forceReport: true);
return;
}
// This is where test failures, e.g. those in expect(), will end up.
// Specifically, runUnaryGuarded() will call this synchronously and
// return our return value if _runTestBody fails synchronously (which it
// won't, so this never happens), and Future will call this when the
// Future completes with an error and it would otherwise call listeners
// if the listener is in a different zone (which it would be for the
// `whenComplete` handler below), or if the Future completes with an
// error and the future has no listeners at all.
//
// This handler further calls the onError handler above, which sets
// _pendingExceptionDetails. Nothing gets printed as a result of that
// call unless we already had an exception pending, because in general
// we want people to be able to cause the framework to report exceptions
// and then use takeException to verify that they were really caught.
// Now, if we actually get here, this isn't going to be one of those
// cases. We only get here if the test has actually failed. So, once
// we've carefully reported it, we then immediately end the test by
// calling the testCompletionHandler in the _parentZone.
//
// We have to manually call testCompletionHandler because if the Future
// library calls us, it is maybe _instead_ of calling a registered
// listener from a different zone. In our case, that would be instead of
// calling the whenComplete() listener below.
//
// We have to call it in the parent zone because if we called it in
// _this_ zone, the test framework would find this zone was the current
// zone and helpfully throw the error in this zone, causing us to be
// directly called again.
String treeDump;
try {
treeDump = renderViewElement?.toStringDeep() ?? '<no tree>';
} catch (exception) {
treeDump = '<additional error caught while dumping tree: $exception>';
}
final StringBuffer expectLine = new StringBuffer();
final int stackLinesToOmit = reportExpectCall(stack, expectLine);
FlutterError.reportError(new FlutterErrorDetails(
exception: exception,
stack: _unmangle(stack),
context: 'running a test',
library: 'Flutter test framework',
stackFilter: (Iterable<String> frames) {
return FlutterError.defaultStackFilter(frames.skip(stackLinesToOmit));
},
informationCollector: (StringBuffer information) {
if (stackLinesToOmit > 0)
information.writeln(expectLine.toString());
if (showAppDumpInErrors) {
information.writeln('At the time of the failure, the widget tree looked as follows:');
information.writeln('# ${treeDump.split("\n").takeWhile((String s) => s != "").join("\n# ")}');
}
));
assert(_parentZone != null);
assert(_pendingExceptionDetails != null, 'A test overrode FlutterError.onError but either failed to return it to its original state, or had unexpected additional errors that it could not handle. Typically, this is caused by using expect() before restoring FlutterError.onError.');
_parentZone.run<void>(testCompletionHandler);
if (description.isNotEmpty)
information.writeln('The test description was:\n$description');
}
));
assert(_parentZone != null);
assert(_pendingExceptionDetails != null, 'A test overrode FlutterError.onError but either failed to return it to its original state, or had unexpected additional errors that it could not handle. Typically, this is caused by using expect() before restoring FlutterError.onError.');
_parentZone.run<void>(testCompletionHandler);
}
final ZoneSpecification errorHandlingZoneSpecification = new ZoneSpecification(
handleUncaughtError: (Zone self, ZoneDelegate parent, Zone zone, dynamic exception, StackTrace stack) {
handleUncaughtError(exception, stack);
}
);
_parentZone = Zone.current;
final Zone testZone = _parentZone.fork(specification: errorHandlingZoneSpecification);
testZone.runBinary(_runTestBody, testBody, invariantTester)
.whenComplete(testCompletionHandler);
timeout?.catchError(handleUncaughtError);
asyncBarrier(); // When using AutomatedTestWidgetsFlutterBinding, this flushes the microtasks.
return testCompleter.future;
}
......@@ -605,7 +622,7 @@ class AutomatedTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
ui.window.onDrawFrame = null;
}
FakeAsync _currentFakeAsync; // set from runTest to postTest
FakeAsync _currentFakeAsync; // set in runTest; cleared in postTest
Completer<void> _pendingAsyncTasks;
@override
......@@ -621,8 +638,10 @@ class AutomatedTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
@override
bool get checkIntrinsicSizes => true;
// The timeout here is absurdly high because we do our own timeout logic and
// this is just a backstop.
@override
test_package.Timeout get defaultTestTimeout => const test_package.Timeout(const Duration(seconds: 5));
test_package.Timeout get defaultTestTimeout => const test_package.Timeout(const Duration(minutes: 5));
@override
bool get inTest => _currentFakeAsync != null;
......@@ -639,6 +658,7 @@ class AutomatedTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
_currentFakeAsync.elapse(duration);
_phase = newPhase;
if (hasScheduledFrame) {
addTime(const Duration(milliseconds: 100));
_currentFakeAsync.flushMicrotasks();
handleBeginFrame(new Duration(
milliseconds: _clock.now().millisecondsSinceEpoch,
......@@ -652,7 +672,10 @@ class AutomatedTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
}
@override
Future<T> runAsync<T>(Future<T> callback()) {
Future<T> runAsync<T>(Future<T> callback(), {
Duration additionalTime = const Duration(milliseconds: 250),
}) {
assert(additionalTime != null);
assert(() {
if (_pendingAsyncTasks == null)
return true;
......@@ -678,6 +701,8 @@ class AutomatedTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
),
);
addTime(additionalTime);
return realAsyncZone.run(() {
_pendingAsyncTasks = new Completer<void>();
return callback().catchError((dynamic exception, StackTrace stack) {
......@@ -750,12 +775,67 @@ class AutomatedTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
}
}
Duration _timeout;
Stopwatch _timeoutStopwatch;
Timer _timeoutTimer;
Completer<Null> _timeoutCompleter;
void _checkTimeout(Timer timer) {
assert(_timeoutTimer == timer);
if (_timeoutStopwatch.elapsed > _timeout) {
_timeoutCompleter.completeError(
new TimeoutException(
'The test exceeded the timeout. It may have hung.\n'
'Consider using "addTime" to increase the timeout before expensive operations.',
_timeout,
),
);
}
}
/// Increase the timeout for the current test by the given duration.
///
/// Tests by default time out after two seconds, but the timeout can be
/// increased before an expensive operation to allow it to complete without
/// hitting the test timeout.
///
/// By default, each [pump] and [pumpWidget] call increases the timeout by a
/// hundred milliseconds, and each [matchesGoldenFile] expectation increases
/// it by several seconds.
///
/// In general, unit tests are expected to run very fast, and this method is
/// usually not necessary.
///
/// The granularity of timeouts is coarse: the time is checked once per
/// second, and only when the test is not executing. It is therefore possible
/// for a timeout to be exceeded by hundreds of milliseconds and for the test
/// to still succeed. If precise timing is required, it should be implemented
/// as a part of the test rather than relying on this mechanism.
///
/// See also:
///
/// * [defaultTestTimeout], the maximum that the timeout can reach.
/// (That timeout is implemented by the test package.)
void addTime(Duration duration) {
assert(_timeout != null, 'addTime can only be called during a test.');
_timeout += duration;
}
@override
Future<Null> runTest(Future<Null> testBody(), VoidCallback invariantTester, { String description = '' }) {
Future<Null> runTest(Future<Null> testBody(), VoidCallback invariantTester, {
String description = '',
Duration timeout = const Duration(seconds: 2),
}) {
assert(description != null);
assert(!inTest);
assert(_currentFakeAsync == null);
assert(_clock == null);
_timeout = timeout;
_timeoutStopwatch = new Stopwatch()..start();
_timeoutTimer = new Timer.periodic(const Duration(seconds: 1), _checkTimeout);
_timeoutCompleter = new Completer<Null>();
final FakeAsync fakeAsync = new FakeAsync();
_currentFakeAsync = fakeAsync; // reset in postTest
_clock = fakeAsync.getClock(new DateTime.utc(2015, 1, 1));
......@@ -763,7 +843,7 @@ class AutomatedTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
fakeAsync.run((FakeAsync localFakeAsync) {
assert(fakeAsync == _currentFakeAsync);
assert(fakeAsync == localFakeAsync);
testBodyResult = _runTest(testBody, invariantTester, description);
testBodyResult = _runTest(testBody, invariantTester, description, timeout: _timeoutCompleter.future);
assert(inTest);
});
......@@ -815,6 +895,11 @@ class AutomatedTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
assert(_clock != null);
_clock = null;
_currentFakeAsync = null;
_timeoutCompleter = null;
_timeoutTimer.cancel();
_timeoutTimer = null;
_timeoutStopwatch = null;
_timeout = null;
}
}
......@@ -1090,7 +1175,9 @@ class LiveTestWidgetsFlutterBinding extends TestWidgetsFlutterBinding {
}
@override
Future<T> runAsync<T>(Future<T> callback()) async {
Future<T> runAsync<T>(Future<T> callback(), {
Duration additionalTime = const Duration(milliseconds: 250),
}) async {
assert(() {
if (!_runningAsyncTasks)
return true;
......
packages/flutter_test/lib/src/matchers.dart
View file @ dac2ebf0
......@@ -1248,7 +1248,10 @@ class _MatchesGoldenFile extends AsyncMatcher {
final TestWidgetsFlutterBinding binding = TestWidgetsFlutterBinding.ensureInitialized();
return binding.runAsync<String>(() async {
final ui.Image image = await imageFuture;
final ByteData bytes = await image.toByteData(format: ui.ImageByteFormat.png);
final ByteData bytes = await image.toByteData(format: ui.ImageByteFormat.png)
.timeout(const Duration(seconds: 10), onTimeout: () => null);
if (bytes == null)
return 'Failed to generate screenshot from engine within the 10,000ms timeout.';
if (autoUpdateGoldenFiles) {
await goldenFileComparator.update(key, bytes.buffer.asUint8List());
} else {
......@@ -1259,7 +1262,7 @@ class _MatchesGoldenFile extends AsyncMatcher {
return ex.message;
}
}
});
}, additionalTime: const Duration(seconds: 11));
}
@override
......
packages/flutter_test/lib/src/widget_tester.dart
View file @ dac2ebf0
......@@ -317,7 +317,9 @@ class WidgetTester extends WidgetController implements HitTestDispatcher, Ticker
/// are required to wait for the returned future to complete before calling
/// this method again. Attempts to do otherwise will result in a
/// [TestFailure] error being thrown.
Future<T> runAsync<T>(Future<T> callback()) => binding.runAsync(callback);
Future<T> runAsync<T>(Future<T> callback(), {
Duration additionalTime = const Duration(milliseconds: 250),
}) => binding.runAsync(callback, additionalTime: additionalTime);
/// Whether there are any any transient callbacks scheduled.
///
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment

HIAST - GitLab