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