mirror of
https://github.com/SK8-ENGINE/skate-3-rust-engine.git
synced 2026-10-26 19:47:44 +00:00
Add bounded opt-in CPU timelines and GPU pass diagnostics
This commit is contained in:
1 parent
57742e0e54
commit
71af0e867f
15 files changed
+859
-13
No files matched your search
@@ -80,6 +80,7 @@ try {
|
||||
Copy-Item -LiteralPath docs/installation.md -Destination "$stage/docs/installation.md"
|
||||
Copy-Item -LiteralPath docs/retail-renderer.md -Destination "$stage/docs/retail-renderer.md"
|
||||
Copy-Item -LiteralPath docs/crash-reports.md -Destination "$stage/docs/crash-reports.md"
|
||||
Copy-Item -LiteralPath docs/performance-tracing.md -Destination "$stage/docs/performance-tracing.md"
|
||||
Copy-Item -LiteralPath docs/updates.md -Destination "$stage/docs/updates.md"
|
||||
New-Item -ItemType Directory -Path "$stage/licenses" -Force | Out-Null
|
||||
Copy-Item -LiteralPath tools/vendor/utt/LICENSE -Destination "$stage/licenses/UTT.txt"
|
||||
|
||||
Generated
+17
@@ -354,6 +354,7 @@ checksum = "1fd310426290cec560221f9750c2f4484be4a8eeea7de3483c423329b465c40e"
|
||||
dependencies = [
|
||||
"bevy_dylib",
|
||||
"bevy_internal",
|
||||
"tracing",
|
||||
]
|
||||
|
||||
[[package]]
|
||||
@@ -462,6 +463,7 @@ dependencies = [
|
||||
"downcast-rs 2.0.2",
|
||||
"log",
|
||||
"thiserror 2.0.20",
|
||||
"tracing",
|
||||
"variadics_please",
|
||||
"wasm-bindgen",
|
||||
"web-sys",
|
||||
@@ -702,6 +704,7 @@ dependencies = [
|
||||
"slotmap",
|
||||
"smallvec",
|
||||
"thiserror 2.0.20",
|
||||
"tracing",
|
||||
"variadics_please",
|
||||
]
|
||||
|
||||
@@ -1016,6 +1019,7 @@ dependencies = [
|
||||
"bevy_platform",
|
||||
"bevy_utils",
|
||||
"tracing",
|
||||
"tracing-error",
|
||||
"tracing-log",
|
||||
"tracing-oslog",
|
||||
"tracing-subscriber",
|
||||
@@ -1283,6 +1287,7 @@ dependencies = [
|
||||
"naga",
|
||||
"nonmax",
|
||||
"offset-allocator",
|
||||
"profiling",
|
||||
"send_wrapper",
|
||||
"smallvec",
|
||||
"thiserror 2.0.20",
|
||||
@@ -4204,6 +4209,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
|
||||
checksum = "3d595e54a326bc53c1c197b32d295e14b169e3cfeaa8dc82b529f947fba6bcf5"
|
||||
dependencies = [
|
||||
"profiling-procmacros",
|
||||
"tracing",
|
||||
]
|
||||
|
||||
[[package]]
|
||||
@@ -4739,6 +4745,7 @@ dependencies = [
|
||||
"skate-mods",
|
||||
"skate-net",
|
||||
"skate-vehicles",
|
||||
"tracing-log",
|
||||
]
|
||||
|
||||
[[package]]
|
||||
@@ -5185,6 +5192,16 @@ dependencies = [
|
||||
"valuable",
|
||||
]
|
||||
|
||||
[[package]]
|
||||
name = "tracing-error"
|
||||
version = "0.2.1"
|
||||
source = "registry+https://github.com/rust-lang/crates.io-index"
|
||||
checksum = "8b1581020d7a273442f5b45074a6a57d5757ad0a47dac0e9f0bd57b81936f3db"
|
||||
dependencies = [
|
||||
"tracing",
|
||||
"tracing-subscriber",
|
||||
]
|
||||
|
||||
[[package]]
|
||||
name = "tracing-log"
|
||||
version = "0.2.0"
|
||||
|
||||
@@ -48,3 +48,8 @@ are shipped. The included format-demo map is original procedural content.
|
||||
Implementation notes are in [`docs/`](docs/). Patched Bevy dependencies and
|
||||
their licenses are in [`vendor/`](vendor/). This is an unofficial project,
|
||||
not affiliated with EA.
|
||||
|
||||
## Advanced diagnostics
|
||||
|
||||
Windows builds support opt-in [performance timeline capture](docs/performance-tracing.md)
|
||||
through the `--trace` CLI option, including optional GPU pass diagnostics.
|
||||
@@ -0,0 +1,61 @@
|
||||
//! Read-only map inventory; no window, renderer, physics initialization or conversion.
|
||||
use skate_data::skate_map::SkateMap;
|
||||
use std::collections::{HashMap, HashSet};
|
||||
use std::hash::{Hash, Hasher};
|
||||
fn main() -> Result<(), String> {
|
||||
let path = std::env::args_os()
|
||||
.nth(1)
|
||||
.ok_or("Usage: map-performance-inventory MAP.skate")?;
|
||||
let map = SkateMap::load(std::path::Path::new(&path))?;
|
||||
let mut buckets: HashMap<(u32, u32, u32, u64), Vec<usize>> = HashMap::new();
|
||||
let mut bytes = 0usize;
|
||||
let mut unique_bytes = 0usize;
|
||||
let mut unique = 0;
|
||||
for (i, t) in map.textures.iter().enumerate() {
|
||||
bytes += t.rgba.len();
|
||||
let mut hash = std::collections::hash_map::DefaultHasher::new();
|
||||
t.rgba.hash(&mut hash);
|
||||
let bucket = buckets
|
||||
.entry((t.width, t.height, t.color_space, hash.finish()))
|
||||
.or_default();
|
||||
if !bucket.iter().any(|&j| map.textures[j].rgba == t.rgba) {
|
||||
bucket.push(i);
|
||||
unique += 1;
|
||||
unique_bytes += t.rgba.len();
|
||||
}
|
||||
}
|
||||
let mut bounds = vec![([f32::INFINITY; 3], [f32::NEG_INFINITY; 3], 0u64); map.materials.len()];
|
||||
let mut cells = HashSet::new();
|
||||
for tri in map.geometry.indices.chunks_exact(3) {
|
||||
let material = map.geometry.vertices[tri[0] as usize].material as usize - 1;
|
||||
let b = &mut bounds[material];
|
||||
b.2 += 1;
|
||||
let mut center = [0.; 3];
|
||||
for &i in tri {
|
||||
let p = map.geometry.vertices[i as usize].position;
|
||||
for a in 0..3 {
|
||||
b.0[a] = b.0[a].min(p[a]);
|
||||
b.1[a] = b.1[a].max(p[a]);
|
||||
center[a] += p[a] / 3.;
|
||||
}
|
||||
}
|
||||
cells.insert((
|
||||
material,
|
||||
(center[0] / 32.).floor() as i32,
|
||||
(center[2] / 32.).floor() as i32,
|
||||
));
|
||||
}
|
||||
let used: Vec<_> = bounds.iter().filter(|b| b.2 > 0).collect();
|
||||
let spans: Vec<_> = [50.,100.,250.,500.].into_iter().map(|threshold| {
|
||||
let matching: Vec<_> = used.iter().filter(|b|(b.1[0]-b.0[0]).max(b.1[2]-b.0[2])>threshold).collect();
|
||||
serde_json::json!({"horizontal_extent_over_metres":threshold,"raw_material_groups":matching.len(),"triangles":matching.iter().map(|b|b.2).sum::<u64>()})
|
||||
}).collect();
|
||||
println!("{}",serde_json::to_string_pretty(&serde_json::json!({
|
||||
"schema":1,"map_version":map.version,"vertices":map.geometry.vertices.len(),"triangles":map.geometry.indices.len()/3,
|
||||
"materials":map.materials.len(),"used_raw_material_groups":used.len(),"raw_material_32m_cells":cells.len(),
|
||||
"textures":map.textures.len(),"unique_texture_payloads":unique,"decoded_texture_bytes":bytes,"unique_decoded_texture_bytes":unique_bytes,
|
||||
"rail_records":map.rails.len(),"bounds":spans,
|
||||
"interpretation":"Raw material groups before renderer canonicalization; cells are triangle-centroid estimates, not actual proposed batches. Texture bytes exclude role expansion, mip chains and GPU allocation. No visibility or frame-time measurement."
|
||||
})).unwrap());
|
||||
Ok(())
|
||||
}
|
||||
@@ -23,7 +23,8 @@ default = ["dev-dynamic"]
|
||||
dev-dynamic = ["bevy/dynamic_linking"]
|
||||
|
||||
[dependencies]
|
||||
bevy = { workspace = true, features = ["jpeg"] }
|
||||
bevy = { workspace = true, features = ["jpeg", "trace"] }
|
||||
tracing-log = "0.2"
|
||||
skate-core.workspace = true
|
||||
skate-data.workspace = true
|
||||
half = "=2.7.1"
|
||||
|
||||
@@ -65,7 +65,7 @@ pub(crate) fn build(
|
||||
..default()
|
||||
}),
|
||||
..default()
|
||||
}),
|
||||
}).build().disable::<bevy::log::LogPlugin>(),
|
||||
)
|
||||
.insert_resource(bevy::winit::WinitSettings {focused_mode:bevy::winit::UpdateMode::Continuous,unfocused_mode:bevy::winit::UpdateMode::Continuous})
|
||||
.insert_resource(config)
|
||||
@@ -119,5 +119,6 @@ pub(crate) fn build(
|
||||
app.add_plugins(crate::multiplayer::MultiplayerPlugin);
|
||||
app.add_plugins(crate::scoring_hud::ScoringHudPlugin);
|
||||
app.add_systems(Last, crate::crash_context::sample);
|
||||
crate::profiling::install(&mut app);
|
||||
app
|
||||
}
|
||||
@@ -34,6 +34,8 @@ impl Config {
|
||||
let mut args = std::env::args_os().skip(1);
|
||||
while let Some(arg) = args.next() {
|
||||
match arg.to_str() {
|
||||
Some("--trace" | "--trace-seconds" | "--trace-delay") => { args.next().ok_or("Trace option requires a value")?; }
|
||||
Some("--trace-wait" | "--trace-gpu") => {}
|
||||
Some("--net-host") => config.multiplayer.host = Some(args.next().ok_or("Missing host bind address")?.to_string_lossy().parse().map_err(|_|"Invalid host bind address")?),
|
||||
Some("--net-local") => {
|
||||
let bind=args.next().ok_or("--net-local requires bind and peer addresses")?.to_string_lossy().parse().map_err(|_|"Invalid bind address")?;
|
||||
|
||||
@@ -30,6 +30,7 @@ mod physics;
|
||||
mod skater_animation;
|
||||
mod verification;
|
||||
mod performance;
|
||||
mod profiling;
|
||||
mod graphics_menu;
|
||||
mod modding;
|
||||
mod customiser;
|
||||
@@ -54,14 +55,20 @@ fn main() -> bevy::app::AppExit {
|
||||
Ok(false) => {}
|
||||
}
|
||||
if let Some(code) = crash_report::entry() { std::process::exit(code); }
|
||||
let _trace = match profiling::init() {
|
||||
Ok(guard) => guard,
|
||||
Err(error) => { eprintln!("{error}"); return bevy::app::AppExit::error(); }
|
||||
};
|
||||
let _startup = bevy::log::info_span!("startup").entered();
|
||||
eprintln!("REPORT_META stage=configuration_and_installation");
|
||||
let config = match config::Config::from_env() {
|
||||
let config = match bevy::log::info_span!("load_configuration_and_map").in_scope(config::Config::from_env) {
|
||||
Ok(config) => config,
|
||||
Err(error) => {
|
||||
eprintln!("{error}");
|
||||
return bevy::app::AppExit::error();
|
||||
}
|
||||
};
|
||||
profiling::map_metadata(&config);
|
||||
eprintln!("REPORT_META startup=map_fingerprint:{:016x} difficulty:{} multiplayer_requested:{} custom_appearance:{} renderer:Vulkan", config.map_fingerprint, config.difficulty.key(), config.multiplayer.host.is_some() || config.multiplayer.direct.is_some(), config.multiplayer.appearance.is_some());
|
||||
eprintln!("REPORT_META stage=gameplay_configuration");
|
||||
if let Err(error) = skate_data::input_config::StockGameplayConfig::load(&config.asset_root) {
|
||||
@@ -69,7 +76,7 @@ fn main() -> bevy::app::AppExit {
|
||||
return bevy::app::AppExit::error();
|
||||
}
|
||||
eprintln!("REPORT_META stage=asset_manifest");
|
||||
let manifest = match skate_data::GameAssets::load(&config.asset_root) {
|
||||
let manifest = match bevy::log::info_span!("load_manifest").in_scope(|| skate_data::GameAssets::load(&config.asset_root)) {
|
||||
Ok(manifest) => manifest,
|
||||
Err(error) => {
|
||||
eprintln!("{error}");
|
||||
@@ -77,7 +84,7 @@ fn main() -> bevy::app::AppExit {
|
||||
}
|
||||
};
|
||||
eprintln!("REPORT_META stage=stock_graphs");
|
||||
let graphs = match graph_runtime::StockGraphs::load(&config.asset_root, &manifest) {
|
||||
let graphs = match bevy::log::info_span!("load_graphs").in_scope(|| graph_runtime::StockGraphs::load(&config.asset_root, &manifest)) {
|
||||
Ok(graphs) => graphs,
|
||||
Err(error) => {
|
||||
eprintln!("{error}");
|
||||
@@ -93,7 +100,7 @@ fn main() -> bevy::app::AppExit {
|
||||
}
|
||||
eprintln!("SKATE_DIFFICULTY mode={} native_index={}", config.difficulty.key(), config.difficulty as u32);
|
||||
eprintln!("REPORT_META stage=physics_initialization");
|
||||
let mut physics = match physics::GamePhysics::load_with_difficulty(&config.asset_root, config.map.as_ref(), config.difficulty) {
|
||||
let mut physics = match bevy::log::info_span!("load_physics").in_scope(|| physics::GamePhysics::load_with_difficulty(&config.asset_root, config.map.as_ref(), config.difficulty)) {
|
||||
Ok(physics) => physics,
|
||||
Err(error) => {
|
||||
eprintln!("{error}");
|
||||
@@ -106,7 +113,7 @@ fn main() -> bevy::app::AppExit {
|
||||
physics.board.set_transform(spawn);
|
||||
}
|
||||
eprintln!("REPORT_META stage=skater_initialization");
|
||||
let skater = match physics::SkaterRuntime::load(&config.asset_root, &graphs, &physics, config.difficulty.key()) {
|
||||
let skater = match bevy::log::info_span!("load_skater").in_scope(|| physics::SkaterRuntime::load(&config.asset_root, &graphs, &physics, config.difficulty.key())) {
|
||||
Ok(skater) => skater,
|
||||
Err(error) => {
|
||||
eprintln!("{error}");
|
||||
@@ -130,6 +137,7 @@ fn main() -> bevy::app::AppExit {
|
||||
let mut app = app::build(config, manifest, graphs, physics, skater);
|
||||
app.insert_resource(controls);
|
||||
eprintln!("REPORT_META stage=app_run");
|
||||
drop(_startup);
|
||||
app.run()
|
||||
}
|
||||
|
||||
|
||||
@@ -104,6 +104,7 @@ impl PreparedScene {
|
||||
}
|
||||
}
|
||||
pub fn publish(mut self, world: &mut World) {
|
||||
let _span = info_span!("publish_map_assets").entered();
|
||||
let owned = MapAssets {
|
||||
meshes: self.meshes.publish(world), materials: self.materials.publish(world),
|
||||
retail: self.retail.publish(world), sky: self.sky.publish(world),
|
||||
|
||||
@@ -102,8 +102,9 @@ fn start(world: &World, entry: Entry) -> Result<Phase, String> {
|
||||
let progress = Arc::new(AtomicU8::new(0));
|
||||
let stage = progress.clone();
|
||||
let job = std::thread::Builder::new().name("map-loader".into()).spawn(move || {
|
||||
let _span = info_span!("load_map_transition").entered();
|
||||
let started = Instant::now();
|
||||
let map = selected.path.as_deref().map(skate_data::skate_map::SkateMap::load).transpose()?;
|
||||
let map = info_span!("read_map").in_scope(|| selected.path.as_deref().map(skate_data::skate_map::SkateMap::load).transpose())?;
|
||||
let map_fingerprint = crate::config::map_fingerprint(selected.path.as_deref())?;
|
||||
let read_time = started.elapsed();
|
||||
let validation_started = Instant::now();
|
||||
@@ -125,7 +126,7 @@ fn start(world: &World, entry: Entry) -> Result<Phase, String> {
|
||||
let simulation_started = Instant::now();
|
||||
let simulation = (|| -> Result<_, String> {
|
||||
stage.store(1, Ordering::Relaxed);
|
||||
let physics = GamePhysics::load_with_difficulty(&root, map.as_ref(), difficulty)?;
|
||||
let physics = info_span!("load_physics").in_scope(|| GamePhysics::load_with_difficulty(&root, map.as_ref(), difficulty))?;
|
||||
stage.store(2, Ordering::Relaxed);
|
||||
let skater = SkaterRuntime::load_for_world(&root, &graphs, &physics, difficulty.key(), Some(source))?;
|
||||
let mut controls = PlayerControls::load(&root)?;
|
||||
|
||||
@@ -53,13 +53,13 @@ pub(super) fn advance(
|
||||
.riding
|
||||
.start_wheel_queries(&physics.board, &physics.world)?;
|
||||
let skeleton_queries = super::foot_ik_queries::query(&physics.world, &skater.skeleton)?;
|
||||
let animation = animation_phase::advance(
|
||||
let animation = bevy::log::info_span!("fixed_animation_graphs").in_scope(|| animation_phase::advance(
|
||||
physics,
|
||||
skater,
|
||||
controls,
|
||||
graphs,
|
||||
&physics.animation_profile,
|
||||
)
|
||||
))
|
||||
.map_err(|e| format!("Animation tick{}: {e}", physics.ticks))?;
|
||||
super::offboard_audit_trace::stage(tick, "animation", physics, skater, controls);
|
||||
#[cfg(test)]
|
||||
@@ -228,14 +228,14 @@ pub(super) fn advance(
|
||||
//World8275ECA4 ends skeleton tests after state/forces and before solving.
|
||||
//Teleport resets previous observations, but preserves this pending batch.
|
||||
skeleton_queries.publish(&mut skater.player_input.player);
|
||||
solve::advance(physics, skater, skater.ground.steering.targets)?;
|
||||
bevy::log::info_span!("fixed_collision_and_solve").in_scope(|| solve::advance(physics, skater, skater.ground.steering.targets))?;
|
||||
super::offboard_audit_trace::stage(tick, "solve", physics, skater, controls);
|
||||
#[cfg(test)]
|
||||
super::offboard_root_trace::trace(tick, "solve", skater);
|
||||
//ProcessOutput82DB6EE8 resets the packet before its component publishers.
|
||||
//All consumers of the preceding output have completed this frame's input.
|
||||
super::player_input::reset_outputs(&mut skater.player_input.physical);
|
||||
physics.finish_skater(skater)?;
|
||||
bevy::log::info_span!("fixed_finish_skater").in_scope(|| physics.finish_skater(skater))?;
|
||||
super::offboard_audit_trace::stage(tick, "finish", physics, skater, controls);
|
||||
#[cfg(test)]
|
||||
super::offboard_root_trace::trace(tick, "finish", skater);
|
||||
|
||||
@@ -0,0 +1,562 @@
|
||||
//! Bounded, local-only CPU timeline. GPU diagnostics are delayed duration counters.
|
||||
use bevy::{
|
||||
log::{
|
||||
tracing::{
|
||||
self, Subscriber,
|
||||
span::{Attributes, Id},
|
||||
},
|
||||
tracing_subscriber::{
|
||||
self as subscriber, Layer,
|
||||
layer::{Context, SubscriberExt},
|
||||
registry::LookupSpan,
|
||||
},
|
||||
},
|
||||
prelude::*,
|
||||
};
|
||||
use serde_json::{Value, json};
|
||||
use std::{
|
||||
cell::RefCell,
|
||||
collections::HashMap,
|
||||
fs::OpenOptions,
|
||||
io::{BufWriter, Write},
|
||||
path::PathBuf,
|
||||
sync::{
|
||||
Arc, OnceLock,
|
||||
atomic::{AtomicBool, AtomicU64, Ordering},
|
||||
mpsc::{SyncSender, sync_channel},
|
||||
},
|
||||
thread::JoinHandle,
|
||||
time::{Duration, Instant},
|
||||
};
|
||||
|
||||
const MAX_BYTES: usize = 128 * 1024 * 1024;
|
||||
static CAPTURE: OnceLock<Arc<Capture>> = OnceLock::new();
|
||||
static NEXT_THREAD: AtomicU64 = AtomicU64::new(1);
|
||||
thread_local! {
|
||||
static THREAD: u64 = NEXT_THREAD.fetch_add(1, Ordering::Relaxed);
|
||||
static ENTERED: RefCell<Vec<(u64, Instant)>> = const { RefCell::new(Vec::new()) };
|
||||
}
|
||||
#[derive(Debug, Default)]
|
||||
struct Options {
|
||||
path: Option<PathBuf>,
|
||||
seconds: u64,
|
||||
delay: u64,
|
||||
wait: bool,
|
||||
gpu: bool,
|
||||
}
|
||||
impl Options {
|
||||
fn parse(args: impl Iterator<Item = std::ffi::OsString>) -> Result<Self, String> {
|
||||
let mut result = Self {
|
||||
seconds: 30,
|
||||
..Self::default()
|
||||
};
|
||||
let mut args = args;
|
||||
let mut modifiers = false;
|
||||
while let Some(arg) = args.next() {
|
||||
match arg.to_str() {
|
||||
Some("--trace") => {
|
||||
if result.path.is_some() {
|
||||
return Err("Duplicate --trace".into());
|
||||
}
|
||||
result.path = Some(
|
||||
args.next()
|
||||
.ok_or("--trace requires a new output JSON path")?
|
||||
.into(),
|
||||
);
|
||||
}
|
||||
Some("--trace-seconds" | "--trace-delay") => {
|
||||
modifiers = true;
|
||||
let value = args
|
||||
.next()
|
||||
.and_then(|a| a.to_str().and_then(|v| v.parse::<u64>().ok()))
|
||||
.ok_or("Trace duration must be an integer")?;
|
||||
if value > 600 || (arg == "--trace-seconds" && value == 0) {
|
||||
return Err("Trace seconds: 1..600; delay: 0..600".into());
|
||||
}
|
||||
if arg == "--trace-seconds" {
|
||||
result.seconds = value;
|
||||
} else {
|
||||
result.delay = value;
|
||||
}
|
||||
}
|
||||
Some("--trace-wait") => {
|
||||
modifiers = true;
|
||||
result.wait = true;
|
||||
}
|
||||
Some("--trace-gpu") => {
|
||||
modifiers = true;
|
||||
result.gpu = true;
|
||||
}
|
||||
// Consume values of other CLI options; never interpret them as trace flags.
|
||||
Some("--net-local") => {
|
||||
args.next();
|
||||
args.next();
|
||||
}
|
||||
Some(
|
||||
"--net-host" | "--net-session" | "--spawn-offset" | "--player-title"
|
||||
| "--appearance" | "--controller" | "--assets" | "--map" | "--teleport"
|
||||
| "--difficulty" | "--verify",
|
||||
) => {
|
||||
args.next();
|
||||
}
|
||||
_ => {}
|
||||
}
|
||||
}
|
||||
if modifiers && result.path.is_none() {
|
||||
return Err("Trace modifiers require --trace FILE.json".into());
|
||||
}
|
||||
if result.wait && result.delay != 0 {
|
||||
return Err("Choose --trace-wait or --trace-delay".into());
|
||||
}
|
||||
Ok(result)
|
||||
}
|
||||
}
|
||||
struct Capture {
|
||||
origin: Instant,
|
||||
active: AtomicBool,
|
||||
start: AtomicBool,
|
||||
stop: AtomicBool,
|
||||
dropped: AtomicU64,
|
||||
sender: SyncSender<Value>,
|
||||
gpu: bool,
|
||||
}
|
||||
impl Capture {
|
||||
fn send(&self, value: Value) {
|
||||
if self.sender.try_send(value).is_err() {
|
||||
self.dropped.fetch_add(1, Ordering::Relaxed);
|
||||
}
|
||||
}
|
||||
fn counter(&self, name: &str, args: Value) {
|
||||
if self.active.load(Ordering::Relaxed) {
|
||||
self.send(json!({"name":name,"ph":"C","pid":1,"tid":0,"ts":self.origin.elapsed().as_micros() as u64,"args":args}));
|
||||
}
|
||||
}
|
||||
}
|
||||
pub(crate) struct Guard(Arc<Capture>, Option<JoinHandle<std::io::Result<()>>>);
|
||||
impl Drop for Guard {
|
||||
fn drop(&mut self) {
|
||||
self.0.stop.store(true, Ordering::Relaxed);
|
||||
if let Some(writer) = self.1.take() {
|
||||
if !matches!(writer.join(), Ok(Ok(()))) {
|
||||
eprintln!("TRACE export failed; capture may be incomplete");
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
pub(crate) fn init() -> Result<Option<Guard>, String> {
|
||||
let options = Options::parse(std::env::args_os().skip(1))?;
|
||||
init_options(options)
|
||||
}
|
||||
fn init_options(options: Options) -> Result<Option<Guard>, String> {
|
||||
let mut guard = None;
|
||||
let layer = if let Some(path) = options.path {
|
||||
// create_new refuses to destroy a previous recording.
|
||||
let file = OpenOptions::new()
|
||||
.write(true)
|
||||
.create_new(true)
|
||||
.open(&path)
|
||||
.map_err(
|
||||
|_| "Cannot create trace: use a new filename in an existing writable directory",
|
||||
)?;
|
||||
let (sender, receiver) = sync_channel::<Value>(8192);
|
||||
let capture = Arc::new(Capture {
|
||||
origin: Instant::now(),
|
||||
active: AtomicBool::new(!options.wait && options.delay == 0),
|
||||
start: AtomicBool::new(false),
|
||||
stop: AtomicBool::new(false),
|
||||
dropped: AtomicU64::new(0),
|
||||
sender,
|
||||
gpu: options.gpu,
|
||||
});
|
||||
CAPTURE
|
||||
.set(capture.clone())
|
||||
.map_err(|_| "Trace already initialized")?;
|
||||
let state = capture.clone();
|
||||
let writer = std::thread::Builder::new().name("trace-export".into()).spawn(move || {
|
||||
let result = (|| -> std::io::Result<()> {
|
||||
let mut writer = BufWriter::new(file);
|
||||
writer.write_all(b"{\"traceEvents\":[\n")?;
|
||||
let mut bytes = 0;
|
||||
let mut started = state.active.load(Ordering::Relaxed).then(Instant::now);
|
||||
let mut reason = "stopped";
|
||||
loop {
|
||||
if state.stop.load(Ordering::Relaxed) { break; }
|
||||
if started.is_none() && (state.start.swap(false, Ordering::Relaxed) || (!options.wait && state.origin.elapsed().as_secs() >= options.delay)) {
|
||||
started = Some(Instant::now());
|
||||
state.active.store(true, Ordering::Relaxed);
|
||||
}
|
||||
if started.is_some_and(|s| s.elapsed() >= Duration::from_secs(options.seconds)) { reason = "duration"; break; }
|
||||
if let Ok(event) = receiver.recv_timeout(Duration::from_millis(20)) {
|
||||
let line = serde_json::to_vec(&event)?;
|
||||
if bytes + line.len() + 2 > MAX_BYTES { reason = "size_limit"; break; }
|
||||
writer.write_all(&line)?;
|
||||
writer.write_all(b",\n")?;
|
||||
bytes += line.len() + 2;
|
||||
}
|
||||
}
|
||||
state.active.store(false, Ordering::Relaxed);
|
||||
// Drain the bounded queue on normal stop so end-of-frame events survive.
|
||||
while let Ok(event) = receiver.try_recv() {
|
||||
let line = serde_json::to_vec(&event)?;
|
||||
if bytes + line.len() + 2 > MAX_BYTES { reason = "size_limit"; break; }
|
||||
writer.write_all(&line)?; writer.write_all(b",\n")?; bytes += line.len() + 2;
|
||||
}
|
||||
let footer = json!({"name":"capture_complete","ph":"i","s":"g","pid":1,"tid":0,"ts":state.origin.elapsed().as_micros() as u64,"args":{"reason":reason,"dropped_events":state.dropped.load(Ordering::Relaxed)}});
|
||||
serde_json::to_writer(&mut writer, &footer)?;
|
||||
writer.write_all(b"],\"displayTimeUnit\":\"ms\"}\n")?;
|
||||
writer.flush()?;
|
||||
eprintln!("TRACE complete ({reason}); open the requested JSON in https://ui.perfetto.dev");
|
||||
Ok(())
|
||||
})();
|
||||
state.active.store(false, Ordering::Relaxed);
|
||||
if result.is_err() { eprintln!("TRACE export failed; check free disk space and destination access"); }
|
||||
result
|
||||
}).map_err(|_| "Cannot start trace writer")?;
|
||||
capture.send(json!({"name":"build","ph":"M","pid":1,"tid":0,"args":{"build_id":env!("SKATE_BUILD_ID"),"version":env!("CARGO_PKG_VERSION"),"revision":env!("SKATE_RELEASE_REVISION"),"bevy":"0.18.1","wgpu":"27.0.1","debug_assertions":cfg!(debug_assertions),"gpu_requested":options.gpu,"seconds":options.seconds,"delay":options.delay,"wait":options.wait}}));
|
||||
eprintln!(
|
||||
"TRACE armed; F9 starts waiting capture, F10 stops/exports. Recording does not stop gameplay."
|
||||
);
|
||||
guard = Some(Guard(capture.clone(), Some(writer)));
|
||||
Some(
|
||||
Timeline(capture).with_filter(subscriber::filter::FilterFn::new(|m| {
|
||||
m.is_span()
|
||||
&& (m.target().starts_with("bevy_") || m.target().starts_with("skate3rust"))
|
||||
})),
|
||||
)
|
||||
} else {
|
||||
None
|
||||
};
|
||||
// Per-layer filters keep spans completely disabled in normal play. No environment
|
||||
// filter is applied to the recorder; RUST_LOG cannot silently remove its systems.
|
||||
let filter = subscriber::EnvFilter::try_from_default_env()
|
||||
.unwrap_or_else(|_| subscriber::EnvFilter::new("info,wgpu=error,naga=warn"));
|
||||
let logs = subscriber::fmt::layer()
|
||||
.with_writer(std::io::stderr)
|
||||
.with_filter(subscriber::filter::FilterFn::new(|m| m.is_event()))
|
||||
.with_filter(filter);
|
||||
tracing::subscriber::set_global_default(subscriber::registry().with(layer).with(logs))
|
||||
.map_err(|_| "Cannot install profiling/log subscriber")?;
|
||||
let _ = tracing_log::LogTracer::init();
|
||||
Ok(guard)
|
||||
}
|
||||
|
||||
struct Timeline(Arc<Capture>);
|
||||
#[derive(Default)]
|
||||
struct SystemName(String);
|
||||
impl tracing::field::Visit for SystemName {
|
||||
fn record_debug(&mut self, _: &tracing::field::Field, _: &dyn std::fmt::Debug) {}
|
||||
fn record_str(&mut self, field: &tracing::field::Field, value: &str) {
|
||||
if field.name() == "name" && value.len() <= 512 && !value.contains(['/', '\\', '\n']) {
|
||||
self.0 = value.into();
|
||||
}
|
||||
}
|
||||
}
|
||||
impl<S: Subscriber + for<'a> LookupSpan<'a>> Layer<S> for Timeline {
|
||||
fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
|
||||
// Only Bevy ECS system labels may supply dynamic text. All other fields,
|
||||
// source locations, thread names and log events are deliberately omitted.
|
||||
if attrs.metadata().target().starts_with("bevy_ecs")
|
||||
&& matches!(attrs.metadata().name(), "system" | "system_commands")
|
||||
{
|
||||
let mut name = SystemName::default();
|
||||
attrs.record(&mut name);
|
||||
if let Some(span) = ctx.span(id) {
|
||||
span.extensions_mut().insert(name);
|
||||
}
|
||||
}
|
||||
}
|
||||
fn on_enter(&self, id: &Id, _: Context<'_, S>) {
|
||||
if self.0.active.load(Ordering::Relaxed) {
|
||||
ENTERED.with(|stack| stack.borrow_mut().push((id.into_u64(), Instant::now())));
|
||||
}
|
||||
}
|
||||
fn on_exit(&self, id: &Id, ctx: Context<'_, S>) {
|
||||
let start = ENTERED.with(|stack| {
|
||||
let mut stack = stack.borrow_mut();
|
||||
let index = stack.iter().rposition(|(key, _)| *key == id.into_u64())?;
|
||||
Some(stack.remove(index).1)
|
||||
});
|
||||
if let Some(start) = start.filter(|_| self.0.active.load(Ordering::Relaxed)) {
|
||||
if let Some(span) = ctx.span(id) {
|
||||
let ext = span.extensions();
|
||||
let label = ext
|
||||
.get::<SystemName>()
|
||||
.filter(|s| !s.0.is_empty())
|
||||
.map(|s| s.0.as_str())
|
||||
.unwrap_or(span.metadata().name());
|
||||
THREAD.with(|tid| self.0.send(json!({"name":label,"cat":span.metadata().name(),"ph":"X","pid":1,"tid":tid,"ts":start.duration_since(self.0.origin).as_micros() as u64,"dur":start.elapsed().as_micros() as u64})));
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
#[derive(Resource, Default)]
|
||||
struct Frames {
|
||||
last: Option<Instant>,
|
||||
fixed: u32,
|
||||
frame: u64,
|
||||
diagnostics: HashMap<String, (usize, bevy::platform::time::Instant)>,
|
||||
}
|
||||
pub(crate) fn install(app: &mut App) {
|
||||
let Some(capture) = CAPTURE.get() else {
|
||||
return;
|
||||
};
|
||||
if capture.gpu {
|
||||
app.add_plugins(bevy::render::diagnostic::RenderDiagnosticsPlugin);
|
||||
}
|
||||
if let Some(render) = app.get_sub_app_mut(bevy::render::RenderApp) {
|
||||
render.add_systems(
|
||||
bevy::render::Render,
|
||||
render_counters.after(bevy::render::RenderSystems::Cleanup),
|
||||
);
|
||||
}
|
||||
app.init_resource::<Frames>()
|
||||
.add_systems(First, begin_frame)
|
||||
.add_systems(FixedFirst, |mut frames: ResMut<Frames>| {
|
||||
frames.fixed += 1;
|
||||
})
|
||||
.add_systems(Last, end_frame);
|
||||
}
|
||||
fn render_counters(
|
||||
mut frame: Local<u64>,
|
||||
meshes: Res<bevy::render::render_asset::RenderAssets<bevy::render::mesh::RenderMesh>>,
|
||||
images: Res<bevy::render::render_asset::RenderAssets<bevy::render::texture::GpuImage>>,
|
||||
pipelines: Res<bevy::render::render_resource::PipelineCache>,
|
||||
) {
|
||||
*frame += 1;
|
||||
let capture = CAPTURE.get().unwrap();
|
||||
if *frame % 60 == 1 && capture.active.load(Ordering::Relaxed) {
|
||||
capture.counter("render_resources",json!({"prepared_meshes":meshes.iter().count(),"prepared_images":images.iter().count(),"waiting_pipelines":pipelines.waiting_pipelines().count()}));
|
||||
}
|
||||
}
|
||||
pub(crate) fn map_metadata(config: &crate::config::Config) {
|
||||
let Some(capture) = CAPTURE.get() else {
|
||||
return;
|
||||
};
|
||||
capture.send(json!({"name":"loaded_map","ph":"i","s":"g","pid":1,"tid":0,"ts":capture.origin.elapsed().as_micros() as u64,"args":{"fingerprint":format!("{:016x}",config.map_fingerprint),"difficulty":config.difficulty.key(),"geometry":config.map.as_ref().map(|m|json!({"version":m.version,"triangles":m.geometry.indices.len()/3,"materials":m.materials.len(),"textures":m.textures.len(),"rail_records":m.rails.len()}))}}));
|
||||
}
|
||||
fn begin_frame(mut frames: ResMut<Frames>) {
|
||||
let capture = CAPTURE.get().unwrap();
|
||||
let now = Instant::now();
|
||||
if let Some(last) = frames.last.replace(now) {
|
||||
capture.counter(
|
||||
"frame_interval_ms",
|
||||
json!({"value":now.duration_since(last).as_secs_f64()*1000.}),
|
||||
);
|
||||
}
|
||||
frames.fixed = 0;
|
||||
frames.frame += 1;
|
||||
}
|
||||
fn end_frame(
|
||||
mut frames: ResMut<Frames>,
|
||||
keys: Res<ButtonInput<KeyCode>>,
|
||||
config: Res<crate::config::Config>,
|
||||
fixed: Res<Time<Fixed>>,
|
||||
meshes: Res<Assets<Mesh>>,
|
||||
images: Res<Assets<Image>>,
|
||||
entities: Query<Entity>,
|
||||
diagnostics: Res<bevy::diagnostic::DiagnosticsStore>,
|
||||
device: Option<Res<bevy::render::renderer::RenderDevice>>,
|
||||
windows: Query<&Window>,
|
||||
cameras: Query<(&Camera, &Msaa)>,
|
||||
menu: Option<Res<crate::graphics_menu::Menu>>,
|
||||
map: Res<crate::map_transition::CurrentMap>,
|
||||
transition: Res<crate::map_transition::MapTransition>,
|
||||
adapter: Option<Res<bevy::render::renderer::RenderAdapterInfo>>,
|
||||
) {
|
||||
let capture = CAPTURE.get().unwrap();
|
||||
if keys.just_pressed(KeyCode::F9) {
|
||||
capture.start.store(true, Ordering::Relaxed);
|
||||
}
|
||||
if keys.just_pressed(KeyCode::F10) {
|
||||
capture.stop.store(true, Ordering::Relaxed);
|
||||
}
|
||||
if !capture.active.load(Ordering::Relaxed) {
|
||||
return;
|
||||
}
|
||||
capture.counter("frame", json!({"number":frames.frame,"fixed_schedule_iterations":frames.fixed,"fixed_period_ms":fixed.timestep().as_secs_f64()*1000.,"cpu_main_until_trace_sample_ms":frames.last.unwrap().elapsed().as_secs_f64()*1000.}));
|
||||
if frames.frame % 60 == 1 {
|
||||
if let Some(adapter) = adapter {
|
||||
capture.send(json!({"name":"adapter","ph":"i","s":"g","pid":1,"tid":0,"ts":capture.origin.elapsed().as_micros() as u64,"args":{"vendor":adapter.vendor,"device":adapter.device,"backend":format!("{:?}",adapter.backend)}}));
|
||||
}
|
||||
capture.send(json!({"name":"game_configuration","ph":"i","s":"g","pid":1,"tid":0,"ts":capture.origin.elapsed().as_micros() as u64,"args":{"graphics":menu.as_ref().map(|m|m.diagnostic_settings()),"paused":menu.as_ref().is_some_and(|m|m.open),"map_loading":transition.busy(),"map_generation":map.generation}}));
|
||||
capture.counter(
|
||||
"assets",
|
||||
json!({"meshes":meshes.len(),"images":images.len(),"entities":entities.iter().count()}),
|
||||
);
|
||||
capture.send(json!({"name":"configuration","ph":"i","s":"g","pid":1,"tid":0,"ts":capture.origin.elapsed().as_micros() as u64,"args":{"map_fingerprint":format!("{:016x}",config.map_fingerprint),"difficulty":config.difficulty.key(),"timestamp_queries":device.as_ref().is_some_and(|d|d.features().contains(bevy::render::settings::WgpuFeatures::TIMESTAMP_QUERY)),"windows":windows.iter().map(|w|json!({"width":w.physical_width(),"height":w.physical_height(),"present_mode":format!("{:?}",w.present_mode)})).collect::<Vec<_>>(),"cameras":cameras.iter().map(|(c,m)|json!({"size":c.physical_target_size().map(|s|[s.x,s.y]),"msaa":m.samples()})).collect::<Vec<_>>()}}));
|
||||
}
|
||||
for diagnostic in diagnostics.iter() {
|
||||
let path = diagnostic.path().as_str();
|
||||
// Built-in render paths only. Do not export arbitrary plugin diagnostic labels.
|
||||
if !path.starts_with("render/") || path.len() > 1024 || path.contains(['\\', ':']) {
|
||||
continue;
|
||||
}
|
||||
let Some(measurement) = diagnostic.measurement() else {
|
||||
continue;
|
||||
};
|
||||
if frames
|
||||
.diagnostics
|
||||
.get(path)
|
||||
.is_some_and(|(_, time)| *time == measurement.time)
|
||||
{
|
||||
continue;
|
||||
}
|
||||
if frames.diagnostics.len() >= 2048 && !frames.diagnostics.contains_key(path) {
|
||||
continue;
|
||||
}
|
||||
let next = frames.diagnostics.len();
|
||||
let entry = frames
|
||||
.diagnostics
|
||||
.entry(path.into())
|
||||
.or_insert((next, measurement.time));
|
||||
entry.1 = measurement.time;
|
||||
// View names may originate in mods. Keep a stable numeric series ID and
|
||||
// only allowlisted engine pass/measurement labels in the exported name.
|
||||
if let Some(label) = render_label(path, entry.0) {
|
||||
capture.counter(&label, json!({"value":measurement.value}));
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
fn render_label(path: &str, id: usize) -> Option<String> {
|
||||
let field = path.rsplit('/').next()?;
|
||||
if !matches!(
|
||||
field,
|
||||
"elapsed_cpu"
|
||||
| "elapsed_gpu"
|
||||
| "vertex_shader_invocations"
|
||||
| "clipper_invocations"
|
||||
| "clipper_primitives_out"
|
||||
| "fragment_shader_invocations"
|
||||
| "compute_shader_invocations"
|
||||
) {
|
||||
return None;
|
||||
}
|
||||
let pass = path
|
||||
.split('/')
|
||||
.find(|s| {
|
||||
matches!(
|
||||
*s,
|
||||
"main_opaque_pass_3d"
|
||||
| "main_transparent_pass_3d"
|
||||
| "main_transmissive_pass_3d"
|
||||
| "early_mesh_preprocessing"
|
||||
| "late_mesh_preprocessing"
|
||||
| "retail_exposure_meter"
|
||||
| "retail_exposed_tone"
|
||||
| "prepass"
|
||||
| "early_prepass"
|
||||
| "late_prepass"
|
||||
| "tonemapping"
|
||||
| "upscaling"
|
||||
| "depth_downsample"
|
||||
| "ui"
|
||||
)
|
||||
})
|
||||
.unwrap_or("other_pass");
|
||||
Some(format!("render/{id}/{pass}/{field}"))
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
#[test]
|
||||
fn disabled_subscriber_rejects_spans() {
|
||||
let logs = subscriber::fmt::layer()
|
||||
.with_filter(subscriber::filter::FilterFn::new(|m| m.is_event()));
|
||||
tracing::subscriber::with_default(subscriber::registry().with(logs), || {
|
||||
assert!(tracing::info_span!("disabled_probe").is_disabled());
|
||||
});
|
||||
}
|
||||
#[test]
|
||||
fn full_queue_drops_without_blocking() {
|
||||
let (sender, _receiver) = sync_channel(1);
|
||||
let capture = Capture {
|
||||
origin: Instant::now(),
|
||||
active: AtomicBool::new(true),
|
||||
start: AtomicBool::new(false),
|
||||
stop: AtomicBool::new(false),
|
||||
dropped: AtomicU64::new(0),
|
||||
sender,
|
||||
gpu: false,
|
||||
};
|
||||
for _ in 0..3 {
|
||||
capture.counter("test", json!({"value":1}));
|
||||
}
|
||||
assert_eq!(capture.dropped.load(Ordering::Relaxed), 2);
|
||||
}
|
||||
fn parse(args: &[&str]) -> Result<Options, String> {
|
||||
Options::parse(args.iter().map(std::ffi::OsString::from))
|
||||
}
|
||||
#[test]
|
||||
fn bounds_and_dependencies() {
|
||||
for args in [
|
||||
vec!["--trace-seconds", "0"],
|
||||
vec!["--trace", "a", "--trace-seconds", "601"],
|
||||
vec!["--trace", "a", "--trace-delay", "-1"],
|
||||
vec!["--trace-gpu"],
|
||||
vec!["--trace", "a", "--trace-wait", "--trace-delay", "1"],
|
||||
vec!["--trace", "a", "--trace", "b"],
|
||||
] {
|
||||
assert!(parse(&args).is_err());
|
||||
}
|
||||
let options = parse(&["--trace", "a", "--trace-seconds", "600", "--trace-wait"]).unwrap();
|
||||
assert!(options.wait);
|
||||
assert_eq!(options.seconds, 600);
|
||||
assert!(
|
||||
parse(&["--player-title", "--trace"])
|
||||
.unwrap()
|
||||
.path
|
||||
.is_none()
|
||||
);
|
||||
}
|
||||
#[test]
|
||||
fn viewer_export_wait_stop_and_privacy() {
|
||||
let path =
|
||||
std::env::temp_dir().join(format!("skate-trace-test-{}.json", std::process::id()));
|
||||
let _ = std::fs::remove_file(&path);
|
||||
let guard = init_options(Options {
|
||||
path: Some(path.clone()),
|
||||
seconds: 1,
|
||||
wait: true,
|
||||
..Options::default()
|
||||
})
|
||||
.unwrap()
|
||||
.unwrap();
|
||||
assert!(!guard.0.active.load(Ordering::Relaxed));
|
||||
guard.0.start.store(true, Ordering::Relaxed);
|
||||
let deadline = Instant::now() + Duration::from_secs(2);
|
||||
while !guard.0.active.load(Ordering::Relaxed) && Instant::now() < deadline {
|
||||
std::thread::sleep(Duration::from_millis(5));
|
||||
}
|
||||
assert!(guard.0.active.load(Ordering::Relaxed));
|
||||
tracing::info_span!(
|
||||
"safe_test_span",
|
||||
secret = "CANARY_SECRET",
|
||||
path = "C:\\CANARY_PERSONAL\\asset"
|
||||
)
|
||||
.in_scope(|| tracing::info!("CANARY_LOG"));
|
||||
drop(guard);
|
||||
let text = std::fs::read_to_string(&path).unwrap();
|
||||
let parsed: Value = serde_json::from_str(&text).unwrap();
|
||||
assert!(
|
||||
parsed["traceEvents"]
|
||||
.as_array()
|
||||
.unwrap()
|
||||
.iter()
|
||||
.any(|e| e["name"] == "safe_test_span" && e["ph"] == "X")
|
||||
);
|
||||
assert_eq!(
|
||||
parsed["traceEvents"].as_array().unwrap().last().unwrap()["name"],
|
||||
"capture_complete"
|
||||
);
|
||||
assert!(!text.contains("CANARY"));
|
||||
assert_eq!(
|
||||
render_label("render/CANARY_SECRET/main_opaque_pass_3d/elapsed_gpu", 7).unwrap(),
|
||||
"render/7/main_opaque_pass_3d/elapsed_gpu"
|
||||
);
|
||||
std::fs::remove_file(path).unwrap();
|
||||
}
|
||||
}
|
||||
@@ -228,6 +228,8 @@ impl ViewNode for ExposureNode {
|
||||
return Ok(());
|
||||
};
|
||||
let post = view.post_process_write();
|
||||
use bevy::render::diagnostic::RecordDiagnostics;
|
||||
let diagnostics = context.diagnostic_recorder();
|
||||
let meter = context.render_device().create_bind_group(
|
||||
"retail meter",
|
||||
&cache.get_bind_group_layout(&p.compute_layout),
|
||||
@@ -251,8 +253,10 @@ impl ViewNode for ExposureNode {
|
||||
timestamp_writes: None,
|
||||
});
|
||||
pass.set_pipeline(compute);
|
||||
let span = diagnostics.pass_span(&mut pass, "retail_exposure_meter");
|
||||
pass.set_bind_group(0, &meter, &[]);
|
||||
pass.dispatch_workgroups(1, 1, 1);
|
||||
span.end(&mut pass);
|
||||
}
|
||||
let mut pass = context.begin_tracked_render_pass(RenderPassDescriptor {
|
||||
label: Some("retail exposed tone"),
|
||||
@@ -267,8 +271,10 @@ impl ViewNode for ExposureNode {
|
||||
occlusion_query_set: None,
|
||||
});
|
||||
pass.set_render_pipeline(tone);
|
||||
let span = diagnostics.pass_span(&mut pass, "retail_exposed_tone");
|
||||
pass.set_bind_group(0, &output, &[]);
|
||||
pass.draw(0..3, 0..1);
|
||||
span.end(&mut pass);
|
||||
Ok(())
|
||||
}
|
||||
}
|
||||
@@ -21,6 +21,7 @@ use skate_data::skate_map::SkateMap;
|
||||
use std::collections::HashMap;
|
||||
|
||||
pub(crate) fn validate_runtime(map: &SkateMap) -> Result<(), String> {
|
||||
let _span = info_span!("validate_map").entered();
|
||||
let archive = retail_archive(map)?;
|
||||
if map.geometry.collision.is_empty() && archive.is_none() {
|
||||
return Err("SKATE map has no collision geometry".into());
|
||||
@@ -421,6 +422,39 @@ fn render_groups(
|
||||
groups
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod performance_inventory {
|
||||
use super::*;
|
||||
/// Explicit read-only inventory, never initializes Bevy or a GPU. Asset path
|
||||
/// stays in the environment; output contains counts/bounds only.
|
||||
#[test]
|
||||
#[ignore = "requires SKATE_MAP_INVENTORY and SKATE_MAP_INVENTORY_OUT"]
|
||||
fn runtime_batches() {
|
||||
let map = SkateMap::load(std::path::Path::new(&std::env::var_os("SKATE_MAP_INVENTORY").unwrap())).unwrap();
|
||||
let textures = render_texture_ids(&map.textures);
|
||||
let materials = render_material_ids(&map.materials, &textures);
|
||||
let groups = render_groups(&map.geometry, &materials);
|
||||
let mut spans = [0usize;4];
|
||||
let mut triangles = [0usize;4];
|
||||
let mut cells = std::collections::HashSet::new();
|
||||
for (material, indices) in &groups {
|
||||
let mut min = Vec3::splat(f32::INFINITY);
|
||||
let mut max = Vec3::splat(f32::NEG_INFINITY);
|
||||
for &i in indices { let p=Vec3::from_array(map.geometry.vertices[i as usize].position); min=min.min(p); max=max.max(p); }
|
||||
let extent=(max.x-min.x).max(max.z-min.z);
|
||||
for (i,threshold) in [50.,100.,250.,500.].iter().enumerate() {
|
||||
if extent>*threshold {spans[i]+=1;triangles[i]+=indices.len()/3;}
|
||||
}
|
||||
for tri in indices.chunks_exact(3) {
|
||||
let p=tri.iter().map(|&i|Vec3::from_array(map.geometry.vertices[i as usize].position)/3.).sum::<Vec3>();
|
||||
cells.insert((*material,(p.x/32.).floor() as i32,(p.z/32.).floor() as i32));
|
||||
}
|
||||
}
|
||||
let result=serde_json::json!({"schema":1,"runtime_material_batches":groups.len(),"extent_threshold_metres":[50,100,250,500],"batches_over_threshold":spans,"triangles_in_batches_over_threshold":triangles,"centroid_32m_cells":cells.len(),"note":"Exact current material canonicalization and grouping; no frustum, occlusion or runtime frame measurement"});
|
||||
std::fs::write(std::env::var_os("SKATE_MAP_INVENTORY_OUT").unwrap(),serde_json::to_vec_pretty(&result).unwrap()).unwrap();
|
||||
}
|
||||
}
|
||||
|
||||
pub(crate) fn spawn(
|
||||
map: &SkateMap,
|
||||
commands: &mut crate::map_render::SceneCommands,
|
||||
@@ -431,6 +465,7 @@ pub(crate) fn spawn(
|
||||
tuning: &crate::retail_render::MaterialTuning,
|
||||
) {
|
||||
// Texture roles have different transfer functions even when sharing a record.
|
||||
let _span = info_span!("prepare_map_geometry_and_textures").entered();
|
||||
let texture_ids = render_texture_ids(&map.textures);
|
||||
let mut cache = HashMap::<(u32, u8), Handle<Image>>::new();
|
||||
let mut texture = |id: u32, role: u8| -> Option<Handle<Image>> {
|
||||
|
||||
@@ -0,0 +1,145 @@
|
||||
# Advanced performance capture
|
||||
|
||||
Windows releases built from this revision include the recorder. No Rust, engine rebuild,
|
||||
profiler installation, network listener or menu setting is needed to **record**.
|
||||
From a terminal in the installed release directory:
|
||||
|
||||
```bat
|
||||
skate3rust.exe --trace university-cpu.json --trace-wait --trace-seconds 30
|
||||
```
|
||||
|
||||
Load University normally, settle at the area you want to measure, press **F9**, and
|
||||
skate for 30 seconds. **F10** stops and exports early. Continue playing or close
|
||||
normally; the capture does not terminate gameplay. Use a new output filename for
|
||||
each launch: existing files are never overwritten. The destination directory must
|
||||
already exist and be writable. Relative filenames resolve from the working directory.
|
||||
|
||||
For GPU pass diagnostics, repeat the same route and settings in a separate launch:
|
||||
|
||||
```bat
|
||||
skate3rust.exe --trace university-gpu.json --trace-wait --trace-seconds 30 --trace-gpu
|
||||
```
|
||||
|
||||
For startup/loading, omit `--trace-wait`. For unattended delayed recording use
|
||||
`--trace-delay 60` instead of `--trace-wait`. Delay is measured from recorder
|
||||
initialization, not map readiness. Duration defaults to 30 seconds (range 1–600);
|
||||
delay range is 0–600 seconds. There is one capture per process. F9 cannot restart
|
||||
a completed recording. Trace modifiers without `--trace` are rejected. Existing
|
||||
`--assets` and `--map` options can select prepared data as usual.
|
||||
|
||||
Open the completed JSON using **Open trace file** in [Perfetto](https://ui.perfetto.dev/).
|
||||
Select a CPU slice to see its duration; search for `physics::advance`,
|
||||
`fixed_collision_and_solve`, `fixed_animation_graphs`, `prepare_mesh_bind_groups`,
|
||||
`prepare_windows`, or `present_frames`. Expand counter tracks for frame intervals
|
||||
and render pass diagnostics. Load after recording to avoid viewer GPU contention.
|
||||
Nothing in the recorder uploads captures. Share the JSON file explicitly when needed.
|
||||
|
||||
## What the measurements mean
|
||||
|
||||
- CPU thread slices use Bevy 0.18.1's built-in ECS/system, schedule and render
|
||||
instrumentation plus startup/map/physics subspans. They measure **wall time inside
|
||||
a scope**, including waits and descheduling, not exclusively CPU execution time.
|
||||
Worker threads have anonymous numeric IDs. Nested slices must not be summed as
|
||||
independent work. Re-entered spans emit separate intervals. Scopes crossing a
|
||||
capture boundary can be absent; partial frames should be excluded from analysis.
|
||||
- `frame_interval_ms` measures successive main-app `First` samples. It includes
|
||||
pacing and scheduling effects; it is not a monitor presentation/scanout measurement.
|
||||
`fixed_schedule_iterations` counts fixed schedule loops, not successful physics
|
||||
steps. `fixed_period_ms` reports the existing native-derived timestep. The main
|
||||
sample duration stops at the trace system in `Last`; unordered `Last` systems,
|
||||
including the FPS pacer, may fall outside it. Use their CPU spans separately.
|
||||
- Render preparation, command encoding, queue submission and `present_frames`
|
||||
**are CPU intervals**. A long `prepare_windows` can reflect waiting for the GPU
|
||||
or presentation rather than expensive mesh preparation. Main and render apps
|
||||
are pipelined, so their work need not correspond to the same displayed frame.
|
||||
- With `--trace-gpu`, `render/.../elapsed_gpu` counters are **measured GPU timestamp
|
||||
durations in milliseconds**, when the device supports them. `elapsed_cpu` is
|
||||
CPU pass encoding time. Other render counters are pipeline invocation statistics.
|
||||
Results arrive asynchronously and are sampled only when a new diagnostic arrives.
|
||||
They are plotted at CPU receipt time, **not on a calibrated GPU timeline**; do not
|
||||
infer exact GPU start times or associate them blindly with that main frame.
|
||||
Anonymous series IDs distinguish views; only recognized pass names are retained.
|
||||
- Bevy's instrumented passes are covered, with added diagnostics for the custom
|
||||
retail exposure meter and tone pass. This is not complete GPU-frame coverage:
|
||||
other custom passes may be uninstrumented, and nested pass durations can overlap.
|
||||
Never add all counters to claim total GPU frame time. Missing GPU counters mean
|
||||
unavailable measurements, not zero GPU cost.
|
||||
- Asset counters show main-world asset entries, not VRAM usage. Map meshes/images
|
||||
use `RENDER_WORLD` ownership and can leave those main-world collections after
|
||||
upload. Treat counts as lifecycle clues, not resident memory or draw-call counts.
|
||||
- Metadata includes the existing build ID/revision, engine versions, map fingerprint,
|
||||
initial map counts, timestep, numeric adapter IDs/backend, window dimensions,
|
||||
camera target sizes/MSAA and graphics settings. Map names, source filenames,
|
||||
local asset paths, player names, environment dumps, CLI arguments and log payloads
|
||||
are omitted. The map fingerprint identifies content without publishing its path.
|
||||
|
||||
## Bounds, overhead and failure behavior
|
||||
|
||||
The writer runs on a separate thread with an 8,192-event queue. Full queues drop
|
||||
events instead of waiting for disk; `capture_complete.args.dropped_events` reports
|
||||
loss. A nonzero count makes the timeline incomplete. The event body is limited to
|
||||
128 MiB, plus a small JSON header/footer, and ends early with `size_limit` if reached.
|
||||
The time limit also exports while gameplay continues. A normal return, startup
|
||||
error or Rust unwind drops the guard and finishes the file. Forced process termination,
|
||||
native crashes, power loss or disk errors can leave incomplete JSON; this is not a
|
||||
crash-safe journal. The crash supervisor retains its existing independent behavior.
|
||||
|
||||
CPU recording costs timestamps, span bookkeeping, JSON values and queue operations;
|
||||
export costs CPU and disk bandwidth. GPU queries/readback and pipeline statistics
|
||||
add overhead. This implementation has **not** had its overhead benchmarked in-game.
|
||||
Compare CPU-only and GPU-enabled runs, and treat heavily instrumented results as
|
||||
diagnostic evidence rather than baseline FPS. GPU instrumentation remains installed
|
||||
for the entire `--trace-gpu` launch, including while waiting and after export. CPU
|
||||
span subscription also remains installed after export, although event creation stops.
|
||||
Relaunch without tracing for normal play. With no `--trace`, no recorder, writer,
|
||||
sampling systems or GPU diagnostics are installed; the log subscriber rejects spans
|
||||
before recording. Built-in trace callsites remain compiled but disabled.
|
||||
|
||||
The application retains its existing Vulkan device configuration. GPU timestamp
|
||||
and pipeline statistics support depends on adapter features and drivers; the trace
|
||||
does not force unsupported features or change device limits. Bevy 0.18.1 supports
|
||||
these diagnostics on Vulkan/DX12, and internally bounds timestamp/query capacity.
|
||||
CPU capture works when GPU measurements are unavailable. No textures, shaders,
|
||||
resolution, culling policy, density, animation cadence or simulation timestep are
|
||||
changed by the launch flags. Do not combine this workflow with the older
|
||||
`SKATE_PERF_REPORT`/camera-sweep benchmark environment options: that is a separate
|
||||
benchmark mode with different controls and collection semantics.
|
||||
|
||||
## Developer support and tooling choice
|
||||
|
||||
The package always enables Bevy's `trace` feature; the normal static release build
|
||||
(`cargo build --release --locked -p skate-game --bin skate3rust --no-default-features`)
|
||||
therefore supports the CLI. No separate `trace_chrome` or `trace_tracy` build feature
|
||||
is necessary. The custom subscriber retains event logging and the existing panic
|
||||
hook while filtering timeline and log layers independently; `RUST_LOG` controls
|
||||
logs and cannot silently remove CPU trace systems.
|
||||
|
||||
Bevy's stock Chrome backend is convenient but its default formatter includes span
|
||||
fields and lacks our capture controls/privacy bounds. Tracy offers live CPU/GPU
|
||||
correlation and richer analysis, but requires matching capture/viewer tooling and
|
||||
an alternative instrumented build. It is a developer escalation, not a requirement
|
||||
for distributed capture. RenderDoc is useful for inspecting actual draws, resources,
|
||||
pipeline state and overdraw on Vulkan; replay/capture overhead means its numbers
|
||||
should not be substituted for an ordinary frame-time profile. Capture only after
|
||||
the user launches the game. wgpu API tracing is primarily reproduction/replay of
|
||||
GPU API traffic, not a replacement for CPU or hardware duration profiling, and may
|
||||
contain asset contents. It is intentionally not enabled by these flags.
|
||||
|
||||
Versioned official references: [Bevy 0.18.1 profiling guide](https://github.com/bevyengine/bevy/blob/v0.18.1/docs/profiling.md),
|
||||
[Bevy 0.18.1 render diagnostics](https://docs.rs/bevy_render/0.18.1/bevy_render/diagnostic/struct.RenderDiagnosticsPlugin.html),
|
||||
[wgpu 27 source](https://github.com/gfx-rs/wgpu/tree/v27.0.1), and
|
||||
[RenderDoc documentation](https://renderdoc.org/docs/getting_started/quick_start.html).
|
||||
The pinned local Bevy/wgpu source is the authority for this implementation; newer
|
||||
Bevy documentation uses some different diagnostic names.
|
||||
|
||||
For static inventory without starting the game:
|
||||
|
||||
```text
|
||||
cargo run --release --locked -p skate-data --example map-performance-inventory -- MAP.skate
|
||||
```
|
||||
|
||||
This reports texture payload identity, material bounds and a spatial-cell estimate.
|
||||
For exact renderer canonicalization, the ignored, data-only
|
||||
`skate_world::performance_inventory::runtime_batches` test accepts
|
||||
`SKATE_MAP_INVENTORY` and `SKATE_MAP_INVENTORY_OUT`. Neither initializes Bevy or a GPU.
|
||||
Keep private inventory paths and personal launchers out of published docs/artifacts.
|
||||
Reference in new issue
Block a user