diff --git a/lib/src/analysis_control_flow.rs b/lib/src/analysis_control_flow.rs index e28f630..007691d 100644 --- a/lib/src/analysis_control_flow.rs +++ b/lib/src/analysis_control_flow.rs @@ -1,6 +1,6 @@ //! Performs control flow analysis. -use log::{debug, info}; +use log::trace; use std::cmp::Ordering; use crate::analysis_main::AnalysisError; @@ -107,7 +107,7 @@ fn calc_preds_and_succs( TypedIxVec>, TypedIxVec>, ) { - info!(" calc_preds_and_succs: begin"); + trace!(" calc_preds_and_succs: begin"); assert!(func.blocks().len() == num_blocks as usize); @@ -140,9 +140,9 @@ fn calc_preds_and_succs( assert!(succ_map.len() == num_blocks); let mut n = 0; - debug!(""); + trace!(""); for (preds, succs) in pred_map.iter().zip(succ_map.iter()) { - debug!( + trace!( "{:<3?} preds {:<16?} succs {:?}", BlockIx::new(n), preds, @@ -151,7 +151,7 @@ fn calc_preds_and_succs( n += 1; } - info!(" calc_preds_and_succs: end"); + trace!(" calc_preds_and_succs: end"); (pred_map, succ_map) } @@ -167,7 +167,7 @@ fn calc_preord_and_postord( num_blocks: u32, succ_map: &TypedIxVec>, ) -> Option<(Vec, Vec)> { - info!(" calc_preord_and_postord: begin"); + trace!(" calc_preord_and_postord: begin"); let mut pre_ord = Vec::::new(); let mut post_ord = Vec::::new(); @@ -207,7 +207,7 @@ fn calc_preord_and_postord( assert!(pre_ord.len() == post_ord.len()); assert!(pre_ord.len() <= num_blocks as usize); if pre_ord.len() < num_blocks as usize { - info!( + trace!( " calc_preord_and_postord: invalid: {} blocks, {} reachable", num_blocks, pre_ord.len() @@ -228,7 +228,7 @@ fn calc_preord_and_postord( debug_assert!(post_ord_sorted == expected); } - info!(" calc_preord_and_postord: end. {} blocks", num_blocks); + trace!(" calc_preord_and_postord: end. {} blocks", num_blocks); Some((pre_ord, post_ord)) } @@ -247,7 +247,7 @@ fn calc_dom_sets_slow( post_ord: &Vec, start: BlockIx, ) -> TypedIxVec> { - info!(" calc_dom_sets_slow: begin"); + trace!(" calc_dom_sets_slow: begin"); let mut dom_map = TypedIxVec::>::new(); @@ -271,7 +271,7 @@ fn calc_dom_sets_slow( let mut num_iter = 0; loop { num_iter += 1; - info!(" calc_dom_sets_slow: outer loop {}", num_iter); + trace!(" calc_dom_sets_slow: outer loop {}", num_iter); let mut change = false; for i in 0..num_blocks { // block_ix travels in "reverse preorder" @@ -296,13 +296,13 @@ fn calc_dom_sets_slow( } } - debug!(""); + trace!(""); let mut block_ix = 0; for dom_set in dom_map.iter() { - debug!("{:<3?} dom_set {:<16?}", BlockIx::new(block_ix), dom_set); + trace!("{:<3?} dom_set {:<16?}", BlockIx::new(block_ix), dom_set); block_ix += 1; } - info!(" calc_dom_sets_slow: end"); + trace!(" calc_dom_sets_slow: end"); dom_map } @@ -354,7 +354,7 @@ fn calc_dom_tree( post_ord: &Vec, start: BlockIx, ) -> TypedIxVec { - info!(" calc_dom_tree: begin"); + trace!(" calc_dom_tree: begin"); // We use 2^32-1 as a marker for an invalid BlockIx or postorder number. // Hence we need this: @@ -461,7 +461,7 @@ fn calc_dom_tree( // by walking up the tree to the root, and check that it's the same as // what the simple algorithm produced. - info!(" calc_dom_tree crosscheck: begin"); + trace!(" calc_dom_tree crosscheck: begin"); let slow_sets = calc_dom_sets_slow(num_blocks, pred_map, post_ord, start); assert!(slow_sets.len() == idom.len()); @@ -478,10 +478,10 @@ fn calc_dom_tree( } assert!(set.to_vec() == slow_sets[BlockIx::new(i)].to_vec()); } - info!(" calc_dom_tree crosscheck: end"); + trace!(" calc_dom_tree crosscheck: end"); } - info!(" calc_dom_tree: end"); + trace!(" calc_dom_tree: end"); idom } @@ -496,7 +496,7 @@ fn calc_loop_depths( post_ord: &Vec, start: BlockIx, ) -> TypedIxVec { - info!(" calc_loop_depths: begin"); + trace!(" calc_loop_depths: begin"); let idom = calc_dom_tree(num_blocks, pred_map, post_ord, start); // Find the loops. First, find the "loop header nodes", and from those, @@ -613,9 +613,9 @@ fn calc_loop_depths( debug_assert!(depth_map.len() == num_blocks); let mut n = 0; - debug!(""); + trace!(""); for (depth, idom_by) in depth_map.iter().zip(idom.iter()) { - debug!( + trace!( "{:<3?} depth {} idom {:?}", BlockIx::new(n), depth, @@ -624,7 +624,7 @@ fn calc_loop_depths( n += 1; } - info!(" calc_loop_depths: end"); + trace!(" calc_loop_depths: end"); depth_map } @@ -653,7 +653,7 @@ pub struct CFGInfo { impl CFGInfo { #[inline(never)] pub fn create(func: &F) -> Result { - info!(" CFGInfo::create: begin"); + trace!(" CFGInfo::create: begin"); // Throw out insanely large inputs. They'll probably cause failure later // on. @@ -730,7 +730,7 @@ impl CFGInfo { // // === END compute loop depth of all Blocks - info!(" CFGInfo::create: end"); + trace!(" CFGInfo::create: end"); Ok(CFGInfo { pred_map, succ_map, diff --git a/lib/src/analysis_data_flow.rs b/lib/src/analysis_data_flow.rs index 2f030cb..d7248eb 100644 --- a/lib/src/analysis_data_flow.rs +++ b/lib/src/analysis_data_flow.rs @@ -1,6 +1,6 @@ //! Performs dataflow and liveness analysis, including live range construction. -use log::{debug, info, log_enabled, Level}; +use log::{log_enabled, trace, Level}; use smallvec::{smallvec, SmallVec}; use std::cmp::min; use std::fmt; @@ -377,7 +377,7 @@ pub fn get_sanitized_reg_uses_for_func( assert!(!reg_vecs.is_sanitized()); reg_vecs.set_sanitized(true); - if log_enabled!(Level::Debug) { + if log_enabled!(Level::Trace) { let show_reg = |r: Reg| { if r.is_real() { reg_universe.regs[r.get_index()].1.clone() @@ -407,9 +407,12 @@ pub fn get_sanitized_reg_uses_for_func( ®_vecs.defs[bounds_vec[iix].defs_start as usize ..bounds_vec[iix].defs_start as usize + bounds_vec[iix].defs_len as usize], ); - debug!( + trace!( "{:?} SAN_RU: use {{ {}}} mod {{ {}}} def {{ {}}}", - iix, s_use, s_mod, s_def + iix, + s_use, + s_mod, + s_def ); } } @@ -520,7 +523,7 @@ pub fn calc_def_and_use( TypedIxVec>, TypedIxVec>, ) { - info!(" calc_def_and_use: begin"); + trace!(" calc_def_and_use: begin"); assert!(rvb.is_sanitized()); let mut def_sets = TypedIxVec::new(); let mut use_sets = TypedIxVec::new(); @@ -578,9 +581,9 @@ pub fn calc_def_and_use( assert!(def_sets.len() == use_sets.len()); - if log_enabled!(Level::Debug) { + if log_enabled!(Level::Trace) { let mut n = 0; - debug!(""); + trace!(""); for (def_set, use_set) in def_sets.iter().zip(use_sets.iter()) { let mut first = true; let mut defs_str = "".to_string(); @@ -600,7 +603,7 @@ pub fn calc_def_and_use( first = false; uses_str = uses_str + &uce.show_with_rru(univ); } - debug!( + trace!( "{:<3?} def {{{}}} use {{{}}}", BlockIx::new(n), defs_str, @@ -610,7 +613,7 @@ pub fn calc_def_and_use( } } - info!(" calc_def_and_use: end"); + trace!(" calc_def_and_use: end"); (def_sets, use_sets) } @@ -630,7 +633,7 @@ pub fn calc_livein_and_liveout( TypedIxVec>, TypedIxVec>, ) { - info!(" calc_livein_and_liveout: begin"); + trace!(" calc_livein_and_liveout: begin"); let num_blocks = func.blocks().len() as u32; let empty = SparseSet::::empty(); @@ -709,14 +712,16 @@ pub fn calc_livein_and_liveout( } let ratio: f32 = (num_evals as f32) / ((if num_blocks == 0 { 1 } else { num_blocks }) as f32); - info!( + trace!( " calc_livein_and_liveout: {} blocks, {} evals ({:<.2} per block)", - num_blocks, num_evals, ratio + num_blocks, + num_evals, + ratio ); - if log_enabled!(Level::Debug) { + if log_enabled!(Level::Trace) { let mut n = 0; - debug!(""); + trace!(""); for (livein, liveout) in liveins.iter().zip(liveouts.iter()) { let mut first = true; let mut li_str = "".to_string(); @@ -736,7 +741,7 @@ pub fn calc_livein_and_liveout( first = false; lo_str = lo_str + &lo.show_with_rru(univ); } - debug!( + trace!( "{:<3?} livein {{{}}} liveout {{{}}}", BlockIx::new(n), li_str, @@ -746,7 +751,7 @@ pub fn calc_livein_and_liveout( } } - info!(" calc_livein_and_liveout: end"); + trace!(" calc_livein_and_liveout: end"); (liveins, liveouts) } @@ -1146,7 +1151,7 @@ pub fn get_range_frags( TypedIxVec, Vec, ) { - info!(" get_range_frags: begin"); + trace!(" get_range_frags: begin"); assert!(livein_sets_per_block.len() == func.blocks().len() as u32); assert!(liveout_sets_per_block.len() == func.blocks().len() as u32); assert!(rvb.is_sanitized()); @@ -1224,21 +1229,21 @@ pub fn get_range_frags( assert!(state_elem.is_none()); } - if log_enabled!(Level::Debug) { - debug!(""); + if log_enabled!(Level::Trace) { + trace!(""); let mut n = 0; for frag in result_frags.iter() { - debug!("{:<3?} {:?}", RangeFragIx::new(n), frag); + trace!("{:<3?} {:?}", RangeFragIx::new(n), frag); n += 1; } - debug!(""); + trace!(""); for (reg_ix, frag_ixs) in result_map.iter().enumerate() { if frag_ixs.len() == 0 { continue; } let reg = reg_ix_to_reg(reg_universe, &vreg_classes, reg_ix as u32); - debug!( + trace!( "frags for {} {:?}", reg.show_with_rru(reg_universe), frag_ixs @@ -1246,7 +1251,7 @@ pub fn get_range_frags( } } - info!(" get_range_frags: end"); + trace!(" get_range_frags: end"); assert!(result_frags.len() == result_frag_metrics.len()); (result_map, result_frags, result_frag_metrics, vreg_classes) } @@ -1519,11 +1524,12 @@ pub(crate) fn merge_range_frags( stats_num_total_incoming_regs += 1; } } - info!(" merge_range_frags: begin"); - info!(" in: {} in frag_env", frag_env.len()); - info!( + trace!(" merge_range_frags: begin"); + trace!(" in: {} in frag_env", frag_env.len()); + trace!( " in: {} regs containing in total {} frags", - stats_num_total_incoming_regs, stats_num_total_incoming_frags + stats_num_total_incoming_regs, + stats_num_total_incoming_frags ); let mut stats_num_single_grps = 0; @@ -1777,29 +1783,32 @@ pub(crate) fn merge_range_frags( // END merge `all_frag_ixs_for_reg` entries as much as possible } // END per reg loop - info!(" in: {} single groups", stats_num_single_grps); - info!( + trace!(" in: {} single groups", stats_num_single_grps); + trace!( " in: {} local frags in multi groups", stats_num_local_frags ); - info!( + trace!( " in: {} small multi groups, {} small multi group total size", - stats_num_multi_grps_small, stats_size_multi_grps_small + stats_num_multi_grps_small, + stats_size_multi_grps_small ); - info!( + trace!( " in: {} large multi groups, {} large multi group total size", - stats_num_multi_grps_large, stats_size_multi_grps_large + stats_num_multi_grps_large, + stats_size_multi_grps_large ); - info!( + trace!( " out: {} VLRs, {} RLRs", result_virtual.len(), result_real.len() ); - info!( + trace!( " compress vfrags: in {}, out {}", - stats_num_vfrags_uncompressed, stats_num_vfrags_compressed + stats_num_vfrags_uncompressed, + stats_num_vfrags_compressed ); - info!(" merge_range_frags: end"); + trace!(" merge_range_frags: end"); (result_real, result_virtual) } diff --git a/lib/src/analysis_main.rs b/lib/src/analysis_main.rs index f1e3909..ea403d3 100644 --- a/lib/src/analysis_main.rs +++ b/lib/src/analysis_main.rs @@ -1,6 +1,6 @@ //! Top level module for all analysis activities. -use log::{debug, info}; +use log::trace; use crate::data_structures::*; use crate::sparse_set::SparseSet; @@ -79,26 +79,22 @@ impl ToString for AnalysisError { regs_string ) } - AnalysisError::IllegalRealReg(reg) => { - format!( - "instructions mention real register {:?}, which either isn't defined in the + AnalysisError::IllegalRealReg(reg) => format!( + "instructions mention real register {:?}, which either isn't defined in the register universe, or is a 'suggested_scratch' register", - reg - ) - } + reg + ), AnalysisError::UnreachableBlocks => "at least one block is unreachable".to_string(), AnalysisError::ImplementationLimitsExceeded => { "implementation limits exceeded (more than 1 million blocks or 16 million insns)" .to_string() } - AnalysisError::LsraCriticalEdge { block, inst } => { - format!( - "block {:?} ends with control flow instruction {:?} that mentions a register, + AnalysisError::LsraCriticalEdge { block, inst } => format!( + "block {:?} ends with control flow instruction {:?} that mentions a register, and at least one of the multiple successors has several predecessors; consider splitting the outgoing edges!", - block, inst - ) - } + block, inst + ), } } } @@ -139,8 +135,8 @@ pub fn run_analysis( reftype_class: RegClass, reftyped_vregs: &Vec, // as supplied by the client ) -> Result { - info!("run_analysis: begin"); - info!( + trace!("run_analysis: begin"); + trace!( " run_analysis: {} blocks, {} insns", func.blocks().len(), func.insns().len() @@ -149,7 +145,7 @@ pub fn run_analysis( // LSRA uses its own analysis. assert!(!client_wants_stackmaps || algorithm != AlgorithmWithDefaults::LinearScan); - info!(" run_analysis: begin control flow analysis"); + trace!(" run_analysis: begin control flow analysis"); // First do control flow analysis. This is (relatively) simple. Note that // this can fail, for various reasons; we propagate the failure if so. @@ -162,10 +158,10 @@ pub fn run_analysis( // Annotate each Block with its estimated execution frequency. let estimated_frequencies = DepthBasedFrequencies::new(func, &cfg_info); - info!(" run_analysis: end control flow analysis"); + trace!(" run_analysis: end control flow analysis"); // Now perform dataflow analysis. This is somewhat more complex. - info!(" run_analysis: begin data flow analysis"); + trace!(" run_analysis: begin data flow analysis"); // See `get_sanitized_reg_uses_for_func` for the meaning of "sanitized". let reg_vecs_and_bounds = get_sanitized_reg_uses_for_func(func, reg_universe) @@ -222,13 +218,13 @@ pub fn run_analysis( } } - info!(" run_analysis: end data flow analysis"); + trace!(" run_analysis: end data flow analysis"); // Dataflow analysis is now complete. Now compute the virtual and real live // ranges, in two steps: (1) compute RangeFrags, and (2) merge them // together, guided by flow and liveness info, so as to create the final // VirtualRanges and RealRanges. - info!(" run_analysis: begin liveness analysis"); + trace!(" run_analysis: begin liveness analysis"); let (frag_ixs_per_reg, frag_env, frag_metrics_env, vreg_classes) = get_range_frags( func, @@ -252,10 +248,10 @@ pub fn run_analysis( debug_assert!(liveout_sets_per_block.len() == estimated_frequencies.len()); - debug!(""); + trace!(""); let mut n = 0; for rlr in rlr_env.iter() { - debug!( + trace!( "{:<4?} {}", RealRangeIx::new(n), rlr.show_with_rru(®_universe) @@ -263,10 +259,10 @@ pub fn run_analysis( n += 1; } - debug!(""); + trace!(""); n = 0; for vlr in vlr_env.iter() { - debug!("{:<4?} {:?}", VirtualRangeIx::new(n), vlr); + trace!("{:<4?} {:?}", VirtualRangeIx::new(n), vlr); n += 1; } @@ -293,10 +289,10 @@ pub fn run_analysis( (None, None) }; - info!(" run_analysis: end liveness analysis"); + trace!(" run_analysis: end liveness analysis"); if client_wants_stackmaps { - info!(" run_analysis: begin reftypes analysis"); + trace!(" run_analysis: begin reftypes analysis"); do_reftypes_analysis( &mut rlr_env, &mut vlr_env, @@ -306,10 +302,10 @@ pub fn run_analysis( reftype_class, reftyped_vregs, ); - info!(" run_analysis: end reftypes analysis"); + trace!(" run_analysis: end reftypes analysis"); } - info!("run_analysis: end"); + trace!("run_analysis: end"); Ok(AnalysisInfo { reg_vecs_and_bounds, @@ -390,12 +386,12 @@ impl<'a> ReftypeAnalysis for BacktrackingReftypeAnalysis<'a> { if range.is_real() { let rrange = &mut self.rlr_env[range.to_real()]; debug_assert!(!rrange.is_ref); - debug!(" -> rrange {:?} is reffy", range.to_real()); + trace!(" -> rrange {:?} is reffy", range.to_real()); rrange.is_ref = true; } else { let vrange = &mut self.vlr_env[range.to_virtual()]; debug_assert!(!vrange.is_ref); - debug!(" -> rrange {:?} is reffy", range.to_virtual()); + trace!(" -> rrange {:?} is reffy", range.to_virtual()); vrange.is_ref = true; } } @@ -403,7 +399,7 @@ impl<'a> ReftypeAnalysis for BacktrackingReftypeAnalysis<'a> { #[inline(always)] fn insert_reffy_ranges(&self, vreg: VirtualReg, set: &mut SparseSet) { for vlr_ix in &self.reg_to_ranges_maps.vreg_to_vlrs_map[vreg.get_index()] { - debug!("range {:?} is reffy due to reffy vreg {:?}", vlr_ix, vreg); + trace!("range {:?} is reffy due to reffy vreg {:?}", vlr_ix, vreg); set.insert(RangeId::new_virtual(*vlr_ix)); } } diff --git a/lib/src/bt_coalescing_analysis.rs b/lib/src/bt_coalescing_analysis.rs index beb4fe8..349c768 100644 --- a/lib/src/bt_coalescing_analysis.rs +++ b/lib/src/bt_coalescing_analysis.rs @@ -26,7 +26,7 @@ #![allow(non_snake_case)] #![allow(non_camel_case_types)] -use log::{debug, info, log_enabled, Level}; +use log::{log_enabled, trace, Level}; use smallvec::{smallvec, SmallVec}; use crate::data_structures::{ @@ -144,8 +144,8 @@ pub(crate) fn do_coalescing_analysis( UnionFindEquivClasses, TypedIxVec, ) { - info!(""); - info!("do_coalescing_analysis: begin"); + trace!(""); + trace!("do_coalescing_analysis: begin"); // This function contains significant additional complexity due to the requirement to handle // pathological cases in reasonable time without unduly burdening the common cases. @@ -535,9 +535,12 @@ pub(crate) fn do_coalescing_analysis( .. } in move_info.iter() { - debug!( + trace!( "connected by moves: {:?} {:?} <- {:?} (est_freq {})", - iix, dst, src, est_freq + iix, + dst, + src, + est_freq ); match (dst.is_virtual(), src.is_virtual()) { (true, true) => { @@ -565,7 +568,7 @@ pub(crate) fn do_coalescing_analysis( // both `vlrixSrc` and `vlrixDst`. This is so as to reduce to // zero, the cost of a VLR whose only instructions are its // v-v boundary copies. - debug!("reduce cost of {:?} and {:?}", vlrixSrc, vlrixDst); + trace!("reduce cost of {:?} and {:?}", vlrixSrc, vlrixDst); decVLRcosts.push((vlrixSrc, vlrixDst, 1 * est_freq)); } } @@ -633,22 +636,22 @@ pub(crate) fn do_coalescing_analysis( let vlrEquivClasses: UnionFindEquivClasses = vlrEquivClassesUF.get_equiv_classes(); - if log_enabled!(Level::Debug) { - debug!("Revised VLRs:"); + if log_enabled!(Level::Trace) { + trace!("Revised VLRs:"); let mut n = 0; for vlr in vlr_env.iter() { - debug!("{:<4?} {:?}", VirtualRangeIx::new(n), vlr); + trace!("{:<4?} {:?}", VirtualRangeIx::new(n), vlr); n += 1; } - debug!("Coalescing hints:"); + trace!("Coalescing hints:"); n = 0; for hints_for_one_vlr in hints.iter() { let mut s = "".to_string(); for hint in hints_for_one_vlr { s = s + &show_hint(hint, &univ) + &" ".to_string(); } - debug!(" hintsfor {:<4?} = {}", VirtualRangeIx::new(n), s); + trace!(" hintsfor {:<4?} = {}", VirtualRangeIx::new(n), s); n += 1; } @@ -659,18 +662,18 @@ pub(crate) fn do_coalescing_analysis( tmpvec.reverse(); tmpvec.push(elem); } - debug!(" eclassof {:?} = {:?}", vlrix, tmpvec); + trace!(" eclassof {:?} = {:?}", vlrix, tmpvec); } for (b, i) in is_vv_boundary_move.iter().zip(0..) { if *b { - debug!(" vv_boundary_move at {:?}", InstIx::new(i)); + trace!(" vv_boundary_move at {:?}", InstIx::new(i)); } } } - info!("do_coalescing_analysis: end"); - info!(""); + trace!("do_coalescing_analysis: end"); + trace!(""); (hints, vlrEquivClasses, is_vv_boundary_move) } diff --git a/lib/src/bt_main.rs b/lib/src/bt_main.rs index e192705..aaac638 100644 --- a/lib/src/bt_main.rs +++ b/lib/src/bt_main.rs @@ -3,7 +3,7 @@ //! Core implementation of the backtracking allocator. -use log::{debug, info, log_enabled, Level}; +use log::{debug, log_enabled, Level}; use smallvec::SmallVec; use std::default; use std::fmt; @@ -723,14 +723,14 @@ pub fn alloc_main( // -------- Alloc main -------- // Create initial state - info!("alloc_main: begin"); - info!( + debug!("alloc_main: begin"); + debug!( "alloc_main: in: {} insns in {} blocks", func.insns().len(), func.blocks().len() ); let num_vlrs_initial = vlr_env.len(); - info!( + debug!( "alloc_main: in: {} VLRs, {} RLRs", num_vlrs_initial, rlr_env.len() @@ -798,7 +798,7 @@ pub fn alloc_main( debug!(""); debug!("-- MAIN ALLOCATION LOOP (DI means 'direct', CO means 'coalesced'):"); - info!("alloc_main: main allocation loop: begin"); + debug!("alloc_main: main allocation loop: begin"); // ======== BEGIN Main allocation loop ======== let mut num_vlrs_processed = 0; // stats only @@ -1396,7 +1396,7 @@ pub fn alloc_main( } // ======== END Main allocation loop ======== - info!("alloc_main: main allocation loop: end"); + debug!("alloc_main: main allocation loop: end"); if log_enabled!(Level::Debug) { debug!(""); @@ -1415,7 +1415,7 @@ pub fn alloc_main( // ======== BEGIN Do spill slot coalescing ======== debug!(""); - info!("alloc_main: create spills_n_reloads for MOVE insns"); + debug!("alloc_main: create spills_n_reloads for MOVE insns"); // Sort `edit_list_move` by the insn with which each item is associated. edit_list_move.sort_unstable_by(|eli1, eli2| eli1.iix.cmp(&eli2.iix)); @@ -1559,7 +1559,7 @@ pub fn alloc_main( // ======== BEGIN Create all other spills and reloads ======== debug!(""); - info!("alloc_main: create spills_n_reloads for other insns"); + debug!("alloc_main: create spills_n_reloads for other insns"); // Reload and spill instructions are missing. To generate them, go through // the "edit list", which contains info on both how to generate the @@ -1642,7 +1642,7 @@ pub fn alloc_main( // not take account of spill or reload instructions. Dealing with those // is relatively simple and happens later. - info!("alloc_main: create frag_map"); + debug!("alloc_main: create frag_map"); let mut frag_map = Vec::<(RangeFrag, VirtualReg, RealReg)>::new(); // For each real register under our control .. @@ -1667,7 +1667,7 @@ pub fn alloc_main( let mut stackmaps = Vec::>::new(); if !safepoint_insns.is_empty() { - info!("alloc_main: create safepoints and stackmaps"); + debug!("alloc_main: create safepoints and stackmaps"); for safepoint_iix in safepoint_insns { // Create the stackmap artefacts for `safepoint_iix`. Save the stackmap (the // reftyped spillslots); we'll have to return it to the client as part of the @@ -1716,7 +1716,7 @@ pub fn alloc_main( } } - info!("alloc_main: edit_inst_stream"); + debug!("alloc_main: edit_inst_stream"); let final_insns_and_targetmap_and_new_safepoints__or_err = edit_inst_stream( func, @@ -1735,39 +1735,39 @@ pub fn alloc_main( match final_insns_and_targetmap_and_new_safepoints__or_err { Ok((ref final_insns, ..)) => { - info!( + debug!( "alloc_main: out: VLRs: {} initially, {} processed", num_vlrs_initial, num_vlrs_processed ); - info!( + debug!( "alloc_main: out: VLRs: {} evicted, {} spilled", num_vlrs_evicted, num_vlrs_spilled ); - info!( + debug!( "alloc_main: out: insns: {} total, {} spills, {} reloads, {} nopzs", final_insns.len(), num_spills, num_reloads, iixs_to_nop_out.len() ); - info!( + debug!( "alloc_main: out: spill slots: {} used", spill_slot_allocator.num_slots_in_use() ); } Err(_) => { - info!("alloc_main: allocation failed!"); + debug!("alloc_main: allocation failed!"); } } let (final_insns, target_map, new_to_old_insn_map, new_safepoint_insns) = match final_insns_and_targetmap_and_new_safepoints__or_err { Err(e) => { - info!("alloc_main: fail"); + debug!("alloc_main: fail"); return Err(e); } Ok(quad) => { - info!("alloc_main: creating RegAllocResult"); + debug!("alloc_main: creating RegAllocResult"); quad } }; @@ -1835,7 +1835,7 @@ pub fn alloc_main( new_safepoint_insns, }; - info!("alloc_main: end"); + debug!("alloc_main: end"); // ======== END Create the RegAllocResult ======== diff --git a/lib/src/lib.rs b/lib/src/lib.rs index 69508d1..32b0740 100644 --- a/lib/src/lib.rs +++ b/lib/src/lib.rs @@ -32,7 +32,7 @@ mod snapshot; mod sparse_set; mod union_find; -use log::{info, log_enabled, Level}; +use log::{debug, log_enabled, Level}; use std::default; use std::{borrow::Cow, fmt}; @@ -522,15 +522,15 @@ pub fn allocate_registers_with_opts( stackmap_info: Option<&StackmapRequestInfo>, opts: Options, ) -> Result, RegAllocError> { - info!(""); - info!("================ regalloc.rs: BEGIN function ================"); + debug!(""); + debug!("================ regalloc.rs: BEGIN function ================"); - if log_enabled!(Level::Info) { - info!("with options: {:?}", opts); + if log_enabled!(Level::Debug) { + debug!("with options: {:?}", opts); let strs = rreg_universe.show(); - info!("using RealRegUniverse:"); + debug!("using RealRegUniverse:"); for s in strs { - info!(" {}", s); + debug!(" {}", s); } } @@ -599,7 +599,7 @@ pub fn allocate_registers_with_opts( } }; - info!("================ regalloc.rs: END function ================"); + debug!("================ regalloc.rs: END function ================"); res } diff --git a/lib/src/linear_scan/analysis.rs b/lib/src/linear_scan/analysis.rs index 1810e78..554fa45 100644 --- a/lib/src/linear_scan/analysis.rs +++ b/lib/src/linear_scan/analysis.rs @@ -13,7 +13,7 @@ use crate::{ union_find::UnionFind, AnalysisError, Function, RealRegUniverse, RegClass, StackmapRequestInfo, TypedIxVec, }; -use log::{debug, info, log_enabled, trace, Level}; +use log::{log_enabled, trace, Level}; use smallvec::{smallvec, SmallVec}; use std::{cmp::Ordering, fmt, mem}; @@ -138,7 +138,7 @@ pub(crate) fn run( reg_universe: &RealRegUniverse, stackmap_request: Option<&StackmapRequestInfo>, ) -> Result { - info!( + trace!( "run_analysis: begin: {} blocks, {} insns", func.blocks().len(), func.insns().len() @@ -148,12 +148,12 @@ pub(crate) fn run( // various reasons; we propagate the failure if so. Also create the InstIx-to-BlockIx map; // this isn't really control-flow analysis, but needs to be done at some point. - info!(" run_analysis: begin control flow analysis"); + trace!(" run_analysis: begin control flow analysis"); let cfg_info = CFGInfo::create(func)?; let inst_to_block_map = InstIxToBlockIxMap::new(func); - info!(" run_analysis: end control flow analysis"); + trace!(" run_analysis: end control flow analysis"); - info!(" run_analysis: begin data flow analysis"); + trace!(" run_analysis: begin data flow analysis"); // See `get_sanitized_reg_uses_for_func` for the meaning of "sanitized". let reg_vecs_and_bounds = get_sanitized_reg_uses_for_func(func, reg_universe) @@ -228,9 +228,9 @@ pub(crate) fn run( } } - info!(" run_analysis: end data flow analysis"); + trace!(" run_analysis: end data flow analysis"); - info!(" run_analysis: begin liveness analysis"); + trace!(" run_analysis: begin liveness analysis"); let (frag_ixs_per_reg, mut frag_env, frag_metrics_env, vreg_classes) = get_range_frags( func, ®_universe, @@ -250,7 +250,7 @@ pub(crate) fn run( &vreg_classes, stackmap_request.is_some(), )?; - info!(" run_analysis: end liveness analysis"); + trace!(" run_analysis: end liveness analysis"); // Make sure the fixed interval's fragment are sorted, to allow for binary search in misc // contexts. @@ -278,7 +278,7 @@ pub(crate) fn run( fixeds: fixed_intervals, }; - info!("run_analysis: end"); + trace!("run_analysis: end"); Ok(AnalysisInfo { cfg: cfg_info, @@ -339,9 +339,10 @@ impl<'a> ReftypeAnalysis for LsraReftypeAnalysis<'a> { fn insert_reffy_ranges(&self, vreg: VirtualReg, set: &mut SparseSet) { for vrange in &self.vreg_to_vranges[vreg.get_index()] { - debug!( + trace!( "range {:?} is reffy due to reffy vreg {:?}", - vrange.int, vreg + vrange.int, + vreg ); set.insert(RangeId::Virtual(vrange.int.0)); } @@ -652,7 +653,7 @@ fn get_range_frags( Vec, Vec, ) { - info!(" get_range_frags: begin"); + trace!(" get_range_frags: begin"); debug_assert!(liveins.len() == func.blocks().len() as u32); debug_assert!(liveouts.len() == func.blocks().len() as u32); debug_assert!(rvb.is_sanitized()); @@ -715,21 +716,21 @@ fn get_range_frags( assert!(state_elem.is_none()); } - if log_enabled!(Level::Debug) { - debug!(""); + if log_enabled!(Level::Trace) { + trace!(""); let mut n = 0; for frag in result_frags.iter() { - debug!("{:<3?} {:?}", RangeFragIx::new(n), frag); + trace!("{:<3?} {:?}", RangeFragIx::new(n), frag); n += 1; } - debug!(""); + trace!(""); for (reg_ix, frag_ixs) in result_map.iter().enumerate() { if frag_ixs.len() == 0 { continue; } let reg = reg_ix_to_reg(reg_universe, &vreg_classes, reg_ix as u32); - debug!( + trace!( "frags for {} {:?}", reg.show_with_rru(reg_universe), frag_ixs @@ -737,7 +738,7 @@ fn get_range_frags( } } - info!(" get_range_frags: end"); + trace!(" get_range_frags: end"); assert!(result_frags.len() == result_frag_metrics.len()); (result_map, result_frags, result_frag_metrics, vreg_classes) @@ -762,14 +763,14 @@ fn merge_range_frags( vreg_classes: &Vec, wants_stackmaps: bool, ) -> Result<(Vec, Vec, VirtualRegToRanges), AnalysisError> { - info!(" merge_range_frags: begin"); - if log_enabled!(Level::Info) { + trace!(" merge_range_frags: begin"); + if log_enabled!(Level::Trace) { let mut stats_num_total_incoming_frags = 0; for all_frag_ixs_for_reg in frag_ix_vec_per_reg.iter() { stats_num_total_incoming_frags += all_frag_ixs_for_reg.len(); } - info!(" in: {} in frag_env", frag_env.len()); - info!( + trace!(" in: {} in frag_env", frag_env.len()); + trace!( " in: {} regs containing in total {} frags", frag_ix_vec_per_reg.len(), stats_num_total_incoming_frags @@ -1031,7 +1032,7 @@ fn merge_range_frags( } } - info!(" merge_range_frags: end"); + trace!(" merge_range_frags: end"); Ok((result_fixed, result_virtual, vreg_to_vranges)) } diff --git a/lib/src/linear_scan/assign_registers.rs b/lib/src/linear_scan/assign_registers.rs index 1c471f5..4c28c49 100644 --- a/lib/src/linear_scan/assign_registers.rs +++ b/lib/src/linear_scan/assign_registers.rs @@ -204,7 +204,7 @@ pub(crate) fn run( let mut prev_start = InstPoint::min_value(); while let Some(id) = state.next_unhandled() { - info!("main loop: allocating {}", state.intervals.get(id)); + debug!("main loop: allocating {}", state.intervals.get(id)); #[cfg(debug_assertions)] { diff --git a/lib/src/linear_scan/mod.rs b/lib/src/linear_scan/mod.rs index f4eeaa0..7821376 100644 --- a/lib/src/linear_scan/mod.rs +++ b/lib/src/linear_scan/mod.rs @@ -4,7 +4,7 @@ //! Optimized Interval Splitting in a Linear Scan Register Allocator, //! by Wimmer et al., 2005 -use log::{info, log_enabled, trace, Level}; +use log::{log_enabled, trace, Level}; use std::env; use std::fmt; @@ -716,7 +716,7 @@ fn set_registers( stackmap_request: Option<&StackmapRequestInfo>, stackmaps: &[Vec], ) -> Result, CheckerErrors> { - info!("set_registers"); + trace!("set_registers"); let mut clobbered_registers = Set::empty(); @@ -885,7 +885,7 @@ fn apply_registers( use_checker: bool, stackmap_request: Option<&StackmapRequestInfo>, ) -> Result, RegAllocError> { - info!("apply_registers"); + trace!("apply_registers"); let stackmaps = compute_stackmaps(virtual_intervals, stackmap_request.clone()); diff --git a/lib/src/linear_scan/resolve_moves.rs b/lib/src/linear_scan/resolve_moves.rs index caf9ca7..f220600 100644 --- a/lib/src/linear_scan/resolve_moves.rs +++ b/lib/src/linear_scan/resolve_moves.rs @@ -477,7 +477,7 @@ pub(crate) fn run( spill_slot: &mut u32, scratches_by_rc: &[Option], ) -> Vec { - info!("resolve_moves"); + debug!("resolve_moves"); // Keep three lists of moves to insert: // - moves across blocks, that must happen at the start of blocks,