diff --git a/Build-Release.ps1 b/Build-Release.ps1 index 2784498b..27ef0bb2 100644 --- a/Build-Release.ps1 +++ b/Build-Release.ps1 @@ -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" diff --git a/Cargo.lock b/Cargo.lock index 07dccbec..be18cdc1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -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" diff --git a/README.md b/README.md index aaa67fa2..a8fb18a9 100644 --- a/README.md +++ b/README.md @@ -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. diff --git a/crates/skate-data/examples/map-performance-inventory.rs b/crates/skate-data/examples/map-performance-inventory.rs new file mode 100644 index 00000000..4b03b3af --- /dev/null +++ b/crates/skate-data/examples/map-performance-inventory.rs @@ -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> = 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::()}) + }).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(()) +} diff --git a/crates/skate-game/Cargo.toml b/crates/skate-game/Cargo.toml index 9cd5bde7..02024130 100644 --- a/crates/skate-game/Cargo.toml +++ b/crates/skate-game/Cargo.toml @@ -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" diff --git a/crates/skate-game/src/app.rs b/crates/skate-game/src/app.rs index e4c9be8d..df561e55 100644 --- a/crates/skate-game/src/app.rs +++ b/crates/skate-game/src/app.rs @@ -65,7 +65,7 @@ pub(crate) fn build( ..default() }), ..default() - }), + }).build().disable::(), ) .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 } diff --git a/crates/skate-game/src/config.rs b/crates/skate-game/src/config.rs index d19e5382..1bd7023a 100644 --- a/crates/skate-game/src/config.rs +++ b/crates/skate-game/src/config.rs @@ -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")?; diff --git a/crates/skate-game/src/main.rs b/crates/skate-game/src/main.rs index a2b8596f..569091ea 100644 --- a/crates/skate-game/src/main.rs +++ b/crates/skate-game/src/main.rs @@ -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() } diff --git a/crates/skate-game/src/map_render.rs b/crates/skate-game/src/map_render.rs index 84fd2487..dc66ceec 100644 --- a/crates/skate-game/src/map_render.rs +++ b/crates/skate-game/src/map_render.rs @@ -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), diff --git a/crates/skate-game/src/map_transition.rs b/crates/skate-game/src/map_transition.rs index 84975a3e..021e73a3 100644 --- a/crates/skate-game/src/map_transition.rs +++ b/crates/skate-game/src/map_transition.rs @@ -102,8 +102,9 @@ fn start(world: &World, entry: Entry) -> Result { 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 { 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)?; diff --git a/crates/skate-game/src/physics/frame.rs b/crates/skate-game/src/physics/frame.rs index 0e6086cb..be15f027 100644 --- a/crates/skate-game/src/physics/frame.rs +++ b/crates/skate-game/src/physics/frame.rs @@ -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); diff --git a/crates/skate-game/src/profiling.rs b/crates/skate-game/src/profiling.rs new file mode 100644 index 00000000..053b2bc3 --- /dev/null +++ b/crates/skate-game/src/profiling.rs @@ -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> = OnceLock::new(); +static NEXT_THREAD: AtomicU64 = AtomicU64::new(1); +thread_local! { + static THREAD: u64 = NEXT_THREAD.fetch_add(1, Ordering::Relaxed); + static ENTERED: RefCell> = const { RefCell::new(Vec::new()) }; +} +#[derive(Debug, Default)] +struct Options { + path: Option, + seconds: u64, + delay: u64, + wait: bool, + gpu: bool, +} +impl Options { + fn parse(args: impl Iterator) -> Result { + 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::().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, + 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, Option>>); +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, String> { + let options = Options::parse(std::env::args_os().skip(1))?; + init_options(options) +} +fn init_options(options: Options) -> Result, 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::(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); +#[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 LookupSpan<'a>> Layer 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::() + .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, + fixed: u32, + frame: u64, + diagnostics: HashMap, +} +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::() + .add_systems(First, begin_frame) + .add_systems(FixedFirst, |mut frames: ResMut| { + frames.fixed += 1; + }) + .add_systems(Last, end_frame); +} +fn render_counters( + mut frame: Local, + meshes: Res>, + images: Res>, + pipelines: Res, +) { + *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) { + 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, + keys: Res>, + config: Res, + fixed: Res>, + meshes: Res>, + images: Res>, + entities: Query, + diagnostics: Res, + device: Option>, + windows: Query<&Window>, + cameras: Query<(&Camera, &Msaa)>, + menu: Option>, + map: Res, + transition: Res, + adapter: Option>, +) { + 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::>(),"cameras":cameras.iter().map(|(c,m)|json!({"size":c.physical_target_size().map(|s|[s.x,s.y]),"msaa":m.samples()})).collect::>()}})); + } + 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 { + 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::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(); + } +} diff --git a/crates/skate-game/src/retail_exposure.rs b/crates/skate-game/src/retail_exposure.rs index 6052b6bb..1216dbcb 100644 --- a/crates/skate-game/src/retail_exposure.rs +++ b/crates/skate-game/src/retail_exposure.rs @@ -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(()) } } diff --git a/crates/skate-game/src/skate_world.rs b/crates/skate-game/src/skate_world.rs index 597b71e0..4175f345 100644 --- a/crates/skate-game/src/skate_world.rs +++ b/crates/skate-game/src/skate_world.rs @@ -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::(); + 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>::new(); let mut texture = |id: u32, role: u8| -> Option> { diff --git a/docs/performance-tracing.md b/docs/performance-tracing.md new file mode 100644 index 00000000..7942ae24 --- /dev/null +++ b/docs/performance-tracing.md @@ -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.