diff --git a/reverie-ptrace/src/lib.rs b/reverie-ptrace/src/lib.rs index 37a83be..c9843a0 100644 --- a/reverie-ptrace/src/lib.rs +++ b/reverie-ptrace/src/lib.rs @@ -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; diff --git a/reverie-ptrace/src/regs.rs b/reverie-ptrace/src/regs.rs index 639f65a..0b1ec48 100644 --- a/reverie-ptrace/src/regs.rs +++ b/reverie-ptrace/src/regs.rs @@ -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; diff --git a/reverie-ptrace/src/task.rs b/reverie-ptrace/src/task.rs index ca38c05..5448fdf 100644 --- a/reverie-ptrace/src/task.rs +++ b/reverie-ptrace/src/task.rs @@ -2157,6 +2157,8 @@ impl Guest for TracedTask { 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 Guest for TracedTask { } 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(()) } diff --git a/reverie-ptrace/src/timer.rs b/reverie-ptrace/src/timer.rs index 11fc6e1..1d4d28a 100644 --- a/reverie-ptrace/src/timer.rs +++ b/reverie-ptrace/src/timer.rs @@ -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 { 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 { + 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 { 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 { - 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, + ) { + 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); + } +} diff --git a/reverie/src/timer.rs b/reverie/src/timer.rs index c1465e0..26dfc68 100644 --- a/reverie/src/timer.rs +++ b/reverie/src/timer.rs @@ -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. diff --git a/tests/timer_semantics.rs b/tests/timer_semantics.rs index 699210a..d9ffc28 100644 --- a/tests/timer_semantics.rs +++ b/tests/timer_semantics.rs @@ -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>(guest: &mut T) -> Tgkill { .with_sig(libc::SIGWINCH) } +#[derive(Default)] +struct InstructionTracingGlobal { + timer_events: Mutex>, +} + +#[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)>, +} + +#[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>( + &self, + guest: &mut T, + c: Syscall, + ) -> Result { + 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>(&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, + rcb_2: u64, + instr_2: Option, + ) { + ret_without_perf!(); + let gs_1 = check_fn_with_config::( + 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::( + 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]); + } }