Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Miri/interpreter debugging tweaks #96160

Merged
merged 3 commits into from
Apr 20, 2022
Merged

Miri/interpreter debugging tweaks #96160

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
5640304
add log warnings for when we overwrite parts of a pointer, and de-ini…
RalfJung Apr 17, 2022
989e747
interpret: more debug logging for read_scalar and write_scalar
RalfJung Apr 17, 2022
f3bdcfb
downgrade really verbose logging to trace
RalfJung Apr 17, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions compiler/rustc_const_eval/src/interpret/eval_context.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -679,7 +679,7 @@ impl<'mir, 'tcx: 'mir, M: Machine<'mir, 'tcx>> InterpCx<'mir, 'tcx, M> {
return_place: Option<&PlaceTy<'tcx, M::PointerTag>>,
return_to_block: StackPopCleanup,
) -> InterpResult<'tcx> {
debug!("body: {:#?}", body);
trace!("body: {:#?}", body);
// first push a stack frame so we have access to the local substs
let pre_frame = Frame {
body,
Expand Down Expand Up @@ -836,7 +836,7 @@ impl<'mir, 'tcx: 'mir, M: Machine<'mir, 'tcx>> InterpCx<'mir, 'tcx, M> {
return Ok(());
}

debug!("locals: {:#?}", frame.locals);
trace!("locals: {:#?}", frame.locals);

// Cleanup: deallocate all locals that are backed by an allocation.
for local in &frame.locals {
Expand Down
25 changes: 21 additions & 4 deletions compiler/rustc_const_eval/src/interpret/memory.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -877,9 +877,17 @@ impl<'tcx, 'a, Tag: Provenance, Extra> AllocRefMut<'a, 'tcx, Tag, Extra> {
range: AllocRange,
val: ScalarMaybeUninit<Tag>,
) -> InterpResult<'tcx> {
let range = self.range.subrange(range);
debug!(
"write_scalar in {} at {:#x}, size {}: {:?}",
self.alloc_id,
range.start.bytes(),
range.size.bytes(),
val
);
Ok(self
.alloc
.write_scalar(&self.tcx, self.range.subrange(range), val)
.write_scalar(&self.tcx, range, val)
.map_err(|e| e.to_interp_error(self.alloc_id))?)
}

Expand All @@ -899,10 +907,19 @@ impl<'tcx, 'a, Tag: Provenance, Extra> AllocRefMut<'a, 'tcx, Tag, Extra> {

impl<'tcx, 'a, Tag: Provenance, Extra> AllocRef<'a, 'tcx, Tag, Extra> {
pub fn read_scalar(&self, range: AllocRange) -> InterpResult<'tcx, ScalarMaybeUninit<Tag>> {
Ok(self
let range = self.range.subrange(range);
let res = self
.alloc
.read_scalar(&self.tcx, self.range.subrange(range))
.map_err(|e| e.to_interp_error(self.alloc_id))?)
.read_scalar(&self.tcx, range)
.map_err(|e| e.to_interp_error(self.alloc_id))?;
debug!(
"read_scalar in {} at {:#x}, size {}: {:?}",
self.alloc_id,
range.start.bytes(),
range.size.bytes(),
res
);
Ok(res)
}

pub fn read_ptr_sized(&self, offset: Size) -> InterpResult<'tcx, ScalarMaybeUninit<Tag>> {
Expand Down
8 changes: 8 additions & 0 deletions compiler/rustc_middle/src/mir/interpret/allocation.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -509,6 +509,9 @@ impl<Tag: Copy, Extra> Allocation<Tag, Extra> {
if Tag::ERR_ON_PARTIAL_PTR_OVERWRITE {
return Err(AllocError::PartialPointerOverwrite(first));
}
warn!(
"Partial pointer overwrite! De-initializing memory at offsets {first:?}..{start:?}."
);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have RUSTC_LOG=warn set in my zshrc I believe. This will cause be rather noisy I think.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We kind of emit warn and error unconditionally, or at least used to at some point.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

They alsodon't get optimized out, so nightly will have them

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

At least warn is only emitted when using RUSTC_LOG=warn.

Copy link
Member Author

@RalfJung RalfJung Apr 19, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have RUSTC_LOG=warn set in my zshrc I believe. This will cause be rather noisy I think.

Note that this is never printed by rustc, since ERR_ON_PARTIAL_PTR_OVERWRITE is true there.
Only Miri can ever trigger this.

They alsodon't get optimized out, so nightly will have them

This is a very cold path, so that's fine. We have info! for each statement and terminator we run (also exists on nightly), this is at least as important as that.

When this triggers, it can cause subtly wrong execution later in the program, where memory is uninit that should be init -- so there should be a good way to figure out if this triggered.

We kind of emit warn and error unconditionally, or at least used to at some point.

This is definitely not printed by default, I verified that.

self.init_mask.set_range(first, start, false);
}
if last > end {
Expand All @@ -517,10 +520,15 @@ impl<Tag: Copy, Extra> Allocation<Tag, Extra> {
last - cx.data_layout().pointer_size,
));
}
warn!(
"Partial pointer overwrite! De-initializing memory at offsets {end:?}..{last:?}."
);
self.init_mask.set_range(end, last, false);
}

// Forget all the relocations.
// Since relocations do not overlap, we know that removing until `last` (exclusive) is fine,
// i.e., this will not remove any other relocations just after the ones we care about.
self.relocations.0.remove_range(first..last);

Ok(())
Expand Down