Skip to main content

provenant/
progress.rs

1// SPDX-FileCopyrightText: nexB Inc. and others
2// ScanCode is a trademark of nexB Inc.
3// SPDX-FileCopyrightText: Provenant contributors
4// SPDX-License-Identifier: Apache-2.0
5// Derived from ScanCode Toolkit (Apache-2.0); modified. See NOTICE.
6
7use std::collections::HashMap;
8use std::env;
9use std::io::IsTerminal;
10use std::path::Path;
11use std::sync::Mutex;
12use std::time::Instant;
13
14use env_logger::Env;
15use indicatif::{MultiProgress, ProgressBar, ProgressDrawTarget, ProgressStyle};
16use indicatif_log_bridge::LogWrapper;
17use log::LevelFilter;
18
19use crate::cli::ProcessMode;
20use crate::models::{DiagnosticSeverity, FileInfo, FileType, Header, ScanDiagnostic};
21
22#[derive(Clone, Copy, Debug, PartialEq, Eq)]
23pub enum ProgressMode {
24    Quiet,
25    Default,
26    Verbose,
27}
28
29#[derive(Debug, Default, Clone)]
30pub struct ScanStats {
31    pub processes: ProcessMode,
32    pub scan_names: String,
33    pub initial_files: usize,
34    pub initial_dirs: usize,
35    pub initial_size: u64,
36    pub excluded_count: usize,
37    pub final_files: usize,
38    pub final_dirs: usize,
39    pub final_size: u64,
40    pub error_count: usize,
41    pub warning_count: usize,
42    pub total_bytes_scanned: u64,
43    pub packages_assembled: usize,
44    pub manifests_seen: usize,
45    pub top_level_timings: Vec<(String, f64)>,
46    pub detail_timings: Vec<(String, f64)>,
47    pub incremental_reused: usize,
48}
49
50pub struct ScanProgress {
51    mode: ProgressMode,
52    multi: MultiProgress,
53    scan_bar: ProgressBar,
54    stats: Mutex<ScanStats>,
55    phase_starts: Mutex<HashMap<&'static str, Instant>>,
56    phase_spinner: Mutex<Option<ProgressBar>>,
57    stderr_is_tty: bool,
58}
59
60impl ScanProgress {
61    pub fn new(mode: ProgressMode) -> Self {
62        let stderr_is_tty = std::io::stderr().is_terminal();
63        let multi = match mode {
64            ProgressMode::Quiet => MultiProgress::with_draw_target(ProgressDrawTarget::hidden()),
65            ProgressMode::Default if stderr_is_tty => {
66                MultiProgress::with_draw_target(ProgressDrawTarget::stderr_with_hz(15))
67            }
68            ProgressMode::Default | ProgressMode::Verbose => {
69                MultiProgress::with_draw_target(ProgressDrawTarget::hidden())
70            }
71        };
72
73        let scan_bar = if mode == ProgressMode::Default && stderr_is_tty {
74            multi.add(ProgressBar::new(0))
75        } else {
76            ProgressBar::hidden()
77        };
78
79        scan_bar.set_style(
80            ProgressStyle::default_bar()
81                .template(
82                    "{spinner:.green} [{elapsed_precise}] [{bar:40.cyan/blue}] {pos}/{len} files ({per_sec}) ({eta})",
83                )
84                .expect("Failed to create progress bar style")
85                .progress_chars("#>-"),
86        );
87
88        Self {
89            mode,
90            multi,
91            scan_bar,
92            stats: Mutex::new(ScanStats::default()),
93            phase_starts: Mutex::new(HashMap::new()),
94            phase_spinner: Mutex::new(None),
95            stderr_is_tty,
96        }
97    }
98
99    pub fn start_setup(&self) {
100        self.start_phase("setup");
101    }
102
103    pub fn finish_setup(&self) {
104        self.finish_top_level_phase("setup");
105    }
106
107    pub fn set_processes(&self, processes: ProcessMode) {
108        let mut stats = self.stats.lock().expect("stats lock poisoned");
109        stats.processes = processes;
110    }
111
112    pub fn set_scan_names(&self, scan_names: String) {
113        let mut stats = self.stats.lock().expect("stats lock poisoned");
114        stats.scan_names = scan_names;
115    }
116
117    pub fn init_logging_bridge(&self) {
118        if self.mode == ProgressMode::Quiet {
119            return;
120        }
121
122        let logger = build_env_logger();
123        let level = logger.filter();
124        if LogWrapper::new(self.multi.clone(), logger)
125            .try_init()
126            .is_ok()
127        {
128            log::set_max_level(level);
129        }
130    }
131
132    pub fn start_discovery(&self) {
133        self.start_phase("inventory");
134        match self.mode {
135            ProgressMode::Quiet => {}
136            ProgressMode::Default => {
137                self.start_spinner("Collecting files...");
138            }
139            ProgressMode::Verbose => {
140                self.message("Collecting files...");
141            }
142        }
143    }
144
145    pub fn finish_discovery(&self, files: usize, dirs: usize, size: u64, excluded: usize) {
146        self.finish_spinner();
147        self.finish_top_level_phase("inventory");
148        let mut stats = self.stats.lock().expect("stats lock poisoned");
149        stats.initial_files = files;
150        stats.initial_dirs = dirs;
151        stats.initial_size = size;
152        stats.excluded_count = excluded;
153    }
154
155    pub fn start_license_detection_engine_creation(&self) {
156        self.start_phase("license_detection_engine_creation");
157    }
158
159    /// Surface the one-time cold-build latency notice. Invoked by the engine
160    /// initializer only when it actually rebuilds the index (cache miss,
161    /// `--reindex`, or an invalidated cache); the common warm path loads the
162    /// rkyv cache in a fraction of a second and stays silent.
163    pub fn notify_license_index_cold_build(&self) {
164        self.message("Building license index (first run may take a few seconds)...");
165    }
166
167    pub fn finish_license_detection_engine_creation(&self, detail_name: impl Into<String>) {
168        self.finish_detail_phase(detail_name.into(), "license_detection_engine_creation");
169    }
170
171    pub fn start_scan(&self, total_files: usize) {
172        self.start_phase("scan");
173        self.scan_bar.set_length(total_files as u64);
174        self.scan_bar.set_position(0);
175
176        if matches!(self.mode, ProgressMode::Default | ProgressMode::Verbose) && !self.stderr_is_tty
177        {
178            self.message(&format!(
179                "Scanning {total_files} {}...",
180                pluralize_files(total_files)
181            ));
182        }
183    }
184
185    pub fn file_completed(&self, path: &Path, bytes: u64, scan_diagnostics: &[ScanDiagnostic]) {
186        self.scan_bar.inc(1);
187        let mut stats = self.stats.lock().expect("stats lock poisoned");
188        stats.total_bytes_scanned += bytes;
189
190        let PartitionedDiagnostics {
191            errors,
192            warnings,
193            infos,
194        } = partition_scan_diagnostics(scan_diagnostics);
195
196        if !errors.is_empty() {
197            stats.error_count += 1;
198        } else if !warnings.is_empty() {
199            stats.warning_count += 1;
200        }
201        drop(stats);
202
203        match self.mode {
204            ProgressMode::Quiet => {}
205            ProgressMode::Default => {
206                if let Some(formatted) =
207                    format_default_scan_error_from_diagnostics(path, scan_diagnostics)
208                {
209                    self.error(&formatted);
210                } else if let Some(formatted) =
211                    format_default_scan_warning_from_list(path, &warnings)
212                {
213                    self.message(&format!("Warning: {formatted}"));
214                }
215            }
216            ProgressMode::Verbose => {
217                if self.stderr_is_tty
218                    || !errors.is_empty()
219                    || !warnings.is_empty()
220                    || !infos.is_empty()
221                {
222                    self.message(&path.to_string_lossy());
223                }
224                for err in &errors {
225                    for line in err.lines() {
226                        self.error(&format!("  {line}"));
227                    }
228                }
229                for warning in &warnings {
230                    for line in warning.lines() {
231                        self.message(&format!("  warning: {line}"));
232                    }
233                }
234                for info in &infos {
235                    for line in info.lines() {
236                        self.message(&format!("  info: {line}"));
237                    }
238                }
239            }
240        }
241    }
242
243    pub fn record_runtime_error(&self, path: &Path, err: &str) {
244        let mut stats = self.stats.lock().expect("stats lock poisoned");
245        stats.error_count += 1;
246        drop(stats);
247
248        match self.mode {
249            ProgressMode::Quiet => {}
250            ProgressMode::Default => self.error(&format_default_scan_error(path, err)),
251            ProgressMode::Verbose => {
252                self.error(&format!("Path: {}", path.to_string_lossy()));
253                for line in err.lines() {
254                    self.error(&format!("  {line}"));
255                }
256            }
257        }
258    }
259
260    pub fn record_additional_error(&self, err: &str) {
261        let mut stats = self.stats.lock().expect("stats lock poisoned");
262        stats.error_count += 1;
263        drop(stats);
264
265        if self.mode != ProgressMode::Quiet {
266            self.error(err);
267        }
268    }
269
270    pub fn finish_scan(&self) {
271        self.finish_top_level_phase("scan");
272        if self.mode == ProgressMode::Default && self.stderr_is_tty {
273            self.scan_bar.finish_with_message("Scan complete!");
274        } else {
275            self.scan_bar.finish_and_clear();
276            if matches!(self.mode, ProgressMode::Default)
277                || (self.mode == ProgressMode::Verbose && !self.stderr_is_tty)
278            {
279                self.message("Scan complete.");
280            }
281        }
282    }
283
284    pub fn record_incremental_reused(&self, count: usize) {
285        let mut stats = self.stats.lock().expect("stats lock poisoned");
286        stats.incremental_reused += count;
287    }
288
289    pub fn start_assembly(&self) {
290        self.start_phase("assembly");
291        match self.mode {
292            ProgressMode::Quiet => {}
293            ProgressMode::Default => self.start_spinner("Assembling packages..."),
294            ProgressMode::Verbose => self.message("Assembling packages..."),
295        }
296    }
297
298    pub fn assembly_step(&self, step: &str) {
299        if self.mode == ProgressMode::Verbose {
300            self.message(&format!("  {step}"));
301        }
302    }
303
304    pub fn finish_assembly(&self, packages_assembled: usize, manifests_seen: usize) {
305        self.finish_spinner();
306        self.finish_top_level_phase("assembly");
307        let mut stats = self.stats.lock().expect("stats lock poisoned");
308        stats.packages_assembled = packages_assembled;
309        stats.manifests_seen = manifests_seen;
310    }
311
312    pub fn start_output(&self) {
313        self.start_phase("output");
314        match self.mode {
315            ProgressMode::Quiet => {}
316            ProgressMode::Default => self.start_spinner("Writing output..."),
317            ProgressMode::Verbose => self.message("Writing output..."),
318        }
319    }
320
321    pub fn output_written(&self, text: &str) {
322        self.message(text);
323    }
324
325    pub fn finish_output(&self) {
326        self.finish_spinner();
327        self.finish_top_level_phase("output");
328    }
329
330    pub fn start_post_scan(&self) {
331        self.start_phase("post-scan");
332        if self.mode == ProgressMode::Verbose {
333            self.message("Post-processing scan results...");
334        }
335    }
336
337    pub fn post_scan_step(&self, step: &str) {
338        if self.mode == ProgressMode::Verbose {
339            self.message(&format!("  {step}"));
340        }
341    }
342
343    pub fn finish_post_scan(&self) {
344        self.finish_top_level_phase("post-scan");
345    }
346
347    pub fn start_finalize(&self) {
348        self.start_phase("finalize");
349        if self.mode == ProgressMode::Verbose {
350            self.message("Finalizing scan results...");
351        }
352    }
353
354    pub fn finalize_step(&self, step: &str) {
355        if self.mode == ProgressMode::Verbose {
356            self.message(&format!("  {step}"));
357        }
358    }
359
360    pub fn finish_finalize(&self) {
361        self.finish_top_level_phase("finalize");
362    }
363
364    pub fn record_detail_timing(&self, name: impl Into<String>, duration: f64) {
365        let mut stats = self.stats.lock().expect("stats lock poisoned");
366        accumulate_timing(&mut stats.detail_timings, name.into(), duration);
367    }
368
369    pub fn record_final_counts(&self, files: &[FileInfo]) {
370        let mut stats = self.stats.lock().expect("stats lock poisoned");
371        stats.final_files = files
372            .iter()
373            .filter(|f| f.file_type == FileType::File)
374            .count();
375        stats.final_dirs = files
376            .iter()
377            .filter(|f| f.file_type == FileType::Directory)
378            .count();
379        stats.final_size = files
380            .iter()
381            .filter(|f| f.file_type == FileType::File)
382            .map(|f| f.size)
383            .sum();
384    }
385
386    pub fn record_final_header_counts(&self, headers: &[Header]) {
387        let mut stats = self.stats.lock().expect("stats lock poisoned");
388        let header_error_count: usize = headers.iter().map(|header| header.errors.len()).sum();
389        let header_warning_count: usize = headers.iter().map(|header| header.warnings.len()).sum();
390
391        stats.error_count = stats.error_count.max(header_error_count);
392        stats.warning_count = stats.warning_count.max(header_warning_count);
393    }
394
395    pub fn display_summary(&self, scan_start: &str, scan_end: &str) {
396        if self.mode == ProgressMode::Quiet {
397            return;
398        }
399
400        let stats = self.stats.lock().expect("stats lock poisoned");
401
402        if stats.error_count > 0 {
403            self.error("Some files failed to scan properly:");
404        } else if stats.warning_count > 0 {
405            self.message("Some files reported recoverable scan warnings:");
406        }
407        for line in build_summary_messages(
408            &stats,
409            scan_start,
410            scan_end,
411            self.mode == ProgressMode::Verbose,
412        ) {
413            self.message(&line);
414        }
415        if stats.incremental_reused > 0 {
416            self.message(&format!(
417                "Incremental:    {} unchanged file(s) reused",
418                stats.incremental_reused
419            ));
420        }
421    }
422
423    fn message(&self, msg: &str) {
424        if self.mode == ProgressMode::Quiet {
425            return;
426        }
427
428        if self.mode == ProgressMode::Default && self.stderr_is_tty {
429            let _ = self.multi.println(msg);
430        } else {
431            eprintln!("{msg}");
432        }
433    }
434
435    fn error(&self, msg: &str) {
436        if self.mode == ProgressMode::Quiet {
437            return;
438        }
439
440        if supports_color(self.stderr_is_tty) {
441            self.message(&format!("\u{1b}[31m{msg}\u{1b}[0m"));
442        } else {
443            self.message(msg);
444        }
445    }
446
447    fn start_phase(&self, phase: &'static str) {
448        self.phase_starts
449            .lock()
450            .expect("phase lock poisoned")
451            .insert(phase, Instant::now());
452    }
453
454    fn finish_top_level_phase(&self, phase: &'static str) {
455        let start = self
456            .phase_starts
457            .lock()
458            .expect("phase lock poisoned")
459            .remove(phase);
460        if let Some(start) = start {
461            let mut stats = self.stats.lock().expect("stats lock poisoned");
462            accumulate_timing(
463                &mut stats.top_level_timings,
464                phase.to_string(),
465                start.elapsed().as_secs_f64(),
466            );
467        }
468    }
469
470    fn finish_detail_phase(&self, name: String, phase: &'static str) {
471        let start = self
472            .phase_starts
473            .lock()
474            .expect("phase lock poisoned")
475            .remove(phase);
476        if let Some(start) = start {
477            let mut stats = self.stats.lock().expect("stats lock poisoned");
478            accumulate_timing(
479                &mut stats.detail_timings,
480                name,
481                start.elapsed().as_secs_f64(),
482            );
483        }
484    }
485
486    fn start_spinner(&self, message: &str) {
487        if self.mode != ProgressMode::Default || !self.stderr_is_tty {
488            self.message(message);
489            return;
490        }
491
492        let spinner = self.multi.add(ProgressBar::new_spinner());
493        spinner.set_style(
494            ProgressStyle::default_spinner()
495                .template("{spinner:.green} {msg}")
496                .expect("Failed to create spinner style"),
497        );
498        spinner.enable_steady_tick(std::time::Duration::from_millis(80));
499        spinner.set_message(message.to_string());
500        *self
501            .phase_spinner
502            .lock()
503            .expect("phase spinner lock poisoned") = Some(spinner);
504    }
505
506    fn finish_spinner(&self) {
507        if let Some(spinner) = self
508            .phase_spinner
509            .lock()
510            .expect("phase spinner lock poisoned")
511            .take()
512        {
513            spinner.finish_and_clear();
514        }
515    }
516}
517
518fn build_env_logger() -> env_logger::Logger {
519    let mut builder = env_logger::Builder::from_env(Env::default().default_filter_or("warn"));
520    apply_default_log_filters(&mut builder);
521    builder.build()
522}
523
524/// Install a plain global logger for CLI subcommands other than `scan`.
525///
526/// `scan` installs an indicatif-aware bridge via [`ScanProgress::init_logging_bridge`]
527/// so log lines never corrupt its progress bars; the other subcommands have no
528/// bars and use this simpler logger. `default_level` sets the baseline filter
529/// (derived from `-q`/`-v`); an explicit `RUST_LOG` still overrides it. Safe to
530/// call at most once — a second call, or a call after a bridge is installed, is
531/// a no-op.
532pub fn init_cli_logger(default_level: LevelFilter) {
533    let default_filter = match default_level {
534        LevelFilter::Off => "off",
535        LevelFilter::Error => "error",
536        LevelFilter::Warn => "warn",
537        LevelFilter::Info => "info",
538        LevelFilter::Debug => "debug",
539        LevelFilter::Trace => "trace",
540    };
541    let mut builder =
542        env_logger::Builder::from_env(Env::default().default_filter_or(default_filter));
543    apply_default_log_filters(&mut builder);
544    // Concise CLI-facing format: informational lines print bare, warnings and
545    // errors carry a prefix, and debug/trace keep their module target.
546    builder.format(|buf, record| {
547        use std::io::Write as _;
548        match record.level() {
549            log::Level::Error => writeln!(buf, "error: {}", record.args()),
550            log::Level::Warn => writeln!(buf, "warning: {}", record.args()),
551            log::Level::Info => writeln!(buf, "{}", record.args()),
552            log::Level::Debug | log::Level::Trace => {
553                writeln!(buf, "[{}] {}", record.target(), record.args())
554            }
555        }
556    });
557    let _ = builder.try_init();
558}
559
560fn apply_default_log_filters(builder: &mut env_logger::Builder) {
561    apply_default_log_filters_from(builder, env::var("RUST_LOG").ok().as_deref());
562}
563
564fn apply_default_log_filters_from(builder: &mut env_logger::Builder, rust_log: Option<&str>) {
565    if let Some(level) = pdf_oxide_default_log_filter_from(rust_log) {
566        builder.filter_module("pdf_oxide", level);
567    }
568}
569
570pub(crate) fn format_default_scan_error(path: &Path, err: &str) -> String {
571    let reason = concise_scan_error_reason(err);
572    format!("{reason}: {}", path.to_string_lossy())
573}
574
575pub(crate) fn format_default_scan_error_from_diagnostics(
576    path: &Path,
577    scan_diagnostics: &[ScanDiagnostic],
578) -> Option<String> {
579    let errors: Vec<&ScanDiagnostic> = scan_diagnostics
580        .iter()
581        .filter(|d| {
582            d.severity == DiagnosticSeverity::Error || d.severity == DiagnosticSeverity::Timeout
583        })
584        .collect();
585
586    errors
587        .iter()
588        .find(|d| d.is_timeout())
589        .or_else(|| errors.first())
590        .map(|d| format_default_scan_error(path, &d.message))
591}
592
593pub(crate) fn format_default_scan_warning_from_list(
594    path: &Path,
595    scan_warnings: &[String],
596) -> Option<String> {
597    scan_warnings
598        .first()
599        .map(|warning| format_default_scan_error(path, warning))
600}
601
602/// Diagnostics split by severity in a single pass.
603#[derive(Default)]
604pub(crate) struct PartitionedDiagnostics {
605    pub errors: Vec<String>,
606    pub warnings: Vec<String>,
607    /// Informational outcomes (for example, benign binary-content skips). These
608    /// are neither failures nor warnings: they are excluded from `scan_errors`
609    /// and from error/warning counts, and only surface in verbose output.
610    pub infos: Vec<String>,
611}
612
613pub(crate) fn partition_scan_diagnostics(
614    scan_diagnostics: &[ScanDiagnostic],
615) -> PartitionedDiagnostics {
616    let mut partitioned = PartitionedDiagnostics::default();
617
618    for diagnostic in scan_diagnostics {
619        match diagnostic.severity {
620            DiagnosticSeverity::Error | DiagnosticSeverity::Timeout => {
621                partitioned.errors.push(diagnostic.message.clone())
622            }
623            DiagnosticSeverity::Warning => partitioned.warnings.push(diagnostic.message.clone()),
624            DiagnosticSeverity::Info => partitioned.infos.push(diagnostic.message.clone()),
625        }
626    }
627
628    partitioned
629}
630
631fn concise_scan_error_reason(err: &str) -> String {
632    let first_line = err
633        .lines()
634        .find(|line| !line.trim().is_empty())
635        .map(str::trim)
636        .unwrap_or("Scan failed");
637
638    if let Some((prefix, _)) = first_line.split_once(" at ")
639        && is_structured_error_prefix(prefix)
640    {
641        return prefix.to_string();
642    }
643
644    if let Some((prefix, _)) = first_line.split_once(": ")
645        && is_structured_error_prefix(prefix)
646    {
647        return prefix.to_string();
648    }
649
650    first_line.to_string()
651}
652
653fn is_structured_error_prefix(prefix: &str) -> bool {
654    let lowercase = prefix.to_ascii_lowercase();
655    lowercase.starts_with("failed to ")
656        || lowercase.ends_with(" failed")
657        || lowercase.starts_with("timeout ")
658        || lowercase.starts_with("processing interrupted")
659}
660
661fn pluralize_files(count: usize) -> &'static str {
662    if count == 1 { "file" } else { "files" }
663}
664
665fn pdf_oxide_default_log_filter_from(rust_log: Option<&str>) -> Option<LevelFilter> {
666    should_filter_pdf_oxide_default_warnings_from(rust_log).then_some(LevelFilter::Off)
667}
668
669fn should_filter_pdf_oxide_default_warnings_from(rust_log: Option<&str>) -> bool {
670    rust_log.is_none_or(|value| !value.contains("pdf_oxide"))
671}
672
673fn accumulate_timing(timings: &mut Vec<(String, f64)>, name: String, duration: f64) {
674    if let Some((_, existing)) = timings
675        .iter_mut()
676        .find(|(existing_name, _)| *existing_name == name)
677    {
678        *existing += duration;
679    } else {
680        timings.push((name, duration));
681    }
682}
683
684fn supports_color(stderr_is_tty: bool) -> bool {
685    if !stderr_is_tty {
686        return false;
687    }
688    if env::var_os("NO_COLOR").is_some() {
689        return false;
690    }
691    !matches!(env::var("TERM"), Ok(term) if term == "dumb")
692}
693
694fn build_summary_messages(
695    stats: &ScanStats,
696    scan_start: &str,
697    scan_end: &str,
698    verbose: bool,
699) -> Vec<String> {
700    let total = stats
701        .top_level_timings
702        .iter()
703        .map(|(_, value)| *value)
704        .sum::<f64>()
705        .max(0.0);
706    let scan_time = stats
707        .top_level_timings
708        .iter()
709        .find_map(|(name, value)| (name == "scan").then_some(*value))
710        .unwrap_or(0.0);
711
712    let speed_files = if scan_time > 0.0 {
713        stats.final_files as f64 / scan_time
714    } else {
715        0.0
716    };
717    let speed_bytes = if scan_time > 0.0 {
718        stats.total_bytes_scanned as f64 / scan_time
719    } else {
720        0.0
721    };
722
723    let scan_names = if stats.scan_names.is_empty() {
724        "scan".to_string()
725    } else {
726        stats.scan_names.clone()
727    };
728
729    let mut lines = vec![
730        format!(
731            "Summary:        {scan_names} with {} process(es)",
732            stats.processes.to_i32()
733        ),
734        format!("Errors count:   {}", stats.error_count),
735        format!("Warnings count: {}", stats.warning_count),
736        format!(
737            "Scan Speed:     {speed_files:.2} files/sec. {}/sec.",
738            format_size(speed_bytes)
739        ),
740        format!(
741            "Initial counts: {} resource(s): {} file(s) and {} directorie(s) for {}",
742            stats.initial_files + stats.initial_dirs,
743            stats.initial_files,
744            stats.initial_dirs,
745            format_size(stats.initial_size as f64)
746        ),
747        format!(
748            "Final counts:   {} resource(s): {} file(s) and {} directorie(s) for {}",
749            stats.final_files + stats.final_dirs,
750            stats.final_files,
751            stats.final_dirs,
752            format_size(stats.final_size as f64)
753        ),
754        format!("Excluded count: {}", stats.excluded_count),
755        format!(
756            "Packages:       {} assembled from {} manifests",
757            stats.packages_assembled, stats.manifests_seen
758        ),
759        "Timings:".to_string(),
760        format!("  scan_start: {scan_start}"),
761        format!("  scan_end:   {scan_end}"),
762    ];
763
764    // The per-phase breakdown is developer-facing diagnostic detail; keep the
765    // default summary compact (counts, ScanCode-style timestamps, and total) and
766    // surface the full tree only under --verbose.
767    if verbose {
768        for (name, value) in &stats.top_level_timings {
769            lines.push(format!("  {name}: {value:.2}s"));
770
771            let detail_timings = stats
772                .detail_timings
773                .iter()
774                .filter(|(detail_name, _)| detail_parent_phase(detail_name) == Some(name.as_str()));
775
776            if name == "scan" {
777                let scan_breakdown: Vec<_> = detail_timings.collect();
778                if !scan_breakdown.is_empty() {
779                    lines.push("  scan breakdown (cumulative worker time):".to_string());
780                    lines.extend(
781                        scan_breakdown
782                            .into_iter()
783                            .map(|(detail_name, detail_value)| {
784                                format!("    {detail_name}: {detail_value:.2}s")
785                            }),
786                    );
787                }
788            } else {
789                lines.extend(detail_timings.map(|(detail_name, detail_value)| {
790                    format!("    {detail_name}: {detail_value:.2}s")
791                }));
792            }
793        }
794    }
795    lines.push(format!("  total: {total:.2}s"));
796
797    lines
798}
799
800fn detail_parent_phase(detail_name: &str) -> Option<&'static str> {
801    if detail_name.starts_with("setup:") || detail_name.starts_with("setup_scan:") {
802        Some("setup")
803    } else if detail_name.starts_with("scan:") {
804        Some("scan")
805    } else if detail_name.starts_with("post-scan:") || detail_name.starts_with("output-filter:") {
806        Some("post-scan")
807    } else if detail_name.starts_with("assembly:") {
808        Some("assembly")
809    } else if detail_name.starts_with("finalize:") {
810        Some("finalize")
811    } else if detail_name.starts_with("output:") {
812        Some("output")
813    } else {
814        None
815    }
816}
817
818pub fn format_size(bytes: f64) -> String {
819    if bytes < 1.0 {
820        return "0 Bytes".to_string();
821    }
822    if bytes == 1.0 {
823        return "1 Byte".to_string();
824    }
825
826    let mut size = bytes;
827    let units = ["Bytes", "KB", "MB", "GB", "TB"];
828    let mut idx = 0;
829    while size >= 1024.0 && idx < units.len() - 1 {
830        size /= 1024.0;
831        idx += 1;
832    }
833
834    if idx == 0 {
835        format!("{:.0} {}", size, units[idx])
836    } else {
837        format!("{size:.2} {}", units[idx])
838    }
839}
840
841#[cfg(test)]
842mod tests {
843    use super::{
844        ProgressMode, ScanProgress, ScanStats, apply_default_log_filters_from,
845        build_summary_messages, concise_scan_error_reason, format_default_scan_error, format_size,
846        pdf_oxide_default_log_filter_from, pluralize_files,
847        should_filter_pdf_oxide_default_warnings_from,
848    };
849    use crate::cli::ProcessMode;
850    use crate::models::ScanDiagnostic;
851
852    use std::path::Path;
853
854    use log::{Level, LevelFilter, Log, MetadataBuilder};
855
856    #[test]
857    fn format_size_matches_expected_shape() {
858        assert_eq!(format_size(0.0), "0 Bytes");
859        assert_eq!(format_size(1.0), "1 Byte");
860        assert_eq!(format_size(1024.0), "1.00 KB");
861        assert_eq!(format_size(2_567_000.0), "2.45 MB");
862    }
863
864    #[test]
865    fn summary_messages_render_detail_timings_hierarchically() {
866        let stats = ScanStats {
867            processes: ProcessMode::Parallel(4),
868            scan_names: "licenses, packages".to_string(),
869            initial_files: 10,
870            initial_dirs: 2,
871            initial_size: 2_048,
872            excluded_count: 1,
873            final_files: 8,
874            final_dirs: 1,
875            final_size: 1_024,
876            error_count: 0,
877            warning_count: 0,
878            total_bytes_scanned: 800,
879            packages_assembled: 3,
880            manifests_seen: 5,
881            incremental_reused: 0,
882            top_level_timings: vec![
883                ("setup".to_string(), 1.0),
884                ("inventory".to_string(), 2.0),
885                ("scan".to_string(), 3.0),
886                ("post-scan".to_string(), 4.0),
887                ("assembly".to_string(), 5.0),
888                ("finalize".to_string(), 6.0),
889                ("output".to_string(), 7.0),
890            ],
891            detail_timings: vec![
892                ("setup_scan:licenses".to_string(), 0.5),
893                ("scan:packages".to_string(), 1.25),
894                ("output-filter:only-findings".to_string(), 1.5),
895                ("finalize:output-prepare".to_string(), 2.0),
896            ],
897        };
898
899        let lines = build_summary_messages(&stats, "start", "end", true);
900        let line_index = |needle: &str| {
901            lines
902                .iter()
903                .position(|line| line == needle)
904                .unwrap_or_else(|| panic!("missing line: {needle}"))
905        };
906
907        assert!(lines.contains(&"  total: 28.00s".to_string()));
908        assert!(lines.contains(&"    setup_scan:licenses: 0.50s".to_string()));
909        assert!(lines.contains(&"  scan breakdown (cumulative worker time):".to_string()));
910        assert!(lines.contains(&"    scan:packages: 1.25s".to_string()));
911        assert!(lines.contains(&"    output-filter:only-findings: 1.50s".to_string()));
912        assert!(lines.contains(&"    finalize:output-prepare: 2.00s".to_string()));
913        assert!(line_index("  setup: 1.00s") < line_index("    setup_scan:licenses: 0.50s"));
914        assert!(
915            line_index("  scan: 3.00s") < line_index("  scan breakdown (cumulative worker time):")
916        );
917        assert!(
918            line_index("  scan breakdown (cumulative worker time):")
919                < line_index("    scan:packages: 1.25s")
920        );
921        assert!(
922            line_index("  post-scan: 4.00s") < line_index("    output-filter:only-findings: 1.50s")
923        );
924        assert!(line_index("  finalize: 6.00s") < line_index("    finalize:output-prepare: 2.00s"));
925    }
926
927    #[test]
928    fn summary_messages_use_scan_time_for_scan_speed() {
929        let stats = ScanStats {
930            final_files: 20,
931            total_bytes_scanned: 2_048,
932            top_level_timings: vec![("scan".to_string(), 4.0)],
933            ..ScanStats::default()
934        };
935
936        let lines = build_summary_messages(&stats, "start", "end", false);
937
938        assert!(lines.contains(&"Scan Speed:     5.00 files/sec. 512 Bytes/sec.".to_string()));
939    }
940
941    #[test]
942    fn default_summary_keeps_total_but_omits_phase_breakdown() {
943        let stats = ScanStats {
944            final_files: 10,
945            total_bytes_scanned: 800,
946            top_level_timings: vec![("setup".to_string(), 1.0), ("scan".to_string(), 3.0)],
947            detail_timings: vec![("scan:packages".to_string(), 1.25)],
948            ..ScanStats::default()
949        };
950
951        let lines = build_summary_messages(&stats, "start", "end", false);
952
953        // Compact default: counts, ScanCode-style timestamps, and total wall time.
954        assert!(lines.contains(&"Timings:".to_string()));
955        assert!(lines.contains(&"  scan_start: start".to_string()));
956        assert!(lines.contains(&"  scan_end:   end".to_string()));
957        assert!(lines.contains(&"  total: 4.00s".to_string()));
958        // No per-phase breakdown without --verbose.
959        assert!(!lines.contains(&"  setup: 1.00s".to_string()));
960        assert!(!lines.contains(&"  scan: 3.00s".to_string()));
961        assert!(!lines.iter().any(|line| line.contains("scan breakdown")));
962        assert!(!lines.contains(&"    scan:packages: 1.25s".to_string()));
963    }
964
965    #[test]
966    fn default_pdf_oxide_warnings_are_suppressed() {
967        assert_eq!(
968            pdf_oxide_default_log_filter_from(None),
969            Some(LevelFilter::Off)
970        );
971        assert!(should_filter_pdf_oxide_default_warnings_from(None));
972    }
973
974    #[test]
975    fn explicit_pdf_oxide_rust_log_override_disables_default_filter() {
976        assert!(!should_filter_pdf_oxide_default_warnings_from(Some(
977            "pdf_oxide::fonts::font_dict=warn"
978        )));
979    }
980
981    #[test]
982    fn default_pdf_oxide_filter_covers_unlisted_submodules() {
983        let mut builder = env_logger::Builder::new();
984        builder.filter_level(LevelFilter::Warn);
985        apply_default_log_filters_from(&mut builder, None);
986        let logger = builder.build();
987        let warn_metadata = MetadataBuilder::new()
988            .target("pdf_oxide::content::parser")
989            .level(Level::Warn)
990            .build();
991        let error_metadata = MetadataBuilder::new()
992            .target("pdf_oxide::content::parser")
993            .level(Level::Error)
994            .build();
995
996        assert!(!logger.enabled(&warn_metadata));
997        assert!(!logger.enabled(&error_metadata));
998    }
999
1000    #[test]
1001    fn concise_scan_error_reason_keeps_high_level_failure_context() {
1002        assert_eq!(
1003            concise_scan_error_reason(
1004                "Failed to read or parse package.json at \"fixtures/package.json\": key must be a string at line 1 column 3"
1005            ),
1006            "Failed to read or parse package.json"
1007        );
1008        assert_eq!(
1009            concise_scan_error_reason("License detection failed: missing query token"),
1010            "License detection failed"
1011        );
1012        assert_eq!(
1013            concise_scan_error_reason("Processing interrupted due to timeout after 2.00 seconds"),
1014            "Processing interrupted due to timeout after 2.00 seconds"
1015        );
1016    }
1017
1018    #[test]
1019    fn default_scan_error_format_includes_reason_and_path() {
1020        let formatted = format_default_scan_error(
1021            Path::new("fixtures/package.json"),
1022            "Failed to read or parse package.json at \"fixtures/package.json\": key must be a string at line 1 column 3",
1023        );
1024
1025        assert_eq!(
1026            formatted,
1027            "Failed to read or parse package.json: fixtures/package.json"
1028        );
1029    }
1030
1031    #[test]
1032    fn pluralize_files_uses_expected_labels() {
1033        assert_eq!(pluralize_files(1), "file");
1034        assert_eq!(pluralize_files(2), "files");
1035    }
1036
1037    #[test]
1038    fn file_completed_counts_warning_diagnostics_without_prefix_heuristics() {
1039        let progress = ScanProgress::new(ProgressMode::Quiet);
1040
1041        progress.file_completed(
1042            Path::new("project/custom.txt"),
1043            42,
1044            &[ScanDiagnostic::warning("custom recoverable warning")],
1045        );
1046
1047        let stats = progress.stats.lock().expect("stats lock poisoned");
1048        assert_eq!(stats.warning_count, 1);
1049        assert_eq!(stats.error_count, 0);
1050    }
1051
1052    #[test]
1053    fn final_header_counts_raise_summary_warning_count() {
1054        let progress = ScanProgress::new(ProgressMode::Quiet);
1055
1056        progress.record_final_header_counts(&[crate::models::Header {
1057            tool_name: "provenant".to_string(),
1058            tool_version: "0.0.0-test".to_string(),
1059            options: serde_json::Map::new(),
1060            notice: "test".to_string(),
1061            start_timestamp: "start".to_string(),
1062            end_timestamp: "end".to_string(),
1063            output_format_version: "4.1.0".to_string(),
1064            duration: 0.0,
1065            errors: vec![],
1066            warnings: vec!["custom replay warning".to_string()],
1067            extra_data: crate::models::ExtraData {
1068                system_environment: crate::models::SystemEnvironment {
1069                    operating_system: "linux".to_string(),
1070                    cpu_architecture: "x86_64".to_string(),
1071                    platform: "linux".to_string(),
1072                    platform_version: "test".to_string(),
1073                    rust_version: "1.0.0".to_string(),
1074                },
1075                spdx_license_list_version: "test".to_string(),
1076                files_count: 0,
1077                directories_count: 0,
1078                excluded_count: 0,
1079                license_index_provenance: None,
1080            },
1081        }]);
1082
1083        let stats = progress.stats.lock().expect("stats lock poisoned");
1084        assert_eq!(stats.warning_count, 1);
1085        assert_eq!(stats.error_count, 0);
1086    }
1087}