Skip to content

Commit 3da7fc8

Browse files
[DI] Dump value label assignments in a table (#10549)
* Dump compilation start/end * [DI] Log value label ranges in a table Sample table: |Inst |IP |VL0 |VL1 |VL3 |VL4 |VL5 |VL7 |VL10 |VL11 |VL4294967294| |--------|----|--------|---------|---------|--------|--------|--------|---------|--------|------------| |Inst 0 |53 | | | | | | | | | | | | | | | | | | | |Inst 1 |53 | | | | | | | | | | | | | | | | | | | |Inst 2 |60 |v194|p2i|v232|p12i| | | | | | | | | | | | |v192|p7i | |Inst 3 |64 |* |p2i|* |p12i|v231|p13i| | | | | | | | | | |* |p7i | |Inst 4 |68 |* |p2i|* |p12i|* |p13i| | | | | | | | | | |* |p7i | |Inst 5 |72 |* |p2i|* |p12i|* |p13i| | | | | | | | | | |* |p7i | |Inst 6 |76 |* |p2i|* |p12i|* |p13i| | | | | | | | | | |* |p7i | |Inst 7 |87 |* | |* |p12i|* |p13i| | | | | | | | | | |* |p7i | |Inst 8 |92 |* | |* |p12i|* |p13i|v227|p0i| | | | | | | | |* |p15i | |Inst 9 |94 |* | |v204| |v204| |v204| |v204| |v204| |v204| |v204| |* |p15i | |Inst 10 |100 |* | |* | |* | |* | |* | |* | |* | |* | |* |p15i | |Inst 11 |105 |* | |* | |* | |* | |v226|p9i|* | |* | |* | |* |p15i | |Inst 12 |109 |* | |* | |* | |* | |* | |v225|p9i|* | |* | |* |p15i | |Inst 13 |114 |* | |* | |* | |* | |* | |* | |* | |* | |* |p15i | |Inst 14 |119 |* | |* | |* | |* | |* | |* | |* | |* | |* |p15i | |Inst 15 |125 |* | |* | |* | |* | |* | |* | |* | |* | |* |p15i | |Inst 16 |129 |* | |* | |* | |* | |* | |* | |v223|p11i|* | |* |p15i | |Inst 17 |134 |* | |* | |* | |* | |* | |* | |* | |* | |* |p15i | |Inst 18 |134 |* | |* | |* | |* | |* | |* | |* | |* | |* |p15i | |Inst 19 |139 |* | |* | |* | |* | |* | |* | |* | |v222|p0i|* |p15i | |Inst 20 |143 |* | |* | |* | |* | |* | |* | |* | |* |p0i|* |p15i | |Inst 21 |143 |* | |* | |* | |* | |* | |* | |* | |* |p0i|* | | This will make it much easier to diagnose problems with incomplete/missing live ranges.
1 parent 7bf3172 commit 3da7fc8

File tree

6 files changed

+250
-21
lines changed

6 files changed

+250
-21
lines changed

cranelift/codegen/src/context.rs

Lines changed: 11 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -129,13 +129,17 @@ impl Context {
129129
isa: &dyn TargetIsa,
130130
ctrl_plane: &mut ControlPlane,
131131
) -> CodegenResult<CompiledCodeStencil> {
132-
let _tt = timing::compile();
133-
134-
self.verify_if(isa)?;
135-
136-
self.optimize(isa, ctrl_plane)?;
137-
138-
isa.compile_function(&self.func, &self.domtree, self.want_disasm, ctrl_plane)
132+
let result;
133+
trace!("****** START compiling {}", self.func.display_spec());
134+
{
135+
let _tt = timing::compile();
136+
137+
self.verify_if(isa)?;
138+
self.optimize(isa, ctrl_plane)?;
139+
result = isa.compile_function(&self.func, &self.domtree, self.want_disasm, ctrl_plane);
140+
}
141+
trace!("****** DONE compiling {}\n", self.func.display_spec());
142+
result
139143
}
140144

141145
/// Optimize the function, performing all compilation steps up to

cranelift/codegen/src/ir/function.rs

Lines changed: 21 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,7 @@ use crate::ir::{
1111
StackSlot, StackSlotData, StackSlots, Type,
1212
};
1313
use crate::isa::CallConv;
14-
use crate::write::write_function;
14+
use crate::write::{write_function, write_function_spec};
1515
use crate::HashMap;
1616
#[cfg(feature = "enable-serde")]
1717
use alloc::string::String;
@@ -447,6 +447,11 @@ impl Function {
447447
DisplayFunction(self)
448448
}
449449

450+
/// Return an object that can display this function's name and signature.
451+
pub fn display_spec(&self) -> DisplayFunctionSpec<'_> {
452+
DisplayFunctionSpec(self)
453+
}
454+
450455
/// Sets an absolute source location for the given instruction.
451456
///
452457
/// If no base source location has been set yet, records it at the same time.
@@ -495,3 +500,18 @@ impl fmt::Debug for Function {
495500
write_function(fmt, self)
496501
}
497502
}
503+
504+
/// Wrapper type capable of displaying a 'Function's name and signature.
505+
pub struct DisplayFunctionSpec<'a>(&'a Function);
506+
507+
impl<'a> fmt::Display for DisplayFunctionSpec<'a> {
508+
fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
509+
write_function_spec(fmt, self.0)
510+
}
511+
}
512+
513+
impl<'a> fmt::Debug for DisplayFunctionSpec<'a> {
514+
fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
515+
write_function_spec(fmt, self.0)
516+
}
517+
}

cranelift/codegen/src/ir/mod.rs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -85,7 +85,7 @@ pub(crate) type SourceLocs = SecondaryMap<Inst, RelSourceLoc>;
8585
#[derive(Copy, Clone, PartialEq, Eq, Hash)]
8686
#[cfg_attr(feature = "enable-serde", derive(Serialize, Deserialize))]
8787
pub struct ValueLabel(u32);
88-
entity_impl!(ValueLabel, "val");
88+
entity_impl!(ValueLabel, "VL");
8989

9090
/// A label of a Value.
9191
#[derive(Debug, Clone, PartialEq, Hash)]

cranelift/codegen/src/lib.rs

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -104,4 +104,13 @@ macro_rules! trace {
104104
};
105105
}
106106

107+
/// Dynamic check for whether trace logging is enabled.
108+
#[macro_export]
109+
macro_rules! trace_log_enabled {
110+
() => {
111+
cfg!(any(feature = "trace-log", debug_assertions))
112+
&& ::log::log_enabled!(::log::Level::Trace)
113+
};
114+
}
115+
107116
include!(concat!(env!("OUT_DIR"), "/version.rs"));

cranelift/codegen/src/machinst/vcode.rs

Lines changed: 205 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -19,23 +19,24 @@
1919
2020
use crate::ir::pcc::*;
2121
use crate::ir::{self, types, Constant, ConstantData, ValueLabel};
22-
use crate::machinst::*;
2322
use crate::ranges::Ranges;
2423
use crate::timing;
2524
use crate::trace;
2625
use crate::CodegenError;
26+
use crate::{machinst::*, trace_log_enabled};
2727
use crate::{LabelValueLoc, ValueLocRange};
2828
use regalloc2::{
2929
Edit, Function as RegallocFunction, InstOrEdit, InstRange, MachineEnv, Operand,
3030
OperandConstraint, OperandKind, PRegSet, RegClass,
3131
};
3232
use rustc_hash::FxHashMap;
3333

34+
use core::cmp::Ordering;
35+
use core::fmt::{self, Write};
3436
use core::mem::take;
3537
use cranelift_entity::{entity_impl, Keys};
3638
use std::collections::hash_map::Entry;
3739
use std::collections::HashMap;
38-
use std::fmt;
3940

4041
/// Index referring to an instruction in VCode.
4142
pub type InsnIndex = regalloc2::Inst;
@@ -731,9 +732,6 @@ impl<I: VCodeInst> VCode<I> {
731732
where
732733
I: VCodeInst,
733734
{
734-
// To write into disasm string.
735-
use core::fmt::Write;
736-
737735
let _tt = timing::vcode_emit();
738736
let mut buffer = MachBuffer::new();
739737
buffer.set_log2_min_function_alignment(self.log2_min_function_alignment);
@@ -1157,11 +1155,14 @@ impl<I: VCodeInst> VCode<I> {
11571155
return ValueLabelsRanges::default();
11581156
}
11591157

1158+
if trace_log_enabled!() {
1159+
self.log_value_labels_ranges(regalloc, inst_offsets);
1160+
}
1161+
11601162
let mut value_labels_ranges: ValueLabelsRanges = HashMap::new();
11611163
for &(label, from, to, alloc) in &regalloc.debug_locations {
1162-
let ranges = value_labels_ranges
1163-
.entry(ValueLabel::from_u32(label))
1164-
.or_insert_with(|| vec![]);
1164+
let label = ValueLabel::from_u32(label);
1165+
let ranges = value_labels_ranges.entry(label).or_insert_with(|| vec![]);
11651166
let from_offset = inst_offsets[from.inst().index()];
11661167
let to_offset = if to.inst().index() == inst_offsets.len() {
11671168
func_body_len
@@ -1214,7 +1215,7 @@ impl<I: VCodeInst> VCode<I> {
12141215
if let Some(last_loc_range) = ranges.last_mut() {
12151216
if last_loc_range.loc == loc && last_loc_range.end == start {
12161217
trace!(
1217-
"Extending debug range for VL{} in {:?} to {}",
1218+
"Extending debug range for {:?} in {:?} to {}",
12181219
label,
12191220
loc,
12201221
end
@@ -1225,7 +1226,7 @@ impl<I: VCodeInst> VCode<I> {
12251226
}
12261227

12271228
trace!(
1228-
"Recording debug range for VL{} in {:?}: [Inst {}..Inst {}) [{}..{})",
1229+
"Recording debug range for {:?} in {:?}: [Inst {}..Inst {}) [{}..{})",
12291230
label,
12301231
loc,
12311232
from.inst().index(),
@@ -1240,6 +1241,200 @@ impl<I: VCodeInst> VCode<I> {
12401241
value_labels_ranges
12411242
}
12421243

1244+
fn log_value_labels_ranges(&self, regalloc: &regalloc2::Output, inst_offsets: &[CodeOffset]) {
1245+
debug_assert!(trace_log_enabled!());
1246+
1247+
// What debug labels do we have? Note we'll skip those that have not been
1248+
// allocated any location at all. They will show up as numeric gaps in the table.
1249+
let mut labels = vec![];
1250+
for &(label, _, _, _) in &regalloc.debug_locations {
1251+
if Some(&label) == labels.last() {
1252+
continue;
1253+
}
1254+
labels.push(label);
1255+
}
1256+
1257+
// Reformat the data on what VRegs were the VLs assigned to by lowering, since
1258+
// the array we have is sorted by VReg, and we want it sorted by VL for easy
1259+
// access in the loop below.
1260+
let mut vregs = vec![];
1261+
for &(vreg, start, end, label) in &self.debug_value_labels {
1262+
if matches!(labels.binary_search(&label), Ok(_)) {
1263+
vregs.push((label, start, end, vreg));
1264+
}
1265+
}
1266+
vregs.sort_unstable_by(
1267+
|(l_label, l_start, _, _), (r_label, r_start, _, _)| match l_label.cmp(r_label) {
1268+
Ordering::Equal => l_start.cmp(r_start),
1269+
cmp => cmp,
1270+
},
1271+
);
1272+
1273+
#[derive(PartialEq)]
1274+
enum Mode {
1275+
Measure,
1276+
Emit,
1277+
}
1278+
#[derive(PartialEq)]
1279+
enum Row {
1280+
Head,
1281+
Line,
1282+
Inst(usize),
1283+
}
1284+
1285+
let mut widths = vec![0; 2 + 2 * labels.len()];
1286+
let mut row = String::new();
1287+
let mut output_row = |row_kind: Row, mode: Mode| {
1288+
let mut column_index = 0;
1289+
row.clear();
1290+
1291+
macro_rules! output_cell_impl {
1292+
($fill:literal, $span:literal, $($cell_fmt:tt)*) => {
1293+
let column_start = row.len();
1294+
{
1295+
row.push('|');
1296+
write!(row, $($cell_fmt)*).unwrap();
1297+
}
1298+
1299+
let next_column_index = column_index + $span;
1300+
let expected_width: usize = widths[column_index..next_column_index].iter().sum();
1301+
if mode == Mode::Measure {
1302+
let actual_width = row.len() - column_start;
1303+
if actual_width > expected_width {
1304+
widths[next_column_index - 1] += actual_width - expected_width;
1305+
}
1306+
} else {
1307+
let column_end = column_start + expected_width;
1308+
while row.len() != column_end {
1309+
row.push($fill);
1310+
}
1311+
}
1312+
column_index = next_column_index;
1313+
};
1314+
}
1315+
macro_rules! output_cell {
1316+
($($cell_fmt:tt)*) => {
1317+
output_cell_impl!(' ', 1, $($cell_fmt)*);
1318+
};
1319+
}
1320+
1321+
match row_kind {
1322+
Row::Head => {
1323+
output_cell!("Inst");
1324+
output_cell!("IP");
1325+
for label in &labels {
1326+
output_cell_impl!(' ', 2, "{:?}", ValueLabel::from_u32(*label));
1327+
}
1328+
}
1329+
Row::Line => {
1330+
debug_assert!(mode == Mode::Emit);
1331+
output_cell_impl!('-', 1, "");
1332+
output_cell_impl!('-', 1, "");
1333+
for _ in &labels {
1334+
output_cell_impl!('-', 2, "");
1335+
}
1336+
}
1337+
Row::Inst(inst_index) => {
1338+
output_cell!("Inst {inst_index} ");
1339+
output_cell!("{} ", inst_offsets[inst_index]);
1340+
1341+
// The ranges which we query below operate on the logic of
1342+
// "IP(inst) == IP after inst", while the rows of our table
1343+
// represent IPs 'before' "inst", so we need to convert "inst"
1344+
// into these "IP after" coordinates.
1345+
let inst_ip_index = inst_index.wrapping_sub(1);
1346+
for label in &labels {
1347+
// First, the VReg.
1348+
use regalloc2::Inst;
1349+
let vreg_cmp = |inst: usize,
1350+
vreg_label: &u32,
1351+
range_start: &Inst,
1352+
range_end: &Inst| {
1353+
match vreg_label.cmp(&label) {
1354+
Ordering::Equal => {
1355+
if range_end.index() <= inst {
1356+
Ordering::Less
1357+
} else if range_start.index() > inst {
1358+
Ordering::Greater
1359+
} else {
1360+
Ordering::Equal
1361+
}
1362+
}
1363+
cmp => cmp,
1364+
}
1365+
};
1366+
let vreg_index =
1367+
vregs.binary_search_by(|(l, s, e, _)| vreg_cmp(inst_ip_index, l, s, e));
1368+
if let Ok(vreg_index) = vreg_index {
1369+
let mut prev_vreg = None;
1370+
if inst_ip_index > 0 {
1371+
let prev_vreg_index = vregs.binary_search_by(|(l, s, e, _)| {
1372+
vreg_cmp(inst_ip_index - 1, l, s, e)
1373+
});
1374+
if let Ok(prev_vreg_index) = prev_vreg_index {
1375+
prev_vreg = Some(vregs[prev_vreg_index].3);
1376+
}
1377+
}
1378+
1379+
let vreg = vregs[vreg_index].3;
1380+
if Some(vreg) == prev_vreg {
1381+
output_cell!("*");
1382+
} else {
1383+
output_cell!("{}", vreg);
1384+
}
1385+
} else {
1386+
output_cell!("");
1387+
}
1388+
1389+
// Second, the allocated location.
1390+
let range_index = regalloc.debug_locations.binary_search_by(
1391+
|(range_label, range_start, range_end, _)| match range_label.cmp(label)
1392+
{
1393+
Ordering::Equal => {
1394+
if range_end.inst().index() <= inst_ip_index {
1395+
Ordering::Less
1396+
} else if range_start.inst().index() > inst_ip_index {
1397+
Ordering::Greater
1398+
} else {
1399+
Ordering::Equal
1400+
}
1401+
}
1402+
cmp => cmp,
1403+
},
1404+
);
1405+
if let Ok(range_index) = range_index {
1406+
// Live at this instruction, print the location.
1407+
if let Some(reg) = regalloc.debug_locations[range_index].3.as_reg() {
1408+
output_cell!("{:?}", Reg::from(reg));
1409+
} else {
1410+
output_cell!("Stk");
1411+
}
1412+
} else {
1413+
// Not live at this instruction.
1414+
output_cell!("");
1415+
}
1416+
}
1417+
}
1418+
}
1419+
row.push('|');
1420+
1421+
if mode == Mode::Emit {
1422+
trace!("{}", row.as_str());
1423+
}
1424+
};
1425+
1426+
for inst_index in 0..inst_offsets.len() {
1427+
output_row(Row::Inst(inst_index), Mode::Measure);
1428+
}
1429+
output_row(Row::Head, Mode::Measure);
1430+
1431+
output_row(Row::Head, Mode::Emit);
1432+
output_row(Row::Line, Mode::Emit);
1433+
for inst_index in 0..inst_offsets.len() {
1434+
output_row(Row::Inst(inst_index), Mode::Emit);
1435+
}
1436+
}
1437+
12431438
/// Get the IR block for a BlockIndex, if one exists.
12441439
pub fn bindex_to_bb(&self, block: BlockIndex) -> Option<ir::Block> {
12451440
self.block_order.lowered_order()[block.index()].orig_block()

cranelift/codegen/src/write.rs

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -180,7 +180,7 @@ pub fn decorate_function<FW: FuncWriter>(
180180
func: &Function,
181181
) -> fmt::Result {
182182
write!(w, "function ")?;
183-
write_spec(w, func)?;
183+
write_function_spec(w, func)?;
184184
writeln!(w, " {{")?;
185185
let aliases = alias_map(func);
186186
let mut any = func_w.write_preamble(w, func)?;
@@ -198,7 +198,8 @@ pub fn decorate_function<FW: FuncWriter>(
198198
//
199199
// Function spec.
200200

201-
fn write_spec(w: &mut dyn Write, func: &Function) -> fmt::Result {
201+
/// Writes the spec (name and signature) of 'func' to 'w' as text.
202+
pub fn write_function_spec(w: &mut dyn Write, func: &Function) -> fmt::Result {
202203
write!(w, "{}{}", func.name, func.signature)
203204
}
204205

0 commit comments

Comments
 (0)