lumen_runtime/
profile.rs

1//! Opt-in profiler installation invoked from `lumenc run --profile <kind>`.
2//!
3//! Compiled in only when lumenc is built with the `profiling` cargo feature
4//! (which also enables `bevy_ecs/trace` so per-system spans exist at all);
5//! `--profile tracy` additionally needs `profiling-tracy`. On a default
6//! build every mode errors at startup with a rebuild hint - the default
7//! binary carries neither span instrumentation nor a subscriber stack.
8//!
9//! Installs a `tracing` subscriber that captures `bevy_ecs/trace` spans and exports them in one of three formats.
10//!
11//! - `chrome`: writes `lumen-trace.json` in the cwd in Chrome trace format; open in `chrome://tracing` or Perfetto.
12//! - `tracy`: connects to a running `tracy-profiler` GUI over TCP.
13//! - `stderr`: line-per-span formatter writing to stderr.
14
15#[cfg(feature = "profiling")]
16use std::fs::File;
17#[cfg(feature = "profiling")]
18use std::io::BufWriter;
19#[cfg(feature = "profiling")]
20use std::path::PathBuf;
21#[cfg(feature = "profiling")]
22use tracing_subscriber::EnvFilter;
23#[cfg(feature = "profiling")]
24use tracing_subscriber::layer::SubscriberExt;
25#[cfg(feature = "profiling")]
26use tracing_subscriber::util::SubscriberInitExt;
27
28/// Default `tracing` filter applied when `RUST_LOG` is unset.
29/// Enables `trace`-level capture for `bevy_ecs`, `lumen`, and `lumenc`; override at runtime via `RUST_LOG`.
30#[cfg(feature = "profiling")]
31const DEFAULT_PROFILE_FILTER: &str = "bevy_ecs=trace,lumen=trace,lumenc=trace";
32
33#[cfg(feature = "profiling")]
34fn profile_filter() -> EnvFilter {
35    EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new(DEFAULT_PROFILE_FILTER))
36}
37
38/// Profiler output mode chosen via `--profile <kind>` on the CLI.
39#[derive(Clone, Copy, Debug, PartialEq, Eq)]
40pub enum ProfileMode {
41    /// Chrome JSON trace exporter - writes `lumen-trace.json`.
42    Chrome,
43    /// Live Tracy connection - launch `tracy-profiler` to view.
44    Tracy,
45    /// stderr line dump via `tracing-subscriber`'s default formatter.
46    Stderr,
47}
48
49impl TryFrom<&str> for ProfileMode {
50    type Error = String;
51    fn try_from(s: &str) -> Result<Self, Self::Error> {
52        match s {
53            "chrome" => Ok(Self::Chrome),
54            "tracy" => Ok(Self::Tracy),
55            "stderr" => Ok(Self::Stderr),
56            other => Err(format!(
57                "unknown profile mode '{other}' (supported: chrome, tracy, stderr)"
58            )),
59        }
60    }
61}
62
63/// Lifetime guard returned by [`install`]. Drop flushes and closes the underlying writer.
64#[cfg(feature = "profiling")]
65pub struct ProfileGuard {
66    chrome: Option<tracing_chrome::FlushGuard>,
67    chrome_path: Option<PathBuf>,
68}
69
70/// Stub guard for builds without the `profiling` feature - [`install`]
71/// always errors before one is constructed, but the type must exist for
72/// the CLI's `Option<ProfileGuard>` binding to compile.
73#[cfg(not(feature = "profiling"))]
74pub struct ProfileGuard {}
75
76#[cfg(feature = "profiling")]
77impl Drop for ProfileGuard {
78    fn drop(&mut self) {
79        // Drop the chrome flush guard first so the writer flushes and closes the file.
80        // Then rewrite chrome event names via `rewrite_chrome_names` so spans show the system fn path instead of the generic `system` placeholder.
81        self.chrome.take();
82        if let Some(path) = self.chrome_path.take()
83            && let Err(e) = rewrite_chrome_names(&path)
84        {
85            eprintln!(
86                "lumenc: failed to rewrite chrome trace names ({}): {e}",
87                path.display()
88            );
89        }
90    }
91}
92
93/// Streams `path` line-by-line, lifting `args.name` into the top-level chrome `name` field via [`lift_args_name`] and rewriting the file in place.
94#[cfg(feature = "profiling")]
95fn rewrite_chrome_names(path: &std::path::Path) -> std::io::Result<()> {
96    use std::io::{BufRead, BufReader, Write};
97    let tmp = path.with_extension("json.tmp");
98    let reader = BufReader::new(File::open(path)?);
99    let mut writer = BufWriter::new(File::create(&tmp)?);
100    for line in reader.lines() {
101        let mut line = line?;
102        if let Some(rewritten) = lift_args_name(&line) {
103            line = rewritten;
104        }
105        writer.write_all(line.as_bytes())?;
106        writer.write_all(b"\n")?;
107    }
108    writer.flush()?;
109    drop(writer);
110    std::fs::rename(&tmp, path)?;
111    Ok(())
112}
113
114/// Parses one chrome JSON event line and returns a rewritten line that copies `args.name` into the top-level `name` field.
115/// Returns `None` for the array bracket lines and events whose top-level `name` is not one of the generic placeholders.
116#[cfg(feature = "profiling")]
117fn lift_args_name(line: &str) -> Option<String> {
118    let trimmed = line.trim_end_matches(',').trim();
119    if trimmed.is_empty() || matches!(trimmed, "[" | "]") {
120        return None;
121    }
122    let trailing_comma = line.trim_end().ends_with(',');
123    let mut v: serde_json::Value = serde_json::from_str(trimmed).ok()?;
124    let obj = v.as_object_mut()?;
125    // Skip events whose top-level `name` is not a generic `tracing-chrome` placeholder.
126    let current_name = obj.get("name").and_then(|n| n.as_str())?;
127    if !matches!(current_name, "system" | "schedule" | "system_commands") {
128        return None;
129    }
130    let args_name = obj
131        .get("args")
132        .and_then(|a| a.get("name"))
133        .and_then(|n| n.as_str())?
134        .trim_matches('"')
135        .to_string();
136    if args_name.is_empty() {
137        return None;
138    }
139    // Keep the `system_commands` (deferred command apply) span visually
140    // distinct from the system's own run. Renaming BOTH to the bare fn
141    // path made every system appear to run twice per tick in trace
142    // viewers - that artifact was mis-diagnosed as a double registration
143    // at least once.
144    let lifted = if current_name == "system_commands" {
145        format!("{args_name} (commands)")
146    } else {
147        args_name
148    };
149    obj.insert("name".into(), serde_json::Value::String(lifted));
150    let mut s = serde_json::to_string(&v).ok()?;
151    if trailing_comma {
152        s.push(',');
153    }
154    Some(s)
155}
156
157#[cfg(all(test, feature = "profiling"))]
158mod lift_tests {
159    use super::lift_args_name;
160
161    #[test]
162    fn system_span_takes_bare_fn_path() {
163        let line = r#"{"name":"system","args":{"name":"my_crate::my_system"}},"#;
164        let out = lift_args_name(line).unwrap();
165        assert!(out.contains(r#""name":"my_crate::my_system""#));
166        assert!(out.ends_with(','));
167    }
168
169    /// The command-apply span must stay distinguishable from the system's
170    /// own run - naming both identically made every system look like it
171    /// ran twice per tick in trace viewers.
172    #[test]
173    fn system_commands_span_keeps_commands_suffix() {
174        let line = r#"{"name":"system_commands","args":{"name":"my_crate::my_system"}}"#;
175        let out = lift_args_name(line).unwrap();
176        assert!(out.contains(r#""name":"my_crate::my_system (commands)""#));
177    }
178
179    #[test]
180    fn non_placeholder_names_pass_through() {
181        let line = r#"{"name":"already_named","args":{"name":"x"}}"#;
182        assert!(lift_args_name(line).is_none());
183    }
184}
185
186/// Installs a global `tracing` subscriber wired to `mode` and returns a [`ProfileGuard`] that flushes on drop.
187///
188/// Errors on builds without the `profiling` feature (all modes) or without
189/// `profiling-tracy` (`--profile tracy`) - spans don't exist in those
190/// builds, so silently installing a subscriber would record nothing.
191#[cfg(not(feature = "profiling"))]
192pub fn install(_mode: ProfileMode) -> Result<ProfileGuard, String> {
193    Err(
194        "this lumenc was built without profiler support; rebuild with \
195         `cargo build -p lumenc --features profiling` (chrome / stderr) or \
196         `--features profiling-tracy` (adds tracy)"
197            .into(),
198    )
199}
200
201/// Installs a global `tracing` subscriber wired to `mode` and returns a [`ProfileGuard`] that flushes on drop.
202///
203/// Errors on builds without the `profiling` feature (all modes) or without
204/// `profiling-tracy` (`--profile tracy`) - spans don't exist in those
205/// builds, so silently installing a subscriber would record nothing.
206#[cfg(feature = "profiling")]
207pub fn install(mode: ProfileMode) -> Result<ProfileGuard, String> {
208    match mode {
209        ProfileMode::Chrome => {
210            let path = PathBuf::from("lumen-trace.json");
211            let file = File::create(&path).map_err(|e| format!("open {}: {e}", path.display()))?;
212            let writer = BufWriter::new(file);
213            let (chrome_layer, guard) = tracing_chrome::ChromeLayerBuilder::new()
214                .writer(writer)
215                .include_args(true)
216                .build();
217            tracing_subscriber::registry()
218                .with(profile_filter())
219                .with(chrome_layer)
220                .try_init()
221                .map_err(|e| format!("install chrome subscriber: {e}"))?;
222            eprintln!(
223                "lumenc: chrome profiler writing to {} - open in chrome://tracing or https://ui.perfetto.dev",
224                path.display()
225            );
226            Ok(ProfileGuard {
227                chrome: Some(guard),
228                chrome_path: Some(path),
229            })
230        }
231        #[cfg(feature = "profiling-tracy")]
232        ProfileMode::Tracy => {
233            // `manual-lifetime` + `delayed-init` on the tracy-client dep
234            // mean nothing tracy-related ran before this point (no ctor,
235            // no calibration sleep, no worker threads). The layer's
236            // construction starts the client here, at explicit opt-in.
237            tracing_subscriber::registry()
238                .with(profile_filter())
239                .with(tracing_tracy::TracyLayer::default())
240                .try_init()
241                .map_err(|e| format!("install tracy subscriber: {e}"))?;
242            eprintln!("lumenc: tracy profiler active - launch `tracy-profiler` to connect");
243            Ok(ProfileGuard {
244                chrome: None,
245                chrome_path: None,
246            })
247        }
248        #[cfg(not(feature = "profiling-tracy"))]
249        ProfileMode::Tracy => Err("this lumenc was built without tracy support; rebuild with \
250             `cargo build -p lumenc --features profiling-tracy`"
251            .into()),
252        ProfileMode::Stderr => {
253            tracing_subscriber::registry()
254                .with(profile_filter())
255                .with(
256                    tracing_subscriber::fmt::layer()
257                        .with_target(false)
258                        // Emit one line per span CLOSE with the measured
259                        // busy/idle times - without this the fmt layer
260                        // only prints events, and bevy_ecs's per-system
261                        // instrumentation is all spans, so `--profile
262                        // stderr` printed nothing.
263                        .with_span_events(tracing_subscriber::fmt::format::FmtSpan::CLOSE)
264                        .with_writer(std::io::stderr),
265                )
266                .try_init()
267                .map_err(|e| format!("install stderr subscriber: {e}"))?;
268            eprintln!("lumenc: stderr profiler active - one line per system span");
269            Ok(ProfileGuard {
270                chrome: None,
271                chrome_path: None,
272            })
273        }
274    }
275}
lumen_runtime/profile.rs

lumen_runtime/
profile.rs
