Skip to content

Replace all uses of log::log_enabled with Debug printers #74876

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
Jul 30, 2020
Merged

Replace all uses of log::log_enabled with Debug printers #74876

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
5e96bb4
Replace all uses of `log::log_enabled` with `Debug` printers
oli-obk Jul 28, 2020
7d67a1b
Replace write-to-vec hack by introducing a display renderer for alloc…
oli-obk Jul 28, 2020
b81d164
Address review comments
oli-obk Jul 29, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 3 additions & 9 deletions src/librustc_interface/passes.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@ use crate::interface::{Compiler, Result};
use crate::proc_macro_decls;
use crate::util;

use log::{info, log_enabled, warn};
use log::{info, warn};
use once_cell::sync::Lazy;
use rustc_ast::mut_visit::MutVisitor;
use rustc_ast::{self, ast, visit};
Expand Down Expand Up @@ -1015,21 +1015,15 @@ pub fn start_codegen<'tcx>(
tcx: TyCtxt<'tcx>,
outputs: &OutputFilenames,
) -> Box<dyn Any> {
if log_enabled!(::log::Level::Info) {
println!("Pre-codegen");
tcx.print_debug_stats();
}
info!("Pre-codegen\n{:?}", tcx.debug_stats());

let (metadata, need_metadata_module) = encode_and_write_metadata(tcx, outputs);

let codegen = tcx.sess.time("codegen_crate", move || {
codegen_backend.codegen_crate(tcx, metadata, need_metadata_module)
});

if log_enabled!(::log::Level::Info) {
println!("Post-codegen");
tcx.print_debug_stats();
}
info!("Post-codegen\n{:?}", tcx.debug_stats());

if tcx.sess.opts.output_types.contains_key(&OutputType::Mir) {
if let Err(e) = mir::transform::dump_mir::emit_mir(tcx, outputs) {
Expand Down
54 changes: 32 additions & 22 deletions src/librustc_metadata/creader.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@ use rustc_span::symbol::{sym, Symbol};
use rustc_span::{Span, DUMMY_SP};
use rustc_target::spec::{PanicStrategy, TargetTriple};

use log::{debug, info, log_enabled};
use log::{debug, info};
use proc_macro::bridge::client::ProcMacro;
use std::path::Path;
use std::{cmp, env, fs};
Expand Down Expand Up @@ -82,24 +82,36 @@ impl std::ops::Deref for CrateMetadataRef<'_> {
}
}

fn dump_crates(cstore: &CStore) {
info!("resolved crates:");
cstore.iter_crate_data(|cnum, data| {
info!(" name: {}", data.name());
info!(" cnum: {}", cnum);
info!(" hash: {}", data.hash());
info!(" reqd: {:?}", data.dep_kind());
let CrateSource { dylib, rlib, rmeta } = data.source();
if let Some(dylib) = dylib {
info!(" dylib: {}", dylib.0.display());
}
if let Some(rlib) = rlib {
info!(" rlib: {}", rlib.0.display());
}
if let Some(rmeta) = rmeta {
info!(" rmeta: {}", rmeta.0.display());
}
});
struct CrateDump<'a>(&'a CStore);

impl<'a> std::fmt::Debug for CrateDump<'a> {
fn fmt(&self, fmt: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
writeln!(fmt, "resolved crates:")?;
// `iter_crate_data` does not allow returning values. Thus we use a mutable variable here
// that aggregates the value (and any errors that could happen).
let mut res = Ok(());
self.0.iter_crate_data(|cnum, data| {
res = res.and(
try {
writeln!(fmt, " name: {}", data.name())?;
writeln!(fmt, " cnum: {}", cnum)?;
writeln!(fmt, " hash: {}", data.hash())?;
writeln!(fmt, " reqd: {:?}", data.dep_kind())?;
let CrateSource { dylib, rlib, rmeta } = data.source();
if let Some(dylib) = dylib {
writeln!(fmt, " dylib: {}", dylib.0.display())?;
}
if let Some(rlib) = rlib {
writeln!(fmt, " rlib: {}", rlib.0.display())?;
}
if let Some(rmeta) = rmeta {
writeln!(fmt, " rmeta: {}", rmeta.0.display())?;
}
},
);
});
res
}
}

impl CStore {
Expand Down Expand Up @@ -864,9 +876,7 @@ impl<'a> CrateLoader<'a> {
self.inject_allocator_crate(krate);
self.inject_panic_runtime(krate);

if log_enabled!(log::Level::Info) {
dump_crates(&self.cstore);
}
info!("{:?}", CrateDump(&self.cstore));

self.report_unused_deps(krate);
}
Expand Down
1 change: 1 addition & 0 deletions src/librustc_metadata/lib.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
#![feature(proc_macro_internals)]
#![feature(min_specialization)]
#![feature(stmt_expr_attributes)]
#![feature(try_blocks)]
#![feature(never_type)]
#![recursion_limit = "256"]

Expand Down
89 changes: 52 additions & 37 deletions src/librustc_middle/ty/context.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1831,7 +1831,7 @@ pub mod tls {
}

macro_rules! sty_debug_print {
($ctxt: expr, $($variant: ident),*) => {{
($fmt: expr, $ctxt: expr, $($variant: ident),*) => {{
// Curious inner module to allow variant names to be used as
// variable names.
#[allow(non_snake_case)]
Expand All @@ -1848,7 +1848,7 @@ macro_rules! sty_debug_print {
all_infer: usize,
}

pub fn go(tcx: TyCtxt<'_>) {
pub fn go(fmt: &mut std::fmt::Formatter<'_>, tcx: TyCtxt<'_>) -> std::fmt::Result {
let mut total = DebugStat {
total: 0,
lt_infer: 0,
Expand Down Expand Up @@ -1878,18 +1878,18 @@ macro_rules! sty_debug_print {
if ct { total.ct_infer += 1; variant.ct_infer += 1 }
if lt && ty && ct { total.all_infer += 1; variant.all_infer += 1 }
}
println!("Ty interner total ty lt ct all");
$(println!(" {:18}: {uses:6} {usespc:4.1}%, \
writeln!(fmt, "Ty interner total ty lt ct all")?;
$(writeln!(fmt, " {:18}: {uses:6} {usespc:4.1}%, \
{ty:4.1}% {lt:5.1}% {ct:4.1}% {all:4.1}%",
stringify!($variant),
uses = $variant.total,
usespc = $variant.total as f64 * 100.0 / total.total as f64,
ty = $variant.ty_infer as f64 * 100.0 / total.total as f64,
lt = $variant.lt_infer as f64 * 100.0 / total.total as f64,
ct = $variant.ct_infer as f64 * 100.0 / total.total as f64,
all = $variant.all_infer as f64 * 100.0 / total.total as f64);
all = $variant.all_infer as f64 * 100.0 / total.total as f64)?;
)*
println!(" total {uses:6} \
writeln!(fmt, " total {uses:6} \
{ty:4.1}% {lt:5.1}% {ct:4.1}% {all:4.1}%",
uses = total.total,
ty = total.ty_infer as f64 * 100.0 / total.total as f64,
Expand All @@ -1899,41 +1899,56 @@ macro_rules! sty_debug_print {
}
}

inner::go($ctxt)
inner::go($fmt, $ctxt)
}}
}

impl<'tcx> TyCtxt<'tcx> {
pub fn print_debug_stats(self) {
sty_debug_print!(
self,
Adt,
Array,
Slice,
RawPtr,
Ref,
FnDef,
FnPtr,
Placeholder,
Generator,
GeneratorWitness,
Dynamic,
Closure,
Tuple,
Bound,
Param,
Infer,
Projection,
Opaque,
Foreign
);

println!("InternalSubsts interner: #{}", self.interners.substs.len());
println!("Region interner: #{}", self.interners.region.len());
println!("Stability interner: #{}", self.stability_interner.len());
println!("Const Stability interner: #{}", self.const_stability_interner.len());
println!("Allocation interner: #{}", self.allocation_interner.len());
println!("Layout interner: #{}", self.layout_interner.len());
pub fn debug_stats(self) -> impl std::fmt::Debug + 'tcx {
struct DebugStats<'tcx>(TyCtxt<'tcx>);

impl std::fmt::Debug for DebugStats<'tcx> {
fn fmt(&self, fmt: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
sty_debug_print!(
fmt,
self.0,
Adt,
Array,
Slice,
RawPtr,
Ref,
FnDef,
FnPtr,
Placeholder,
Generator,
GeneratorWitness,
Dynamic,
Closure,
Tuple,
Bound,
Param,
Infer,
Projection,
Opaque,
Foreign
)?;

writeln!(fmt, "InternalSubsts interner: #{}", self.0.interners.substs.len())?;
writeln!(fmt, "Region interner: #{}", self.0.interners.region.len())?;
writeln!(fmt, "Stability interner: #{}", self.0.stability_interner.len())?;
writeln!(
fmt,
"Const Stability interner: #{}",
self.0.const_stability_interner.len()
)?;
writeln!(fmt, "Allocation interner: #{}", self.0.allocation_interner.len())?;
writeln!(fmt, "Layout interner: #{}", self.0.layout_interner.len())?;

Ok(())
}
}

DebugStats(self)
}
}

Expand Down
2 changes: 1 addition & 1 deletion src/librustc_mir/const_eval/machine.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,7 @@ impl<'mir, 'tcx> InterpCx<'mir, 'tcx, CompileTimeInterpreter<'mir, 'tcx>> {
self.copy_op(place.into(), dest)?;

self.return_to_block(ret.map(|r| r.1))?;
self.dump_place(*dest);
trace!("{:?}", self.dump_place(*dest));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Btw, why are these Debug impls? They are definitely made for human consumption, so sounds more like a case of Display to me TBH... (but changing it now is probably not worth it because Miri also needs adjusting).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

idk, the choice was fairly arbitrary

Ok(true)
}

Expand Down
Loading