From: Ben Kimock Date: Sat, 12 Mar 2022 22:23:22 +0000 (-0500) Subject: Print spans where tags are created and invalidated X-Git-Url: https://git.lizzy.rs/?a=commitdiff_plain;h=f3f7e083dc92aba7a4c1818e56464fcb79f22f19;p=rust.git Print spans where tags are created and invalidated --- diff --git a/src/diagnostics.rs b/src/diagnostics.rs index 1a39a1ff332..c6b6c3388ca 100644 --- a/src/diagnostics.rs +++ b/src/diagnostics.rs @@ -7,7 +7,8 @@ use rustc_middle::ty; use rustc_span::{source_map::DUMMY_SP, Span, SpanData, Symbol}; -use crate::stacked_borrows::{AccessKind, SbTag}; +use crate::helpers::HexRange; +use crate::stacked_borrows::{AccessKind, SbTag, TagHistory}; use crate::*; /// Details of premature program termination. @@ -19,6 +20,7 @@ pub enum TerminationInfo { msg: String, help: Option, url: String, + history: Option, }, Deadlock, MultipleSymbolDefinitions { @@ -155,12 +157,46 @@ 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, protected }) => { + 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)); + } + if let Some((protecting_tag, protecting_tag_span, protection_span)) = protected { + helps.push((Some(protecting_tag_span.clone()), format!("{:?} was protected due to {:?} which was created here", tag, protecting_tag))); + helps.push((Some(protection_span.clone()), "this protector is live for this call".to_string())); + } + } + Some(TagHistory::Untagged{ recently_created, recently_invalidated, matching_created, protected }) => { + 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)); + } + if let Some((protecting_tag, protecting_tag_span, protection_span)) = protected { + helps.push((Some(protecting_tag_span.clone()), format!("{:?} was protected due to a tag which was created here", protecting_tag))); + helps.push((Some(protection_span.clone()), "this protector is live for this call".to_string())); + } + } + None => {} + } + helps } MultipleSymbolDefinitions { first, first_crate, second, second_crate, .. } => vec![ diff --git a/src/eval.rs b/src/eval.rs index f8d23cb8279..8b964ba90f0 100644 --- a/src/eval.rs +++ b/src/eval.rs @@ -283,6 +283,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.machine.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. @@ -310,6 +328,9 @@ pub fn eval_entry<'tcx>( let info = ecx.preprocess_diagnostics(); match ecx.schedule()? { SchedulingAction::ExecuteStep => { + if ecx.machine.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 107a2551995..8d7147fff7a 100644 --- a/src/helpers.rs +++ b/src/helpers.rs @@ -813,3 +813,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/machine.rs b/src/machine.rs index 0a8a229c8aa..5f25fd29886 100644 --- a/src/machine.rs +++ b/src/machine.rs @@ -632,7 +632,7 @@ fn memory_read( alloc_id, tag, range, - machine.stacked_borrows.as_ref().unwrap(), + machine.stacked_borrows.as_ref().unwrap(), ) } else { Ok(()) @@ -655,7 +655,7 @@ fn memory_written( alloc_id, tag, range, - machine.stacked_borrows.as_mut().unwrap(), + machine.stacked_borrows.as_ref().unwrap(), ) } else { Ok(()) @@ -681,7 +681,7 @@ fn memory_deallocated( alloc_id, tag, range, - machine.stacked_borrows.as_mut().unwrap(), + machine.stacked_borrows.as_ref().unwrap(), ) } else { Ok(()) diff --git a/src/stacked_borrows.rs b/src/stacked_borrows.rs index d6caba81713..225407a7bbf 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,9 +15,11 @@ layout::{HasParamEnv, LayoutOf}, }; use rustc_span::DUMMY_SP; +use rustc_span::{Span, SpanData}; use rustc_target::abi::Size; use std::collections::HashSet; +use crate::helpers::HexRange; use crate::*; pub type PtrId = NonZeroU64; @@ -111,7 +114,53 @@ pub struct GlobalStateInner { tracked_call_ids: HashSet, /// 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, + protectors: Vec, +} + +#[derive(Debug)] +struct Protection { + orig_tag: SbTag, + tag: SbTag, + span: Span, +} + +#[derive(Debug)] +struct Event { + time: usize, + parent: Option, + tag: SbTag, + range: AllocRange, + span: Span, +} + +pub enum TagHistory { + Tagged { + tag: SbTag, + created: (AllocRange, SpanData), + invalidated: Option<(AllocRange, SpanData)>, + protected: Option<(SbTag, SpanData, SpanData)>, + }, + Untagged { + recently_created: Option<(AllocRange, SpanData)>, + recently_invalidated: Option<(AllocRange, SpanData)>, + matching_created: Option<(AllocRange, SpanData)>, + protected: Option<(SbTag, SpanData, SpanData)>, + }, +} + /// We need interior mutable access to the global state. pub type GlobalState = RefCell; @@ -171,6 +220,8 @@ pub fn new( tracked_pointer_tags, tracked_call_ids, tag_raw, + extras: HashMap::new(), + current_span: DUMMY_SP, } } @@ -218,16 +269,155 @@ pub fn base_tag_untagged(&mut self, id: AllocId) -> SbTag { self.base_ptr_ids.try_insert(id, tag).unwrap(); tag } + + fn add_creation( + &mut self, + parent: Option, + tag: SbTag, + alloc: AllocId, + range: AllocRange, + ) { + let extras = self.extras.entry(alloc).or_default(); + extras.creations.push(Event { + parent, + 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 extras = self.extras.entry(alloc).or_default(); + extras.invalidations.push(Event { + parent: None, + tag, + range, + span: self.current_span, + time: extras.current_time, + }); + extras.current_time += 1; + } + + fn add_protector(&mut self, orig_tag: SbTag, tag: SbTag, alloc: AllocId) { + let extras = self.extras.entry(alloc).or_default(); + extras.protectors.push(Protection { orig_tag, tag, span: self.current_span }); + extras.current_time += 1; + } + + fn get_stack_history( + &self, + tag: SbTag, + alloc: AllocId, + alloc_range: AllocRange, + offset: Size, + protector_tag: Option, + ) -> Option { + let extras = self.extras.get(&alloc)?; + let protected = protector_tag + .and_then(|protector| { + extras.protectors.iter().find_map(|protection| { + if protection.tag == protector { + Some((protection.orig_tag, protection.span.data())) + } else { + None + } + }) + }) + .and_then(|(tag, call_span)| { + extras.creations.iter().rev().find_map(|event| { + if event.tag == tag { + Some((event.parent?, event.span.data(), call_span)) + } else { + None + } + }) + }); + 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)?, + invalidated: get_matching(&extras.invalidations), + protected, + }) + } 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, + protected, + }) + } + } } /// 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 }) } @@ -308,31 +498,39 @@ fn find_first_write_incompatible(&self, granting: usize) -> usize { /// `None` during a deallocation. fn check_protector( item: &Item, - provoking_access: Option<(SbTag, AccessKind)>, + provoking_access: Option<(SbTag, AllocId, AllocRange, Size)>, // just for debug printing amd error messages global: &GlobalStateInner, ) -> InterpResult<'tcx> { if let SbTag::Tagged(id) = item.tag { if global.tracked_pointer_tags.contains(&id) { register_diagnostic(NonHaltingDiagnostic::PoppedPointerTag( *item, - provoking_access, + None, )); } } if let Some(call) = item.protector { if global.is_active(call) { - if let Some((tag, _)) = provoking_access { + if let Some((tag, alloc_id, alloc_range, offset)) = provoking_access { Err(err_sb_ub( format!( "not granting access to tag {:?} because incompatible item is protected: {:?}", tag, item ), None, + global.get_stack_history( + tag, + alloc_id, + alloc_range, + offset, + Some(item.tag), + ), ))? } else { Err(err_sb_ub( format!("deallocating while item is protected: {:?}", item), None, + None, ))? } } @@ -348,15 +546,15 @@ fn access( &mut self, access: AccessKind, tag: SbTag, - (alloc_id, range, offset): (AllocId, AllocRange, Size), // just for debug printing and error messages - global: &GlobalStateInner, + (alloc_id, alloc_range, offset): (AllocId, AllocRange, Size), // just for debug printing and error messages + global: &mut GlobalStateInner, ) -> 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,7 +564,8 @@ fn access( let first_incompatible_idx = self.find_first_write_incompatible(granting_idx); for item in self.borrows.drain(first_incompatible_idx..).rev() { trace!("access: popping item {:?}", item); - Stack::check_protector(&item, Some((tag, access)), global)?; + Stack::check_protector(&item, Some((tag, alloc_id, alloc_range, offset)), 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. @@ -381,8 +580,13 @@ fn access( let item = &mut self.borrows[idx]; if item.perm == Permission::Unique { trace!("access: disabling item {:?}", item); - Stack::check_protector(item, Some((tag, access)), global)?; + Stack::check_protector( + item, + Some((tag, alloc_id, alloc_range, offset)), + global, + )?; item.perm = Permission::Disabled; + global.add_invalidation(item.tag, alloc_id, alloc_range); } } } @@ -396,15 +600,18 @@ fn access( 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: &GlobalStateInner, ) -> 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, None), + ) })?; // Step 2: Remove all items. Also checks for protectors. @@ -426,16 +633,16 @@ fn grant( derived_from: SbTag, new: Item, (alloc_id, alloc_range, offset): (AllocId, AllocRange, Size), // just for debug printing and error messages - global: &GlobalStateInner, + global: &mut GlobalStateInner, ) -> 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 @@ -483,6 +690,7 @@ fn grant_error( alloc_id: AllocId, alloc_range: AllocRange, error_offset: Size, + global: &GlobalStateInner, ) -> InterpError<'static> { let action = format!( "trying to reborrow {:?} for {:?} permission at {}[{:#x}]", @@ -494,6 +702,7 @@ fn grant_error( 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, None), ) } @@ -505,6 +714,7 @@ fn access_error( alloc_id: AllocId, alloc_range: AllocRange, error_offset: Size, + global: &GlobalStateInner, ) -> InterpError<'static> { let action = format!( "attempting a {} using {:?} at {}[{:#x}]", @@ -516,6 +726,7 @@ fn access_error( 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, None), ) } @@ -525,11 +736,10 @@ fn operation_summary( 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) ) } @@ -620,6 +830,7 @@ pub fn new_allocation( (tag, Permission::SharedReadWrite) } }; + extra.add_creation(None, base_tag, id, alloc_range(Size::ZERO, size)); Stacks::new(size, perm, base_tag) } @@ -637,11 +848,11 @@ pub fn memory_read<'tcx>( Pointer::new(alloc_id, range.start), range.size.bytes() ); - let global = &*state.borrow(); self.for_each(range, move |offset, stack| { - stack.access(AccessKind::Read, tag, (alloc_id, range, offset), global) + let mut state = state.borrow_mut(); + stack.access(AccessKind::Read, tag, (alloc_id, range, offset), &mut state) }) - } + } #[inline(always)] pub fn memory_written<'tcx>( @@ -649,7 +860,7 @@ pub fn memory_written<'tcx>( alloc_id: AllocId, tag: SbTag, range: AllocRange, - state: &mut GlobalState, + state: &GlobalState, ) -> InterpResult<'tcx> { trace!( "write access with tag {:?}: {:?}, size {}", @@ -657,9 +868,9 @@ pub fn memory_written<'tcx>( Pointer::new(alloc_id, range.start), range.size.bytes() ); - let global = state.get_mut(); self.for_each_mut(range, move |offset, stack| { - stack.access(AccessKind::Write, tag, (alloc_id, range, offset), global) + let mut state = state.borrow_mut(); + stack.access(AccessKind::Write, tag, (alloc_id, range, offset), &mut state) }) } @@ -669,13 +880,15 @@ pub fn memory_deallocated<'tcx>( alloc_id: AllocId, tag: SbTag, range: AllocRange, - state: &mut GlobalState, + state: &GlobalState, ) -> InterpResult<'tcx> { trace!("deallocation with tag {:?}: {:?}, size {}", tag, alloc_id, range.size.bytes()); - let global = state.get_mut(); self.for_each_mut(range, move |offset, stack| { - stack.dealloc(tag, Pointer::new(alloc_id, offset), global) - }) + let mut state = state.borrow_mut(); + stack.dealloc(tag, (alloc_id, range, offset), &mut state) + })?; + state.borrow_mut().extras.remove(&alloc_id); + Ok(()) } } @@ -705,6 +918,17 @@ fn reborrow( } let (alloc_id, base_offset, orig_tag) = this.ptr_get_alloc_id(place.ptr)?; + let mem_extra = this.machine.stacked_borrows.as_mut().unwrap().get_mut(); + mem_extra.add_creation( + Some(orig_tag), + new_tag, + alloc_id, + alloc_range(base_offset, base_offset + size), + ); + if protect { + mem_extra.add_protector(orig_tag, new_tag, alloc_id); + } + // Ensure we bail out if the pointer goes out-of-bounds (see miri#1050). let (alloc_size, _) = this.get_alloc_size_and_align(alloc_id, AllocCheck::Dereferenceable)?; @@ -753,7 +977,6 @@ fn reborrow( let extra = this.get_alloc_extra(alloc_id)?; let stacked_borrows = extra.stacked_borrows.as_ref().expect("we should have Stacked Borrows data"); - let global = this.machine.stacked_borrows.as_ref().unwrap().borrow(); this.visit_freeze_sensitive(place, size, |mut range, frozen| { // Adjust range. range.start += base_offset; @@ -765,7 +988,9 @@ fn reborrow( }; 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.machine.stacked_borrows.as_ref().unwrap().borrow_mut(); + stack.grant(orig_tag, item, (alloc_id, range, offset), &mut *global) }) })?; return Ok(()); @@ -777,11 +1002,11 @@ fn reborrow( let (alloc_extra, memory_extra) = this.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(()) } @@ -807,14 +1032,12 @@ fn retag_reference( }; // Compute new borrow. - let new_tag = { - let mem_extra = this.machine.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.machine.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()), }; // Reborrow.