feat(driver): add per-phase pipeline timing instrumentation

.gitignore

@@ -19,3 +19,8 @@ tests/lit/**/*.txt
 tests/lit/**/Output/
 tests/lit/**/header_generator/**/*.h
 !tests/lit/**/header_generator/**/dependencies.plc.h
+
+# Local-only baseline / test corpora (not committed)
+/.baseline/
+/benchmarks/local/
+

book/src/SUMMARY.md

@@ -26,3 +26,5 @@
   - [Codegen](./arch/codegen.md)
 - [CFC](./cfc/cfc.md)
   - [Model-to-Model Conversion](./cfc/m2m.md)
+- [Development]()
+  - [Profiling Build Phases](./development/phase_timing.md)

book/src/development/phase_timing.md

@@ -0,0 +1,116 @@
+# Profiling Build Phases
+
+The compiler driver has a built-in phase timer that records wall-clock
+time for each stage of `BuildPipeline` and for every participant
+invocation. It is intended for ad-hoc performance work — for example,
+when investigating why a particular project compiles slower than
+expected, or when measuring the impact of a change to the lowering
+pipeline.
+
+## Enabling
+
+Set the environment variable `PLC_TIMING=1` before invoking the
+compiler:
+
+```sh
+PLC_TIMING=1 plc --check my_project.st
+```
+
+When the variable is unset (or set to `0` / empty), the timers compile
+to a no-op and emit nothing. There is no behavioural difference and no
+test impact, so it is safe to leave the code path always present.
+
+## Reading the output
+
+Each timed scope writes one line to stderr on completion, indented by
+nesting depth. Children appear *before* their parent's log line (the
+parent prints when it drops, i.e. at end-of-scope), which matches the
+standard flame-graph convention.
+
+Each participant invocation is timed individually with a label of
+the form `<hook>/<participant-type-name>`, e.g.
+`post_index/PolymorphismLowerer`. `ParsedProject::index` and
+`IndexedProject::annotate` self-time, so any participant that
+re-invokes them appears with a nested `ParsedProject::index` (or
+`IndexedProject::annotate`) child line. Those nested re-passes are
+the main thing to look for when investigating slow builds.
+
+## Examples
+
+### `plc build` (full pipeline)
+
+`plc build plc.json` runs every phase end-to-end — parsing, indexing,
+annotation, codegen, and linking. The trace shows all four
+top-level driver scopes, with `link` nested inside
+`generate (driver)`:
+
+```text
+[plc-timing] parse: 25.7ms
+[plc-timing]   pre_index (participants): 12.6ms
+[plc-timing]     pre_index/LoopDesugarer: 6.6ms
+[plc-timing]     pre_index/ControlStatementParticipant: 3.0ms
+[plc-timing]   ParsedProject::index: 7.4ms
+[plc-timing]   post_index (participants): 27.6ms
+[plc-timing]     post_index/PolymorphismLowerer: 11.7ms
+[plc-timing]       ParsedProject::index: 9.6ms
+[plc-timing]     post_index/RetainParticipant: 15.8ms
+[plc-timing]       ParsedProject::index: 5.8ms
+[plc-timing] index (driver): 47.6ms
+[plc-timing] annotate (driver): 615.2ms
+[plc-timing]   link: 32.1ms
+[plc-timing] generate (driver): 184.4ms
+```
+
+The default mode (`plc <files>` without a subcommand) follows the
+same shape — same four scopes, same nesting.
+
+### `plc check` (front-end only)
+
+`plc check plc.json` (or the global `--check` flag) stops the
+pipeline after annotation; codegen and linking never run, so the
+trace ends at `annotate`:
+
+```text
+[plc-timing] parse: 24.9ms
+[plc-timing]   pre_index (participants): 12.4ms
+[plc-timing]   ParsedProject::index: 7.3ms
+[plc-timing]   post_index (participants): 27.0ms
+[plc-timing] index (driver): 47.0ms
+[plc-timing] annotate (driver): 612.8ms
+```
+
+This is the right mode for measuring front-end work in isolation —
+the codegen and link costs are excluded.
+
+## What to look for
+
+The trace is most useful for spotting **redundant whole-project
+re-passes**: cases where a participant mutates the AST and then re-runs
+indexing or annotation against the entire project, even though only a
+few units were touched. A nested `ParsedProject::index` or
+`IndexedProject::annotate` under a participant hook is a visible
+indicator of one of those re-passes.
+
+## Adding new timed scopes
+
+To time a new scope, construct a `PhaseTimer` and let it drop at the
+end of the scope you want to measure:
+
+```rust
+use crate::pipelines::timing::PhaseTimer;
+
+fn expensive_thing() {
+    let _t = PhaseTimer::new("expensive_thing");
+    // ... work ...
+}
+```
+
+For participant-style instrumentation, prefer wrapping the *callee*
+(the inner method that does the work) rather than each call site. That
+way a re-entrant call from a participant gets timed automatically,
+without having to thread timer code through every place that might
+call into the method.
+
+The timer label is the only argument and accepts any
+`Into<String>`. Use a stable, easily-greppable string — these strings
+end up in the trace output and may be parsed by tooling.

compiler/plc_driver/src/pipelines.rs

@@ -58,6 +58,9 @@ use serde_json;
 use toml;
 
 pub mod participant;
+pub mod timing;
+
+use timing::PhaseTimer;
 pub mod property;
 
 pub struct BuildPipeline<T: SourceContainer> {
@@ -456,39 +459,65 @@ impl<T: SourceContainer> Pipeline for BuildPipeline<T> {
     }
 
     fn parse(&mut self) -> Result<ParsedProject, Diagnostic> {
+        let _t = PhaseTimer::new("parse");
         let project = ParsedProject::parse(&self.context, &self.project, &mut self.diagnostician)?;
         Ok(project)
     }
 
     fn index(&mut self, project: ParsedProject) -> Result<IndexedProject, Diagnostic> {
-        self.participants.iter_mut().for_each(|p| {
-            p.pre_index(&project);
-        });
-        let project = self.mutable_participants.iter_mut().fold(project, |project, p| p.pre_index(project));
+        let _t = PhaseTimer::new("index (driver)");
+        let project = {
+            let _t = PhaseTimer::new("pre_index (participants)");
+            self.participants.iter_mut().for_each(|p| {
+                let _t = PhaseTimer::new_with(|| format!("pre_index/{}", p.name()));
+                p.pre_index(&project);
+            });
+            self.mutable_participants.iter_mut().fold(project, |project, p| {
+                let _t = PhaseTimer::new_with(|| format!("pre_index/{}", p.name()));
+                p.pre_index(project)
+            })
+        };
         let indexed_project = project.index(self.context.provider());
-        self.participants.iter().for_each(|p| {
-            p.post_index(&indexed_project);
-        });
-        let project =
-            self.mutable_participants.iter_mut().fold(indexed_project, |project, p| p.post_index(project));
+        let project = {
+            let _t = PhaseTimer::new("post_index (participants)");
+            self.participants.iter().for_each(|p| {
+                let _t = PhaseTimer::new_with(|| format!("post_index/{}", p.name()));
+                p.post_index(&indexed_project);
+            });
+            self.mutable_participants.iter_mut().fold(indexed_project, |project, p| {
+                let _t = PhaseTimer::new_with(|| format!("post_index/{}", p.name()));
+                p.post_index(project)
+            })
+        };
 
         Ok(project)
     }
 
     fn annotate(&mut self, project: IndexedProject) -> Result<AnnotatedProject, Diagnostic> {
-        self.participants.iter().for_each(|p| {
-            p.pre_annotate(&project);
-        });
-        let project =
-            self.mutable_participants.iter_mut().fold(project, |project, p| p.pre_annotate(project));
+        let _t = PhaseTimer::new("annotate (driver)");
+        let project = {
+            let _t = PhaseTimer::new("pre_annotate (participants)");
+            self.participants.iter().for_each(|p| {
+                let _t = PhaseTimer::new_with(|| format!("pre_annotate/{}", p.name()));
+                p.pre_annotate(&project);
+            });
+            self.mutable_participants.iter_mut().fold(project, |project, p| {
+                let _t = PhaseTimer::new_with(|| format!("pre_annotate/{}", p.name()));
+                p.pre_annotate(project)
+            })
+        };
         let annotated_project = project.annotate(self.context.provider());
-        self.participants.iter().for_each(|p| {
-            p.post_annotate(&annotated_project);
-        });
-        let mut annotated_project = self
-            .mutable_participants
-            .iter_mut()
-            .fold(annotated_project, |project, p| p.post_annotate(project));
+        let mut annotated_project = {
+            let _t = PhaseTimer::new("post_annotate (participants)");
+            self.participants.iter().for_each(|p| {
+                let _t = PhaseTimer::new_with(|| format!("post_annotate/{}", p.name()));
+                p.post_annotate(&annotated_project);
+            });
+            self.mutable_participants.iter_mut().fold(annotated_project, |project, p| {
+                let _t = PhaseTimer::new_with(|| format!("post_annotate/{}", p.name()));
+                p.post_annotate(project)
+            })
+        };
 
         // Collect diagnostics from participants that validated during lowering.
         for p in &mut self.mutable_participants {
@@ -499,6 +528,7 @@ impl<T: SourceContainer> Pipeline for BuildPipeline<T> {
     }
 
     fn generate(&mut self, _context: &CodegenContext, project: AnnotatedProject) -> Result<(), Diagnostic> {
+        let _t = PhaseTimer::new("generate (driver)");
         self.participants.iter_mut().try_fold((), |_, participant| participant.pre_generate(&project))?;
         let Some(compile_options) = self.get_compile_options() else {
             log::debug!("No compile options provided");
@@ -694,6 +724,7 @@ impl ParsedProject {
 
     /// Creates an index out of a pased project. The index could then be used to query datatypes
     pub fn index(self, id_provider: IdProvider) -> IndexedProject {
+        let _t = PhaseTimer::new("ParsedProject::index");
         let indexed_units = self
             .units
             .into_par_iter()
@@ -744,6 +775,7 @@ pub struct IndexedProject {
 impl IndexedProject {
     /// Creates annotations on the project in order to facilitate codegen and validation
     pub fn annotate(self, mut id_provider: IdProvider) -> AnnotatedProject {
+        let _t = PhaseTimer::new("IndexedProject::annotate");
         //Create and call the annotator
         let mut annotated_units = Vec::new();
         let mut all_annotations = AnnotationMapImpl::default();