From 401bb38666ab2a2a7734e87bd753cb92f832e61d Mon Sep 17 00:00:00 2001 From: SingleAccretion Date: Fri, 10 Jan 2025 00:26:52 +0300 Subject: [PATCH] [DWARF] Add logging to range building --- cranelift/codegen/src/isa/aarch64/mod.rs | 5 ++ cranelift/codegen/src/isa/mod.rs | 7 +- .../codegen/src/isa/pulley_shared/mod.rs | 5 ++ cranelift/codegen/src/isa/riscv64/mod.rs | 6 ++ cranelift/codegen/src/isa/s390x/mod.rs | 5 ++ cranelift/codegen/src/isa/x64/mod.rs | 5 ++ .../transform/debug_transform_logging.rs | 86 ++++++++++++++++++- .../src/debug/transform/expression.rs | 83 ++++++++++++++++-- 8 files changed, 193 insertions(+), 9 deletions(-) diff --git a/cranelift/codegen/src/isa/aarch64/mod.rs b/cranelift/codegen/src/isa/aarch64/mod.rs index ce70f51e184f..6fd51a5cc9ea 100644 --- a/cranelift/codegen/src/isa/aarch64/mod.rs +++ b/cranelift/codegen/src/isa/aarch64/mod.rs @@ -15,6 +15,7 @@ use crate::settings as shared_settings; use alloc::{boxed::Box, vec::Vec}; use core::fmt; use cranelift_control::ControlPlane; +use std::string::String; use target_lexicon::{Aarch64Architecture, Architecture, OperatingSystem, Triple}; // New backend: @@ -214,6 +215,10 @@ impl TargetIsa for AArch64Backend { Ok(cs) } + fn pretty_print_reg(&self, reg: Reg, _size: u8) -> String { + inst::regs::pretty_print_reg(reg) + } + fn has_native_fma(&self) -> bool { true } diff --git a/cranelift/codegen/src/isa/mod.rs b/cranelift/codegen/src/isa/mod.rs index ba9b5ab3f3f7..76a9ec51c7b1 100644 --- a/cranelift/codegen/src/isa/mod.rs +++ b/cranelift/codegen/src/isa/mod.rs @@ -46,7 +46,6 @@ use crate::dominator_tree::DominatorTree; pub use crate::isa::call_conv::CallConv; -use crate::flowgraph; use crate::ir::{self, Function, Type}; #[cfg(feature = "unwind")] use crate::isa::unwind::{systemv::RegisterMappingError, UnwindInfoKind}; @@ -55,10 +54,12 @@ use crate::settings; use crate::settings::Configurable; use crate::settings::SetResult; use crate::CodegenResult; +use crate::{flowgraph, Reg}; use alloc::{boxed::Box, sync::Arc, vec::Vec}; use core::fmt; use core::fmt::{Debug, Formatter}; use cranelift_control::ControlPlane; +use std::string::String; use target_lexicon::{triple, Architecture, PointerWidth, Triple}; // This module is made public here for benchmarking purposes. No guarantees are @@ -373,6 +374,10 @@ pub trait TargetIsa: fmt::Display + Send + Sync { Err(capstone::Error::UnsupportedArch) } + /// Return the string representation of "reg" accessed as "size" bytes. + /// The returned string will match the usual disassemly view of "reg". + fn pretty_print_reg(&self, reg: Reg, size: u8) -> String; + /// Returns whether this ISA has a native fused-multiply-and-add instruction /// for floats. /// diff --git a/cranelift/codegen/src/isa/pulley_shared/mod.rs b/cranelift/codegen/src/isa/pulley_shared/mod.rs index 16aba8304e72..4257fe2e674a 100644 --- a/cranelift/codegen/src/isa/pulley_shared/mod.rs +++ b/cranelift/codegen/src/isa/pulley_shared/mod.rs @@ -21,6 +21,7 @@ use alloc::vec::Vec; use core::fmt::Debug; use core::marker::PhantomData; use cranelift_control::ControlPlane; +use std::string::String; use target_lexicon::{Architecture, Triple}; pub use settings::Flags as PulleyFlags; @@ -215,6 +216,10 @@ where inst::InstAndKind::

::function_alignment() } + fn pretty_print_reg(&self, reg: crate::Reg, _size: u8) -> String { + format!("{reg:?}") + } + fn has_native_fma(&self) -> bool { false } diff --git a/cranelift/codegen/src/isa/riscv64/mod.rs b/cranelift/codegen/src/isa/riscv64/mod.rs index 0035a721048c..ccd5affb6c94 100644 --- a/cranelift/codegen/src/isa/riscv64/mod.rs +++ b/cranelift/codegen/src/isa/riscv64/mod.rs @@ -14,6 +14,7 @@ use crate::{ir, CodegenError}; use alloc::{boxed::Box, vec::Vec}; use core::fmt; use cranelift_control::ControlPlane; +use std::string::String; use target_lexicon::{Architecture, Triple}; mod abi; pub(crate) mod inst; @@ -191,6 +192,11 @@ impl TargetIsa for Riscv64Backend { Ok(cs) } + fn pretty_print_reg(&self, reg: Reg, _size: u8) -> String { + // TODO-RISC-V: implement proper register pretty-printing. + format!("{reg:?}") + } + fn has_native_fma(&self) -> bool { true } diff --git a/cranelift/codegen/src/isa/s390x/mod.rs b/cranelift/codegen/src/isa/s390x/mod.rs index 842cc4cdf11e..86227f928b8d 100644 --- a/cranelift/codegen/src/isa/s390x/mod.rs +++ b/cranelift/codegen/src/isa/s390x/mod.rs @@ -15,6 +15,7 @@ use crate::settings as shared_settings; use alloc::{boxed::Box, vec::Vec}; use core::fmt; use cranelift_control::ControlPlane; +use std::string::String; use target_lexicon::{Architecture, Triple}; // New backend: @@ -174,6 +175,10 @@ impl TargetIsa for S390xBackend { Ok(cs) } + fn pretty_print_reg(&self, reg: Reg, _size: u8) -> String { + inst::regs::pretty_print_reg(reg) + } + fn has_native_fma(&self) -> bool { true } diff --git a/cranelift/codegen/src/isa/x64/mod.rs b/cranelift/codegen/src/isa/x64/mod.rs index 7545a6f14835..63467aa71daa 100644 --- a/cranelift/codegen/src/isa/x64/mod.rs +++ b/cranelift/codegen/src/isa/x64/mod.rs @@ -19,6 +19,7 @@ use crate::{Final, MachBufferFinalized}; use alloc::{boxed::Box, vec::Vec}; use core::fmt; use cranelift_control::ControlPlane; +use std::string::String; use target_lexicon::Triple; mod abi; @@ -158,6 +159,10 @@ impl TargetIsa for X64Backend { .build() } + fn pretty_print_reg(&self, reg: Reg, size: u8) -> String { + inst::regs::pretty_print_reg(reg, size) + } + fn has_native_fma(&self) -> bool { self.x64_flags.use_fma() } diff --git a/crates/cranelift/src/debug/transform/debug_transform_logging.rs b/crates/cranelift/src/debug/transform/debug_transform_logging.rs index 1a56eb70a1bc..e725ab50cb2b 100644 --- a/crates/cranelift/src/debug/transform/debug_transform_logging.rs +++ b/crates/cranelift/src/debug/transform/debug_transform_logging.rs @@ -1,10 +1,17 @@ -use crate::debug::Reader; +use crate::{debug::Reader, translate::get_vmctx_value_label}; use core::fmt; +use cranelift_codegen::{ir::ValueLabel, isa::TargetIsa, LabelValueLoc, ValueLabelsRanges}; use gimli::{ write, AttributeValue, DebuggingInformationEntry, Dwarf, LittleEndian, Unit, UnitOffset, UnitSectionOffset, }; +macro_rules! dbi_log_enabled { + () => { + cfg!(any(feature = "trace-log", debug_assertions)) + && ::log::log_enabled!(target: "debug-info-transform", ::log::Level::Trace) + }; +} macro_rules! dbi_log { ($($tt:tt)*) => { if cfg!(any(feature = "trace-log", debug_assertions)) { @@ -13,6 +20,7 @@ macro_rules! dbi_log { }; } pub(crate) use dbi_log; +pub(crate) use dbi_log_enabled; pub struct CompileUnitSummary<'a> { unit: &'a Unit, usize>, @@ -274,3 +282,79 @@ fn get_offset_value(offset: UnitSectionOffset) -> usize { UnitSectionOffset::DebugTypesOffset(offs) => offs.0, } } + +pub fn log_get_value_name(value: ValueLabel) -> ValueNameSummary { + ValueNameSummary { value } +} + +pub struct ValueNameSummary { + value: ValueLabel, +} + +impl fmt::Debug for ValueNameSummary { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + if self.value == get_vmctx_value_label() { + f.pad("VMCTX") + } else { + f.pad(&format!("L#{}", self.value.as_u32())) + } + } +} + +pub fn log_get_value_loc(loc: LabelValueLoc, isa: &dyn TargetIsa) -> ValueLocSummary { + ValueLocSummary { loc, isa } +} + +pub struct ValueLocSummary<'a> { + loc: LabelValueLoc, + isa: &'a dyn TargetIsa, +} + +impl<'a> fmt::Debug for ValueLocSummary<'a> { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + if let LabelValueLoc::Reg(reg) = self.loc { + let reg_name = self.isa.pretty_print_reg(reg, self.isa.pointer_bytes()); + return write!(f, "{reg_name}"); + } + + write!(f, "{:?}", self.loc) + } +} + +pub fn log_get_value_ranges<'a>( + ranges: Option<&'a ValueLabelsRanges>, + isa: &'a dyn TargetIsa, +) -> ValueRangesSummary<'a> { + ValueRangesSummary { ranges, isa } +} + +pub struct ValueRangesSummary<'a> { + ranges: Option<&'a ValueLabelsRanges>, + isa: &'a dyn TargetIsa, +} + +impl<'a> fmt::Debug for ValueRangesSummary<'a> { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + if let Some(ranges) = self.ranges { + // Sort the output first for nicer display. + let mut locals = Vec::new(); + for value in ranges { + locals.push(*value.0); + } + locals.sort_by_key(|n| n.as_u32()); + + for i in 0..locals.len() { + let name = locals[i]; + write!(f, "{:<6?}:", log_get_value_name(name))?; + for range in ranges.get(&name).unwrap() { + write!(f, " {:?}", log_get_value_loc(range.loc, self.isa))?; + write!(f, "@[{}..{})", range.start, range.end)?; + } + if i != locals.len() - 1 { + writeln!(f)?; + } + } + } + Ok(()) + } +} diff --git a/crates/cranelift/src/debug/transform/expression.rs b/crates/cranelift/src/debug/transform/expression.rs index 6a5f0973efa3..ebe1b41e46f9 100644 --- a/crates/cranelift/src/debug/transform/expression.rs +++ b/crates/cranelift/src/debug/transform/expression.rs @@ -1,12 +1,18 @@ use super::address_transform::AddressTransform; +use super::dbi_log; +use crate::debug::transform::debug_transform_logging::{ + dbi_log_enabled, log_get_value_loc, log_get_value_name, log_get_value_ranges, +}; use crate::debug::ModuleMemoryOffset; use crate::translate::get_vmctx_value_label; use anyhow::{Context, Error, Result}; +use core::fmt; use cranelift_codegen::ir::ValueLabel; use cranelift_codegen::isa::TargetIsa; use cranelift_codegen::LabelValueLoc; use cranelift_codegen::ValueLabelsRanges; use gimli::{write, Expression, Operation, Reader, ReaderOffset}; +use itertools::Itertools; use std::cmp::PartialEq; use std::collections::{HashMap, HashSet}; use std::hash::{Hash, Hasher}; @@ -296,7 +302,7 @@ impl CompiledExpression { // Some locals are present, preparing and divided ranges based on the scope // and frame_info data. - let mut ranges_builder = ValueLabelRangesBuilder::new(scope, addr_tr, frame_info); + let mut ranges_builder = ValueLabelRangesBuilder::new(scope, addr_tr, frame_info, isa); for p in self.parts.iter() { match p { CompiledExpressionPart::Code(_) @@ -651,7 +657,36 @@ struct CachedValueLabelRange { label_location: HashMap, } +struct BuiltRangeSummary<'a> { + range: &'a CachedValueLabelRange, + isa: &'a dyn TargetIsa, +} + +impl<'a> fmt::Debug for BuiltRangeSummary<'a> { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + let range = self.range; + write!(f, "[")?; + let mut is_first = true; + for (value, value_loc) in &range.label_location { + if !is_first { + write!(f, ", ")?; + } else { + is_first = false; + } + write!( + f, + "{:?}:{:?}", + log_get_value_name(*value), + log_get_value_loc(*value_loc, self.isa) + )?; + } + write!(f, "]@[{}..{})", range.start, range.end)?; + Ok(()) + } +} + struct ValueLabelRangesBuilder<'a, 'b> { + isa: &'a dyn TargetIsa, ranges: Vec, frame_info: Option<&'a FunctionFrameInfo<'b>>, processed_labels: HashSet, @@ -662,6 +697,7 @@ impl<'a, 'b> ValueLabelRangesBuilder<'a, 'b> { scope: &[(u64, u64)], // wasm ranges addr_tr: &'a AddressTransform, frame_info: Option<&'a FunctionFrameInfo<'b>>, + isa: &'a dyn TargetIsa, ) -> Self { let mut ranges = Vec::new(); for (wasm_start, wasm_end) in scope { @@ -675,7 +711,17 @@ impl<'a, 'b> ValueLabelRangesBuilder<'a, 'b> { } } ranges.sort_unstable_by(|a, b| a.start.cmp(&b.start)); + + dbi_log!( + "Building ranges for values in scope: {}\n{:?}", + ranges + .iter() + .map(|r| format!("[{}..{})", r.start, r.end)) + .join(" "), + log_get_value_ranges(frame_info.map(|f| f.value_ranges), isa) + ); ValueLabelRangesBuilder { + isa, ranges, frame_info, processed_labels: HashSet::new(), @@ -686,6 +732,7 @@ impl<'a, 'b> ValueLabelRangesBuilder<'a, 'b> { if self.processed_labels.contains(&label) { return; } + dbi_log!("Intersecting with {:?}", log_get_value_name(label)); self.processed_labels.insert(label); let value_ranges = match self.frame_info.and_then(|fi| fi.value_ranges.get(&label)) { @@ -750,9 +797,23 @@ impl<'a, 'b> ValueLabelRangesBuilder<'a, 'b> { pub fn into_ranges(self) -> impl Iterator { // Ranges with not-enough labels are discarded. let processed_labels_len = self.processed_labels.len(); - self.ranges - .into_iter() - .filter(move |r| r.label_location.len() == processed_labels_len) + let is_valid_range = + move |r: &CachedValueLabelRange| r.label_location.len() == processed_labels_len; + + if dbi_log_enabled!() { + dbi_log!("Built ranges:"); + for range in self.ranges.iter().filter(|r| is_valid_range(*r)) { + dbi_log!( + "{:?}", + BuiltRangeSummary { + range, + isa: self.isa + } + ); + } + dbi_log!(""); + } + self.ranges.into_iter().filter(is_valid_range) } } @@ -801,7 +862,9 @@ mod tests { FunctionFrameInfo, JumpTargetMarker, ValueLabel, ValueLabelsRanges, }; use crate::CompiledFunctionMetadata; + use cranelift_codegen::{isa::lookup, settings::Flags}; use gimli::{constants, Encoding, EndianSlice, Expression, RunTimeEndian}; + use target_lexicon::triple; use wasmtime_environ::FilePos; macro_rules! dw_op { @@ -1222,6 +1285,10 @@ mod tests { use super::ValueLabelRangesBuilder; use crate::debug::ModuleMemoryOffset; + let isa = lookup(triple!("x86_64")) + .expect("expect x86_64 ISA") + .finish(Flags::new(cranelift_codegen::settings::builder())) + .expect("Creating ISA"); let addr_tr = create_mock_address_transform(); let (value_ranges, value_labels) = create_mock_value_ranges(); let fi = FunctionFrameInfo { @@ -1230,7 +1297,7 @@ mod tests { }; // No value labels, testing if entire function range coming through. - let builder = ValueLabelRangesBuilder::new(&[(10, 20)], &addr_tr, Some(&fi)); + let builder = ValueLabelRangesBuilder::new(&[(10, 20)], &addr_tr, Some(&fi), isa.as_ref()); let ranges = builder.into_ranges().collect::>(); assert_eq!(ranges.len(), 1); assert_eq!(ranges[0].func_index, 0); @@ -1238,7 +1305,8 @@ mod tests { assert_eq!(ranges[0].end, 30); // Two labels (val0@0..25 and val1@5..30), their common lifetime intersect at 5..25. - let mut builder = ValueLabelRangesBuilder::new(&[(10, 20)], &addr_tr, Some(&fi)); + let mut builder = + ValueLabelRangesBuilder::new(&[(10, 20)], &addr_tr, Some(&fi), isa.as_ref()); builder.process_label(value_labels.0); builder.process_label(value_labels.1); let ranges = builder.into_ranges().collect::>(); @@ -1248,7 +1316,8 @@ mod tests { // Adds val2 with complex lifetime @0..10 and @20..30 to the previous test, and // also narrows range. - let mut builder = ValueLabelRangesBuilder::new(&[(11, 17)], &addr_tr, Some(&fi)); + let mut builder = + ValueLabelRangesBuilder::new(&[(11, 17)], &addr_tr, Some(&fi), isa.as_ref()); builder.process_label(value_labels.0); builder.process_label(value_labels.1); builder.process_label(value_labels.2);