From 2ad160b2f94dceb663b6adb17a66a6f7f09863df Mon Sep 17 00:00:00 2001 From: Ben Kimock Date: Sat, 12 Mar 2022 17:23:22 -0500 Subject: [PATCH] Print spans where tags are created and invalidated --- src/diagnostics.rs | 39 ++++++- src/eval.rs | 21 ++++ src/helpers.rs | 9 ++ src/stacked_borrows.rs | 228 ++++++++++++++++++++++++++++++++++------- 4 files changed, 257 insertions(+), 40 deletions(-) diff --git a/src/diagnostics.rs b/src/diagnostics.rs index 0815d73d9b..c5dbe4dd95 100644 --- a/src/diagnostics.rs +++ b/src/diagnostics.rs @@ -7,9 +7,11 @@ use log::trace; use rustc_middle::ty; use rustc_span::{source_map::DUMMY_SP, Span, SpanData, Symbol}; -use crate::stacked_borrows::{AccessKind, SbTag}; +use crate::stacked_borrows::{AccessKind, SbTag, TagHistory}; +use crate::helpers::HexRange; use crate::*; + /// Details of premature program termination. pub enum TerminationInfo { Exit(i64), @@ -19,6 +21,7 @@ pub enum TerminationInfo { msg: String, help: Option, url: String, + history: Option, }, Deadlock, MultipleSymbolDefinitions { @@ -155,12 +158,38 @@ pub fn report_error<'tcx, 'mir>( (None, format!("pass the flag `-Zmiri-disable-isolation` to disable isolation;")), (None, format!("or pass `-Zmiri-isolation-error=warn` to configure Miri to return an error code from isolated operations (if supported for that operation) and continue with a warning")), ], - ExperimentalUb { url, help, .. } => { + ExperimentalUb { url, help, history, .. } => { msg.extend(help.clone()); - vec![ + let mut helps = vec![ (None, format!("this indicates a potential bug in the program: it performed an invalid operation, but the rules it violated are still experimental")), - (None, format!("see {} for further information", url)) - ] + (None, format!("see {} for further information", url)), + ]; + match history { + Some(TagHistory::Tagged {tag, created: (created_range, created_span), invalidated}) => { + let msg = format!("{:?} was created due to a retag at offsets {}", tag, HexRange(*created_range)); + helps.push((Some(created_span.clone()), msg)); + if let Some((invalidated_range, invalidated_span)) = invalidated { + let msg = format!("{:?} was later invalidated due to a retag at offsets {}", tag, HexRange(*invalidated_range)); + helps.push((Some(invalidated_span.clone()), msg)); + } + } + Some(TagHistory::Untagged{ recently_created, recently_invalidated, matching_created }) => { + if let Some((range, span)) = recently_created { + let msg = format!("tag was most recently created at offsets {}", HexRange(*range)); + helps.push((Some(span.clone()), msg)); + } + if let Some((range, span)) = recently_invalidated { + let msg = format!("tag was later invalidated at offsets {}", HexRange(*range)); + helps.push((Some(span.clone()), msg)); + } + if let Some((range, span)) = matching_created { + let msg = format!("this tag was also created here at offsets {}", HexRange(*range)); + helps.push((Some(span.clone()), msg)); + } + } + None => {} + } + helps } MultipleSymbolDefinitions { first, first_crate, second, second_crate, .. } => vec![ diff --git a/src/eval.rs b/src/eval.rs index 97856d9202..c83abc0a9e 100644 --- a/src/eval.rs +++ b/src/eval.rs @@ -279,6 +279,24 @@ pub fn create_ecx<'mir, 'tcx: 'mir>( Ok((ecx, ret_place)) } +// This is potentially a performance hazard. +// Factoring it into its own function lets us keep an eye on how much it shows up in a profile. +fn set_current_span<'mir, 'tcx: 'mir>(ecx: &mut MiriEvalContext<'mir, 'tcx>) { + let current_span = Machine::stack(&ecx) + .into_iter() + .rev() + .find(|frame| { + let info = + FrameInfo { instance: frame.instance, span: frame.current_span(), lint_root: None }; + ecx.machine.is_local(&info) + }) + .map(|frame| frame.current_span()) + .unwrap_or(rustc_span::DUMMY_SP); + if let Some(sb) = ecx.memory.extra.stacked_borrows.as_mut() { + sb.get_mut().current_span = current_span; + } +} + /// Evaluates the entry function specified by `entry_id`. /// Returns `Some(return_code)` if program executed completed. /// Returns `None` if an evaluation error occured. @@ -306,6 +324,9 @@ pub fn eval_entry<'tcx>( let info = ecx.preprocess_diagnostics(); match ecx.schedule()? { SchedulingAction::ExecuteStep => { + if ecx.memory.extra.stacked_borrows.is_some() { + set_current_span(&mut ecx); + } assert!(ecx.step()?, "a terminated thread was scheduled for execution"); } SchedulingAction::ExecuteTimeoutCallback => { diff --git a/src/helpers.rs b/src/helpers.rs index 3ffb983aa6..b6047cf428 100644 --- a/src/helpers.rs +++ b/src/helpers.rs @@ -794,3 +794,12 @@ pub fn get_local_crates(tcx: &TyCtxt<'_>) -> Vec { } local_crates } + +/// Formats an AllocRange like [0x1..0x3], for use in diagnostics. +pub struct HexRange(pub AllocRange); + +impl std::fmt::Display for HexRange { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!(f, "[{:#x}..{:#x}]", self.0.start.bytes(), self.0.end().bytes()) + } +} diff --git a/src/stacked_borrows.rs b/src/stacked_borrows.rs index 777b8e9331..f7d64cccf0 100644 --- a/src/stacked_borrows.rs +++ b/src/stacked_borrows.rs @@ -3,6 +3,7 @@ use log::trace; use std::cell::RefCell; +use std::collections::HashMap; use std::fmt; use std::num::NonZeroU64; @@ -14,8 +15,10 @@ use rustc_middle::ty::{ layout::{HasParamEnv, LayoutOf}, }; use rustc_span::DUMMY_SP; +use rustc_span::{Span, SpanData}; use rustc_target::abi::Size; +use crate::helpers::HexRange; use crate::*; pub type PtrId = NonZeroU64; @@ -110,7 +113,42 @@ pub struct GlobalState { tracked_call_id: Option, /// Whether to track raw pointers. tag_raw: bool, + /// Extra per-allocation information + extras: HashMap, + /// Current span + pub(crate) current_span: Span, } + +#[derive(Debug, Default)] +struct AllocHistory { + // The time tags can be compressed down to one bit per event, by just storing a Vec + // where each bit is set to indicate if the event was a creation or a retag + current_time: usize, + creations: Vec, + invalidations: Vec, +} + +#[derive(Debug)] +struct Event { + time: usize, + tag: SbTag, + range: AllocRange, + span: Span, +} + +pub enum TagHistory { + Tagged { + tag: SbTag, + created: (AllocRange, SpanData), + invalidated: Option<(AllocRange, SpanData)>, + }, + Untagged { + recently_created: Option<(AllocRange, SpanData)>, + recently_invalidated: Option<(AllocRange, SpanData)>, + matching_created: Option<(AllocRange, SpanData)>, + }, +} + /// Memory extra state gives us interior mutable access to the global state. pub type MemoryExtra = RefCell; @@ -170,6 +208,8 @@ impl GlobalState { tracked_pointer_tag, tracked_call_id, tag_raw, + extras: HashMap::new(), + current_span: DUMMY_SP, } } @@ -217,16 +257,115 @@ impl GlobalState { self.base_ptr_ids.try_insert(id, tag).unwrap(); tag } + + fn add_creation(&mut self, tag: SbTag, alloc: AllocId, range: AllocRange) { + let mut extras = self.extras.entry(alloc).or_default(); + extras.creations.push(Event { + tag, + range, + span: self.current_span, + time: extras.current_time, + }); + extras.current_time += 1; + } + + fn add_invalidation(&mut self, tag: SbTag, alloc: AllocId, range: AllocRange) { + let mut extras = self.extras.entry(alloc).or_default(); + extras.invalidations.push(Event { + tag, + range, + span: self.current_span, + time: extras.current_time, + }); + extras.current_time += 1; + } + + fn get_stack_history( + &self, + tag: SbTag, + alloc: AllocId, + alloc_range: AllocRange, + offset: Size, + ) -> Option { + let extras = self.extras.get(&alloc)?; + if let SbTag::Tagged(_) = tag { + let get_matching = |events: &[Event]| { + events.iter().rev().find_map(|event| { + if event.tag == tag { Some((event.range, event.span.data())) } else { None } + }) + }; + Some(TagHistory::Tagged { + tag, + created: get_matching(&extras.creations).unwrap(), + invalidated: get_matching(&extras.invalidations), + }) + } else { + let mut created_time = 0; + // Find the most recently created tag that satsfies this offset + let recently_created = extras.creations.iter().rev().find_map(|event| { + if event.tag == tag && offset >= event.range.start && offset < event.range.end() { + created_time = event.time; + Some((event.range, event.span.data())) + } else { + None + } + }); + + // Find a different recently created tag that satisfies this whole operation, predates + // the recently created tag, and has a different span. + // We're trying to make a guess at which span the user wanted to provide the tag that + // they're using. + let matching_created = if let Some((_created_range, created_span)) = recently_created { + extras.creations.iter().rev().find_map(|event| { + if event.tag == tag + && alloc_range.start >= event.range.start + && alloc_range.end() <= event.range.end() + && event.span.data() != created_span + && event.time != created_time + { + Some((event.range, event.span.data())) + } else { + None + } + }) + } else { + None + }; + + let recently_invalidated = if recently_created.is_some() { + // Find the most recent invalidation of this tag which post-dates the creation + let mut found = None; + for event in extras.invalidations.iter().rev() { + if event.time < created_time { + break; + } + if event.tag == tag && offset >= event.range.start && offset < event.range.end() + { + found = Some((event.range, event.span.data())) + } + } + found + } else { + None + }; + Some(TagHistory::Untagged { recently_created, matching_created, recently_invalidated }) + } + } } /// Error reporting -fn err_sb_ub(msg: String, help: Option) -> InterpError<'static> { +fn err_sb_ub( + msg: String, + help: Option, + history: Option, +) -> InterpError<'static> { err_machine_stop!(TerminationInfo::ExperimentalUb { msg, help, url: format!( "https://github.com/rust-lang/unsafe-code-guidelines/blob/master/wip/stacked-borrows.md" ), + history }) } @@ -327,11 +466,13 @@ impl<'tcx> Stack { tag, item ), None, + None, ))? } else { Err(err_sb_ub( format!("deallocating while item is protected: {:?}", item), None, + None, ))? } } @@ -347,15 +488,15 @@ impl<'tcx> Stack { &mut self, access: AccessKind, tag: SbTag, - (alloc_id, range, offset): (AllocId, AllocRange, Size), // just for debug printing and error messages - global: &GlobalState, + (alloc_id, alloc_range, offset): (AllocId, AllocRange, Size), // just for debug printing amd error messages + global: &mut GlobalState, ) -> InterpResult<'tcx> { // Two main steps: Find granting item, remove incompatible items above. // Step 1: Find granting item. - let granting_idx = self - .find_granting(access, tag) - .ok_or_else(|| self.access_error(access, tag, alloc_id, range, offset))?; + let granting_idx = self.find_granting(access, tag).ok_or_else(|| { + self.access_error(access, tag, alloc_id, alloc_range, offset, &*global) + })?; // Step 2: Remove incompatible items above them. Make sure we do not remove protected // items. Behavior differs for reads and writes. @@ -366,6 +507,7 @@ impl<'tcx> Stack { for item in self.borrows.drain(first_incompatible_idx..).rev() { trace!("access: popping item {:?}", item); Stack::check_protector(&item, Some((tag, access)), global)?; + global.add_invalidation(item.tag, alloc_id, alloc_range); } } else { // On a read, *disable* all `Unique` above the granting item. This ensures U2 for read accesses. @@ -382,6 +524,7 @@ impl<'tcx> Stack { trace!("access: disabling item {:?}", item); Stack::check_protector(item, Some((tag, access)), global)?; item.perm = Permission::Disabled; + global.add_invalidation(item.tag, alloc_id, alloc_range); } } } @@ -395,15 +538,18 @@ impl<'tcx> Stack { fn dealloc( &mut self, tag: SbTag, - dbg_ptr: Pointer, // just for debug printing and error messages + (alloc_id, alloc_range, offset): (AllocId, AllocRange, Size), // just for debug printing amd error messages global: &GlobalState, ) -> InterpResult<'tcx> { // Step 1: Find granting item. self.find_granting(AccessKind::Write, tag).ok_or_else(|| { err_sb_ub(format!( "no item granting write access for deallocation to tag {:?} at {:?} found in borrow stack", - tag, dbg_ptr, - ), None) + tag, alloc_id, + ), + None, + global.get_stack_history(tag, alloc_id, alloc_range, offset), + ) })?; // Step 2: Remove all items. Also checks for protectors. @@ -424,17 +570,17 @@ impl<'tcx> Stack { &mut self, derived_from: SbTag, new: Item, - (alloc_id, alloc_range, offset): (AllocId, AllocRange, Size), // just for debug printing and error messages - global: &GlobalState, + (alloc_id, alloc_range, offset): (AllocId, AllocRange, Size), // just for debug printing amd error messages + global: &mut GlobalState, ) -> InterpResult<'tcx> { // Figure out which access `perm` corresponds to. let access = if new.perm.grants(AccessKind::Write) { AccessKind::Write } else { AccessKind::Read }; // Now we figure out which item grants our parent (`derived_from`) this kind of access. // We use that to determine where to put the new item. - let granting_idx = self - .find_granting(access, derived_from) - .ok_or_else(|| self.grant_error(derived_from, new, alloc_id, alloc_range, offset))?; + let granting_idx = self.find_granting(access, derived_from).ok_or_else(|| { + self.grant_error(derived_from, new, alloc_id, alloc_range, offset, &*global) + })?; // Compute where to put the new item. // Either way, we ensure that we insert the new item in a way such that between @@ -482,6 +628,7 @@ impl<'tcx> Stack { alloc_id: AllocId, alloc_range: AllocRange, error_offset: Size, + global: &GlobalState, ) -> InterpError<'static> { let action = format!( "trying to reborrow {:?} for {:?} permission at {}[{:#x}]", @@ -493,6 +640,7 @@ impl<'tcx> Stack { err_sb_ub( format!("{}{}", action, self.error_cause(derived_from)), Some(Self::operation_summary("a reborrow", alloc_id, alloc_range)), + global.get_stack_history(derived_from, alloc_id, alloc_range, error_offset), ) } @@ -504,6 +652,7 @@ impl<'tcx> Stack { alloc_id: AllocId, alloc_range: AllocRange, error_offset: Size, + global: &GlobalState, ) -> InterpError<'static> { let action = format!( "attempting a {} using {:?} at {}[{:#x}]", @@ -515,6 +664,7 @@ impl<'tcx> Stack { err_sb_ub( format!("{}{}", action, self.error_cause(tag)), Some(Self::operation_summary("an access", alloc_id, alloc_range)), + global.get_stack_history(tag, alloc_id, alloc_range, error_offset), ) } @@ -524,11 +674,10 @@ impl<'tcx> Stack { alloc_range: AllocRange, ) -> String { format!( - "this error occurs as part of {} at {:?}[{:#x}..{:#x}]", + "this error occurs as part of {} at {:?}{}", operation, alloc_id, - alloc_range.start.bytes(), - alloc_range.end().bytes() + HexRange(alloc_range) ) } @@ -619,6 +768,7 @@ impl Stacks { (tag, Permission::SharedReadWrite) } }; + extra.add_creation(base_tag, id, alloc_range(Size::ZERO, size)); Stacks::new(size, perm, base_tag) } @@ -636,8 +786,8 @@ impl Stacks { Pointer::new(alloc_id, range.start), range.size.bytes() ); - let global = &*extra.borrow(); self.for_each(range, move |offset, stack| { + let global = &mut *extra.borrow_mut(); stack.access(AccessKind::Read, tag, (alloc_id, range, offset), global) }) } @@ -656,9 +806,9 @@ impl Stacks { Pointer::new(alloc_id, range.start), range.size.bytes() ); - let global = extra.get_mut(); self.for_each_mut(range, move |offset, stack| { - stack.access(AccessKind::Write, tag, (alloc_id, range, offset), global) + let mut global = extra.borrow_mut(); + stack.access(AccessKind::Write, tag, (alloc_id, range, offset), &mut *global) }) } @@ -673,8 +823,10 @@ impl Stacks { trace!("deallocation with tag {:?}: {:?}, size {}", tag, alloc_id, range.size.bytes()); let global = extra.get_mut(); self.for_each_mut(range, move |offset, stack| { - stack.dealloc(tag, Pointer::new(alloc_id, offset), global) - }) + stack.dealloc(tag, (alloc_id, range, offset), global) + })?; + extra.borrow_mut().extras.remove(&alloc_id); + Ok(()) } } @@ -753,7 +905,6 @@ trait EvalContextPrivExt<'mir, 'tcx: 'mir>: crate::MiriEvalContextExt<'mir, 'tcx let extra = this.memory.get_alloc_extra(alloc_id)?; let stacked_borrows = extra.stacked_borrows.as_ref().expect("we should have Stacked Borrows data"); - let global = this.memory.extra.stacked_borrows.as_ref().unwrap().borrow(); this.visit_freeze_sensitive(place, size, |mut range, frozen| { // Adjust range. range.start += base_offset; @@ -765,7 +916,9 @@ trait EvalContextPrivExt<'mir, 'tcx: 'mir>: crate::MiriEvalContextExt<'mir, 'tcx }; let item = Item { perm, tag: new_tag, protector }; stacked_borrows.for_each(range, |offset, stack| { - stack.grant(orig_tag, item, (alloc_id, range, offset), &*global) + let mut global = + this.memory.extra.stacked_borrows.as_ref().unwrap().borrow_mut(); + stack.grant(orig_tag, item, (alloc_id, range, offset), &mut *global) }) })?; return Ok(()); @@ -777,11 +930,11 @@ trait EvalContextPrivExt<'mir, 'tcx: 'mir>: crate::MiriEvalContextExt<'mir, 'tcx let (alloc_extra, memory_extra) = this.memory.get_alloc_extra_mut(alloc_id)?; let stacked_borrows = alloc_extra.stacked_borrows.as_mut().expect("we should have Stacked Borrows data"); - let global = memory_extra.stacked_borrows.as_mut().unwrap().get_mut(); let item = Item { perm, tag: new_tag, protector }; let range = alloc_range(base_offset, size); - stacked_borrows.for_each_mut(alloc_range(base_offset, size), |offset, stack| { - stack.grant(orig_tag, item, (alloc_id, range, offset), global) + stacked_borrows.for_each_mut(range, |offset, stack| { + let mut global = memory_extra.stacked_borrows.as_ref().unwrap().borrow_mut(); + stack.grant(orig_tag, item, (alloc_id, range, offset), &mut *global) })?; Ok(()) } @@ -806,17 +959,22 @@ trait EvalContextPrivExt<'mir, 'tcx: 'mir>: crate::MiriEvalContextExt<'mir, 'tcx None => return Ok(*val), }; + // May return Err for retags of size 0 + let alloc = this.memory.ptr_get_alloc(place.ptr); + // Compute new borrow. - let new_tag = { - let mem_extra = this.memory.extra.stacked_borrows.as_mut().unwrap().get_mut(); - match kind { - // Give up tracking for raw pointers. - RefKind::Raw { .. } if !mem_extra.tag_raw => SbTag::Untagged, - // All other pointers are properly tracked. - _ => SbTag::Tagged(mem_extra.new_ptr()), - } + let mem_extra = this.memory.extra.stacked_borrows.as_mut().unwrap().get_mut(); + let new_tag = match kind { + // Give up tracking for raw pointers. + RefKind::Raw { .. } if !mem_extra.tag_raw => SbTag::Untagged, + // All other pointers are properly tracked. + _ => SbTag::Tagged(mem_extra.new_ptr()), }; + if let Ok((alloc_id, base_offset, _ptr)) = alloc { + mem_extra.add_creation(new_tag, alloc_id, alloc_range(base_offset, base_offset + size)); + } + // Reborrow. this.reborrow(&place, size, kind, new_tag, protect)?;