From 17b904404d9fcaa29d94ac923c9aec7bfab1a2c6 Mon Sep 17 00:00:00 2001 From: Andrei Homescu Date: Fri, 5 Jul 2024 23:07:12 -0700 Subject: [PATCH] Use log crate for debugging output in c2rust-analyze Replace all eprintln! macros with uses of the log crate for more efficient and fine-grained debugging output. --- c2rust-analyze/src/analyze.rs | 85 +++++++++---------- c2rust-analyze/src/borrowck/def_use.rs | 13 +-- c2rust-analyze/src/borrowck/mod.rs | 29 ++++--- c2rust-analyze/src/borrowck/type_check.rs | 27 +++--- c2rust-analyze/src/context.rs | 34 ++++---- c2rust-analyze/src/dataflow/mod.rs | 11 +-- c2rust-analyze/src/dataflow/type_check.rs | 19 +++-- c2rust-analyze/src/main.rs | 2 +- c2rust-analyze/src/pointee_type/type_check.rs | 4 +- c2rust-analyze/src/rewrite/apply.rs | 3 +- c2rust-analyze/src/rewrite/expr/convert.rs | 6 +- .../src/rewrite/expr/hir_only_casts.rs | 9 +- c2rust-analyze/src/rewrite/expr/mir_op.rs | 8 +- c2rust-analyze/src/rewrite/expr/unlower.rs | 2 +- c2rust-analyze/src/rewrite/mod.rs | 13 +-- c2rust-analyze/src/rewrite/ty.rs | 10 +-- c2rust-analyze/src/trivial.rs | 5 +- c2rust-analyze/src/util.rs | 5 +- c2rust-analyze/tests/common/mod.rs | 3 +- 19 files changed, 149 insertions(+), 139 deletions(-) diff --git a/c2rust-analyze/src/analyze.rs b/c2rust-analyze/src/analyze.rs index dc22282551..f29e95eeae 100644 --- a/c2rust-analyze/src/analyze.rs +++ b/c2rust-analyze/src/analyze.rs @@ -25,9 +25,9 @@ use crate::type_desc::Ownership; use crate::util; use crate::util::Callee; use crate::util::TestAttr; -use ::log::warn; use c2rust_pdg::graph::Graphs; use c2rust_pdg::info::NodeInfo; +use log::{debug, info, warn}; use rustc_hir::def::DefKind; use rustc_hir::def_id::CrateNum; use rustc_hir::def_id::DefId; @@ -244,7 +244,7 @@ fn update_pointer_info<'tcx>(acx: &mut AnalysisCtxt<'_, 'tcx>, mir: &Body<'tcx>) _ => continue, }; - eprintln!( + debug!( "update_pointer_info: visit assignment: {:?}[{}]: {:?}", bb, i, stmt ); @@ -252,7 +252,7 @@ fn update_pointer_info<'tcx>(acx: &mut AnalysisCtxt<'_, 'tcx>, mir: &Body<'tcx>) if !pl.is_indirect() { // This is a write directly to `pl.local`. *write_count.entry(pl.local).or_insert(0) += 1; - eprintln!(" record write to LHS {:?}", pl); + debug!(" record write to LHS {:?}", pl); } let ref_pl = match *rv { @@ -264,7 +264,7 @@ fn update_pointer_info<'tcx>(acx: &mut AnalysisCtxt<'_, 'tcx>, mir: &Body<'tcx>) // For simplicity, we consider taking the address of a local to be a write. We // expect this not to happen for the sorts of temporary refs we're looking for. if !ref_pl.is_indirect() { - eprintln!(" record write to ref target {:?}", ref_pl); + debug!(" record write to ref target {:?}", ref_pl); *write_count.entry(ref_pl.local).or_insert(0) += 1; } @@ -385,7 +385,7 @@ fn mark_foreign_fixed<'tcx>( let fields = adt_def.all_fields(); for field in fields { let field_lty = gacx.field_ltys[&field.did]; - eprintln!( + debug!( "adding FIXED permission for {adt_did:?} field {:?}", field.did ); @@ -573,9 +573,9 @@ struct FuncInfo<'tcx> { } fn run(tcx: TyCtxt) { - eprintln!("all defs:"); + debug!("all defs:"); for ldid in tcx.hir_crate_items(()).definitions() { - eprintln!("{:?}", ldid); + debug!("{:?}", ldid); } // Load the list of fixed defs early, so any errors are reported immediately. @@ -591,9 +591,9 @@ fn run(tcx: TyCtxt) { // Follow a postorder traversal, so that callers are visited after their callees. This means // callee signatures will usually be up to date when we visit the call site. let all_fn_ldids = fn_body_owners_postorder(tcx); - eprintln!("callgraph traversal order:"); + debug!("callgraph traversal order:"); for &ldid in &all_fn_ldids { - eprintln!(" {:?}", ldid); + debug!(" {:?}", ldid); } populate_field_users(&mut gacx, &all_fn_ldids); @@ -629,9 +629,9 @@ fn run(tcx: TyCtxt) { // Collect all `static` items. let all_static_dids = all_static_items(tcx); - eprintln!("statics:"); + debug!("statics:"); for &did in &all_static_dids { - eprintln!(" {:?}", did); + debug!(" {:?}", did); } // Assign global `PointerId`s for types of `static` items. @@ -834,7 +834,7 @@ fn run(tcx: TyCtxt) { // Remap pointers based on equivalence classes, so all members of an equivalence class now use // the same `PointerId`. let (global_counter, global_equiv_map) = global_equiv.renumber(); - eprintln!("global_equiv_map = {global_equiv_map:?}"); + debug!("global_equiv_map = {global_equiv_map:?}"); pointee_type::remap_pointers_global( &mut global_pointee_types, &global_equiv_map, @@ -849,7 +849,7 @@ fn run(tcx: TyCtxt) { let info = func_info.get_mut(&ldid).unwrap(); let (local_counter, local_equiv_map) = info.local_equiv.renumber(&global_equiv_map); - eprintln!("local_equiv_map = {local_equiv_map:?}"); + debug!("local_equiv_map = {local_equiv_map:?}"); pointee_type::remap_pointers_local( &mut global_pointee_types, &mut info.local_pointee_types, @@ -1043,8 +1043,8 @@ fn run(tcx: TyCtxt) { &mut g_updates_forbidden, ); - eprintln!("=== ADT Metadata ==="); - eprintln!("{:?}", gacx.adt_metadata); + debug!("=== ADT Metadata ==="); + debug!("{:?}", gacx.adt_metadata); let mut loop_count = 0; loop { @@ -1110,14 +1110,14 @@ fn run(tcx: TyCtxt) { let added = new & !old; let removed = old & !new; let kept = old & new; - eprintln!( + debug!( "changed {:?}: added {:?}, removed {:?}, kept {:?}", ptr, added, removed, kept ); num_changed += 1; } } - eprintln!( + debug!( "iteration {}: {} global pointers changed", loop_count, num_changed ); @@ -1126,7 +1126,7 @@ fn run(tcx: TyCtxt) { break; } } - eprintln!("reached fixpoint in {} iterations", loop_count); + info!("reached fixpoint in {} iterations", loop_count); // Do final processing on each function. for &ldid in &all_fn_ldids { @@ -1404,7 +1404,7 @@ fn run2<'tcx>( assert!(i < 100); func_reports.clear(); all_rewrites.clear(); - eprintln!("\n--- start rewriting ---"); + info!("--- start rewriting ---"); // Update non-rewritten items first. This has two purposes. First, it clears the // `new_keys()` lists, which we check at the end of the loop to see whether we've reached a @@ -1536,7 +1536,7 @@ fn run2<'tcx>( let mut adt_reports = HashMap::::new(); for &def_id in gacx.adt_metadata.table.keys() { if gacx.foreign_mentioned_tys.contains(&def_id) { - eprintln!("Avoiding rewrite for foreign-mentioned type: {def_id:?}"); + debug!("Avoiding rewrite for foreign-mentioned type: {def_id:?}"); continue; } if fixed_defs.contains(&def_id) { @@ -1587,7 +1587,7 @@ fn run2<'tcx>( // Print labeling and rewrites for the current function. - eprintln!("\nfinal labeling for {:?}:", name); + debug!("\nfinal labeling for {:?}:", name); let lcx1 = crate::labeled_ty::LabeledTyCtxt::new(tcx); let lcx2 = crate::labeled_ty::LabeledTyCtxt::new(tcx); for (local, decl) in mir.local_decls.iter_enumerated() { @@ -1602,12 +1602,11 @@ fn run2<'tcx>( ); } - eprintln!("\ntype assignment for {:?}:", name); + debug!("\ntype assignment for {:?}:", name); rewrite::dump_rewritten_local_tys(&acx, &asn, pointee_types, &mir, describe_local); - eprintln!(); if let Some(report) = func_reports.remove(&ldid) { - eprintln!("{}", report); + debug!("{}", report); } info.acx_data.set(acx.into_data()); @@ -1673,7 +1672,7 @@ fn run2<'tcx>( } // Print results for `static` items. - eprintln!("\nfinal labeling for static items:"); + debug!("\nfinal labeling for static items:"); let lcx1 = crate::labeled_ty::LabeledTyCtxt::new(tcx); let lcx2 = crate::labeled_ty::LabeledTyCtxt::new(tcx); let mut static_dids = gacx.static_tys.keys().cloned().collect::>(); @@ -1691,10 +1690,10 @@ fn run2<'tcx>( &gasn.flags, ); } - eprintln!("\n{statics_report}"); + debug!("\n{statics_report}"); // Print results for ADTs and fields - eprintln!("\nfinal labeling for fields:"); + debug!("\nfinal labeling for fields:"); let mut field_dids = gacx.field_ltys.keys().cloned().collect::>(); field_dids.sort(); for did in field_dids { @@ -1704,7 +1703,7 @@ fn run2<'tcx>( if pid != PointerId::NONE { let ty_perms = gasn.perms[pid]; let ty_flags = gasn.flags[pid]; - eprintln!("{name:}: ({pid}) perms = {ty_perms:?}, flags = {ty_flags:?}"); + debug!("{name:}: ({pid}) perms = {ty_perms:?}, flags = {ty_flags:?}"); } // Emit annotations for fields @@ -1739,7 +1738,7 @@ fn run2<'tcx>( adt_dids.sort(); for did in adt_dids { if let Some(report) = adt_reports.remove(&did) { - eprintln!("\n{}", report); + debug!("\n{}", report); } } @@ -1778,17 +1777,17 @@ fn run2<'tcx>( // ---------------------------------- // Report errors that were caught previously - eprintln!("\nerror details:"); + debug!("\nerror details:"); for ldid in tcx.hir().body_owners() { if let Some(detail) = gacx.fns_failed.get(&ldid.to_def_id()) { if !detail.has_backtrace() { continue; } - eprintln!("\nerror in {:?}:\n{}", ldid, detail.to_string_full()); + debug!("\nerror in {:?}:{}", ldid, detail.to_string_full()); } } - eprintln!("\nerror summary:"); + debug!("\nerror summary:"); fn sorted_def_ids(it: impl IntoIterator) -> Vec { let mut v = it.into_iter().collect::>(); v.sort(); @@ -1802,27 +1801,27 @@ fn run2<'tcx>( Some(detail) => detail.to_string_short(), None => "(no panic)".into(), }; - eprintln!("analysis of {def_id:?} failed: {flags:?}, {detail_str}"); + debug!("analysis of {def_id:?} failed: {flags:?}, {detail_str}"); } for def_id in sorted_def_ids(gacx.dont_rewrite_statics.keys()) { let flags = gacx.dont_rewrite_statics.get(def_id); - eprintln!("analysis of {def_id:?} failed: {flags:?}"); + debug!("analysis of {def_id:?} failed: {flags:?}"); } for def_id in sorted_def_ids(gacx.dont_rewrite_fields.keys()) { let flags = gacx.dont_rewrite_fields.get(def_id); - eprintln!("analysis of {def_id:?} failed: {flags:?}"); + debug!("analysis of {def_id:?} failed: {flags:?}"); } - eprintln!( + info!( "\nsaw errors in {} / {} functions", gacx.fns_failed.len(), all_fn_ldids.len() ); if !known_perm_error_fns.is_empty() { - eprintln!( + info!( "saw permission errors in {} known fns", known_perm_error_fns.len() ); @@ -2184,7 +2183,7 @@ fn print_labeling_for_var<'tcx>( perms[lty.label] } }); - eprintln!("{}: addr_of = {:?}, type = {:?}", desc, addr_of1, ty1); + debug!("{}: addr_of = {:?}, type = {:?}", desc, addr_of1, ty1); let addr_of2 = flags[addr_of_ptr]; let ty2 = lcx2.relabel(lty, &mut |lty| { @@ -2194,14 +2193,14 @@ fn print_labeling_for_var<'tcx>( flags[lty.label] } }); - eprintln!( + debug!( "{}: addr_of flags = {:?}, type flags = {:?}", desc, addr_of2, ty2 ); let addr_of3 = addr_of_ptr; let ty3 = lty; - eprintln!("{}: addr_of = {:?}, type = {:?}", desc, addr_of3, ty3); + debug!("{}: addr_of = {:?}, type = {:?}", desc, addr_of3, ty3); } fn print_function_pointee_types<'tcx>( @@ -2210,9 +2209,9 @@ fn print_function_pointee_types<'tcx>( mir: &Body<'tcx>, pointee_types: PointerTable>, ) { - eprintln!("\npointee types for {}", name); + debug!("\npointee types for {}", name); for (local, decl) in mir.local_decls.iter_enumerated() { - eprintln!( + debug!( "{:?} ({}): addr_of = {:?}, type = {:?}", local, describe_local(acx.tcx(), decl), @@ -2235,7 +2234,7 @@ fn print_function_pointee_types<'tcx>( if tys.ltys.is_empty() && !tys.incomplete { continue; } - eprintln!( + debug!( " pointer {:?}: {:?}{}", ptr, tys.ltys, diff --git a/c2rust-analyze/src/borrowck/def_use.rs b/c2rust-analyze/src/borrowck/def_use.rs index e92ecceeff..395fd33f82 100644 --- a/c2rust-analyze/src/borrowck/def_use.rs +++ b/c2rust-analyze/src/borrowck/def_use.rs @@ -1,4 +1,5 @@ use crate::borrowck::atoms::{AllFacts, AtomMaps, Loan, Path, SubPoint}; +use log::debug; use rustc_middle::mir::visit::{ MutatingUseContext, NonMutatingUseContext, NonUseContext, PlaceContext, Visitor, }; @@ -96,7 +97,7 @@ struct DefUseVisitor<'tcx, 'a> { impl<'tcx> Visitor<'tcx> for DefUseVisitor<'tcx, '_> { fn visit_place(&mut self, place: &Place<'tcx>, context: PlaceContext, location: Location) { self.super_place(place, context, location); - eprintln!( + debug!( "visit place {:?} with context {:?} = {:?} at {:?}", place, context, @@ -132,7 +133,7 @@ impl<'tcx> Visitor<'tcx> for DefUseVisitor<'tcx, '_> { } fn visit_local(&mut self, local: Local, context: PlaceContext, location: Location) { - eprintln!( + debug!( "visit local {:?} with context {:?} = {:?} at {:?}", local, context, @@ -157,7 +158,7 @@ impl<'tcx> Visitor<'tcx> for DefUseVisitor<'tcx, '_> { fn visit_statement(&mut self, stmt: &Statement<'tcx>, location: Location) { self.super_statement(stmt, location); - eprintln!("visit stmt {:?} at {:?}", stmt, location); + debug!("visit stmt {:?} at {:?}", stmt, location); if let StatementKind::StorageDead(local) = stmt.kind { // Observed: `StorageDead` emits `path_moved_at_base` at the `Mid` point. @@ -194,7 +195,7 @@ impl<'tcx> LoanInvalidatedAtVisitor<'tcx, '_> { context: PlaceContext, location: Location, ) { - eprintln!( + debug!( "access loan {:?} (kind {:?}) at location {:?} (context {:?} = {:?})", loan, borrow_kind, @@ -223,7 +224,7 @@ impl<'tcx> LoanInvalidatedAtVisitor<'tcx, '_> { impl<'tcx> Visitor<'tcx> for LoanInvalidatedAtVisitor<'tcx, '_> { fn visit_place(&mut self, place: &Place<'tcx>, context: PlaceContext, location: Location) { //self.super_place(place, context, location); - eprintln!( + debug!( "loan_invalidated_at: visit place {:?} with context {:?} = {:?} at {:?}", place, context, @@ -260,7 +261,7 @@ impl<'tcx> Visitor<'tcx> for LoanInvalidatedAtVisitor<'tcx, '_> { } fn visit_local(&mut self, local: Local, context: PlaceContext, location: Location) { - eprintln!( + debug!( "loan_invalidated_at: visit local {:?} with context {:?} = {:?} at {:?}", local, context, diff --git a/c2rust-analyze/src/borrowck/mod.rs b/c2rust-analyze/src/borrowck/mod.rs index a1f2eb72d6..3d38a6b728 100644 --- a/c2rust-analyze/src/borrowck/mod.rs +++ b/c2rust-analyze/src/borrowck/mod.rs @@ -7,6 +7,7 @@ use crate::labeled_ty::{LabeledTy, LabeledTyCtxt}; use crate::pointer_id::{PointerTable, PointerTableMut}; use crate::util::{describe_rvalue, RvalueDesc}; use indexmap::{IndexMap, IndexSet}; +use log::{debug, info, warn}; use rustc_hir::def_id::DefId; use rustc_middle::mir::{Body, LocalKind, Place, StatementKind, START_BLOCK}; use rustc_middle::ty::{ @@ -128,9 +129,9 @@ pub fn borrowck_mir<'tcx>( ) { let mut i = 0; loop { - eprintln!("run polonius"); + info!("run polonius"); let (facts, maps, output) = run_polonius(acx, hypothesis, name, mir, &field_ltys); - eprintln!( + info!( "polonius: iteration {}: {} errors, {} move_errors", i, output.errors.len(), @@ -173,7 +174,7 @@ pub fn borrowck_mir<'tcx>( }, _ => panic!("loan {:?} was issued by non-assign stmt {:?}?", loan, stmt), }; - eprintln!("want to drop UNIQUE from pointer {:?}", ptr); + debug!("want to drop UNIQUE from pointer {:?}", ptr); if hypothesis[ptr].contains(PermissionSet::UNIQUE) { hypothesis[ptr].remove(PermissionSet::UNIQUE); @@ -182,12 +183,12 @@ pub fn borrowck_mir<'tcx>( } } - eprintln!("propagate"); + info!("propagate"); changed |= dataflow.propagate(hypothesis, updates_forbidden); - eprintln!("done propagating"); + info!("done propagating"); if !changed { - eprintln!( + warn!( "{} unresolved borrowck errors in function {:?} (after {} iterations)", output.errors.len(), name, @@ -257,10 +258,10 @@ fn run_polonius<'tcx>( // Populate `cfg_edge` for (bb, bb_data) in mir.basic_blocks().iter_enumerated() { - eprintln!("{:?}:", bb); + debug!("{:?}:", bb); for idx in 0..bb_data.statements.len() { - eprintln!(" {}: {:?}", idx, bb_data.statements[idx]); + debug!(" {}: {:?}", idx, bb_data.statements[idx]); let start = maps.point(bb, idx, SubPoint::Start); let mid = maps.point(bb, idx, SubPoint::Mid); let next_start = maps.point(bb, idx + 1, SubPoint::Start); @@ -269,7 +270,7 @@ fn run_polonius<'tcx>( } let term_idx = bb_data.statements.len(); - eprintln!(" {}: {:?}", term_idx, bb_data.terminator()); + debug!(" {}: {:?}", term_idx, bb_data.terminator()); let term_start = maps.point(bb, term_idx, SubPoint::Start); let term_mid = maps.point(bb, term_idx, SubPoint::Mid); facts.cfg_edge.push((term_start, term_mid)); @@ -383,7 +384,7 @@ fn run_polonius<'tcx>( dump::dump_facts_to_dir(&facts, &maps, format!("inspect/{}", name)).unwrap(); - eprintln!("running polonius analysis on {name}"); + info!("running polonius analysis on {name}"); let facts_hash = bytes_to_hex_string(&hash_facts(&facts)); let output = match try_load_cached_output(&facts_hash) { Some(output) => output, @@ -409,7 +410,7 @@ fn try_load_cached_output(facts_hash: &str) -> Option { let raw = match bincode::deserialize_from(f) { Ok(x) => x, Err(e) => { - log::warn!("failed to parse polonius cache file {path:?}: {e}"); + warn!("failed to parse polonius cache file {path:?}: {e}"); return None; } }; @@ -441,7 +442,7 @@ fn try_load_cached_output(facts_hash: &str) -> Option { ), ) = raw; - eprintln!("loaded cached facts from {}", path); + info!("loaded cached facts from {}", path); Some(Output { errors, @@ -598,7 +599,7 @@ fn construct_adt_origins<'tcx>( ty: &Ty, amaps: &mut AtomMaps, ) -> &'tcx [(OriginParam, Origin)] { - eprintln!("ty: {ty:?}"); + debug!("ty: {ty:?}"); let adt_def = ty.ty_adt_def().unwrap(); // create a concrete origin for each actual or hypothetical @@ -610,7 +611,7 @@ fn construct_adt_origins<'tcx>( .map_or(&default, |adt| &adt.lifetime_params) .iter() .map(|origin| (*origin, amaps.origin())) - .inspect(|pairing| eprintln!("pairing lifetime parameter with origin: {pairing:?}")); + .inspect(|pairing| log::debug!("pairing lifetime parameter with origin: {pairing:?}")); ltcx.arena().alloc_from_iter(origins) } diff --git a/c2rust-analyze/src/borrowck/type_check.rs b/c2rust-analyze/src/borrowck/type_check.rs index c0f323b9fc..001910a9e1 100644 --- a/c2rust-analyze/src/borrowck/type_check.rs +++ b/c2rust-analyze/src/borrowck/type_check.rs @@ -7,6 +7,7 @@ use crate::pointer_id::PointerTableMut; use crate::util::{self, ty_callee, Callee}; use assert_matches::assert_matches; use indexmap::IndexMap; +use log::debug; use rustc_hir::def_id::DefId; use rustc_index::vec::IndexVec; use rustc_middle::mir::{ @@ -67,7 +68,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { OriginParam::try_from(&oa).unwrap() }) .and_then(|o| { - eprintln!( + debug!( "finding {o:?} in {base_adt_def:?} {base_origin_param_map:?}" ); base_origin_param_map.get(&o) @@ -108,7 +109,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { `'0`) and `Foo` lifetime parameter `'a`. This mapping is created below. */ let mut field_origin_param_map = vec![]; - eprintln!("{:?}", fadt_def.did()); + debug!("{:?}", fadt_def.did()); let field_adt_metadata = if let Some(field_adt_metadata) = self.acx.gacx.adt_metadata.table.get(&fadt_def.did()) { field_adt_metadata } else { @@ -128,7 +129,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { field_lifetime_param.and_then(|field_lifetime_param| { base_origin_param_map.get_key_value(&field_lifetime_param) }).map(|(base_lifetime_param, og)| { - eprintln!( + debug!( "mapping {base_adt_def:?} lifetime parameter {base_lifetime_param:?} to \ {base_adt_def:?}.{:} struct definition lifetime parameter {field_struct_lifetime_param:?}, \ corresponding to its lifetime parameter {field_lifetime_param:?} within {base_adt_def:?}", @@ -161,7 +162,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { for proj in pl.projection { lty = util::lty_project(lty, &proj, &mut |lty, adt, f| self.field_lty(lty, adt, f)); } - eprintln!("final label for {pl:?}: {:?}", lty); + debug!("final label for {pl:?}: {:?}", lty); lty } @@ -189,19 +190,19 @@ impl<'tcx> TypeChecker<'tcx, '_> { }; if let Some(origin) = l.label.origin { // constrain this origin to be 'static - eprintln!("constraining origin {origin:?} to 'static lifetime"); + debug!("constraining origin {origin:?} to 'static lifetime"); add_subset_base(static_origin, origin); add_subset_base(origin, static_origin) } for (op, origin) in l.label.origin_params { // constrain this origin to be 'static - eprintln!("constraining origin {op:?} ({origin:?}) to 'static lifetime"); + debug!("constraining origin {op:?} ({origin:?}) to 'static lifetime"); add_subset_base(static_origin, *origin); add_subset_base(*origin, static_origin); } } - eprintln!("NEW STATIC LTY: {:?}", c.ty().kind()); + debug!("NEW STATIC LTY: {:?}", c.ty().kind()); let pointer_id = self.acx.type_of(op).label; let perm = self.hypothesis[pointer_id]; let args = self.ltcx.mk_slice(&[lty]); @@ -241,7 +242,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { .push((path, loan, borrow_kind)); let point = self.current_point(SubPoint::Mid); self.facts.loan_issued_at.push((origin, loan, point)); - eprintln!("issued loan {:?} = {:?} ({:?})", loan, pl, borrow_kind); + debug!("issued loan {:?} = {:?} ({:?})", loan, pl, borrow_kind); origin } @@ -449,11 +450,11 @@ impl<'tcx> TypeChecker<'tcx, '_> { for (fid, op) in ops.iter().enumerate() { let field_lty = self.field_lty(expect_ty, adt_def, Field::from(fid)); let op_lty = self.visit_operand(op); - eprintln!("pseudo-assigning fields {field_lty:?} = {op_lty:?}"); + debug!("pseudo-assigning fields {field_lty:?} = {op_lty:?}"); self.do_assign(field_lty, op_lty); } - eprintln!("Aggregate literal label: {expect_ty:?}"); + debug!("Aggregate literal label: {expect_ty:?}"); expect_ty } _ => panic!("unsupported rvalue AggregateKind {:?}", kind), @@ -480,7 +481,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { } fn do_assign(&mut self, pl_lty: LTy<'tcx>, rv_lty: LTy<'tcx>) { - eprintln!("assign {:?} = {:?}", pl_lty, rv_lty); + debug!("assign {:?} = {:?}", pl_lty, rv_lty); match (pl_lty.ty.kind(), rv_lty.ty.kind()) { // exempt pointer casts such as `PointerCast::MutToConstPointer` @@ -531,7 +532,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { } pub fn visit_terminator(&mut self, term: &Terminator<'tcx>) { - eprintln!("borrowck: visit_terminator({:?})", term.kind); + debug!("borrowck: visit_terminator({:?})", term.kind); let _g = panic_detail::set_current_span(term.source_info.span); // TODO(spernsteiner): other `TerminatorKind`s will be handled in the future #[allow(clippy::single_match)] @@ -545,7 +546,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { } => { let func_ty = func.ty(self.local_decls, *self.ltcx); let callee = ty_callee(*self.ltcx, func_ty); - eprintln!("callee = {callee:?}"); + debug!("callee = {callee:?}"); match callee { Callee::Trivial => {} Callee::UnknownDef { .. } => { diff --git a/c2rust-analyze/src/context.rs b/c2rust-analyze/src/context.rs index 3423fbf4c3..2ba3b875e4 100644 --- a/c2rust-analyze/src/context.rs +++ b/c2rust-analyze/src/context.rs @@ -642,10 +642,10 @@ fn construct_adt_metadata<'tcx>( .table .insert(adt_def.did(), AdtMetadata::default()); let metadata = adt_metadata_table.table.get_mut(&adt_def.did()).unwrap(); - eprintln!("gathering known lifetimes for {adt_def:?}"); + debug!("gathering known lifetimes for {adt_def:?}"); for sub in substs.iter() { if let GenericArgKind::Lifetime(r) = sub.unpack() { - eprintln!("\tfound lifetime {r:?} in {adt_def:?}"); + debug!("\nfound lifetime {r:?} in {adt_def:?}"); assert_matches!(r.kind(), ReEarlyBound(eb) => { metadata.lifetime_params.insert(OriginParam::Actual(eb)); }); @@ -677,25 +677,25 @@ fn construct_adt_metadata<'tcx>( loop_count += 1; assert!(loop_count < 1000); - eprintln!("---- running fixed point struct field analysis iteration #{loop_count:?} ----"); + info!("---- running fixed point struct field analysis iteration #{loop_count:?} ----"); let old_adt_metadata = adt_metadata_table.table.clone(); let mut next_hypo_origin_id = 0; // for each struct, gather lifetime information (actual and hypothetical) for struct_did in &adt_metadata_table.struct_dids { let adt_def = tcx.adt_def(struct_did); - eprintln!("gathering lifetimes and lifetime parameters for {adt_def:?}"); + debug!("gathering lifetimes and lifetime parameters for {adt_def:?}"); for field in adt_def.all_fields() { let field_lty = field_ltys .get(&field.did) .unwrap_or_else(|| panic!("missing field_ltys entry for {:?}", field.did)); - eprintln!("\t{adt_def:?}.{:}", field.name); + debug!("\t{adt_def:?}.{:}", field.name); let field_origin_args = ltcx.relabel(field_lty, &mut |lty| { let mut field_origin_args = IndexSet::new(); match lty.kind() { TyKind::RawPtr(ty) => { if needs_region(lty) { - eprintln!( + debug!( "\t\tfound pointer that requires hypothetical lifetime: *{:}", if let Mutability::Mut = ty.mutbl { "mut" @@ -710,7 +710,7 @@ fn construct_adt_metadata<'tcx>( let origin_arg = OriginArg::Hypothetical(next_hypo_origin_id); let origin_param = OriginParam::Hypothetical(next_hypo_origin_id); - eprintln!( + debug!( "\t\t\tinserting origin {origin_param:?} into {adt_def:?}" ); @@ -721,7 +721,7 @@ fn construct_adt_metadata<'tcx>( } } TyKind::Ref(reg, _ty, _mutability) => { - eprintln!("\t\tfound reference field lifetime: {reg:}"); + debug!("\t\tfound reference field lifetime: {reg:}"); assert_matches!(reg.kind(), ReEarlyBound(..) | ReStatic); let origin_arg = OriginArg::Actual(*reg); adt_metadata_table @@ -729,7 +729,7 @@ fn construct_adt_metadata<'tcx>( .entry(*struct_did) .and_modify(|adt| { if let ReEarlyBound(eb) = reg.kind() { - eprintln!("\t\t\tinserting origin {eb:?} into {adt_def:?}"); + debug!("\t\tinserting origin {eb:?} into {adt_def:?}"); adt.lifetime_params.insert(OriginParam::Actual(eb)); } @@ -737,11 +737,11 @@ fn construct_adt_metadata<'tcx>( }); } TyKind::Adt(adt_field, substs) => { - eprintln!("\t\tfound ADT field base type: {adt_field:?}"); + debug!("\t\tfound ADT field base type: {adt_field:?}"); for sub in substs.iter() { if let GenericArgKind::Lifetime(r) = sub.unpack() { - eprintln!("\tfound field lifetime {r:?} in {adt_def:?}.{adt_field:?}"); - eprintln!("\t\t\tinserting {adt_field:?} lifetime param {r:?} into {adt_def:?}.{:} lifetime parameters", field.name); + debug!("\tfound field lifetime {r:?} in {adt_def:?}.{adt_field:?}"); + debug!("\t\tinserting {adt_field:?} lifetime param {r:?} into {adt_def:?}.{:} lifetime parameters", field.name); assert_matches!(r.kind(), ReEarlyBound(..) | ReStatic); field_origin_args.insert(OriginArg::Actual(r)); } @@ -752,7 +752,7 @@ fn construct_adt_metadata<'tcx>( for adt_field_lifetime_param in adt_field_metadata.lifetime_params.iter() { adt_metadata_table.table.entry(*struct_did).and_modify(|adt| { if let OriginParam::Hypothetical(h) = adt_field_lifetime_param { - eprintln!("\t\t\tbubbling {adt_field:?} origin {adt_field_lifetime_param:?} up into {adt_def:?} origins"); + debug!("\t\tbubbling {adt_field:?} origin {adt_field_lifetime_param:?} up into {adt_def:?} origins"); field_origin_args.insert(OriginArg::Hypothetical(*h)); adt.lifetime_params.insert(*adt_field_lifetime_param); } @@ -783,11 +783,11 @@ fn construct_adt_metadata<'tcx>( }); } - eprintln!(); + debug!(""); } if adt_metadata_table.table == old_adt_metadata { - eprintln!("reached a fixed point in struct lifetime reconciliation\n"); + info!("reached a fixed point in struct lifetime reconciliation\n"); break; } } @@ -1129,7 +1129,7 @@ impl<'a, 'tcx> AnalysisCtxt<'a, 'tcx> { let (pointee_lty, proj, ptr) = match desc { RvalueDesc::Project { base, proj } => { let base_lty = self.type_of(base); - eprintln!( + debug!( "rvalue = {:?}, desc = {:?}, base_lty = {:?}", rv, desc, base_lty ); @@ -1203,7 +1203,7 @@ impl<'a, 'tcx> AnalysisCtxt<'a, 'tcx> { let projection_lty = |_lty: LTy, adt_def: AdtDef, field: Field| { let field_def = &adt_def.non_enum_variant().fields[field.index()]; let field_def_name = field_def.name; - eprintln!("projecting into {adt_def:?}.{field_def_name:}"); + debug!("projecting into {adt_def:?}.{field_def_name:}"); let field_lty: LTy = self.gacx.field_ltys.get(&field_def.did).unwrap_or_else(|| { panic!("Could not find {adt_def:?}.{field_def_name:?} in field type map") }); diff --git a/c2rust-analyze/src/dataflow/mod.rs b/c2rust-analyze/src/dataflow/mod.rs index fa7224a91b..bd8a733904 100644 --- a/c2rust-analyze/src/dataflow/mod.rs +++ b/c2rust-analyze/src/dataflow/mod.rs @@ -4,6 +4,7 @@ use crate::context::{AnalysisCtxt, Assignment, FlagSet, PermissionSet, PointerId use crate::pointee_type::PointeeTypes; use crate::pointer_id::{OwnedPointerTable, PointerTable, PointerTableMut}; use crate::recent_writes::RecentWrites; +use log::debug; use rustc_middle::mir::Body; mod type_check; @@ -65,14 +66,14 @@ impl DataflowConstraints { hypothesis: &mut PointerTableMut, updates_forbidden: &PointerTable, ) -> bool { - eprintln!("=== propagating ==="); - eprintln!("constraints:"); + debug!("=== propagating ==="); + debug!("constraints:"); for c in &self.constraints { - eprintln!(" {:?}", c); + debug!(" {:?}", c); } - eprintln!("hypothesis:"); + debug!("hypothesis:"); for (id, p) in hypothesis.iter() { - eprintln!(" {}: {:?}", id, p); + debug!(" {}: {:?}", id, p); } struct PropagatePerms; diff --git a/c2rust-analyze/src/dataflow/type_check.rs b/c2rust-analyze/src/dataflow/type_check.rs index 9120747ead..560614ce36 100644 --- a/c2rust-analyze/src/dataflow/type_check.rs +++ b/c2rust-analyze/src/dataflow/type_check.rs @@ -10,6 +10,7 @@ use crate::util::{ }; use assert_matches::assert_matches; use either::Either; +use log::{debug, error}; use rustc_hir::def_id::DefId; use rustc_middle::mir::{ AggregateKind, BinOp, Body, CastKind, Location, Mutability, Operand, Place, PlaceRef, @@ -68,7 +69,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { } fn record_access(&mut self, ptr: PointerId, mutbl: Mutability) { - eprintln!("record_access({:?}, {:?})", ptr, mutbl); + debug!("record_access({:?}, {:?})", ptr, mutbl); if ptr == PointerId::NONE { return; } @@ -174,7 +175,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { pub fn visit_rvalue(&mut self, rv: &Rvalue<'tcx>, rvalue_lty: LTy<'tcx>) { let rv_desc = describe_rvalue(rv); - eprintln!("visit_rvalue({rv:?}), desc = {rv_desc:?}"); + debug!("visit_rvalue({rv:?}), desc = {rv_desc:?}"); if let Some(desc) = rv_desc { match desc { @@ -363,7 +364,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { self.acx.tcx().erase_regions(lty2.ty) ); for (sub_lty1, sub_lty2) in lty1.iter().zip(lty2.iter()) { - eprintln!("equate {:?} = {:?}", sub_lty1, sub_lty2); + debug!("equate {:?} = {:?}", sub_lty1, sub_lty2); if sub_lty1.label != PointerId::NONE || sub_lty2.label != PointerId::NONE { assert!(sub_lty1.label != PointerId::NONE); assert!(sub_lty2.label != PointerId::NONE); @@ -373,7 +374,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { } pub fn visit_statement(&mut self, stmt: &Statement<'tcx>, loc: Location) { - eprintln!("visit_statement({:?})", stmt); + debug!("visit_statement({:?})", stmt); let _g = panic_detail::set_current_span(stmt.source_info.span); @@ -405,7 +406,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { } pub fn visit_terminator(&mut self, term: &Terminator<'tcx>, loc: Location) { - eprintln!("visit_terminator({:?})", term.kind); + debug!("visit_terminator({:?})", term.kind); let tcx = self.acx.tcx(); let _g = panic_detail::set_current_span(term.source_info.span); // TODO(spernsteiner): other `TerminatorKind`s will be handled in the future @@ -435,7 +436,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { ) { let tcx = self.acx.tcx(); let callee = ty_callee(tcx, func); - eprintln!("callee = {callee:?}"); + debug!("callee = {callee:?}"); match callee { Callee::Trivial => {} Callee::LocalDef { def_id, substs } => { @@ -451,7 +452,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { self.visit_local_call(def_id, substs, args, destination); } Callee::UnknownDef(_) => { - log::error!("TODO: visit Callee::{callee:?}"); + error!("TODO: visit Callee::{callee:?}"); } Callee::PtrOffset { .. } => { // We handle this like a pointer assignment. @@ -551,7 +552,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { maybe_offset_perm = PermissionSet::empty(); } } - eprintln!("memcpy at {:?} needs offset? {:?}", loc, maybe_offset_perm); + debug!("memcpy at {:?} needs offset? {:?}", loc, maybe_offset_perm); // input needs WRITE permission let perms = PermissionSet::WRITE | maybe_offset_perm; @@ -595,7 +596,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { maybe_offset_perm = PermissionSet::empty(); } } - eprintln!("memset at {:?} needs offset? {:?}", loc, maybe_offset_perm); + debug!("memset at {:?} needs offset? {:?}", loc, maybe_offset_perm); let perms = PermissionSet::WRITE | maybe_offset_perm; self.constraints.add_all_perms(rv_lty.label, perms); diff --git a/c2rust-analyze/src/main.rs b/c2rust-analyze/src/main.rs index 6ccc405f61..fef990dd66 100644 --- a/c2rust-analyze/src/main.rs +++ b/c2rust-analyze/src/main.rs @@ -216,7 +216,7 @@ impl Cargo { f(&mut cmd)?; let status = cmd.status()?; if !status.success() { - eprintln!("error ({status}) running: {cmd:?}"); + ::log::error!("error ({status}) running: {cmd:?}"); exit_with_status(status); } Ok(()) diff --git a/c2rust-analyze/src/pointee_type/type_check.rs b/c2rust-analyze/src/pointee_type/type_check.rs index ffb393e3f5..9d33bdb2f7 100644 --- a/c2rust-analyze/src/pointee_type/type_check.rs +++ b/c2rust-analyze/src/pointee_type/type_check.rs @@ -219,7 +219,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { pub fn visit_call(&mut self, func: Ty<'tcx>, args: &[Operand<'tcx>], dest_lty: LTy<'tcx>) { let tcx = self.acx.tcx(); let callee = ty_callee(tcx, func); - eprintln!("callee = {callee:?}"); + debug!("callee = {callee:?}"); match callee { Callee::Trivial => {} Callee::LocalDef { def_id, substs } => { @@ -253,7 +253,7 @@ impl<'tcx> TypeChecker<'tcx, '_> { // include information about expected/required pointee types } Callee::UnknownDef(_) => { - log::error!("TODO: visit Callee::{callee:?}"); + error!("TODO: visit Callee::{callee:?}"); } Callee::PtrOffset { .. } => { diff --git a/c2rust-analyze/src/rewrite/apply.rs b/c2rust-analyze/src/rewrite/apply.rs index d9e6b53e6b..5a1f4c7b84 100644 --- a/c2rust-analyze/src/rewrite/apply.rs +++ b/c2rust-analyze/src/rewrite/apply.rs @@ -1,4 +1,5 @@ use crate::rewrite::Rewrite; +use log::warn; use rustc_hir::Mutability; use rustc_span::source_map::{FileName, SourceMap}; use rustc_span::{BytePos, SourceFile, Span, SyntaxContext}; @@ -650,7 +651,7 @@ pub fn apply_rewrites( ) -> HashMap { let (rts, errs) = RewriteTree::build(rws); for (span, rw, err) in errs { - eprintln!( + warn!( "{:?}: warning: failed to apply rewrite {:?}: {:?}", span, rw, err ); diff --git a/c2rust-analyze/src/rewrite/expr/convert.rs b/c2rust-analyze/src/rewrite/expr/convert.rs index 6ee0b0bde2..6091d9c17a 100644 --- a/c2rust-analyze/src/rewrite/expr/convert.rs +++ b/c2rust-analyze/src/rewrite/expr/convert.rs @@ -108,7 +108,7 @@ impl<'tcx> ConvertVisitor<'tcx> { if let Some(child_span_rw) = self.rewrites.get(&sub_ex.hir_id) { let child_rw = &child_span_rw.1; if let Some(subst_rw) = child_rw.try_subst(&rw_sub) { - eprintln!( + debug!( "get_subexpr: substituted {rw_sub:?} into {child_rw:?}, producing {subst_rw:?}" ); self.subsumed_child_rewrites @@ -603,7 +603,7 @@ impl<'tcx> Visitor<'tcx> for ConvertVisitor<'tcx> { hir_rw = self.rewrite_from_mir_rws(Some(ex), mir_rws, hir_rw); if !matches!(hir_rw, Rewrite::Identity) { - eprintln!( + debug!( "rewrite {:?} at {:?} (materialize? {})", hir_rw, callsite_span, self.materialize_adjustments ); @@ -710,7 +710,7 @@ fn generate_zeroize_code(zero_ty: &ZeroizeType, lv: &str) -> String { generate_zeroize_code(elem_zero_ty, "(*elem)") ), ZeroizeType::Struct(_, ref fields) => { - eprintln!("zeroize: {} fields on {lv}: {fields:?}", fields.len()); + debug!("zeroize: {} fields on {lv}: {fields:?}", fields.len()); let mut s = String::new(); writeln!(s, "{{").unwrap(); for (name, field_zero_ty) in fields { diff --git a/c2rust-analyze/src/rewrite/expr/hir_only_casts.rs b/c2rust-analyze/src/rewrite/expr/hir_only_casts.rs index 07a725e27b..4a76e21b63 100644 --- a/c2rust-analyze/src/rewrite/expr/hir_only_casts.rs +++ b/c2rust-analyze/src/rewrite/expr/hir_only_casts.rs @@ -10,6 +10,7 @@ //! path starts with rewrites on MIR and lifts them up to the HIR level. use crate::rewrite::Rewrite; +use log::debug; use rustc_hir as hir; use rustc_hir::intravisit::{self, Visitor}; use rustc_middle::hir::nested_filter; @@ -88,7 +89,7 @@ where fn visit_expr(&mut self, ex: &'tcx hir::Expr<'tcx>) { // Check for the syntactic pattern of a two-part address-of. if let Some((ref_expr, mutbl)) = match_two_part_address_of(ex) { - eprintln!( + debug!( "found two-part address-of pattern at {:?}, {:?}, {:?}", ex.span, ref_expr.span, mutbl ); @@ -96,14 +97,14 @@ where if self.expr_has_address_of_adjustments(ref_expr, mutbl) { if (self.filter)(ref_expr) { // Emit a rewrite to remove the cast, leaving only the inner `&x`. - eprintln!(" emit rewrite for expr at {:?}", ref_expr.span); + debug!(" emit rewrite for expr at {:?}", ref_expr.span); self.rewrites .push((ex.span, Rewrite::Sub(0, ref_expr.span))); } else { - eprintln!(" filter rejected expr at {:?}", ref_expr.span); + debug!(" filter rejected expr at {:?}", ref_expr.span); } } else { - eprintln!(" missing adjustments for expr at {:?}", ref_expr.span); + debug!(" missing adjustments for expr at {:?}", ref_expr.span); } } diff --git a/c2rust-analyze/src/rewrite/expr/mir_op.rs b/c2rust-analyze/src/rewrite/expr/mir_op.rs index 6db229a594..70b89a3ec4 100644 --- a/c2rust-analyze/src/rewrite/expr/mir_op.rs +++ b/c2rust-analyze/src/rewrite/expr/mir_op.rs @@ -13,7 +13,7 @@ use crate::pointee_type::PointeeTypes; use crate::pointer_id::{PointerId, PointerTable}; use crate::type_desc::{self, Ownership, Quantity, TypeDesc}; use crate::util::{self, ty_callee, Callee}; -use log::{error, trace}; +use log::{debug, error, trace}; use rustc_ast::Mutability; use rustc_middle::mir::{ BasicBlock, Body, BorrowKind, Location, Operand, Place, PlaceElem, PlaceRef, Rvalue, Statement, @@ -347,7 +347,7 @@ impl<'a, 'tcx> ExprRewriteVisitor<'a, 'tcx> { fn visit_statement(&mut self, stmt: &Statement<'tcx>, loc: Location) { let _g = panic_detail::set_current_span(stmt.source_info.span); - eprintln!( + debug!( "mir_op::visit_statement: {:?} @ {:?}: {:?}", loc, stmt.source_info.span, stmt ); @@ -880,7 +880,7 @@ impl<'a, 'tcx> ExprRewriteVisitor<'a, 'tcx> { /// Visit an `Rvalue`. If `expect_ty` is `Some`, also emit whatever casts are necessary to /// make the `Rvalue` produce a value of type `expect_ty`. fn visit_rvalue(&mut self, rv: &Rvalue<'tcx>, expect_ty: Option>) { - eprintln!("mir_op::visit_rvalue: {:?}, expect {:?}", rv, expect_ty); + debug!("mir_op::visit_rvalue: {:?}, expect {:?}", rv, expect_ty); match *rv { Rvalue::Use(ref op) => { self.enter_rvalue_operand(0, |v| v.visit_operand(op, expect_ty)); @@ -965,7 +965,7 @@ impl<'a, 'tcx> ExprRewriteVisitor<'a, 'tcx> { self.perms[rv_lty.label], self.flags[rv_lty.label], ); - eprintln!("Cast with common pointee {:?}:\n op_desc = {:?}\n rv_desc = {:?}\n matches? {}", + debug!("Cast with common pointee {:?}:\n op_desc = {:?}\n rv_desc = {:?}\n matches? {}", pointee_lty, op_desc, rv_desc, op_desc == rv_desc); if op_desc == rv_desc { // After rewriting, the input and output types of the cast will be diff --git a/c2rust-analyze/src/rewrite/expr/unlower.rs b/c2rust-analyze/src/rewrite/expr/unlower.rs index 6a7e634fe2..5b07f992c3 100644 --- a/c2rust-analyze/src/rewrite/expr/unlower.rs +++ b/c2rust-analyze/src/rewrite/expr/unlower.rs @@ -252,7 +252,7 @@ impl<'a, 'tcx> UnlowerVisitor<'a, 'tcx> { Some(x @ (pl, _)) if is_var(pl) => x, _ => { warn("expected final Assign to store into var"); - eprintln!( + debug!( "visit_expr_inner: bail out: expr at {:?} isn't assigned to a var", ex.span ); diff --git a/c2rust-analyze/src/rewrite/mod.rs b/c2rust-analyze/src/rewrite/mod.rs index 106ed1eddc..8801ea0d26 100644 --- a/c2rust-analyze/src/rewrite/mod.rs +++ b/c2rust-analyze/src/rewrite/mod.rs @@ -23,6 +23,7 @@ //! require us to update the `Span`s mentioned in the later rewrites to account for the changes in //! the source code produced by the earlier ones). +use log::{debug, info, warn}; use rustc_hir::Mutability; use rustc_middle::ty::TyCtxt; use rustc_span::{FileName, Span}; @@ -327,18 +328,18 @@ pub fn apply_rewrites( update_files: UpdateFiles, ) { let emit = |filename, src: String| { - println!("\n\n ===== BEGIN {:?} =====", filename); + info!("\n\n ===== BEGIN {:?} =====", filename); for line in src.lines() { // Omit filecheck directives from the debug output, as filecheck can get confused due // to directives matching themselves (e.g. `// CHECK: foo` will match the `foo` in the // line `// CHECK: foo`). if let Some((pre, _post)) = line.split_once("// CHECK") { - println!("{}// (FileCheck directive omitted)", pre); + info!("{}// (FileCheck directive omitted)", pre); } else { - println!("{}", line); + info!("{}", line); } } - println!(" ===== END {:?} =====", filename); + info!(" ===== END {:?} =====", filename); if !matches!(update_files, UpdateFiles::No) { let mut path_ok = false; @@ -350,7 +351,7 @@ pub fn apply_rewrites( UpdateFiles::AlongsidePointwise(ref s) => { let ext = format!("{}.rs", s); let p = path.with_extension(&ext); - eprintln!("writing to {:?}", p); + debug!("writing to {:?}", p); p } UpdateFiles::No => unreachable!(), @@ -360,7 +361,7 @@ pub fn apply_rewrites( } } if !path_ok { - log::warn!("couldn't write to non-real file {filename:?}"); + warn!("couldn't write to non-real file {filename:?}"); } } }; diff --git a/c2rust-analyze/src/rewrite/ty.rs b/c2rust-analyze/src/rewrite/ty.rs index 69b5a8c25e..37cce5a984 100644 --- a/c2rust-analyze/src/rewrite/ty.rs +++ b/c2rust-analyze/src/rewrite/ty.rs @@ -21,7 +21,7 @@ use crate::type_desc::{self, Ownership, PtrDesc, Quantity, TypeDesc}; use hir::{ FnRetTy, GenericParamKind, Generics, ItemKind, Path, PathSegment, VariantData, WherePredicate, }; -use log::warn; +use log::{debug, warn}; use rustc_ast::ast; use rustc_hir as hir; use rustc_hir::def::{DefKind, Namespace, Res}; @@ -255,9 +255,9 @@ fn deconstruct_hir_ty<'a, 'tcx>( if type_args.len() < substs.types().count() { // this situation occurs when there are hidden type arguments // such as the allocator `std::alloc::Global` type argument in `Vec` - eprintln!("warning: extra MIR type argument for {adt_def:?}:"); + debug!("warning: extra MIR type argument for {adt_def:?}:"); for mir_arg in substs.types().into_iter().skip(type_args.len()) { - eprintln!("\t{:?}", mir_arg) + debug!("\t{:?}", mir_arg) } } else if type_args.len() != substs.types().count() { panic!("mismatched number of type arguments for {adt_def:?} and {hir_ty:?}") @@ -278,7 +278,7 @@ fn deconstruct_hir_ty<'a, 'tcx>( Some(v) } (tk, hir_tk) => { - eprintln!("deconstruct_hir_ty: {tk:?} -- {hir_tk:?} not supported"); + debug!("deconstruct_hir_ty: {tk:?} -- {hir_tk:?} not supported"); None } } @@ -946,7 +946,7 @@ pub fn dump_rewritten_local_tys<'tcx>( acx.gacx, ); let ty = mk_rewritten_ty(rw_lcx, rw_lty); - eprintln!( + debug!( "{:?} ({}): {:?}", local, describe_local(acx.tcx(), decl), diff --git a/c2rust-analyze/src/trivial.rs b/c2rust-analyze/src/trivial.rs index 02dc0bd922..c18cf1d862 100644 --- a/c2rust-analyze/src/trivial.rs +++ b/c2rust-analyze/src/trivial.rs @@ -1,3 +1,4 @@ +use log::debug; use rustc_middle::ty::{self, Binder, EarlyBinder, FnSig, GenSig, Subst, Ty, TyCtxt}; pub trait IsTrivial<'tcx> { @@ -60,7 +61,7 @@ impl<'tcx> IsTrivial<'tcx> for Ty<'tcx> { fn is_trivial(&self, tcx: TyCtxt<'tcx>) -> bool { let not_sure_yet = |is_trivial: bool| { let kind = self.kind(); - eprintln!("assuming non-trivial for now as a safe backup (guessed {is_trivial:?}): ty.kind() = {kind:?}, ty = {self:?}"); + debug!("assuming non-trivial for now as a safe backup (guessed {is_trivial:?}): ty.kind() = {kind:?}, ty = {self:?}"); false }; @@ -84,7 +85,7 @@ impl<'tcx> IsTrivial<'tcx> for Ty<'tcx> { // don't know, as `dyn Trait` could be anything ty::Dynamic(trait_ty, _reg) => { - eprintln!("unsure how to check `dyn Trait` for accessible pointers, so assuming non-trivial: ty = {self:?}, trait_ty = {trait_ty:?}"); + debug!("unsure how to check `dyn Trait` for accessible pointers, so assuming non-trivial: ty = {self:?}, trait_ty = {trait_ty:?}"); false } diff --git a/c2rust-analyze/src/util.rs b/c2rust-analyze/src/util.rs index 037f3a46d2..3212f39978 100644 --- a/c2rust-analyze/src/util.rs +++ b/c2rust-analyze/src/util.rs @@ -1,5 +1,6 @@ use crate::labeled_ty::LabeledTy; use crate::trivial::IsTrivial; +use log::debug; use rustc_ast::ast::AttrKind; use rustc_const_eval::interpret::Scalar; use rustc_hir::def::DefKind; @@ -201,7 +202,7 @@ pub enum Callee<'tcx> { pub fn ty_callee<'tcx>(tcx: TyCtxt<'tcx>, ty: Ty<'tcx>) -> Callee<'tcx> { let is_trivial = || { let is_trivial = ty.fn_sig(tcx).is_trivial(tcx); - eprintln!("{ty:?} is trivial: {is_trivial}"); + debug!("{ty:?} is trivial: {is_trivial}"); is_trivial }; @@ -390,7 +391,7 @@ fn builtin_callee<'tcx>(tcx: TyCtxt<'tcx>, did: DefId, substs: SubstsRef<'tcx>) } _ => { - eprintln!("name: {name:?}"); + debug!("name: {name:?}"); None } } diff --git a/c2rust-analyze/tests/common/mod.rs b/c2rust-analyze/tests/common/mod.rs index 599e2e3149..aa09445b6c 100644 --- a/c2rust-analyze/tests/common/mod.rs +++ b/c2rust-analyze/tests/common/mod.rs @@ -1,3 +1,4 @@ +use log::warn; use std::{ collections::HashSet, env, @@ -337,7 +338,7 @@ pub fn check_for_missing_tests_for(main_test_path: impl AsRef) { .collect::>(); for test_name in &missing_tests { let test_path = rel_test_dir.join(format!("{test_name}.rs")); - eprintln!("missing a `#[test] fn {test_name}` for {test_path:?}"); + warn!("missing a `#[test] fn {test_name}` for {test_path:?}"); } assert!(missing_tests.is_empty(), "see missing tests above"); }