rgen_core/
simple_tracing.rs

1use std::path::Path;
2use std::time::Instant;
3
4/// Simple tracing system for pipeline debugging
5pub struct SimpleTracer;
6
7impl SimpleTracer {
8    /// Check if tracing is enabled
9    pub fn is_enabled() -> bool {
10        std::env::var("RGEN_TRACE").is_ok()
11    }
12
13    /// Get trace level
14    pub fn trace_level() -> TraceLevel {
15        match std::env::var("RGEN_TRACE")
16            .unwrap_or_default()
17            .to_lowercase()
18            .as_str()
19        {
20            "error" => TraceLevel::Error,
21            "warn" => TraceLevel::Warn,
22            "info" => TraceLevel::Info,
23            "debug" => TraceLevel::Debug,
24            "trace" => TraceLevel::Trace,
25            "1" | "true" | "yes" => TraceLevel::Debug,
26            "0" | "false" | "no" => TraceLevel::Error,
27            _ => TraceLevel::Info,
28        }
29    }
30
31    /// Log a trace message
32    pub fn trace(level: TraceLevel, message: &str, context: Option<&str>) {
33        if !Self::is_enabled() {
34            return;
35        }
36
37        let current_level = Self::trace_level();
38        if level as u8 > current_level as u8 {
39            return;
40        }
41
42        let prefix = match level {
43            TraceLevel::Error => "ERROR",
44            TraceLevel::Warn => "WARN ",
45            TraceLevel::Info => "INFO ",
46            TraceLevel::Debug => "DEBUG",
47            TraceLevel::Trace => "TRACE",
48        };
49
50        if let Some(ctx) = context {
51            eprintln!("[RGEN {}] {}: {}", prefix, ctx, message);
52        } else {
53            eprintln!("[RGEN {}] {}", prefix, message);
54        }
55    }
56
57    /// Log template processing start
58    pub fn template_start(template_path: &Path) {
59        Self::trace(
60            TraceLevel::Info,
61            &format!("Starting template processing: {}", template_path.display()),
62            None,
63        );
64    }
65
66    /// Log template processing completion
67    pub fn template_complete(template_path: &Path, output_path: &Path, content_size: usize) {
68        Self::trace(
69            TraceLevel::Info,
70            &format!(
71                "Template processing complete: {} -> {} ({} bytes)",
72                template_path.display(),
73                output_path.display(),
74                content_size
75            ),
76            None,
77        );
78    }
79
80    /// Log frontmatter processing
81    pub fn frontmatter_processed(frontmatter: &crate::template::Frontmatter) {
82        Self::trace(
83            TraceLevel::Debug,
84            &format!(
85                "Frontmatter processed: to={:?}, inject={}, vars={}",
86                frontmatter.to,
87                frontmatter.inject,
88                frontmatter.vars.len()
89            ),
90            Some("frontmatter"),
91        );
92    }
93
94    /// Log context blessing
95    pub fn context_blessed(vars_count: usize) {
96        Self::trace(
97            TraceLevel::Debug,
98            &format!(
99                "Context blessed: {} variables (Name, locals added)",
100                vars_count
101            ),
102            Some("context"),
103        );
104    }
105
106    /// Log RDF loading
107    pub fn rdf_loading(files: &[String], inline_blocks: usize, triples: usize) {
108        Self::trace(
109            TraceLevel::Info,
110            &format!(
111                "RDF loaded: {} files, {} inline blocks, {} triples",
112                files.len(),
113                inline_blocks,
114                triples
115            ),
116            Some("rdf"),
117        );
118    }
119
120    /// Log SPARQL query
121    pub fn sparql_query(query: &str, result_count: Option<usize>) {
122        let count_str = result_count
123            .map(|c| c.to_string())
124            .unwrap_or_else(|| "N/A".to_string());
125        Self::trace(
126            TraceLevel::Debug,
127            &format!("SPARQL query: {} results", count_str),
128            Some("sparql"),
129        );
130        Self::trace(TraceLevel::Trace, query, Some("sparql"));
131    }
132
133    /// Log file injection
134    pub fn file_injection(target_path: &Path, mode: &str, success: bool) {
135        let status = if success { "completed" } else { "failed" };
136        Self::trace(
137            TraceLevel::Info,
138            &format!("File injection {}: {} mode", status, mode),
139            Some(&format!("injection:{}", target_path.display())),
140        );
141    }
142
143    /// Log shell hook
144    pub fn shell_hook(command: &str, timing: &str, exit_code: i32) {
145        let status = if exit_code == 0 {
146            "completed"
147        } else {
148            "failed"
149        };
150        Self::trace(
151            TraceLevel::Info,
152            &format!(
153                "Shell hook {}: {} (exit code: {})",
154                status, timing, exit_code
155            ),
156            Some(&format!("hook:{}", command)),
157        );
158    }
159
160    /// Log performance metric
161    pub fn performance(operation: &str, duration_ms: u64) {
162        Self::trace(
163            TraceLevel::Debug,
164            &format!("Performance: {} took {}ms", operation, duration_ms),
165            Some("performance"),
166        );
167    }
168
169    /// Log dry run
170    pub fn dry_run(output_path: &Path, content_size: usize) {
171        Self::trace(
172            TraceLevel::Info,
173            &format!(
174                "DRY RUN: Would generate {} ({} bytes)",
175                output_path.display(),
176                content_size
177            ),
178            Some("dry_run"),
179        );
180    }
181
182    /// Log backup creation
183    pub fn backup_created(original_path: &Path, backup_path: &Path) {
184        Self::trace(
185            TraceLevel::Info,
186            &format!(
187                "Backup created: {} -> {}",
188                original_path.display(),
189                backup_path.display()
190            ),
191            Some("backup"),
192        );
193    }
194
195    /// Log skip condition
196    pub fn skip_condition(condition: &str, reason: &str) {
197        Self::trace(
198            TraceLevel::Info,
199            &format!("Skipped: {} ({})", condition, reason),
200            Some("skip"),
201        );
202    }
203
204    /// Log error
205    pub fn error(error: &anyhow::Error, context: &str) {
206        Self::trace(
207            TraceLevel::Error,
208            &format!("Error in {}: {}", context, error),
209            Some("error"),
210        );
211    }
212
213    /// Log warning
214    pub fn warning(message: &str, context: Option<&str>) {
215        Self::trace(TraceLevel::Warn, message, context);
216    }
217}
218
219#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord)]
220pub enum TraceLevel {
221    Error = 0,
222    Warn = 1,
223    Info = 2,
224    Debug = 3,
225    Trace = 4,
226}
227
228/// Performance timer for measuring operation duration
229pub struct SimpleTimer {
230    start: Instant,
231    operation: String,
232}
233
234impl SimpleTimer {
235    /// Start timing an operation
236    pub fn start(operation: &str) -> Self {
237        Self {
238            start: Instant::now(),
239            operation: operation.to_string(),
240        }
241    }
242
243    /// Finish timing and log the result
244    pub fn finish(self) {
245        let duration = self.start.elapsed();
246        SimpleTracer::performance(&self.operation, duration.as_millis() as u64);
247    }
248}
249
250/// Macro for easy performance timing
251#[macro_export]
252macro_rules! time_operation {
253    ($name:expr, $block:block) => {{
254        let _timer = $crate::simple_tracing::SimpleTimer::start($name);
255        let result = $block;
256        _timer.finish();
257        result
258    }};
259}
260
261#[cfg(test)]
262mod tests {
263    use super::*;
264    use std::fs;
265    use tempfile::TempDir;
266
267    #[test]
268    fn test_trace_level_ordering() {
269        assert!(TraceLevel::Error < TraceLevel::Warn);
270        assert!(TraceLevel::Warn < TraceLevel::Info);
271        assert!(TraceLevel::Info < TraceLevel::Debug);
272        assert!(TraceLevel::Debug < TraceLevel::Trace);
273    }
274
275    #[test]
276    fn test_simple_timer() {
277        let timer = SimpleTimer::start("test_operation");
278        std::thread::sleep(std::time::Duration::from_millis(10));
279        timer.finish(); // Should not panic
280    }
281
282    #[test]
283    fn test_tracing_methods() {
284        let temp_dir = TempDir::new().unwrap();
285        let test_path = temp_dir.path().join("test.tmpl");
286        fs::write(&test_path, "test content").unwrap();
287
288        // Test all tracing methods compile and work
289        SimpleTracer::template_start(&test_path);
290        SimpleTracer::template_complete(&test_path, &test_path, 100);
291
292        let frontmatter = crate::template::Frontmatter::default();
293        SimpleTracer::frontmatter_processed(&frontmatter);
294
295        SimpleTracer::context_blessed(5);
296        SimpleTracer::rdf_loading(&["file1.ttl".to_string()], 2, 100);
297        SimpleTracer::sparql_query("SELECT * WHERE { ?s ?p ?o }", Some(10));
298
299        SimpleTracer::file_injection(&test_path, "append", true);
300        SimpleTracer::shell_hook("echo 'test'", "before", 0);
301        SimpleTracer::performance("test_operation", 50);
302        SimpleTracer::dry_run(&test_path, 500);
303        SimpleTracer::backup_created(&test_path, &temp_dir.path().join("backup.tmpl"));
304        SimpleTracer::skip_condition("skip_if", "pattern found");
305
306        let error = anyhow::anyhow!("Test error");
307        SimpleTracer::error(&error, "test context");
308        SimpleTracer::warning("Test warning", Some("test context"));
309        SimpleTracer::warning("Test warning", None);
310    }
311
312    #[test]
313    fn test_tracing_environment_variables() {
314        // Test different RGEN_TRACE values
315        let test_values = [
316            "error", "warn", "info", "debug", "trace", "1", "0", "true", "false",
317        ];
318
319        for value in &test_values {
320            std::env::set_var("RGEN_TRACE", value);
321            let level = SimpleTracer::trace_level();
322            assert!(matches!(
323                level,
324                TraceLevel::Error
325                    | TraceLevel::Warn
326                    | TraceLevel::Info
327                    | TraceLevel::Debug
328                    | TraceLevel::Trace
329            ));
330        }
331    }
332
333    #[test]
334    fn test_time_operation_macro() {
335        let result = crate::time_operation!("test_op", {
336            std::thread::sleep(std::time::Duration::from_millis(2));
337            42
338        });
339        assert_eq!(result, 42);
340    }
341}
rgen_core/simple_tracing.rs

rgen_core/
simple_tracing.rs
