Profiler: commands, feature evaluation, io; diagnostics.profile; CLI --profile

- Session::execute is a command span; Model::evaluate and each feature computed
  (by its type) are spans; io's import, export and design read/write too; the
  STEP reader's topology, pcurves and solid record.
- diagnostics.profile (contract + output schema): report, start/stop, reset,
  Chrome trace file.
- A STEP/IGES import's reply carries its own profile while recording.
- Every app compiles the profiler in by default (feature `profile`);
  SOLIDCRAFT_PROFILE=1 starts it.
- solidcraft-cli run/eval/bench-open --profile print the table on stderr,
  --profile-out writes the trace; run --profile works on designs and STEP files.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

Cargo.lock

@@ -4122,6 +4122,7 @@ dependencies = [
  "solidcraft-derive",
  "solidcraft-geom",
  "solidcraft-kernel",
+ "solidcraft-profile",
  "solidcraft-render",
  "solidcraft-sketch",
  "thiserror 2.0.21",
@@ -4142,6 +4143,7 @@ dependencies = [
  "solidcraft-geom",
  "solidcraft-io",
  "solidcraft-kernel",
+ "solidcraft-profile",
  "solidcraft-render",
  "solidcraft-sketch",
  "thiserror 2.0.21",
@@ -4198,6 +4200,7 @@ dependencies = [
  "solidcraft-doc",
  "solidcraft-geom",
  "solidcraft-kernel",
+ "solidcraft-profile",
  "thiserror 2.0.21",
  "zip",
 ]
@@ -4287,6 +4290,7 @@ name = "solidcraft-step"
 version = "0.24.0"
 dependencies = [
  "solidcraft-geom",
+ "solidcraft-profile",
 ]
 
 [[package]]

apps/solidcraft-cli/Cargo.toml

@@ -20,12 +20,15 @@ name = "solvecraft-cli"
 path = "src/alias.rs"
 
 [features]
-default = ["raytrace-cpu", "smlib"]
+default = ["raytrace-cpu", "smlib", "profile"]
 bundled-render-library = ["solidcraft-engine/bundled-render-library"]
 raytrace-cpu = ["solidcraft-engine/raytrace-cpu"]
 # Link SMLib into the kernel (solidcraft-engine/smlib; needs scripts/fetch-smlib.sh). SMLib is the
 # only kernel, so without it the command line models nothing.
 smlib = ["solidcraft-engine/smlib"]
+# The profiler, compiled in so any build can say where its time goes (`--profile`,
+# SOLIDCRAFT_PROFILE=1); it records nothing until asked.
+profile = ["solidcraft-engine/profile"]
 
 [dependencies]
 solidcraft-engine = { workspace = true }

apps/solidcraft-cli/src/main.rs

@@ -36,6 +36,7 @@ mod kernel_cases;
 mod logger;
 mod oracle;
 mod preview;
+mod profiling;
 mod recipe;
 mod render;
 mod spatial;
@@ -58,13 +59,13 @@ struct Command {
 }
 
 /// `run`'s lines in the usage.
-const USAGE_RUN: &str = "  solidcraft-cli run <script.json|design.solidcraft|part.step> [--in design.solidcraft|part.step] [--out FILE]... [--save FILE] [--quiet] [--results] [--timings] [--profile] [--json-out FILE] [--allow-errors]\n  solidcraft-cli run --in <design.solidcraft|part.step> [--out FILE]...\n      (a timeline feature that fails fails the run and nothing is written; --allow-errors writes anyway)\n      (--timings prints {timings: [{index, command, ms}], total_ms} for a script, with --results its results too;\n       --profile adds each command's profile: {boolean_ms, tessellate_ms, other_ms}, the kernel's share)\n";
+const USAGE_RUN: &str = "  solidcraft-cli run <script.json|design.solidcraft|part.step> [--in design.solidcraft|part.step] [--out FILE]... [--save FILE] [--quiet] [--results] [--timings] [--profile] [--profile-out trace.json] [--json-out FILE] [--allow-errors]\n  solidcraft-cli run --in <design.solidcraft|part.step> [--out FILE]...\n      (a timeline feature that fails fails the run and nothing is written; --allow-errors writes anyway)\n      (--timings prints {timings: [{index, command, ms}], total_ms} for a script, with --results its results too;\n       --profile adds each command's profile: {boolean_ms, tessellate_ms, other_ms}, the kernel's share)\n      (--profile also records where the time goes, SMLib's calls, kernel operations, features, commands and import stages,\n       and prints the table to stderr: count, total, self time and longest per span; --profile-out FILE writes the spans\n       as a Chrome trace for chrome://tracing or ui.perfetto.dev; SOLIDCRAFT_PROFILE=1 does the same for any command)\n";
 /// `eval`'s lines in the usage.
-const USAGE_EVAL: &str = "  solidcraft-cli eval <script.json|design.solidcraft|part.step> [--in design.solidcraft|part.step] [--json-out FILE]     (alias: inspect)\n  solidcraft-cli eval --in <script.json|design.solidcraft|part.step> [--json-out FILE]\n      (with both inputs, runs the positional script on --in before measuring; does not automatically save the modified design)\n      (--json-out FILE writes the JSON that run (with --results, else the measurement) and eval print to FILE instead of stdout,\n       as plain UTF-8: a shell's > can re-encode it, e.g. Windows PowerShell adds a byte-order mark)\n";
+const USAGE_EVAL: &str = "  solidcraft-cli eval <script.json|design.solidcraft|part.step> [--in design.solidcraft|part.step] [--json-out FILE] [--profile] [--profile-out trace.json]     (alias: inspect)\n  solidcraft-cli eval --in <script.json|design.solidcraft|part.step> [--json-out FILE]\n      (with both inputs, runs the positional script on --in before measuring; does not automatically save the modified design)\n      (--json-out FILE writes the JSON that run (with --results, else the measurement) and eval print to FILE instead of stdout,\n       as plain UTF-8: a shell's > can re-encode it, e.g. Windows PowerShell adds a byte-order mark)\n      (--profile and --profile-out as for run)\n";
 /// `script`'s lines in the usage.
 const USAGE_SCRIPT: &str = "  solidcraft-cli script <design.solidcraft|script.json> [--out script.json]\n      (the design's history as a command script that eval and run replay)\n";
 /// `bench-open`'s lines in the usage.
-const USAGE_BENCH_OPEN: &str = "  solidcraft-cli bench-open <design.solidcraft | part.step> [--parse-only] [--save OUT.solidcraft] [--display LEVEL [--edit NAME EXPR]] [--ops script.json]\n      (--ops: after opening, run each command of the script and undo it, timing the command, the\n       evaluations it caused and the view it leaves: placing and meshing what changed)\n";
+const USAGE_BENCH_OPEN: &str = "  solidcraft-cli bench-open <design.solidcraft | part.step> [--parse-only] [--save OUT.solidcraft] [--display LEVEL [--edit NAME EXPR]] [--ops script.json] [--profile] [--profile-out trace.json]\n      (--profile and --profile-out as for run)\n      (--ops: after opening, run each command of the script and undo it, timing the command, the\n       evaluations it caused and the view it leaves: placing and meshing what changed)\n";
 /// `bench-agent`'s lines in the usage.
 const USAGE_BENCH_AGENT: &str = "  solidcraft-cli bench-agent [--scale F] [--save design.solidcraft] [--script-out script.json]\n";
 /// `bench-assistant`'s lines in the usage.
@@ -136,6 +137,19 @@ const COMMANDS: &[Command] = &[
 fn main() -> ExitCode {
     let mut args: Vec<String> = std::env::args().skip(1).collect();
     logger::init(&mut args);
+    // `--profile` / `--profile-out` (run, eval, bench-open) or SOLIDCRAFT_PROFILE (any command):
+    // record from here, and print the table when the command ends.
+    let profiling = match args.first().map(String::as_str) {
+        Some("run" | "eval" | "inspect" | "bench-open") => profiling::start(&args[1..]),
+        _ => profiling::start(&[]),
+    };
+    let profiling = match profiling {
+        Ok(p) => p,
+        Err(e) => {
+            eprintln!("error: {e}");
+            return ExitCode::FAILURE;
+        }
+    };
     let r = match args.first().map(String::as_str) {
         // Asked-for help is not an error: the command's usage on stdout, exit 0. It is read
         // before the command runs, so `--help` never starts a run (a fuzz run, a server).
@@ -202,6 +216,11 @@ fn main() -> ExitCode {
         }
         _ => Err(usage()),
     };
+    // The table also when the command failed: where it spent its time before failing.
+    let r = match (r, profiling.map(profiling::Profiling::finish)) {
+        (Ok(()), Some(Err(e))) => Err(e),
+        (r, _) => r,
+    };
     match r {
         Ok(()) => ExitCode::SUCCESS,
         Err(e) => {
@@ -314,6 +333,16 @@ fn positional(args: &[String]) -> Option<&String> {
     None
 }
 
+/// Is `path` a command script (or a recipe), not a design: JSON that is no saved design.
+fn is_script(path: &str) -> bool {
+    let Ok(bytes) = solidcraft_engine::io::vfs::read(path, solidcraft_engine::io::MAX_DESIGN_BYTES) else { return false };
+    if solidcraft_engine::io::is_design_container(&bytes) {
+        return false;
+    }
+    serde_json::from_slice::<Value>(&bytes)
+        .is_ok_and(|v| !v.get("format").and_then(Value::as_str).is_some_and(|f| solidcraft_engine::doc::format::version_of(f).is_some()))
+}
+
 /// `--json-out FILE`: where the JSON a command prints goes instead of stdout.
 fn json_out(args: &[String]) -> Result<Option<&str>, String> {
     if !args.iter().any(|a| a == "--json-out") {
@@ -345,15 +374,23 @@ fn print_json(v: &Value, file: Option<&str>) -> Result<(), String> {
 fn cmd_run(args: &[String]) -> Result<(), String> {
     install_renderer();
     let json_out = json_out(args)?;
-    known_args("run", args, &["--in", "--out", "--save", "--json-out"], &["--quiet", "--results", "--timings", "--profile", "--allow-errors"], true)?;
+    known_args(
+        "run",
+        args,
+        &["--in", "--out", "--save", "--json-out", "--profile-out"],
+        &["--quiet", "--results", "--timings", "--profile", "--allow-errors"],
+        true,
+    )?;
     let base = flag(args, "--in");
     let path = positional(args);
     if path.is_none() && base.is_none() {
         return Err(usage());
     }
     let want_results = args.iter().any(|a| a == "--results");
-    // `--profile` times each command and splits out its kernel time; it implies `--timings`.
-    let profile = args.iter().any(|a| a == "--profile");
+    // `--profile` records the profiler's spans (the table goes to stderr, `profiling.rs`); for a
+    // script it also times each command and splits out its kernel time, implying `--timings`.
+    let script = path.is_some_and(|p| is_script(p));
+    let profile = script && args.iter().any(|a| a == "--profile" || a == "--profile-out");
     let timings = profile || args.iter().any(|a| a == "--timings");
     let (mut s, results) = if want_results || timings {
         // Collect every command's result or time (scripts only), then process requested files too.
@@ -450,7 +487,7 @@ fn timeline_ok(s: &Session) -> Result<(), String> {
 
 fn cmd_eval(args: &[String]) -> Result<(), String> {
     let json_out = json_out(args)?;
-    known_args("eval", args, &["--in", "--json-out"], &[], true)?;
+    known_args("eval", args, &["--in", "--json-out", "--profile-out"], &["--profile"], true)?;
     let mut s = open(flag(args, "--in"), positional(args))?;
     let m = s.execute("inspect.measure", &json!({})).map_err(|e| e.to_string())?;
     let d = s.execute("document.inspect", &json!({})).map_err(|e| e.to_string())?;

apps/solidcraft-cli/src/profiling.rs

@@ -0,0 +1,50 @@
+//! `--profile` and `--profile-out FILE` for `run`, `eval` and `bench-open` (and
+//! `SOLIDCRAFT_PROFILE=1` for any command): record where the time goes, SMLib's calls to the
+//! commands, print the table to stderr when the command ends (stdout stays the command's JSON)
+//! and write the spans as a Chrome trace for chrome://tracing or Perfetto.
+
+use solidcraft_engine::profile;
+
+/// Rows the table prints.
+const TOP: usize = 30;
+
+/// A recording that prints its table when finished.
+pub struct Profiling {
+    trace: Option<String>,
+}
+
+/// Start recording when `args` (after the command) ask for it, or `SOLIDCRAFT_PROFILE` does.
+pub fn start(args: &[String]) -> Result<Option<Profiling>, String> {
+    let trace = match args.iter().position(|a| a == "--profile-out") {
+        Some(i) => match args.get(i + 1) {
+            Some(f) if !f.starts_with("--") => Some(f.clone()),
+            _ => return Err("--profile-out needs a FILE".into()),
+        },
+        None => None,
+    };
+    let asked = trace.is_some() || args.iter().any(|a| a == "--profile");
+    if !asked && !solidcraft_engine::timing::profile_from_env() {
+        return Ok(None);
+    }
+    if !profile::COMPILED {
+        return Err("this solidcraft-cli was built without the profiler (its `profile` feature)".into());
+    }
+    profile::reset();
+    profile::set_enabled(true);
+    Ok(Some(Profiling { trace }))
+}
+
+impl Profiling {
+    /// Stop recording, print the table on stderr and write the trace.
+    pub fn finish(self) -> Result<(), String> {
+        profile::set_enabled(false);
+        eprint!("{}", profile::report().table(TOP));
+        if let Some(path) = self.trace {
+            let mut bytes = Vec::new();
+            profile::write_chrome_trace(&mut bytes).map_err(|e| format!("{path}: {e}"))?;
+            std::fs::write(&path, bytes).map_err(|e| format!("{path}: {e}"))?;
+            eprintln!("profile: trace written to {path} (open it in chrome://tracing or ui.perfetto.dev)");
+        }
+        Ok(())
+    }
+}

apps/solidcraft-web/Cargo.toml

@@ -14,12 +14,15 @@ name = "solidcraft-web"
 path = "src/main.rs"
 
 [features]
-default = ["smlib"]
+default = ["smlib", "profile"]
 bundled-render-library = ["solidcraft-engine/bundled-render-library"]
 # Link SMLib into the kernel (solidcraft-engine/smlib; needs scripts/fetch-smlib.sh
 # wasm32-unknown-unknown, or the sources and wasi-sdk in WASI_SDK_PATH, crates/smlib/build.rs). SMLib
 # is the only kernel, so without it the web app models nothing.
 smlib = ["solidcraft-engine/smlib"]
+# The profiler, compiled in so any build can say where its time goes (the Profile operations
+# preference, SOLIDCRAFT_PROFILE=1, diagnostics.profile); it records nothing until asked.
+profile = ["solidcraft-engine/profile"]
 
 [dependencies]
 solidcraft-engine = { workspace = true }

apps/solidcraft/Cargo.toml

@@ -8,12 +8,15 @@ publish = false
 default-run = "solidcraft"
 
 [features]
-default = ["raytrace-cpu", "bundled-render-library", "smlib"]
+default = ["raytrace-cpu", "bundled-render-library", "smlib", "profile"]
 bundled-render-library = ["solidcraft-engine/bundled-render-library"]
 raytrace-cpu = ["solidcraft-engine/raytrace-cpu"]
 # Link SMLib into the kernel (solidcraft-engine/smlib; needs scripts/fetch-smlib.sh). SMLib is the
 # only kernel, so without it the app models nothing.
 smlib = ["solidcraft-engine/smlib"]
+# The profiler, compiled in so any build can say where its time goes (the Profile operations
+# preference, SOLIDCRAFT_PROFILE=1, diagnostics.profile); it records nothing until asked.
+profile = ["solidcraft-engine/profile"]
 
 # The workspace lints, except unsafe_code: denied, not forbidden, so that src/open_documents.rs
 # (macOS file-open events), src/native_crash.rs (Windows exception filter), src/native_crash_macos.rs

crates/doc/Cargo.toml

@@ -12,6 +12,7 @@ workspace = true
 solidcraft-geom = { workspace = true }
 solidcraft-sketch = { workspace = true }
 solidcraft-kernel = { workspace = true }
+solidcraft-profile = { workspace = true }
 solidcraft-render = { workspace = true }
 solidcraft-derive = { workspace = true }
 serde = { workspace = true }

crates/doc/src/eval.rs

@@ -1751,6 +1751,7 @@ impl Model {
 
     /// Re-evaluate the document, reusing results up to the first changed feature.
     pub fn evaluate(&mut self, doc: &Document) {
+        let _span = solidcraft_profile::span("doc", "evaluate");
         let (vals, perr) = evaluation_values(doc);
         self.param_errors = perr;
         self.frame_bodies.lock().unwrap_or_else(|e| e.into_inner()).next_generation();
@@ -1877,6 +1878,8 @@ impl Model {
                 continue;
             }
             recomputed += 1;
+            // Each feature computed is a profiler span named after its kind.
+            let _feature_span = solidcraft_profile::span("feature", f.kind.type_name());
             let before = state.clone();
             let t0 = now();
             let mut next = (*state).clone();

crates/engine/Cargo.toml

@@ -19,6 +19,10 @@ smlib = ["solidcraft-kernel/smlib"]
 # `src/schema/record.rs`), for checking a new contract against the whole test suite.
 param-audit = []
 solver-profiling = ["solidcraft-sketch/solver-profiling"]
+# Compile the profiler in (solidcraft-profile/enabled): every app turns it on by default, so any
+# build can be profiled; it records only once switched on (SOLIDCRAFT_PROFILE=1, the CLI's
+# --profile, the app's preference, diagnostics.profile).
+profile = ["solidcraft-profile/enabled"]
 
 [[example]]
 name = "sketch_analysis_bench"
@@ -39,6 +43,7 @@ solidcraft-kernel = { workspace = true }
 solidcraft-doc = { workspace = true }
 solidcraft-io = { workspace = true }
 solidcraft-render = { workspace = true }
+solidcraft-profile = { workspace = true }
 image = { workspace = true, features = ["jpeg"] }
 serde = { workspace = true }
 serde_json = { workspace = true }
@@ -50,6 +55,7 @@ log = { workspace = true }
 web-time = { workspace = true }
 
 [dev-dependencies]
+solidcraft-profile = { workspace = true, features = ["enabled"] }
 # Model-cache tests also run in a source tarball build (no git commit).
 solidcraft-io = { workspace = true, features = ["trust-unknown-source"] }
 # Normal CI exercises profiling assertions without enabling the production feature.

crates/engine/src/cmd/diagnostics.rs

@@ -1,5 +1,6 @@
 //! Crash reports, for agents and people (see `crate::crash` and docs/crash-reports.md): list
-//! them, read one, delete them. They live on this computer and are never sent anywhere.
+//! them, read one, delete them. They live on this computer and are never sent anywhere. And the
+//! profiler (`solidcraft_profile`, docs/perf.md): where the time goes, SMLib's calls to commands.
 
 use serde_json::{Value, json};
 
@@ -22,6 +23,21 @@ pub static COMMANDS: &[CommandSpec] = &[
         .icon("delete")
         .noundo()
         .params("id?: one report (default: all). Returns {deleted}"),
+    CommandSpec::new("diagnostics.profile", "Profile", crate::checked!("diagnostics.profile", profile))
+        .icon("bug_report")
+        .noundo()
+        .contract(&PROFILE_CONTRACT)
+        .output(crate::schema::output_schema_for::<crate::schema::diagnostics::ProfileReport>)
+        .params(
+            "enabled?: bool (start or stop recording); reset?: bool (forget what was recorded); top?: rows (default 20, 0: all); \
+             trace?: path (write the recorded spans as a Chrome trace-event file, for chrome://tracing or Perfetto). Returns what \
+             was recorded before enabled and reset apply: {compiled, enabled, wall_ms, spans, dropped, by_category: [{category, \
+             self_ms, share}], rows: [{category, name, count, total_ms, self_ms, max_ms}], rows_total, trace?}, the rows the most \
+             self time first. Categories: smlib (SMLib's C API calls, timed by the C API), kernel, feature (one per feature \
+             computed, by its type), doc, command, import (STEP/IGES stages), io. Self time is a span's time less the spans \
+             inside it; total counts its outermost run only. Recording also starts with SOLIDCRAFT_PROFILE=1, the CLI's \
+             --profile and the app's preference; off, it costs nothing measurable. Read-only",
+        ),
     CommandSpec::new("diagnostics.crash_test", "Crash Test", crash_test).icon("bug_report").noundo().enabled(crash_test_enabled).params(
         "mode: panic | kernel | abort. Checks that crash reports work: panic = an internal error in this command (caught; \
          the design is unchanged), kernel = one inside the geometry kernel (caught), abort = the app ends at once (reported \
@@ -73,3 +89,42 @@ fn crash_test(_: &mut Session, p: &Value) -> Result<Value> {
         _ => Err(bad(cmd, "`mode` must be panic, kernel or abort")),
     }
 }
+
+const PROFILE_CONTRACT: crate::schema::TypedContract<crate::schema::diagnostics::ProfileParams> = crate::schema::TypedContract::new();
+
+/// Rows `diagnostics.profile` returns at most.
+const MAX_PROFILE_ROWS: u64 = 10_000;
+
+fn profile(_: &mut Session, p: &Value) -> Result<Value> {
+    let cmd = "diagnostics.profile";
+    let flag = |key: &str| match p.get(key) {
+        None | Some(Value::Null) => Ok(None),
+        Some(Value::Bool(b)) => Ok(Some(*b)),
+        Some(_) => Err(bad(cmd, format!("`{key}` must be true or false"))),
+    };
+    let (enabled, reset) = (flag("enabled")?, flag("reset")?);
+    let top = match p.get("top") {
+        None | Some(Value::Null) => 20,
+        Some(v) => v.as_u64().ok_or_else(|| bad(cmd, "`top` must be a whole number of rows (0: all)"))?.min(MAX_PROFILE_ROWS) as usize,
+    };
+    let trace = match p.get("trace") {
+        None | Some(Value::Null) => None,
+        Some(_) => Some(str_(p, "trace").filter(|t| !t.trim().is_empty() && t.len() < 4096).ok_or_else(|| bad(cmd, "`trace` must be a file path"))?),
+    };
+    let report = solidcraft_profile::report();
+    let mut out = crate::schema::diagnostics::ProfileReport::new(&report, top);
+    if let Some(path) = trace {
+        let mut bytes = Vec::new();
+        solidcraft_profile::write_chrome_trace(&mut bytes).map_err(|e| bad(cmd, format!("trace: {e}")))?;
+        solidcraft_io::vfs::write(path, &bytes).map_err(|e| EngineError::Other(format!("{path}: {e}")))?;
+        out.trace = Some(path.to_string());
+    }
+    if reset == Some(true) {
+        solidcraft_profile::reset();
+    }
+    if let Some(on) = enabled {
+        solidcraft_profile::set_enabled(on);
+        out.enabled = solidcraft_profile::enabled();
+    }
+    serde_json::to_value(out).map_err(|e| EngineError::Other(format!("{cmd}: {e}")))
+}

crates/engine/src/cmd/file.rs

@@ -141,7 +141,12 @@ fn quarter_turn_x() -> solidcraft_doc::Mat {
 
 /// Add an Import feature for a STEP file to the session's design, in a new component named
 /// after the file (#1386).
+///
+/// While the profiler records, the reply's `profile` is the import's share of it (reading,
+/// building the solids in SMLib, placing, meshing and evaluating them), as
+/// `diagnostics.profile` reports it.
 fn add_step(s: &mut Session, path: &str, name: Option<&str>, options: &StepOptions) -> Result<Value> {
+    let profiled = solidcraft_profile::enabled().then(solidcraft_profile::mark);
     let sf = read_step(path, options.names)?;
     let fname = name.filter(|n| !n.trim().is_empty()).unwrap_or(&sf.name).to_string();
     let cname = import::component_name(path, name);
@@ -160,6 +165,10 @@ fn add_step(s: &mut Session, path: &str, name: Option<&str>, options: &StepOptio
     if let Some(turned) = turned {
         out["stand_up"] = json!(turned);
     }
+    if let Some(mark) = profiled {
+        let report = crate::schema::diagnostics::ProfileReport::new(&mark.report(), 20);
+        out["profile"] = serde_json::to_value(report).map_err(|e| EngineError::Other(format!("{path}: {e}")))?;
+    }
     Ok(out)
 }
 
@@ -835,6 +844,32 @@ mod urdf_tests;
 mod tests {
     use super::*;
 
+    /// While the profiler records, a STEP import's reply carries its own profile: the import's
+    /// stages and SMLib's calls, as diagnostics.profile reports them.
+    #[cfg(feature = "smlib")]
+    #[test]
+    fn a_step_import_reports_its_profile_while_the_profiler_records() {
+        let _serial = crate::schema::diagnostics::PROFILE_TESTS.lock().unwrap_or_else(std::sync::PoisonError::into_inner);
+        let dir = std::env::temp_dir().join(format!("solidcraft-import-profile-{}", std::process::id()));
+        std::fs::create_dir_all(&dir).unwrap();
+        let path = dir.join("block.step").to_string_lossy().to_string();
+        let mut s = Session::default();
+        s.execute("solid.box", &json!({"length": 20, "width": 10, "height": 5})).unwrap();
+        s.execute("file.export", &json!({"path": path})).unwrap();
+        // The first read of the file (a second one finds it in the import cache).
+        solidcraft_profile::set_enabled(true);
+        let out = Session::default().execute("file.insert_step", &json!({"path": path})).unwrap();
+        solidcraft_profile::set_enabled(false);
+        let plain = Session::default().execute("file.insert_step", &json!({"path": path})).unwrap();
+        assert!(plain.get("profile").is_none(), "nothing recorded, nothing reported: {plain}");
+        let p = &out["profile"];
+        let rows = p["rows"].as_array().unwrap();
+        let has = |cat: &str| rows.iter().any(|r| r["category"] == cat);
+        assert!(has("import") && has("smlib"), "{p}");
+        assert!(p["by_category"].as_array().is_some_and(|c| !c.is_empty()) && p["wall_ms"].as_f64().is_some_and(|w| w > 0.0), "{p}");
+        let _ = std::fs::remove_dir_all(&dir);
+    }
+
     /// #4747: a mesh export's `quality` follows curved faces more closely. A 3 mm hole in a
     /// 200 mm plate gets more triangles at fine and more again at finest, in STL and 3MF alike
     /// (Save As Mesh too); standard is what the export always gave; anything else is refused.

crates/engine/src/lib.rs

@@ -48,6 +48,7 @@ pub use solidcraft_doc::Visibility;
 pub use solidcraft_geom as geom;
 pub use solidcraft_io as io;
 pub use solidcraft_kernel as kernel;
+pub use solidcraft_profile as profile;
 pub use solidcraft_render as render;
 pub use solidcraft_sketch as sketch;
 
@@ -1118,6 +1119,8 @@ impl Session {
     /// the model up to date before anything reads it.
     pub fn execute(&mut self, id: &str, params: &Value) -> Result<Value> {
         let spec = find_command(id).ok_or_else(|| EngineError::UnknownCommand(id.to_string()))?;
+        // The command, the evaluation it causes and the refresh after it: one profiler span.
+        let _span = solidcraft_profile::span("command", spec.id);
         let host_viewport = self.render_viewport.clone();
         let host_jobs = self.render_jobs.host.clone();
         let additional_jobs = self.render_jobs.additional.clone();

crates/engine/src/schema/diagnostics.rs

@@ -0,0 +1,151 @@
+//! Contracts and result types for the commands in `cmd/diagnostics.rs`.
+
+use schemars::JsonSchema;
+use serde::{Deserialize, Serialize};
+use serde_json::Value;
+
+/// `true`, `false` or null, with the handler's message for anything else.
+fn flag<'de, D: serde::Deserializer<'de>>(d: D) -> Result<Option<bool>, D::Error> {
+    match Value::deserialize(d)? {
+        Value::Null => Ok(None),
+        Value::Bool(b) => Ok(Some(b)),
+        _ => Err(serde::de::Error::custom("must be true or false")),
+    }
+}
+
+/// A row count, with the handler's message for anything else.
+fn rows<'de, D: serde::Deserializer<'de>>(d: D) -> Result<Option<u64>, D::Error> {
+    match Value::deserialize(d)? {
+        Value::Null => Ok(None),
+        v => v.as_u64().map(Some).ok_or_else(|| serde::de::Error::custom("must be a whole number of rows (0: all)")),
+    }
+}
+
+/// A file path, with the handler's message for anything else.
+fn path<'de, D: serde::Deserializer<'de>>(d: D) -> Result<Option<String>, D::Error> {
+    match Value::deserialize(d)? {
+        Value::Null => Ok(None),
+        Value::String(s) if !s.trim().is_empty() && s.len() < 4096 => Ok(Some(s)),
+        _ => Err(serde::de::Error::custom("must be a file path")),
+    }
+}
+
+/// What `diagnostics.profile` should do besides reporting.
+#[derive(Debug, Default, Deserialize, JsonSchema)]
+#[schemars(deny_unknown_fields)]
+pub struct ProfileParams {
+    /// Start (`true`) or stop (`false`) recording, after the report is taken.
+    #[serde(default, deserialize_with = "flag")]
+    pub enabled: Option<bool>,
+    /// Forget what was recorded, after the report is taken.
+    #[serde(default, deserialize_with = "flag")]
+    pub reset: Option<bool>,
+    /// How many rows to return, the most self time first (default 20; 0: all of them).
+    #[serde(default, deserialize_with = "rows")]
+    pub top: Option<u64>,
+    /// Write the recorded spans here as a Chrome trace-event file (chrome://tracing, Perfetto).
+    #[serde(default, deserialize_with = "path")]
+    pub trace: Option<String>,
+}
+
+/// One category's share of the recorded self time.
+#[derive(Debug, Serialize, JsonSchema)]
+pub struct ProfileCategory {
+    /// `smlib` (SMLib's own time, measured by its C API), `kernel`, `feature`, `doc`, `command`,
+    /// `import`, `io`.
+    pub category: String,
+    pub self_ms: f64,
+    /// Of all recorded self time, 0–1.
+    pub share: f64,
+}
+
+/// One span name's aggregate.
+#[derive(Debug, Serialize, JsonSchema)]
+pub struct ProfileRow {
+    pub category: String,
+    pub name: String,
+    pub count: u64,
+    /// Its time, counting only its outermost occurrence on each thread's stack.
+    pub total_ms: f64,
+    /// Its time less the time of the spans inside it.
+    pub self_ms: f64,
+    /// Its longest single run.
+    pub max_ms: f64,
+}
+
+/// What the profiler recorded: the reply of `diagnostics.profile`, and an import's `profile`.
+#[derive(Debug, Serialize, JsonSchema)]
+pub struct ProfileReport {
+    /// The profiler is compiled into this build (the apps' `profile` feature).
+    pub compiled: bool,
+    /// It is recording (after this call's `enabled`).
+    pub enabled: bool,
+    /// Wall time the report covers.
+    pub wall_ms: f64,
+    /// Spans recorded.
+    pub spans: u64,
+    /// Spans left out of the trace (past its cap); they are in the rows.
+    pub dropped: u64,
+    /// Self time per category, the most first.
+    pub by_category: Vec<ProfileCategory>,
+    /// The span names with the most self time, the most first.
+    pub rows: Vec<ProfileRow>,
+    /// Span names recorded (rows lists `top` of them).
+    pub rows_total: usize,
+    /// Where the Chrome trace was written, when `trace` asked for one.
+    #[serde(default, skip_serializing_if = "Option::is_none")]
+    pub trace: Option<String>,
+}
+
+fn ms(d: std::time::Duration) -> f64 {
+    (d.as_secs_f64() * 1e6).round() / 1e3
+}
+
+impl ProfileReport {
+    /// `report` with its `top` rows of most self time (0: all of them).
+    pub fn new(report: &solidcraft_profile::Report, top: usize) -> ProfileReport {
+        let sorted = report.sorted();
+        let all: f64 = report.rows.iter().map(|r| r.self_time.as_secs_f64()).sum();
+        let by_category = report
+            .by_category()
+            .into_iter()
+            .map(|(c, d)| ProfileCategory {
+                category: c.to_string(),
+                self_ms: ms(d),
+                share: if all > 0.0 { (d.as_secs_f64() / all * 1000.0).round() / 1000.0 } else { 0.0 },
+            })
+            .collect();
+        let n = if top == 0 { sorted.len() } else { top.min(sorted.len()) };
+        let rows = sorted
+            .iter()
+            .take(n)
+            .map(|r| ProfileRow {
+                category: r.category.to_string(),
+                name: r.name.to_string(),
+                count: r.count,
+                total_ms: ms(r.total),
+                self_ms: ms(r.self_time),
+                max_ms: ms(r.max),
+            })
+            .collect();
+        ProfileReport {
+            compiled: report.compiled,
+            enabled: report.enabled,
+            wall_ms: ms(report.wall),
+            spans: (report.events as u64).saturating_add(report.dropped),
+            dropped: report.dropped,
+            by_category,
+            rows,
+            rows_total: sorted.len(),
+            trace: None,
+        }
+    }
+}
+
+/// Tests that switch the process-wide profiler on, off or reset it run one at a time.
+#[cfg(test)]
+pub(crate) static PROFILE_TESTS: std::sync::Mutex<()> = std::sync::Mutex::new(());
+
+#[cfg(test)]
+#[path = "diagnostics_tests.rs"]
+mod tests;

crates/engine/src/schema/diagnostics_tests.rs

@@ -0,0 +1,57 @@
+use serde_json::json;
+
+use super::ProfileParams;
+use crate::Session;
+use crate::schema::input_schema_for;
+use crate::schema::tests::{assert_keys, assert_strict_keeps_todays_errors};
+
+#[test]
+fn schemas_and_the_key_check_agree() {
+    assert_keys(input_schema_for::<ProfileParams>(), &["enabled", "reset", "top", "trace"]);
+}
+
+#[test]
+fn strict_keeps_todays_errors() {
+    assert_strict_keeps_todays_errors(&[
+        ("diagnostics.profile", json!({"enabled": "yes"})),
+        ("diagnostics.profile", json!({"reset": 1})),
+        ("diagnostics.profile", json!({"top": -1})),
+        ("diagnostics.profile", json!({"top": 2.5})),
+        ("diagnostics.profile", json!({"trace": 5})),
+    ]);
+}
+
+/// The profiler records commands, the features they compute and the kernel below them, and
+/// reports, resets and writes a Chrome trace through the command.
+#[test]
+fn diagnostics_profile_reports_commands_features_and_the_kernel() {
+    let _serial = super::PROFILE_TESTS.lock().unwrap_or_else(std::sync::PoisonError::into_inner);
+    let mut s = Session::default();
+    s.execute("diagnostics.profile", &json!({"reset": true, "enabled": true})).unwrap();
+    s.execute("solid.box", &json!({"length": 10, "width": 10, "height": 10})).unwrap();
+    let r = s.execute("diagnostics.profile", &json!({"top": 0})).unwrap();
+    assert_eq!((r["compiled"].as_bool(), r["enabled"].as_bool()), (Some(true), Some(true)), "{r}");
+    let rows = r["rows"].as_array().unwrap();
+    let row = |cat: &str, name: &str| rows.iter().find(|x| x["category"] == cat && x["name"] == name);
+    let cmd = row("command", "solid.box").unwrap_or_else(|| panic!("{r}"));
+    assert!(row("feature", "BoxFeature").is_some() && row("doc", "evaluate").is_some(), "{r}");
+    assert!(row("kernel", "box_solid").is_some(), "{r}");
+    assert!(cmd["self_ms"].as_f64().unwrap() <= cmd["total_ms"].as_f64().unwrap(), "{r}");
+    assert_eq!(r["rows_total"].as_u64(), Some(rows.len() as u64));
+    // `top` keeps the rows with the most self time.
+    let one = s.execute("diagnostics.profile", &json!({"top": 1})).unwrap();
+    assert_eq!(one["rows"].as_array().map(Vec::len), Some(1));
+    // A trace file, then stop and forget.
+    let dir = std::env::temp_dir().join(format!("solidcraft-profile-trace-{}", std::process::id()));
+    std::fs::create_dir_all(&dir).unwrap();
+    let path = dir.join("trace.json").to_string_lossy().to_string();
+    let t = s.execute("diagnostics.profile", &json!({"trace": path, "enabled": false, "reset": true})).unwrap();
+    assert_eq!((t["trace"].as_str(), t["enabled"].as_bool()), (Some(path.as_str()), Some(false)));
+    let trace: serde_json::Value = serde_json::from_slice(&std::fs::read(&path).unwrap()).unwrap();
+    assert!(trace["traceEvents"].as_array().unwrap().iter().any(|e| e["ph"] == "X" && e["name"] == "solid.box"), "{trace}");
+    // Only the call that reset it (its own span ends after the reset).
+    let after = s.execute("diagnostics.profile", &json!({})).unwrap();
+    let names: Vec<&str> = after["rows"].as_array().unwrap().iter().filter_map(|r| r["name"].as_str()).collect();
+    assert_eq!(names, ["diagnostics.profile"], "{after}");
+    let _ = std::fs::remove_dir_all(&dir);
+}

crates/engine/src/schema/mod.rs

@@ -54,6 +54,7 @@ mod coverage_tests;
 mod tests;
 
 // The contracts, by command file.
+pub mod diagnostics;
 pub mod features;
 pub mod inspect;
 

crates/engine/src/timing.rs

@@ -40,6 +40,20 @@ pub fn time<T>(profile: bool, f: impl FnOnce() -> T) -> (T, Step) {
     }
 }
 
+/// `SOLIDCRAFT_PROFILE` asks for the profiler from the start: `1`, `true`, `on` or `yes`.
+pub fn profile_env_on(value: Option<&str>) -> bool {
+    value.map(|v| v.trim().to_ascii_lowercase()).is_some_and(|v| matches!(v.as_str(), "1" | "true" | "on" | "yes"))
+}
+
+/// Start the profiler when `SOLIDCRAFT_PROFILE` asks for it (the apps call this at start-up);
+/// true when it is recording.
+pub fn profile_from_env() -> bool {
+    if profile_env_on(solidcraft_geom::env::var("PROFILE").as_deref()) {
+        solidcraft_profile::set_enabled(true);
+    }
+    solidcraft_profile::enabled()
+}
+
 /// Milliseconds to the microsecond, so the JSON stays readable.
 pub fn round_ms(ms: f64) -> f64 {
     if ms.is_finite() { (ms * 1000.0).round() / 1000.0 } else { 0.0 }
@@ -64,6 +78,16 @@ impl Step {
 mod tests {
     use super::*;
 
+    #[test]
+    fn the_profile_variable_takes_the_usual_yes_words() {
+        for v in ["1", "true", " ON ", "yes"] {
+            assert!(profile_env_on(Some(v)), "{v}");
+        }
+        for v in [None, Some(""), Some("0"), Some("off"), Some("2")] {
+            assert!(!profile_env_on(v), "{v:?}");
+        }
+    }
+
     #[test]
     fn steps_report_their_time_and_profile_only_when_asked() {
         let (r, step) = time(false, || 7);

crates/io/Cargo.toml

@@ -16,6 +16,7 @@ trust-unknown-source = []
 solidcraft-geom = { workspace = true }
 solidcraft-kernel = { workspace = true }
 solidcraft-doc = { workspace = true }
+solidcraft-profile = { workspace = true }
 thiserror = { workspace = true }
 log = { workspace = true }
 zip = { workspace = true }

crates/io/src/design.rs

@@ -231,6 +231,7 @@ pub fn write_design_container_with_thumbnail(
     geometry: Option<&solidcraft_doc::SavedModel>,
     thumbnail: Option<&[u8]>,
 ) -> Result<Vec<u8>> {
+    let _span = solidcraft_profile::span("io", "write_design_container_with_thumbnail");
     write_container(doc, compression, preview, geometry, thumbnail, MAX_DESIGN_BYTES)
 }
 
@@ -654,6 +655,7 @@ pub(super) fn read(bytes: &[u8]) -> Result<Document> {
 /// keeps one seekable file handle instead of buffering the complete archive. JSON continues
 /// through the normal migrations.
 pub fn read_design_file(path: &str, notify: Option<impl FnOnce(DesignPreview)>) -> Result<(Document, Option<solidcraft_doc::SavedModel>)> {
+    let _span = solidcraft_profile::span("io", "read_design_file");
     #[cfg(not(target_arch = "wasm32"))]
     let mut source = {
         crate::vfs::check(path).map_err(invalid)?;

crates/io/src/lib.rs

@@ -207,6 +207,7 @@ pub fn step_import_feature(bytes: &[u8], file: &str) -> Result<StepFeature> {
 
 /// [`step_import_feature`], with the bodies named after `names`.
 pub fn step_import_feature_named(bytes: &[u8], file: &str, names: StepNames) -> Result<StepFeature> {
+    let _span = solidcraft_profile::span("import", "step_import_feature_named");
     if bytes.len() > MAX_STEP_BYTES {
         return Err(IoError::Invalid(format!("STEP file too large ({} MB, limit {} MB)", bytes.len() >> 20, MAX_STEP_BYTES >> 20)));
     }
@@ -264,6 +265,7 @@ pub struct MeshFeature {
 /// feature. A glTF file's bodies are all built where they are (see [`read_gltf`] for its node
 /// tree), and it can't read buffers in other files.
 pub fn mesh_import_feature(bytes: &[u8], file: &str) -> Result<MeshFeature> {
+    let _span = solidcraft_profile::span("import", "mesh_import_feature");
     if is_gltf_path(file) {
         let mut no_files = |name: &str| Err(format!("`{name}` can't be read here"));
         let mut g = read_gltf(bytes, file, &mut no_files)?;
@@ -541,6 +543,7 @@ pub fn export_with_quality(
     meta: &Metadata,
     quality: MeshQuality,
 ) -> Result<Vec<u8>> {
+    let _span = solidcraft_profile::span("io", "export_with_quality");
     let sel: Vec<&solidcraft_doc::ModelBody> = state.bodies.iter().filter(|b| bodies.is_empty() || bodies.contains(&b.name)).collect();
     if sel.is_empty() {
         return Err(IoError::Empty);
@@ -620,6 +623,7 @@ fn mesh_object(b: &solidcraft_doc::ModelBody, tagged: bool, quality: MeshQuality
 /// part, built where the file placed it) is taken into its component's frame by that offset,
 /// as the world placement does, so the occurrences above it place it only once.
 pub fn step_assembly(doc: &Document, local: &ModelState, name: &str) -> Result<Vec<u8>> {
+    let _span = solidcraft_profile::span("io", "step_assembly");
     use solidcraft_kernel::{ExportBody, ExportProduct};
     let mut index: std::collections::HashMap<u64, usize> = std::collections::HashMap::new();
     index.insert(0, 0);
@@ -652,6 +656,7 @@ pub fn step_assembly(doc: &Document, local: &ModelState, name: &str) -> Result<V
 
 /// Read a design file's bytes.
 pub fn read_design(bytes: &[u8]) -> Result<Document> {
+    let _span = solidcraft_profile::span("io", "read_design");
     if bytes.len() > MAX_DESIGN_BYTES {
         return Err(IoError::Invalid("design file too large".into()));
     }

crates/profile/src/lib.rs

@@ -21,8 +21,6 @@
 
 use std::time::Duration;
 
-use serde_json::{Value, json};
-
 /// The profiler is compiled into this build.
 pub const COMPILED: bool = cfg!(any(feature = "enabled", test));
 
@@ -124,40 +122,6 @@ impl Report {
         }
     }
 
-    /// The report as JSON, with the `top` rows of most self time (0: all of them):
-    /// `{compiled, enabled, wall_ms, spans, dropped, by_category: [{category, self_ms, share}],
-    /// rows: [{category, name, count, total_ms, self_ms, max_ms}], rows_total}`.
-    pub fn to_json(&self, top: usize) -> Value {
-        let sorted = self.sorted();
-        let all: f64 = self.rows.iter().map(|r| r.self_time.as_secs_f64()).sum();
-        let by_category: Vec<Value> = self
-            .by_category()
-            .into_iter()
-            .map(|(c, d)| {
-                let share = if all > 0.0 { (d.as_secs_f64() / all * 1000.0).round() / 1000.0 } else { 0.0 };
-                json!({"category": c, "self_ms": ms(d), "share": share})
-            })
-            .collect();
-        let n = if top == 0 { sorted.len() } else { top.min(sorted.len()) };
-        let rows: Vec<Value> = sorted
-            .iter()
-            .take(n)
-            .map(|r| {
-                json!({"category": r.category, "name": r.name, "count": r.count, "total_ms": ms(r.total), "self_ms": ms(r.self_time), "max_ms": ms(r.max)})
-            })
-            .collect();
-        json!({
-            "compiled": self.compiled,
-            "enabled": self.enabled,
-            "wall_ms": ms(self.wall),
-            "spans": self.events as u64 + self.dropped,
-            "dropped": self.dropped,
-            "by_category": by_category,
-            "rows": rows,
-            "rows_total": sorted.len(),
-        })
-    }
-
     /// The report as a text table with the `top` rows of most self time (0: all of them).
     pub fn table(&self, top: usize) -> String {
         use std::fmt::Write as _;

crates/profile/src/tests.rs

@@ -90,9 +90,6 @@ fn a_mark_reports_only_what_came_after_it() {
     let r = m.report();
     assert_eq!(r.rows.len(), 1, "{r:?}");
     assert_eq!(row(&r, "after").count, 2);
-    let j = r.to_json(5);
-    assert_eq!(j["rows"][0]["name"], "after");
-    assert_eq!(j["rows_total"], 1);
 }
 
 #[test]
@@ -106,7 +103,7 @@ fn spans_on_other_threads_get_their_own_track() {
     set_enabled(false);
     let mut out = Vec::new();
     write_chrome_trace(&mut out).unwrap();
-    let v: Value = serde_json::from_slice(&out).unwrap();
+    let v: serde_json::Value = serde_json::from_slice(&out).unwrap();
     let events = v["traceEvents"].as_array().unwrap();
     let tid = |name: &str| events.iter().find(|e| e["name"] == name).map(|e| e["tid"].clone()).unwrap();
     assert_ne!(tid("main"), tid("on_worker"));

crates/smlib/src/tests.rs

@@ -74,8 +74,7 @@ fn call_lines_give_the_function_and_the_c_api_time() {
     let (name, took) = call_time("smlib_boolean(op=1, a=#3 (12 faces), b=#4) -> 0 (12.345 ms)").unwrap();
     assert_eq!((name, took), ("smlib_boolean", std::time::Duration::from_micros(12_345)));
     assert_eq!(call_time("smlib_make_box(origin=(0,0,0)) -> -1002 (0.001 ms)").map(|c| c.0), Some("smlib_make_box"));
-    for bad in ["SMLib warning at x.cpp:12: tolerance (in smlib_boolean(...))", "smlib_x() -> 0 (nan ms)", "smlib_x() -> 0 (-1 ms)", "", "smlib_x"]
-    {
+    for bad in ["SMLib warning at x.cpp:12: tolerance (in smlib_boolean(...))", "smlib_x() -> 0 (nan ms)", "smlib_x() -> 0 (-1 ms)", "", "smlib_x"] {
         assert_eq!(call_time(bad), None, "{bad}");
     }
 }

crates/step/Cargo.toml

@@ -10,3 +10,4 @@ workspace = true
 
 [dependencies]
 solidcraft-geom = { workspace = true }
+solidcraft-profile = { workspace = true }

crates/step/src/topology.rs

@@ -305,6 +305,8 @@ fn read_with<'a>(
     let p = e.params();
     let name = p.first().and_then(Param::as_str).unwrap_or("").to_string();
     let mut b = Builder::new(ex, reader, tolerance(&context), budget, trims);
+    // The file's faces, edges, vertices and their geometry read into the builder.
+    let topology = solidcraft_profile::span("import", "step.topology");
     let (shells, kind) = match e.name() {
         "MANIFOLD_SOLID_BREP" => (vec![b.shell(rid(p.get(1), "outer shell")?)?], Kind::Solid),
         "BREP_WITH_VOIDS" => {
@@ -331,6 +333,7 @@ fn read_with<'a>(
         }
         n => return Err(unsupported(n)),
     };
+    drop(topology);
     b.finish(item, name, shells, kind)
 }
 
@@ -689,6 +692,7 @@ impl<'b, 'a> Builder<'b, 'a> {
 
     /// Pcurves, outer loops, domains and the canonical order: the finished record.
     fn finish(mut self, item: u64, name: String, shells: Vec<Vec<(u32, bool)>>, kind: Kind) -> R<Solid> {
+        let _span = solidcraft_profile::span("import", "step.solid_record");
         let mut notes = Vec::new();
         let seams = self.add_seams()?;
         if seams > 0 {
@@ -980,6 +984,7 @@ impl<'b, 'a> Builder<'b, 'a> {
     /// outer loop runs clockwise about the natural normal on a surface where that cannot be a
     /// face's outer boundary.
     fn face_pcurves(&mut self, fi: usize) -> R<(Vec<Vec<Curve2>>, [[f64; 2]; 2], bool, Option<BSurface>)> {
+        let _span = solidcraft_profile::span("import", "step.face_pcurves");
         let face = self.faces.get(fi).ok_or("face reference")?;
         let label = face.surface.clone();
         let edge_loops: Vec<Vec<(u32, bool)>> = face
@@ -1107,6 +1112,7 @@ impl Builder<'_, '_> {
         edge_loops: &[Vec<(u32, bool)>],
         exact: Vec<Vec<Option<Curve2>>>,
     ) -> R<TrimFace<'s>> {
+        let _span = solidcraft_profile::span("import", "step.trim_face");
         let (mut edge_at, mut vertex_at) = (HashMap::new(), HashMap::new());
         let (mut edges, mut vertices) = (Vec::new(), Vec::new());
         let mut loops = Vec::with_capacity(edge_loops.len());