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::cli::ProcessMode;
14use crate::models::{FileInfo, FileType};
15
16#[derive(Clone, Copy, Debug, PartialEq, Eq)]
17pub enum ProgressMode {
18    Quiet,
19    Default,
20    Verbose,
21}
22
23#[derive(Debug, Default, Clone)]
24pub struct ScanStats {
25    pub processes: ProcessMode,
26    pub scan_names: String,
27    pub initial_files: usize,
28    pub initial_dirs: usize,
29    pub initial_size: u64,
30    pub excluded_count: usize,
31    pub final_files: usize,
32    pub final_dirs: usize,
33    pub final_size: u64,
34    pub error_count: usize,
35    pub warning_count: usize,
36    pub total_bytes_scanned: u64,
37    pub packages_assembled: usize,
38    pub manifests_seen: usize,
39    pub top_level_timings: Vec<(String, f64)>,
40    pub detail_timings: Vec<(String, f64)>,
41    pub incremental_reused: usize,
42}
43
44pub struct ScanProgress {
45    mode: ProgressMode,
46    multi: MultiProgress,
47    scan_bar: ProgressBar,
48    stats: Mutex<ScanStats>,
49    phase_starts: Mutex<HashMap<&'static str, Instant>>,
50    phase_spinner: Mutex<Option<ProgressBar>>,
51    stderr_is_tty: bool,
52}
53
54impl ScanProgress {
55    pub fn new(mode: ProgressMode) -> Self {
56        let stderr_is_tty = std::io::stderr().is_terminal();
57        let multi = match mode {
58            ProgressMode::Quiet => MultiProgress::with_draw_target(ProgressDrawTarget::hidden()),
59            ProgressMode::Default if stderr_is_tty => {
60                MultiProgress::with_draw_target(ProgressDrawTarget::stderr_with_hz(15))
61            }
62            ProgressMode::Default | ProgressMode::Verbose => {
63                MultiProgress::with_draw_target(ProgressDrawTarget::hidden())
64            }
65        };
66
67        let scan_bar = if mode == ProgressMode::Default && stderr_is_tty {
68            multi.add(ProgressBar::new(0))
69        } else {
70            ProgressBar::hidden()
71        };
72
73        scan_bar.set_style(
74            ProgressStyle::default_bar()
75                .template(
76                    "{spinner:.green} [{elapsed_precise}] [{bar:40.cyan/blue}] {pos}/{len} files ({per_sec}) ({eta})",
77                )
78                .expect("Failed to create progress bar style")
79                .progress_chars("#>-"),
80        );
81
82        Self {
83            mode,
84            multi,
85            scan_bar,
86            stats: Mutex::new(ScanStats::default()),
87            phase_starts: Mutex::new(HashMap::new()),
88            phase_spinner: Mutex::new(None),
89            stderr_is_tty,
90        }
91    }
92
93    pub fn start_setup(&self) {
94        self.start_phase("setup");
95    }
96
97    pub fn finish_setup(&self) {
98        self.finish_top_level_phase("setup");
99    }
100
101    pub fn set_processes(&self, processes: ProcessMode) {
102        let mut stats = self.stats.lock().expect("stats lock poisoned");
103        stats.processes = processes;
104    }
105
106    pub fn set_scan_names(&self, scan_names: String) {
107        let mut stats = self.stats.lock().expect("stats lock poisoned");
108        stats.scan_names = scan_names;
109    }
110
111    pub fn init_logging_bridge(&self) {
112        if self.mode == ProgressMode::Quiet {
113            return;
114        }
115
116        let logger = build_env_logger();
117        let level = logger.filter();
118        if LogWrapper::new(self.multi.clone(), logger)
119            .try_init()
120            .is_ok()
121        {
122            log::set_max_level(level);
123        }
124    }
125
126    pub fn start_discovery(&self) {
127        self.start_phase("inventory");
128        match self.mode {
129            ProgressMode::Quiet => {}
130            ProgressMode::Default => {
131                self.start_spinner("Collecting files...");
132            }
133            ProgressMode::Verbose => {
134                self.message("Collecting files...");
135            }
136        }
137    }
138
139    pub fn finish_discovery(&self, files: usize, dirs: usize, size: u64, excluded: usize) {
140        self.finish_spinner();
141        self.finish_top_level_phase("inventory");
142        let mut stats = self.stats.lock().expect("stats lock poisoned");
143        stats.initial_files = files;
144        stats.initial_dirs = dirs;
145        stats.initial_size = size;
146        stats.excluded_count = excluded;
147    }
148
149    pub fn start_license_detection_engine_creation(&self) {
150        self.start_phase("license_detection_engine_creation");
151        self.message("Loading SPDX data, this may take a while...");
152    }
153
154    pub fn finish_license_detection_engine_creation(&self, detail_name: impl Into<String>) {
155        self.finish_detail_phase(detail_name.into(), "license_detection_engine_creation");
156    }
157
158    pub fn start_scan(&self, total_files: usize) {
159        self.start_phase("scan");
160        self.scan_bar.set_length(total_files as u64);
161        self.scan_bar.set_position(0);
162
163        if matches!(self.mode, ProgressMode::Default | ProgressMode::Verbose) && !self.stderr_is_tty
164        {
165            self.message(&format!(
166                "Scanning {total_files} {}...",
167                pluralize_files(total_files)
168            ));
169        }
170    }
171
172    pub fn file_completed(&self, path: &Path, bytes: u64, scan_errors: &[String]) {
173        self.scan_bar.inc(1);
174        let mut stats = self.stats.lock().expect("stats lock poisoned");
175        stats.total_bytes_scanned += bytes;
176
177        let errors = scan_errors
178            .iter()
179            .filter(|error| !is_warning_scan_error(error))
180            .cloned()
181            .collect::<Vec<_>>();
182        let warnings = scan_errors
183            .iter()
184            .filter(|error| is_warning_scan_error(error))
185            .cloned()
186            .collect::<Vec<_>>();
187
188        if !errors.is_empty() {
189            stats.error_count += 1;
190        } else if !warnings.is_empty() {
191            stats.warning_count += 1;
192        }
193        drop(stats);
194
195        match self.mode {
196            ProgressMode::Quiet => {}
197            ProgressMode::Default => {
198                if let Some(formatted) = format_default_scan_error_from_list(path, &errors) {
199                    self.error(&formatted);
200                } else if let Some(formatted) =
201                    format_default_scan_warning_from_list(path, &warnings)
202                {
203                    self.message(&format!("Warning: {formatted}"));
204                }
205            }
206            ProgressMode::Verbose => {
207                if self.stderr_is_tty || !errors.is_empty() || !warnings.is_empty() {
208                    self.message(&path.to_string_lossy());
209                }
210                for err in &errors {
211                    for line in err.lines() {
212                        self.error(&format!("  {line}"));
213                    }
214                }
215                for warning in &warnings {
216                    for line in warning.lines() {
217                        self.message(&format!("  warning: {line}"));
218                    }
219                }
220            }
221        }
222    }
223
224    pub fn record_runtime_error(&self, path: &Path, err: &str) {
225        let mut stats = self.stats.lock().expect("stats lock poisoned");
226        stats.error_count += 1;
227        drop(stats);
228
229        match self.mode {
230            ProgressMode::Quiet => {}
231            ProgressMode::Default => self.error(&format_default_scan_error(path, err)),
232            ProgressMode::Verbose => {
233                self.error(&format!("Path: {}", path.to_string_lossy()));
234                for line in err.lines() {
235                    self.error(&format!("  {line}"));
236                }
237            }
238        }
239    }
240
241    pub fn record_additional_error(&self, err: &str) {
242        let mut stats = self.stats.lock().expect("stats lock poisoned");
243        stats.error_count += 1;
244        drop(stats);
245
246        if self.mode != ProgressMode::Quiet {
247            self.error(err);
248        }
249    }
250
251    pub fn finish_scan(&self) {
252        self.finish_top_level_phase("scan");
253        if self.mode == ProgressMode::Default && self.stderr_is_tty {
254            self.scan_bar.finish_with_message("Scan complete!");
255        } else {
256            self.scan_bar.finish_and_clear();
257            if matches!(self.mode, ProgressMode::Default)
258                || (self.mode == ProgressMode::Verbose && !self.stderr_is_tty)
259            {
260                self.message("Scan complete.");
261            }
262        }
263    }
264
265    pub fn record_incremental_reused(&self, count: usize) {
266        let mut stats = self.stats.lock().expect("stats lock poisoned");
267        stats.incremental_reused += count;
268    }
269
270    pub fn start_assembly(&self) {
271        self.start_phase("assembly");
272        match self.mode {
273            ProgressMode::Quiet => {}
274            ProgressMode::Default => self.start_spinner("Assembling packages..."),
275            ProgressMode::Verbose => self.message("Assembling packages..."),
276        }
277    }
278
279    pub fn assembly_step(&self, step: &str) {
280        if self.mode == ProgressMode::Verbose {
281            self.message(&format!("  {step}"));
282        }
283    }
284
285    pub fn finish_assembly(&self, packages_assembled: usize, manifests_seen: usize) {
286        self.finish_spinner();
287        self.finish_top_level_phase("assembly");
288        let mut stats = self.stats.lock().expect("stats lock poisoned");
289        stats.packages_assembled = packages_assembled;
290        stats.manifests_seen = manifests_seen;
291    }
292
293    pub fn start_output(&self) {
294        self.start_phase("output");
295        match self.mode {
296            ProgressMode::Quiet => {}
297            ProgressMode::Default => self.start_spinner("Writing output..."),
298            ProgressMode::Verbose => self.message("Writing output..."),
299        }
300    }
301
302    pub fn output_written(&self, text: &str) {
303        self.message(text);
304    }
305
306    pub fn finish_output(&self) {
307        self.finish_spinner();
308        self.finish_top_level_phase("output");
309    }
310
311    pub fn start_post_scan(&self) {
312        self.start_phase("post-scan");
313        if self.mode == ProgressMode::Verbose {
314            self.message("Post-processing scan results...");
315        }
316    }
317
318    pub fn post_scan_step(&self, step: &str) {
319        if self.mode == ProgressMode::Verbose {
320            self.message(&format!("  {step}"));
321        }
322    }
323
324    pub fn finish_post_scan(&self) {
325        self.finish_top_level_phase("post-scan");
326    }
327
328    pub fn start_finalize(&self) {
329        self.start_phase("finalize");
330        if self.mode == ProgressMode::Verbose {
331            self.message("Finalizing scan results...");
332        }
333    }
334
335    pub fn finalize_step(&self, step: &str) {
336        if self.mode == ProgressMode::Verbose {
337            self.message(&format!("  {step}"));
338        }
339    }
340
341    pub fn finish_finalize(&self) {
342        self.finish_top_level_phase("finalize");
343    }
344
345    pub fn record_detail_timing(&self, name: impl Into<String>, duration: f64) {
346        let mut stats = self.stats.lock().expect("stats lock poisoned");
347        accumulate_timing(&mut stats.detail_timings, name.into(), duration);
348    }
349
350    pub fn record_final_counts(&self, files: &[FileInfo]) {
351        let mut stats = self.stats.lock().expect("stats lock poisoned");
352        stats.final_files = files
353            .iter()
354            .filter(|f| f.file_type == FileType::File)
355            .count();
356        stats.final_dirs = files
357            .iter()
358            .filter(|f| f.file_type == FileType::Directory)
359            .count();
360        stats.final_size = files
361            .iter()
362            .filter(|f| f.file_type == FileType::File)
363            .map(|f| f.size)
364            .sum();
365    }
366
367    pub fn display_summary(&self, scan_start: &str, scan_end: &str) {
368        if self.mode == ProgressMode::Quiet {
369            return;
370        }
371
372        let stats = self.stats.lock().expect("stats lock poisoned");
373
374        if stats.error_count > 0 {
375            self.error("Some files failed to scan properly:");
376        } else if stats.warning_count > 0 {
377            self.message("Some files reported recoverable scan warnings:");
378        }
379        for line in build_summary_messages(&stats, scan_start, scan_end) {
380            self.message(&line);
381        }
382        if stats.incremental_reused > 0 {
383            self.message(&format!(
384                "Incremental:    {} unchanged file(s) reused",
385                stats.incremental_reused
386            ));
387        }
388    }
389
390    fn message(&self, msg: &str) {
391        if self.mode == ProgressMode::Quiet {
392            return;
393        }
394
395        if self.mode == ProgressMode::Default && self.stderr_is_tty {
396            let _ = self.multi.println(msg);
397        } else {
398            eprintln!("{msg}");
399        }
400    }
401
402    fn error(&self, msg: &str) {
403        if self.mode == ProgressMode::Quiet {
404            return;
405        }
406
407        if supports_color(self.stderr_is_tty) {
408            self.message(&format!("\u{1b}[31m{msg}\u{1b}[0m"));
409        } else {
410            self.message(msg);
411        }
412    }
413
414    fn start_phase(&self, phase: &'static str) {
415        self.phase_starts
416            .lock()
417            .expect("phase lock poisoned")
418            .insert(phase, Instant::now());
419    }
420
421    fn finish_top_level_phase(&self, phase: &'static str) {
422        let start = self
423            .phase_starts
424            .lock()
425            .expect("phase lock poisoned")
426            .remove(phase);
427        if let Some(start) = start {
428            let mut stats = self.stats.lock().expect("stats lock poisoned");
429            accumulate_timing(
430                &mut stats.top_level_timings,
431                phase.to_string(),
432                start.elapsed().as_secs_f64(),
433            );
434        }
435    }
436
437    fn finish_detail_phase(&self, name: String, phase: &'static str) {
438        let start = self
439            .phase_starts
440            .lock()
441            .expect("phase lock poisoned")
442            .remove(phase);
443        if let Some(start) = start {
444            let mut stats = self.stats.lock().expect("stats lock poisoned");
445            accumulate_timing(
446                &mut stats.detail_timings,
447                name,
448                start.elapsed().as_secs_f64(),
449            );
450        }
451    }
452
453    fn start_spinner(&self, message: &str) {
454        if self.mode != ProgressMode::Default || !self.stderr_is_tty {
455            self.message(message);
456            return;
457        }
458
459        let spinner = self.multi.add(ProgressBar::new_spinner());
460        spinner.set_style(
461            ProgressStyle::default_spinner()
462                .template("{spinner:.green} {msg}")
463                .expect("Failed to create spinner style"),
464        );
465        spinner.enable_steady_tick(std::time::Duration::from_millis(80));
466        spinner.set_message(message.to_string());
467        *self
468            .phase_spinner
469            .lock()
470            .expect("phase spinner lock poisoned") = Some(spinner);
471    }
472
473    fn finish_spinner(&self) {
474        if let Some(spinner) = self
475            .phase_spinner
476            .lock()
477            .expect("phase spinner lock poisoned")
478            .take()
479        {
480            spinner.finish_and_clear();
481        }
482    }
483}
484
485fn build_env_logger() -> env_logger::Logger {
486    let mut builder = env_logger::Builder::from_env(Env::default().default_filter_or("warn"));
487    apply_default_log_filters(&mut builder);
488    builder.build()
489}
490
491fn apply_default_log_filters(builder: &mut env_logger::Builder) {
492    apply_default_log_filters_from(builder, env::var("RUST_LOG").ok().as_deref());
493}
494
495fn apply_default_log_filters_from(builder: &mut env_logger::Builder, rust_log: Option<&str>) {
496    if let Some(level) = pdf_oxide_default_log_filter_from(rust_log) {
497        builder.filter_module("pdf_oxide", level);
498    }
499}
500
501pub(crate) fn format_default_scan_error(path: &Path, err: &str) -> String {
502    let reason = concise_scan_error_reason(err);
503    format!("{reason}: {}", path.to_string_lossy())
504}
505
506pub(crate) fn format_default_scan_error_from_list(
507    path: &Path,
508    scan_errors: &[String],
509) -> Option<String> {
510    scan_errors
511        .iter()
512        .find(|error| is_timeout_scan_error(error))
513        .or_else(|| scan_errors.first())
514        .map(|error| format_default_scan_error(path, error))
515}
516
517pub(crate) fn format_default_scan_warning_from_list(
518    path: &Path,
519    scan_warnings: &[String],
520) -> Option<String> {
521    scan_warnings
522        .first()
523        .map(|warning| format_default_scan_error(path, warning))
524}
525
526fn concise_scan_error_reason(err: &str) -> String {
527    let first_line = err
528        .lines()
529        .find(|line| !line.trim().is_empty())
530        .map(str::trim)
531        .unwrap_or("Scan failed");
532
533    if let Some((prefix, _)) = first_line.split_once(" at ")
534        && is_structured_error_prefix(prefix)
535    {
536        return prefix.to_string();
537    }
538
539    if let Some((prefix, _)) = first_line.split_once(": ")
540        && is_structured_error_prefix(prefix)
541    {
542        return prefix.to_string();
543    }
544
545    first_line.to_string()
546}
547
548fn is_timeout_scan_error(err: &str) -> bool {
549    err.contains("Timeout while ")
550        || err.contains("Timeout before ")
551        || err.contains("Processing interrupted due to timeout")
552}
553
554pub(crate) fn is_warning_scan_error(err: &str) -> bool {
555    let first_line = err.lines().next().unwrap_or(err).trim();
556    first_line.starts_with("Maven property ")
557        || first_line.starts_with("Skipping Maven template coordinates")
558        || first_line.starts_with("Circular include detected")
559}
560
561fn is_structured_error_prefix(prefix: &str) -> bool {
562    let lowercase = prefix.to_ascii_lowercase();
563    lowercase.starts_with("failed to ")
564        || lowercase.ends_with(" failed")
565        || lowercase.starts_with("timeout ")
566        || lowercase.starts_with("processing interrupted")
567}
568
569fn pluralize_files(count: usize) -> &'static str {
570    if count == 1 { "file" } else { "files" }
571}
572
573fn pdf_oxide_default_log_filter_from(rust_log: Option<&str>) -> Option<LevelFilter> {
574    should_filter_pdf_oxide_default_warnings_from(rust_log).then_some(LevelFilter::Off)
575}
576
577fn should_filter_pdf_oxide_default_warnings_from(rust_log: Option<&str>) -> bool {
578    rust_log.is_none_or(|value| !value.contains("pdf_oxide"))
579}
580
581fn accumulate_timing(timings: &mut Vec<(String, f64)>, name: String, duration: f64) {
582    if let Some((_, existing)) = timings
583        .iter_mut()
584        .find(|(existing_name, _)| *existing_name == name)
585    {
586        *existing += duration;
587    } else {
588        timings.push((name, duration));
589    }
590}
591
592fn supports_color(stderr_is_tty: bool) -> bool {
593    if !stderr_is_tty {
594        return false;
595    }
596    if env::var_os("NO_COLOR").is_some() {
597        return false;
598    }
599    !matches!(env::var("TERM"), Ok(term) if term == "dumb")
600}
601
602fn build_summary_messages(stats: &ScanStats, scan_start: &str, scan_end: &str) -> Vec<String> {
603    let total = stats
604        .top_level_timings
605        .iter()
606        .map(|(_, value)| *value)
607        .sum::<f64>()
608        .max(0.0);
609    let scan_time = stats
610        .top_level_timings
611        .iter()
612        .find_map(|(name, value)| (name == "scan").then_some(*value))
613        .unwrap_or(0.0);
614
615    let speed_files = if scan_time > 0.0 {
616        stats.final_files as f64 / scan_time
617    } else {
618        0.0
619    };
620    let speed_bytes = if scan_time > 0.0 {
621        stats.total_bytes_scanned as f64 / scan_time
622    } else {
623        0.0
624    };
625
626    let scan_names = if stats.scan_names.is_empty() {
627        "scan".to_string()
628    } else {
629        stats.scan_names.clone()
630    };
631
632    let mut lines = vec![
633        format!(
634            "Summary:        {scan_names} with {} process(es)",
635            stats.processes.to_i32()
636        ),
637        format!("Errors count:   {}", stats.error_count),
638        format!("Warnings count: {}", stats.warning_count),
639        format!(
640            "Scan Speed:     {speed_files:.2} files/sec. {}/sec.",
641            format_size(speed_bytes)
642        ),
643        format!(
644            "Initial counts: {} resource(s): {} file(s) and {} directorie(s) for {}",
645            stats.initial_files + stats.initial_dirs,
646            stats.initial_files,
647            stats.initial_dirs,
648            format_size(stats.initial_size as f64)
649        ),
650        format!(
651            "Final counts:   {} resource(s): {} file(s) and {} directorie(s) for {}",
652            stats.final_files + stats.final_dirs,
653            stats.final_files,
654            stats.final_dirs,
655            format_size(stats.final_size as f64)
656        ),
657        format!("Excluded count: {}", stats.excluded_count),
658        format!(
659            "Packages:       {} assembled from {} manifests",
660            stats.packages_assembled, stats.manifests_seen
661        ),
662        "Timings:".to_string(),
663        format!("  scan_start: {scan_start}"),
664        format!("  scan_end:   {scan_end}"),
665    ];
666
667    for (name, value) in &stats.top_level_timings {
668        lines.push(format!("  {name}: {value:.2}s"));
669
670        let detail_timings = stats
671            .detail_timings
672            .iter()
673            .filter(|(detail_name, _)| detail_parent_phase(detail_name) == Some(name.as_str()));
674
675        if name == "scan" {
676            let scan_breakdown: Vec<_> = detail_timings.collect();
677            if !scan_breakdown.is_empty() {
678                lines.push("  scan breakdown (cumulative worker time):".to_string());
679                lines.extend(
680                    scan_breakdown
681                        .into_iter()
682                        .map(|(detail_name, detail_value)| {
683                            format!("    {detail_name}: {detail_value:.2}s")
684                        }),
685                );
686            }
687        } else {
688            lines.extend(detail_timings.map(|(detail_name, detail_value)| {
689                format!("    {detail_name}: {detail_value:.2}s")
690            }));
691        }
692    }
693    lines.push(format!("  total: {total:.2}s"));
694
695    lines
696}
697
698fn detail_parent_phase(detail_name: &str) -> Option<&'static str> {
699    if detail_name.starts_with("setup:") || detail_name.starts_with("setup_scan:") {
700        Some("setup")
701    } else if detail_name.starts_with("scan:") {
702        Some("scan")
703    } else if detail_name.starts_with("post-scan:") || detail_name.starts_with("output-filter:") {
704        Some("post-scan")
705    } else if detail_name.starts_with("assembly:") {
706        Some("assembly")
707    } else if detail_name.starts_with("finalize:") {
708        Some("finalize")
709    } else if detail_name.starts_with("output:") {
710        Some("output")
711    } else {
712        None
713    }
714}
715
716pub fn format_size(bytes: f64) -> String {
717    if bytes < 1.0 {
718        return "0 Bytes".to_string();
719    }
720    if bytes == 1.0 {
721        return "1 Byte".to_string();
722    }
723
724    let mut size = bytes;
725    let units = ["Bytes", "KB", "MB", "GB", "TB"];
726    let mut idx = 0;
727    while size >= 1024.0 && idx < units.len() - 1 {
728        size /= 1024.0;
729        idx += 1;
730    }
731
732    if idx == 0 {
733        format!("{:.0} {}", size, units[idx])
734    } else {
735        format!("{size:.2} {}", units[idx])
736    }
737}
738
739#[cfg(test)]
740mod tests {
741    use super::{
742        ScanStats, apply_default_log_filters_from, build_summary_messages,
743        concise_scan_error_reason, format_default_scan_error, format_default_scan_error_from_list,
744        format_size, pdf_oxide_default_log_filter_from, pluralize_files,
745        should_filter_pdf_oxide_default_warnings_from,
746    };
747    use crate::cli::ProcessMode;
748
749    use std::path::Path;
750
751    use log::{Level, LevelFilter, Log, MetadataBuilder};
752
753    #[test]
754    fn format_size_matches_expected_shape() {
755        assert_eq!(format_size(0.0), "0 Bytes");
756        assert_eq!(format_size(1.0), "1 Byte");
757        assert_eq!(format_size(1024.0), "1.00 KB");
758        assert_eq!(format_size(2_567_000.0), "2.45 MB");
759    }
760
761    #[test]
762    fn summary_messages_render_detail_timings_hierarchically() {
763        let stats = ScanStats {
764            processes: ProcessMode::Parallel(4),
765            scan_names: "licenses, packages".to_string(),
766            initial_files: 10,
767            initial_dirs: 2,
768            initial_size: 2_048,
769            excluded_count: 1,
770            final_files: 8,
771            final_dirs: 1,
772            final_size: 1_024,
773            error_count: 0,
774            warning_count: 0,
775            total_bytes_scanned: 800,
776            packages_assembled: 3,
777            manifests_seen: 5,
778            incremental_reused: 0,
779            top_level_timings: vec![
780                ("setup".to_string(), 1.0),
781                ("inventory".to_string(), 2.0),
782                ("scan".to_string(), 3.0),
783                ("post-scan".to_string(), 4.0),
784                ("assembly".to_string(), 5.0),
785                ("finalize".to_string(), 6.0),
786                ("output".to_string(), 7.0),
787            ],
788            detail_timings: vec![
789                ("setup_scan:licenses".to_string(), 0.5),
790                ("scan:packages".to_string(), 1.25),
791                ("output-filter:only-findings".to_string(), 1.5),
792                ("finalize:output-prepare".to_string(), 2.0),
793            ],
794        };
795
796        let lines = build_summary_messages(&stats, "start", "end");
797        let line_index = |needle: &str| {
798            lines
799                .iter()
800                .position(|line| line == needle)
801                .unwrap_or_else(|| panic!("missing line: {needle}"))
802        };
803
804        assert!(lines.contains(&"  total: 28.00s".to_string()));
805        assert!(lines.contains(&"    setup_scan:licenses: 0.50s".to_string()));
806        assert!(lines.contains(&"  scan breakdown (cumulative worker time):".to_string()));
807        assert!(lines.contains(&"    scan:packages: 1.25s".to_string()));
808        assert!(lines.contains(&"    output-filter:only-findings: 1.50s".to_string()));
809        assert!(lines.contains(&"    finalize:output-prepare: 2.00s".to_string()));
810        assert!(line_index("  setup: 1.00s") < line_index("    setup_scan:licenses: 0.50s"));
811        assert!(
812            line_index("  scan: 3.00s") < line_index("  scan breakdown (cumulative worker time):")
813        );
814        assert!(
815            line_index("  scan breakdown (cumulative worker time):")
816                < line_index("    scan:packages: 1.25s")
817        );
818        assert!(
819            line_index("  post-scan: 4.00s") < line_index("    output-filter:only-findings: 1.50s")
820        );
821        assert!(line_index("  finalize: 6.00s") < line_index("    finalize:output-prepare: 2.00s"));
822    }
823
824    #[test]
825    fn summary_messages_use_scan_time_for_scan_speed() {
826        let stats = ScanStats {
827            final_files: 20,
828            total_bytes_scanned: 2_048,
829            top_level_timings: vec![("scan".to_string(), 4.0)],
830            ..ScanStats::default()
831        };
832
833        let lines = build_summary_messages(&stats, "start", "end");
834
835        assert!(lines.contains(&"Scan Speed:     5.00 files/sec. 512 Bytes/sec.".to_string()));
836    }
837
838    #[test]
839    fn default_pdf_oxide_warnings_are_suppressed() {
840        assert_eq!(
841            pdf_oxide_default_log_filter_from(None),
842            Some(LevelFilter::Off)
843        );
844        assert!(should_filter_pdf_oxide_default_warnings_from(None));
845    }
846
847    #[test]
848    fn explicit_pdf_oxide_rust_log_override_disables_default_filter() {
849        assert!(!should_filter_pdf_oxide_default_warnings_from(Some(
850            "pdf_oxide::fonts::font_dict=warn"
851        )));
852    }
853
854    #[test]
855    fn default_pdf_oxide_filter_covers_unlisted_submodules() {
856        let mut builder = env_logger::Builder::new();
857        builder.filter_level(LevelFilter::Warn);
858        apply_default_log_filters_from(&mut builder, None);
859        let logger = builder.build();
860        let warn_metadata = MetadataBuilder::new()
861            .target("pdf_oxide::content::parser")
862            .level(Level::Warn)
863            .build();
864        let error_metadata = MetadataBuilder::new()
865            .target("pdf_oxide::content::parser")
866            .level(Level::Error)
867            .build();
868
869        assert!(!logger.enabled(&warn_metadata));
870        assert!(!logger.enabled(&error_metadata));
871    }
872
873    #[test]
874    fn concise_scan_error_reason_keeps_high_level_failure_context() {
875        assert_eq!(
876            concise_scan_error_reason(
877                "Failed to read or parse package.json at \"fixtures/package.json\": key must be a string at line 1 column 3"
878            ),
879            "Failed to read or parse package.json"
880        );
881        assert_eq!(
882            concise_scan_error_reason("License detection failed: missing query token"),
883            "License detection failed"
884        );
885        assert_eq!(
886            concise_scan_error_reason("Processing interrupted due to timeout after 2.00 seconds"),
887            "Processing interrupted due to timeout after 2.00 seconds"
888        );
889    }
890
891    #[test]
892    fn default_scan_error_format_includes_reason_and_path() {
893        let formatted = format_default_scan_error(
894            Path::new("fixtures/package.json"),
895            "Failed to read or parse package.json at \"fixtures/package.json\": key must be a string at line 1 column 3",
896        );
897
898        assert_eq!(
899            formatted,
900            "Failed to read or parse package.json: fixtures/package.json"
901        );
902    }
903
904    #[test]
905    fn default_scan_error_format_prefers_timeout_from_error_list() {
906        let formatted = format_default_scan_error_from_list(
907            Path::new("fixtures/package.json"),
908            &[
909                "Failed to read or parse package.json at \"fixtures/package.json\": expected value"
910                    .to_string(),
911                "Timeout before license scan (> 120.00s)".to_string(),
912            ],
913        );
914
915        assert_eq!(
916            formatted.as_deref(),
917            Some("Timeout before license scan (> 120.00s): fixtures/package.json")
918        );
919    }
920
921    #[test]
922    fn pluralize_files_uses_expected_labels() {
923        assert_eq!(pluralize_files(1), "file");
924        assert_eq!(pluralize_files(2), "files");
925    }
926}