feat(test): print pending tests on sigint (#18246)

This commit is contained in:
Nayeem Rahman 2023-03-25 19:32:11 +00:00 committed by GitHub
parent fe88b53e50
commit 8a4865c379
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
16 changed files with 649 additions and 584 deletions

View file

@ -39,6 +39,7 @@ use deno_runtime::permissions::Permissions;
use deno_runtime::permissions::PermissionsContainer;
use deno_runtime::tokio_util::run_local;
use indexmap::IndexMap;
use indexmap::IndexSet;
use log::Level;
use rand::rngs::SmallRng;
use rand::seq::SliceRandom;
@ -47,6 +48,8 @@ use regex::Regex;
use serde::Deserialize;
use std::cell::RefCell;
use std::collections::BTreeMap;
use std::collections::BTreeSet;
use std::collections::HashMap;
use std::collections::HashSet;
use std::fmt::Write as _;
use std::io::Read;
@ -58,8 +61,10 @@ use std::sync::atomic::AtomicUsize;
use std::sync::Arc;
use std::time::Duration;
use std::time::Instant;
use tokio::signal;
use tokio::sync::mpsc::unbounded_channel;
use tokio::sync::mpsc::UnboundedSender;
use tokio::sync::mpsc::WeakUnboundedSender;
/// The test mode is used to determine how a specifier is to be tested.
#[derive(Debug, Clone, Eq, PartialEq)]
@ -154,13 +159,100 @@ pub enum TestOutput {
Bytes(Vec<u8>),
}
#[allow(clippy::derive_partial_eq_without_eq)]
#[derive(Debug, Clone, PartialEq, Deserialize)]
#[serde(rename_all = "camelCase")]
pub enum TestFailure {
JsError(Box<JsError>),
FailedSteps(usize),
IncompleteSteps,
LeakedOps(Vec<String>, bool), // Details, isOpCallTracingEnabled
LeakedResources(Vec<String>), // Details
// The rest are for steps only.
Incomplete,
OverlapsWithSanitizers(IndexSet<String>), // Long names of overlapped tests
HasSanitizersAndOverlaps(IndexSet<String>), // Long names of overlapped tests
}
impl ToString for TestFailure {
fn to_string(&self) -> String {
match self {
TestFailure::JsError(js_error) => format_test_error(js_error),
TestFailure::FailedSteps(1) => "1 test step failed.".to_string(),
TestFailure::FailedSteps(n) => format!("{} test steps failed.", n),
TestFailure::IncompleteSteps => "Completed while steps were still running. Ensure all steps are awaited with `await t.step(...)`.".to_string(),
TestFailure::Incomplete => "Didn't complete before parent. Await step with `await t.step(...)`.".to_string(),
TestFailure::LeakedOps(details, is_op_call_tracing_enabled) => {
let mut string = "Leaking async ops:".to_string();
for detail in details {
string.push_str(&format!("\n - {}", detail));
}
if !is_op_call_tracing_enabled {
string.push_str("\nTo get more details where ops were leaked, run again with --trace-ops flag.");
}
string
}
TestFailure::LeakedResources(details) => {
let mut string = "Leaking resources:".to_string();
for detail in details {
string.push_str(&format!("\n - {}", detail));
}
string
}
TestFailure::OverlapsWithSanitizers(long_names) => {
let mut string = "Started test step while another test step with sanitizers was running:".to_string();
for long_name in long_names {
string.push_str(&format!("\n * {}", long_name));
}
string
}
TestFailure::HasSanitizersAndOverlaps(long_names) => {
let mut string = "Started test step with sanitizers while another test step was running:".to_string();
for long_name in long_names {
string.push_str(&format!("\n * {}", long_name));
}
string
}
}
}
}
impl TestFailure {
fn format_label(&self) -> String {
match self {
TestFailure::Incomplete => colors::gray("INCOMPLETE").to_string(),
_ => colors::red("FAILED").to_string(),
}
}
fn format_inline_summary(&self) -> Option<String> {
match self {
TestFailure::FailedSteps(1) => Some("due to 1 failed step".to_string()),
TestFailure::FailedSteps(n) => Some(format!("due to {} failed steps", n)),
TestFailure::IncompleteSteps => {
Some("due to incomplete steps".to_string())
}
_ => None,
}
}
fn hide_in_summary(&self) -> bool {
// These failure variants are hidden in summaries because they are caused
// by child errors that will be summarized separately.
matches!(
self,
TestFailure::FailedSteps(_) | TestFailure::IncompleteSteps
)
}
}
#[allow(clippy::derive_partial_eq_without_eq)]
#[derive(Debug, Clone, PartialEq, Deserialize)]
#[serde(rename_all = "camelCase")]
pub enum TestResult {
Ok,
Ignored,
Failed(Box<JsError>),
Failed(TestFailure),
Cancelled,
}
@ -193,18 +285,7 @@ impl TestStepDescription {
pub enum TestStepResult {
Ok,
Ignored,
Failed(Option<Box<JsError>>),
Pending(Option<Box<JsError>>),
}
impl TestStepResult {
fn error(&self) -> Option<&JsError> {
match self {
TestStepResult::Failed(Some(error)) => Some(error),
TestStepResult::Pending(Some(error)) => Some(error),
_ => None,
}
}
Failed(TestFailure),
}
#[derive(Debug, Clone, Eq, PartialEq, Deserialize)]
@ -228,6 +309,7 @@ pub enum TestEvent {
StepRegister(TestStepDescription),
StepWait(usize),
StepResult(usize, TestStepResult, u64),
Sigint,
}
#[derive(Debug, Clone, Deserialize)]
@ -238,11 +320,10 @@ pub struct TestSummary {
pub ignored: usize,
pub passed_steps: usize,
pub failed_steps: usize,
pub pending_steps: usize,
pub ignored_steps: usize,
pub filtered_out: usize,
pub measured: usize,
pub failures: Vec<(TestDescription, Box<JsError>)>,
pub failures: Vec<(TestDescription, TestFailure)>,
pub uncaught_errors: Vec<(String, Box<JsError>)>,
}
@ -262,7 +343,6 @@ impl TestSummary {
ignored: 0,
passed_steps: 0,
failed_steps: 0,
pending_steps: 0,
ignored_steps: 0,
filtered_out: 0,
measured: 0,
@ -280,10 +360,12 @@ struct PrettyTestReporter {
parallel: bool,
echo_output: bool,
in_new_line: bool,
last_wait_id: Option<usize>,
scope_test_id: Option<usize>,
cwd: Url,
did_have_user_output: bool,
started_tests: bool,
child_results_buffer:
HashMap<usize, IndexMap<usize, (TestStepDescription, TestStepResult, u64)>>,
}
impl PrettyTestReporter {
@ -292,10 +374,11 @@ impl PrettyTestReporter {
parallel,
echo_output,
in_new_line: true,
last_wait_id: None,
scope_test_id: None,
cwd: Url::from_directory_path(std::env::current_dir().unwrap()).unwrap(),
did_have_user_output: false,
started_tests: false,
child_results_buffer: Default::default(),
}
}
@ -316,7 +399,7 @@ impl PrettyTestReporter {
self.in_new_line = false;
// flush for faster feedback when line buffered
std::io::stdout().flush().unwrap();
self.last_wait_id = Some(description.id);
self.scope_test_id = Some(description.id);
}
fn to_relative_path_or_remote_url(&self, path_or_url: &str) -> String {
@ -341,7 +424,7 @@ impl PrettyTestReporter {
self.in_new_line = false;
// flush for faster feedback when line buffered
std::io::stdout().flush().unwrap();
self.last_wait_id = Some(description.id);
self.scope_test_id = Some(description.id);
}
fn force_report_step_result(
@ -350,32 +433,53 @@ impl PrettyTestReporter {
result: &TestStepResult,
elapsed: u64,
) {
let status = match result {
TestStepResult::Ok => colors::green("ok").to_string(),
TestStepResult::Ignored => colors::yellow("ignored").to_string(),
TestStepResult::Pending(_) => colors::gray("pending").to_string(),
TestStepResult::Failed(_) => colors::red("FAILED").to_string(),
};
self.write_output_end();
if self.in_new_line || self.last_wait_id != Some(description.id) {
if self.in_new_line || self.scope_test_id != Some(description.id) {
self.force_report_step_wait(description);
}
println!(
" {} {}",
status,
colors::gray(format!("({})", display::human_elapsed(elapsed.into())))
);
if let Some(js_error) = result.error() {
let err_string = format_test_error(js_error);
let err_string = format!("{}: {}", colors::red_bold("error"), err_string);
for line in err_string.lines() {
println!("{}{}", " ".repeat(description.level + 1), line);
if !self.parallel {
let child_results = self
.child_results_buffer
.remove(&description.id)
.unwrap_or_default();
for (desc, result, elapsed) in child_results.values() {
self.force_report_step_result(desc, result, *elapsed);
}
if !child_results.is_empty() {
self.force_report_step_wait(description);
}
}
let status = match &result {
TestStepResult::Ok => colors::green("ok").to_string(),
TestStepResult::Ignored => colors::yellow("ignored").to_string(),
TestStepResult::Failed(failure) => failure.format_label(),
};
print!(" {}", status);
if let TestStepResult::Failed(failure) = result {
if let Some(inline_summary) = failure.format_inline_summary() {
print!(" ({})", inline_summary)
}
}
if !matches!(result, TestStepResult::Failed(TestFailure::Incomplete)) {
print!(
" {}",
colors::gray(format!("({})", display::human_elapsed(elapsed.into())))
);
}
println!();
self.in_new_line = true;
if self.parallel {
self.scope_test_id = None;
} else {
self.scope_test_id = Some(description.parent_id);
}
self
.child_results_buffer
.entry(description.parent_id)
.or_default()
.remove(&description.id);
}
fn write_output_end(&mut self) {
@ -442,23 +546,28 @@ impl PrettyTestReporter {
}
self.write_output_end();
if self.in_new_line || self.last_wait_id != Some(description.id) {
if self.in_new_line || self.scope_test_id != Some(description.id) {
self.force_report_wait(description);
}
let status = match result {
TestResult::Ok => colors::green("ok").to_string(),
TestResult::Ignored => colors::yellow("ignored").to_string(),
TestResult::Failed(_) => colors::red("FAILED").to_string(),
TestResult::Failed(failure) => failure.format_label(),
TestResult::Cancelled => colors::gray("cancelled").to_string(),
};
print!(" {}", status);
if let TestResult::Failed(failure) = result {
if let Some(inline_summary) = failure.format_inline_summary() {
print!(" ({})", inline_summary)
}
}
println!(
" {} {}",
status,
" {}",
colors::gray(format!("({})", display::human_elapsed(elapsed.into())))
);
self.in_new_line = true;
self.scope_test_id = None;
}
fn report_uncaught_error(&mut self, origin: &str, _error: &JsError) {
@ -477,14 +586,14 @@ impl PrettyTestReporter {
fn report_step_register(&mut self, _description: &TestStepDescription) {}
fn report_step_wait(&mut self, description: &TestStepDescription) {
if !self.parallel {
if !self.parallel && self.scope_test_id == Some(description.parent_id) {
self.force_report_step_wait(description);
}
}
fn report_step_result(
&mut self,
description: &TestStepDescription,
desc: &TestStepDescription,
result: &TestStepResult,
elapsed: u64,
tests: &IndexMap<usize, TestDescription>,
@ -492,35 +601,34 @@ impl PrettyTestReporter {
) {
if self.parallel {
self.write_output_end();
let root;
let mut ancestor_names = vec![];
let mut current_desc = description;
loop {
if let Some(step_desc) = test_steps.get(&current_desc.parent_id) {
ancestor_names.push(&step_desc.name);
current_desc = step_desc;
} else {
root = tests.get(&current_desc.parent_id).unwrap();
break;
}
}
ancestor_names.reverse();
print!(
"{}",
"{} {} ...",
colors::gray(format!(
"{} =>",
self.to_relative_path_or_remote_url(&description.origin)
))
self.to_relative_path_or_remote_url(&desc.origin)
)),
self.format_test_step_ancestry(desc, tests, test_steps)
);
print!(" {} ...", root.name);
for name in ancestor_names {
print!(" {name} ...");
}
print!(" {} ...", description.name);
self.in_new_line = false;
self.last_wait_id = Some(description.id);
self.scope_test_id = Some(desc.id);
self.force_report_step_result(desc, result, elapsed);
} else {
let sibling_results =
self.child_results_buffer.entry(desc.parent_id).or_default();
if self.scope_test_id == Some(desc.id)
|| self.scope_test_id == Some(desc.parent_id)
{
let sibling_results = std::mem::take(sibling_results);
self.force_report_step_result(desc, result, elapsed);
// Flush buffered sibling results.
for (desc, result, elapsed) in sibling_results.values() {
self.force_report_step_result(desc, result, *elapsed);
}
} else {
sibling_results
.insert(desc.id, (desc.clone(), result.clone(), elapsed));
}
}
self.force_report_step_result(description, result, elapsed);
}
fn report_summary(&mut self, summary: &TestSummary, elapsed: &Duration) {
@ -528,14 +636,14 @@ impl PrettyTestReporter {
#[allow(clippy::type_complexity)] // Type alias doesn't look better here
let mut failures_by_origin: BTreeMap<
String,
(Vec<(&TestDescription, &JsError)>, Option<&JsError>),
(Vec<(&TestDescription, &TestFailure)>, Option<&JsError>),
> = BTreeMap::default();
let mut failure_titles = vec![];
for (description, js_error) in &summary.failures {
for (description, failure) in &summary.failures {
let (failures, _) = failures_by_origin
.entry(description.origin.clone())
.or_default();
failures.push((description, js_error.as_ref()));
failures.push((description, failure));
}
for (origin, js_error) in &summary.uncaught_errors {
let (_, uncaught_error) =
@ -544,27 +652,14 @@ impl PrettyTestReporter {
}
println!("\n{}\n", colors::white_bold_on_red(" ERRORS "));
for (origin, (failures, uncaught_error)) in failures_by_origin {
for (description, js_error) in failures {
let failure_title = format!(
"{} {}",
&description.name,
colors::gray(format!(
"=> {}:{}:{}",
self.to_relative_path_or_remote_url(
&description.location.file_name
),
description.location.line_number,
description.location.column_number
))
);
println!("{}", &failure_title);
println!(
"{}: {}",
colors::red_bold("error"),
format_test_error(js_error)
);
println!();
failure_titles.push(failure_title);
for (description, failure) in failures {
if !failure.hide_in_summary() {
let failure_title = self.format_test_for_summary(description);
println!("{}", &failure_title);
println!("{}: {}", colors::red_bold("error"), failure.to_string());
println!();
failure_titles.push(failure_title);
}
}
if let Some(js_error) = uncaught_error {
let failure_title = format!(
@ -613,7 +708,7 @@ impl PrettyTestReporter {
summary.passed,
get_steps_text(summary.passed_steps),
summary.failed,
get_steps_text(summary.failed_steps + summary.pending_steps),
get_steps_text(summary.failed_steps),
)
.unwrap();
@ -647,6 +742,98 @@ impl PrettyTestReporter {
);
self.in_new_line = true;
}
fn report_sigint(
&mut self,
tests_pending: &HashSet<usize>,
tests: &IndexMap<usize, TestDescription>,
test_steps: &IndexMap<usize, TestStepDescription>,
) {
if tests_pending.is_empty() {
return;
}
let mut formatted_pending = BTreeSet::new();
for id in tests_pending {
if let Some(desc) = tests.get(id) {
formatted_pending.insert(self.format_test_for_summary(desc));
}
if let Some(desc) = test_steps.get(id) {
formatted_pending
.insert(self.format_test_step_for_summary(desc, tests, test_steps));
}
}
println!(
"\n{} The following tests were pending:\n",
colors::intense_blue("SIGINT")
);
for entry in formatted_pending {
println!("{}", entry);
}
println!();
self.in_new_line = true;
}
fn format_test_step_ancestry(
&self,
desc: &TestStepDescription,
tests: &IndexMap<usize, TestDescription>,
test_steps: &IndexMap<usize, TestStepDescription>,
) -> String {
let root;
let mut ancestor_names = vec![];
let mut current_desc = desc;
loop {
if let Some(step_desc) = test_steps.get(&current_desc.parent_id) {
ancestor_names.push(&step_desc.name);
current_desc = step_desc;
} else {
root = tests.get(&current_desc.parent_id).unwrap();
break;
}
}
ancestor_names.reverse();
let mut result = String::new();
result.push_str(&root.name);
result.push_str(" ... ");
for name in ancestor_names {
result.push_str(name);
result.push_str(" ... ");
}
result.push_str(&desc.name);
result
}
fn format_test_for_summary(&self, desc: &TestDescription) -> String {
format!(
"{} {}",
&desc.name,
colors::gray(format!(
"=> {}:{}:{}",
self.to_relative_path_or_remote_url(&desc.location.file_name),
desc.location.line_number,
desc.location.column_number
))
)
}
fn format_test_step_for_summary(
&self,
desc: &TestStepDescription,
tests: &IndexMap<usize, TestDescription>,
test_steps: &IndexMap<usize, TestStepDescription>,
) -> String {
let long_name = self.format_test_step_ancestry(desc, tests, test_steps);
format!(
"{} {}",
long_name,
colors::gray(format!(
"=> {}:{}:{}",
self.to_relative_path_or_remote_url(&desc.location.file_name),
desc.location.line_number,
desc.location.column_number
))
)
}
}
fn abbreviate_test_error(js_error: &JsError) -> JsError {
@ -1007,6 +1194,12 @@ async fn test_specifiers(
let sender = TestEventSender::new(sender);
let concurrent_jobs = options.concurrent_jobs;
let sender_ = sender.downgrade();
let sigint_handler_handle = tokio::task::spawn(async move {
signal::ctrl_c().await.unwrap();
sender_.upgrade().map(|s| s.send(TestEvent::Sigint).ok());
});
let join_handles =
specifiers_with_mode
.into_iter()
@ -1060,6 +1253,7 @@ async fn test_specifiers(
let earlier = Instant::now();
let mut tests = IndexMap::new();
let mut test_steps = IndexMap::new();
let mut tests_started = HashSet::new();
let mut tests_with_result = HashSet::new();
let mut summary = TestSummary::new();
let mut used_only = false;
@ -1083,7 +1277,9 @@ async fn test_specifiers(
}
TestEvent::Wait(id) => {
reporter.report_wait(tests.get(&id).unwrap());
if tests_started.insert(id) {
reporter.report_wait(tests.get(&id).unwrap());
}
}
TestEvent::Output(output) => {
@ -1100,9 +1296,11 @@ async fn test_specifiers(
TestResult::Ignored => {
summary.ignored += 1;
}
TestResult::Failed(error) => {
TestResult::Failed(failure) => {
summary.failed += 1;
summary.failures.push((description.clone(), error.clone()));
summary
.failures
.push((description.clone(), failure.clone()));
}
TestResult::Cancelled => {
unreachable!("should be handled in TestEvent::UncaughtError");
@ -1130,36 +1328,65 @@ async fn test_specifiers(
}
TestEvent::StepWait(id) => {
reporter.report_step_wait(test_steps.get(&id).unwrap());
if tests_started.insert(id) {
reporter.report_step_wait(test_steps.get(&id).unwrap());
}
}
TestEvent::StepResult(id, result, duration) => {
match &result {
TestStepResult::Ok => {
summary.passed_steps += 1;
if tests_with_result.insert(id) {
let description = test_steps.get(&id).unwrap();
match &result {
TestStepResult::Ok => {
summary.passed_steps += 1;
}
TestStepResult::Ignored => {
summary.ignored_steps += 1;
}
TestStepResult::Failed(failure) => {
summary.failed_steps += 1;
summary.failures.push((
TestDescription {
id: description.id,
name: reporter.format_test_step_ancestry(
description,
&tests,
&test_steps,
),
origin: description.origin.clone(),
location: description.location.clone(),
},
failure.clone(),
))
}
}
TestStepResult::Ignored => {
summary.ignored_steps += 1;
}
TestStepResult::Failed(_) => {
summary.failed_steps += 1;
}
TestStepResult::Pending(_) => {
summary.pending_steps += 1;
}
}
reporter.report_step_result(
test_steps.get(&id).unwrap(),
&result,
duration,
reporter.report_step_result(
description,
&result,
duration,
&tests,
&test_steps,
);
}
}
TestEvent::Sigint => {
reporter.report_sigint(
&tests_started
.difference(&tests_with_result)
.copied()
.collect(),
&tests,
&test_steps,
);
std::process::exit(130);
}
}
}
sigint_handler_handle.abort();
let elapsed = Instant::now().duration_since(earlier);
reporter.report_summary(&summary, &elapsed);
@ -1598,6 +1825,10 @@ impl TestEventSender {
Ok(())
}
fn downgrade(&self) -> WeakUnboundedSender<TestEvent> {
self.sender.downgrade()
}
fn flush_stdout_and_stderr(&mut self) -> Result<(), AnyError> {
self.stdout_writer.flush()?;
self.stderr_writer.flush()?;