From 1619c4be600a6998e074f62c267151242401577c Mon Sep 17 00:00:00 2001 From: Henry Guo Date: Sat, 15 Aug 2026 21:32:05 +0800 Subject: [PATCH] fix(scanner): add context to corrupt metadata logs (#6099) Co-authored-by: Henry Guo --- crates/filemeta/src/filemeta/codec.rs | 5 +- crates/scanner/Cargo.toml | 2 +- crates/scanner/src/scanner_folder.rs | 123 +++++++++++++++++++++++--- crates/scanner/src/scanner_io.rs | 11 --- 4 files changed, 113 insertions(+), 28 deletions(-) diff --git a/crates/filemeta/src/filemeta/codec.rs b/crates/filemeta/src/filemeta/codec.rs index 7f2851581..86af49b97 100644 --- a/crates/filemeta/src/filemeta/codec.rs +++ b/crates/filemeta/src/filemeta/codec.rs @@ -135,10 +135,7 @@ impl FileMeta { let i = buf.len() as u64; // check version, buf = buf[8..] - let (buf, _, _) = Self::check_xl2_v1(buf).map_err(|e| { - error!("failed to check XL2 v1 format: {}", e); - e - })?; + let (buf, _, _) = Self::check_xl2_v1(buf)?; if buf.len() < 5 { error!( diff --git a/crates/scanner/Cargo.toml b/crates/scanner/Cargo.toml index 9b5aa3342..16ff34a8e 100644 --- a/crates/scanner/Cargo.toml +++ b/crates/scanner/Cargo.toml @@ -102,7 +102,7 @@ bytes.workspace = true hex-simd.workspace = true [dev-dependencies] -tracing-subscriber = { workspace = true, features = ["env-filter", "time"] } +tracing-subscriber = { workspace = true, features = ["json", "env-filter", "time"] } serial_test = { workspace = true } temp-env = { workspace = true } tempfile = { workspace = true } diff --git a/crates/scanner/src/scanner_folder.rs b/crates/scanner/src/scanner_folder.rs index ac6b86c32..7e353bf75 100644 --- a/crates/scanner/src/scanner_folder.rs +++ b/crates/scanner/src/scanner_folder.rs @@ -65,6 +65,7 @@ const LOG_SUBSYSTEM_FOLDER: &str = "folder"; const LOG_SUBSYSTEM_LIFECYCLE: &str = "lifecycle"; const LOG_SUBSYSTEM_HEAL: &str = "heal"; const EVENT_SCANNER_FOLDER_STATE: &str = "scanner_folder_state"; +const EVENT_SCANNER_METADATA_CORRUPT: &str = "scanner_metadata_corrupt"; const EVENT_SCANNER_LIFECYCLE_ACTION: &str = "scanner_lifecycle_action"; const EVENT_SCANNER_HEAL_ADMISSION: &str = "scanner_heal_admission"; const EVENT_SCANNER_ALERT_STATE: &str = "scanner_alert_state"; @@ -2154,17 +2155,34 @@ impl FolderScanner { self.record_failed(&item.path); if should_log_failed_object(into.failed_objects) { - warn!( - target: "rustfs::scanner::folder", - event = EVENT_SCANNER_FOLDER_STATE, - component = LOG_COMPONENT_SCANNER, - subsystem = LOG_SUBSYSTEM_FOLDER, - path = %item.path, - failed_objects = into.failed_objects, - state = "get_size_failed", - error = %e, - "Scanner folder failed to get object size" - ); + if let GetSizeFailureAction::HealMetadata { object } = &failure_action { + error!( + target: "rustfs::scanner::folder", + event = EVENT_SCANNER_METADATA_CORRUPT, + component = LOG_COMPONENT_SCANNER, + subsystem = LOG_SUBSYSTEM_FOLDER, + drive = %self.local_disk.path().display(), + bucket = %item.bucket, + object = %object, + metadata_path = %item.path, + failed_objects = into.failed_objects, + state = "metadata_corrupt", + error = %e, + "Scanner detected corrupt object metadata" + ); + } else { + warn!( + target: "rustfs::scanner::folder", + event = EVENT_SCANNER_FOLDER_STATE, + component = LOG_COMPONENT_SCANNER, + subsystem = LOG_SUBSYSTEM_FOLDER, + path = %item.path, + failed_objects = into.failed_objects, + state = "get_size_failed", + error = %e, + "Scanner folder failed to get object size" + ); + } } } @@ -3054,12 +3072,59 @@ mod tests { use crate::{DiskOption, Endpoint, STORAGE_FORMAT_FILE, TierStats, new_disk, storageclass}; use rustfs_filemeta::{FileInfo, FileMeta}; use serial_test::serial; + use std::io::Write; #[cfg(unix)] use std::os::unix::fs::{PermissionsExt, symlink}; + use std::sync::Mutex; use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering}; use temp_env::{with_var, with_var_unset}; + use tracing_subscriber::fmt::MakeWriter; use uuid::Uuid; + #[derive(Clone, Default)] + struct CapturedLogs { + buffer: Arc>>, + } + + struct CapturedLogWriter { + buffer: Arc>>, + } + + impl CapturedLogs { + fn contents(&self) -> String { + let buffer = self + .buffer + .lock() + .expect("captured logs mutex should not be poisoned") + .clone(); + String::from_utf8(buffer).expect("captured logs should be valid UTF-8") + } + } + + impl Write for CapturedLogWriter { + fn write(&mut self, buf: &[u8]) -> std::io::Result { + self.buffer + .lock() + .expect("captured logs mutex should not be poisoned") + .extend_from_slice(buf); + Ok(buf.len()) + } + + fn flush(&mut self) -> std::io::Result<()> { + Ok(()) + } + } + + impl<'a> MakeWriter<'a> for CapturedLogs { + type Writer = CapturedLogWriter; + + fn make_writer(&'a self) -> Self::Writer { + CapturedLogWriter { + buffer: Arc::clone(&self.buffer), + } + } + } + #[test] fn scanner_size_summary_application_saturates_usage_counters() { let target = "arn:minio:replication::target".to_string(); @@ -4542,9 +4607,19 @@ mod tests { assert!(budget.entries_visited() >= 1); } - #[tokio::test] + #[tokio::test(flavor = "current_thread")] #[serial] async fn test_scan_folder_corrupt_xl_meta_stops_erasure_data_dir_descent() { + let logs = CapturedLogs::default(); + let subscriber = tracing_subscriber::fmt() + .json() + .with_max_level(tracing::Level::ERROR) + .with_writer(logs.clone()) + .with_ansi(false) + .without_time() + .finish(); + let _subscriber_guard = tracing::subscriber::set_default(subscriber); + let (mut scanner, temp_dir) = build_test_scanner().await; let _guard = TestGuard::new(60, 100, &mut scanner, temp_dir.clone()); @@ -4596,6 +4671,30 @@ mod tests { assert!(!budget.budget_elapsed()); assert_eq!(budget.reason(), None); + let captured = logs.contents(); + assert!( + !captured.contains("failed to check XL2 v1 format"), + "the context-free filemeta parser error must not be emitted" + ); + let events = captured + .lines() + .map(|line| serde_json::from_str::(line).expect("captured scanner log should be valid JSON")) + .filter(|line| line["fields"]["event"] == EVENT_SCANNER_METADATA_CORRUPT) + .collect::>(); + assert_eq!( + events.len(), + 1, + "one corrupt metadata observation must emit one scanner-owned diagnostic event" + ); + let fields = &events[0]["fields"]; + assert_eq!(fields["component"], LOG_COMPONENT_SCANNER); + assert_eq!(fields["subsystem"], LOG_SUBSYSTEM_FOLDER); + assert_eq!(fields["drive"], temp_dir.to_string_lossy().as_ref()); + assert_eq!(fields["bucket"], "bucket"); + assert_eq!(fields["object"], "object"); + assert_eq!(fields["metadata_path"], metadata_path.to_string_lossy().as_ref()); + assert_eq!(fields["state"], "metadata_corrupt"); + let retry_budget = ScannerCycleBudget::new_with_progress_tracking( &parent, crate::scanner_budget::ScannerCycleBudgetConfig { diff --git a/crates/scanner/src/scanner_io.rs b/crates/scanner/src/scanner_io.rs index 2b234ac59..15ee9cca0 100644 --- a/crates/scanner/src/scanner_io.rs +++ b/crates/scanner/src/scanner_io.rs @@ -3849,17 +3849,6 @@ impl ScannerIODisk for Disk { let fivs = match meta.get_file_info_versions(item.bucket.as_str(), item.object_path().as_str(), false) { Ok(versions) => versions, Err(e) => { - error!( - target: "rustfs::scanner::io", - event = EVENT_SCANNER_DISK_BUCKET_STATE, - component = LOG_COMPONENT_SCANNER, - subsystem = LOG_SUBSYSTEM_IO, - bucket = %item.bucket, - object = %item.object_path(), - state = "file_info_versions_failed", - error = %e, - "Scanner disk bucket failed to resolve file info versions" - ); return Err(scanner_metadata_corrupt_error( format!("failed to resolve file info versions: {e}"), &item.bucket,