use std::collections::{HashMap, HashSet};
use std::path::PathBuf;
use std::fs::File;
use std::io::Write;
use std::time::{Duration, SystemTime};
use serde::Serialize;
use serde_repr::Serialize_repr;
use crate::function_trace::*;
use indexmap::set::IndexSet;
type FirefoxTime = f64;
#[derive(Serialize, Debug)]
enum Unused {}
type StringIndex = usize;
pub struct FirefoxProfileThreadId {
tid: usize,
start_duration: Duration,
}
#[derive(Serialize, Debug)]
pub struct FirefoxProfile {
meta: Metadata,
counters: Vec<Unused>,
threads: Vec<FirefoxThread>,
#[serde(skip_serializing)]
thread_count: usize,
}
#[derive(Serialize, Debug)]
#[serde(rename_all = "lowercase")]
#[allow(dead_code)]
enum Color {
Transparent,
Purple,
Green,
Orange,
Yellow,
LightBlue,
Grey,
Blue,
Brown
}
#[derive(Serialize, Debug)]
struct Category {
name: &'static str,
color: Color,
subcategories: [&'static str; 1],
}
#[derive(Serialize_repr, Debug)]
#[repr(usize)]
enum CategoryIndex {
Logs,
Python,
Native,
Exceptions,
Imports,
GarbageCollection,
Length
}
const CATEGORIES: [Category; CategoryIndex::Length as usize] = [
Category {
name: "Logs",
color: Color::Grey,
subcategories: ["Unused"],
},
Category {
name: "Python",
color: Color::Orange,
subcategories: ["Code"]
},
Category {
name: "Native",
color: Color::LightBlue,
subcategories: ["Code"]
},
Category {
name: "Exceptions",
color: Color::Brown,
subcategories: ["Unused"],
},
Category {
name: "Imports",
color: Color::Grey,
subcategories: ["Unused"],
},
Category {
name: "GarbageCollection",
color: Color::Purple,
subcategories: ["Unused"],
},
];
macro_rules! struct_table {
($struct_name: ident, $($element: ident: $ty: ty),*) => {
paste::item! {
#[derive(Serialize, Debug, Copy, Clone)]
struct [<$struct_name Index>] (usize);
#[derive(Serialize, Debug)]
#[serde(rename_all = "camelCase")]
struct [<$struct_name Table>] {
$($element: Vec<$ty>),*,
length: usize
}
struct $struct_name {
$($element: $ty),*,
}
impl [<$struct_name Table>] {
fn new() -> Self {
Self {
$($element: Vec::new()),*,
length: 0
}
}
#[allow(dead_code)]
fn add(&mut self, arg: $struct_name) -> [<$struct_name Index>] {
let length = self.length;
$(self.$element.push(arg.$element);)*
self.length += 1;
[<$struct_name Index>](length)
}
#[allow(dead_code)]
fn is_empty(&self) -> bool {
self.length == 0
}
}
}
}
}
struct_table!(Sample,
event_delay: u32,
stack: StackIndex,
time: FirefoxTime,
duration: Option<FirefoxTime>
);
struct_table!(Stack,
frame: FrameIndex,
category: CategoryIndex,
subcategory: u32,
prefix: Option<StackIndex>
);
struct_table!(Frame,
address: Option<u32>,
category: CategoryIndex,
subcategory: u32,
func: FunctionIndex,
innerWindowID: Option<Unused>,
implementation: Option<Unused>,
line: Option<u32>,
column: Option<u32>,
optimizations: Option<Unused>
);
struct_table!(Function,
address: Option<Unused>,
isJS: bool,
name: StringIndex,
resource: i32,
relevantForJS: bool,
file_name: StringIndex,
line_number: Option<u32>,
column_number: Option<u32>
);
struct_table!(NativeAllocation,
time: FirefoxTime,
duration: isize,
stack: Option<StackIndex>,
memory_address: usize,
thread_id: usize
);
struct_table!(Marker,
data: serde_json::Value,
name: StringIndex,
time: FirefoxTime,
category: CategoryIndex
);
struct_table!(Resource,
lib: Unused,
name: Unused,
host: Unused,
r#type: Unused
);
#[derive(Serialize, Debug)]
#[serde(rename_all = "camelCase")]
struct Metadata {
interval: f32,
start_time: f64,
process_type: u32,
categories: &'static [Category; CategoryIndex::Length as usize],
stackwalk: u32,
version: u32,
preprocessed_profile_version: u32,
symbolicated: bool,
product: String,
#[serde(rename = "appBuildID")]
app_build_id: String,
abi: String,
platform: String,
misc: String,
#[serde(rename = "physicalCPUs")]
physical_cpus: usize,
#[serde(rename = "logicalCPUs")]
logical_cpus: usize,
#[serde(skip_serializing)]
start_duration: Duration,
}
#[derive(Serialize, Debug)]
#[serde(rename_all = "camelCase")]
pub struct FirefoxThread {
process_type: &'static str,
process_startup_time: FirefoxTime,
process_shutdown_time: FirefoxTime,
register_time: FirefoxTime,
unregister_time: Option<FirefoxTime>,
paused_ranges: Vec<Unused>,
name: &'static str,
process_name: String,
is_js_tracer: bool,
pid: usize,
tid: usize,
samples: SampleTable,
markers: MarkerTable,
stack_table: StackTable,
frame_table: FrameTable,
func_table: FunctionTable,
string_array: IndexSet<String>,
#[serde(skip_serializing_if = "NativeAllocationTable::is_empty")]
native_allocations: NativeAllocationTable,
libs: Vec<Unused>,
resource_table: ResourceTable,
#[serde(skip_serializing)]
calls: Vec<SampleIndex>,
#[serde(skip_serializing)]
functions: HashMap<String, FunctionIndex>,
#[serde(skip_serializing)]
start_duration: Duration,
#[serde(skip_serializing)]
allocations: HashMap<usize, usize>,
}
impl FirefoxProfile {
pub fn new(info: TraceInitialization) -> FirefoxProfile {
FirefoxProfile {
meta: Metadata {
start_time: SystemTime::now().duration_since(SystemTime::UNIX_EPOCH).map_or(0.0, |n| n.as_secs_f64() * 1000.0),
start_duration: info.time,
interval: 0.000_001,
process_type: 0,
categories: &CATEGORIES,
stackwalk: 0,
version: 19,
preprocessed_profile_version: 28,
symbolicated: true,
physical_cpus: num_cpus::get_physical(),
logical_cpus: num_cpus::get(),
product: info.program_name,
app_build_id: "<git revision>".to_string(),
abi: info.lang_version,
platform: info.platform,
misc: info.program_version,
},
counters: Vec::new(),
threads: Vec::new(),
thread_count: 0,
}
}
pub fn register_thread(&mut self) -> FirefoxProfileThreadId {
self.thread_count += 1;
FirefoxProfileThreadId {
tid: self.thread_count,
start_duration: self.meta.start_duration,
}
}
pub fn finalize_thread(&mut self, thread: FirefoxThread) {
self.threads.push(thread);
}
pub fn export(&mut self, mut output_dir: PathBuf) -> std::io::Result<()> {
self.threads.sort_by(|x, y| x.register_time.partial_cmp(&y.register_time).expect("Registration time is reasonable"));
let mut registered_pids = HashSet::new();
for thread in self.threads.iter_mut() {
thread.name = if registered_pids.contains(&thread.pid) { "thread" } else { "GeckoMain" };
registered_pids.insert(thread.pid);
}
let output_file = {
let mut dir = output_dir.clone();
let now = chrono::Local::now();
dir.push(format!("functiontrace.{}.json", now.format("%F-%T.%3f")));
dir
};
let json = serde_json::to_string(&self)?;
let bytes = json.as_bytes();
File::create(&output_file)?.write_all(bytes)?;
output_dir.push("functiontrace.latest.json");
let _ = std::fs::remove_file(&output_dir);
std::os::unix::fs::symlink(&output_file, &output_dir)?;
println!("\n[FunctionTrace] Wrote profile data to {} ({})\n", output_file.display(), bytesize::to_string(bytes.len() as u64, false));
Ok(())
}
}
impl FirefoxThread {
pub fn new(registration: ThreadRegistration, thread: FirefoxProfileThreadId) -> FirefoxThread {
FirefoxThread {
process_type: "default",
process_startup_time: 0.0,
process_shutdown_time: 0.0,
register_time: (registration.time - thread.start_duration).as_secs_f64() * 1000.0,
unregister_time: None,
paused_ranges: Vec::new(),
name: "<filled in at export>",
process_name: registration.program_name,
is_js_tracer: true,
pid: registration.pid,
tid: thread.tid,
samples: SampleTable::new(),
markers: MarkerTable::new(),
stack_table: StackTable::new(),
frame_table: FrameTable::new(),
func_table: FunctionTable::new(),
string_array: IndexSet::new(),
native_allocations: NativeAllocationTable::new(),
libs: Vec::new(),
resource_table: ResourceTable::new(),
calls: Vec::new(),
functions: HashMap::new(),
start_duration: thread.start_duration,
allocations: HashMap::new(),
}
}
fn offset_time(&self, time: Duration) -> FirefoxTime {
(time - self.start_duration).as_secs_f64() * 1000.0
}
fn unique_string(&mut self, string: &str) -> StringIndex {
match self.string_array.get_full(string) {
Some((index, _)) => index,
None => self.string_array.insert_full(string.to_string()).0
}
}
fn emit_call(&mut self, name: &str, time: Duration, file_or_module: &str, linenumber: Option<u32>) -> FirefoxTime {
let native = linenumber.is_none();
let func_uid = if native {
format!("{}:{}:native", name, file_or_module)
} else {
format!("{} ({}:{})", name, file_or_module, linenumber.expect("Checked above"))
};
let function_id = match self.functions.get(&func_uid) {
Some(&x) => x,
None => {
let funcname_id = self.unique_string(name);
let filename_id = self.unique_string(file_or_module);
let function_id = self.func_table.add(Function {
address: None,
isJS: false,
name: funcname_id,
resource: -1,
relevantForJS: false,
file_name: filename_id,
line_number: linenumber,
column_number: None
});
self.frame_table.add(Frame {
address: None,
category: if native { CategoryIndex::Native } else { CategoryIndex::Python },
subcategory: 0,
func: function_id,
innerWindowID: None,
implementation: None,
line: linenumber,
column: None,
optimizations: None
});
self.functions.insert(func_uid, function_id);
function_id
}
};
let time = self.offset_time(time);
let stack_id = self.stack_table.add(Stack {
frame: FrameIndex(function_id.0),
category: if native { CategoryIndex::Native } else { CategoryIndex::Python },
subcategory: 0,
prefix: self.calls.last().map(|&x| StackIndex(x.0))
});
let samples_id = self.samples.add(Sample {
event_delay: 0,
stack: stack_id,
time,
duration: None
});
self.calls.push(samples_id);
time
}
fn emit_return(&mut self, func_name: &str, time: FirefoxTime) -> FirefoxTime {
while let Some(call_id) = self.calls.pop() {
let matches = {
let caller_id = self.func_table.name[self.frame_table.func[self.stack_table.frame[self.samples.stack[call_id.0].0].0].0];
self.string_array.get_full(func_name).map_or(false, |(id,_)| id == caller_id)
};
self.samples.duration[call_id.0] = Some(time - self.samples.time[call_id.0]);
if matches {
break;
}
log::trace!("Returning from `{}` which was not the most recently called function", func_name);
};
time
}
pub fn add_trace(&mut self, trace: FunctionTrace) {
let event_time = match trace {
FunctionTrace::Call {time, func_name, filename, linenumber} =>
self.emit_call(&func_name, time, &filename, Some(linenumber)),
FunctionTrace::NativeCall{time, func_name, module_name} =>
self.emit_call(&func_name, time, &module_name, None),
FunctionTrace::Return{time, func_name} => self.emit_return(&func_name, self.offset_time(time)),
FunctionTrace::NativeReturn{time, func_name} => self.emit_return(&func_name, self.offset_time(time)),
FunctionTrace::Exception{time, exception_type, exception_value, filename, linenumber} => {
let unique_type = self.unique_string(&exception_type);
let time = self.offset_time(time);
self.markers.add(Marker {
data: serde_json::json!({
"type": "Log",
"name": exception_value,
"module": format!("{}:{}", filename, linenumber)
}),
name: unique_type,
time,
category: CategoryIndex::Exceptions
});
time
},
FunctionTrace::Log{time, log_type, log_value} => {
let time = self.offset_time(time);
let unique_type = self.unique_string(&log_type);
self.markers.add(Marker {
data: serde_json::json!({
"type": "Text",
"name": log_value,
}),
name: unique_type,
time,
category: CategoryIndex::Logs,
});
time
},
FunctionTrace::Import{time, module_name} => {
let time = self.offset_time(time);
let unique_type = self.unique_string("Import");
self.markers.add(Marker {
data: serde_json::json!({
"type": "Log",
"name": module_name,
"module": "import",
}),
name: unique_type,
time,
category: CategoryIndex::Imports,
});
time
},
FunctionTrace::Allocation{time, details} => {
let time = self.offset_time(time);
let stack = self.calls.last().map(|&x| StackIndex(x.0));
match details {
AllocationDetails::Alloc{bytes, addr} => {
self.allocations.insert(addr, bytes);
self.native_allocations.add(NativeAllocation {
time,
duration: bytes as isize,
stack,
memory_address: addr,
thread_id: self.tid
});
},
AllocationDetails::Realloc{bytes, old_addr, new_addr} => {
let old_bytes = self.allocations.remove(&old_addr).unwrap_or(0);
self.native_allocations.add(NativeAllocation {
time,
duration: -(old_bytes as isize),
stack,
memory_address: old_addr,
thread_id: self.tid
});
self.allocations.insert(new_addr, bytes);
self.native_allocations.add(NativeAllocation {
time,
duration: bytes as isize,
stack,
memory_address: new_addr,
thread_id: self.tid
});
},
AllocationDetails::Free{old_addr} => {
let bytes = self.allocations.remove(&old_addr).unwrap_or(0);
self.native_allocations.add(NativeAllocation {
time,
duration: -(bytes as isize),
stack,
memory_address: old_addr,
thread_id: self.tid
});
},
}
time
},
msg => panic!("Invalid message variant: {:?}", msg)
};
self.process_shutdown_time = self.process_shutdown_time.max(event_time);
}
}