Use correct conversion for time values

Two errors I made:
* cycle durations are not constant, their value relies on the cbr
* tsc frequency was not exactly 2.7Ghz, now calculated at runtime
This commit is contained in:
David Venhoff 2025-09-04 18:11:20 +02:00
parent 10ca8f89f6
commit f072c0ce53
4 changed files with 47 additions and 21 deletions

10
Cargo.lock generated
View File

@ -639,6 +639,7 @@ version = "0.1.0"
dependencies = [ dependencies = [
"libipt", "libipt",
"memmap2", "memmap2",
"raw-cpuid",
] ]
[[package]] [[package]]
@ -711,6 +712,15 @@ dependencies = [
"rand_core", "rand_core",
] ]
[[package]]
name = "raw-cpuid"
version = "11.5.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "c6df7ab838ed27997ba19a4664507e6f82b41fe6e20be42929332156e5e85146"
dependencies = [
"bitflags 2.9.1",
]
[[package]] [[package]]
name = "regex" name = "regex"
version = "1.11.1" version = "1.11.1"

View File

@ -10,6 +10,7 @@ fn main() {
let start = std::time::Instant::now(); let start = std::time::Instant::now();
ptwrite(42); ptwrite(42);
loop { loop {
// ptwrite(69);
if start.elapsed().as_secs() >= 2 { if start.elapsed().as_secs() >= 2 {
break; break;
} }

View File

@ -9,3 +9,4 @@ edition = "2024"
[dependencies] [dependencies]
libipt = { version = "0.4.0", features = ["libipt_master"] } libipt = { version = "0.4.0", features = ["libipt_master"] }
memmap2 = "0.9.7" memmap2 = "0.9.7"
raw-cpuid = "11.5.0"

View File

@ -1,15 +1,16 @@
use libipt::enc_dec_builder::EncoderDecoderBuilder; use libipt::enc_dec_builder::EncoderDecoderBuilder;
use libipt::packet::{Packet, PacketDecoder}; use libipt::packet::{Packet, PacketDecoder};
use memmap2::Mmap; use memmap2::Mmap;
use std::collections::HashMap;
use std::error::Error; use std::error::Error;
use std::fs::File; use std::fs::File;
use std::path::Path; use std::path::Path;
use std::time::Duration; use std::time::Duration;
use raw_cpuid::CpuId;
#[derive(Debug)] #[derive(Debug)]
pub struct AnalyzeData { pub struct AnalyzeData {
pub packets: u64, pub packets: u64,
pub cycles: u64,
pub time_tsc: Duration, pub time_tsc: Duration,
pub time_cyc: Duration, pub time_cyc: Duration,
pub time_main: Duration, pub time_main: Duration,
@ -34,17 +35,30 @@ pub fn analyze_dump(path: impl AsRef<Path>) -> Result<AnalyzeData, Box<dyn Error
// Required before it can be used // Required before it can be used
decoder.sync_forward()?; decoder.sync_forward()?;
let mut segments = vec![(Scope::PreRun, 0u64)]; let mut segments = vec![(Scope::PreRun, Duration::ZERO)];
let mut total = 0u64; let mut total = 0u64;
// Lets assume 100Mhz bus frequency (TODO compute that automatically)
let f_bus = 100_000_000.0;
let mut current_cbr = 0u8;
let mut first_tsc = None::<u64>; let mut first_tsc = None::<u64>;
let mut last_tsc = 0; let mut last_tsc = 0;
let mut seen_cbrs = HashMap::<u8, u64>::new();
for packet in decoder { for packet in decoder {
total += 1; total += 1;
match packet { match packet {
Ok(Packet::Cyc(cyc)) => { Ok(Packet::Cyc(cyc)) => {
segments.last_mut().unwrap().1 += cyc.value(); // Ignore cycle packets when there was no cbr packet yet.
if current_cbr == 0 {
println!("Ignoring {} cycles, because cbr is still unknown!", cyc.value());
continue;
}
let f_core = f_bus * current_cbr as f64;
let duration = Duration::from_secs_f64(cyc.value() as f64 / f_core);
segments.last_mut().unwrap().1 += duration;
} }
Ok(Packet::Tsc(tsc)) => { Ok(Packet::Tsc(tsc)) => {
if first_tsc.is_none() { if first_tsc.is_none() {
@ -52,15 +66,19 @@ pub fn analyze_dump(path: impl AsRef<Path>) -> Result<AnalyzeData, Box<dyn Error
} }
last_tsc = tsc.tsc(); last_tsc = tsc.tsc();
} }
Ok(Packet::Cbr(cbr)) => {
current_cbr = cbr.ratio();
*seen_cbrs.entry(cbr.ratio()).or_default() += 1;
}
Ok(Packet::Ptw(ptwrite)) => { Ok(Packet::Ptw(ptwrite)) => {
if ptwrite.payload() == 42 { if ptwrite.payload() == 42 {
// Main enter // Main enter
segments.push((Scope::Main, 0)); segments.push((Scope::Main, Duration::ZERO));
} else if ptwrite.payload() == 43 { } else if ptwrite.payload() == 43 {
// Main exit // Main exit
segments.push((Scope::PostRun, 0)); segments.push((Scope::PostRun, Duration::ZERO));
} else { } else {
println!("GOT PTWRITE!!!!!: {ptwrite:?}"); // println!("GOT PTWRITE!!!!!: {ptwrite:?}");
} }
} }
Ok(Packet::Ovf(overflow)) => { Ok(Packet::Ovf(overflow)) => {
@ -70,29 +88,25 @@ pub fn analyze_dump(path: impl AsRef<Path>) -> Result<AnalyzeData, Box<dyn Error
Err(error) => println!("Got error: {error:?}"), Err(error) => println!("Got error: {error:?}"),
} }
} }
// dbg!(&segments); dbg!(seen_cbrs);
let cycles_total = segments.iter().map(|(_, cycles)| cycles).sum(); let duration_total = segments.iter().map(|(_, duration)| *duration).sum();
let total_seconds = cycles_total as f64 / 2_700_000_000.0;
let total_seconds_tsc = (last_tsc - first_tsc.unwrap()) as f64 / 2_700_000_000.0;
let main_duration = duration_in_mode(&segments, Scope::Main); let main_duration = duration_in_mode(&segments, Scope::Main);
let f_tsc = CpuId::new().get_tsc_info().unwrap().tsc_frequency().unwrap();
let total_seconds_tsc = (last_tsc - first_tsc.unwrap()) as f64 / f_tsc as f64;
Ok(AnalyzeData { Ok(AnalyzeData {
packets: total, packets: total,
cycles: cycles_total, time_cyc: duration_total,
time_cyc: Duration::from_secs_f64(total_seconds),
time_main: main_duration, time_main: main_duration,
time_tsc: Duration::from_secs_f64(total_seconds_tsc) time_tsc: Duration::from_secs_f64(total_seconds_tsc),
}) })
} }
fn duration_in_mode(segments: &[(Scope, u64)], scope: Scope) -> Duration { fn duration_in_mode(segments: &[(Scope, Duration)], scope: Scope) -> Duration {
let total_cycles = segments segments
.into_iter() .into_iter()
.filter(|(it, _)| *it == scope) .filter(|(it, _)| *it == scope)
.map(|(_, cycles)| *cycles) .map(|(_, duration)| *duration)
.sum::<u64>(); .sum::<Duration>()
let total_seconds = total_cycles as f64 / 2_700_000_000.0;
Duration::from_secs_f64(total_seconds)
} }