Skip to main content

provenant/
progress.rs

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