blob: 49d3857d19ddc2089f15f64d1b044d1c723b0ebb [file] [log] [blame]
// Copyright 2019 The Fuchsia 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 'dart:io';
import 'package:fxtest/fxtest.dart';
import 'package:io/ansi.dart';
import 'package:meta/meta.dart';
class Emoji {
final String emoji;
final String fallback;
Emoji(this.emoji, this.fallback);
static final Emoji party = Emoji('πŸŽ‰', '!');
static final Emoji thinking = Emoji('πŸ€”', '?');
static final Emoji check = Emoji('βœ…', '√');
static final Emoji x = Emoji('❌', 'F');
}
abstract class OutputFormatter {
final bool isVerbose;
final bool simpleOutput;
final bool hasRealTimeOutput;
final Duration slowTestThreshold;
final List<TestInfo> _infoEvents;
final List<TestStarted> _testStartedEvents;
final List<TestResult> _testResultEvents;
final OutputBuffer _buffer;
DateTime _testSuiteStartTime;
DateTime _lastTestStartTime;
bool _hasStartedTests;
bool _currentTestIsSlow;
bool _lastTestHadOutput;
int _numPassed;
int _numRun;
int _numFailed;
OutputFormatter({
@required this.isVerbose,
@required this.hasRealTimeOutput,
@required this.slowTestThreshold,
this.simpleOutput = false,
OutputBuffer buffer,
}) : _testResultEvents = [],
_infoEvents = [],
_testStartedEvents = [],
_numPassed = 0,
_numRun = 0,
_numFailed = 0,
_buffer = buffer ?? OutputBuffer.realIO(),
_currentTestIsSlow = false,
_hasStartedTests = false,
_lastTestHadOutput = false;
factory OutputFormatter.fromConfig(
TestsConfig testsConfig, {
OutputBuffer buffer,
}) {
if (testsConfig.flags.infoOnly) {
return InfoFormatter();
}
var slowTestThreshold = testsConfig.flags.slowThreshold > 0
? Duration(seconds: testsConfig.flags.slowThreshold)
: null;
return StandardOutputFormatter(
buffer: buffer,
hasRealTimeOutput: testsConfig.flags.allOutput,
isVerbose: testsConfig.flags.isVerbose || testsConfig.flags.allOutput,
simpleOutput: testsConfig.flags.simpleOutput,
slowTestThreshold: slowTestThreshold,
);
}
bool get hasStartedTests => _hasStartedTests;
int get numFailures => _numFailed;
String get testExecutionTime => _getExecutionTime(_lastTestStartTime);
String get suiteExecutionTime => _getExecutionTime(_testSuiteStartTime);
String _getExecutionTime(DateTime _startTime) {
Duration elapsedTime = DateTime.now().difference(_startTime);
String minutes = elapsedTime.inMinutes.toString().padLeft(2, '0');
String seconds = (elapsedTime.inSeconds % 60).toString().padLeft(2, '0');
return '$minutes:$seconds';
}
String get ratioDisplay {
var passed = colorize(_numPassed.toString(), [green]);
var run = colorize(_numRun.toString(), [numFailures == 0 ? green : red]);
return '[$passed/$run]';
}
/// Future that resolves when the stdout closes for any reason
Future get stdOutClosedFuture => _buffer.stdOutClosedFuture();
/// Pass-thru to the actual buffer's close method
void close() => _buffer.close();
void forcefullyClose() => _buffer.forcefullyClose();
String colorize(String content, Iterable<AnsiCode> args) {
return simpleOutput ? content : wrapWith(content, args);
}
String addEmoji(Emoji emoji) {
return simpleOutput ? emoji.fallback : emoji.emoji;
}
/// Accepts a [TestEvent] and updates the output buffer.
void update(TestEvent event) {
if (event is TestInfo) {
_infoEvents.add(event);
} else if (event is TestStarted) {
_testStartedEvents.add(event);
} else if (event is TestResult) {
_testResultEvents.add(event);
}
_updateAfterEvent(event);
}
void _updateAfterEvent(TestEvent event) {
var _now = DateTime.now();
if (event is BeginningTests) {
_hasStartedTests = true;
_testSuiteStartTime = _now;
} else if (event is TestStarted) {
_currentTestIsSlow = false;
_lastTestStartTime = _now;
_numRun += 1;
_handleTestStarted(event);
} else if (event is TestResult) {
(event.isSuccess) ? _numPassed += 1 : _numFailed += 1;
_handleTestResult(event);
} else if (event is TestOutputEvent) {
// This must always come before `TestInfo`, because it is a subclass
_handleTestOutputEvent(event);
} else if (event is TimeElapsedEvent) {
// We do nothing with time events during realtime output -- the user is
// already getting constant updates
if (hasRealTimeOutput) return;
if (event.timeElapsed >= slowTestThreshold) {
if (!_currentTestIsSlow) {
_currentTestIsSlow = true;
_handleSlowTest(event);
}
}
_handleTimeElapsedEvent(event);
} else if (event is TestInfo) {
_handleTestInfo(event);
} else if (event is FatalError) {
stderr.writeln(event.message);
_finalizeOutput();
} else if (event is AllTestsCompleted) {
_finalizeOutput();
}
}
/// Handles every [TimeElapsedEvent] instance, regardless of whether the test
/// has yet been deemed "slow".
void _handleTimeElapsedEvent(TimeElapsedEvent event);
/// Handles only the first [TimeElapsedEvent] that passes the slow threshold.
void _handleSlowTest(TimeElapsedEvent event) {
var hint =
colorize('(adjust this value with the -s|--slow flag)', [darkGray]);
_buffer
..addLine(
colorize(
' >> Runtime has exceeded ${slowTestThreshold.inSeconds} '
'seconds $hint',
[magenta]),
)
..addLines(event.output);
}
/// Generic info events handler.
void _handleTestInfo(TestInfo event);
/// Handler for the stream of stdout and stderr content produced by running
/// tests.
void _handleTestOutputEvent(TestOutputEvent event) {
if (_currentTestIsSlow || hasRealTimeOutput) {
_lastTestHadOutput = true;
return _handleTestInfo(event);
}
}
/// Handles the event that fires as each test beings execution.
void _handleTestStarted(TestStarted event);
/// Handles the event that fires as each test completes execution.
void _handleTestResult(TestResult event);
/// Produces summarizing content for the user. Called once.
void _finalizeOutput();
void _reportSummary() {
_buffer.reduceEmptyRowsTo(0);
if (_testResultEvents.isEmpty) {
_buffer.addLines(['Ran zero tests']);
return;
}
String failures = numFailures != 1 ? 'failures' : 'failure';
String verb = _testResultEvents.last.isDryRun ? 'Faked' : 'Ran';
var verboseHint = !isVerbose && !cleanEndOfOutput
? wrapWith(' (use the -v flag to see each test)', [darkGray])
: '';
String summary =
'$verb ${_testResultEvents.length} tests with $numFailures $failures$verboseHint';
if (numFailures == 0) {
summary = '${addEmoji(Emoji.party)} ${colorize(summary, [
green
])} ${addEmoji(Emoji.party)}';
}
_buffer.addLines([summary]);
}
bool get cleanEndOfOutput =>
// Did the last test end with verbose output?
!isVerbose &&
!_currentTestIsSlow &&
!hasRealTimeOutput &&
// Did the last test fail?
(_testResultEvents.isNotEmpty && _testResultEvents.last.isSuccess);
}
/// Default output wrapper inspired by both Dart's test runner and fx build's
/// standard output.
///
/// Aims to print something like this (when no tests fail):
/// ```txt
/// $ fx test --limit 2 -v
/// Found N total tests in //out/default/tests.json
/// Will run 2 tests
///
/// [2/2] 00:01 √ All tests completed
///
/// πŸŽ‰ Ran 2 tests with 0 failures πŸŽ‰
/// ```
class StandardOutputFormatter extends OutputFormatter {
StandardOutputFormatter({
@required bool hasRealTimeOutput,
bool simpleOutput = true,
Duration slowTestThreshold,
OutputBuffer buffer,
bool isVerbose,
}) : super(
isVerbose: isVerbose,
hasRealTimeOutput: hasRealTimeOutput,
simpleOutput: simpleOutput,
slowTestThreshold: slowTestThreshold,
buffer: buffer,
);
@override
void _handleTestInfo(TestInfo event) {
_buffer.addLines([
// Padding for info events that appear in the middle of the result stream
if (hasStartedTests && event.requiresPadding)
' ',
// The message itself
event.message,
// Padding for info events that appear in the middle of the result stream
if (hasStartedTests && event.requiresPadding)
' ',
]);
}
@override
void _handleTimeElapsedEvent(TimeElapsedEvent event) {}
@override
void _handleTestStarted(TestStarted event) {
String testName = colorize(event.testName, [cyan]);
// Add some padding for our first test event
if (_testStartedEvents.length == 1) {
_buffer.addLine('');
}
_lastTestHadOutput = false;
var output =
'$ratioDisplay $testExecutionTime ${addEmoji(Emoji.thinking)} $testName';
if (isVerbose) {
_buffer.addLine(output);
} else {
// Add some more padding for our first test event
if (_testStartedEvents.length == 1) {
_buffer.addLine('');
}
_buffer.updateLines([output]);
}
}
/// Prints something like "[numPassed/numRun] TT:TT <emoji> <test-name>"
@override
void _handleTestResult(TestResult event) {
if (_lastTestHadOutput) _buffer.addLines(['']);
String testName = colorize(event.testName, [cyan]);
String emoji = event.isDryRun
? colorize('(dry run)', [darkGray])
: event.isSuccess
? '${addEmoji(Emoji.check)} '
: '${addEmoji(Emoji.x)} ';
var output = '$ratioDisplay $testExecutionTime $emoji $testName';
// When piping realtime output to the user, we don't want to remove the
// last line. Usually, the last line is what indicates a new test is underway,
// which we replace in favor of the results line, but in this scenario,
// it's likely some output from the test.
// We do the same for slow tests because we print realtime output for them.
if (hasRealTimeOutput || _currentTestIsSlow) {
_buffer.addLines([output]);
} else {
_buffer.updateLines([output]);
}
// Report for failed messages
if (!event.isSuccess && event.message != null) {
// But only if not already doing realtime
if (!hasRealTimeOutput && !_currentTestIsSlow) {
_buffer.addLines([event.message, '']);
}
}
}
void _finalizeLastTestLine() {
if (!cleanEndOfOutput) return;
var verboseHint = wrapWith(
' (use the -v flag to see each test)',
[darkGray],
);
_buffer.updateLines([
'$ratioDisplay $suiteExecutionTime All tests completed$verboseHint',
]);
}
@override
void _finalizeOutput() {
_finalizeLastTestLine();
_reportSummary();
}
}
/// Special formatter for when the caller is only using this tool to translate
/// shorthand test invocation patterns into fully-formed patterns.
///
/// This formatter is not intended to be paired with an actual test suite
/// execution, and as such, ignores all events except `TestStarted`, which it
/// uses to print a fully hydrated test invocation pattern.
class InfoFormatter extends OutputFormatter {
InfoFormatter()
: super(
buffer: OutputBuffer.realIO(cursorStartsOnNewLine: true),
hasRealTimeOutput: false,
slowTestThreshold: Duration(seconds: 0),
isVerbose: false,
);
@override
void _handleTestInfo(TestInfo event) {}
@override
void _handleTestStarted(TestStarted event) {
_buffer.addLines([
...infoPrint(event.testDefinition),
'',
]);
}
@override
void _handleTestResult(TestResult event) {}
@override
void _finalizeOutput() {}
@override
void _handleTimeElapsedEvent(TimeElapsedEvent event) {}
}
List<String> infoPrint(TestDefinition testDefinition) {
var command =
testDefinition.executionHandle.getInvocationTokens(const []).toString();
return <String>[
_isTruthy(command) ? 'command: $command' : null,
_isTruthy(testDefinition.cpu) ? 'cpu: ${testDefinition.cpu}' : null,
_isTruthy(testDefinition.depsFile)
? 'depsFile: ${testDefinition.depsFile}'
: null,
_isTruthy(testDefinition.name) ? 'name: ${testDefinition.name}' : null,
_isTruthy(testDefinition.os) ? 'os: ${testDefinition.os}' : null,
_isTruthy(testDefinition.packageUrl)
? 'package_url: ${testDefinition.packageUrl}'
: null,
_isTruthy(testDefinition.label) ? 'label: ${testDefinition.label}' : null,
_isTruthy(testDefinition.path) ? 'path: ${testDefinition.path}' : null,
].where((_val) => _val != null).toList()
..sort();
}
bool _isTruthy(String val) => val != null && val != '';