Deduplicate compiler diagnostics.

This commit is contained in:
Eric Huss 2021-07-09 15:30:15 -07:00
parent cc80b40f1c
commit 493e8b7dd1
8 changed files with 281 additions and 77 deletions

View file

@ -129,7 +129,7 @@ pub fn prepare(cx: &mut Context<'_, '_>, unit: &Unit) -> CargoResult<Job> {
}
fn emit_build_output(
state: &JobState<'_>,
state: &JobState<'_, '_>,
output: &BuildOutput,
out_dir: &Path,
package_id: PackageId,

View file

@ -12,13 +12,13 @@ pub struct Job {
/// Each proc should send its description before starting.
/// It should send either once or close immediately.
pub struct Work {
inner: Box<dyn FnOnce(&JobState<'_>) -> CargoResult<()> + Send>,
inner: Box<dyn FnOnce(&JobState<'_, '_>) -> CargoResult<()> + Send>,
}
impl Work {
pub fn new<F>(f: F) -> Work
where
F: FnOnce(&JobState<'_>) -> CargoResult<()> + Send + 'static,
F: FnOnce(&JobState<'_, '_>) -> CargoResult<()> + Send + 'static,
{
Work { inner: Box::new(f) }
}
@ -27,7 +27,7 @@ impl Work {
Work::new(|_| Ok(()))
}
pub fn call(self, tx: &JobState<'_>) -> CargoResult<()> {
pub fn call(self, tx: &JobState<'_, '_>) -> CargoResult<()> {
(self.inner)(tx)
}
@ -58,7 +58,7 @@ impl Job {
/// Consumes this job by running it, returning the result of the
/// computation.
pub fn run(self, state: &JobState<'_>) -> CargoResult<()> {
pub fn run(self, state: &JobState<'_, '_>) -> CargoResult<()> {
self.work.call(state)
}

View file

@ -49,8 +49,9 @@
//! The current scheduling algorithm is relatively primitive and could likely be
//! improved.
use std::cell::Cell;
use std::cell::{Cell, RefCell};
use std::collections::{BTreeMap, BTreeSet, HashMap, HashSet};
use std::fmt::Write as _;
use std::io;
use std::marker;
use std::sync::Arc;
@ -125,6 +126,14 @@ struct DrainState<'cfg> {
queue: DependencyQueue<Unit, Artifact, Job>,
messages: Arc<Queue<Message>>,
/// Diagnostic deduplication support.
diag_dedupe: DiagDedupe<'cfg>,
/// Count of warnings, used to print a summary after the job succeeds.
///
/// First value is the total number of warnings, and the second value is
/// the number that were suppressed because they were duplicates of a
/// previous warning.
warning_count: HashMap<JobId, (usize, usize)>,
active: HashMap<JobId, Unit>,
compiled: HashSet<PackageId>,
documented: HashSet<PackageId>,
@ -174,7 +183,7 @@ impl std::fmt::Display for JobId {
///
/// The job may execute on either a dedicated thread or the main thread. If the job executes on the
/// main thread, the `output` field must be set to prevent a deadlock.
pub struct JobState<'a> {
pub struct JobState<'a, 'cfg> {
/// Channel back to the main thread to coordinate messages and such.
///
/// When the `output` field is `Some`, care must be taken to avoid calling `push_bounded` on
@ -191,7 +200,7 @@ pub struct JobState<'a> {
/// interleaved. In the future, it may be wrapped in a `Mutex` instead. In this case
/// interleaving is still prevented as the lock would be held for the whole printing of an
/// output message.
output: Option<&'a Config>,
output: Option<&'a DiagDedupe<'cfg>>,
/// The job id that this state is associated with, used when sending
/// messages back to the main thread.
@ -207,6 +216,36 @@ pub struct JobState<'a> {
_marker: marker::PhantomData<&'a ()>,
}
/// Handler for deduplicating diagnostics.
struct DiagDedupe<'cfg> {
seen: RefCell<HashSet<u64>>,
config: &'cfg Config,
}
impl<'cfg> DiagDedupe<'cfg> {
fn new(config: &'cfg Config) -> Self {
DiagDedupe {
seen: RefCell::new(HashSet::new()),
config,
}
}
/// Emits a diagnostic message.
///
/// Returns `true` if the message was emitted, or `false` if it was
/// suppressed for being a duplicate.
fn emit_diag(&self, diag: &str) -> CargoResult<bool> {
let h = util::hash_u64(diag);
if !self.seen.borrow_mut().insert(h) {
return Ok(false);
}
let mut shell = self.config.shell();
shell.print_ansi_stderr(diag.as_bytes())?;
shell.err().write_all(b"\n")?;
Ok(true)
}
}
/// Possible artifacts that can be produced by compilations, used as edge values
/// in the dependency graph.
///
@ -232,6 +271,15 @@ enum Message {
BuildPlanMsg(String, ProcessBuilder, Arc<Vec<OutputFile>>),
Stdout(String),
Stderr(String),
Diagnostic {
id: JobId,
level: String,
diag: String,
},
WarningCount {
id: JobId,
emitted: bool,
},
FixDiagnostic(diagnostic_server::Message),
Token(io::Result<Acquired>),
Finish(JobId, Artifact, CargoResult<()>),
@ -244,7 +292,7 @@ enum Message {
ReleaseToken(JobId),
}
impl<'a> JobState<'a> {
impl<'a, 'cfg> JobState<'a, 'cfg> {
pub fn running(&self, cmd: &ProcessBuilder) {
self.messages.push(Message::Run(self.id, cmd.to_string()));
}
@ -260,8 +308,8 @@ impl<'a> JobState<'a> {
}
pub fn stdout(&self, stdout: String) -> CargoResult<()> {
if let Some(config) = self.output {
writeln!(config.shell().out(), "{}", stdout)?;
if let Some(dedupe) = self.output {
writeln!(dedupe.config.shell().out(), "{}", stdout)?;
} else {
self.messages.push_bounded(Message::Stdout(stdout));
}
@ -269,8 +317,8 @@ impl<'a> JobState<'a> {
}
pub fn stderr(&self, stderr: String) -> CargoResult<()> {
if let Some(config) = self.output {
let mut shell = config.shell();
if let Some(dedupe) = self.output {
let mut shell = dedupe.config.shell();
shell.print_ansi_stderr(stderr.as_bytes())?;
shell.err().write_all(b"\n")?;
} else {
@ -279,6 +327,25 @@ impl<'a> JobState<'a> {
Ok(())
}
pub fn emit_diag(&self, level: String, diag: String) -> CargoResult<()> {
if let Some(dedupe) = self.output {
let emitted = dedupe.emit_diag(&diag)?;
if level == "warning" {
self.messages.push(Message::WarningCount {
id: self.id,
emitted,
});
}
} else {
self.messages.push_bounded(Message::Diagnostic {
id: self.id,
level,
diag,
});
}
Ok(())
}
/// A method used to signal to the coordinator thread that the rmeta file
/// for an rlib has been produced. This is only called for some rmeta
/// builds when required, and can be called at any time before a job ends.
@ -410,6 +477,8 @@ impl<'cfg> JobQueue<'cfg> {
// typical messages. If you change this, please update the test
// caching_large_output, too.
messages: Arc::new(Queue::new(100)),
diag_dedupe: DiagDedupe::new(cx.bcx.config),
warning_count: HashMap::new(),
active: HashMap::new(),
compiled: HashSet::new(),
documented: HashSet::new(),
@ -563,6 +632,15 @@ impl<'cfg> DrainState<'cfg> {
shell.print_ansi_stderr(err.as_bytes())?;
shell.err().write_all(b"\n")?;
}
Message::Diagnostic { id, level, diag } => {
let emitted = self.diag_dedupe.emit_diag(&diag)?;
if level == "warning" {
self.bump_warning_count(id, emitted);
}
}
Message::WarningCount { id, emitted } => {
self.bump_warning_count(id, emitted);
}
Message::FixDiagnostic(msg) => {
self.print.print(&msg)?;
}
@ -586,6 +664,7 @@ impl<'cfg> DrainState<'cfg> {
self.tokens.extend(rustc_tokens);
}
self.to_send_clients.remove(&id);
self.report_warning_count(cx.bcx.config, id);
self.active.remove(&id).unwrap()
}
// ... otherwise if it hasn't finished we leave it
@ -936,7 +1015,7 @@ impl<'cfg> DrainState<'cfg> {
let fresh = job.freshness();
let rmeta_required = cx.rmeta_required(unit);
let doit = move |state: JobState<'_>| {
let doit = move |state: JobState<'_, '_>| {
let mut sender = FinishOnDrop {
messages: &state.messages,
id,
@ -992,7 +1071,7 @@ impl<'cfg> DrainState<'cfg> {
doit(JobState {
id,
messages,
output: Some(cx.bcx.config),
output: Some(&self.diag_dedupe),
rmeta_required: Cell::new(rmeta_required),
_marker: marker::PhantomData,
});
@ -1044,6 +1123,44 @@ impl<'cfg> DrainState<'cfg> {
Ok(())
}
fn bump_warning_count(&mut self, id: JobId, emitted: bool) {
let cnts = self.warning_count.entry(id).or_default();
cnts.0 += 1;
if !emitted {
cnts.1 += 1;
}
}
/// Displays a final report of the warnings emitted by a particular job.
fn report_warning_count(&mut self, config: &Config, id: JobId) {
let count = match self.warning_count.remove(&id) {
Some(count) => count,
None => return,
};
let unit = &self.active[&id];
let mut message = format!("`{}` ({}", unit.pkg.name(), unit.target.description_named());
if unit.mode.is_rustc_test() && !(unit.target.is_test() || unit.target.is_bench()) {
message.push_str(" test");
} else if unit.mode.is_doc_test() {
message.push_str(" doctest");
} else if unit.mode.is_doc() {
message.push_str(" doc");
}
message.push_str(") generated ");
match count.0 {
1 => message.push_str("1 warning"),
n => drop(write!(message, "{} warnings", n)),
};
match count.1 {
0 => {}
1 => message.push_str(" (1 duplicate)"),
n => drop(write!(message, " ({} duplicates)", n)),
}
// Errors are ignored here because it is tricky to handle them
// correctly, and they aren't important.
drop(config.shell().warn(message));
}
fn finish(
&mut self,
id: JobId,

View file

@ -347,6 +347,8 @@ fn rustc(cx: &mut Context<'_, '_>, unit: &Unit, exec: &Arc<dyn Executor>) -> Car
};
format!("could not compile `{}`{}{}", name, errors, warnings)
})?;
// Exec should never return with success *and* generate an error.
debug_assert_eq!(output_options.errors_seen, 0);
}
if rustc_dep_info_loc.exists() {
@ -1199,7 +1201,7 @@ impl OutputOptions {
}
fn on_stdout_line(
state: &JobState<'_>,
state: &JobState<'_, '_>,
line: &str,
_package_id: PackageId,
_target: &Target,
@ -1209,7 +1211,7 @@ fn on_stdout_line(
}
fn on_stderr_line(
state: &JobState<'_>,
state: &JobState<'_, '_>,
line: &str,
package_id: PackageId,
manifest_path: &std::path::Path,
@ -1231,7 +1233,7 @@ fn on_stderr_line(
/// Returns true if the line should be cached.
fn on_stderr_line_inner(
state: &JobState<'_>,
state: &JobState<'_, '_>,
line: &str,
package_id: PackageId,
manifest_path: &std::path::Path,
@ -1296,27 +1298,30 @@ fn on_stderr_line_inner(
message: String,
level: String,
}
if let Ok(mut error) = serde_json::from_str::<CompilerMessage>(compiler_message.get()) {
if error.level == "error" && error.message.starts_with("aborting due to") {
if let Ok(mut msg) = serde_json::from_str::<CompilerMessage>(compiler_message.get()) {
if msg.message.starts_with("aborting due to")
|| msg.message.ends_with("warning emitted")
|| msg.message.ends_with("warnings emitted")
{
// Skip this line; we'll print our own summary at the end.
return Ok(true);
}
// state.stderr will add a newline
if error.rendered.ends_with('\n') {
error.rendered.pop();
if msg.rendered.ends_with('\n') {
msg.rendered.pop();
}
let rendered = if options.color {
error.rendered
msg.rendered
} else {
// Strip only fails if the the Writer fails, which is Cursor
// on a Vec, which should never fail.
strip_ansi_escapes::strip(&error.rendered)
strip_ansi_escapes::strip(&msg.rendered)
.map(|v| String::from_utf8(v).expect("utf8"))
.expect("strip should never fail")
};
if options.show_warnings {
count_diagnostic(&error.level, options);
state.stderr(rendered)?;
count_diagnostic(&msg.level, options);
state.emit_diag(msg.level, rendered)?;
}
return Ok(true);
}

View file

@ -925,7 +925,7 @@ impl Target {
TargetKind::ExampleLib(..) | TargetKind::ExampleBin => {
format!("example \"{}\"", self.name())
}
TargetKind::CustomBuild => "custom-build".to_string(),
TargetKind::CustomBuild => "build script".to_string(),
}
}
}

View file

@ -1,10 +1,8 @@
//! Tests for caching compiler diagnostics.
use super::messages::raw_rustc_output;
use cargo_test_support::tools;
use cargo_test_support::{
basic_manifest, is_coarse_mtime, process, project, registry::Package, sleep_ms,
};
use std::path::Path;
use cargo_test_support::{basic_manifest, is_coarse_mtime, project, registry::Package, sleep_ms};
fn as_str(bytes: &[u8]) -> &str {
std::str::from_utf8(bytes).expect("valid utf-8")
@ -23,33 +21,23 @@ fn simple() {
)
.build();
let agnostic_path = Path::new("src").join("lib.rs");
let agnostic_path_s = agnostic_path.to_str().unwrap();
// Capture what rustc actually emits. This is done to avoid relying on the
// exact message formatting in rustc.
let rustc_output = process("rustc")
.cwd(p.root())
.args(&["--crate-type=lib", agnostic_path_s])
.exec_with_output()
.expect("rustc to run");
assert!(rustc_output.stdout.is_empty());
assert!(rustc_output.status.success());
let rustc_output = raw_rustc_output(&p, "src/lib.rs", &[]);
// -q so the output is the same as rustc (no "Compiling" or "Finished").
let cargo_output1 = p
.cargo("check -q --color=never")
.exec_with_output()
.expect("cargo to run");
assert_eq!(as_str(&rustc_output.stderr), as_str(&cargo_output1.stderr));
assert_eq!(rustc_output, as_str(&cargo_output1.stderr));
assert!(cargo_output1.stdout.is_empty());
// Check that the cached version is exactly the same.
let cargo_output2 = p
.cargo("check -q")
.exec_with_output()
.expect("cargo to run");
assert_eq!(as_str(&rustc_output.stderr), as_str(&cargo_output2.stderr));
assert_eq!(rustc_output, as_str(&cargo_output2.stderr));
assert!(cargo_output2.stdout.is_empty());
}
@ -66,30 +54,20 @@ fn simple_short() {
)
.build();
let agnostic_path = Path::new("src").join("lib.rs");
let agnostic_path_s = agnostic_path.to_str().unwrap();
let rustc_output = process("rustc")
.cwd(p.root())
.args(&["--crate-type=lib", agnostic_path_s, "--error-format=short"])
.exec_with_output()
.expect("rustc to run");
assert!(rustc_output.stdout.is_empty());
assert!(rustc_output.status.success());
let rustc_output = raw_rustc_output(&p, "src/lib.rs", &["--error-format=short"]);
let cargo_output1 = p
.cargo("check -q --color=never --message-format=short")
.exec_with_output()
.expect("cargo to run");
assert_eq!(as_str(&rustc_output.stderr), as_str(&cargo_output1.stderr));
assert_eq!(rustc_output, as_str(&cargo_output1.stderr));
// assert!(cargo_output1.stdout.is_empty());
let cargo_output2 = p
.cargo("check -q --message-format=short")
.exec_with_output()
.expect("cargo to run");
println!("{}", String::from_utf8_lossy(&cargo_output2.stdout));
assert_eq!(as_str(&rustc_output.stderr), as_str(&cargo_output2.stderr));
assert_eq!(rustc_output, as_str(&cargo_output2.stderr));
assert!(cargo_output2.stdout.is_empty());
}
@ -112,25 +90,12 @@ fn color() {
assert_eq!(normalize(a), normalize(b));
};
let agnostic_path = Path::new("src").join("lib.rs");
let agnostic_path_s = agnostic_path.to_str().unwrap();
// Capture the original color output.
let rustc_output = process("rustc")
.cwd(p.root())
.args(&["--crate-type=lib", agnostic_path_s, "--color=always"])
.exec_with_output()
.expect("rustc to run");
assert!(rustc_output.status.success());
let rustc_color = as_str(&rustc_output.stderr);
let rustc_color = raw_rustc_output(&p, "src/lib.rs", &["--color=always"]);
assert!(rustc_color.contains("\x1b["));
// Capture the original non-color output.
let rustc_output = process("rustc")
.cwd(p.root())
.args(&["--crate-type=lib", agnostic_path_s])
.exec_with_output()
.expect("rustc to run");
let rustc_nocolor = as_str(&rustc_output.stderr);
let rustc_nocolor = raw_rustc_output(&p, "src/lib.rs", &[]);
assert!(!rustc_nocolor.contains("\x1b["));
// First pass, non-cached, with color, should be the same.
@ -138,21 +103,21 @@ fn color() {
.cargo("check -q --color=always")
.exec_with_output()
.expect("cargo to run");
compare(rustc_color, as_str(&cargo_output1.stderr));
compare(&rustc_color, as_str(&cargo_output1.stderr));
// Replay cached, with color.
let cargo_output2 = p
.cargo("check -q --color=always")
.exec_with_output()
.expect("cargo to run");
compare(rustc_color, as_str(&cargo_output2.stderr));
compare(&rustc_color, as_str(&cargo_output2.stderr));
// Replay cached, no color.
let cargo_output_nocolor = p
.cargo("check -q --color=never")
.exec_with_output()
.expect("cargo to run");
compare(rustc_nocolor, as_str(&cargo_output_nocolor.stderr));
compare(&rustc_nocolor, as_str(&cargo_output_nocolor.stderr));
}
#[cargo_test]
@ -441,7 +406,8 @@ fn caching_large_output() {
.with_stderr(&format!(
"\
[CHECKING] foo [..]
{}[FINISHED] dev [..]
{}warning: `foo` (lib) generated 250 warnings
[FINISHED] dev [..]
",
expected
))
@ -451,7 +417,8 @@ fn caching_large_output() {
.env("RUSTC", rustc.bin("rustc_alt"))
.with_stderr(&format!(
"\
{}[FINISHED] dev [..]
{}warning: `foo` (lib) generated 250 warnings
[FINISHED] dev [..]
",
expected
))

View file

@ -71,6 +71,7 @@ mod lto;
mod member_discovery;
mod member_errors;
mod message_format;
mod messages;
mod metabuild;
mod metadata;
mod minimal_versions;

114
tests/testsuite/messages.rs Normal file
View file

@ -0,0 +1,114 @@
//! General tests specifically about diagnostics and other messages.
//!
//! Tests for message caching can be found in `cache_messages`.
use cargo_test_support::{process, project, Project};
/// Captures the actual diagnostics displayed by rustc. This is done to avoid
/// relying on the exact message formatting in rustc.
pub fn raw_rustc_output(project: &Project, path: &str, extra: &[&str]) -> String {
let mut proc = process("rustc");
if cfg!(windows) {
// Sanitize in case the caller wants to do direct string comparison with Cargo's output.
proc.arg(path.replace('/', "\\"));
} else {
proc.arg(path);
}
let rustc_output = proc
.arg("--crate-type=lib")
.args(extra)
.cwd(project.root())
.exec_with_output()
.expect("rustc to run");
assert!(rustc_output.stdout.is_empty());
assert!(rustc_output.status.success());
// Do a little dance to remove rustc's "warnings emitted" message and the subsequent newline.
let stderr = std::str::from_utf8(&rustc_output.stderr).expect("utf8");
let mut lines = stderr.lines();
let mut result = String::new();
while let Some(line) = lines.next() {
if line.contains("warning emitted") || line.contains("warnings emitted") {
// Eat blank line.
match lines.next() {
None | Some("") => continue,
Some(s) => panic!("unexpected str {}", s),
}
}
result.push_str(line);
result.push('\n');
}
result
}
#[cargo_test]
fn deduplicate_messages_basic() {
let p = project()
.file(
"src/lib.rs",
r#"
pub fn foo() {
let x = 1;
}
"#,
)
.build();
let rustc_message = raw_rustc_output(&p, "src/lib.rs", &[]);
let expected_output = format!(
"{}\
warning: `foo` (lib) generated 1 warning
warning: `foo` (lib test) generated 1 warning (1 duplicate)
[FINISHED] [..]
",
rustc_message
);
p.cargo("test --no-run -j1")
.with_stderr(&format!("[COMPILING] foo [..]\n{}", expected_output))
.run();
// Run again, to check for caching behavior.
p.cargo("test --no-run -j1")
.with_stderr(expected_output)
.run();
}
#[cargo_test]
fn deduplicate_messages_mismatched_warnings() {
// One execution prints 1 warning, the other prints 2 where there is an overlap.
let p = project()
.file(
"src/lib.rs",
r#"
pub fn foo() {
let x = 1;
}
#[test]
fn t1() {
let MY_VALUE = 1;
assert_eq!(MY_VALUE, 1);
}
"#,
)
.build();
let lib_output = raw_rustc_output(&p, "src/lib.rs", &[]);
let mut lib_test_output = raw_rustc_output(&p, "src/lib.rs", &["--test"]);
// Remove the duplicate warning.
let start = lib_test_output.find(&lib_output).expect("same warning");
lib_test_output.replace_range(start..start + lib_output.len(), "");
let expected_output = format!(
"\
{}\
warning: `foo` (lib) generated 1 warning
{}\
warning: `foo` (lib test) generated 2 warnings (1 duplicate)
[FINISHED] [..]
",
lib_output, lib_test_output
);
p.cargo("test --no-run -j1")
.with_stderr(&format!("[COMPILING] foo v0.0.1 [..]\n{}", expected_output))
.run();
// Run again, to check for caching behavior.
p.cargo("test --no-run -j1")
.with_stderr(expected_output)
.run();
}