Replace all uses of log::log_enabled with Debug printers

Author: oli-obk

src/librustc_interface/passes.rs

@@ -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};
@@ -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) {

src/librustc_metadata/creader.rs

@@ -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};
@@ -82,24 +82,38 @@ 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);
+
+fn crate_dump(cstore: &'a CStore) -> impl std::fmt::Debug + 'a {
+    CrateDump(cstore)
+}
+
+impl<'a> std::fmt::Debug for CrateDump<'a> {
+    fn fmt(&self, fmt: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        writeln!(fmt, "resolved crates:")?;
+        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 {
@@ -864,9 +878,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!("{:?}", crate_dump(&self.cstore));
 
         self.report_unused_deps(krate);
     }

src/librustc_metadata/lib.rs

@@ -9,6 +9,7 @@
 #![feature(proc_macro_internals)]
 #![feature(min_specialization)]
 #![feature(stmt_expr_attributes)]
+#![feature(try_blocks)]
 #![feature(never_type)]
 #![recursion_limit = "256"]
 

src/librustc_middle/ty/context.rs

@@ -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)]
@@ -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,
@@ -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,
@@ -1899,14 +1899,23 @@ macro_rules! sty_debug_print {
             }
         }
 
-        inner::go($ctxt)
+        inner::go($fmt, $ctxt)
     }}
 }
 
 impl<'tcx> TyCtxt<'tcx> {
-    pub fn print_debug_stats(self) {
+    pub fn debug_stats(self) -> impl std::fmt::Debug + 'tcx {
+        DebugStats(self)
+    }
+}
+
+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!(
-            self,
+            fmt,
+            self.0,
             Adt,
             Array,
             Slice,
@@ -1926,14 +1935,16 @@ impl<'tcx> TyCtxt<'tcx> {
             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());
+        )?;
+
+        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(())
     }
 }
 

src/librustc_mir/const_eval/machine.rs

@@ -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));
         Ok(true)
     }
 

src/librustc_mir/interpret/eval_context.rs

@@ -1,5 +1,4 @@
 use std::cell::Cell;
-use std::fmt::Write;
 use std::mem;
 
 use rustc_data_structures::fx::FxHashMap;
@@ -728,7 +727,7 @@ impl<'mir, 'tcx: 'mir, M: Machine<'mir, 'tcx>> InterpCx<'mir, 'tcx, M> {
             if let Some(return_place) = frame.return_place {
                 let op = self.access_local(&frame, mir::RETURN_PLACE, None)?;
                 self.copy_op_transmute(op, return_place)?;
-                self.dump_place(*return_place);
+                trace!("{:?}", self.dump_place(*return_place));
             } else {
                 throw_ub!(Unreachable);
             }
@@ -823,9 +822,7 @@ impl<'mir, 'tcx: 'mir, M: Machine<'mir, 'tcx>> InterpCx<'mir, 'tcx, M> {
             // All locals have a backing allocation, even if the allocation is empty
             // due to the local having ZST type.
             let ptr = ptr.assert_ptr();
-            if log_enabled!(::log::Level::Trace) {
-                self.memory.dump_alloc(ptr.alloc_id);
-            }
+            trace!("{:?}", self.memory.dump_alloc(ptr.alloc_id));
             self.memory.deallocate_local(ptr)?;
         };
         Ok(())
@@ -881,47 +878,77 @@ impl<'mir, 'tcx: 'mir, M: Machine<'mir, 'tcx>> InterpCx<'mir, 'tcx, M> {
         self.raw_const_to_mplace(val)
     }
 
-    pub fn dump_place(&self, place: Place<M::PointerTag>) {
-        // Debug output
-        if !log_enabled!(::log::Level::Trace) {
-            return;
+    #[must_use]
+    pub fn dump_place(&'a self, place: Place<M::PointerTag>) -> PlacePrinter<'a, 'mir, 'tcx, M> {
+        PlacePrinter { ecx: self, place }
+    }
+
+    #[must_use]
+    pub fn generate_stacktrace(&self) -> Vec<FrameInfo<'tcx>> {
+        let mut frames = Vec::new();
+        for frame in self.stack().iter().rev() {
+            let source_info = frame.current_source_info();
+            let lint_root = source_info.and_then(|source_info| {
+                match &frame.body.source_scopes[source_info.scope].local_data {
+                    mir::ClearCrossCrate::Set(data) => Some(data.lint_root),
+                    mir::ClearCrossCrate::Clear => None,
+                }
+            });
+            let span = source_info.map_or(DUMMY_SP, |source_info| source_info.span);
+
+            frames.push(FrameInfo { span, instance: frame.instance, lint_root });
         }
-        match place {
+        trace!("generate stacktrace: {:#?}", frames);
+        frames
+    }
+}
+
+#[doc(hidden)]
+/// Helper struct for the `dump_place` function.
+pub struct PlacePrinter<'a, 'mir, 'tcx, M: Machine<'mir, 'tcx>> {
+    ecx: &'a InterpCx<'mir, 'tcx, M>,
+    place: Place<M::PointerTag>,
+}
+
+impl<'a, 'mir, 'tcx: 'mir, M: Machine<'mir, 'tcx>> std::fmt::Debug
+    for PlacePrinter<'a, 'mir, 'tcx, M>
+{
+    fn fmt(&self, fmt: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        match self.place {
             Place::Local { frame, local } => {
                 let mut allocs = Vec::new();
-                let mut msg = format!("{:?}", local);
-                if frame != self.frame_idx() {
-                    write!(msg, " ({} frames up)", self.frame_idx() - frame).unwrap();
+                write!(fmt, "{:?}", local)?;
+                if frame != self.ecx.frame_idx() {
+                    write!(fmt, " ({} frames up)", self.ecx.frame_idx() - frame)?;
                 }
-                write!(msg, ":").unwrap();
+                write!(fmt, ":")?;
 
-                match self.stack()[frame].locals[local].value {
-                    LocalValue::Dead => write!(msg, " is dead").unwrap(),
-                    LocalValue::Uninitialized => write!(msg, " is uninitialized").unwrap(),
+                match self.ecx.stack()[frame].locals[local].value {
+                    LocalValue::Dead => write!(fmt, " is dead")?,
+                    LocalValue::Uninitialized => write!(fmt, " is uninitialized")?,
                     LocalValue::Live(Operand::Indirect(mplace)) => match mplace.ptr {
                         Scalar::Ptr(ptr) => {
                             write!(
-                                msg,
+                                fmt,
                                 " by align({}){} ref:",
                                 mplace.align.bytes(),
                                 match mplace.meta {
                                     MemPlaceMeta::Meta(meta) => format!(" meta({:?})", meta),
                                     MemPlaceMeta::Poison | MemPlaceMeta::None => String::new(),
                                 }
-                            )
-                            .unwrap();
+                            )?;
                             allocs.push(ptr.alloc_id);
                         }
-                        ptr => write!(msg, " by integral ref: {:?}", ptr).unwrap(),
+                        ptr => write!(fmt, " by integral ref: {:?}", ptr)?,
                     },
                     LocalValue::Live(Operand::Immediate(Immediate::Scalar(val))) => {
-                        write!(msg, " {:?}", val).unwrap();
+                        write!(fmt, " {:?}", val)?;
                         if let ScalarMaybeUninit::Scalar(Scalar::Ptr(ptr)) = val {
                             allocs.push(ptr.alloc_id);
                         }
                     }
                     LocalValue::Live(Operand::Immediate(Immediate::ScalarPair(val1, val2))) => {
-                        write!(msg, " ({:?}, {:?})", val1, val2).unwrap();
+                        write!(fmt, " ({:?}, {:?})", val1, val2)?;
                         if let ScalarMaybeUninit::Scalar(Scalar::Ptr(ptr)) = val1 {
                             allocs.push(ptr.alloc_id);
                         }
@@ -931,36 +958,19 @@ impl<'mir, 'tcx: 'mir, M: Machine<'mir, 'tcx>> InterpCx<'mir, 'tcx, M> {
                     }
                 }
 
-                trace!("{}", msg);
-                self.memory.dump_allocs(allocs);
+                write!(fmt, ": {:?}", self.ecx.memory.dump_allocs(allocs))
             }
             Place::Ptr(mplace) => match mplace.ptr {
-                Scalar::Ptr(ptr) => {
-                    trace!("by align({}) ref:", mplace.align.bytes());
-                    self.memory.dump_alloc(ptr.alloc_id);
-                }
-                ptr => trace!(" integral by ref: {:?}", ptr),
+                Scalar::Ptr(ptr) => write!(
+                    fmt,
+                    "by align({}) ref: {:?}",
+                    mplace.align.bytes(),
+                    self.ecx.memory.dump_alloc(ptr.alloc_id)
+                ),
+                ptr => write!(fmt, " integral by ref: {:?}", ptr),
             },
         }
     }
-
-    pub fn generate_stacktrace(&self) -> Vec<FrameInfo<'tcx>> {
-        let mut frames = Vec::new();
-        for frame in self.stack().iter().rev() {
-            let source_info = frame.current_source_info();
-            let lint_root = source_info.and_then(|source_info| {
-                match &frame.body.source_scopes[source_info.scope].local_data {
-                    mir::ClearCrossCrate::Set(data) => Some(data.lint_root),
-                    mir::ClearCrossCrate::Clear => None,
-                }
-            });
-            let span = source_info.map_or(DUMMY_SP, |source_info| source_info.span);
-
-            frames.push(FrameInfo { span, instance: frame.instance, lint_root });
-        }
-        trace!("generate stacktrace: {:#?}", frames);
-        frames
-    }
 }
 
 impl<'ctx, 'mir, 'tcx, Tag, Extra> HashStable<StableHashingContext<'ctx>>

src/librustc_mir/interpret/intrinsics.rs

@@ -430,7 +430,7 @@ impl<'mir, 'tcx: 'mir, M: Machine<'mir, 'tcx>> InterpCx<'mir, 'tcx, M> {
             _ => return Ok(false),
         }
 
-        self.dump_place(*dest);
+        trace!("{:?}", self.dump_place(*dest));
         self.go_to_block(ret);
         Ok(true)
     }