Actually produce profiler files

This commit is contained in:
Simon Gellis 2025-08-13 23:58:40 -04:00
parent c223c80269
commit adc333e6a6
6 changed files with 325 additions and 127 deletions

25
Cargo.lock generated
View File

@ -1507,6 +1507,20 @@ dependencies = [
"slab",
]
[[package]]
name = "fxprof-processed-profile"
version = "0.8.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "25234f20a3ec0a962a61770cfe39ecf03cb529a6e474ad8cff025ed497eda557"
dependencies = [
"bitflags 2.9.1",
"debugid",
"rustc-hash 2.1.1",
"serde",
"serde_derive",
"serde_json",
]
[[package]]
name = "gethostname"
version = "0.4.3"
@ -2140,10 +2154,12 @@ dependencies = [
"egui_extras",
"elf",
"fixed",
"fxprof-processed-profile",
"gilrs",
"hex",
"image",
"itertools 0.14.0",
"normpath",
"num-derive",
"num-traits",
"oneshot",
@ -2569,6 +2585,15 @@ dependencies = [
"minimal-lexical",
]
[[package]]
name = "normpath"
version = "1.3.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "c8911957c4b1549ac0dc74e30db9c8b0e66ddcd6d7acc33098f4c63a64a6d7ed"
dependencies = [
"windows-sys 0.59.0",
]
[[package]]
name = "nu-ansi-term"
version = "0.46.0"

View File

@ -22,11 +22,13 @@ egui-notify = "0.20"
egui-winit = "0.32"
egui-wgpu = { version = "0.32", features = ["winit"] }
elf = "0.8"
fxprof-processed-profile = "0.8"
fixed = { version = "1.28", features = ["num-traits"] }
gilrs = { version = "0.11", features = ["serde-serialize"] }
hex = "0.4"
image = { version = "0.25", default-features = false, features = ["png"] }
itertools = "0.14"
normpath = "1"
num-derive = "0.4"
num-traits = "0.2"
oneshot = "0.1"

View File

@ -1,15 +1,19 @@
use std::{
collections::HashMap,
path::PathBuf,
sync::{Arc, Mutex},
thread,
};
use anyhow::{Result, bail};
use anyhow::Result;
use tokio::{select, sync::mpsc};
use wholesym::{SymbolManager, SymbolMap};
use crate::emulator::{EmulatorClient, EmulatorCommand, ProfileEvent, SimEvent, SimId};
use recording::Recording;
use state::ProgramState;
mod recording;
mod state;
mod symbols;
pub struct Profiler {
sim_id: SimId,
@ -182,14 +186,6 @@ enum RecordingAction {
Cancel,
}
struct Recording {}
impl Recording {
fn new() -> Self {
Self {}
}
}
struct ProfilerSession {
program: Option<ProgramState>,
recording: Option<Recording>,
@ -210,8 +206,8 @@ impl ProfilerSession {
}
fn track_elapsed_cycles(&mut self, cycles: u32) -> Result<()> {
if let Some(program) = &mut self.program {
program.track_elapsed_cycles(cycles)?;
if let (Some(state), Some(recording)) = (&self.program, &mut self.recording) {
recording.track_elapsed_cycles(state, cycles);
}
Ok(())
}
@ -224,126 +220,16 @@ impl ProfilerSession {
}
fn start_recording(&mut self) {
self.recording = Some(Recording::new());
if let Some(program) = &self.program {
self.recording = Some(Recording::new(program));
}
}
fn finish_recording(&mut self) -> Option<Vec<u8>> {
self.recording.take().map(|_| vec![])
self.recording.take().map(|r| r.finish())
}
fn cancel_recording(&mut self) {
self.recording.take();
}
}
struct ProgramState {
symbol_map: SymbolMap,
call_stacks: HashMap<u16, Vec<StackFrame>>,
context_stack: Vec<u16>,
}
struct StackFrame {
#[expect(dead_code)]
address: u32,
cycles: u64,
}
const RESET_CODE: u16 = 0xfff0;
impl ProgramState {
async fn new(file_path: PathBuf) -> Result<Self> {
let symbol_manager = SymbolManager::with_config(Default::default());
let symbol_map = symbol_manager
.load_symbol_map_for_binary_at_path(&file_path, None)
.await?;
let mut call_stacks = HashMap::new();
call_stacks.insert(
RESET_CODE,
vec![StackFrame {
address: 0xfffffff0,
cycles: 0,
}],
);
Ok(Self {
symbol_map,
call_stacks,
context_stack: vec![RESET_CODE],
})
}
fn track_elapsed_cycles(&mut self, cycles: u32) -> Result<()> {
let Some(code) = self.context_stack.last() else {
return Ok(()); // program is halted, CPU is idle
};
let Some(stack) = self.call_stacks.get_mut(code) else {
bail!("missing stack {code:04x}");
};
for frame in stack {
frame.cycles += cycles as u64;
}
Ok(())
}
fn track_event(&mut self, event: SimEvent) -> Result<()> {
match event {
SimEvent::Call(address) => {
let Some(code) = self.context_stack.last() else {
bail!("How did we call anything when we're halted?");
};
let Some(stack) = self.call_stacks.get_mut(code) else {
bail!("missing stack {code:04x}");
};
let name = self
.symbol_map
.lookup_sync(wholesym::LookupAddress::Svma(address as u64));
println!("depth {}: {:x?}", stack.len(), name);
stack.push(StackFrame { address, cycles: 0 });
}
SimEvent::Return => {
let Some(code) = self.context_stack.last() else {
bail!("how did we return when we're halted?");
};
let Some(stack) = self.call_stacks.get_mut(code) else {
bail!("missing stack {code:04x}");
};
if stack.pop().is_none() {
bail!("returned from {code:04x} but stack was empty");
}
if stack.is_empty() {
bail!("returned to oblivion");
}
}
SimEvent::Halt => {
let Some(RESET_CODE) = self.context_stack.pop() else {
bail!("halted when not in an interrupt");
};
}
SimEvent::Interrupt(code, address) => {
// if the CPU was halted before, wake it up now
if self.context_stack.is_empty() {
self.context_stack.push(RESET_CODE);
}
self.context_stack.push(code);
if self
.call_stacks
.insert(code, vec![StackFrame { address, cycles: 0 }])
.is_some()
{
bail!("{code:04x} fired twice");
}
}
SimEvent::Reti => {
let Some(code) = self.context_stack.pop() else {
bail!("RETI when halted");
};
if code == RESET_CODE {
bail!("RETI when not in interrupt");
}
if self.call_stacks.remove(&code).is_none() {
bail!("{code:04x} popped but never called");
}
}
}
Ok(())
}
}

114
src/profiler/recording.rs Normal file
View File

@ -0,0 +1,114 @@
use std::collections::HashMap;
use fxprof_processed_profile::{
CategoryHandle, CpuDelta, Frame, FrameFlags, FrameInfo, ProcessHandle, Profile,
ReferenceTimestamp, SamplingInterval, StackHandle, ThreadHandle, Timestamp,
};
use crate::profiler::state::{ProgramState, RESET_CODE, StackFrame};
pub struct Recording {
profile: Profile,
process: ProcessHandle,
threads: HashMap<u16, ThreadHandle>,
now: u64,
}
impl Recording {
pub fn new(state: &ProgramState) -> Self {
let symbol_file = state.symbol_file();
let name = &symbol_file.name();
let reference_timestamp = ReferenceTimestamp::from_millis_since_unix_epoch(0.0);
let interval = SamplingInterval::from_hz(20_000_000.0);
let mut profile = Profile::new(name, reference_timestamp, interval);
let process = profile.add_process(name, 1, Timestamp::from_nanos_since_reference(0));
let lib = profile.add_lib(symbol_file.library_info().clone());
profile.add_lib_mapping(process, lib, 0x00000000, 0xffffffff, 0);
let mut me = Self {
profile,
process,
threads: HashMap::new(),
now: 0,
};
me.track_elapsed_cycles(state, 0);
me
}
pub fn track_elapsed_cycles(&mut self, state: &ProgramState, cycles: u32) {
self.now += cycles as u64;
let timestamp = Timestamp::from_nanos_since_reference(self.now * 50);
let weight = 1;
let active_code = if let Some((code, frames)) = state.current_stack() {
let thread = *self.threads.entry(code).or_insert_with(|| {
let process = self.process;
let tid = code as u32;
let start_time = Timestamp::from_nanos_since_reference(self.now * 50);
let is_main = code == RESET_CODE;
let thread = self.profile.add_thread(process, tid, start_time, is_main);
self.profile
.set_thread_name(thread, &thread_name_for_code(code));
thread
});
let stack = self.handle_for_stack(thread, frames);
let cpu_delta = CpuDelta::from_nanos((self.now - cycles as u64) * 50);
self.profile
.add_sample(thread, timestamp, stack, cpu_delta, weight);
Some(code)
} else {
None
};
for (code, thread) in &self.threads {
if active_code == Some(*code) {
continue;
}
self.profile
.add_sample_same_stack_zero_cpu(*thread, timestamp, weight);
}
}
pub fn finish(self) -> Vec<u8> {
serde_json::to_vec(&self.profile).expect("could not serialize profile")
}
fn handle_for_stack(
&mut self,
thread: ThreadHandle,
frames: &[StackFrame],
) -> Option<StackHandle> {
self.profile.intern_stack_frames(
thread,
frames.iter().map(|f| FrameInfo {
frame: Frame::InstructionPointer(f.address as u64),
category_pair: CategoryHandle::OTHER.into(),
flags: FrameFlags::empty(),
}),
)
}
}
fn thread_name_for_code(code: u16) -> std::borrow::Cow<'static, str> {
match code {
RESET_CODE => "Main".into(),
0xffd0 => "Duplexed exception".into(),
0xfe40 => "VIP interrupt".into(),
0xfe30 => "Communication interrupt".into(),
0xfe20 => "Game pak interrupt".into(),
0xfe10 => "Timer interrupt".into(),
0xfe00 => "Game pad interrupt".into(),
0xffc0 => "Address trap".into(),
0xffa0..0xffc0 => format!("Trap (vector {})", code - 0xffa0).into(),
0xff90 => "Illegal opcode exception".into(),
0xff80 => "Zero division exception".into(),
0xff60 => "Floating-point reserved operand exception".into(),
0xff70 => "Floating-point invalid operation exception".into(),
0xff68 => "Floating-point zero division exception".into(),
0xff64 => "Floating-point overflow exception".into(),
other => format!("Unrecognized handler (0x{other:04x})").into(),
}
}

104
src/profiler/state.rs Normal file
View File

@ -0,0 +1,104 @@
use std::{collections::HashMap, path::PathBuf};
use anyhow::{Result, bail};
use crate::{emulator::SimEvent, profiler::symbols::SymbolFile};
pub struct ProgramState {
symbol_file: SymbolFile,
call_stacks: HashMap<u16, Vec<StackFrame>>,
context_stack: Vec<u16>,
}
pub struct StackFrame {
pub address: u32,
}
pub const RESET_CODE: u16 = 0xfff0;
impl ProgramState {
pub async fn new(file_path: PathBuf) -> Result<Self> {
let symbol_file = SymbolFile::load(&file_path).await?;
let mut call_stacks = HashMap::new();
call_stacks.insert(
RESET_CODE,
vec![StackFrame {
address: 0xfffffff0,
}],
);
Ok(Self {
symbol_file,
call_stacks,
context_stack: vec![RESET_CODE],
})
}
pub fn symbol_file(&self) -> &SymbolFile {
&self.symbol_file
}
pub fn current_stack(&self) -> Option<(u16, &[StackFrame])> {
let code = self.context_stack.last()?;
let call_stack = self.call_stacks.get(code)?;
Some((*code, call_stack))
}
pub fn track_event(&mut self, event: SimEvent) -> Result<()> {
match event {
SimEvent::Call(address) => {
let Some(code) = self.context_stack.last() else {
bail!("How did we call anything when we're halted?");
};
let Some(stack) = self.call_stacks.get_mut(code) else {
bail!("missing stack {code:04x}");
};
stack.push(StackFrame { address });
}
SimEvent::Return => {
let Some(code) = self.context_stack.last() else {
bail!("how did we return when we're halted?");
};
let Some(stack) = self.call_stacks.get_mut(code) else {
bail!("missing stack {code:04x}");
};
if stack.pop().is_none() {
bail!("returned from {code:04x} but stack was empty");
}
if stack.is_empty() {
bail!("returned to oblivion");
}
}
SimEvent::Halt => {
let Some(RESET_CODE) = self.context_stack.pop() else {
bail!("halted when not in an interrupt");
};
}
SimEvent::Interrupt(code, address) => {
// if the CPU was halted before, wake it up now
if self.context_stack.is_empty() {
self.context_stack.push(RESET_CODE);
}
self.context_stack.push(code);
if self
.call_stacks
.insert(code, vec![StackFrame { address }])
.is_some()
{
bail!("{code:04x} fired twice");
}
}
SimEvent::Reti => {
let Some(code) = self.context_stack.pop() else {
bail!("RETI when halted");
};
if code == RESET_CODE {
bail!("RETI when not in interrupt");
}
if self.call_stacks.remove(&code).is_none() {
bail!("{code:04x} popped but never called");
}
}
}
Ok(())
}
}

67
src/profiler/symbols.rs Normal file
View File

@ -0,0 +1,67 @@
use std::{path::Path, sync::Arc};
use anyhow::Result;
use fxprof_processed_profile::{LibraryInfo, Symbol, SymbolTable};
use wholesym::{SymbolManager, samply_symbols::demangle_any};
pub struct SymbolFile {
library_info: LibraryInfo,
}
impl SymbolFile {
pub async fn load(file_path: &Path) -> Result<Self> {
let normalized = normpath::PathExt::normalize(file_path)?;
let library_info =
SymbolManager::library_info_for_binary_at_path(normalized.as_path(), None).await?;
let symbol_manager = SymbolManager::with_config(Default::default());
let symbol_map = symbol_manager
.load_symbol_map_for_binary_at_path(normalized.as_path(), None)
.await?;
let name = library_info
.name
.or_else(|| {
normalized
.file_name()
.map(|n| n.to_string_lossy().into_owned())
})
.unwrap_or("game".to_string());
let debug_name = library_info.debug_name.unwrap_or_else(|| name.clone());
let path = library_info
.path
.unwrap_or_else(|| normalized.into_os_string().to_string_lossy().into_owned());
let debug_path = library_info.debug_path.unwrap_or_else(|| path.clone());
let debug_id = library_info.debug_id.unwrap_or_default();
let code_id = library_info.code_id.map(|id| id.to_string());
let arch = library_info.arch;
let symbols = symbol_map
.iter_symbols()
.map(|(address, name)| Symbol {
address: address + 0x07000000,
size: None,
name: demangle_any(&name),
})
.collect();
Ok(Self {
library_info: LibraryInfo {
name,
debug_name,
path,
debug_path,
debug_id,
code_id,
arch,
symbol_table: Some(Arc::new(SymbolTable::new(symbols))),
},
})
}
pub fn name(&self) -> &str {
&self.library_info.name
}
pub fn library_info(&self) -> &LibraryInfo {
&self.library_info
}
}