feat(scanner): expand scanner observability metrics (#3159)

* feat(scanner): expand scanner observability metrics

* chore(scanner): align bucket-drive metric wording

---------

Co-authored-by: Henry Guo <marshawcoco@users.noreply.github.com>

crates/scanner/src/scanner.rs

@@ -266,8 +266,13 @@ fn bitrot_scan_cycle() -> Option<Duration> {
     }
 }
 
-fn get_cycle_scan_mode(current_cycle: u64, bitrot_start_cycle: u64, bitrot_start_time: Option<DateTime<Utc>>) -> HealScanMode {
-    let Some(bitrot_cycle) = bitrot_scan_cycle() else {
+fn get_cycle_scan_mode(
+    current_cycle: u64,
+    bitrot_start_cycle: u64,
+    bitrot_start_time: Option<DateTime<Utc>>,
+    bitrot_cycle: Option<Duration>,
+) -> HealScanMode {
+    let Some(bitrot_cycle) = bitrot_cycle else {
         return HealScanMode::Normal;
     };
 
@@ -299,8 +304,10 @@ fn background_heal_info_for_scan_start(
     current_cycle: u64,
     scan_mode: HealScanMode,
     now: DateTime<Utc>,
+    bitrot_cycle: Option<Duration>,
 ) -> Option<BackgroundHealInfo> {
-    let reset_bitrot_start = scan_mode == HealScanMode::Deep && should_reset_bitrot_start(&info, current_cycle, now);
+    let reset_bitrot_start =
+        scan_mode == HealScanMode::Deep && should_reset_bitrot_start(&info, current_cycle, now, bitrot_cycle);
     if info.current_scan_mode == scan_mode && !reset_bitrot_start {
         return None;
     }
@@ -314,12 +321,17 @@ fn background_heal_info_for_scan_start(
     Some(info)
 }
 
-fn should_reset_bitrot_start(info: &BackgroundHealInfo, current_cycle: u64, now: DateTime<Utc>) -> bool {
+fn should_reset_bitrot_start(
+    info: &BackgroundHealInfo,
+    current_cycle: u64,
+    now: DateTime<Utc>,
+    bitrot_cycle: Option<Duration>,
+) -> bool {
     let Some(bitrot_start_time) = info.bitrot_start_time else {
         return true;
     };
 
-    let Some(bitrot_cycle) = bitrot_scan_cycle() else {
+    let Some(bitrot_cycle) = bitrot_cycle else {
         return false;
     };
 
@@ -424,6 +436,9 @@ fn get_lock_acquire_timeout() -> Duration {
 async fn run_data_scanner_cycle(ctx: &CancellationToken, storeapi: &Arc<ECStore>, cycle_info: &mut CurrentCycle) {
     let _activity_guard = ScannerActivityGuard::new();
     SCANNER_SLEEPER.refresh_from_env();
+    let configured_cycle_interval = cycle_interval();
+    let configured_bitrot_cycle = bitrot_scan_cycle();
+    global_metrics().record_scanner_cycle_config(configured_cycle_interval, configured_bitrot_cycle);
     info!("Start run data scanner cycle");
     cycle_info.current = cycle_info.next;
     let now = Instant::now();
@@ -437,11 +452,16 @@ async fn run_data_scanner_cycle(ctx: &CancellationToken, storeapi: &Arc<ECStore>
         cycle_info.current,
         background_heal_info.bitrot_start_cycle,
         background_heal_info.bitrot_start_time,
+        configured_bitrot_cycle,
     );
     let _scan_mode_guard = ScannerScanModeGuard::new(scan_mode);
-    if let Some(new_heal_info) =
-        background_heal_info_for_scan_start(background_heal_info.clone(), cycle_info.current, scan_mode, Utc::now())
-    {
+    if let Some(new_heal_info) = background_heal_info_for_scan_start(
+        background_heal_info.clone(),
+        cycle_info.current,
+        scan_mode,
+        Utc::now(),
+        configured_bitrot_cycle,
+    ) {
         background_heal_info = new_heal_info.clone();
         save_background_heal_info(storeapi.clone(), new_heal_info).await;
     }
@@ -600,18 +620,22 @@ pub async fn store_data_usage_in_backend(
         // Save a backup every 10th update
         if attempts > 10 {
             let backup_path = format!("{}.bkp", DATA_USAGE_OBJ_NAME_PATH.as_str());
+            let done_save = Metrics::time(Metric::SaveUsage);
             if let Err(e) = save_config(storeapi.clone(), &backup_path, data.clone()).await {
                 warn!("Failed to save data usage backup to {}: {}", backup_path, e);
             }
+            done_save();
             attempts = 1;
         }
 
         // Save main configuration
+        let done_save = Metrics::time(Metric::SaveUsage);
         if let Err(e) = save_config(storeapi.clone(), DATA_USAGE_OBJ_NAME_PATH.as_str(), data).await {
             error!("Failed to save data usage info to {}: {e}", DATA_USAGE_OBJ_NAME_PATH.as_str());
         } else {
             rustfs_ecstore::data_usage::replace_bucket_usage_memory_from_info(&data_usage_info).await;
         }
+        done_save();
 
         attempts += 1;
     }
@@ -866,7 +890,7 @@ mod tests {
     #[serial]
     fn test_get_cycle_scan_mode_runs_deep_until_selection_window_completes() {
         with_var(ENV_SCANNER_BITROT_CYCLE_SECS, Some("3600"), || {
-            let mode = get_cycle_scan_mode(10, 0, Some(Utc::now()));
+            let mode = get_cycle_scan_mode(10, 0, Some(Utc::now()), bitrot_scan_cycle());
             assert_eq!(mode, HealScanMode::Deep);
         });
     }
@@ -878,8 +902,8 @@ mod tests {
             let recent = Utc::now() - chrono::Duration::minutes(30);
             let old = Utc::now() - chrono::Duration::hours(2);
 
-            assert_eq!(get_cycle_scan_mode(2048, 0, Some(recent)), HealScanMode::Normal);
-            assert_eq!(get_cycle_scan_mode(2048, 0, Some(old)), HealScanMode::Deep);
+            assert_eq!(get_cycle_scan_mode(2048, 0, Some(recent), bitrot_scan_cycle()), HealScanMode::Normal);
+            assert_eq!(get_cycle_scan_mode(2048, 0, Some(old), bitrot_scan_cycle()), HealScanMode::Deep);
         });
     }
 
@@ -887,7 +911,7 @@ mod tests {
     #[serial]
     fn test_get_cycle_scan_mode_can_disable_periodic_deep_scan() {
         with_var(ENV_SCANNER_BITROT_CYCLE_SECS, Some("off"), || {
-            assert_eq!(get_cycle_scan_mode(1, 0, None), HealScanMode::Normal);
+            assert_eq!(get_cycle_scan_mode(1, 0, None, bitrot_scan_cycle()), HealScanMode::Normal);
         });
     }
 
@@ -895,8 +919,9 @@ mod tests {
     #[serial]
     fn test_background_heal_info_for_scan_start_marks_deep_active() {
         let now = Utc::now();
-        let info = background_heal_info_for_scan_start(BackgroundHealInfo::default(), 7, HealScanMode::Deep, now)
-            .expect("deep scan should update background heal info");
+        let info =
+            background_heal_info_for_scan_start(BackgroundHealInfo::default(), 7, HealScanMode::Deep, now, bitrot_scan_cycle())
+                .expect("deep scan should update background heal info");
 
         assert_eq!(info.current_scan_mode, HealScanMode::Deep);
         assert_eq!(info.bitrot_start_cycle, 7);
@@ -914,7 +939,7 @@ mod tests {
                 current_scan_mode: HealScanMode::Normal,
             };
 
-            let info = background_heal_info_for_scan_start(info, 8, HealScanMode::Deep, Utc::now())
+            let info = background_heal_info_for_scan_start(info, 8, HealScanMode::Deep, Utc::now(), bitrot_scan_cycle())
                 .expect("deep scan should mark active status");
 
             assert_eq!(info.current_scan_mode, HealScanMode::Deep);

crates/scanner/src/scanner_folder.rs

@@ -16,19 +16,19 @@ use std::collections::HashSet;
 use std::fs::FileType;
 use std::io::ErrorKind;
 use std::sync::{Arc, Once};
-use std::time::{Duration, SystemTime};
+use std::time::{Duration, Instant, SystemTime};
 
 use crate::ReplTargetSizeSummary;
 use crate::data_usage_define::{DataUsageCache, DataUsageEntry, DataUsageHash, DataUsageHashMap, SizeSummary, hash_path};
 use crate::error::ScannerError;
 use crate::scanner_io::ScannerIODisk as _;
-use crate::sleeper::DynamicSleeper;
+use crate::sleeper::{DynamicSleeper, scanner_yield_every_n_objects};
 use metrics::{counter, describe_counter};
 use rustfs_common::heal_channel::{
     HEAL_DELETE_DANGLING, HealAdmissionResult, HealChannelPriority, HealChannelRequest, HealScanMode,
     send_heal_request_with_admission,
 };
-use rustfs_common::metrics::{IlmAction, Metric, Metrics, UpdateCurrentPathFn, current_path_updater};
+use rustfs_common::metrics::{IlmAction, Metric, Metrics, UpdateCurrentPathFn, current_path_updater, global_metrics};
 use rustfs_ecstore::bucket::lifecycle::bucket_lifecycle_audit::LcEventSrc;
 use rustfs_ecstore::bucket::lifecycle::bucket_lifecycle_ops::{GLOBAL_ExpiryState, apply_expiry_rule};
 use rustfs_ecstore::bucket::lifecycle::evaluator::Evaluator;
@@ -143,13 +143,6 @@ fn scanner_excess_folders_threshold() -> u64 {
     )
 }
 
-fn scanner_yield_every_n_objects() -> u64 {
-    rustfs_utils::get_env_u64(
-        rustfs_config::ENV_SCANNER_YIELD_EVERY_N_OBJECTS,
-        rustfs_config::DEFAULT_SCANNER_YIELD_EVERY_N_OBJECTS,
-    )
-}
-
 fn should_yield_after_object(object_count: u64, yield_every: u64) -> bool {
     yield_every > 0 && object_count.is_multiple_of(yield_every)
 }
@@ -485,6 +478,7 @@ impl ScannerItem {
                         debug!("apply_actions: applying expiry rule for object: {} {}", oi.name, event.action);
                         apply_expiry_rule(event, &LcEventSrc::Scanner, oi).await;
                         done_ilm(1)();
+                        global_metrics().record_scanner_ilm_action(1);
                         break 'eventLoop;
                     }
 
@@ -497,6 +491,7 @@ impl ScannerItem {
                         debug!("apply_actions: applying expiry rule for object: {} {}", oi.name, event.action);
                         apply_expiry_rule(event, &LcEventSrc::Scanner, oi).await;
                         done_ilm(1)();
+                        global_metrics().record_scanner_ilm_action(1);
                     }
                     IlmAction::DeleteVersionAction => {
                         remaining_versions -= 1;
@@ -510,11 +505,13 @@ impl ScannerItem {
                         }
                         noncurrent_events.push(event.clone());
                         done_ilm(1)();
+                        global_metrics().record_scanner_ilm_action(1);
                     }
                     IlmAction::TransitionAction | IlmAction::TransitionVersionAction => {
                         debug!("apply_actions: applying transition rule for object: {} {}", oi.name, event.action);
                         apply_transition_rule(event, &LcEventSrc::Scanner, oi).await;
                         done_ilm(1)();
+                        global_metrics().record_scanner_ilm_action(1);
                     }
 
                     IlmAction::NoneAction | IlmAction::ActionCount => {
@@ -560,7 +557,9 @@ impl ScannerItem {
             return;
         };
 
+        let done_replication = Metrics::time(Metric::CheckReplication);
         let roi = queue_replication_heal_internal(&oi.bucket, oi.clone(), (*replication).clone(), 0).await;
+        done_replication();
         if !Self::should_account_replication_stats(oi) {
             return;
         }
@@ -1110,7 +1109,9 @@ impl FolderScanner {
                 timer.sleep().await;
 
                 if should_yield_after_object(object_count, yield_every_objects) {
+                    let yield_start = Instant::now();
                     tokio::task::yield_now().await;
+                    global_metrics().record_scanner_yield(yield_start.elapsed());
                 }
             }
 

crates/scanner/src/scanner_io.rs

@@ -22,7 +22,7 @@ use futures::future::join_all;
 use metrics::counter;
 use rand::seq::SliceRandom as _;
 use rustfs_common::heal_channel::HealScanMode;
-use rustfs_common::metrics::{Metric, Metrics, emit_scan_bucket_drive_complete};
+use rustfs_common::metrics::{Metric, Metrics, emit_scan_bucket_drive_complete, global_metrics};
 use rustfs_config::{
     DEFAULT_SCANNER_MAX_CONCURRENT_DISK_SCANS, DEFAULT_SCANNER_MAX_CONCURRENT_SET_SCANS, ENV_SCANNER_MAX_CONCURRENT_DISK_SCANS,
     ENV_SCANNER_MAX_CONCURRENT_SET_SCANS,
@@ -116,6 +116,28 @@ impl Drop for DiskBucketScanActiveGuard {
     }
 }
 
+struct BucketDriveFailureGuard {
+    failed: bool,
+}
+
+impl BucketDriveFailureGuard {
+    fn new() -> Self {
+        Self { failed: true }
+    }
+
+    fn mark_success(&mut self) {
+        self.failed = false;
+    }
+}
+
+impl Drop for BucketDriveFailureGuard {
+    fn drop(&mut self) {
+        if self.failed {
+            global_metrics().record_scan_bucket_drive_failure();
+        }
+    }
+}
+
 fn decrement_atomic_usize(counter: &AtomicUsize) -> usize {
     counter
         .fetch_update(Ordering::Relaxed, Ordering::Relaxed, |current| Some(current.saturating_sub(1)))
@@ -217,9 +239,11 @@ async fn persist_and_publish_cache_snapshot<S: StorageAPI>(
 ) -> Option<SystemTime> {
     let last_update = cache_snapshot.info.last_update;
 
+    let done_save = Metrics::time(Metric::SaveUsage);
     if let Err(e) = cache_snapshot.save(store, DATA_USAGE_CACHE_NAME).await {
         error!("Failed to save data usage cache: {}", e);
     }
+    done_save();
 
     if let Err(e) = updates.send(cache_snapshot).await {
         error!("Failed to send data usage cache: {}", e);
@@ -732,9 +756,12 @@ impl ScannerIOCache for SetDisks {
 
                             if let (Some(last_update), Some(before_update)) = (cache.info.last_update, before)
                                 && last_update > before_update
-                                && let Err(e) = cache.save(store_clone_clone.clone(), cache_name.as_str()).await
                             {
-                                error!("Failed to save data usage cache: {}", e);
+                                let done_save = Metrics::time(Metric::SaveUsage);
+                                if let Err(e) = cache.save(store_clone_clone.clone(), cache_name.as_str()).await {
+                                    error!("Failed to save data usage cache: {}", e);
+                                }
+                                done_save();
                             }
 
                             if let Err(e) = update_fut.await {
@@ -775,9 +802,11 @@ impl ScannerIOCache for SetDisks {
                         error!("nsscanner_disk: Failed to send data usage entry info: {}", e);
                     }
 
+                    let done_save = Metrics::time(Metric::SaveUsage);
                     if let Err(e) = cache.save(store_clone_clone.clone(), &cache_name).await {
                         error!("nsscanner_disk: Failed to save data usage cache: {}", e);
                     }
+                    done_save();
                 }
             }));
         }
@@ -900,6 +929,8 @@ impl ScannerIODisk for Disk {
         let drive_start = std::time::Instant::now();
         let bucket = cache.info.name.clone();
         let disk_path = self.path().to_string_lossy().to_string();
+        global_metrics().record_scan_bucket_drive_start();
+        let mut failure_guard = BucketDriveFailureGuard::new();
         let _guard = self.start_scan();
 
         let mut cache = cache;
@@ -966,9 +997,11 @@ impl ScannerIODisk for Disk {
                 done_drive();
                 emit_scan_bucket_drive_complete(true, &bucket, &disk_path, drive_start.elapsed());
                 data_usage_info.info.last_update = Some(SystemTime::now());
+                failure_guard.mark_success();
                 Ok(data_usage_info)
             }
             Err(e) => {
+                done_drive();
                 emit_scan_bucket_drive_complete(false, &bucket, &disk_path, drive_start.elapsed());
                 Err(StorageError::other(format!("Failed to scan data folder: {e}")))
             }

crates/scanner/src/sleeper.rs

@@ -16,7 +16,11 @@ use std::sync::atomic::{AtomicBool, AtomicU8, Ordering};
 use std::sync::{Arc, LazyLock, RwLock};
 use std::time::Instant;
 
-use rustfs_config::{DEFAULT_SCANNER_IDLE_MODE, ENV_SCANNER_IDLE_MODE, ENV_SCANNER_SPEED, ScannerSpeed};
+use rustfs_common::metrics::global_metrics;
+use rustfs_config::{
+    DEFAULT_SCANNER_IDLE_MODE, DEFAULT_SCANNER_YIELD_EVERY_N_OBJECTS, ENV_SCANNER_IDLE_MODE, ENV_SCANNER_SPEED,
+    ENV_SCANNER_YIELD_EVERY_N_OBJECTS, ScannerSpeed,
+};
 use tokio::time::Duration;
 
 const MIN_SLEEP: Duration = Duration::from_millis(1);
@@ -64,6 +68,10 @@ fn scanner_env_config() -> (ScannerSpeed, bool) {
     (speed, idle_mode)
 }
 
+pub(crate) fn scanner_yield_every_n_objects() -> u64 {
+    rustfs_utils::get_env_u64(ENV_SCANNER_YIELD_EVERY_N_OBJECTS, DEFAULT_SCANNER_YIELD_EVERY_N_OBJECTS)
+}
+
 /// When `true` (default), the scanner throttles itself between operations.
 /// When `false`, all sleeps are skipped and the scanner runs at full speed.
 pub static SCANNER_IDLE_MODE: AtomicBool = AtomicBool::new(DEFAULT_SCANNER_IDLE_MODE);
@@ -74,7 +82,9 @@ pub static SCANNER_SLEEPER: LazyLock<DynamicSleeper> = LazyLock::new(|| {
     let (speed, idle_mode) = scanner_env_config();
     SCANNER_IDLE_MODE.store(idle_mode, Ordering::Relaxed);
 
-    DynamicSleeper::new(speed)
+    let sleeper = DynamicSleeper::new(speed);
+    sleeper.record_throttle_config();
+    sleeper
 });
 
 /// Proportional-backoff sleeper for the data scanner.
@@ -124,6 +134,7 @@ impl DynamicSleeper {
         let sleep_dur = Duration::from_secs_f64(MIN_SLEEP.as_secs_f64() * factor).min(max_sleep);
         if !sleep_dur.is_zero() {
             tokio::time::sleep(sleep_dur).await;
+            global_metrics().record_scanner_yield(sleep_dur);
         }
     }
 
@@ -150,6 +161,17 @@ impl DynamicSleeper {
         let (speed, idle_mode) = scanner_env_config();
         self.update(speed);
         SCANNER_IDLE_MODE.store(idle_mode, Ordering::Relaxed);
+        self.record_throttle_config();
+    }
+
+    fn record_throttle_config(&self) {
+        let (factor, max_sleep) = self.read_params();
+        global_metrics().record_scanner_throttle_config(
+            SCANNER_IDLE_MODE.load(Ordering::Relaxed),
+            factor,
+            max_sleep,
+            scanner_yield_every_n_objects(),
+        );
     }
 }
 
@@ -177,6 +199,7 @@ impl SleepTimer {
             .min(max_sleep);
         if !sleep_dur.is_zero() {
             tokio::time::sleep(sleep_dur).await;
+            global_metrics().record_scanner_yield(sleep_dur);
         }
     }
 }