From 7fde0bdffde4787bc5bf419c38f396eee0a6930f Mon Sep 17 00:00:00 2001 From: jyviko <2501648+jyviko@users.noreply.github.com> Date: Tue, 27 Oct 2026 10:08:18 -0400 Subject: [PATCH] Profiler: docs/perf.md says how to switch it on and read it What each category records, self and total time, the table and the Chrome trace; the CLI's --profile and --profile-out on scripts, designs and STEP files; diagnostics.profile over the control channel. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01LUXeKMoxpM7Vuv8Rb6E3K2 --- docs/book/src/guide/getting-started.md | 5 +++- docs/perf.md | 34 ++++++++++++++++++++++++++ 2 files changed, 38 insertions(+), 1 deletion(-) diff --git a/docs/book/src/guide/getting-started.md b/docs/book/src/guide/getting-started.md index 4bb2db13eb..9403fe7c35 100644 --- a/docs/book/src/guide/getting-started.md +++ b/docs/book/src/guide/getting-started.md @@ -322,7 +322,10 @@ cargo run --release -p solidcraft-cli -- eval examples/bracket.json --json-out m To find the slow steps of a script, `--timings` prints how long each command took instead of the measurement: `{"timings": [{"index", "command", "ms"}], "total_ms"}`, with `index` counted from 0. `--profile` adds each command's `profile: {"boolean_ms", "tessellate_ms", "other_ms"}`, -its wall time in the kernel's booleans, in tessellation and in everything else. With +its wall time in the kernel's booleans, in tessellation and in everything else, and prints the +profiler's table on stderr: where the time went, SMLib's calls to the commands +(`docs/perf.md`, "Where the time goes"); `--profile-out trace.json` also writes the spans as a +Chrome trace. `--profile` works on a design or STEP file too. With `--results` as well, the results go in the same object as `results`; `--results` alone still prints a plain array. diff --git a/docs/perf.md b/docs/perf.md index 6f36e29cb8..94c5b204ed 100644 --- a/docs/perf.md +++ b/docs/perf.md @@ -1,3 +1,37 @@ +# Where the time goes: the profiler + +Every app is built with the profiler (`crates/profile`, the apps' default `profile` feature). +It records nothing until switched on: `SOLIDCRAFT_PROFILE=1`, the CLI's `--profile`, the +**Profile operations** preference (Graphics page) or `diagnostics.profile {"enabled": true}`. +Off, a span is one relaxed atomic load. + +What it records, as nested spans on each thread: + +| Category | Spans | +|---|---| +| `smlib` | every SMLib C API call, timed by the C API itself (`steady_clock`) | +| `kernel` | booleans, blends, sweeps, lofts, shell/draft/offset, healing, sewing, conversions, meshing, measuring | +| `import` | the stages of a STEP or IGES import: parse, index, each solid, placement, mesh check, convert batches | +| `feature` | each feature computed, by its type; `doc evaluate` around them | +| `command` | each `Session::execute`, by command id | +| `io` | import, export, design read and write | + +Self time is a span's time less the spans inside it; its total counts only its outermost run +on a thread, so a command run by a command is not counted twice. Work handed to other threads +shows under their own spans. The report is a table (the most self time first, with self time +per category) and the individual spans as a Chrome trace-event file for chrome://tracing or +ui.perfetto.dev (at most 200,000 spans; later ones still count in the table). + +```sh +solidcraft-cli run part.step --profile --profile-out trace.json # table on stderr +solidcraft-cli run part.solidcraft --profile --quiet +solidcraft-cli bench-open part.step --profile +``` + +Over the control channel or MCP: `diagnostics.profile {"reset": true, "enabled": true}`, do the +work, then `diagnostics.profile {"top": 30, "trace": "trace.json"}`. A STEP or IGES import's +reply carries its own profile while recording. + # Design loading ## Edges made by booleans: each point evaluated once (2026-10-16)