Skip to main content

provenant/
progress.rs

1use std::collections::HashMap;
2use std::env;
3use std::io::IsTerminal;
4use std::path::Path;
5use std::sync::Mutex;
6use std::time::Instant;
7
8use env_logger::Env;
9use indicatif::{MultiProgress, ProgressBar, ProgressDrawTarget, ProgressStyle};
10use indicatif_log_bridge::LogWrapper;
11use log::LevelFilter;
12
13use crate::models::{FileInfo, FileType};
14
15#[derive(Clone, Copy, Debug, PartialEq, Eq)]
16pub enum ProgressMode {
17    Quiet,
18    Default,
19    Verbose,
20}
21
22#[derive(Debug, Default, Clone)]
23pub struct ScanStats {
24    pub processes: usize,
25    pub scan_names: String,
26    pub initial_files: usize,
27    pub initial_dirs: usize,
28    pub initial_size: u64,
29    pub excluded_count: usize,
30    pub final_files: usize,
31    pub final_dirs: usize,
32    pub final_size: u64,
33    pub error_count: usize,
34    pub total_bytes_scanned: u64,
35    pub packages_assembled: usize,
36    pub manifests_seen: usize,
37    pub top_level_timings: Vec<(String, f64)>,
38    pub detail_timings: Vec<(String, f64)>,
39    pub incremental_reused: usize,
40}
41
42pub struct ScanProgress {
43    mode: ProgressMode,
44    multi: MultiProgress,
45    scan_bar: ProgressBar,
46    stats: Mutex<ScanStats>,
47    phase_starts: Mutex<HashMap<&'static str, Instant>>,
48    phase_spinner: Mutex<Option<ProgressBar>>,
49    stderr_is_tty: bool,
50}
51
52impl ScanProgress {
53    pub fn new(mode: ProgressMode) -> Self {
54        let stderr_is_tty = std::io::stderr().is_terminal();
55        let multi = match mode {
56            ProgressMode::Quiet => MultiProgress::with_draw_target(ProgressDrawTarget::hidden()),
57            ProgressMode::Default if stderr_is_tty => {
58                MultiProgress::with_draw_target(ProgressDrawTarget::stderr_with_hz(15))
59            }
60            ProgressMode::Default | ProgressMode::Verbose => {
61                MultiProgress::with_draw_target(ProgressDrawTarget::hidden())
62            }
63        };
64
65        let scan_bar = if mode == ProgressMode::Default && stderr_is_tty {
66            multi.add(ProgressBar::new(0))
67        } else {
68            ProgressBar::hidden()
69        };
70
71        scan_bar.set_style(
72            ProgressStyle::default_bar()
73                .template(
74                    "{spinner:.green} [{elapsed_precise}] [{bar:40.cyan/blue}] {pos}/{len} files ({per_sec}) ({eta})",
75                )
76                .expect("Failed to create progress bar style")
77                .progress_chars("#>-"),
78        );
79
80        Self {
81            mode,
82            multi,
83            scan_bar,
84            stats: Mutex::new(ScanStats::default()),
85            phase_starts: Mutex::new(HashMap::new()),
86            phase_spinner: Mutex::new(None),
87            stderr_is_tty,
88        }
89    }
90
91    pub fn start_setup(&self) {
92        self.start_phase("setup");
93    }
94
95    pub fn finish_setup(&self) {
96        self.finish_top_level_phase("setup");
97    }
98
99    pub fn set_processes(&self, processes: usize) {
100        let mut stats = self.stats.lock().expect("stats lock poisoned");
101        stats.processes = processes;
102    }
103
104    pub fn set_scan_names(&self, scan_names: String) {
105        let mut stats = self.stats.lock().expect("stats lock poisoned");
106        stats.scan_names = scan_names;
107    }
108
109    pub fn init_logging_bridge(&self) {
110        if self.mode == ProgressMode::Quiet {
111            return;
112        }
113
114        let logger = build_env_logger();
115        let level = logger.filter();
116        if LogWrapper::new(self.multi.clone(), logger)
117            .try_init()
118            .is_ok()
119        {
120            log::set_max_level(level);
121        }
122    }
123
124    pub fn start_discovery(&self) {
125        self.start_phase("inventory");
126        match self.mode {
127            ProgressMode::Quiet => {}
128            ProgressMode::Default => {
129                self.start_spinner("Collecting files...");
130            }
131            ProgressMode::Verbose => {
132                self.message("Collecting files...");
133            }
134        }
135    }
136
137    pub fn finish_discovery(&self, files: usize, dirs: usize, size: u64, excluded: usize) {
138        self.finish_spinner();
139        self.finish_top_level_phase("inventory");
140        let mut stats = self.stats.lock().expect("stats lock poisoned");
141        stats.initial_files = files;
142        stats.initial_dirs = dirs;
143        stats.initial_size = size;
144        stats.excluded_count = excluded;
145    }
146
147    pub fn start_license_detection_engine_creation(&self) {
148        self.start_phase("license_detection_engine_creation");
149        self.message("Loading SPDX data, this may take a while...");
150    }
151
152    pub fn finish_license_detection_engine_creation(&self, detail_name: impl Into<String>) {
153        self.finish_detail_phase(detail_name.into(), "license_detection_engine_creation");
154    }
155
156    pub fn start_scan(&self, total_files: usize) {
157        self.start_phase("scan");
158        self.scan_bar.set_length(total_files as u64);
159        self.scan_bar.set_position(0);
160    }
161
162    pub fn file_completed(&self, path: &Path, bytes: u64, scan_errors: &[String]) {
163        self.scan_bar.inc(1);
164        let mut stats = self.stats.lock().expect("stats lock poisoned");
165        stats.total_bytes_scanned += bytes;
166
167        let has_error = !scan_errors.is_empty();
168        if has_error {
169            stats.error_count += 1;
170        }
171        drop(stats);
172
173        match self.mode {
174            ProgressMode::Quiet => {}
175            ProgressMode::Default => {
176                if has_error {
177                    self.error(&format!("Path: {}", path.to_string_lossy()));
178                }
179            }
180            ProgressMode::Verbose => {
181                self.message(&path.to_string_lossy());
182                for err in scan_errors {
183                    for line in err.lines() {
184                        self.error(&format!("  {line}"));
185                    }
186                }
187            }
188        }
189    }
190
191    pub fn record_runtime_error(&self, path: &Path, err: &str) {
192        let mut stats = self.stats.lock().expect("stats lock poisoned");
193        stats.error_count += 1;
194        drop(stats);
195
196        match self.mode {
197            ProgressMode::Quiet => {}
198            ProgressMode::Default => self.error(&format!("Path: {}", path.to_string_lossy())),
199            ProgressMode::Verbose => {
200                self.error(&format!("Path: {}", path.to_string_lossy()));
201                for line in err.lines() {
202                    self.error(&format!("  {line}"));
203                }
204            }
205        }
206    }
207
208    pub fn finish_scan(&self) {
209        self.finish_top_level_phase("scan");
210        if self.mode == ProgressMode::Default && self.stderr_is_tty {
211            self.scan_bar.finish_with_message("Scan complete!");
212        } else {
213            self.scan_bar.finish_and_clear();
214        }
215    }
216
217    pub fn record_incremental_reused(&self, count: usize) {
218        let mut stats = self.stats.lock().expect("stats lock poisoned");
219        stats.incremental_reused += count;
220    }
221
222    pub fn start_assembly(&self) {
223        self.start_phase("assembly");
224        match self.mode {
225            ProgressMode::Quiet => {}
226            ProgressMode::Default => self.start_spinner("Assembling packages..."),
227            ProgressMode::Verbose => self.message("Assembling packages..."),
228        }
229    }
230
231    pub fn finish_assembly(&self, packages_assembled: usize, manifests_seen: usize) {
232        self.finish_spinner();
233        self.finish_top_level_phase("assembly");
234        let mut stats = self.stats.lock().expect("stats lock poisoned");
235        stats.packages_assembled = packages_assembled;
236        stats.manifests_seen = manifests_seen;
237    }
238
239    pub fn start_output(&self) {
240        self.start_phase("output");
241        match self.mode {
242            ProgressMode::Quiet => {}
243            ProgressMode::Default => self.start_spinner("Writing output..."),
244            ProgressMode::Verbose => self.message("Writing output..."),
245        }
246    }
247
248    pub fn output_written(&self, text: &str) {
249        self.message(text);
250    }
251
252    pub fn finish_output(&self) {
253        self.finish_spinner();
254        self.finish_top_level_phase("output");
255    }
256
257    pub fn start_post_scan(&self) {
258        self.start_phase("post-scan");
259    }
260
261    pub fn finish_post_scan(&self) {
262        self.finish_top_level_phase("post-scan");
263    }
264
265    pub fn start_finalize(&self) {
266        self.start_phase("finalize");
267    }
268
269    pub fn finish_finalize(&self) {
270        self.finish_top_level_phase("finalize");
271    }
272
273    pub fn record_detail_timing(&self, name: impl Into<String>, duration: f64) {
274        let mut stats = self.stats.lock().expect("stats lock poisoned");
275        accumulate_timing(&mut stats.detail_timings, name.into(), duration);
276    }
277
278    pub fn record_final_counts(&self, files: &[FileInfo]) {
279        let mut stats = self.stats.lock().expect("stats lock poisoned");
280        stats.final_files = files
281            .iter()
282            .filter(|f| f.file_type == FileType::File)
283            .count();
284        stats.final_dirs = files
285            .iter()
286            .filter(|f| f.file_type == FileType::Directory)
287            .count();
288        stats.final_size = files
289            .iter()
290            .filter(|f| f.file_type == FileType::File)
291            .map(|f| f.size)
292            .sum();
293    }
294
295    pub fn display_summary(&self, scan_start: &str, scan_end: &str) {
296        if self.mode == ProgressMode::Quiet {
297            return;
298        }
299
300        let stats = self.stats.lock().expect("stats lock poisoned");
301
302        if stats.error_count > 0 {
303            self.error("Some files failed to scan properly:");
304        }
305        for line in build_summary_messages(&stats, scan_start, scan_end) {
306            self.message(&line);
307        }
308        if stats.incremental_reused > 0 {
309            self.message(&format!(
310                "Incremental:    {} unchanged file(s) reused",
311                stats.incremental_reused
312            ));
313        }
314    }
315
316    fn message(&self, msg: &str) {
317        if self.mode == ProgressMode::Quiet {
318            return;
319        }
320
321        if self.mode == ProgressMode::Default && self.stderr_is_tty {
322            let _ = self.multi.println(msg);
323        } else {
324            eprintln!("{msg}");
325        }
326    }
327
328    fn error(&self, msg: &str) {
329        if self.mode == ProgressMode::Quiet {
330            return;
331        }
332
333        if supports_color(self.stderr_is_tty) {
334            self.message(&format!("\u{1b}[31m{msg}\u{1b}[0m"));
335        } else {
336            self.message(msg);
337        }
338    }
339
340    fn start_phase(&self, phase: &'static str) {
341        self.phase_starts
342            .lock()
343            .expect("phase lock poisoned")
344            .insert(phase, Instant::now());
345    }
346
347    fn finish_top_level_phase(&self, phase: &'static str) {
348        let start = self
349            .phase_starts
350            .lock()
351            .expect("phase lock poisoned")
352            .remove(phase);
353        if let Some(start) = start {
354            let mut stats = self.stats.lock().expect("stats lock poisoned");
355            accumulate_timing(
356                &mut stats.top_level_timings,
357                phase.to_string(),
358                start.elapsed().as_secs_f64(),
359            );
360        }
361    }
362
363    fn finish_detail_phase(&self, name: String, phase: &'static str) {
364        let start = self
365            .phase_starts
366            .lock()
367            .expect("phase lock poisoned")
368            .remove(phase);
369        if let Some(start) = start {
370            let mut stats = self.stats.lock().expect("stats lock poisoned");
371            accumulate_timing(
372                &mut stats.detail_timings,
373                name,
374                start.elapsed().as_secs_f64(),
375            );
376        }
377    }
378
379    fn start_spinner(&self, message: &str) {
380        if self.mode != ProgressMode::Default || !self.stderr_is_tty {
381            self.message(message);
382            return;
383        }
384
385        let spinner = self.multi.add(ProgressBar::new_spinner());
386        spinner.set_style(
387            ProgressStyle::default_spinner()
388                .template("{spinner:.green} {msg}")
389                .expect("Failed to create spinner style"),
390        );
391        spinner.enable_steady_tick(std::time::Duration::from_millis(80));
392        spinner.set_message(message.to_string());
393        *self
394            .phase_spinner
395            .lock()
396            .expect("phase spinner lock poisoned") = Some(spinner);
397    }
398
399    fn finish_spinner(&self) {
400        if let Some(spinner) = self
401            .phase_spinner
402            .lock()
403            .expect("phase spinner lock poisoned")
404            .take()
405        {
406            spinner.finish_and_clear();
407        }
408    }
409}
410
411fn build_env_logger() -> env_logger::Logger {
412    let mut builder = env_logger::Builder::from_env(Env::default().default_filter_or("warn"));
413    apply_default_log_filters(&mut builder);
414    builder.build()
415}
416
417fn apply_default_log_filters(builder: &mut env_logger::Builder) {
418    if let Some(level) = pdf_oxide_font_log_filter() {
419        builder.filter_module("pdf_oxide::fonts::font_dict", level);
420    }
421}
422
423fn pdf_oxide_font_log_filter() -> Option<LevelFilter> {
424    should_filter_pdf_oxide_font_warnings().then_some(LevelFilter::Error)
425}
426
427fn should_filter_pdf_oxide_font_warnings() -> bool {
428    let rust_log = env::var("RUST_LOG").ok();
429    should_filter_pdf_oxide_font_warnings_from(rust_log.as_deref())
430}
431
432fn should_filter_pdf_oxide_font_warnings_from(rust_log: Option<&str>) -> bool {
433    rust_log.is_none_or(|value| !value.contains("pdf_oxide"))
434}
435
436fn accumulate_timing(timings: &mut Vec<(String, f64)>, name: String, duration: f64) {
437    if let Some((_, existing)) = timings
438        .iter_mut()
439        .find(|(existing_name, _)| *existing_name == name)
440    {
441        *existing += duration;
442    } else {
443        timings.push((name, duration));
444    }
445}
446
447fn supports_color(stderr_is_tty: bool) -> bool {
448    if !stderr_is_tty {
449        return false;
450    }
451    if env::var_os("NO_COLOR").is_some() {
452        return false;
453    }
454    !matches!(env::var("TERM"), Ok(term) if term == "dumb")
455}
456
457fn build_summary_messages(stats: &ScanStats, scan_start: &str, scan_end: &str) -> Vec<String> {
458    let total = stats
459        .top_level_timings
460        .iter()
461        .map(|(_, value)| *value)
462        .sum::<f64>()
463        .max(0.0);
464    let scan_time = stats
465        .top_level_timings
466        .iter()
467        .find_map(|(name, value)| (name == "scan").then_some(*value))
468        .unwrap_or(0.0);
469
470    let speed_files = if scan_time > 0.0 {
471        stats.final_files as f64 / scan_time
472    } else {
473        0.0
474    };
475    let speed_bytes = if scan_time > 0.0 {
476        stats.total_bytes_scanned as f64 / scan_time
477    } else {
478        0.0
479    };
480
481    let processes = if stats.processes > 0 {
482        stats.processes
483    } else {
484        num_cpus_for_display()
485    };
486    let scan_names = if stats.scan_names.is_empty() {
487        "scan".to_string()
488    } else {
489        stats.scan_names.clone()
490    };
491
492    let mut lines = vec![
493        "Scanning done.".to_string(),
494        format!("Summary:        {scan_names} with {processes} process(es)"),
495        format!("Errors count:   {}", stats.error_count),
496        format!(
497            "Scan Speed:     {speed_files:.2} files/sec. {}/sec.",
498            format_size(speed_bytes as u64)
499        ),
500        format!(
501            "Initial counts: {} resource(s): {} file(s) and {} directorie(s) for {}",
502            stats.initial_files + stats.initial_dirs,
503            stats.initial_files,
504            stats.initial_dirs,
505            format_size(stats.initial_size)
506        ),
507        format!(
508            "Final counts:   {} resource(s): {} file(s) and {} directorie(s) for {}",
509            stats.final_files + stats.final_dirs,
510            stats.final_files,
511            stats.final_dirs,
512            format_size(stats.final_size)
513        ),
514        format!("Excluded count: {}", stats.excluded_count),
515        format!(
516            "Packages:       {} assembled from {} manifests",
517            stats.packages_assembled, stats.manifests_seen
518        ),
519        "Timings:".to_string(),
520        format!("  scan_start: {scan_start}"),
521        format!("  scan_end:   {scan_end}"),
522    ];
523
524    for (name, value) in &stats.top_level_timings {
525        lines.push(format!("  {name}: {value:.2}s"));
526
527        let detail_timings = stats
528            .detail_timings
529            .iter()
530            .filter(|(detail_name, _)| detail_parent_phase(detail_name) == Some(name.as_str()));
531
532        if name == "scan" {
533            let scan_breakdown: Vec<_> = detail_timings.collect();
534            if !scan_breakdown.is_empty() {
535                lines.push("  scan breakdown (cumulative worker time):".to_string());
536                lines.extend(
537                    scan_breakdown
538                        .into_iter()
539                        .map(|(detail_name, detail_value)| {
540                            format!("    {detail_name}: {detail_value:.2}s")
541                        }),
542                );
543            }
544        } else {
545            lines.extend(detail_timings.map(|(detail_name, detail_value)| {
546                format!("    {detail_name}: {detail_value:.2}s")
547            }));
548        }
549    }
550    lines.push(format!("  total: {total:.2}s"));
551
552    lines
553}
554
555fn detail_parent_phase(detail_name: &str) -> Option<&'static str> {
556    if detail_name.starts_with("setup:") || detail_name.starts_with("setup_scan:") {
557        Some("setup")
558    } else if detail_name.starts_with("scan:") {
559        Some("scan")
560    } else if detail_name.starts_with("post-scan:") || detail_name.starts_with("output-filter:") {
561        Some("post-scan")
562    } else if detail_name.starts_with("assembly:") {
563        Some("assembly")
564    } else if detail_name.starts_with("finalize:") {
565        Some("finalize")
566    } else if detail_name.starts_with("output:") {
567        Some("output")
568    } else {
569        None
570    }
571}
572
573pub fn format_size(bytes: u64) -> String {
574    if bytes == 0 {
575        return "0 Bytes".to_string();
576    }
577    if bytes == 1 {
578        return "1 Byte".to_string();
579    }
580
581    let mut size = bytes as f64;
582    let units = ["Bytes", "KB", "MB", "GB", "TB"];
583    let mut idx = 0;
584    while size >= 1024.0 && idx < units.len() - 1 {
585        size /= 1024.0;
586        idx += 1;
587    }
588
589    if idx == 0 {
590        format!("{} {}", bytes, units[idx])
591    } else {
592        format!("{size:.2} {}", units[idx])
593    }
594}
595
596fn num_cpus_for_display() -> usize {
597    let cpus = std::thread::available_parallelism().map_or(1, |n| n.get());
598    if cpus > 1 { cpus - 1 } else { 1 }
599}
600
601#[cfg(test)]
602mod tests {
603    use super::{
604        ScanStats, build_summary_messages, format_size, pdf_oxide_font_log_filter,
605        should_filter_pdf_oxide_font_warnings_from,
606    };
607
608    use log::LevelFilter;
609
610    #[test]
611    fn format_size_matches_expected_shape() {
612        assert_eq!(format_size(0), "0 Bytes");
613        assert_eq!(format_size(1), "1 Byte");
614        assert_eq!(format_size(1024), "1.00 KB");
615        assert_eq!(format_size(2_567_000), "2.45 MB");
616    }
617
618    #[test]
619    fn summary_messages_render_detail_timings_hierarchically() {
620        let stats = ScanStats {
621            processes: 4,
622            scan_names: "licenses, packages".to_string(),
623            initial_files: 10,
624            initial_dirs: 2,
625            initial_size: 2_048,
626            excluded_count: 1,
627            final_files: 8,
628            final_dirs: 1,
629            final_size: 1_024,
630            error_count: 0,
631            total_bytes_scanned: 800,
632            packages_assembled: 3,
633            manifests_seen: 5,
634            incremental_reused: 0,
635            top_level_timings: vec![
636                ("setup".to_string(), 1.0),
637                ("inventory".to_string(), 2.0),
638                ("scan".to_string(), 3.0),
639                ("post-scan".to_string(), 4.0),
640                ("assembly".to_string(), 5.0),
641                ("finalize".to_string(), 6.0),
642                ("output".to_string(), 7.0),
643            ],
644            detail_timings: vec![
645                ("setup_scan:licenses".to_string(), 0.5),
646                ("scan:packages".to_string(), 1.25),
647                ("output-filter:only-findings".to_string(), 1.5),
648                ("finalize:output-prepare".to_string(), 2.0),
649            ],
650        };
651
652        let lines = build_summary_messages(&stats, "start", "end");
653        let line_index = |needle: &str| {
654            lines
655                .iter()
656                .position(|line| line == needle)
657                .unwrap_or_else(|| panic!("missing line: {needle}"))
658        };
659
660        assert!(lines.contains(&"  total: 28.00s".to_string()));
661        assert!(lines.contains(&"    setup_scan:licenses: 0.50s".to_string()));
662        assert!(lines.contains(&"  scan breakdown (cumulative worker time):".to_string()));
663        assert!(lines.contains(&"    scan:packages: 1.25s".to_string()));
664        assert!(lines.contains(&"    output-filter:only-findings: 1.50s".to_string()));
665        assert!(lines.contains(&"    finalize:output-prepare: 2.00s".to_string()));
666        assert!(line_index("  setup: 1.00s") < line_index("    setup_scan:licenses: 0.50s"));
667        assert!(
668            line_index("  scan: 3.00s") < line_index("  scan breakdown (cumulative worker time):")
669        );
670        assert!(
671            line_index("  scan breakdown (cumulative worker time):")
672                < line_index("    scan:packages: 1.25s")
673        );
674        assert!(
675            line_index("  post-scan: 4.00s") < line_index("    output-filter:only-findings: 1.50s")
676        );
677        assert!(line_index("  finalize: 6.00s") < line_index("    finalize:output-prepare: 2.00s"));
678    }
679
680    #[test]
681    fn summary_messages_use_scan_time_for_scan_speed() {
682        let stats = ScanStats {
683            final_files: 20,
684            total_bytes_scanned: 2_048,
685            top_level_timings: vec![("scan".to_string(), 4.0)],
686            ..ScanStats::default()
687        };
688
689        let lines = build_summary_messages(&stats, "start", "end");
690
691        assert!(lines.contains(&"Scan Speed:     5.00 files/sec. 512 Bytes/sec.".to_string()));
692    }
693
694    #[test]
695    fn default_pdf_oxide_font_warnings_are_suppressed() {
696        assert_eq!(pdf_oxide_font_log_filter(), Some(LevelFilter::Error));
697        assert!(should_filter_pdf_oxide_font_warnings_from(None));
698    }
699
700    #[test]
701    fn explicit_pdf_oxide_rust_log_override_disables_default_filter() {
702        assert!(!should_filter_pdf_oxide_font_warnings_from(Some(
703            "pdf_oxide::fonts::font_dict=warn"
704        )));
705    }
706}