Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
65 changes: 64 additions & 1 deletion src/pipeline/pipeline.rs
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
use std::collections::HashMap;

use anyhow::Result;
use tracing::debug;

use super::step::PipelineStep;
use crate::config::OutputType;
Expand Down Expand Up @@ -118,7 +119,12 @@ impl Pipeline {
pub fn run_steps(&self, input: String) -> Result<String> {
let mut current = input;
for step in &self.steps {
let name = step.name();
debug!(step = %name, "Starting pipeline step");
let start = std::time::Instant::now();
current = step.execute(current)?;
let elapsed = start.elapsed();
debug!(step = %name, duration_ms = elapsed.as_millis(), "Pipeline step completed");
}
Ok(current)
}
Expand All @@ -129,8 +135,20 @@ impl Pipeline {
/// `input → transforms → steps`. It is equivalent to calling
/// [`Pipeline::run_transforms`] followed by [`Pipeline::run_steps`].
pub fn run(&self, input: String) -> Result<String> {
let transform_start = std::time::Instant::now();
let transformed = self.run_transforms(input)?;
self.run_steps(transformed)
let transform_elapsed = transform_start.elapsed();
debug!(duration_ms = transform_elapsed.as_millis(), "Transform phase completed");

let steps_start = std::time::Instant::now();
let result = self.run_steps(transformed)?;
let steps_elapsed = steps_start.elapsed();
debug!(duration_ms = steps_elapsed.as_millis(), "Step phase completed");

let total_elapsed = transform_start.elapsed();
debug!(duration_ms = total_elapsed.as_millis(), "Pipeline execution completed");

Ok(result)
}
}

Expand Down Expand Up @@ -421,4 +439,49 @@ mod tests {
// AlwaysFails is skipped and its input is passed through unchanged.
assert_eq!(result.unwrap(), "plain text");
}

// ── Timing and performance tracing tests ─────────────────────────────────

#[test]
fn test_step_default_name_is_pipeline_step() {
let step = AppendStep(" x".to_string());
assert_eq!(step.name(), "PipelineStep");
}

#[test]
fn test_step_custom_name() {
struct NamedStep;
impl PipelineStep for NamedStep {
fn name(&self) -> &str {
"NamedStep"
}
fn execute(&self, input: String) -> Result<String> {
Ok(input)
}
}
let step = NamedStep;
assert_eq!(step.name(), "NamedStep");
}

#[test]
fn test_run_steps_completes_and_returns_correct_output() {
// Verifies that adding timing instrumentation didn't break run_steps correctness.
let mut pipeline = Pipeline::new();
pipeline
.add_step(Box::new(AppendStep(" a".to_string())))
.add_step(Box::new(AppendStep(" b".to_string())));
let result = pipeline.run_steps("start".to_string()).unwrap();
assert_eq!(result, "start a b");
}

#[test]
fn test_run_pipeline_timing_does_not_affect_output() {
// Verifies that the timing wrappers in run() don't alter correctness.
let mut pipeline = Pipeline::new();
pipeline
.add_transform(Box::new(AppendTransform(" t".to_string())))
.add_step(Box::new(AppendStep(" s".to_string())));
let result = pipeline.run("input".to_string()).unwrap();
assert_eq!(result, "input t s");
}
}
8 changes: 8 additions & 0 deletions src/pipeline/step.rs
Original file line number Diff line number Diff line change
@@ -1,5 +1,13 @@
use anyhow::Result;

pub trait PipelineStep {
/// Human-readable name for this step, used in log messages and performance traces.
///
/// Override this in concrete step types to make timing diagnostics more
/// actionable (e.g. `"HtmlStep"` instead of the generic `"PipelineStep"`).
fn name(&self) -> &str {
"PipelineStep"
}

fn execute(&self, input: String) -> Result<String>;
}
10 changes: 10 additions & 0 deletions src/pipeline/strategy_step.rs
Original file line number Diff line number Diff line change
Expand Up @@ -83,6 +83,10 @@ impl StrategyStep {
}

impl PipelineStep for StrategyStep {
fn name(&self) -> &str {
"StrategyStep"
}

fn execute(&self, input: String) -> Result<String> {
info!(output = %self.output_path, "Executing strategy step");
let temp_file = TempFile::with_content(input.as_bytes())?;
Expand Down Expand Up @@ -276,4 +280,10 @@ mod tests {
assert_eq!(result, "Hello [emoji] World");
assert!(!result.contains('😀'), "emoji should have been replaced by the transform");
}

#[test]
fn test_strategy_step_name() {
let step = make_step(Box::new(AlwaysOkStrategy), "/tmp/out.html");
assert_eq!(step.name(), "StrategyStep");
}
}
5 changes: 3 additions & 2 deletions src/transforms/registry.rs
Original file line number Diff line number Diff line change
Expand Up @@ -80,6 +80,7 @@ impl TransformRegistry {
let name = transform.name();
debug!(transform = %name, "Starting transform");

let start = std::time::Instant::now();
if self.failure_mode == FailureMode::FailFast {
current = transform
.apply(current)
Expand Down Expand Up @@ -109,8 +110,8 @@ impl TransformRegistry {
}
}
}

debug!(transform = %name, "Transform completed");
let elapsed = start.elapsed();
debug!(transform = %name, duration_ms = elapsed.as_millis(), "Transform completed");
}
Ok(current)
}
Expand Down