implement set_timer_precise(rbc, instr)

Summary: We want to allow precise timers with an instruction offset. While single stepping we have target and current value of the counter and once we match branches we only increment instructions

Reviewed By: jasonwhite

Differential Revision: D41269879

fbshipit-source-id: 46b3307249663de10607513dc59d8436ca907f78
This commit is contained in:
Vladimir Makaev 2022-11-16 14:01:41 -08:00 committed by Facebook GitHub Bot
parent d7e9901f53
commit 4820afb142
6 changed files with 296 additions and 23 deletions

View file

@ -44,7 +44,7 @@ pub mod decoder;
mod error;
mod gdbstub;
mod perf;
mod regs;
pub mod regs;
mod stack;
mod task;
pub mod testing;

View file

@ -6,6 +6,10 @@
* LICENSE file in the root directory of this source tree.
*/
//! Module provides cross platform access to common registers.
//!
//! Currently supports aarch64 and x86_64 architectures.
/// A single register.
#[cfg(target_pointer_width = "64")]
pub type Reg = u64;

View file

@ -2157,6 +2157,8 @@ impl<L: Tool + 'static> Guest<L> for TracedTask<L> {
let rcbs = match sched {
TimerSchedule::Rcbs(r) => r,
TimerSchedule::Time(dur) => Timer::as_ticks(dur),
//if timer is imprecise there is no really a point in trying to single step any further than r
TimerSchedule::RcbsAndInstructions(r, _) => r,
};
self.timer
.request_event(TimerEventRequest::Imprecise(rcbs))?;
@ -2164,11 +2166,15 @@ impl<L: Tool + 'static> Guest<L> for TracedTask<L> {
}
fn set_timer_precise(&mut self, sched: TimerSchedule) -> Result<(), reverie::Error> {
let rcbs = match sched {
TimerSchedule::Rcbs(r) => r,
TimerSchedule::Time(dur) => Timer::as_ticks(dur),
match sched {
TimerSchedule::Rcbs(r) => self.timer.request_event(TimerEventRequest::Precise(r))?,
TimerSchedule::Time(dur) => self
.timer
.request_event(TimerEventRequest::Precise(Timer::as_ticks(dur)))?,
TimerSchedule::RcbsAndInstructions(r, i) => self
.timer
.request_event(TimerEventRequest::PreciseInstruction(r, i))?,
};
self.timer.request_event(TimerEventRequest::Precise(rcbs))?;
Ok(())
}

View file

@ -29,6 +29,10 @@
//! - before resumption of the guest,
//! which _usually_ means immediately after the tool callback returns.
use std::cmp::Ordering::Equal;
use std::cmp::Ordering::Greater;
use std::cmp::Ordering::Less;
use reverie::Errno;
use reverie::Pid;
use reverie::RegDisplay;
@ -126,6 +130,9 @@ pub enum TimerEventRequest {
/// Event should fire after at least this many RCBs.
Imprecise(u64),
/// Event should fire after precisely this many RCBS and this many instructions
PreciseInstruction(u64, u64),
}
/// The possible results of handling a timer signal.
@ -331,6 +338,8 @@ enum ActiveEvent {
Precise {
/// Expected clock value when event fires.
clock_target: u64,
/// Instruction offset from clock target
offset: u64,
},
Imprecise {
/// Expected minimum clock value when event fires.
@ -343,8 +352,10 @@ impl ActiveEvent {
/// clock to its expected state
fn reschedule_if_spurious_wakeup(&self, curr_clock: u64) -> Option<TimerEventRequest> {
match self {
ActiveEvent::Precise { clock_target } => (clock_target.saturating_sub(curr_clock)
> MAX_SINGLE_STEP_COUNT)
ActiveEvent::Precise {
clock_target,
offset: _,
} => (clock_target.saturating_sub(curr_clock) > MAX_SINGLE_STEP_COUNT)
.then(|| TimerEventRequest::Precise(*clock_target - curr_clock)),
ActiveEvent::Imprecise { clock_min } => (*clock_min > curr_clock)
.then(|| TimerEventRequest::Imprecise(*clock_min - curr_clock)),
@ -389,6 +400,79 @@ const SINGLESTEP_TIMEOUT_RCBS: u64 = 5;
/// is requested that leaves less than the minimum perf timeout remaining.
const MAX_SINGLE_STEP_COUNT: u64 = SKID_MARGIN_RCBS + SINGLESTEP_TIMEOUT_RCBS;
/// This ClockCounter represents a pair in a form of (rcb, instr) that gets increased
/// while single-stepping to reach target (target_rcb, target_instr)
#[derive(Debug, Eq, PartialEq)]
struct ClockCounter {
rcbs: u64,
instr: u64,
target_rcb: u64,
}
impl std::fmt::Display for ClockCounter {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
write!(f, "rcb: {}, instr: {}", self.rcbs, self.instr)
}
}
impl ClockCounter {
pub fn new(rcb: u64, instr: u64, target_rcb: u64) -> Self {
Self {
rcbs: rcb,
instr,
target_rcb,
}
}
/// This method counts instructions & rcbs together in an attempt to reach target_rcb
///
/// With each attempt we either increment rcb or instruction counter based on the read clock value.
/// If we reach target_rcb we no longer increase rcb counter and allow to meet at the target instruction counter
pub fn single_step_with_clock(&mut self, rcbs: u64) {
match (self.rcbs.cmp(&self.target_rcb), self.rcbs.cmp(&rcbs)) {
(Less, Less) => {
self.instr = 0;
self.rcbs = rcbs;
}
(Less | Equal, Equal) => {
self.instr += 1;
}
(Equal, Less) => {
self.instr += 1;
}
(_, Greater) => panic!(
"current counter rcb value {} is greater than privided rcb value {}",
self.rcbs, rcbs
),
(Greater, _) => panic!(
"current counter rcb value {} is greater than target rcb value {}",
self.rcbs, self.target_rcb
),
}
}
/// If a counter behind a given (rcb, instr) pair.
///
/// Note: this is not always comparable. [None] will be returned in this case
fn is_behind(&self, rcbs: u64, instr: u64) -> Option<bool> {
match self.target_rcb.cmp(&rcbs) {
Less => None,
Greater | Equal => match self.rcbs.cmp(&rcbs) {
Less => Some(true),
Equal => Some(self.instr < instr),
Greater => Some(false),
},
}
}
fn rcbs(&self) -> u64 {
self.rcbs
}
}
impl TimerImpl {
pub fn new(guest_pid: Pid, guest_tid: Tid) -> Result<Self, Errno> {
let evt = Event::Raw(get_rcb_perf_config());
@ -420,7 +504,10 @@ impl TimerImpl {
Ok(Self {
timer,
clock,
event: ActiveEvent::Precise { clock_target: 0 },
event: ActiveEvent::Precise {
clock_target: 0,
offset: 0,
},
timer_status: EventStatus::Cancelled,
send_artificial_signal: false,
guest_pid,
@ -430,7 +517,9 @@ impl TimerImpl {
pub fn request_event(&mut self, evt: TimerEventRequest) -> Result<(), Errno> {
let (delivery, notification) = match evt {
TimerEventRequest::Precise(ticks) => (ticks, ticks.saturating_sub(SKID_MARGIN_RCBS)),
TimerEventRequest::Precise(ticks) | TimerEventRequest::PreciseInstruction(ticks, _) => {
(ticks, ticks.saturating_sub(SKID_MARGIN_RCBS))
}
TimerEventRequest::Imprecise(ticks) => (ticks, ticks),
};
if delivery == 0 {
@ -452,6 +541,11 @@ impl TimerImpl {
self.event = match evt {
TimerEventRequest::Precise(_) => ActiveEvent::Precise {
clock_target: clock,
offset: 0,
},
TimerEventRequest::PreciseInstruction(_, instr_offset) => ActiveEvent::Precise {
clock_target: clock,
offset: instr_offset,
},
TimerEventRequest::Imprecise(_) => ActiveEvent::Imprecise { clock_min: clock },
};
@ -564,8 +658,12 @@ impl TimerImpl {
self.send_artificial_signal = false;
match self.event {
ActiveEvent::Precise { clock_target } => {
self.attempt_single_step(task, ctr, clock_target).await
ActiveEvent::Precise {
clock_target,
offset,
} => {
self.attempt_single_step(task, ctr, clock_target, offset)
.await
}
ActiveEvent::Imprecise { clock_min } => {
debug!(
@ -582,29 +680,36 @@ impl TimerImpl {
&self,
task: Stopped,
ctr_initial: u64,
target: u64,
target_rcb: u64,
target_instr: u64,
) -> Result<Stopped, HandleFailure> {
let mut ctr = ctr_initial;
assert!(
ctr <= target,
ctr_initial <= target_rcb,
"Clock perf counter exceeds target value at start of attempted single-step: \
{} > {}. Consider increasing SKID_MARGIN_RCBS.",
ctr,
target
ctr_initial,
target_rcb
);
let mut current = ClockCounter::new(ctr_initial, 0, target_rcb);
assert!(
target - ctr <= MAX_SINGLE_STEP_COUNT,
target_rcb - current.rcbs() <= MAX_SINGLE_STEP_COUNT,
"Single steps from {} to {} requested ({} steps), but that exceeds the skid margin + minimum perf timer steps ({}). \
This probably indicates a bug",
ctr,
target,
(target - ctr),
current.rcbs(),
target_rcb,
(target_rcb - current.rcbs()),
MAX_SINGLE_STEP_COUNT
);
debug!("Timer will single-step from ctr {} to {}", ctr, target);
debug!(
"Timer will single-step from ctr {} to {}",
current, target_rcb
);
let mut task = task;
loop {
if ctr >= target {
if !current
.is_behind(target_rcb, target_instr)
.expect("counter should increase monotonically and stay at target_rcb until equal. This is most likely a BUG with counter tracking")
{
break;
}
#[cfg(target_arch = "x86_64")]
@ -619,7 +724,7 @@ impl TimerImpl {
Wait::Stopped(new_task, TraceEvent::Signal(Signal::SIGTRAP)) => new_task,
wait => return Err(HandleFailure::Event(wait)),
};
ctr = self.read_clock();
current.single_step_with_clock(self.read_clock());
}
Ok(task)
}
@ -683,3 +788,46 @@ fn get_si_fd(signal: &libc::siginfo_t) -> libc::c_int {
.si_fd
}
}
#[cfg(test)]
mod tests {
use test_case::test_case;
use super::ClockCounter;
#[test_case(ClockCounter::new(0, 0, 10), 0, 1, Some(true))]
#[test_case(ClockCounter::new(2, 100, 200), 3, 0, Some(true))]
#[test_case(ClockCounter::new(1, 10, 200), 1, 11, Some(true))]
#[test_case(ClockCounter::new(2, 100, 2), 3, 0, None)]
#[test_case(ClockCounter::new(4, 4, 4), 4, 5, Some(true))]
#[test_case(ClockCounter::new(4, 4, 4), 4, 3, Some(false))]
#[test_case(ClockCounter::new(4, 4, 4), 4, 4, Some(false))]
fn test_clock_counter_is_behind(
counter: ClockCounter,
target_rcb: u64,
target_instr: u64,
expected: Option<bool>,
) {
assert_eq!(counter.is_behind(target_rcb, target_instr), expected);
}
#[test_case(ClockCounter::new(0, 0, 0), 0, (0, 1))]
#[test_case(ClockCounter::new(0, 1, 0), 1, (0, 2))]
#[test_case(ClockCounter::new(0, 1, 0), 2, (0, 2))]
#[test_case(ClockCounter::new(0, 1, 1), 0, (0, 2))]
#[test_case(ClockCounter::new(0, 1, 1), 1, (1, 0))]
#[test_case(ClockCounter::new(0, 1, 1), 2, (2, 0))]
#[test_case(ClockCounter::new(0, 1, 1), 3, (3, 0))]
#[test_case(ClockCounter::new(10, 0, 11), 10, (10, 1))]
#[test_case(ClockCounter::new(10, 1, 11), 10, (10, 2))]
#[test_case(ClockCounter::new(10, 1, 11), 11, (11, 0))]
#[test_case(ClockCounter::new(10, 1, 11), 12, (12, 0))]
fn test_increment_counter_with_clock(
mut counter: ClockCounter,
new_clock: u64,
expected: (u64, u64),
) {
counter.single_step_with_clock(new_clock);
assert_eq!((counter.rcbs, counter.instr), expected);
}
}

View file

@ -16,6 +16,9 @@ pub enum TimerSchedule {
/// Request that a timer event occur after exactly this many retired
/// conditional branches (RCBs).
Rcbs(u64),
/// Request that a timer event occur after exactly this many retired
/// conditional branches (RCBs) and this many instructions
RcbsAndInstructions(u64, u64),
}
/// signal used by reverie perf counter timer.

View file

@ -13,6 +13,7 @@
use std::sync::atomic::AtomicU64;
use std::sync::atomic::Ordering;
use std::sync::Mutex;
use reverie::syscalls::Getpid;
use reverie::syscalls::Gettid;
@ -29,6 +30,7 @@ use reverie::Signal;
use reverie::Subscription;
use reverie::TimerSchedule;
use reverie::Tool;
use reverie_ptrace::regs::RegAccess;
use serde::Deserialize;
use serde::Serialize;
@ -198,6 +200,75 @@ async fn raise_sigwinch<T: Guest<LocalState>>(guest: &mut T) -> Tgkill {
.with_sig(libc::SIGWINCH)
}
#[derive(Default)]
struct InstructionTracingGlobal {
timer_events: Mutex<Vec<TimerEvent>>,
}
#[derive(PartialEq, Default, Debug, Eq, Clone, Copy, Serialize, Deserialize)]
struct TimerEvent {
rcbs: u64,
rip: reverie_ptrace::regs::Reg,
}
#[derive(Default, Clone, Serialize, Deserialize)]
struct InstructionTracingConfig {
set_timer_after_syscall: Option<(u64, Option<u64>)>,
}
#[derive(Serialize, Deserialize)]
enum InstructionTracingRequest {
Timer(TimerEvent),
}
#[reverie::global_tool]
impl GlobalTool for InstructionTracingGlobal {
type Request = InstructionTracingRequest;
type Response = ();
type Config = InstructionTracingConfig;
async fn receive_rpc(&self, _from: reverie::Tid, message: Self::Request) -> Self::Response {
match message {
InstructionTracingRequest::Timer(ev) => self.timer_events.lock().unwrap().push(ev),
}
}
}
#[derive(Debug, Default, Clone)]
struct InstructionTracing;
#[reverie::tool]
impl Tool for InstructionTracing {
type GlobalState = InstructionTracingGlobal;
type ThreadState = ThreadClockState;
async fn handle_syscall_event<T: Guest<Self>>(
&self,
guest: &mut T,
c: Syscall,
) -> Result<i64, Error> {
match guest.config().set_timer_after_syscall {
Some((rcb, Some(instr))) => {
guest.set_timer_precise(reverie::TimerSchedule::RcbsAndInstructions(rcb, instr))?;
}
Some((rcb, None)) => {
guest.set_timer_precise(reverie::TimerSchedule::Rcbs(rcb))?;
}
_ => {}
}
guest.tail_inject(c).await
}
async fn handle_timer_event<T: Guest<Self>>(&self, guest: &mut T) {
let rcbs = guest.read_clock().expect("clock available");
let rip = guest.regs().await.ip();
guest
.send_rpc(InstructionTracingRequest::Timer(TimerEvent { rcbs, rip }))
.await;
}
}
#[cfg(all(not(sanitized), test))]
mod tests {
//! These tests are highly sensitive to the number of branches executed
@ -207,6 +278,7 @@ mod tests {
//! into the tracee, otherwise underflow or overflow checks will break the
//! tests.
use reverie_ptrace::regs::RegAccess;
use reverie_ptrace::ret_without_perf;
use reverie_ptrace::testing::check_fn;
use reverie_ptrace::testing::check_fn_with_config;
@ -696,4 +768,44 @@ mod tests {
true,
);
}
#[test_case(1000, None, 1000, Some(1))]
#[test_case(1000, Some(1), 1000, Some(2))]
#[test_case(1000, Some(100), 1000, Some(101))]
#[test_case(10, None, 10, Some(1))]
#[test_case(10, Some(1), 10, Some(2))]
#[test_case(10, Some(100), 10, Some(101))]
fn test_set_precice_with_instructions_after_syscall(
rcb_1: u64,
instr_1: Option<u64>,
rcb_2: u64,
instr_2: Option<u64>,
) {
ret_without_perf!();
let gs_1 = check_fn_with_config::<InstructionTracing, _>(
move || {
do_syscall();
do_branches(MANY_RCBS);
},
InstructionTracingConfig {
set_timer_after_syscall: Some((rcb_1, instr_1)),
..Default::default()
},
true,
);
let gs_2 = check_fn_with_config::<InstructionTracing, _>(
move || {
do_syscall();
do_branches(MANY_RCBS);
},
InstructionTracingConfig {
set_timer_after_syscall: Some((rcb_2, instr_2)),
..Default::default()
},
true,
);
let rips = [&gs_1, &gs_2].map(|s| s.timer_events.lock().unwrap()[0].rip);
assert_ne!(rips[0], rips[1]);
}
}